BUG #17802: PGLogical getting Terminated - Mailing list pgsql-bugs
From | PG Bug reporting form |
---|---|
Subject | BUG #17802: PGLogical getting Terminated |
Date | |
Msg-id | 17802-e7555b863e9906d4@postgresql.org Whole thread Raw |
List | pgsql-bugs |
The following bug has been logged on the website: Bug reference: 17802 Logged by: Yogesh Pingle Email address: yp311092@gmail.com PostgreSQL version: 14.1 Operating system: RDS Linux Description: Hello Team, Hope you are doing well !! I am trying to configure the PGLogical to migrate the data from the Non-Partition table to the Partition table in RDS DB Version 14.1. Initial copy is working successfully however whenever I am adding a new row on the Source then on Target Side the instance is getting terminated with the below error . The table Setup is as follows : Source : CREATE TABLE partition ( city_id int not null primary key , logdate date not null ); insert into partition values(1,'2023-01-12'); insert into partition values(2,'2023-01-13'); We can INSERT this row once the replication has been started: insert into partition values(4,'2023-02-11'); Target : CREATE TABLE partition ( city_id int not null , logdate date not null, PRIMARY KEY (city_id,logdate) )PARTITION BY RANGE (logdate); Followed the below Steps : Source : CREATE EXTENSION pglogical; select pglogical.create_node(node_name := 'source_test',dsn := ' port=5432 sslmode=require dbname=partition user= password=); select pglogical.replication_set_add_table('default','public.partition',true, row_filter := ' logdate>=''2023-01-13'' '); Target : CREATE EXTENSION pglogical; select pglogical.create_node('target_test', 'host= port=5432 dbname=partition user= password=); select pglogical.create_subscription(subscription_name := 'test_sub',provider_dsn := 'host= port=5432 sslmode=require dbname=partition user= password=, synchronize_structure := false, synchronize_data := true); Error Source : '20401', pglogical_apply_pid '907') 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:DEBUG: sending replication keepalive 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:STATEMENT: START_REPLICATION SLOT "pgl_postgres_source_test_test_sub" LOGICAL 0/D0004A28 (expected_encoding 'UTF8', min_proto_version '1', max_proto_version '1', startup_params_format '1', "binary.want_internal_basetypes" '1', "binary.want_binary_basetypes" '1', "binary.basetypes_major_version" '1400', "binary.sizeof_datum" '8', "binary.sizeof_int" '4', "binary.sizeof_long" '8', "binary.bigendian" '0', "binary.float4_byval" '0', "binary.float8_byval" '1', "binary.integer_datetimes" '0', "hooks.setup_function" 'pglogical.pglogical_hooks_setup', "pglogical.forward_origins" '"all"', "pglogical.replication_set_names" '"default",default_insert_only,ddl_sql', "relmeta_cache_size" '-1', pg_version '140006', pglogical_version '2.4.1', pglogical_version_num '20401', pglogical_apply_pid '907') 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:LOG: could not receive data from client: Connection reset by peer 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:STATEMENT: START_REPLICATION SLOT "pgl_postgres_source_test_test_sub" LOGICAL 0/D0004A28 (expected_encoding 'UTF8', min_proto_version '1', max_proto_version '1', startup_params_format '1', "binary.want_internal_basetypes" '1', "binary.want_binary_basetypes" '1', "binary.basetypes_major_version" '1400', "binary.sizeof_datum" '8', "binary.sizeof_int" '4', "binary.sizeof_long" '8', "binary.bigendian" '0', "binary.float4_byval" '0', "binary.float8_byval" '1', "binary.integer_datetimes" '0', "hooks.setup_function" 'pglogical.pglogical_hooks_setup', "pglogical.forward_origins" '"all"', "pglogical.replication_set_names" '"default",default_insert_only,ddl_sql', "relmeta_cache_size" '-1', pg_version '140006', pglogical_version '2.4.1', pglogical_version_num '20401', pglogical_apply_pid '907') 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:LOG: unexpected EOF on standby connection 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:STATEMENT: START_REPLICATION SLOT "pgl_postgres_source_test_test_sub" LOGICAL 0/D0004A28 (expected_encoding 'UTF8', min_proto_version '1', max_proto_version '1', startup_params_format '1', "binary.want_internal_basetypes" '1', "binary.want_binary_basetypes" '1', "binary.basetypes_major_version" '1400', "binary.sizeof_datum" '8', "binary.sizeof_int" '4', "binary.sizeof_long" '8', "binary.bigendian" '0', "binary.float4_byval" '0', "binary.float8_byval" '1', "binary.integer_datetimes" '0', "hooks.setup_function" 'pglogical.pglogical_hooks_setup', "pglogical.forward_origins" '"all"', "pglogical.replication_set_names" '"default",default_insert_only,ddl_sql', "relmeta_cache_size" '-1', pg_version '140006', pglogical_version '2.4.1', pglogical_version_num '20401', pglogical_apply_pid '907') 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:DEBUG: shmem_exit(0): 8 on_shmem_exit callbacks to make 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:DEBUG: proc_exit(0): 3 callbacks to make 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:DEBUG: exit(0) 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make 2023-02-03 16:16:04 UTC:10.103.90.251(13324):repli_user@postgres:[935]:DEBUG: proc_exit(-1): 0 callbacks to make 2023-02-03 16:16:04 UTC::@:[368]:DEBUG: reaping dead processes 2023-02-03 16:16:04 UTC::@:[368]:DEBUG: server process (PID 935) exited with exit code 0 2023-02-03 16:16:04 UTC::@:[368]:DEBUG: forked new backend, pid=1063 socket=10 2023-02-03 16:16:04 UTC:10.103.90.251(24362):[unknown]@[unknown]:[1063]:DEBUG: SSL: handshake start: "before/accept initialization" 2023-02-03 16:16:04 UTC:10.103.90.251(24362):[unknown]@[unknown]:[1063]:DEBUG: SSL: accept loop: "before/accept initialization" 2023-02-03 16:16:04 UTC:10.103.90.251(24362):[unknown]@[unknown]:[1063]:DEBUG: SSL: accept exit (-1): "SSLv2/v3 read client hello A" 2023-02-03 16:16:04 UTC:10.103.90.251(24362):[unknown]@[unknown]:[1063]:DEBUG: SSL: accept loop: "SSLv3 read client hello A" 2023-02-03 16:16:04 UTC:10.103.90.251(24362):[unknown]@[unknown]:[1063]:DEBUG: SSL: accept loop: "SSLv3 write server hello A" 2023-02-03 16:16:04 UTC:10.103.90.251(24362):[unknown]@[unknown]:[1063]:DEBUG: SSL: accept loop: "SSLv3 write certificate A" 2023-02-03 16:16:04 UTC:10.103.90.251(24362):[unknown]@[unknown]:[1063]:DEBUG: SSL: accept loop: "SSLv3 write key exchange A" 2023-02-03 16:16:04 UTC:10.103.90.251(24362):[unknown]@[unknown]:[1063]:DEBUG: SSL: accept loop: "SSLv3 write certificate request A" Error Target : 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: starting background worker process "pglogical supervisor" 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: starting background worker process "logical replication launcher" 2023-02-03 16:16:06 UTC::@:[368]:LOG: database system is ready to accept connections 2023-02-03 16:16:06 UTC::@:[1277]:DEBUG: logical replication launcher started 2023-02-03 16:16:06 UTC::@:[1277]:DEBUG: InitPostgres 2023-02-03 16:16:06 UTC::@:[1277]:DEBUG: my backend ID is 1 2023-02-03 16:16:06 UTC::@:[1277]:DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[1277]:DEBUG: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[1277]:DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[1277]:DEBUG: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[1277]:DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[1277]:DEBUG: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[1276]:DEBUG: find_in_dynamic_libpath: trying "/rdsdbbin/postgres-14.6.R1/lib/pglogical" 2023-02-03 16:16:06 UTC::@:[1276]:DEBUG: find_in_dynamic_libpath: trying "/rdsdbbin/postgres-14.6.R1/lib/pglogical.so" 2023-02-03 16:16:06 UTC::@:[1276]:LOG: starting pglogical supervisor 2023-02-03 16:16:06 UTC::@:[1276]:DEBUG: InitPostgres 2023-02-03 16:16:06 UTC::@:[1276]:DEBUG: my backend ID is 2 2023-02-03 16:16:06 UTC::@:[1276]:DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[1276]:DEBUG: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[1276]:DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[1276]:DEBUG: registering pglogical manager process for database template1 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: registering background worker "pglogical manager 1" 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: starting background worker process "pglogical manager 1" 2023-02-03 16:16:06 UTC::@:[1272]:DEBUG: checkpointer updated shared memory configuration values 2023-02-03 16:16:06 UTC::@:[1278]:DEBUG: find_in_dynamic_libpath: trying "/rdsdbbin/postgres-14.6.R1/lib/pglogical" 2023-02-03 16:16:06 UTC::@:[1278]:DEBUG: find_in_dynamic_libpath: trying "/rdsdbbin/postgres-14.6.R1/lib/pglogical.so" 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1278]:DEBUG: manager worker [1278] attaching to slot 0 generation 1 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1278]:DEBUG: InitPostgres 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1278]:DEBUG: my backend ID is 3 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1278]:DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: reaping dead processes 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: unregistering background worker "pglogical manager 1" 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: background worker "pglogical manager 1" (PID 1278) exited with exit code 0 2023-02-03 16:16:06 UTC::@:[1276]:DEBUG: none worker at slot 0 exited before we noticed it started 2023-02-03 16:16:06 UTC::@:[1276]:DEBUG: registering pglogical manager process for database postgres 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: registering background worker "pglogical manager 14717" 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: starting background worker process "pglogical manager 14717" 2023-02-03 16:16:06 UTC::@:[1279]:DEBUG: find_in_dynamic_libpath: trying "/rdsdbbin/postgres-14.6.R1/lib/pglogical" 2023-02-03 16:16:06 UTC::@:[1279]:DEBUG: find_in_dynamic_libpath: trying "/rdsdbbin/postgres-14.6.R1/lib/pglogical.so" 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1279]:DEBUG: manager worker [1279] attaching to slot 0 generation 2 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1279]:DEBUG: InitPostgres 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1279]:DEBUG: my backend ID is 3 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1279]:DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: registering background worker "pglogical apply 14717:2769129391" 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: starting background worker process "pglogical apply 14717:2769129391" 2023-02-03 16:16:06 UTC::@:[1280]:DEBUG: find_in_dynamic_libpath: trying "/rdsdbbin/postgres-14.6.R1/lib/pglogical" 2023-02-03 16:16:06 UTC::@:[1280]:DEBUG: find_in_dynamic_libpath: trying "/rdsdbbin/postgres-14.6.R1/lib/pglogical.so" 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1280]:DEBUG: apply worker [1280] attaching to slot 1 generation 1 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1280]:DEBUG: InitPostgres 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1280]:DEBUG: my backend ID is 4 2023-02-03 16:16:06 UTC::[unknown]@[unknown]:[1280]:DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: reaping dead processes 2023-02-03 16:16:06 UTC::@:[368]:LOG: background worker "pglogical apply 14717:2769129391" (PID 1280) was terminated by signal 11: Segmentation fault 2023-02-03 16:16:06 UTC::@:[368]:LOG: terminating any other active server processes 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: sending SIGQUIT to process 1279 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: sending SIGQUIT to process 1276 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: sending SIGQUIT to process 1277 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: sending SIGQUIT to process 1273 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: sending SIGQUIT to process 1272 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: sending SIGQUIT to process 1274 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: sending SIGQUIT to process 1275 2023-02-03 16:16:06 UTC::@:[1275]:DEBUG: writing stats file "pg_stat/global.stat" 2023-02-03 16:16:06 UTC::@:[1275]:DEBUG: writing stats file "pg_stat/db_1.stat" 2023-02-03 16:16:06 UTC::@:[1275]:DEBUG: removing temporary stats file "/rdsdbdata/db/pg_stat_tmp/db_1.stat" 2023-02-03 16:16:06 UTC::@:[1275]:DEBUG: writing stats file "pg_stat/db_0.stat" 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: reaping dead processes 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: reaping dead processes 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: reaping dead processes 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: reaping dead processes 2023-02-03 16:16:06 UTC::@:[1275]:DEBUG: removing temporary stats file "/rdsdbdata/db/pg_stat_tmp/db_0.stat" 2023-02-03 16:16:06 UTC::@:[1275]:DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make 2023-02-03 16:16:06 UTC::@:[1275]:DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make 2023-02-03 16:16:06 UTC::@:[1275]:DEBUG: proc_exit(-1): 0 callbacks to make 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: reaping dead processes 2023-02-03 16:16:06 UTC::@:[368]:LOG: all server processes terminated; reinitializing 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: unregistering background worker "pglogical apply 14717:2769129391" 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: unregistering background worker "pglogical manager 14717" 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: shmem_exit(1): 0 before_shmem_exit callbacks to make 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: shmem_exit(1): 6 on_shmem_exit callbacks to make 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: cleaning up dynamic shared memory control segment with ID 541695338 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: invoking IpcMemoryCreate(size=2182676480) 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: dynamic shared memory system will support 4494 segments 2023-02-03 16:16:06 UTC::@:[368]:DEBUG: created dynamic shared memory control segment 2891381378 (179776 bytes) 2023-02-03 16:16:06 UTC::@:[1281]:LOG: database system was interrupted; last known up at 2023-02-03 16:16:06 UTC 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: removing all temporary WAL segments 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: checkpoint record is at 0/94004390 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: redo record is at 0/94004390; shutdown true 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: next transaction ID: 1079; next OID: 25496 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: next MultiXactId: 1; next MultiXactOffset: 0 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: oldest unfrozen transaction ID: 727, in database 1 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: oldest MultiXactId: 1, in database 1 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: commit timestamp Xid oldest/newest: 0/0 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: transaction ID wrap limit is 2147484374, limited by database with OID 1 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: MultiXactId wrap limit is 2147483648, limited by database with OID 1 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: starting up replication slots 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: starting up replication origin progress state 2023-02-03 16:16:06 UTC::@:[1281]:LOG: recovered replication state of node 1 to 0/D0004A28 2023-02-03 16:16:06 UTC::@:[1281]:LOG: database system was not properly shut down; automatic recovery in progress 2023-02-03 16:16:06 UTC::@:[1281]:DEBUG: resetting unlogged relations: cleanup 1 init 0 2023-02-03 16:16:06 UTC::@:[1281]:LOG: invalid record length at 0/94004408: wanted 24, got 0 2023-02-03 16:16:06 UTC::@:[1281]:LOG: redo is not required 2023-02-03 16:16:06 UTC::@
pgsql-bugs by date: