A failure of standby to follow timeline switch

Started by Kyotaro Horiguchiover 5 years ago18 messageshackers
Jump to latest
#1Kyotaro Horiguchi
horikyota.ntt@gmail.com

Hello.

We found a behavioral change (which seems to be a bug) in recovery at
PG13.

The following steps might seem somewhat strange but the replication
code deliberately cope with the case. This is a sequense seen while
operating a HA cluseter using Pacemaker.

- Run initdb to create a primary.
- Set archive_mode=on on the primary.
- Start the primary.

- Create a standby using pg_basebackup from the primary.
- Stop the standby.
- Stop the primary.

- Put stnadby.signal to the primary then start it.
- Promote the primary.

- Start the standby.

Until PG12, the parimary signals end-of-timeline to the standby and
switches to the next timeline. Since PG13, that doesn't happen and
the standby continues to request for the segment of the older
timeline, which no longer exists.

FATAL: could not receive data from WAL stream: ERROR: requested WAL segment 000000010000000000000003 has already been removed

It is because WalSndSegmentOpen() can fail to detect a timeline switch
on a historic timeline, due to use of a wrong variable to check
that. It is using state->seg.ws_segno but it seems to be a thinko when
the code around was refactored in 709d003fbd.

The first patch detects the wrong behavior. The second small patch
fixes it.

In the first patch, the test added to 001_stream_rep.pl involves two
copied functions related to server-log investigation from
019_repslot_limit.pl.

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

Attachments:

