Subject: Re: Found issues related with logical replication and 2PC

From: shveta malik <[email-masked]>
Date: Wed, 7 Aug 2024 12:37:41 +0530

On Wed, Jul 24, 2024 at 12:25 PM Hayato Kuroda (Fujitsu)
<[email-masked]> 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

---

From: Amit Kapila <[email-masked]>
Date: Wed, 7 Aug 2024 15:32:08 +0530

> Thanks for the patches. I have started reviewing this. I reviewed and

It makes sense. As both are different bugs we should discuss them separately.

> apply_handle_commit_prepared-->CommitTransactionCommand...->RecordTransactionCommit?

I also think so. Additionally, I feel a test case (or some description
of the bug that can arise) should be provided for issue-1.

-- 
With Regards,
Amit Kapila.