pgsql: Ensure that a standby is able to follow a primary on a newer tim

Hi Fujii-san,

On Thu, Jan 14, 2021 at 03:32:52AM +0000, Fujii Masao wrote:

Ensure that a standby is able to follow a primary on a newer timeline.

Commit 709d003fbd refactored WAL-reading code, but accidentally caused
WalSndSegmentOpen() to fail to follow a timeline switch while reading from
a historic timeline. This issue caused a standby to fail to follow a primary
on a newer timeline when WAL archiving is enabled.

florican is telling that this test has some stability problems:
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=florican&dt=2021-01-14%2003%3A55%3A45

Here I can see that replication keeps asking for a segment that's
already gone:
2021-01-13 23:34:52.104 EST [64611:1] LOG: started streaming WAL from
primary at 0/3000000 on timeline 1
2021-01-13 23:34:52.104 EST [64611:2] FATAL: could not receive data
from WAL stream: ERROR: requested WAL segment
000000010000000000000003 has already been removed

At quick glance, it seems to be an issue after the promotion of
primary_2 before starting standby_3.
--
Michael

On 2021/01/14 13:59, Michael Paquier wrote:

Hi Fujii-san,

On Thu, Jan 14, 2021 at 03:32:52AM +0000, Fujii Masao wrote:

Ensure that a standby is able to follow a primary on a newer timeline.

Commit 709d003fbd refactored WAL-reading code, but accidentally caused
WalSndSegmentOpen() to fail to follow a timeline switch while reading from
a historic timeline. This issue caused a standby to fail to follow a primary
on a newer timeline when WAL archiving is enabled.

florican is telling that this test has some stability problems:
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=florican&dt=2021-01-14%2003%3A55%3A45

Here I can see that replication keeps asking for a segment that's
already gone:
2021-01-13 23:34:52.104 EST [64611:1] LOG: started streaming WAL from
primary at 0/3000000 on timeline 1
2021-01-13 23:34:52.104 EST [64611:2] FATAL: could not receive data
from WAL stream: ERROR: requested WAL segment
000000010000000000000003 has already been removed

Thanks for reporting this! I'm looking at this issue.

My guess is that the requested WAL file was removed unfortunately by
checkpoint because no replication slot is used and wal_keep_size is not set.
So easy fix is to set wal_keep_size to 512MB or other in that test. Thought?

Regards,

--
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION

Fujii Masao <masao.fujii@oss.nttdata.com> writes:

On 2021/01/14 13:59, Michael Paquier wrote:

florican is telling that this test has some stability problems:
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=florican&amp;dt=2021-01-14%2003%3A55%3A45

My guess is that the requested WAL file was removed unfortunately by
checkpoint because no replication slot is used and wal_keep_size is not set.
So easy fix is to set wal_keep_size to 512MB or other in that test. Thought?

florican did pass this test on the v13 branch, so I agree it's probably
a timing issue not any deeper bug. Your theory seems plausible.

regards, tom lane

On 2021/01/14 14:23, Tom Lane wrote:

Fujii Masao <masao.fujii@oss.nttdata.com> writes:

On 2021/01/14 13:59, Michael Paquier wrote:

florican is telling that this test has some stability problems:
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=florican&amp;dt=2021-01-14%2003%3A55%3A45

My guess is that the requested WAL file was removed unfortunately by
checkpoint because no replication slot is used and wal_keep_size is not set.
So easy fix is to set wal_keep_size to 512MB or other in that test. Thought?

florican did pass this test on the v13 branch, so I agree it's probably
a timing issue not any deeper bug. Your theory seems plausible.

Thanks for the check!

So, barring any objection, I will push the attached patch that sets
wal_keep_size in the test.

BTW, I included the URL to Michael's report [1]/messages/by-id/X//PsenxcC50jDzX@paquier.xyz in the commit log. But this
URL doesn't seem to work fine maybe because <message-id> part includes
a slash character.

[1]: /messages/by-id/X//PsenxcC50jDzX@paquier.xyz
/messages/by-id/X//PsenxcC50jDzX@paquier.xyz

Regards,

--
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION

On Thu, Jan 14, 2021 at 03:19:02PM +0900, Fujii Masao wrote:

BTW, I included the URL to Michael's report [1] in the commit log. But this
URL doesn't seem to work fine maybe because <message-id> part includes
a slash character.

Sorry about that. This is related to mutt that has changed its logic
to generate message-ids in a recent release to be more random, and
maybe Debian is in play here with some custom patch, but I am not
sure. That's not configurable, but I'll try to investigate more if
there is something I can do about it :/
--
Michael