Content-Type: multipart/mixed; boundary="------------NURRuljFo7G8HSmeKv7VdE24"
Message-ID: <9d00b597-d64a-4f1e-802e-90f9dc394c70@gmail.com>
Date: Wed, 5 Nov 2025 00:03:29 -0600
MIME-Version: 1.0
User-Agent: Mozilla Thunderbird
Content-Language: en-US
To: pgsql-hackers <pgsql-hackers@postgresql.org>
From: Bryan Green <dbryan.green@gmail.com>
Subject: [PATCH] Fix fragile walreceiver test.
Archived-At: 
 <https://www.postgresql.org/message-id/9d00b597-d64a-4f1e-802e-90f9dc394c70%40gmail.com>
Precedence: bulk

This is a multi-part message in MIME format.
--------------NURRuljFo7G8HSmeKv7VdE24
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 7bit

The recovery/004_timeline_switch test has been failing for me on
Windows. The test is wrong.

The test does this:

    $node_standby_2->restart;
    # ... timeline switch happens ...
    ok( !$node_standby_2->log_contains(
            "FATAL: .* terminating walreceiver process due to
administrator command"
        ),
        'WAL receiver should not be stopped across timeline jumps');

Problem: restart() kills the walreceiver (as it should), which writes
that exact FATAL message to the log. The test then searches the log and
finds it.

The test has a comment claiming "a new log file is used on node
restart". TAP tests use pg_ctl with a fixed filename that gets reused
across restarts. No log rotation.

I added logging to confirm what's actually happening. The walreceiver
works correctly - same PID handles both timelines:

    2025-11-04 23:05:28.539 CST walreceiver[83824] LOG:  started
streaming WAL from primary at 0/03000000 on timeline 1
    2025-11-04 23:05:28.543 CST startup[42764] LOG:  new target timeline
is 2
    2025-11-04 23:05:28.544 CST walreceiver[83824] LOG:  restarted WAL
        streaming at 0/03000000 on timeline 2

That's PID 83824 throughout. Works fine.

Earlier in the same log, from the restart:

    2025-11-04 23:05:27.261 CST walreceiver[52440] FATAL:  terminating
        walreceiver process due to administrator command

Different PID (52440), expected shutdown. This is what the test finds.

The fix is obvious: check that the walreceiver PID stays constant.
That's what we actually care about anyway.

This matters because changes to I/O behavior elsewhere in the code can
make this test fail spuriously. I hit it while working on O_CLOEXEC
handling for Windows.

Patch attached.
-- 
Bryan Green
EDB: https://www.enterprisedb.com

--------------NURRuljFo7G8HSmeKv7VdE24
Content-Type: text/plain; charset=UTF-8;
 name="0001-Fix-timing-dependent-failure-in-recovery-004_timelin.patch"
Content-Disposition: attachment;
 filename*0="0001-Fix-timing-dependent-failure-in-recovery-004_timelin.pa";
 filename*1="tch"
Content-Transfer-Encoding: base64

