N2.log

application/octet-stream
Filename: N2.log
Type: application/octet-stream
Part: 0
Message: RE: [PATCH] Reuse Workers and Replication Slots during Logical Replication
2023-07-05 13:20:25.168 UTC [27962] [postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-4.8.5, 64-bit
2023-07-05 13:20:25.168 UTC [27962] [postmaster] LOG:  listening on IPv6 address "::1", port 5432
2023-07-05 13:20:25.168 UTC [27962] [postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 5432
2023-07-05 13:20:25.172 UTC [27962] [postmaster] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2023-07-05 13:20:25.178 UTC [27965] [startup] LOG:  database system was shut down at 2023-07-05 13:20:24 UTC
2023-07-05 13:20:25.188 UTC [27962] [postmaster] LOG:  database system is ready to accept connections
2023-07-05 13:20:25.895 UTC [28040] [logical replication apply worker] LOG:  logical replication apply worker for subscription "sub" has started
2023-07-05 13:20:25.907 UTC [28042] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", table "tbl_5" with relid 16409 has started
2023-07-05 13:20:25.946 UTC [28042] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", relation "tbl_5" with relid 16409 has finished
2023-07-05 13:20:25.946 UTC [28042] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub" has moved to sync table "tbl_6" with relid 16414.
2023-07-05 13:20:25.947 UTC [28042] [logical replication tablesync worker] ERROR:  table copy could not start transaction on publisher: another command is already in progress
2023-07-05 13:20:25.948 UTC [27962] [postmaster] LOG:  background worker "logical replication tablesync worker" (PID 28042) exited with exit code 1
2023-07-05 13:20:25.954 UTC [28044] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", table "tbl_10" with relid 16434 has started
2023-07-05 13:20:25.993 UTC [28044] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", relation "tbl_10" with relid 16434 has finished
2023-07-05 13:20:25.993 UTC [28044] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub" has moved to sync table "tbl_7" with relid 16419.
2023-07-05 13:20:25.993 UTC [28044] [logical replication tablesync worker] ERROR:  table copy could not start transaction on publisher: another command is already in progress
2023-07-05 13:20:25.995 UTC [27962] [postmaster] LOG:  background worker "logical replication tablesync worker" (PID 28044) exited with exit code 1
2023-07-05 13:20:26.001 UTC [28046] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", table "tbl_2" with relid 16394 has started
2023-07-05 13:20:26.040 UTC [28046] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", relation "tbl_2" with relid 16394 has finished
2023-07-05 13:20:26.040 UTC [28046] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub" has moved to sync table "tbl_4" with relid 16404.
2023-07-05 13:20:26.040 UTC [28046] [logical replication tablesync worker] ERROR:  table copy could not start transaction on publisher: another command is already in progress
2023-07-05 13:20:26.041 UTC [27962] [postmaster] LOG:  background worker "logical replication tablesync worker" (PID 28046) exited with exit code 1
2023-07-05 13:20:26.047 UTC [28048] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", table "tbl_0" with relid 16384 has started
2023-07-05 13:20:26.084 UTC [28048] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", relation "tbl_0" with relid 16384 has finished
2023-07-05 13:20:26.084 UTC [28048] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub" has moved to sync table "tbl_3" with relid 16399.
2023-07-05 13:20:26.084 UTC [28048] [logical replication tablesync worker] ERROR:  table copy could not start transaction on publisher: another command is already in progress
2023-07-05 13:20:26.086 UTC [27962] [postmaster] LOG:  background worker "logical replication tablesync worker" (PID 28048) exited with exit code 1
2023-07-05 13:20:26.091 UTC [28050] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", table "tbl_9" with relid 16429 has started
2023-07-05 13:20:26.128 UTC [28050] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", relation "tbl_9" with relid 16429 has finished
2023-07-05 13:20:26.128 UTC [28050] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub" has moved to sync table "tbl_1" with relid 16389.
2023-07-05 13:20:26.128 UTC [28050] [logical replication tablesync worker] ERROR:  table copy could not start transaction on publisher: another command is already in progress
2023-07-05 13:20:26.130 UTC [27962] [postmaster] LOG:  background worker "logical replication tablesync worker" (PID 28050) exited with exit code 1
2023-07-05 13:20:26.136 UTC [28052] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", table "tbl_8" with relid 16424 has started
2023-07-05 13:20:26.174 UTC [28052] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", relation "tbl_8" with relid 16424 has finished
2023-07-05 13:20:26.174 UTC [28052] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub" has moved to sync table "tbl_6" with relid 16414.
2023-07-05 13:20:26.174 UTC [28052] [logical replication tablesync worker] ERROR:  could not drop replication slot "pg_16439_sync_1_7252323818691538217" on publisher: another command is already in progress
2023-07-05 13:20:26.175 UTC [27962] [postmaster] LOG:  background worker "logical replication tablesync worker" (PID 28052) exited with exit code 1
2023-07-05 13:20:26.181 UTC [28054] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", table "tbl_6" with relid 16414 has started
2023-07-05 13:20:26.220 UTC [28054] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", relation "tbl_6" with relid 16414 has finished
2023-07-05 13:20:26.220 UTC [28054] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub" has moved to sync table "tbl_7" with relid 16419.
2023-07-05 13:20:26.220 UTC [28054] [logical replication tablesync worker] ERROR:  could not drop replication slot "pg_16439_sync_2_7252323818691538217" on publisher: another command is already in progress
2023-07-05 13:20:26.221 UTC [27962] [postmaster] LOG:  background worker "logical replication tablesync worker" (PID 28054) exited with exit code 1
2023-07-05 13:20:26.227 UTC [28056] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", table "tbl_7" with relid 16419 has started
2023-07-05 13:20:26.266 UTC [28056] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", relation "tbl_7" with relid 16419 has finished
2023-07-05 13:20:26.266 UTC [28056] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub" has moved to sync table "tbl_4" with relid 16404.
2023-07-05 13:20:26.266 UTC [28056] [logical replication tablesync worker] ERROR:  could not drop replication slot "pg_16439_sync_3_7252323818691538217" on publisher: another command is already in progress
2023-07-05 13:20:26.267 UTC [27962] [postmaster] LOG:  background worker "logical replication tablesync worker" (PID 28056) exited with exit code 1
2023-07-05 13:20:26.273 UTC [28058] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", table "tbl_4" with relid 16404 has started
2023-07-05 13:20:26.312 UTC [28058] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", relation "tbl_4" with relid 16404 has finished
2023-07-05 13:20:26.312 UTC [28058] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub" has moved to sync table "tbl_3" with relid 16399.
2023-07-05 13:20:26.312 UTC [28058] [logical replication tablesync worker] ERROR:  could not drop replication slot "pg_16439_sync_4_7252323818691538217" on publisher: another command is already in progress
2023-07-05 13:20:26.313 UTC [27962] [postmaster] LOG:  background worker "logical replication tablesync worker" (PID 28058) exited with exit code 1
2023-07-05 13:20:26.319 UTC [28060] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", table "tbl_3" with relid 16399 has started
2023-07-05 13:20:26.358 UTC [28060] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", relation "tbl_3" with relid 16399 has finished
2023-07-05 13:20:26.358 UTC [28060] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub" has moved to sync table "tbl_1" with relid 16389.
2023-07-05 13:20:26.358 UTC [28060] [logical replication tablesync worker] ERROR:  could not drop replication slot "pg_16439_sync_5_7252323818691538217" on publisher: another command is already in progress
2023-07-05 13:20:26.359 UTC [27962] [postmaster] LOG:  background worker "logical replication tablesync worker" (PID 28060) exited with exit code 1
2023-07-05 13:20:26.365 UTC [28062] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", table "tbl_1" with relid 16389 has started
2023-07-05 13:20:26.405 UTC [28062] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub", relation "tbl_1" with relid 16389 has finished
2023-07-05 13:20:26.409 UTC [28062] [logical replication tablesync worker] LOG:  logical replication table synchronization worker for subscription "sub" has finished
2023-07-05 13:25:25.232 UTC [27963] [checkpointer] LOG:  checkpoint starting: time
2023-07-05 13:25:36.881 UTC [27963] [checkpointer] LOG:  checkpoint complete: wrote 119 buffers (0.7%); 0 WAL file(s) added, 0 removed, 0 recycled; write=11.633 s, sync=0.012 s, total=11.650 s; sync files=80, longest=0.002 s, average=0.001 s; distance=560 kB, estimate=560 kB; lsn=0/15B0318, redo lsn=0/15B02E0