N1.log

application/octet-stream
Filename: N1.log
Type: application/octet-stream
Part: 3
Message: Re: Handle infinite recursion in logical replication setup
2022-04-07 12:31:39.771 AEST [2213] LOG:  starting PostgreSQL 15devel on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-36), 64-bit
2022-04-07 12:31:39.773 AEST [2213] LOG:  listening on IPv6 address "::1", port 7651
2022-04-07 12:31:39.773 AEST [2213] LOG:  listening on IPv4 address "127.0.0.1", port 7651
2022-04-07 12:31:39.777 AEST [2213] LOG:  listening on Unix socket "/tmp/.s.PGSQL.7651"
2022-04-07 12:31:39.785 AEST [2216] LOG:  database system was shut down at 2022-04-07 12:31:24 AEST
2022-04-07 12:31:39.793 AEST [2213] LOG:  database system is ready to accept connections
2022-04-07 12:31:50.756 AEST [2542] LOG:  !!>> Call AddSubscriptionRelState for subid=16391, relid=16384
2022-04-07 12:31:50.756 AEST [2542] STATEMENT:  create subscription sub12 connection 'port=7652' publication pub2 with (subscribe_local_only=true,copy_data=force);
2022-04-07 12:31:50.775 AEST [2544] LOG:  logical replication apply worker for subscription "sub12" has started
2022-04-07 12:31:50.787 AEST [2549] LOG:  logical replication table synchronization worker for subscription "sub12", table "tbl" has started
2022-04-07 12:31:50.817 AEST [2548] LOG:  logical decoding found consistent point at 0/150F168
2022-04-07 12:31:50.817 AEST [2548] DETAIL:  There are no running transactions.
2022-04-07 12:31:50.817 AEST [2548] STATEMENT:  CREATE_REPLICATION_SLOT "sub21" LOGICAL pgoutput (SNAPSHOT 'nothing')
2022-04-07 12:31:50.838 AEST [2553] LOG:  starting logical decoding for slot "sub21"
2022-04-07 12:31:50.838 AEST [2553] DETAIL:  Streaming transactions committing after 0/150F1A0, reading WAL from 0/150F168.
2022-04-07 12:31:50.838 AEST [2553] STATEMENT:  START_REPLICATION SLOT "sub21" LOGICAL 0/0 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:31:50.838 AEST [2553] LOG:  logical decoding found consistent point at 0/150F168
2022-04-07 12:31:50.838 AEST [2553] DETAIL:  There are no running transactions.
2022-04-07 12:31:50.838 AEST [2553] STATEMENT:  START_REPLICATION SLOT "sub21" LOGICAL 0/0 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:31:50.870 AEST [2555] LOG:  logical decoding found consistent point at 0/150F1A0
2022-04-07 12:31:50.870 AEST [2555] DETAIL:  There are no running transactions.
2022-04-07 12:31:50.870 AEST [2555] STATEMENT:  CREATE_REPLICATION_SLOT "pg_16391_sync_16384_7083683916948375379" LOGICAL pgoutput (SNAPSHOT 'use')
2022-04-07 12:31:50.895 AEST [2555] LOG:  starting logical decoding for slot "pg_16391_sync_16384_7083683916948375379"
2022-04-07 12:31:50.895 AEST [2555] DETAIL:  Streaming transactions committing after 0/150F1D8, reading WAL from 0/150F1A0.
2022-04-07 12:31:50.895 AEST [2555] STATEMENT:  START_REPLICATION SLOT "pg_16391_sync_16384_7083683916948375379" LOGICAL 0/150F1D8 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:31:50.895 AEST [2555] LOG:  logical decoding found consistent point at 0/150F1A0
2022-04-07 12:31:50.895 AEST [2555] DETAIL:  There are no running transactions.
2022-04-07 12:31:50.895 AEST [2555] STATEMENT:  START_REPLICATION SLOT "pg_16391_sync_16384_7083683916948375379" LOGICAL 0/150F1D8 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:31:51.050 AEST [2549] LOG:  logical replication table synchronization worker for subscription "sub12", table "tbl" has finished
2022-04-07 12:32:11.045 AEST [3062] LOG:  !!>> Call AddSubscriptionRelState for subid=16392, relid=16384
2022-04-07 12:32:11.045 AEST [3062] STATEMENT:  create subscription sub13 connection 'port=7653' publication pub3 with (subscribe_local_only=true,copy_data=force);
2022-04-07 12:32:11.072 AEST [3064] LOG:  logical replication apply worker for subscription "sub13" has started
2022-04-07 12:32:11.085 AEST [3069] LOG:  logical replication table synchronization worker for subscription "sub13", table "tbl" has started
2022-04-07 12:32:11.177 AEST [3069] LOG:  logical replication table synchronization worker for subscription "sub13", table "tbl" has finished
2022-04-07 12:32:16.214 AEST [3205] LOG:  logical decoding found consistent point at 0/1510840
2022-04-07 12:32:16.214 AEST [3205] DETAIL:  There are no running transactions.
2022-04-07 12:32:16.214 AEST [3205] STATEMENT:  CREATE_REPLICATION_SLOT "sub31" LOGICAL pgoutput (SNAPSHOT 'nothing')
2022-04-07 12:32:16.237 AEST [3213] LOG:  starting logical decoding for slot "sub31"
2022-04-07 12:32:16.237 AEST [3213] DETAIL:  Streaming transactions committing after 0/1510878, reading WAL from 0/1510840.
2022-04-07 12:32:16.237 AEST [3213] STATEMENT:  START_REPLICATION SLOT "sub31" LOGICAL 0/0 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:32:16.237 AEST [3213] LOG:  logical decoding found consistent point at 0/1510840
2022-04-07 12:32:16.237 AEST [3213] DETAIL:  There are no running transactions.
2022-04-07 12:32:16.237 AEST [3213] STATEMENT:  START_REPLICATION SLOT "sub31" LOGICAL 0/0 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:32:16.271 AEST [3215] LOG:  logical decoding found consistent point at 0/1510878
2022-04-07 12:32:16.271 AEST [3215] DETAIL:  There are no running transactions.
2022-04-07 12:32:16.271 AEST [3215] STATEMENT:  CREATE_REPLICATION_SLOT "pg_16393_sync_16384_7083683934129563568" LOGICAL pgoutput (SNAPSHOT 'use')
2022-04-07 12:32:16.301 AEST [3215] LOG:  starting logical decoding for slot "pg_16393_sync_16384_7083683934129563568"
2022-04-07 12:32:16.301 AEST [3215] DETAIL:  Streaming transactions committing after 0/15108B0, reading WAL from 0/1510878.
2022-04-07 12:32:16.301 AEST [3215] STATEMENT:  START_REPLICATION SLOT "pg_16393_sync_16384_7083683934129563568" LOGICAL 0/15108B0 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:32:16.301 AEST [3215] LOG:  logical decoding found consistent point at 0/1510878
2022-04-07 12:32:16.301 AEST [3215] DETAIL:  There are no running transactions.
2022-04-07 12:32:16.301 AEST [3215] STATEMENT:  START_REPLICATION SLOT "pg_16393_sync_16384_7083683934129563568" LOGICAL 0/15108B0 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:32:37.313 AEST [3692] LOG:  !!>> Call AddSubscriptionRelState for subid=16393, relid=16384
2022-04-07 12:32:37.313 AEST [3692] STATEMENT:  create subscription sub14 connection 'port=7654' publication pub4 with (subscribe_local_only=true,copy_data=force);
2022-04-07 12:32:37.340 AEST [3700] LOG:  logical replication apply worker for subscription "sub14" has started
2022-04-07 12:32:37.354 AEST [3706] LOG:  logical replication table synchronization worker for subscription "sub14", table "tbl" has started
2022-04-07 12:32:37.419 AEST [3706] LOG:  logical replication table synchronization worker for subscription "sub14", table "tbl" has finished
2022-04-07 12:32:42.699 AEST [3815] LOG:  logical decoding found consistent point at 0/1511890
2022-04-07 12:32:42.699 AEST [3815] DETAIL:  There are no running transactions.
2022-04-07 12:32:42.699 AEST [3815] STATEMENT:  CREATE_REPLICATION_SLOT "sub41" LOGICAL pgoutput (SNAPSHOT 'nothing')
2022-04-07 12:32:42.719 AEST [3818] LOG:  starting logical decoding for slot "sub41"
2022-04-07 12:32:42.719 AEST [3818] DETAIL:  Streaming transactions committing after 0/15118C8, reading WAL from 0/1511890.
2022-04-07 12:32:42.719 AEST [3818] STATEMENT:  START_REPLICATION SLOT "sub41" LOGICAL 0/0 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:32:42.720 AEST [3818] LOG:  logical decoding found consistent point at 0/1511890
2022-04-07 12:32:42.720 AEST [3818] DETAIL:  There are no running transactions.
2022-04-07 12:32:42.720 AEST [3818] STATEMENT:  START_REPLICATION SLOT "sub41" LOGICAL 0/0 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:32:42.750 AEST [3820] LOG:  logical decoding found consistent point at 0/15118C8
2022-04-07 12:32:42.750 AEST [3820] DETAIL:  There are no running transactions.
2022-04-07 12:32:42.750 AEST [3820] STATEMENT:  CREATE_REPLICATION_SLOT "pg_16393_sync_16384_7083683948101445629" LOGICAL pgoutput (SNAPSHOT 'use')
2022-04-07 12:32:42.777 AEST [3820] LOG:  starting logical decoding for slot "pg_16393_sync_16384_7083683948101445629"
2022-04-07 12:32:42.777 AEST [3820] DETAIL:  Streaming transactions committing after 0/1511900, reading WAL from 0/15118C8.
2022-04-07 12:32:42.777 AEST [3820] STATEMENT:  START_REPLICATION SLOT "pg_16393_sync_16384_7083683948101445629" LOGICAL 0/1511900 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:32:42.777 AEST [3820] LOG:  logical decoding found consistent point at 0/15118C8
2022-04-07 12:32:42.777 AEST [3820] DETAIL:  There are no running transactions.
2022-04-07 12:32:42.777 AEST [3820] STATEMENT:  START_REPLICATION SLOT "pg_16393_sync_16384_7083683948101445629" LOGICAL 0/1511900 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:33:03.025 AEST [4446] LOG:  !!>> Call AddSubscriptionRelState for subid=16394, relid=16384
2022-04-07 12:33:03.025 AEST [4446] STATEMENT:  create subscription sub15 connection 'port=7655' publication pub5 with (subscribe_local_only=true,copy_data=force);
2022-04-07 12:33:03.050 AEST [4450] LOG:  logical replication apply worker for subscription "sub15" has started
2022-04-07 12:33:03.064 AEST [4455] LOG:  logical replication table synchronization worker for subscription "sub15", table "tbl" has started
2022-04-07 12:33:03.153 AEST [4455] LOG:  logical replication table synchronization worker for subscription "sub15", table "tbl" has finished
2022-04-07 12:33:13.760 AEST [4816] LOG:  logical decoding found consistent point at 0/15129C0
2022-04-07 12:33:13.760 AEST [4816] DETAIL:  There are no running transactions.
2022-04-07 12:33:13.760 AEST [4816] STATEMENT:  CREATE_REPLICATION_SLOT "sub51" LOGICAL pgoutput (SNAPSHOT 'nothing')
2022-04-07 12:33:13.780 AEST [4819] LOG:  starting logical decoding for slot "sub51"
2022-04-07 12:33:13.780 AEST [4819] DETAIL:  Streaming transactions committing after 0/15129F8, reading WAL from 0/15129C0.
2022-04-07 12:33:13.780 AEST [4819] STATEMENT:  START_REPLICATION SLOT "sub51" LOGICAL 0/0 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:33:13.780 AEST [4819] LOG:  logical decoding found consistent point at 0/15129C0
2022-04-07 12:33:13.780 AEST [4819] DETAIL:  There are no running transactions.
2022-04-07 12:33:13.780 AEST [4819] STATEMENT:  START_REPLICATION SLOT "sub51" LOGICAL 0/0 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:33:14.321 AEST [4821] LOG:  logical decoding found consistent point at 0/15129F8
2022-04-07 12:33:14.321 AEST [4821] DETAIL:  There are no running transactions.
2022-04-07 12:33:14.321 AEST [4821] STATEMENT:  CREATE_REPLICATION_SLOT "pg_16393_sync_16384_7083683962603460718" LOGICAL pgoutput (SNAPSHOT 'use')
2022-04-07 12:33:14.358 AEST [4821] LOG:  starting logical decoding for slot "pg_16393_sync_16384_7083683962603460718"
2022-04-07 12:33:14.358 AEST [4821] DETAIL:  Streaming transactions committing after 0/1512A30, reading WAL from 0/15129F8.
2022-04-07 12:33:14.358 AEST [4821] STATEMENT:  START_REPLICATION SLOT "pg_16393_sync_16384_7083683962603460718" LOGICAL 0/1512A30 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:33:14.358 AEST [4821] LOG:  logical decoding found consistent point at 0/15129F8
2022-04-07 12:33:14.358 AEST [4821] DETAIL:  There are no running transactions.
2022-04-07 12:33:14.358 AEST [4821] STATEMENT:  START_REPLICATION SLOT "pg_16393_sync_16384_7083683962603460718" LOGICAL 0/1512A30 (proto_version '3', subscribe_local_only 'on', publication_names '"pub1"')
2022-04-07 12:36:39.818 AEST [2214] LOG:  checkpoint starting: time
2022-04-07 12:36:46.335 AEST [2214] LOG:  checkpoint complete: wrote 66 buffers (0.4%); 0 WAL file(s) added, 0 removed, 0 recycled; write=6.468 s, sync=0.036 s, total=6.517 s; sync files=48, longest=0.009 s, average=0.001 s; distance=152 kB, estimate=152 kB