0001-Add-a-new-test-to-detect-a-replication-bug.patchtext/x-patch; charset=us-asciiDownload+63-2
0002-Fix-a-bug-of-timeline-tracking-while-sending-a-histo.patchtext/x-patch; charset=us-asciiDownload+1-2
#2Fujii Masao
masao.fujii@gmail.com
In reply to: Kyotaro Horiguchi (#1)
Re: A failure of standby to follow timeline switch

On 2020/12/09 17:43, Kyotaro Horiguchi wrote:

Hello.

We found a behavioral change (which seems to be a bug) in recovery at
PG13.

The following steps might seem somewhat strange but the replication
code deliberately cope with the case. This is a sequense seen while
operating a HA cluseter using Pacemaker.

- Run initdb to create a primary.
- Set archive_mode=on on the primary.
- Start the primary.

- Create a standby using pg_basebackup from the primary.
- Stop the standby.
- Stop the primary.

- Put stnadby.signal to the primary then start it.
- Promote the primary.

- Start the standby.

Until PG12, the parimary signals end-of-timeline to the standby and
switches to the next timeline. Since PG13, that doesn't happen and
the standby continues to request for the segment of the older
timeline, which no longer exists.

FATAL: could not receive data from WAL stream: ERROR: requested WAL segment 000000010000000000000003 has already been removed

It is because WalSndSegmentOpen() can fail to detect a timeline switch
on a historic timeline, due to use of a wrong variable to check
that. It is using state->seg.ws_segno but it seems to be a thinko when
the code around was refactored in 709d003fbd.

The first patch detects the wrong behavior. The second small patch
fixes it.

Thanks for reporting this! This looks like a bug.

When I applied two patches in the master branch and
ran "make check-world", I got the following error.

============== creating database "contrib_regression" ==============
# Looks like you planned 37 tests but ran 36.
# Looks like your test exited with 255 just after 36.
t/001_stream_rep.pl ..................
Dubious, test returned 255 (wstat 65280, 0xff00)
Failed 1/37 subtests
...
Test Summary Report
-------------------
t/001_stream_rep.pl (Wstat: 65280 Tests: 36 Failed: 0)
Non-zero exit status: 255
Parse errors: Bad plan. You planned 37 tests but ran 36.
Files=21, Tests=239, 302 wallclock secs ( 0.10 usr 0.05 sys + 41.69 cusr 39.84 csys = 81.68 CPU)
Result: FAIL
make[2]: *** [check] Error 1
make[1]: *** [check-recovery-recurse] Error 2
make[1]: *** Waiting for unfinished jobs....
t/070_dropuser.pl ......... ok

Regards,

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

#3Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Fujii Masao (#2)
Re: A failure of standby to follow timeline switch

Thank you for looking this.

At Thu, 24 Dec 2020 15:33:04 +0900, Fujii Masao <masao.fujii@oss.nttdata.com> wrote in

When I applied two patches in the master branch and
ran "make check-world", I got the following error.

============== creating database "contrib_regression" ==============
# Looks like you planned 37 tests but ran 36.
# Looks like your test exited with 255 just after 36.
t/001_stream_rep.pl ..................
Dubious, test returned 255 (wstat 65280, 0xff00)
Failed 1/37 subtests
...
Test Summary Report
-------------------
t/001_stream_rep.pl (Wstat: 65280 Tests: 36 Failed: 0)
Non-zero exit status: 255
Parse errors: Bad plan. You planned 37 tests but ran 36.
Files=21, Tests=239, 302 wallclock secs ( 0.10 usr 0.05 sys + 41.69
cusr 39.84 csys = 81.68 CPU)
Result: FAIL
make[2]: *** [check] Error 1
make[1]: *** [check-recovery-recurse] Error 2
make[1]: *** Waiting for unfinished jobs....
t/070_dropuser.pl ......... ok

Mmm. I retried that and saw it succeed (with 0002 applied).

If I modified "user Test::More tests => 37" to 38 in the perl file, I
got a similar result.

t/001_stream_rep.pl .. 37/38 # Looks like you planned 38 tests but ran 37.
t/001_stream_rep.pl .. Dubious, test returned 255 (wstat 65280, 0xff00)
Failed 1/38 subtests

Test Summary Report
-------------------
t/001_stream_rep.pl (Wstat: 65280 Tests: 37 Failed: 0)
Non-zero exit status: 255
Parse errors: Bad plan. You planned 38 tests but ran 37.
Files=1, Tests=37, 10 wallclock secs ( 0.03 usr 0.00 sys + 3.64 cusr 2.05 csy
s = 5.72 CPU)
Result: FAIL
make: *** [Makefile:19: check] Error 1

I can't guess what happenened on your environment..

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

#4Fujii Masao
masao.fujii@gmail.com
In reply to: Kyotaro Horiguchi (#3)
Re: A failure of standby to follow timeline switch

On 2020/12/25 12:03, Kyotaro Horiguchi wrote:

Thank you for looking this.

At Thu, 24 Dec 2020 15:33:04 +0900, Fujii Masao <masao.fujii@oss.nttdata.com> wrote in

When I applied two patches in the master branch and
ran "make check-world", I got the following error.

============== creating database "contrib_regression" ==============
# Looks like you planned 37 tests but ran 36.
# Looks like your test exited with 255 just after 36.
t/001_stream_rep.pl ..................
Dubious, test returned 255 (wstat 65280, 0xff00)
Failed 1/37 subtests
...
Test Summary Report
-------------------
t/001_stream_rep.pl (Wstat: 65280 Tests: 36 Failed: 0)
Non-zero exit status: 255
Parse errors: Bad plan. You planned 37 tests but ran 36.
Files=21, Tests=239, 302 wallclock secs ( 0.10 usr 0.05 sys + 41.69
cusr 39.84 csys = 81.68 CPU)
Result: FAIL
make[2]: *** [check] Error 1
make[1]: *** [check-recovery-recurse] Error 2
make[1]: *** Waiting for unfinished jobs....
t/070_dropuser.pl ......... ok

Mmm. I retried that and saw it succeed (with 0002 applied).

If I modified "user Test::More tests => 37" to 38 in the perl file, I
got a similar result.

What happens if you run make check-world with -j 4? When I ran that,
the test failed. But with -j 1, the test finished with success. I'm not sure
why this happened, though..

Regards,

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

#5Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Fujii Masao (#4)
Re: A failure of standby to follow timeline switch

At Sat, 26 Dec 2020 02:15:06 +0900, Fujii Masao <masao.fujii@oss.nttdata.com> wrote in

On 2020/12/25 12:03, Kyotaro Horiguchi wrote:

Thank you for looking this.
At Thu, 24 Dec 2020 15:33:04 +0900, Fujii Masao
<masao.fujii@oss.nttdata.com> wrote in

When I applied two patches in the master branch and
ran "make check-world", I got the following error.

============== creating database "contrib_regression" ==============
# Looks like you planned 37 tests but ran 36.
# Looks like your test exited with 255 just after 36.
t/001_stream_rep.pl ..................
Dubious, test returned 255 (wstat 65280, 0xff00)
Failed 1/37 subtests
...
Test Summary Report
-------------------
t/001_stream_rep.pl (Wstat: 65280 Tests: 36 Failed: 0)
Non-zero exit status: 255
Parse errors: Bad plan. You planned 37 tests but ran 36.
Files=21, Tests=239, 302 wallclock secs ( 0.10 usr 0.05 sys + 41.69
cusr 39.84 csys = 81.68 CPU)
Result: FAIL
make[2]: *** [check] Error 1
make[1]: *** [check-recovery-recurse] Error 2
make[1]: *** Waiting for unfinished jobs....
t/070_dropuser.pl ......... ok

Mmm. I retried that and saw it succeed (with 0002 applied).
If I modified "user Test::More tests => 37" to 38 in the perl file, I
got a similar result.

What happens if you run make check-world with -j 4? When I ran that,
the test failed. But with -j 1, the test finished with success. I'm
not sure
why this happened, though..

Maybe this is it.

+ usleep(100_000);

If the script doesn't find the expected log line, it reaches the
usleep and bark that "Undefined subroutine &main::usleep called...". I
thought I tested that path but perhaps I overlooked the error. "use
Time::HiRes" is needed.

The attached is the fixed version.

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

Attachments:

v2-0001-Add-a-new-test-to-detect-a-replication-bug.patchtext/x-patch; charset=us-asciiDownload+64-2
v2-0002-Fix-a-bug-of-timeline-tracking-while-sending-a-hi.patchtext/x-patch; charset=us-asciiDownload+1-2
#6Fujii Masao
masao.fujii@gmail.com
In reply to: Kyotaro Horiguchi (#5)
Re: A failure of standby to follow timeline switch

On 2021/01/04 12:06, Kyotaro Horiguchi wrote:

At Sat, 26 Dec 2020 02:15:06 +0900, Fujii Masao <masao.fujii@oss.nttdata.com> wrote in

On 2020/12/25 12:03, Kyotaro Horiguchi wrote:

Thank you for looking this.
At Thu, 24 Dec 2020 15:33:04 +0900, Fujii Masao
<masao.fujii@oss.nttdata.com> wrote in

When I applied two patches in the master branch and
ran "make check-world", I got the following error.

============== creating database "contrib_regression" ==============
# Looks like you planned 37 tests but ran 36.
# Looks like your test exited with 255 just after 36.
t/001_stream_rep.pl ..................
Dubious, test returned 255 (wstat 65280, 0xff00)
Failed 1/37 subtests
...
Test Summary Report
-------------------
t/001_stream_rep.pl (Wstat: 65280 Tests: 36 Failed: 0)
Non-zero exit status: 255
Parse errors: Bad plan. You planned 37 tests but ran 36.
Files=21, Tests=239, 302 wallclock secs ( 0.10 usr 0.05 sys + 41.69
cusr 39.84 csys = 81.68 CPU)
Result: FAIL
make[2]: *** [check] Error 1
make[1]: *** [check-recovery-recurse] Error 2
make[1]: *** Waiting for unfinished jobs....
t/070_dropuser.pl ......... ok

Mmm. I retried that and saw it succeed (with 0002 applied).
If I modified "user Test::More tests => 37" to 38 in the perl file, I
got a similar result.

What happens if you run make check-world with -j 4? When I ran that,
the test failed. But with -j 1, the test finished with success. I'm
not sure
why this happened, though..

Maybe this is it.

+ usleep(100_000);

If the script doesn't find the expected log line, it reaches the
usleep and bark that "Undefined subroutine &main::usleep called...". I
thought I tested that path but perhaps I overlooked the error. "use
Time::HiRes" is needed.

Yes.

The attached is the fixed version.

Thanks for updating the patches!

In the first patch, the test added to 001_stream_rep.pl involves two
copied functions related to server-log investigation from
019_repslot_limit.pl.

So you're planning to define them commonly in TestLib.pm or elsewhere?

+$node_primary_2->init(allows_streaming => 1);
+$node_primary_2->enable_archiving; # needed to make .paritial segment

Isn't it better to use has_archiving flag in init() instead of doing
enable_archiving, like other tests do?

0002 looks good to me.

Regards,

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

#7Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Fujii Masao (#6)
Re: A failure of standby to follow timeline switch

At Mon, 4 Jan 2021 19:00:21 +0900, Fujii Masao <masao.fujii@oss.nttdata.com> wrote in

On 2021/01/04 12:06, Kyotaro Horiguchi wrote:

At Sat, 26 Dec 2020 02:15:06 +0900, Fujii Masao
<masao.fujii@oss.nttdata.com> wrote in

On 2020/12/25 12:03, Kyotaro Horiguchi wrote:

The attached is the fixed version.

Thanks for updating the patches!

In the first patch, the test added to 001_stream_rep.pl involves two
copied functions related to server-log investigation from
019_repslot_limit.pl.

So you're planning to define them commonly in TestLib.pm or elsewhere?

Yeah.. That's correct. Newly added as the first patch.

While making that change, I extended the interface of slurp_file to
allow reading from arbitrary position. I attached this as a separate
patch just for clarifying the changeset.

The existing messages for open() and OSHandleOpen() look somewhat
strange after patching since they are not really "read" errors, but
they're harmless. (It successfully ran also on Windows10)

The first hunk below is a fix for a forgotten line-feed.

 		my $fHandle = createFile($filename, "r", "rwd")
-		  or croak "could not open \"$filename\": $^E";
+		  or croak "could not open \"$filename\": $^E\n";
 		OsFHandleOpen(my $fh = IO::Handle->new(), $fHandle, 'r')
 		  or croak "could not read \"$filename\": $^E\n";
+		seek($fh, $from, 0)
+		  or croak "could not seek \"$filename\" to $from: $^E\n";
+$node_primary_2->init(allows_streaming => 1);
+$node_primary_2->enable_archiving; # needed to make .paritial segment

Isn't it better to use has_archiving flag in init() instead of doing
enable_archiving, like other tests do?

Agreed. Fixed 0002 (formerly 0001).

0002 looks good to me.

Thanks. The attached is the revised patchset.

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

Attachments:

v3-0001-Move-TAP-log-searching-feature-to-common-modules.patchtext/x-patch; charset=us-asciiDownload+51-36
v3-0002-New-test-for-timeline-tracking-of-walsender.patchtext/x-patch; charset=us-asciiDownload+40-2
v3-0003-Fix-timeline-tracking-failure-while-sending-a-his.patchtext/x-patch; charset=us-asciiDownload+1-2
#8Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Kyotaro Horiguchi (#7)
Re: A failure of standby to follow timeline switch

At Tue, 05 Jan 2021 17:26:02 +0900 (JST), Kyotaro Horiguchi <horikyota.ntt@gmail.com> wrote in

Thanks. The attached is the revised patchset.

It is not applicable to PG13 due to wording changes. This is an
applicable all-in-one version to PG13.

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

Attachments:

0001-Fix-timeline-tracking-failure-while-sending-a-PG13.patchtext/x-patch; charset=us-asciiDownload+92-38
#9Fujii Masao
masao.fujii@gmail.com
In reply to: Kyotaro Horiguchi (#7)
Re: A failure of standby to follow timeline switch

On 2021/01/05 17:26, Kyotaro Horiguchi wrote:

At Mon, 4 Jan 2021 19:00:21 +0900, Fujii Masao <masao.fujii@oss.nttdata.com> wrote in

On 2021/01/04 12:06, Kyotaro Horiguchi wrote:

At Sat, 26 Dec 2020 02:15:06 +0900, Fujii Masao
<masao.fujii@oss.nttdata.com> wrote in

On 2020/12/25 12:03, Kyotaro Horiguchi wrote:

The attached is the fixed version.

Thanks for updating the patches!

In the first patch, the test added to 001_stream_rep.pl involves two
copied functions related to server-log investigation from
019_repslot_limit.pl.

So you're planning to define them commonly in TestLib.pm or elsewhere?

Yeah.. That's correct. Newly added as the first patch.

While making that change, I extended the interface of slurp_file to
allow reading from arbitrary position.

Is this extension really helpful for current use case?
At least I'd like to avoid back-patching this since it's an exntesion...

  		OsFHandleOpen(my $fh = IO::Handle->new(), $fHandle, 'r')
  		  or croak "could not read \"$filename\": $^E\n";
+		seek($fh, $from, 0)
+		  or croak "could not seek \"$filename\" to $from: $^E\n";

I'm not familiar with this area, but SetFilePointer() is more suitable
rather than seek()?

Thanks. The attached is the revised patchset.

Thanks!

Regards,

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

#10Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Fujii Masao (#9)
Re: A failure of standby to follow timeline switch

At Thu, 7 Jan 2021 11:55:33 +0900, Fujii Masao <masao.fujii@oss.nttdata.com> wrote in

On 2021/01/05 17:26, Kyotaro Horiguchi wrote:

At Mon, 4 Jan 2021 19:00:21 +0900, Fujii Masao <masao.fujii@oss.nttdata.com>
wrote in

On 2021/01/04 12:06, Kyotaro Horiguchi wrote:

At Sat, 26 Dec 2020 02:15:06 +0900, Fujii Masao
<masao.fujii@oss.nttdata.com> wrote in

On 2020/12/25 12:03, Kyotaro Horiguchi wrote:

The attached is the fixed version.

Thanks for updating the patches!

In the first patch, the test added to 001_stream_rep.pl involves two
copied functions related to server-log investigation from
019_repslot_limit.pl.

So you're planning to define them commonly in TestLib.pm or elsewhere?

Yeah.. That's correct. Newly added as the first patch.
While making that change, I extended the interface of slurp_file to
allow reading from arbitrary position.

Is this extension really helpful for current use case?
At least I'd like to avoid back-patching this since it's an exntesion...

Yeah, I felt a hesitattion about it a bit. It's less useful assuming
that log files won't get so large. Removed in this version.

OsFHandleOpen(my $fh = IO::Handle->new(), $fHandle, 'r')
or croak "could not read \"$filename\": $^E\n";
+		seek($fh, $from, 0)
+		  or croak "could not seek \"$filename\" to $from: $^E\n";

I'm not familiar with this area, but SetFilePointer() is more suitable
rather than seek()?

SetFilePointer() works for a native handle, IO::Handle->new()
here. seek() works on $fh, a perl handle. If ReadFile is used later
SetFilePointer() might be needed separately.

Anyway, it is removed.

--
Kyotaro Horiguchi
NTT Open Source Software Center

Attachments:

v4-0001-Move-TAP-log-searching-feature-to-common-modules.patchtext/x-patch; charset=us-asciiDownload+42-32
v4-0002-New-test-for-timeline-tracking-of-walsender.patchtext/x-patch; charset=us-asciiDownload+40-2
v4-0003-Fix-timeline-tracking-failure-while-sending-a-his.patchtext/x-patch; charset=us-asciiDownload+1-2
0001-Fix-timeline-tracking-failure-while-sending-a-PG13.patch.txttext/plain; charset=us-asciiDownload+83-34
#11Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Kyotaro Horiguchi (#10)
Re: A failure of standby to follow timeline switch

Masao-san: Are you intending to act as committer for these? Since the
bug is mine I can look into it, but since you already did all the
reviewing work, I'm good with you giving it the final push.

0001 looks good to me; let's get that one committed quickly so that we
can focus on the interesting stuff. While the implementation of
find_in_log is quite dumb (not this patch's fault), it seems sufficient
to deal with small log files. We can improve the implementation later,
if needed, but we have to get the API right on the first try.

0003: The fix looks good to me. I verified that the test fails without
the fix, and it passes with the fix.

The test added in 0002 is a bit optimistic regarding timing, as well as
potentially slow; it loops 1000 times and sleeps 100 milliseconds each
time. In a very slow server (valgrind or clobber_cache animals) this
could not be sufficient time, while on fast servers it may end up
waiting longer than needed. Maybe we can do something like this:

for (my $i = 0 ; $i < 1000; $i++)
{
my $current_log_size = determine_current_log_size()

if ($node_standby_3->find_in_log(
"requested WAL segment [0-9A-F]+ has already been removed",
$logstart))
{
last;
}
elsif ($node_standby_3->find_in_log(
"End of WAL reached on timeline",
$logstart))
{
$success = 1;
last;
}
$logstart = $current_log_size;

while (determine_current_log_size() == current_log_size)
{
usleep(10_000);
# with a retry count?
}
}

With test patch, make check PROVE_FLAGS="--timer" PROVE_TESTS=t/001_stream_rep.pl

ok 6386 ms ( 0.00 usr 0.00 sys + 1.14 cusr 0.93 csys = 2.07 CPU)
ok 6352 ms ( 0.00 usr 0.00 sys + 1.10 cusr 0.94 csys = 2.04 CPU)
ok 6255 ms ( 0.01 usr 0.00 sys + 0.99 cusr 0.97 csys = 1.97 CPU)

without test patch:

ok 4954 ms ( 0.00 usr 0.00 sys + 0.71 cusr 0.64 csys = 1.35 CPU)
ok 5033 ms ( 0.01 usr 0.00 sys + 0.71 cusr 0.73 csys = 1.45 CPU)
ok 4991 ms ( 0.01 usr 0.00 sys + 0.73 cusr 0.59 csys = 1.33 CPU)

--
�lvaro Herrera

#12Fujii Masao
masao.fujii@gmail.com
In reply to: Alvaro Herrera (#11)
Re: A failure of standby to follow timeline switch

On Sat, Jan 9, 2021 at 5:08 AM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

Masao-san: Are you intending to act as committer for these? Since the
bug is mine I can look into it, but since you already did all the
reviewing work, I'm good with you giving it the final push.

Thanks! I'm thinking to push the patch.

0001 looks good to me; let's get that one committed quickly so that we
can focus on the interesting stuff. While the implementation of
find_in_log is quite dumb (not this patch's fault), it seems sufficient
to deal with small log files. We can improve the implementation later,
if needed, but we have to get the API right on the first try.

0003: The fix looks good to me. I verified that the test fails without
the fix, and it passes with the fix.

Yes.

The test added in 0002 is a bit optimistic regarding timing, as well as
potentially slow; it loops 1000 times and sleeps 100 milliseconds each
time. In a very slow server (valgrind or clobber_cache animals) this
could not be sufficient time, while on fast servers it may end up
waiting longer than needed. Maybe we can do something like this:

On second thought, I think that the regression test should be in
004_timeline_switch.pl instead of 001_stream_rep.pl because it's
the test about timeline switch. Also I'm thinking that it's better to
test the timeline switch by checking whether some data is successfully
replicatead like the existing regression test for timeline switch in
004_timeline_switch.pl does, instead of finding the specific message
in the log file. I attached the POC patch. Thought?

Regards,

--
Fujii Masao

Attachments:

v5-0001-Move-TAP-log-searching-feature-to-common-modules.patchapplication/octet-stream; name=v5-0001-Move-TAP-log-searching-feature-to-common-modules.patchDownload+40-4
#13Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Fujii Masao (#12)
Re: A failure of standby to follow timeline switch

At Tue, 12 Jan 2021 10:47:21 +0900, Fujii Masao <masao.fujii@gmail.com> wrote in

On Sat, Jan 9, 2021 at 5:08 AM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

Masao-san: Are you intending to act as committer for these? Since the
bug is mine I can look into it, but since you already did all the
reviewing work, I'm good with you giving it the final push.

Thanks! I'm thinking to push the patch.

0001 looks good to me; let's get that one committed quickly so that we
can focus on the interesting stuff. While the implementation of
find_in_log is quite dumb (not this patch's fault), it seems sufficient
to deal with small log files. We can improve the implementation later,
if needed, but we have to get the API right on the first try.

0003: The fix looks good to me. I verified that the test fails without
the fix, and it passes with the fix.

Yes.

The test added in 0002 is a bit optimistic regarding timing, as well as
potentially slow; it loops 1000 times and sleeps 100 milliseconds each
time. In a very slow server (valgrind or clobber_cache animals) this
could not be sufficient time, while on fast servers it may end up
waiting longer than needed. Maybe we can do something like this:

On second thought, I think that the regression test should be in
004_timeline_switch.pl instead of 001_stream_rep.pl because it's

Agreed. It's definitely the right place.

the test about timeline switch. Also I'm thinking that it's better to
test the timeline switch by checking whether some data is successfully
replicatead like the existing regression test for timeline switch in
004_timeline_switch.pl does, instead of finding the specific message
in the log file. I attached the POC patch. Thought?

It's practically a check on this issue, and looks better. The 180s
timeout in the failure case seems a bit annoying but it's the way all
of this kind of test follow.

The last check on table content is actually useless but it might make
sense to confirm that replication is actually working. However, I
don't think the test don't need to insert as many as 1000 tuples. Just
a single tuple would suffice.

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

#14Fujii Masao
masao.fujii@gmail.com
In reply to: Kyotaro Horiguchi (#13)
Re: A failure of standby to follow timeline switch

On Wed, Jan 13, 2021 at 10:48 AM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

At Tue, 12 Jan 2021 10:47:21 +0900, Fujii Masao <masao.fujii@gmail.com> wrote in

On Sat, Jan 9, 2021 at 5:08 AM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

Masao-san: Are you intending to act as committer for these? Since the
bug is mine I can look into it, but since you already did all the
reviewing work, I'm good with you giving it the final push.

Thanks! I'm thinking to push the patch.

0001 looks good to me; let's get that one committed quickly so that we
can focus on the interesting stuff. While the implementation of
find_in_log is quite dumb (not this patch's fault), it seems sufficient
to deal with small log files. We can improve the implementation later,
if needed, but we have to get the API right on the first try.

0003: The fix looks good to me. I verified that the test fails without
the fix, and it passes with the fix.

Yes.

The test added in 0002 is a bit optimistic regarding timing, as well as
potentially slow; it loops 1000 times and sleeps 100 milliseconds each
time. In a very slow server (valgrind or clobber_cache animals) this
could not be sufficient time, while on fast servers it may end up
waiting longer than needed. Maybe we can do something like this:

On second thought, I think that the regression test should be in
004_timeline_switch.pl instead of 001_stream_rep.pl because it's

Agreed. It's definitely the right place.

the test about timeline switch. Also I'm thinking that it's better to
test the timeline switch by checking whether some data is successfully
replicatead like the existing regression test for timeline switch in
004_timeline_switch.pl does, instead of finding the specific message
in the log file. I attached the POC patch. Thought?

It's practically a check on this issue, and looks better. The 180s
timeout in the failure case seems a bit annoying but it's the way all
of this kind of test follow.

Yes.

The last check on table content is actually useless but it might make
sense to confirm that replication is actually working. However, I
don't think the test don't need to insert as many as 1000 tuples. Just
a single tuple would suffice.

Thanks for the review!
I'm ok with this change (i.e., insert only single row).
Attached is the updated version of the patch.

Regards,

--
Fujii Masao

Attachments:

v6_follow_timeline_switch.patchapplication/octet-stream; name=v6_follow_timeline_switch.patchDownload+40-4
#15Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Fujii Masao (#14)
Re: A failure of standby to follow timeline switch

On 2021-Jan-13, Fujii Masao wrote:

Thanks for the review!
I'm ok with this change (i.e., insert only single row).
Attached is the updated version of the patch.

Looks good to me, thanks!

--
�lvaro Herrera 39�49'30"S 73�17'W

#16Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Alvaro Herrera (#15)
Re: A failure of standby to follow timeline switch

At Wed, 13 Jan 2021 16:51:32 -0300, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote in

On 2021-Jan-13, Fujii Masao wrote:

Thanks for the review!
I'm ok with this change (i.e., insert only single row).
Attached is the updated version of the patch.

Looks good to me, thanks!

+1

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

#17Fujii Masao
masao.fujii@gmail.com
In reply to: Kyotaro Horiguchi (#16)
Re: A failure of standby to follow timeline switch

On Thu, Jan 14, 2021 at 10:10 AM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

At Wed, 13 Jan 2021 16:51:32 -0300, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote in

On 2021-Jan-13, Fujii Masao wrote:

Thanks for the review!
I'm ok with this change (i.e., insert only single row).
Attached is the updated version of the patch.

Looks good to me, thanks!

+1

Thanks Alvaro and Horiguchi for the review! I pushed the patch.

Regards,

--
Fujii Masao

#18Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Fujii Masao (#17)
Re: A failure of standby to follow timeline switch

At Thu, 14 Jan 2021 12:34:01 +0900, Fujii Masao <masao.fujii@gmail.com> wrote in

On Thu, Jan 14, 2021 at 10:10 AM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

At Wed, 13 Jan 2021 16:51:32 -0300, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote in

On 2021-Jan-13, Fujii Masao wrote:

Thanks for the review!
I'm ok with this change (i.e., insert only single row).
Attached is the updated version of the patch.

Looks good to me, thanks!

+1

Thanks Alvaro and Horiguchi for the review! I pushed the patch.

Thanks for commiting this fix!

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center