# Checking port 58419 # Found port 58419 Name: node_A Data directory: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_A_data/pgdata Backup directory: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_A_data/backup Archive directory: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_A_data/archives Connection string: port=58419 host=/tmp/w3dItm22gp Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_A.log [11:18:59.570](0.030s) # initializing database system by copying initdb template # Running: cp -RPp /tmp/cirrus-ci-build/build/tmp_install/initdb-template /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_A_data/pgdata # Running: /tmp/cirrus-ci-build/build/src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_A_data/pgdata ### Starting node "node_A" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_A_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/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 31806 # Checking port 58420 # Found port 58420 Name: node_B Data directory: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_B_data/pgdata Backup directory: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_B_data/backup Archive directory: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_B_data/archives Connection string: port=58420 host=/tmp/w3dItm22gp Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_B.log [11:18:59.821](0.251s) # initializing database system by copying initdb template # Running: cp -RPp /tmp/cirrus-ci-build/build/tmp_install/initdb-template /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_B_data/pgdata # Running: /tmp/cirrus-ci-build/build/src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_B_data/pgdata ### Starting node "node_B" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_B_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/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 31905 # Checking port 58421 # Found port 58421 Name: node_C Data directory: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_C_data/pgdata Backup directory: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_C_data/backup Archive directory: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_C_data/archives Connection string: port=58421 host=/tmp/w3dItm22gp Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_C.log [11:19:00.002](0.181s) # initializing database system by copying initdb template # Running: cp -RPp /tmp/cirrus-ci-build/build/tmp_install/initdb-template /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_C_data/pgdata # Running: /tmp/cirrus-ci-build/build/src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_C_data/pgdata ### Starting node "node_C" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/data/t_022_twophase_cascade_node_C_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/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 31977 #### Begin standard error psql::5: WARNING: subscriptions created by regression test cases should have names starting with "regress_" psql::5: NOTICE: created replication slot "tap_sub_b" on publisher #### End standard error #### Begin standard error psql::5: WARNING: subscriptions created by regression test cases should have names starting with "regress_" 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/154C720 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/154EDA8 on node_B done [11:19:00.783](0.781s) ok 1 - Cascade setup is complete Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154C8A8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/154EF30 on node_B done [11:19:01.110](0.327s) ok 2 - transaction is prepared on subscriber B [11:19:01.127](0.018s) ok 3 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154C8F8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/154EF30 on node_B done [11:19:01.243](0.116s) ok 4 - Row inserted via 2PC has committed on subscriber B [11:19:01.265](0.022s) ok 5 - Row inserted via 2PC has committed on subscriber C [11:19:01.283](0.018s) ok 6 - transaction is committed on subscriber B [11:19:01.312](0.029s) ok 7 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154CA80 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/154EF88 on node_B done [11:19:01.425](0.113s) ok 8 - transaction is prepared on subscriber B [11:19:01.440](0.015s) ok 9 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154CAD0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/154F168 on node_B done [11:19:01.516](0.075s) ok 10 - Row inserted via 2PC is not present on subscriber B [11:19:01.526](0.010s) ok 11 - Row inserted via 2PC is not present on subscriber C [11:19:01.546](0.020s) ok 12 - transaction is ended on subscriber B [11:19:01.564](0.017s) ok 13 - transaction is ended on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154CCF0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/154F2F0 on node_B done [11:19:01.771](0.208s) ok 14 - transaction is prepared on subscriber B [11:19:01.807](0.036s) ok 15 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154CD28 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/154F348 on node_B done [11:19:01.976](0.169s) ok 16 - transaction is ended on subscriber B [11:19:02.002](0.026s) ok 17 - transaction is ended on subscriber C [11:19:02.025](0.023s) ok 18 - Rows committed are present on subscriber B [11:19:02.053](0.028s) ok 19 - Rows committed are present on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16C7280 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1730000 on node_B done [11:19:04.331](2.279s) ok 20 - transaction is prepared on subscriber B [11:19:04.348](0.017s) not ok 21 - transaction is prepared on subscriber C [11:19:04.349](0.000s) # Failed test 'transaction is prepared on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 325. [11:19:04.349](0.000s) # got: '0' # expected: '1' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16C72C8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1732148 on node_B done [11:19:04.496](0.147s) ok 22 - Rows inserted by 2PC have committed on subscriber B, and extra columns have local defaults [11:19:04.525](0.029s) ok 23 - Rows inserted by 2PC have committed on subscriber C, and extra columns have local defaults [11:19:04.545](0.020s) ok 24 - transaction is committed on subscriber B [11:19:04.560](0.015s) ok 25 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/186CE30 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1796FA8 on node_B done [11:19:05.370](0.811s) ok 26 - transaction is prepared on subscriber B [11:19:05.397](0.026s) not ok 27 - transaction is prepared on subscriber C [11:19:05.399](0.002s) # Failed test 'transaction is prepared on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 390. [11:19:05.399](0.000s) # got: '0' # expected: '1' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/186CE68 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/179DCE0 on node_B done [11:19:05.820](0.421s) ok 28 - transaction is ended on subscriber B [11:19:05.838](0.018s) ok 29 - transaction is ended on subscriber C [11:19:05.873](0.035s) ok 30 - Rows committed are present on subscriber B [11:19:05.895](0.023s) ok 31 - Rows committed are present on subscriber B [11:19:05.913](0.018s) ok 32 - Rows committed are present on subscriber C [11:19:05.926](0.013s) 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 [11:19:05.964](0.039s) ok 34 - check subscription was dropped on subscriber node C [11:19:05.976](0.012s) ok 35 - check subscription relation status was dropped on subscriber node C [11:19:05.987](0.011s) ok 36 - check replication origin was dropped on subscriber node C [11:19:06.010](0.023s) 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 [11:19:06.062](0.052s) ok 38 - check subscription was dropped on subscriber node B [11:19:06.074](0.012s) ok 39 - check subscription relation status was dropped on subscriber node B [11:19:06.085](0.011s) ok 40 - check replication origin was dropped on subscriber node B [11:19:06.099](0.014s) 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/build/testrun/subscription/022_twophase_cascade/data/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/build/testrun/subscription/022_twophase_cascade/data/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/build/testrun/subscription/022_twophase_cascade/data/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" [11:19:06.417](0.318s) 1..41 [11:19:06.420](0.003s) # Looks like you failed 2 tests of 41.