# Checking port 53109 # Found port 53109 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=53109 host=/tmp/eajNyM3CDa Log file: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/log/022_twophase_cascade_node_A.log [07:14:47.660](0.012s) # 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 54806 # Checking port 53110 # Found port 53110 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=53110 host=/tmp/eajNyM3CDa Log file: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/log/022_twophase_cascade_node_B.log [07:14:47.836](0.176s) # 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 54819 # Checking port 53111 # Found port 53111 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=53111 host=/tmp/eajNyM3CDa Log file: /tmp/cirrus-ci-build/src/test/subscription/tmp_check/log/022_twophase_cascade_node_C.log [07:14:48.013](0.177s) # 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 54832 #### 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/1551FC8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15545F0 on node_B done [07:14:48.547](0.534s) ok 1 - Cascade setup is complete Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1552168 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15545F0 on node_B done [07:14:48.654](0.107s) ok 2 - transaction is prepared on subscriber B [07:14:48.669](0.015s) ok 3 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/15521B8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15547D0 on node_B done [07:14:48.770](0.101s) ok 4 - Row inserted via 2PC has committed on subscriber B [07:14:48.782](0.013s) ok 5 - Row inserted via 2PC has committed on subscriber C [07:14:48.796](0.014s) ok 6 - transaction is committed on subscriber B [07:14:48.811](0.014s) ok 7 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1552340 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15547D0 on node_B done [07:14:48.912](0.102s) ok 8 - transaction is prepared on subscriber B [07:14:48.927](0.014s) ok 9 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1552390 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15549B0 on node_B done [07:14:49.025](0.099s) ok 10 - Row inserted via 2PC is not present on subscriber B [07:14:49.038](0.012s) ok 11 - Row inserted via 2PC is not present on subscriber C [07:14:49.052](0.015s) ok 12 - transaction is ended on subscriber B [07:14:49.067](0.015s) ok 13 - transaction is ended on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/15525B0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1554B38 on node_B done [07:14:49.166](0.099s) ok 14 - transaction is prepared on subscriber B [07:14:49.181](0.014s) ok 15 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/15525E8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1554B38 on node_B done [07:14:49.286](0.105s) ok 16 - transaction is ended on subscriber B [07:14:49.301](0.015s) not ok 17 - transaction is ended on subscriber C [07:14:49.301](0.000s) [07:14:49.301](0.000s) # Failed test 'transaction is ended on subscriber C' # at t/022_twophase_cascade.pl line 249. [07:14:49.301](0.000s) # got: '1' # expected: '0' [07:14:49.314](0.013s) ok 18 - Rows committed are present on subscriber B [07:14:49.327](0.013s) not ok 19 - Rows committed are present on subscriber C [07:14:49.327](0.000s) [07:14:49.327](0.000s) # Failed test 'Rows committed are present on subscriber C' # at t/022_twophase_cascade.pl line 259. [07:14:49.327](0.000s) # got: '' # expected: '21' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16CCB40 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1737978 on node_B done [07:14:50.054](0.727s) ok 20 - transaction is prepared on subscriber B [07:14:50.069](0.015s) ok 21 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16CCB88 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17379D0 on node_B done [07:14:50.171](0.102s) ok 22 - Rows inserted by 2PC have committed on subscriber B, and extra columns have local defaults [07:14:50.186](0.015s) ok 23 - Rows inserted by 2PC have committed on subscriber C, and extra columns have local defaults [07:14:50.201](0.015s) ok 24 - transaction is committed on subscriber B [07:14:50.215](0.014s) ok 25 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/18726E8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1794000 on node_B done [07:14:50.653](0.438s) ok 26 - transaction is prepared on subscriber B [07:14:50.667](0.014s) ok 27 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1872720 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17A3420 on node_B done [07:14:50.771](0.104s) ok 28 - transaction is ended on subscriber B [07:14:50.785](0.014s) ok 29 - transaction is ended on subscriber C [07:14:50.799](0.013s) ok 30 - Rows committed are present on subscriber B [07:14:50.811](0.013s) ok 31 - Rows committed are present on subscriber B [07:14:50.825](0.014s) ok 32 - Rows committed are present on subscriber C [07:14:50.840](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:14:50.883](0.043s) ok 34 - check subscription was dropped on subscriber node C [07:14:50.896](0.013s) ok 35 - check subscription relation status was dropped on subscriber node C [07:14:50.908](0.012s) ok 36 - check replication origin was dropped on subscriber node C [07:14:50.923](0.015s) 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:14:50.964](0.041s) ok 38 - check subscription was dropped on subscriber node B [07:14:50.976](0.012s) ok 39 - check subscription relation status was dropped on subscriber node B [07:14:50.988](0.012s) ok 40 - check replication origin was dropped on subscriber node B [07:14:51.002](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/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:14:51.313](0.311s) 1..41 [07:14:51.315](0.001s) # Looks like you failed 2 tests of 41.