## After the tablesync-early-exit patch is applied. ## Testing original PREPARED insert case (which was previously error prone) 2020-12-08 15:01:56.695 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables 2020-12-08 15:01:57.697 AEDT [4924] LOG: !!>> apply worker: LogicalRepApplyLoop 2020-12-08 15:01:57.697 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables 2020-12-08 15:01:58.699 AEDT [4924] LOG: !!>> apply worker: LogicalRepApplyLoop 2020-12-08 15:01:58.699 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables 2020-12-08 15:01:59.699 AEDT [4924] LOG: !!>> apply worker: LogicalRepApplyLoop 2020-12-08 15:01:59.699 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables 2020-12-08 15:02:00.699 AEDT [4924] LOG: !!>> apply worker: LogicalRepApplyLoop 2020-12-08 15:02:00.699 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables 2020-12-08 15:02:01.705 AEDT [4924] LOG: !!>> apply worker: LogicalRepApplyLoop 2020-12-08 15:02:01.705 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables 2020-12-08 15:02:02.637 AEDT [6134] LOG: logical decoding found consistent point at 0/1647FD0 2020-12-08 15:02:02.637 AEDT [6134] DETAIL: There are no running transactions. 2020-12-08 15:02:02.637 AEDT [6134] STATEMENT: CREATE_REPLICATION_SLOT "tap_sub_16458_sync_16385" TEMPORARY LOGICAL pgoutput USE_SNAPSHOT 2020-12-08 15:02:02.648 AEDT [4924] LOG: !!>> apply worker: LogicalRepApplyLoop 2020-12-08 15:02:02.648 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables 2020-12-08 15:02:02.649 AEDT [4931] LOG: !!>> tablesync worker: wait for CATCHUP state notification 2020-12-08 15:02:02.649 AEDT [4924] LOG: !!>> apply worker: LogicalRepApplyLoop 2020-12-08 15:02:02.649 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables ## In debugger during the tablesync CATCHUP mode send this: psql -d test_pub -c "BEGIN;INSERT INTO test_tab VALUES(1, 'foo');PREPARE TRANSACTION 'test_prepared_tab';" psql -d test_pub -c "COMMIT PREPARED 'test_prepared_tab';" ## Continue the tablesync to see what happens ## tablesync determines upfront there is nothing to do and it exits 2020-12-08 15:04:23.911 AEDT [4931] LOG: !!>> tablesync worker: called process_syncing_tables 2020-12-08 15:05:30.681 AEDT [4931] LOG: logical replication table synchronization worker for subscription "tap_sub", table "test_tab" has finished ## Apply worker then handles the PREPARE and also the COMMIT PREPARED 2020-12-08 15:05:30.682 AEDT [4924] LOG: !!>> apply worker: LogicalRepApplyLoop 2020-12-08 15:05:30.682 AEDT [4924] LOG: !!>> apply worker: apply_dispatch for message kind 'B' 2020-12-08 15:05:30.682 AEDT [4924] LOG: !!>> apply worker: apply_dispatch for message kind 'R' 2020-12-08 15:05:30.682 AEDT [4924] LOG: !!>> apply worker: apply_dispatch for message kind 'I' 2020-12-08 15:05:30.684 AEDT [4924] LOG: !!>> apply worker: should_apply_changes_for_rel: true rel->state == READY: false rel->state == SYNCDONE: true rel->statelsn <= remote_final_lsn: true 2020-12-08 15:05:30.684 AEDT [4924] LOG: !!>> apply worker: apply_dispatch for message kind 'P' 2020-12-08 15:05:30.686 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables 2020-12-08 15:05:30.686 AEDT [4924] LOG: !!>> apply worker: apply_dispatch for message kind 'P' 2020-12-08 15:05:30.688 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables 2020-12-08 15:05:30.688 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables 2020-12-08 15:05:31.690 AEDT [4924] LOG: !!>> apply worker: LogicalRepApplyLoop 2020-12-08 15:05:31.690 AEDT [4924] LOG: !!>> apply worker: called process_syncing_tables ... ## Pub/Sub records are in sync [postgres@CentOS7-x64 ~]$ psql -d test_pub -c "SELECT count(*) FROM test_tab;" count ------- 1 (1 row) [postgres@CentOS7-x64 ~]$ psql -d test_sub -p 54321 -c "SELECT count(*) FROM test_tab;" count ------- 1 (1 row)