Re: Track replica origin progress for Rollback Prepared

On Wed, Jan 6, 2021 at 11:56 PM Amit Kapila <amit(dot)kapila16(at)gmail(dot)com> wrote:

> Now, let us see how the tests mentioned by me cover this code. In the
> first test (check that 2PC gets replicated to subscriber then ROLLBACK
> PREPARED), we do below on publisher and wait for it to be applied on
> the subscriber.
> BEGIN;
> INSERT INTO tab_full VALUES (12);
> PREPARE TRANSACTION 'test_prepared_tab_full';
> ROLLBACK PREPARED 'test_prepared_tab_full';

Added some prints in this patch, just to verify that the code is hit
and applied this patch along with the other patches
of two-phase commit shared in [1].

Below are the added logs.
+++ b/src/backend/access/transam/twophase.c
@@ -1133,9 +1133,9 @@ EndPrepare(GlobalTransaction gxact)
gxact->prepare_start_lsn = ProcLastRecPtr;

/*
- * Mark the prepared transaction as valid. As soon as xact.c marks
- * MyProc as not running our XID (which it will do immediately after
- * this function returns), others can commit/rollback the xact.
+ * Mark the prepared transaction as valid. As soon as xact.c
marks MyProc
+ * as not running our XID (which it will do immediately after this
+ * function returns), others can commit/rollback the xact.
*
* NB: a side effect of this is to make a dummy ProcArray entry for the
* prepared XID. This must happen before we clear the XID from MyProc /
@@ -2277,6 +2277,16 @@ RecordTransactionAbortPrepared(TransactionId xid,
const char *gid)
{
XLogRecPtr recptr;
+ bool replorigin;
+
+ /*
+ * Are we using the replication origins feature? Or, in other
words, are
+ * we replaying remote actions?
+ */
+ replorigin = (replorigin_session_origin != InvalidRepOriginId &&
+ replorigin_session_origin !=
DoNotReplicateId);
+
+ elog(LOG,"change replorigin after a rollback prepared");

@@ -2299,6 +2309,14 @@ RecordTransactionAbortPrepared(TransactionId xid,

MyXactFlags | XACT_FLAGS_ACQUIREDACCE
xid, gid);

+ if (replorigin)
+ {
+ /* Move LSNs forward for this replication origin */
+ replorigin_session_advance(replorigin_session_origin_lsn,
+
XactLastRecEnd);
+ elog(LOG,"advance replorigin for abort prepared");
+ }
+

+++ b/src/backend/access/transam/xact.c
@@ -5720,13 +5720,13 @@ XactLogAbortRecord(TimestampTz abort_time,

/* dump transaction origin information only for abort prepared */
if ((replorigin_session_origin != InvalidRepOriginId) &&
- TransactionIdIsValid(twophase_xid) &&
- XLogLogicalInfoActive())
+ TransactionIdIsValid(twophase_xid))
{
xl_xinfo.xinfo |= XACT_XINFO_HAS_ORIGIN;

xl_origin.origin_lsn = replorigin_session_origin_lsn;
xl_origin.origin_timestamp =
replorigin_session_origin_timestamp;
+ elog(LOG,"transaction origin information for abort prepared");
}

And created a pub/sub for table tab:
server1:
postgres=# create table tab(i int);
CREATE TABLE
postgres=# CREATE PUBLICATION tap_pub FOR all tables;
CREATE PUBLICATION

server2:
postgres=# create table tab(i int);
CREATE TABLE
postgres=# CREATE SUBSCRIPTION tap_sub CONNECTION 'host=localhost
dbname=postgres' PUBLICATION tap_pub with(two_phase=on);
NOTICE: created replication slot "tap_sub" on publisher
CREATE SUBSCRIPTION

server1:
postgres=# begin;
BEGIN
postgres=*# insert into tab values (3);
INSERT 0 1
postgres=*# prepare transaction 'test1';
PREPARE TRANSACTION
postgres=# rollback prepared 'test1';
ROLLBACK PREPARED

And confirmed in logs on server2:
2021-01-12 04:01:01.292 EST [19896] LOG: logical replication apply
worker for subscription "tap_sub" has started
2021-01-12 04:01:01.302 EST [19898] LOG: logical replication table
synchronization worker for subscription "tap_sub", table "tab" has
started
2021-01-12 04:01:01.343 EST [19898] LOG: logical replication table
synchronization worker for subscription "tap_sub", table "tab" has
finished
2021-01-12 04:01:49.240 EST [19896] LOG: change replorigin after a
rollback prepared
2021-01-12 04:01:49.240 EST [19896] LOG: transaction origin
information for abort prepared
2021-01-12 04:01:49.240 EST [19896] LOG: advance replorigin for abort prepared

And logs on server1:
2021-01-12 04:01:01.343 EST [19899] STATEMENT: START_REPLICATION SLOT
"tap_sub_16389_sync_16384" LOGICAL 0/16054E0 (proto_version '2',
publication_names '"tap_pub"')
2021-01-12 04:01:49.235 EST [4195] LOG: change replorigin after a
rollback prepared

Also restarted server2 and confirmed that the rollback prepared was
not re-sent again.

regards,
Ajin Cherian
Fujitsu Australia
[1] - https://www.postgresql.org/message-id/CAA4eK1J7TiOQSiDq9MS_4k7zr4Jca7SnO8Vy3L4wtc7t1X9zsQ%40mail.gmail.com