Re: Logical replication keepalive flood

On Thu, Sep 30, 2021 at 3:41 PM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:
>
> At Thu, 30 Sep 2021 17:08:35 +0900 (JST), Kyotaro Horiguchi <horikyota.ntt@gmail.com> wrote in
> > At Thu, 30 Sep 2021 17:21:03 +1000, Greg Nancarrow <gregn4422@gmail.com> wrote in
> > > Actually, with the patch applied, I find that "make check-world" fails
> > > (006_logical_decoding, test 7).
> >
> > Mmm..
> >
> > t/006_logical_decoding.pl .. 4/14
> > #   Failed test 'pg_recvlogical acknowledged changes'
> > #   at t/006_logical_decoding.pl line 117.
> > #          got: 'BEGIN
> > # table public.decoding_test: INSERT: x[integer]:5 y[text]:'5''
> > #     expected: ''
> >
> > I'm not sure what the test is checking for now, though.
>
> It's checking that endpos works correctly? The logical decoded WALs
> looks like this.
>
> 0/1528F10|table public.decoding_test: INSERT: x[integer]:1 y[text]:'1'
> 0/15290F8|table public.decoding_test: INSERT: x[integer]:2 y[text]:'2'
> 0/1529138|table public.decoding_test: INSERT: x[integer]:3 y[text]:'3'
> 0/1529178|table public.decoding_test: INSERT: x[integer]:4 y[text]:'4'
> 0/15291E8|COMMIT 709
> 0/15291E8|BEGIN 710
> 0/15291E8|table public.decoding_test: INSERT: x[integer]:5 y[text]:'5'
> 0/1529228|table public.decoding_test: INSERT: x[integer]:6 y[text]:'6'
>
> The COMMIT and BEGIN shares the same LSN, which I don't understand how come.
>

This is because endlsn is always commit record + 1 which makes it
equal to start of next record and we use endlsn here for commit. See
below comments in code.
/*
* LSN pointing to the end of the commit record + 1.
*/
XLogRecPtr end_lsn;

> The previous read by pg_recvlocal prceeded upto the COMMIT record. and
> the following command runs after that behaves differently.
>
> pg_recvlogical -S test_slot --dbname postgres --endpos '0/15291E8' -f - --no-loop --start
>
> Before the patch it ends before reading a record, and after the patch
> it reads into the "table ..." line.  pg_recvlogical seems using the
> endpos as the beginning of the last record. In that meaning the three
> lines (COMMIT 709/BEGIN 710/table ...'5') are falls under the end of
> data.
>
> The difference seems coming from the timing keepalive
> comes. pg_recvlogical checks the endpos only when keepalive comes.  In
> other words, it needs keepalive for every data line so that it stops
> exactly at the specified endpos.
>
> 1. Is it the correct behavior that the three data lines share the same
>   LSN?  I think BEGIN and the next line should do, but COMMIT and next
>   BEGIN shouldn't.
>
> 2. Is it the designed behavior that pg_recvlogical does check endpos
>   only when a keepalive comes? If it is the correct behavior, we
>   shouldn't avoid the keepalive flood.
>

If anything, I think this is a testcase issue as explained by me in email [1]

[1] - https://www.postgresql.org/message-id/CAA4eK1Ja2XmK59Czv1V%2BtfOgU4mcFfDwTtTgO02Wd%3DrO02JbiQ%40mail.gmail.com

-- 
With Regards,
Amit Kapila.