Message-ID: <c3f123ca-03f7-b7ce-1e49-f8fee4c16545@gmail.com>
Date: Sat, 16 Sep 2023 09:00:00 +0300
MIME-Version: 1.0
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101
 Thunderbird/102.4.2
Subject: Re: BUG #17928: Standby fails to decode WAL on termination of primary
Content-Language: en-US
To: Thomas Munro <thomas.munro@gmail.com>,
 Michael Paquier <michael@paquier.xyz>
Cc: Sergei Kornilov <sk@zsrv.org>, Noah Misch <noah@leadboat.com>,
 Tom Lane <tgl@sss.pgh.pa.us>, Kyotaro Horiguchi <horikyota.ntt@gmail.com>,
 pgsql-bugs@lists.postgresql.org, Fujii Masao <masao.fujii@oss.nttdata.com>
References: 
 <CA+hUKGLcT4ttqts4ow1=ZF9c+AwU=YfovfPs=r-Y2n0G-BunFA@mail.gmail.com>
 <ZPWHHj0cbcKl1x7L@paquier.xyz>
 <CA+hUKG+cap7=Tnf-oRAU2jH6dVxcuygNfyL42afU6UYKaw7pTg@mail.gmail.com>
 <ZPaeUimGAzhYVEn9@paquier.xyz>
 <CA+hUKGJV1Ow_S86Fj25J_orojXkn4WPeARyY8-Xr88c85rJHEQ@mail.gmail.com>
 <ZPaq3KwARVHWzune@paquier.xyz> <ZP+4YYrPZk0GFlc3@paquier.xyz>
 <CA+hUKG+=jiXcE9uOkf3KHDb_ZAkjahQ8jzBXsEOAoXH=y0Z=uw@mail.gmail.com>
 <ZP/I93ZSL0Mvt5rS@paquier.xyz>
 <CA+hUKGKj3vgopo9YC3hk7zDgkAGAA+aP6ZPGgTa-QVLvn7EK7A@mail.gmail.com>
 <ZQTwsT6tsbx6BYn3@paquier.xyz>
 <CA+hUKGJOXdpWO_6wK0q3jsEwk5cJ6fAQj1T1mE9cFj6R+tPtrw@mail.gmail.com>
From: Alexander Lakhin <exclusion@gmail.com>
In-Reply-To: 
 <CA+hUKGJOXdpWO_6wK0q3jsEwk5cJ6fAQj1T1mE9cFj6R+tPtrw@mail.gmail.com>
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 8bit
Archived-At: 
 <https://www.postgresql.org/message-id/c3f123ca-03f7-b7ce-1e49-f8fee4c16545%40gmail.com>
Precedence: bulk

Hello,

16.09.2023 03:20, Thomas Munro wrote:
> On Sat, Sep 16, 2023 at 12:03 PM Michael Paquier <michael@paquier.xyz> wrote:
>>> [1] https://github.com/macdice/postgres/commits/fix-12
>> Hmm.  What was the test that failed?
> $ make -s -C src/test/recovery/ check PROVE_TESTS=t/039*
> t/039_end_of_wal.pl .. 4/?
> #   Failed test 'xlp_magic zero'
> #   at t/039_end_of_wal.pl line 312.
>
> not ok 5 - xlp_magic zero
>
> Where the log should say "invalid magic number 0000" I see:
>
> 2023-09-16 12:13:07.331 NZST [156812] LOG:  record with incorrect
> prev-link 0/16B60C0 at 0/16B6120
>
> It has to do with initial WAL position after initdb, because I get
> this only on Debian, on REL_12_STABLE (with the commit listed above on
> my public fix-12 branch) and only with --with-icu, but not without it,
> and I can't repro it on my other local OSes.

I tried to reproduce the failure on Debian 9, 10, 11, but not succeeded yet.
Though I got another error on Debian 9:
t/039_end_of_wal.pl .. Dubious, test returned 25 (wstat 6400, 0x1900)
No subtests run
...
cat src/test/recovery/tmp_check/log/regress_log_039_end_of_wal
could not find match in header access/xlog_internal.h

It looks like the construction "@{^CAPTURE}" used in scan_server_header()
is not supported by Perl 5.24, which is included in Debian stretch:
https://perldoc.perl.org/variables/@%7B%5ECAPTURE%7D
I replaced it with
@match = ($1);
and that worked for me.

Also, I observed that "wal_log_hints = on" in extra.config, which I use via
"TEMP_CONFIG=extra.config make check-world" makes the test fail too, though
check-world passes fine without the new test.
Maybe that's not an issue, and probably there are other parameters, which
might affect this test, but I'm somewhat confused by the fact that only this
test breaks with it.

Best regards,
Alexander