Re: Found issues related with logical replication and 2PC

On Wed, Jul 24, 2024 at 12:25 PM Hayato Kuroda (Fujitsu)
<kuroda.hayato@fujitsu.com> wrote:
>
> Hi hackers,
>
> While creating a patch which allows ALTER SUBSCRIPTION SET (two_phase) [1],
> we found some issues related with logical replication and two_phase. I think this
> can happen not only HEAD but PG14+, but for now I shared patches for HEAD.
>
> Issue #1
>
> When handling a PREPARE message, the subscriber mistook the wrong lsn position
> (the end position of the last commit) as the end position of the current prepare.
> This can be fixed by adding a new global variable to record the end position of
> the last prepare. 0001 patch fixes the issue.

Thanks for the patches. I have started reviewing this. I reviewed and
tested patch001 alone.

I have a query, shouldn't the local-lsn stored in
apply_handle_commit_prepared() be the end position of
'COMMIT_PREPARED' instead of 'PREPARE'? I put additional logging on
sub and got this:

LOG:  apply_handle_prepare - prepare_data.end_lsn:  0/15892E0 ,
XactLastPrepareEnd: 0/1537FD8.
LOG:  apply_handle_commit_prepared - prepare_data.end_lsn:  0/1589318
, XactLastPrepareEnd: 0/1537FD8.

In apply_handle_prepare(), remote-lsn ('0/15892E0') is end position of
'PREPARE' and in apply_handle_commit_prepared(), remote-lsn
('0/1589318') is end position of 'COMMIT_PREPARED', while local-lsn in
both cases is end-lsn of 'PREPARE'. Details at [1].

Shouldn't we use 'XactLastCommitEnd' in apply_handle_commit_prepared()
which is the end position of last COMMIT_PREPARED? It is assigned in
the below flow:
apply_handle_commit_prepared-->CommitTransactionCommand...->RecordTransactionCommit?

Please let me know if I have misunderstood.

[1]:

Pub:
------
SELECT * FROM pg_get_wal_record_info('0/15892E0');
start_lsn |  end_lsn  | prev_lsn  |   record_type
---------+-----------+-----------+-----------------
0/15892E0 | 0/1589318 | 0/15891E8 | COMMIT_PREPARED

--see prev_lsn
SELECT * FROM pg_get_wal_record_info('0/15891E8');
start_lsn |  end_lsn  | prev_lsn  | record_type
---------+-----------+-----------+-------------
0/15891E8 | 0/15892E0 | 0/15891A8 | PREPARE

SELECT * FROM pg_get_wal_record_info('0/1589318');
start_lsn |  end_lsn  | prev_lsn  |  record_type
---------+-----------+-----------+---------------
0/1589318 | 0/1589350 | 0/15892E0 | RUNNING_XACTS

--see prev_lsn
SELECT * FROM pg_get_wal_record_info('0/15892E0');
start_lsn |  end_lsn  | prev_lsn  |   record_type
---------+-----------+-----------+-----------------
0/15892E0 | 0/1589318 | 0/15891E8 | COMMIT_PREPARED


Sub:
------
SELECT * FROM pg_get_wal_record_info('0/1537FD8');
start_lsn |  end_lsn  | prev_lsn  |    record_type
---------+-----------+-----------+------------------
0/1537FD8 | 0/1538030 | 0/1537ED0 |  COMMIT_PREPARED

--see prev_lsn:
SELECT * FROM pg_get_wal_record_info('0/1537ED0');
start_lsn |  end_lsn  | prev_lsn  |record_type
---------+-----------+-----------+------------
0/1537ED0 | 0/1537FD8 | 0/1537E90 |PREPARE

thanks
Shveta