RnJvbSBlZjRiNTk3NjBhOTEwZmJmZDNlYTg4MDExMzA3YzNhZjE4OGMyYjQyIE1vbiBTZXAg
MTcgMDA6MDA6MDAgMjAwMQpGcm9tOiBCcnlhbiBHcmVlbiA8ZGJyeWFuLmdyZWVuQGdtYWls
LmNvbT4KRGF0ZTogVHVlLCA0IE5vdiAyMDI1IDIzOjQxOjI5IC0wNjAwClN1YmplY3Q6IFtQ
QVRDSF0gRml4IHRpbWluZy1kZXBlbmRlbnQgZmFpbHVyZSBpbiByZWNvdmVyeS8wMDRfdGlt
ZWxpbmVfc3dpdGNoLgoKVGhlIHRlc3QgdmVyaWZpZWQgd2FscmVjZWl2ZXIgc3Vydml2YWwg
Ynkgc2VhcmNoaW5nIGxvZ3MgZm9yIHRlcm1pbmF0aW9uCm1lc3NhZ2VzLiBIb3dldmVyLCBp
dCBjYWxsZWQgcmVzdGFydCgpIGJlZm9yZSB0aGUgdGltZWxpbmUgc3dpdGNoLCB3aGljaApr
aWxscyB3YWxyZWNlaXZlciBhbmQgbG9ncyB0aGUgZXhhY3QgbWVzc2FnZSBiZWluZyBjaGVj
a2VkLiBUQVAgdGVzdHMKcmV1c2UgdGhlIHNhbWUgbG9nIGZpbGUgYWNyb3NzIHJlc3RhcnRz
LCBzbyBsb2dfY29udGFpbnMoKSBmaW5kcyB0aGF0Cm1lc3NhZ2UgYW5kIHRoZSB0ZXN0IGZh
aWxzLgoKRXhjZXB0IHNvbWV0aW1lcyBpdCBkaWRuJ3QgZmFpbCwgYmVjYXVzZSB0aGUgbWVz
c2FnZSB3YXNuJ3QgZmx1c2hlZCB5ZXQuClJlY2VudCBjaGFuZ2VzIHRvIGZpbGUgaGFuZGxl
IGluaGVyaXRhbmNlIGFsdGVyZWQgSS9PIHRpbWluZyBlbm91Z2ggdG8KbWFrZSB0aGlzIGZh
aWwgY29uc2lzdGVudGx5IHdoaWxlIHRlc3RpbmcgYW5vdGhlciBwYXRjaC4KClJlcGxhY2Ug
dGhlIGxvZyBjaGVjayB3aXRoIGEgUElEIGNvbXBhcmlzb24sIHdoaWNoIGFjdHVhbGx5IHRl
c3RzIHdoYXQKd2UgY2FyZSBhYm91dC4KLS0tCiBzcmMvdGVzdC9yZWNvdmVyeS90LzAwNF90
aW1lbGluZV9zd2l0Y2gucGwgfCAyOCArKysrKysrKysrKysrKysrLS0tLS0tCiAxIGZpbGUg
Y2hhbmdlZCwgMjEgaW5zZXJ0aW9ucygrKSwgNyBkZWxldGlvbnMoLSkKCmRpZmYgLS1naXQg
YS9zcmMvdGVzdC9yZWNvdmVyeS90LzAwNF90aW1lbGluZV9zd2l0Y2gucGwgYi9zcmMvdGVz
dC9yZWNvdmVyeS90LzAwNF90aW1lbGluZV9zd2l0Y2gucGwKaW5kZXggMTM4NzRmZjg2Ni4u
MjFlOTRhMWRlMyAxMDA2NDQKLS0tIGEvc3JjL3Rlc3QvcmVjb3ZlcnkvdC8wMDRfdGltZWxp
bmVfc3dpdGNoLnBsCisrKyBiL3NyYy90ZXN0L3JlY292ZXJ5L3QvMDA0X3RpbWVsaW5lX3N3
aXRjaC5wbApAQCAtNTYsNiArNTYsMTYgQEAgcHJpbWFyeV9jb25uaW5mbz0nJGNvbm5zdHJf
MScKICkpOwogJG5vZGVfc3RhbmRieV8yLT5yZXN0YXJ0OwogCisjIFdhaXQgZm9yIHdhbHJl
Y2VpdmVyIHRvIHJlY29ubmVjdCBhZnRlciB0aGUgcmVzdGFydC4gIFRoZSByZXN0YXJ0Cisj
IHdpbGwgaGF2ZSBraWxsZWQgdGhlIG9sZCB3YWxyZWNlaXZlciwgd2hpY2ggaXMgZXhwZWN0
ZWQuICBXZSB3YW50IHRvCisjIHZlcmlmeSB0aGF0IGFmdGVyIHJlY29ubmVjdGlvbiwgdGhl
IHdhbHJlY2VpdmVyIHN0YXlzIGFsaXZlIGR1cmluZworIyB0aGUgdGltZWxpbmUgc3dpdGNo
LgorJG5vZGVfc3RhbmRieV8yLT5wb2xsX3F1ZXJ5X3VudGlsKCdwb3N0Z3JlcycsCisJIlNF
TEVDVCBFWElTVFMoU0VMRUNUIDEgRlJPTSBwZ19zdGF0X3dhbF9yZWNlaXZlcikiKTsKK215
ICR3cl9waWRfYmVmb3JlX3N3aXRjaCA9ICRub2RlX3N0YW5kYnlfMi0+c2FmZV9wc3FsKCdw
b3N0Z3JlcycsCisJIlNFTEVDVCBwaWQgRlJPTSBwZ19zdGF0X3dhbF9yZWNlaXZlciIpOwor
CisKICMgSW5zZXJ0IHNvbWUgZGF0YSBpbiBzdGFuZGJ5IDEgYW5kIGNoZWNrIGl0cyBwcmVz
ZW5jZSBpbiBzdGFuZGJ5IDIKICMgdG8gZW5zdXJlIHRoYXQgdGhlIHRpbWVsaW5lIHN3aXRj
aCBoYXMgYmVlbiBkb25lLgogJG5vZGVfc3RhbmRieV8xLT5zYWZlX3BzcWwoJ3Bvc3RncmVz
JywKQEAgLTY2LDEzICs3NiwxNyBAQCBteSAkcmVzdWx0ID0KICAgJG5vZGVfc3RhbmRieV8y
LT5zYWZlX3BzcWwoJ3Bvc3RncmVzJywgIlNFTEVDVCBjb3VudCgqKSBGUk9NIHRhYl9pbnQi
KTsKIGlzKCRyZXN1bHQsIHFxKDIwMDApLCAnY2hlY2sgY29udGVudCBvZiBzdGFuZGJ5IDIn
KTsKIAotIyBDaGVjayB0aGUgbG9ncywgV0FMIHJlY2VpdmVyIHNob3VsZCBub3QgaGF2ZSBi
ZWVuIHN0b3BwZWQgd2hpbGUKLSMgdHJhbnNpdGlvbmluZyB0byBpdHMgbmV3IHRpbWVsaW5l
LiAgVGhlcmUgaXMgbm8gbmVlZCB0byByZWx5IG9uIGFuCi0jIG9mZnNldCBpbiB0aGlzIGNo
ZWNrIG9mIHRoZSBzZXJ2ZXIgbG9nczogYSBuZXcgbG9nIGZpbGUgaXMgdXNlZCBvbgotIyBu
b2RlIHJlc3RhcnQgd2hlbiBwcmltYXJ5X2Nvbm5pbmZvIGlzIHVwZGF0ZWQgYWJvdmUuCi1v
ayggISRub2RlX3N0YW5kYnlfMi0+bG9nX2NvbnRhaW5zKAotCQkiRkFUQUw6IC4qIHRlcm1p
bmF0aW5nIHdhbHJlY2VpdmVyIHByb2Nlc3MgZHVlIHRvIGFkbWluaXN0cmF0b3IgY29tbWFu
ZCIKLQkpLAorCisjIFZlcmlmeSB0aGF0IHRoZSB3YWxyZWNlaXZlciBwcm9jZXNzIHN0YXll
ZCBhbGl2ZSBhY3Jvc3MgdGhlIHRpbWVsaW5lCisjIHN3aXRjaC4gIFdlIHJlY29yZGVkIHRo
ZSBQSUQgYWZ0ZXIgcmVjb25uZWN0aW9uIGFuZCBub3cgY2hlY2sgdGhhdAorIyBpdCdzIHRo
ZSBzYW1lIGFmdGVyIGNvbXBsZXRpbmcgdGhlIHRpbWVsaW5lIHN3aXRjaC4gIFRoaXMgaXMg
bW9yZQorIyByZWxpYWJsZSB0aGFuIGNoZWNraW5nIGxvZyBtZXNzYWdlcywgd2hpY2ggbWF5
IGluY2x1ZGUgZXhwZWN0ZWQKKyMgc2h1dGRvd24gbWVzc2FnZXMgZnJvbSB0aGUgcmVzdGFy
dC4KK215ICR3cl9waWRfYWZ0ZXJfc3dpdGNoID0gJG5vZGVfc3RhbmRieV8yLT5zYWZlX3Bz
cWwoJ3Bvc3RncmVzJywKKwkiU0VMRUNUIHBpZCBGUk9NIHBnX3N0YXRfd2FsX3JlY2VpdmVy
Iik7CisKK2lzKCAkd3JfcGlkX2JlZm9yZV9zd2l0Y2gsCisJJHdyX3BpZF9hZnRlcl9zd2l0
Y2gsCiAJJ1dBTCByZWNlaXZlciBzaG91bGQgbm90IGJlIHN0b3BwZWQgYWNyb3NzIHRpbWVs
aW5lIGp1bXBzJyk7CiAKICMgRW5zdXJlIHRoYXQgYSBzdGFuZGJ5IGlzIGFibGUgdG8gZm9s
bG93IGEgcHJpbWFyeSBvbiBhIG5ld2VyIHRpbWVsaW5lCi0tIAoyLjQ2LjAud2luZG93cy4x
Cgo=

--------------NURRuljFo7G8HSmeKv7VdE24--