On Mon, Feb 1, 2021 at 11:26 PM Amit Kapila <amit.kapil...@gmail.com> wrote:
>
> I have updated the patch to display WARNING for each of the tablesync
> slots during DropSubscription. As discussed, I have moved the drop
> slot related code towards the end in AlterSubscription_refresh. Apart
> from this, I have fixed one more issue in tablesync code where in
> after catching the exception we were not clearing the transaction
> state on the publisher, see changes in LogicalRepSyncTableStart.
...
I know that in another email [ac0202] Ajin has reported some problem
he found related to this new (LogicalRepSyncTableStart PG_CATCH) code
for some different use-case, but for my test scenario of a "broken
connection during a table copy" the code did appear to be working
properly.
PSA detailed logs which show the test steps and output for this
""broken connection during a table copy" scenario.
----
[ac0202]
https://www.postgresql.org/message-id/CAFPTHDaZw5o%2BwMbv3aveOzuLyz_rqZebXAj59rDKTJbwXFPYgw%40mail.gmail.com
Kind Regards,
Peter Smith.
Fujitsu Australia
Test Scenario
=================
OBJECTIVE
- Break the connection during table copy (after slot is created)
- Later re-establish the connection
- Check tablesync is able to recover and finish normally.
- Check no slots are left dangling.
=================
STEPS
1. Create PUBLISHER
2. Insert some initial table data
3. Create SUBSCRIBER
4. Cause a network connection failure DURING table copy but AFTER the slot
is created
4a. Pause in debugger AFTER slot created but before the copy
4b. Make the connect fail by stopping the PUBLISHER Postgres
instance at this time
5. Let the tablesync continue.
5a. The tablesync will re-launch but I think it will continue to
fail and and fail and fail because cannot create slot which the connection is
broken
6. Then fix the connection by starting the PUBLISHER Postgres instance
again
6a. The tablesync will attempt to create the slot will ERROR
(already exists) at this time but then the PG_CATCH will drop it and the
tablesync will be launched yet again…
7. The tablesync should recover
7a. This time when the tablesync is relaunched there is no “already
exists” error so it should be able to recover OK.
8. The tablesync worker should finish normally
9. The replicated data should be visible in the subscribed table
10. There should be no dangling slots (e.g. check for warnings during DROP
SUBSCRIPTION)
=================
##
## 2. Insert a record at publisher
##
[postgres@CentOS7-x64 ~]$ psql -d test_pub -c "INSERT INTO test_tab VALUES(1,
'foo');"
INSERT 0 1
##
## 3. Start Subscription and pause the tablesync after its slot is created but
before the copy starts
##
[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-02 16:02:44.094 AEDT [24946] LOG: logical decoding found consistent
point at 0/1653EB0
2021-02-02 16:02:44.094 AEDT [24946] DETAIL: There are no running transactions.
2021-02-02 16:02:44.094 AEDT [24946] STATEMENT: CREATE_REPLICATION_SLOT
"tap_sub" LOGICAL pgoutput NOEXPORT_SNAPSHOT
NOTICE: created replication slot "tap_sub" on publisher
CREATE SUBSCRIPTION
2021-02-02 16:02:44.103 AEDT [24947] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:02:44.103 AEDT [24947] LOG: !!>> The apply worker process has
PID = 24947
[postgres@CentOS7-x64 ~]$ 2021-02-02 16:02:44.110 AEDT [24954] LOG: starting
logical decoding for slot "tap_sub"
2021-02-02 16:02:44.110 AEDT [24954] DETAIL: Streaming transactions committing
after 0/1653EE8, reading WAL from 0/1653EB0.
2021-02-02 16:02:44.110 AEDT [24954] STATEMENT: START_REPLICATION SLOT
"tap_sub" LOGICAL 0/0 (proto_version '2', publication_names '"tap_pub"')
2021-02-02 16:02:44.110 AEDT [24954] LOG: logical decoding found consistent
point at 0/1653EB0
2021-02-02 16:02:44.110 AEDT [24954] DETAIL: There are no running transactions.
2021-02-02 16:02:44.110 AEDT [24954] STATEMENT: START_REPLICATION SLOT
"tap_sub" LOGICAL 0/0 (proto_version '2', publication_names '"tap_pub"')
2021-02-02 16:02:44.110 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:44.110 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:44.115 AEDT [24955] LOG: logical replication table
synchronization worker for subscription "tap_sub", table "test_tab" has started
2021-02-02 16:02:44.115 AEDT [24955] LOG: !!>> The tablesync worker process
has PID = 24955
2021-02-02 16:02:44.115 AEDT [24955] LOG: !!>>
Sleeping 30 secs. For debugging, attach to process 24955 now!
# sync worker is PID 24955
# apply worker is PID 24947
2021-02-02 16:02:44.122 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:44.122 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:45.137 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:45.137 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:46.139 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:46.139 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:47.140 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:47.140 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:48.143 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:48.143 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:49.151 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:49.151 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:50.151 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:50.151 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:51.168 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:51.168 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:52.170 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:52.171 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:53.177 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:53.177 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:54.179 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:54.179 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:55.180 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:55.180 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:56.187 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:56.187 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:57.191 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:57.191 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:58.194 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:58.194 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:02:59.196 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:02:59.196 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:00.198 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:00.198 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:01.201 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:01.201 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:02.229 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:02.229 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:03.232 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:03.232 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:04.236 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:04.236 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:05.238 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:05.238 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:06.239 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:06.239 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:07.243 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:07.244 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:08.290 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:08.290 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:09.294 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:09.294 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:10.295 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:10.295 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:11.307 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:11.307 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:12.309 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:12.309 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:13.311 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:13.312 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:14.121 AEDT [24955] LOG: !!>> tablesync worker: About to call
LogicalRepSyncTableStart to do initial syncing
2021-02-02 16:03:14.314 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:14.314 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:14.314 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:14.314 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:15.314 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:15.314 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:16.315 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:16.315 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:17.316 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:17.316 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:18.323 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:18.323 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:19.325 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:19.325 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:20.362 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:20.362 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:21.364 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:21.365 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:22.367 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:22.367 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:23.370 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:23.370 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:24.382 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:24.382 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:25.383 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:25.383 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:26.390 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:26.390 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:27.391 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:27.391 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:28.392 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:28.392 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:29.394 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:29.394 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:30.398 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:30.398 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:31.400 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:31.400 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:32.402 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:32.403 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:33.405 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:33.405 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:34.407 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:34.407 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:35.407 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:35.407 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:36.409 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:36.409 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:37.411 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:37.411 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:38.412 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:38.412 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:39.413 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:39.413 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:40.414 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:40.414 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:41.418 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:41.418 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:42.421 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:42.421 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:43.422 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:43.422 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:44.425 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:44.425 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:44.426 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:44.426 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:45.427 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:45.428 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:46.428 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:46.428 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:47.429 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:47.429 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:48.431 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:48.431 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:49.432 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:49.433 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:49.603 AEDT [26921] LOG: logical decoding found consistent
point at 0/1653EE8
2021-02-02 16:03:49.603 AEDT [26921] DETAIL: There are no running transactions.
2021-02-02 16:03:49.603 AEDT [26921] STATEMENT: CREATE_REPLICATION_SLOT
"pg_16398_sync_16385" LOGICAL pgoutput USE_SNAPSHOT
2021-02-02 16:03:49.607 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:49.607 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:50.608 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:50.608 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:51.609 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:51.609 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:52.610 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:52.610 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:53.611 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:53.611 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:54.612 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:54.612 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:55.613 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:55.613 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:56.614 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:56.614 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:57.615 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:57.615 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:58.616 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:58.616 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:03:59.617 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:03:59.617 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:04:00.618 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:04:00.618 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:04:01.619 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:04:01.619 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:04:02.620 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:04:02.620 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:04:03.627 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:04:03.627 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:04:04.629 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:04:04.629 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:04:05.629 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:04:05.629 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:04:06.631 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:04:06.631 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:04:07.632 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:04:07.632 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:04:08.633 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:04:08.633 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
##
## 4b Here is where I break the connection by stopping the Publisher's PG
instance
##
pg_ctl -D ./MYDATAOSS_2PC_PUB/ stop2021-02-02 16:04:09.634 AEDT [24947] LOG:
!!>> apply worker: LogicalRepApplyLoop
2021-02-02 16:04:09.634 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
waiting for server to shut down....2021-02-02 16:04:09.906 AEDT [25486] LOG:
received fast shutdown request
2021-02-02 16:04:09.921 AEDT [25486] LOG: aborting any active transactions
2021-02-02 16:04:09.922 AEDT [25486] LOG: background worker "logical
replication launcher" (PID 25493) exited with exit code 1
2021-02-02 16:04:09.922 AEDT [25488] LOG: shutting down
2021-02-02 16:04:09.922 AEDT [24947] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:04:09.922 AEDT [26921] FATAL: terminating connection due to
administrator command
##
## 5a. Now the connection is broken. The apply worker fails because the broken
connection.....
##
2021-02-02 16:04:09.923 AEDT [24947] LOG: data stream from publisher has ended
2021-02-02 16:04:09.923 AEDT [24947] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:04:09.923 AEDT [24947] ERROR: could not send end-of-streaming
message to primary: server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
no COPY in progress
2021-02-02 16:04:09.923 AEDT [25536] LOG: background worker "logical
replication worker" (PID 24947) exited with exit code 1
##
## 5a. Apply worker cannot connect. It keeps attempting to re-launch again and
again and again...
##
2021-02-02 16:04:09.927 AEDT [27457] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:04:09.927 AEDT [27457] LOG: !!>> The apply worker process has
PID = 27457
2021-02-02 16:04:09.928 AEDT [27458] FATAL: the database system is shutting
down
2021-02-02 16:04:09.928 AEDT [27457] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed: FATAL:
the database system is shutting down
2021-02-02 16:04:09.929 AEDT [25536] LOG: background worker "logical
replication worker" (PID 27457) exited with exit code 1
2021-02-02 16:04:09.960 AEDT [25486] LOG: database system is shut down
done
server stopped
[postgres@CentOS7-x64 ~]$ 2021-02-02 16:04:14.938 AEDT [27587] LOG: logical
replication apply worker for subscription "tap_sub" has started
2021-02-02 16:04:14.938 AEDT [27587] LOG: !!>> The apply worker process has
PID = 27587
2021-02-02 16:04:14.939 AEDT [27587] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:04:14.939 AEDT [25536] LOG: background worker "logical
replication worker" (PID 27587) exited with exit code 1
2021-02-02 16:04:19.949 AEDT [27685] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:04:19.949 AEDT [27685] LOG: !!>> The apply worker process has
PID = 27685
2021-02-02 16:04:19.950 AEDT [27685] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:04:19.950 AEDT [25536] LOG: background worker "logical
replication worker" (PID 27685) exited with exit code 1
2021-02-02 16:04:24.982 AEDT [27827] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:04:24.982 AEDT [27827] LOG: !!>> The apply worker process has
PID = 27827
2021-02-02 16:04:24.990 AEDT [27827] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:04:25.000 AEDT [25536] LOG: background worker "logical
replication worker" (PID 27827) exited with exit code 1
2021-02-02 16:04:30.018 AEDT [27956] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:04:30.018 AEDT [27956] LOG: !!>> The apply worker process has
PID = 27956
2021-02-02 16:04:30.020 AEDT [27956] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:04:30.021 AEDT [25536] LOG: background worker "logical
replication worker" (PID 27956) exited with exit code 1
2021-02-02 16:04:35.030 AEDT [28026] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:04:35.031 AEDT [28026] LOG: !!>> The apply worker process has
PID = 28026
2021-02-02 16:04:35.031 AEDT [28026] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:04:35.032 AEDT [25536] LOG: background worker "logical
replication worker" (PID 28026) exited with exit code 1
2021-02-02 16:04:40.044 AEDT [28191] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:04:40.044 AEDT [28191] LOG: !!>> The apply worker process has
PID = 28191
2021-02-02 16:04:40.046 AEDT [28191] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:04:40.047 AEDT [25536] LOG: background worker "logical
replication worker" (PID 28191) exited with exit code 1
2021-02-02 16:04:45.080 AEDT [28344] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:04:45.080 AEDT [28344] LOG: !!>> The apply worker process has
PID = 28344
2021-02-02 16:04:45.084 AEDT [28344] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:04:45.085 AEDT [25536] LOG: background worker "logical
replication worker" (PID 28344) exited with exit code 1
2021-02-02 16:04:50.084 AEDT [24955] ERROR: table copy could not rollback
transaction on publisher
2021-02-02 16:04:50.084 AEDT [24955] DETAIL: The error was: no connection to
the server
2021-02-02 16:04:50.085 AEDT [25536] LOG: background worker "logical
replication worker" (PID 24955) exited with exit code 1
2021-02-02 16:04:50.090 AEDT [28441] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:04:50.090 AEDT [28441] LOG: !!>> The apply worker process has
PID = 28441
2021-02-02 16:04:50.091 AEDT [28441] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:04:50.091 AEDT [25536] LOG: background worker "logical
replication worker" (PID 28441) exited with exit code 1
2021-02-02 16:04:55.104 AEDT [28551] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:04:55.104 AEDT [28551] LOG: !!>> The apply worker process has
PID = 28551
2021-02-02 16:04:55.105 AEDT [28551] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:04:55.106 AEDT [25536] LOG: background worker "logical
replication worker" (PID 28551) exited with exit code 1
2021-02-02 16:05:00.117 AEDT [28710] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:05:00.117 AEDT [28710] LOG: !!>> The apply worker process has
PID = 28710
2021-02-02 16:05:00.118 AEDT [28710] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:05:00.119 AEDT [25536] LOG: background worker "logical
replication worker" (PID 28710) exited with exit code 1
2021-02-02 16:05:05.128 AEDT [28839] LOG: logical replication apply worker for
subscription "tap_sub" has started
2021-02-02 16:05:05.129 AEDT [28839] LOG: !!>> The apply worker process has
PID = 28839
2021-02-02 16:05:05.129 AEDT [28839] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:05:05.130 AEDT [25536] LOG: background worker "logical
replication worker" (PID 28839) exited with exit code 1
##
## 6. Now we re-establish the connection by starting the Publisher instance.
##
pg_ctl -D ./MYDATAOSS_2PC_PUB/ start2021-02-02 16:05:10.140 AEDT [28978] LOG:
logical replication apply worker for subscription "tap_sub" has started
2021-02-02 16:05:10.140 AEDT [28978] LOG: !!>> The apply worker process has
PID = 28978
2021-02-02 16:05:10.141 AEDT [28978] ERROR: could not connect to the
publisher: connection to server at "localhost" (::1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
connection to server at "localhost" (127.0.0.1), port 5432 failed:
Connection refused
Is the server running on that host and accepting TCP/IP
connections?
2021-02-02 16:05:10.141 AEDT [25536] LOG: background worker "logical
replication worker" (PID 28978) exited with exit code 1
waiting for server to start....2021-02-02 16:05:11.229 AEDT [29017] LOG:
starting PostgreSQL 14devel on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5
20150623 (Red Hat 4.8.5-36), 64-bit
2021-02-02 16:05:11.230 AEDT [29017] LOG: listening on IPv6 address "::1",
port 5432
2021-02-02 16:05:11.230 AEDT [29017] LOG: listening on IPv4 address
"127.0.0.1", port 5432
2021-02-02 16:05:11.234 AEDT [29017] LOG: listening on Unix socket
"/tmp/.s.PGSQL.5432"
2021-02-02 16:05:11.240 AEDT [29018] LOG: database system was shut down at
2021-02-02 16:04:09 AEDT
2021-02-02 16:05:11.245 AEDT [29017] LOG: database system is ready to accept
connections
done
server started
[postgres@CentOS7-x64 ~]$ 2021-02-02 16:05:15.152 AEDT [29111] LOG: logical
replication apply worker for subscription "tap_sub" has started
##
## Now the apply worker can start OK
##
2021-02-02 16:05:15.152 AEDT [29111] LOG: !!>> The apply worker process has
PID = 29111
2021-02-02 16:05:15.177 AEDT [29112] LOG: starting logical decoding for slot
"tap_sub"
2021-02-02 16:05:15.177 AEDT [29112] DETAIL: Streaming transactions committing
after 0/1653EE8, reading WAL from 0/1653EE8.
2021-02-02 16:05:15.177 AEDT [29112] STATEMENT: START_REPLICATION SLOT
"tap_sub" LOGICAL 0/0 (proto_version '2', publication_names '"tap_pub"')
2021-02-02 16:05:15.177 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:15.177 AEDT [29112] LOG: logical decoding found consistent
point at 0/1653EE8
2021-02-02 16:05:15.177 AEDT [29112] DETAIL: There are no running transactions.
2021-02-02 16:05:15.177 AEDT [29112] STATEMENT: START_REPLICATION SLOT
"tap_sub" LOGICAL 0/0 (proto_version '2', publication_names '"tap_pub"')
2021-02-02 16:05:15.177 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
##
## 7a. Now the tablesync worker is re-launched
##
2021-02-02 16:05:15.182 AEDT [29113] LOG: logical replication table
synchronization worker for subscription "tap_sub", table "test_tab" has started
2021-02-02 16:05:15.182 AEDT [29113] LOG: !!>> The tablesync worker process
has PID = 29113
2021-02-02 16:05:15.182 AEDT [29113] LOG: !!>>
Sleeping 30 secs. For debugging, attach to process 29113 now!
## Apply worker PID = 29111
## Sync worker PID = 29113
2021-02-02 16:05:15.188 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:15.188 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:16.194 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:16.194 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:17.199 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:17.199 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:18.211 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:18.211 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:19.212 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:19.212 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:20.214 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:20.215 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:21.217 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:21.217 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:22.241 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:22.241 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:23.278 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:23.278 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:24.309 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:24.309 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:25.312 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:25.312 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:26.317 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:26.317 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:26.435 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:26.435 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:27.437 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:27.437 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:28.443 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:28.443 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:29.444 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:29.444 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:30.445 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:30.445 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:31.447 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:31.447 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:32.449 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:32.449 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:33.450 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:33.450 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:34.452 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:34.452 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:35.452 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:35.452 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:36.454 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:36.454 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:37.456 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:37.456 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:38.457 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:38.457 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:39.459 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:39.459 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:40.461 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:40.461 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:41.461 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:41.462 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:42.465 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:42.465 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:43.466 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:43.466 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:44.468 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:44.468 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:45.185 AEDT [29113] LOG: !!>> tablesync worker: About to call
LogicalRepSyncTableStart to do initial syncing
2021-02-02 16:05:45.469 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:45.469 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:46.470 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:46.470 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:47.472 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:47.472 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:48.474 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:48.474 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:49.475 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:49.475 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:50.476 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:50.476 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:51.477 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:51.477 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:52.484 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:52.484 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:53.485 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:53.485 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:54.409 AEDT [30185] ERROR: replication slot
"pg_16398_sync_16385" already exists
2021-02-02 16:05:54.409 AEDT [30185] STATEMENT: CREATE_REPLICATION_SLOT
"pg_16398_sync_16385" LOGICAL pgoutput USE_SNAPSHOT
2021-02-02 16:05:54.486 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:54.486 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:55.488 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:55.488 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:56.489 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:56.489 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:56.490 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:56.490 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:57.490 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:57.490 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:58.491 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:58.491 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:05:59.492 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:05:59.492 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:00.493 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:00.493 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:01.494 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:01.494 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:02.495 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:02.495 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:03.496 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:03.496 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:04.497 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:04.497 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:05.498 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:05.498 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:06.500 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:06.500 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:07.501 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:07.501 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:08.503 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:08.503 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:09.504 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:09.504 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:10.505 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:10.505 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:11.506 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:11.506 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:12.515 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:12.515 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:13.515 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:13.515 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:14.516 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:14.516 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:15.520 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:15.520 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
##
## 6a. The tablesync (PID 29113) get expected error when it tried to create the
slot with
## same name which already exists.
##
2021-02-02 16:06:15.797 AEDT [29113] ERROR: could not create replication slot
"pg_16398_sync_16385": ERROR: replication slot "pg_16398_sync_16385" already
exists
2021-02-02 16:06:15.798 AEDT [25536] LOG: background worker "logical
replication worker" (PID 29113) exited with exit code 1
##
## 6a This is where the PG_CATCH code was executed which did a DROP SLOT
##
2021-02-02 16:06:15.798 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:15.798 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
##
## 7a. And tablesyn is relaunched again
##
## apply worker PID = 29111
## sync worker PID = 30732
##
2021-02-02 16:06:15.803 AEDT [30732] LOG: logical replication table
synchronization worker for subscription "tap_sub", table "test_tab" has started
2021-02-02 16:06:15.803 AEDT [30732] LOG: !!>> The tablesync worker process
has PID = 30732
2021-02-02 16:06:15.803 AEDT [30732] LOG: !!>>
Sleeping 30 secs. For debugging, attach to process 30732 now!
2021-02-02 16:06:16.842 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:16.842 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:17.844 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:17.844 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:18.847 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:18.847 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:19.848 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:19.848 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:20.876 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:20.876 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:21.881 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:21.881 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:22.883 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:22.883 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:23.884 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:23.884 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:24.916 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:24.916 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:25.959 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:25.959 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:26.962 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:26.962 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:26.962 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:26.962 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:27.967 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:27.967 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:28.969 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:28.969 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:29.971 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:29.971 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:30.979 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:30.979 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:31.981 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:31.981 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:32.982 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:32.982 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:33.986 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:33.986 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:34.988 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:34.988 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:35.991 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:35.991 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:36.996 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:36.996 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:37.997 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:37.997 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:38.998 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:38.998 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:40.006 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:40.006 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:41.007 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:41.007 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:42.009 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:42.009 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:43.031 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:43.031 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:44.033 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:44.033 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:45.035 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:45.035 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:45.806 AEDT [30732] LOG: !!>> tablesync worker: About to call
LogicalRepSyncTableStart to do initial syncing
2021-02-02 16:06:46.037 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:46.037 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:47.039 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:47.039 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:48.046 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:48.047 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:49.048 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:49.048 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:50.048 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:50.048 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:51.069 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:51.069 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:51.178 AEDT [31727] LOG: logical decoding found consistent
point at 0/1653FD0
2021-02-02 16:06:51.178 AEDT [31727] DETAIL: There are no running transactions.
2021-02-02 16:06:51.178 AEDT [31727] STATEMENT: CREATE_REPLICATION_SLOT
"pg_16398_sync_16385" LOGICAL pgoutput USE_SNAPSHOT
2021-02-02 16:06:51.182 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:51.182 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:52.184 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:52.184 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:53.185 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:53.186 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:54.190 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:54.190 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:55.194 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:55.194 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:56.196 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:56.196 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:57.199 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:57.199 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:58.200 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:58.200 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:06:59.204 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:59.204 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
##
## 7a. This time there are no more tablesync errors
##
2021-02-02 16:06:59.299 AEDT [30732] LOG: !!>> tablesync worker: wait for
CATCHUP state notification
2021-02-02 16:06:59.299 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:06:59.300 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:03.477 AEDT [30732] LOG: !!>> tablesync worker: received
CATCHUP state notification
2021-02-02 16:07:03.477 AEDT [30732] LOG: !!>> tablesync worker: Returned from
LogicalRepSyncTableStart
2021-02-02 16:07:03.478 AEDT [31727] LOG: starting logical decoding for slot
"pg_16398_sync_16385"
2021-02-02 16:07:03.478 AEDT [31727] DETAIL: Streaming transactions committing
after 0/1654020, reading WAL from 0/1653FD0.
2021-02-02 16:07:03.478 AEDT [31727] STATEMENT: START_REPLICATION SLOT
"pg_16398_sync_16385" LOGICAL 0/1654020 (proto_version '2', publication_names
'"tap_pub"')
2021-02-02 16:07:03.478 AEDT [31727] LOG: logical decoding found consistent
point at 0/1653FD0
2021-02-02 16:07:03.478 AEDT [31727] DETAIL: There are no running transactions.
2021-02-02 16:07:03.478 AEDT [31727] STATEMENT: START_REPLICATION SLOT
"pg_16398_sync_16385" LOGICAL 0/1654020 (proto_version '2', publication_names
'"tap_pub"')
2021-02-02 16:07:04.976 AEDT [30732] LOG: !!>> tablesync worker:
LogicalRepApplyLoop
2021-02-02 16:07:04.976 AEDT [30732] LOG: !!>> tablesync worker: called
process_syncing_tables
2021-02-02 16:07:13.253 AEDT [30732] LOG: logical replication table
synchronization worker for subscription "tap_sub", table "test_tab" has finished
##
## 8. The sync worker was able to finish normally.
##
2021-02-02 16:07:13.255 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:13.255 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:14.256 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:14.256 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:15.260 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:15.260 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:16.261 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:16.261 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:17.265 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:17.265 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:18.271 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:18.271 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:19.301 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:19.301 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:20.312 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:20.312 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:21.330 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:21.330 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:21.332 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:21.332 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:22.337 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:22.338 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:23.339 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:23.339 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:24.352 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:24.352 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:25.354 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:25.354 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:26.363 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:26.363 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:27.365 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:27.365 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:28.375 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:28.375 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:29.378 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:29.378 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:30.397 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:30.397 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:31.398 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:31.398 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
2021-02-02 16:07:32.399 AEDT [29111] LOG: !!>> apply worker:
LogicalRepApplyLoop
2021-02-02 16:07:32.399 AEDT [29111] LOG: !!>> apply worker: called
process_syncing_tables
##
## 10. Drop Subscription
##
psql -d test_sub -p 54321 -c "DROP SUBSCRIPTION tap_sub;"
2021-02-02 16:07:33.286 AEDT [29111] FATAL: terminating logical replication
worker due to administrator command
2021-02-02 16:07:33.286 AEDT [25536] LOG: background worker "logical
replication worker" (PID 29111) exited with exit code 1
NOTICE: dropped replication slot "tap_sub" on publisher
DROP SUBSCRIPTION
##
## There are no dangling 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 | confirmed_flush_
lsn | wal_status | safe_wal_size
-----------+--------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+-----------------
----+------------+---------------
(0 rows)
##
## The initial row of data was replicated correctly.
##
[postgres@CentOS7-x64 ~]$ psql -d test_sub -p 54321 -c "SELECT * FROM test_tab;"
a | b | c | d
---+-----+-------------------------------+-----
1 | foo | 2021-02-02 15:11:58.121875+11 | 999
(1 row)
[postgres@CentOS7-x64 ~]$
