TEST SCENARIO Purpose: To observe that the patch can process cleanups caused by the tablesync kills during AlterSubscription_refresh Note: The "!!>>" is extra logging added for testing, not a normal part of PG. Steps: 1. CREATE PUBLICATION for some table T1 2. CREATE SUBSCRIPTION for that publication 3. Pause the tablesync worker in CATCHUP state (so there would be a tablesync slot in need of cleanup) 4. Show the slots 5. ALTER PUBLICATION to DROP the table from it 6. ALTER SUBSCRIPTION REFRESH PUBLICATION // this will signal the tablesync to be stopped 7. Allow the tablesync work to proceed. // See if it gets into the interrupt cleanup function and drops the tablsync slots/origin as expected 8. Show the slots 9. DROP SUBSCRIPTION // this will kill the apply worker and remove the apply slot 10. Show the slots ================== ## ## No slots/origin to start with ## [postgres@CentOS7-x64 ~]$ psql -d test_sub -p 54321 -c "select * from pg_replication_origin;" roident | roname ---------+-------- (0 rows) [postgres@CentOS7-x64 ~]$ psql -d test_pub -c "select * from pg_replication_slots;" slot_name | plugin | slot_type | datoid | database | temporary | active | active_pid | xmin | catalog_xmin | restart_lsn | conf irmed_flush_lsn | wal_status | safe_wal_size -----------+--------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+----- ----------------+------------+--------------- (0 rows) ## ## Normal PUBLICATION of a table ## [postgres@CentOS7-x64 ~]$ psql -d test_pub -c "CREATE PUBLICATION tap_pub FOR TABLE test_tab;" CREATE PUBLICATION ## ## Create subscription, and pause the tablsync process when gets to CATCHUP state ## [postgres@CentOS7-x64 ~]$ psql -d test_sub -p 54321 -c "CREATE SUBSCRIPTION tap_sub CONNECTION 'host=localhost dbname=test_pub application_name=tap_sub' PUBLICATION tap_pub;" 2021-01-18 19:16:48.045 AEDT [8618] LOG: logical decoding found consistent point at 0/1618EF0 2021-01-18 19:16:48.045 AEDT [8618] DETAIL: There are no running transactions. 2021-01-18 19:16:48.045 AEDT [8618] STATEMENT: CREATE_REPLICATION_SLOT "tap_sub" LOGICAL pgoutput NOEXPORT_SNAPSHOT NOTICE: created replication slot "tap_sub" on publisher CREATE SUBSCRIPTION 2021-01-18 19:16:48.059 AEDT [8619] LOG: logical replication apply worker for subscription "tap_sub" has started 2021-01-18 19:16:48.059 AEDT [8619] LOG: !!>> The apply worker process has PID = 8619 [postgres@CentOS7-x64 ~]$ 2021-01-18 19:16:48.068 AEDT [8624] LOG: starting logical decoding for slot "tap_sub" 2021-01-18 19:16:48.068 AEDT [8624] DETAIL: Streaming transactions committing after 0/1618F28, reading WAL from 0/1618EF0. 2021-01-18 19:16:48.068 AEDT [8624] STATEMENT: START_REPLICATION SLOT "tap_sub" LOGICAL 0/0 (proto_version '2', publication_names '"tap_pub"') 2021-01-18 19:16:48.068 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:48.068 AEDT [8624] LOG: logical decoding found consistent point at 0/1618EF0 2021-01-18 19:16:48.068 AEDT [8624] DETAIL: There are no running transactions. 2021-01-18 19:16:48.068 AEDT [8624] STATEMENT: START_REPLICATION SLOT "tap_sub" LOGICAL 0/0 (proto_version '2', publication_names '"tap_pub"') 2021-01-18 19:16:48.068 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:48.073 AEDT [8627] LOG: logical replication table synchronization worker for subscription "tap_sub", table "test_tab" has started 2021-01-18 19:16:48.073 AEDT [8627] LOG: !!>> The tablesync worker process has PID = 8627 2021-01-18 19:16:48.073 AEDT [8627] LOG: !!>> Sleeping 30 secs. For debugging, attach to process 8627 now! 2021-01-18 19:16:48.082 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:48.083 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:49.090 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:49.090 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:50.092 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:50.092 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:51.094 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:51.095 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:52.097 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:52.098 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:53.099 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:53.099 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:54.104 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:54.104 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:55.106 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:55.106 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:56.110 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:56.111 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:57.113 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:57.113 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:58.116 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:58.116 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:16:59.122 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:16:59.122 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:00.124 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:00.124 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:01.126 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:01.126 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:02.128 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:02.128 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:03.132 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:03.132 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:04.132 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:04.133 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:05.136 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:05.136 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:06.139 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:06.139 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:07.141 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:07.141 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:08.142 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:08.142 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:09.148 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:09.149 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:10.150 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:10.150 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:11.151 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:11.151 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:12.156 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:12.156 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:13.157 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:13.157 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:14.159 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:14.159 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:15.162 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:15.162 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:16.164 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:16.164 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:17.165 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:17.165 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:18.087 AEDT [8627] LOG: !!>> tablesync worker: About to call LogicalRepSyncTableStart to do initial syncing 2021-01-18 19:17:18.168 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:18.168 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:18.168 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:18.168 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:19.169 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:19.169 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:20.172 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:20.172 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:21.172 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:21.172 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:22.174 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:22.174 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:23.176 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:23.176 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:23.233 AEDT [8627] LOG: !!>> LogicalRepSyncTableStart: walrcv_create_slot for "pg_16399_sync_16385". 2021-01-18 19:17:23.254 AEDT [9687] LOG: logical decoding found consistent point at 0/1618F28 2021-01-18 19:17:23.254 AEDT [9687] DETAIL: There are no running transactions. 2021-01-18 19:17:23.254 AEDT [9687] STATEMENT: CREATE_REPLICATION_SLOT "pg_16399_sync_16385" LOGICAL pgoutput USE_SNAPSHOT 2021-01-18 19:17:23.262 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:23.262 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:17:23.273 AEDT [8627] LOG: !!>> LogicalRepSyncTableStart: 1 replorigin_create "pg_16399_16385". 2021-01-18 19:17:23.273 AEDT [8627] LOG: !!>> LogicalRepSyncTableStart: 1 replorigin_advance "pg_16399_16385". 2021-01-18 19:17:23.273 AEDT [8627] LOG: !!>> LogicalRepSyncTableStart: 1 replorigin_session_setup "pg_16399_16385". 2021-01-18 19:17:23.273 AEDT [8627] LOG: LogicalRepSyncTableStart: 'pg_16399_16385' origin_startpos lsn 0/1618F60 2021-01-18 19:17:23.273 AEDT [8627] LOG: !!>> tablesync worker: wait for CATCHUP state notification 2021-01-18 19:17:23.273 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:17:23.273 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables ## ## Show the slots ## psql -d test_pub -c "select * from pg_replication_slots;" slot_name | plugin | slot_type | datoid | database | temporary | active | active_pid | xmin | catalog_xmin | restar t_lsn | confirmed_flush_lsn | wal_status | safe_wal_size ---------------------+----------+-----------+--------+----------+-----------+--------+------------+------+--------------+------- ------+---------------------+------------+--------------- tap_sub | pgoutput | logical | 16384 | test_pub | f | t | 8624 | | 513 | 0/1618 F28 | 0/1618F60 | reserved | pg_16399_sync_16385 | pgoutput | logical | 16384 | test_pub | f | f | | | 513 | 0/1618 F28 | 0/1618F60 | reserved | (2 rows) ## ## ALTER PUBLICATION (drop the table) ## [postgres@CentOS7-x64 ~]$ psql -d test_pub -c "ALTER PUBLICATION tap_pub DROP TABLE test_tab;" ALTER PUBLICATION 2021-01-18 19:19:15.236 AEDT [8624] LOG: !!>> pgoutput_begin_txn 2021-01-18 19:19:15.236 AEDT [8624] CONTEXT: slot "tap_sub", output plugin "pgoutput", in the begin callback, associated LSN 0/1619048 2021-01-18 19:19:15.236 AEDT [8624] STATEMENT: START_REPLICATION SLOT "tap_sub" LOGICAL 0/0 (proto_version '2', publication_names '"tap_pub"') 2021-01-18 19:19:15.237 AEDT [8624] LOG: !!>> pgoutput_commit_txn 2021-01-18 19:19:15.237 AEDT [8624] CONTEXT: slot "tap_sub", output plugin "pgoutput", in the commit callback, associated LSN 0/161A730 2021-01-18 19:19:15.237 AEDT [8624] STATEMENT: START_REPLICATION SLOT "tap_sub" LOGICAL 0/0 (proto_version '2', publication_names '"tap_pub"') [postgres@CentOS7-x64 ~]$ ## ## ALTER SUBSCRIPTION while tablesync is still paused ## [postgres@CentOS7-x64 ~]$ psql -d test_sub -p 54321 -c "ALTER SUBSCRIPTION tap_sub REFRESH PUBLICATION;" ## ## Continue... from the paused tablesync worker ## ## PID 2077 was the tablesync worker ## PID 2069 was the Apply worker ## 2021-01-18 19:23:28.653 AEDT [8627] LOG: !!>> tablesync worker: received CATCHUP state notification 2021-01-18 19:23:28.653 AEDT [8627] LOG: !!>> ProcessInterrupts: Hello, I am a LogicalWorker 2021-01-18 19:23:54.525 AEDT [8627] LOG: !!>> tablesync_cleanup_at_interrupt for relid = 16385 (gdb) p *MyLogicalRepWorker $6 = {launch_time = 664273008068979, in_use = true, generation = 2, proc = 0x7ff2080714e8, dbid = 16384, userid = 10, subid = 16399, relid = 16385, relstate = 99 'c', relstate_lsn = 23170912, relmutex = 0 '\000', last_lsn = 0, last_send_time = 664273008070041, last_recv_time = 664273008070041, reply_lsn = 0, reply_time = 664273008070041} (gdb) p drop_slot_needed $7 = true (gdb) 2021-01-18 19:25:10.554 AEDT [8627] LOG: !!>> tablesync_cleanup_at_interrupt: dropping the tablesync slot "pg_16399_sync_16385". 2021-01-18 19:25:12.370 AEDT [8627] LOG: !!>> tablesync_cleanup_at_interrupt: dropped the tablesync slot "pg_16399_sync_16385". 2021-01-18 19:25:16.337 AEDT [8627] LOG: !!>> tablesync_cleanup_at_interrupt: dropping origin tracking for "pg_16399_16385" 2021-01-18 19:25:18.747 AEDT [8627] LOG: !!>> tablesync_cleanup_at_interrupt: dropped origin tracking for "pg_16399_16385" 2021-01-18 19:25:25.645 AEDT [8627] LOG: logical replication table synchronization worker for subscription "tap_sub", table "test_tab" has finished ## ## The Apply worker continues... ## 2021-01-18 19:25:25.646 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:25.646 AEDT [8619] LOG: !!>> apply worker: apply_dispatch for message kind 'B' 2021-01-18 19:25:25.646 AEDT [8619] LOG: !!>> apply worker: apply_dispatch for message kind 'C' 2021-01-18 19:25:25.646 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:25.647 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables ALTER SUBSCRIPTION [postgres@CentOS7-x64 ~]$ 2021-01-18 19:25:26.648 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:26.648 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:27.649 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:27.649 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:28.650 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:28.650 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:29.651 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:29.651 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:30.652 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:30.652 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:31.652 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:31.653 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:32.654 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:32.654 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:33.655 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:33.655 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:34.656 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:34.656 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:35.658 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:35.658 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:36.659 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:36.659 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:37.660 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:37.660 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:38.661 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:38.661 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:39.661 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:39.661 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:40.663 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:40.663 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:41.664 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:41.664 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:42.664 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:42.664 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:43.665 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:43.665 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:44.667 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:44.667 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:45.668 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:45.668 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:46.668 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:46.668 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables ## ## Check the tablesyn slot was cleaned up (the logs above says it was) ## psql -d test_pub -c "select * from pg_replication_slots;" slot_name | plugin | slot_type | datoid | database | temporary | active | active_pid | xmin | catalog_xmin | restart_lsn | co nfirmed_flush_lsn | wal_status | safe_wal_size -----------+----------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+--- ------------------+------------+--------------- tap_sub | pgoutput | logical | 16384 | test_pub | f | t | 8624 | | 514 | 0/1619010 | 0/ 161A8C8 | reserved | (1 row) ## ## Apply worker continues... ## 2021-01-18 19:25:48.671 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:49.672 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:49.672 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:50.674 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:50.674 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:51.674 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:51.674 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:52.676 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:52.676 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:53.677 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:53.677 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:54.678 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:54.678 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:55.679 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:55.679 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:55.679 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:55.679 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:56.679 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:56.680 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:57.680 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:57.681 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:58.682 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:58.682 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:25:59.684 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:25:59.684 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:26:00.685 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:26:00.685 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:26:01.686 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:26:01.686 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:26:02.687 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:26:02.687 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:26:03.688 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:26:03.688 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:26:04.689 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:26:04.690 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:26:05.691 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:26:05.691 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:26:06.692 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:26:06.692 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables ## ## Drop subscription. This terminates the apply worker ## psql -d test_sub -p 54321 -c "DROP SUBSCRIPTION tap_sub;"2021-01-18 19:26:07.693 AEDT [8619] LOG: !!>> apply worker: LogicalRepApplyLoop 2021-01-18 19:26:07.693 AEDT [8619] LOG: !!>> apply worker: called process_syncing_tables 2021-01-18 19:26:07.890 AEDT [8619] LOG: !!>> ProcessInterrupts: Hello, I am a LogicalWorker 2021-01-18 19:26:07.890 AEDT [8619] FATAL: terminating logical replication worker due to administrator command 2021-01-18 19:26:07.891 AEDT [30060] LOG: background worker "logical replication worker" (PID 8619) exited with exit code 1 NOTICE: dropped replication slot "tap_sub" on publisher DROP SUBSCRIPTION ## ## Show now there are no slots. ## [postgres@CentOS7-x64 ~]$ psql -d test_pub -c "select * from pg_replication_slots;" slot_name | plugin | slot_type | datoid | database | temporary | active | active_pid | xmin | catalog_xmin | restart_lsn | conf irmed_flush_lsn | wal_status | safe_wal_size -----------+--------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+----- ----------------+------------+--------------- (0 rows) [postgres@CentOS7-x64 ~]$ psql -d test_sub -p 54321 -c "select * from pg_replication_origin;" roident | roname ---------+-------- (0 rows) [END]