On Wed, Feb 3, 2021 at 12:26 AM Amit Kapila <amit.kapil...@gmail.com> wrote:
>
> On Tue, Feb 2, 2021 at 3:31 PM Peter Smith <smithpb2...@gmail.com> wrote:
> >
> > After seeing Ajin's test [ac0202] which did a DROP TABLE, I have also
> > tried a simple test where I do a DROP TABLE with very bad timing for
> > the tablesync worker. It seems that doing this can cause the sync
> > worker's MyLogicalRepWorker->relid to become invalid.
> >
>
> I think this should be fixed by latest patch because I have disallowed
> drop of a table when its synchronization is in progress. You can check
> once and let me know if the issue still exists?
>
FYI - I confirmed that the problem scenario that I reported yesterday
is no longer possible because now the V25 patch is disallowing the
DROP TABLE while the tablesync is still running.
PSA my test logs showing it is now working as expected.
----
Kind Regards,
Peter Smith.
Fujitsu Australia
Test Scenario
1. INSERT data so tablesync should copy something
2. While paused in LogicalRepSyncTableStart do a DROP TABLE to rip the rug out
from under the sync worker!
3. Continue the sync worker.... see what happens
==============
##
## Insert data
##
[postgres@CentOS7-x64 ~]$ psql -d test_pub -c "INSERT INTO test_tab VALUES(1,
'foo');"
INSERT 0 1
##
## SUBSCRIBE and continue to breakpoint at top of tablesync function
LogicalRepSyncTableStart
##
[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-02-03 11:46:07.207 AEDT [8298] LOG: logical decoding found consistent
point at 0/1654698
2021-02-03 11:46:07.207 AEDT [8298] DETAIL: There are no running transactions.
2021-02-03 11:46:07.207 AEDT [8298] STATEMENT: CREATE_REPLICATION_SLOT
"tap_sub" LOGICAL pgoutput NOEXPORT_SNAPSHOT
NOTICE: created replication slot "tap_sub" on publisher
CREATE SUBSCRIPTION
2021-02-03 11:46:07.218 AEDT [8302] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-03 11:46:07.218 AEDT [8302] LOG: !!>> The apply worker process has PID
= 8302
[postgres@CentOS7-x64 ~]$ 2021-02-03 11:46:07.224 AEDT [8306] LOG: starting
logical decoding for slot "tap_sub"
2021-02-03 11:46:07.224 AEDT [8306] DETAIL: Streaming transactions committing
after 0/16546D0, reading WAL from 0/1654698.
2021-02-03 11:46:07.224 AEDT [8306] STATEMENT: START_REPLICATION SLOT
"tap_sub" LOGICAL 0/0 (proto_version '2', publication_names '"tap_pub"')
2021-02-03 11:46:07.225 AEDT [8306] LOG: logical decoding found consistent
point at 0/1654698
2021-02-03 11:46:07.225 AEDT [8306] DETAIL: There are no running transactions.
2021-02-03 11:46:07.225 AEDT [8306] STATEMENT: START_REPLICATION SLOT
"tap_sub" LOGICAL 0/0 (proto_version '2', publication_names '"tap_pub"')
2021-02-03 11:46:07.225 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:07.225 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:07.229 AEDT [8307] LOG: logical replication table
synchronization worker for subscription "tap_sub", table "test_tab" has started
2021-02-03 11:46:07.229 AEDT [8307] LOG: !!>> The tablesync worker process has
PID = 8307
2021-02-03 11:46:07.229 AEDT [8307] LOG: !!>>
Sleeping 30 secs. For debugging, attach to process 8307 now!
## PID 8302 is apply worker
## PID 8307 is tablesync worker
2021-02-03 11:46:08.241 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:08.241 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:09.253 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:09.253 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:10.255 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:10.255 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:11.258 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:11.258 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:12.263 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:12.263 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:13.265 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:13.265 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:14.275 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:14.275 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:15.280 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:15.280 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:16.282 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:16.282 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:17.284 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:17.284 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:18.285 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:18.286 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:19.287 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:19.287 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:20.288 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:20.288 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:21.290 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:21.290 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:22.291 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:22.291 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:23.293 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:23.293 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:24.295 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:24.295 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:25.297 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:25.297 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:26.308 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:26.308 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:27.309 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:27.309 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:28.311 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:28.311 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:29.313 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:29.313 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:30.315 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:30.315 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:31.333 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:31.333 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:32.335 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:32.335 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:33.336 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:33.336 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:34.337 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:34.337 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:35.339 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:35.339 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:36.362 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:36.362 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:37.239 AEDT [8307] LOG: !!>> tablesync worker: About to call
LogicalRepSyncTableStart to do initial syncing
2021-02-03 11:46:37.364 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:37.364 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:37.364 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:37.364 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:38.371 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:38.371 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:39.373 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:39.373 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:40.388 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:40.388 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:41.389 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:41.390 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:42.391 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:42.391 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:43.393 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:43.394 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:44.410 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:44.410 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:45.411 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:45.411 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:46.412 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:46.412 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:47.413 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:47.413 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:48.414 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:48.414 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:49.415 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:49.415 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
##
## While paused in debugger for the tablesync worker do DROP TABLE on
subscriber.
## Note we have not done any ALTER SUBSCRIPTION.
##
psql -d test_sub -p 54321 -c "DROP TABLE test_tab;"
##
## But now (since V25 fix) the DROP is disallowed while tablesync not in the
READY state...
##
2021-02-03 11:46:50.341 AEDT [9648] ERROR: could not drop relation mapping for
subscription "tap_sub"
2021-02-03 11:46:50.341 AEDT [9648] DETAIL: Table synchronization for relation
"test_tab" is in progress and is in state "i".
2021-02-03 11:46:50.341 AEDT [9648] HINT: Use ALTER SUBSCRIPTION ... ENABLE to
enable subscription if not already enabled or use DROP SUBSCRIPTION ... to drop
the subscription.
2021-02-03 11:46:50.341 AEDT [9648] STATEMENT: DROP TABLE test_tab;
ERROR: could not drop relation mapping for subscription "tap_sub"
DETAIL: Table synchronization for relation "test_tab" is in progress and is in
state "i".
HINT: Use ALTER SUBSCRIPTION ... ENABLE to enable subscription if not already
enabled or use DROP SUBSCRIPTION ... to drop the subscription.
##
## Now let the tablesync function continue...
##
[postgres@CentOS7-x64 ~]$ 2021-02-03 11:46:50.416 AEDT [8302] LOG: !!>> apply
worker: LogicalRepApplyLoop
2021-02-03 11:46:50.416 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:51.417 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:51.417 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:52.418 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:52.418 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:53.420 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:53.420 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:54.420 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:54.420 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:55.422 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:55.422 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:56.422 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:56.422 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:57.350 AEDT [9862] LOG: logical decoding found consistent
point at 0/16546D0
2021-02-03 11:46:57.350 AEDT [9862] DETAIL: There are no running transactions.
2021-02-03 11:46:57.350 AEDT [9862] STATEMENT: CREATE_REPLICATION_SLOT
"pg_16398_sync_16385" LOGICAL pgoutput USE_SNAPSHOT
2021-02-03 11:46:57.359 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:57.359 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:46:57.367 AEDT [8307] LOG: !!>> tablesync worker: wait for
CATCHUP state notification
2021-02-03 11:46:57.367 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:46:57.367 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:07.352 AEDT [8307] LOG: !!>> tablesync worker: received
CATCHUP state notification
2021-02-03 11:47:07.352 AEDT [8307] LOG: !!>> tablesync worker: Returned from
LogicalRepSyncTableStart
2021-02-03 11:47:07.352 AEDT [9862] LOG: starting logical decoding for slot
"pg_16398_sync_16385"
2021-02-03 11:47:07.352 AEDT [9862] DETAIL: Streaming transactions committing
after 0/1654708, reading WAL from 0/16546D0.
2021-02-03 11:47:07.352 AEDT [9862] STATEMENT: START_REPLICATION SLOT
"pg_16398_sync_16385" LOGICAL 0/1654708 (proto_version '2', publication_names
'"tap_pub"')
2021-02-03 11:47:07.352 AEDT [9862] LOG: logical decoding found consistent
point at 0/16546D0
2021-02-03 11:47:07.352 AEDT [9862] DETAIL: There are no running transactions.
2021-02-03 11:47:07.352 AEDT [9862] STATEMENT: START_REPLICATION SLOT
"pg_16398_sync_16385" LOGICAL 0/1654708 (proto_version '2', publication_names
'"tap_pub"')
2021-02-03 11:47:09.275 AEDT [8307] LOG: !!>> tablesync worker:
LogicalRepApplyLoop
2021-02-03 11:47:09.275 AEDT [8307] LOG: !!>> tablesync worker: called
process_syncing_tables
2021-02-03 11:47:15.264 AEDT [8307] LOG: logical replication table
synchronization worker for subscription "tap_sub", table "test_tab" has finished
##
## Tablesync worker completed normally
##
2021-02-03 11:47:15.265 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:15.265 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:16.270 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:16.270 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:17.272 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:17.272 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:18.276 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:18.276 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:19.291 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:19.291 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:20.297 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:20.297 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:21.299 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:21.299 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:22.339 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:22.339 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:23.341 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:23.341 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:24.347 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:24.347 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:25.352 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:25.352 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:26.357 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:26.357 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:27.361 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:27.362 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:27.362 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:27.362 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:28.367 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:28.367 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:29.368 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:29.368 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:30.370 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:30.370 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:31.371 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:31.371 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:32.374 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:32.374 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:33.376 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:33.376 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:34.380 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:34.380 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:35.381 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:35.381 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:36.383 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:36.384 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:37.385 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:37.385 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
##
## There are no tablesync slots lying around
##
psql -d test_pub -c "select * from pg_replication_slots;"2021-02-03
11:47:38.394 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:38.394 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
slot_name | plugin | slot_type | datoid | database | temporary | active |
active_pid | xmin | catalog_xmin | restart_lsn | confirmed_flus
h_lsn | wal_status | safe_wal_size
-----------+----------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+---------------
------+------------+---------------
tap_sub | pgoutput | logical | 16384 | test_pub | f | t |
8306 | | 518 | 0/16546D0 | 0/1654708
| reserved |
(1 row)
[postgres@CentOS7-x64 ~]$ 2021-02-03 11:47:39.398 AEDT [8302] LOG: !!>> apply
worker: LogicalRepApplyLoop
2021-02-03 11:47:39.399 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:40.400 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:40.400 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:41.405 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:41.405 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:42.406 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:42.406 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:43.417 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:43.417 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:44.418 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:44.418 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:45.419 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:45.419 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:46.420 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:46.420 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:47.427 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:47.427 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:48.428 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:48.428 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:49.429 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:49.429 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:50.430 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:50.430 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:51.431 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:51.431 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:52.432 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:52.432 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:53.433 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:53.433 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:54.435 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:54.435 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:55.435 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:55.435 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:56.436 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:56.436 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:57.437 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:57.437 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:57.437 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:57.437 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:58.438 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:58.438 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:47:59.439 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:47:59.439 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
##
## Drop the subscription
##
psql -d test_sub -p 54321 -c "DROP SUBSCRIPTION tap_sub;"2021-02-03
11:48:00.440 AEDT [8302] LOG: !!>> apply worker: LogicalRepApplyLoop
2021-02-03 11:48:00.440 AEDT [8302] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-03 11:48:00.566 AEDT [8302] FATAL: terminating logical replication
worker due to administrator command
2021-02-03 11:48:00.567 AEDT [1646] LOG: background worker "logical
replication worker" (PID 8302) exited with exit code 1
NOTICE: dropped replication slot "tap_sub" on publisher
DROP SUBSCRIPTION
##
## All slots are cleaned up
##
[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 | confirmed_flush_
lsn | wal_status | safe_wal_size
-----------+--------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+-----------------
----+------------+---------------
(0 rows)
##
## The data is replicated correctly
##
## (Publisher side)
[postgres@CentOS7-x64 ~]$ psql -d test_pub -c "SELECT * FROM test_tab;"
a | b | c | d
---+-----+------------------------------+-----
1 | foo | 2021-02-03 11:44:28.43011+11 | 999
(1 row)
## (Subscriber side)
[postgres@CentOS7-x64 ~]$ psql -d test_sub -p 54321 -c "SELECT * FROM test_tab;"
a | b | c | d
---+-----+------------------------------+-----
1 | foo | 2021-02-03 11:44:28.43011+11 | 999
(1 row)
[postgres@CentOS7-x64 ~]$
