Horton

Thread

Commits

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

  1. A failure of standby to follow timeline switch

    Kyotaro Horiguchi <horikyota.ntt@gmail.com> — 2020-12-09T08:43:14Z

    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

  2. Re: A failure of standby to follow timeline switch

    Fujii Masao <masao.fujii@oss.nttdata.com> — 2020-12-24T06:33:04Z

    
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

  3. Re: A failure of standby to follow timeline switch

    Kyotaro Horiguchi <horikyota.ntt@gmail.com> — 2020-12-25T03:03:57Z

    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

  4. Re: A failure of standby to follow timeline switch

    Fujii Masao <masao.fujii@oss.nttdata.com> — 2020-12-25T17:15:06Z

    
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

  5. Re: A failure of standby to follow timeline switch

    Kyotaro Horiguchi <horikyota.ntt@gmail.com> — 2021-01-04T03:06:10Z

    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

  6. Re: A failure of standby to follow timeline switch

    Fujii Masao <masao.fujii@oss.nttdata.com> — 2021-01-04T10:00:21Z

    
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

  7. Re: A failure of standby to follow timeline switch

    Kyotaro Horiguchi <horikyota.ntt@gmail.com> — 2021-01-05T08:26:02Z

    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

  8. Re: A failure of standby to follow timeline switch

    Kyotaro Horiguchi <horikyota.ntt@gmail.com> — 2021-01-06T01:48:04Z

    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

  9. Re: A failure of standby to follow timeline switch

    Fujii Masao <masao.fujii@oss.nttdata.com> — 2021-01-07T02:55:33Z

    
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

  10. Re: A failure of standby to follow timeline switch

    Kyotaro Horiguchi <horikyota.ntt@gmail.com> — 2021-01-07T07:32:36Z

    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

  11. Re: A failure of standby to follow timeline switch

    Alvaro Herrera <alvherre@alvh.no-ip.org> — 2021-01-08T20:08:43Z

    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

  12. Re: A failure of standby to follow timeline switch

    Fujii Masao <masao.fujii@gmail.com> — 2021-01-12T01:47:21Z

    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

  13. Re: A failure of standby to follow timeline switch

    Kyotaro Horiguchi <horikyota.ntt@gmail.com> — 2021-01-13T01:48:52Z

    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

  14. Re: A failure of standby to follow timeline switch

    Fujii Masao <masao.fujii@gmail.com> — 2021-01-13T03:08:30Z

    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

  15. Re: A failure of standby to follow timeline switch

    Alvaro Herrera <alvherre@alvh.no-ip.org> — 2021-01-13T19:51:32Z

    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

  16. Re: A failure of standby to follow timeline switch

    Kyotaro Horiguchi <horikyota.ntt@gmail.com> — 2021-01-14T01:10:22Z

    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

  17. Re: A failure of standby to follow timeline switch

    Fujii Masao <masao.fujii@gmail.com> — 2021-01-14T03:34:01Z

    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

  18. Re: A failure of standby to follow timeline switch

    Kyotaro Horiguchi <horikyota.ntt@gmail.com> — 2021-01-14T04:32:29Z

    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