# Checking port 57456 # Found port 57456 Name: node_A Data directory: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_A_data/pgdata Backup directory: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_A_data/backup Archive directory: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_A_data/archives Connection string: port=57456 host=/tmp/eH87OnMTp7 Log file: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/log/022_twophase_cascade_node_A.log [07:31:05.130](0.014s) # initializing database system by copying initdb template # Running: cp -RPp /tmp/cirrus-ci-build/tmp_install/initdb-template /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_A_data/pgdata # Running: /tmp/cirrus-ci-build/src/test/subscription/../../../src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_A_data/pgdata ### Starting node "node_A" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_A_data/pgdata -l /tmp/cirrus-ci-build/src/test/subscription/tmp_check/log/022_twophase_cascade_node_A.log -o --cluster-name=node_A start waiting for server to start.... done server started # Postmaster PID for node "node_A" is 40844 # Checking port 57457 # Found port 57457 Name: node_B Data directory: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_B_data/pgdata Backup directory: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_B_data/backup Archive directory: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_B_data/archives Connection string: port=57457 host=/tmp/eH87OnMTp7 Log file: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/log/022_twophase_cascade_node_B.log [07:31:05.315](0.185s) # initializing database system by copying initdb template # Running: cp -RPp /tmp/cirrus-ci-build/tmp_install/initdb-template /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_B_data/pgdata # Running: /tmp/cirrus-ci-build/src/test/subscription/../../../src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_B_data/pgdata ### Starting node "node_B" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_B_data/pgdata -l /tmp/cirrus-ci-build/src/test/subscription/tmp_check/log/022_twophase_cascade_node_B.log -o --cluster-name=node_B start waiting for server to start.... done server started # Postmaster PID for node "node_B" is 40861 # Checking port 57458 # Found port 57458 Name: node_C Data directory: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_C_data/pgdata Backup directory: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_C_data/backup Archive directory: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_C_data/archives Connection string: port=57458 host=/tmp/eH87OnMTp7 Log file: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/log/022_twophase_cascade_node_C.log [07:31:05.508](0.193s) # initializing database system by copying initdb template # Running: cp -RPp /tmp/cirrus-ci-build/tmp_install/initdb-template /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_C_data/pgdata # Running: /tmp/cirrus-ci-build/src/test/subscription/../../../src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_C_data/pgdata ### Starting node "node_C" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_C_data/pgdata -l /tmp/cirrus-ci-build/src/test/subscription/tmp_check/log/022_twophase_cascade_node_C.log -o --cluster-name=node_C start waiting for server to start.... done server started # Postmaster PID for node "node_C" is 40879 #### Begin standard error psql::5: NOTICE: created replication slot "tap_sub_b" on publisher #### End standard error #### Begin standard error psql::5: NOTICE: created replication slot "tap_sub_c" on publisher #### End standard error Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1553A18 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1556050 on node_B done [07:31:06.128](0.620s) ok 1 - Cascade setup is complete Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1553BA0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1556050 on node_B done [07:31:06.257](0.128s) ok 2 - transaction is prepared on subscriber B [07:31:06.274](0.017s) ok 3 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1553BF0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15561D8 on node_B done [07:31:06.401](0.127s) ok 4 - Row inserted via 2PC has committed on subscriber B [07:31:06.418](0.017s) not ok 5 - Row inserted via 2PC has committed on subscriber C [07:31:06.418](0.000s) [07:31:06.418](0.000s) # Failed test 'Row inserted via 2PC has committed on subscriber C' # at t/022_twophase_cascade.pl line 156. [07:31:06.419](0.000s) # got: '0' # expected: '1' [07:31:06.438](0.019s) ok 6 - transaction is committed on subscriber B [07:31:06.458](0.020s) ok 7 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1553D78 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1556230 on node_B done [07:31:06.600](0.143s) ok 8 - transaction is prepared on subscriber B [07:31:06.617](0.017s) ok 9 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1553DC8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1556410 on node_B done [07:31:06.746](0.129s) ok 10 - Row inserted via 2PC is not present on subscriber B [07:31:06.763](0.017s) ok 11 - Row inserted via 2PC is not present on subscriber C [07:31:06.785](0.022s) ok 12 - transaction is ended on subscriber B [07:31:06.805](0.019s) ok 13 - transaction is ended on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1553FE8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1556598 on node_B done [07:31:06.938](0.133s) ok 14 - transaction is prepared on subscriber B [07:31:06.956](0.018s) ok 15 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1554038 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15565F0 on node_B done [07:31:07.088](0.132s) ok 16 - transaction is ended on subscriber B [07:31:07.106](0.017s) ok 17 - transaction is ended on subscriber C [07:31:07.123](0.018s) ok 18 - Rows committed are present on subscriber B [07:31:07.141](0.018s) ok 19 - Rows committed are present on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16CE590 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1730000 on node_B done [07:31:07.690](0.549s) ok 20 - transaction is prepared on subscriber B [07:31:07.707](0.016s) not ok 21 - transaction is prepared on subscriber C [07:31:07.707](0.000s) [07:31:07.707](0.000s) # Failed test 'transaction is prepared on subscriber C' # at t/022_twophase_cascade.pl line 325. [07:31:07.707](0.000s) # got: '0' # expected: '1' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16CE5D8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17393D8 on node_B done [07:31:07.943](0.236s) ok 22 - Rows inserted by 2PC have committed on subscriber B, and extra columns have local defaults [07:31:07.960](0.017s) ok 23 - Rows inserted by 2PC have committed on subscriber C, and extra columns have local defaults [07:31:07.977](0.016s) ok 24 - transaction is committed on subscriber B [07:31:07.994](0.017s) ok 25 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1874140 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17A0000 on node_B done [07:31:08.459](0.465s) ok 26 - transaction is prepared on subscriber B [07:31:08.476](0.017s) not ok 27 - transaction is prepared on subscriber C [07:31:08.476](0.000s) [07:31:08.476](0.000s) # Failed test 'transaction is prepared on subscriber C' # at t/022_twophase_cascade.pl line 390. [07:31:08.476](0.000s) # got: '0' # expected: '1' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1874178 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17A4F88 on node_B done [07:31:08.598](0.121s) ok 28 - transaction is ended on subscriber B [07:31:08.615](0.017s) not ok 29 - transaction is ended on subscriber C [07:31:08.615](0.000s) [07:31:08.615](0.000s) # Failed test 'transaction is ended on subscriber C' # at t/022_twophase_cascade.pl line 404. [07:31:08.615](0.000s) # got: '1' # expected: '0' [07:31:08.632](0.017s) ok 30 - Rows committed are present on subscriber B [07:31:08.649](0.016s) ok 31 - Rows committed are present on subscriber B [07:31:08.665](0.016s) ok 32 - Rows committed are present on subscriber C [07:31:08.680](0.015s) ok 33 - Rows committed are present on subscriber C #### Begin standard error psql::1: NOTICE: dropped replication slot "tap_sub_c" on publisher #### End standard error [07:31:08.725](0.045s) ok 34 - check subscription was dropped on subscriber node C [07:31:08.740](0.015s) ok 35 - check subscription relation status was dropped on subscriber node C [07:31:08.754](0.014s) ok 36 - check replication origin was dropped on subscriber node C [07:31:08.772](0.018s) ok 37 - check replication slot was dropped on publisher node B #### Begin standard error psql::1: NOTICE: dropped replication slot "tap_sub_b" on publisher #### End standard error [07:31:08.820](0.048s) ok 38 - check subscription was dropped on subscriber node B [07:31:08.833](0.013s) ok 39 - check subscription relation status was dropped on subscriber node B [07:31:08.847](0.014s) ok 40 - check replication origin was dropped on subscriber node B [07:31:08.864](0.017s) ok 41 - check replication slot was dropped on publisher node A ### Stopping node "node_C" using mode fast # Running: pg_ctl -D /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_C_data/pgdata -m fast stop waiting for server to shut down.... done server stopped # No postmaster PID for node "node_C" ### Stopping node "node_B" using mode fast # Running: pg_ctl -D /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_B_data/pgdata -m fast stop waiting for server to shut down.... done server stopped # No postmaster PID for node "node_B" ### Stopping node "node_A" using mode fast # Running: pg_ctl -D /tmp/cirrus-ci-build/src/test/subscription/tmp_check/t_022_twophase_cascade_node_A_data/pgdata -m fast stop waiting for server to shut down.... done server stopped # No postmaster PID for node "node_A" [07:31:09.177](0.313s) 1..41 [07:31:09.179](0.002s) # Looks like you failed 4 tests of 41.