# Checking port 52795 # Found port 52795 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=52795 host=/tmp/b9vMPolmYo Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_A.log [10:12:41.760](0.044s) # 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 41323 # Checking port 52796 # Found port 52796 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=52796 host=/tmp/b9vMPolmYo Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_B.log [10:12:41.979](0.220s) # 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 41443 # Checking port 52797 # Found port 52797 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=52797 host=/tmp/b9vMPolmYo Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_C.log [10:12:42.339](0.360s) # 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 41538 #### 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/155FAC8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1562168 on node_B done [10:12:43.312](0.973s) ok 1 - Cascade setup is complete Waiting for replication conn tap_sub_B's replay_lsn to pass 0/155FC50 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1562168 on node_B done [10:12:43.482](0.171s) ok 2 - transaction is prepared on subscriber B [10:12:43.500](0.018s) ok 3 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/155FCA0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15622F0 on node_B done [10:12:43.597](0.097s) ok 4 - Row inserted via 2PC has committed on subscriber B [10:12:43.612](0.015s) not ok 5 - Row inserted via 2PC has committed on subscriber C [10:12:43.612](0.000s) # Failed test 'Row inserted via 2PC has committed on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 156. [10:12:43.612](0.000s) # got: '0' # expected: '1' [10:12:43.631](0.019s) ok 6 - transaction is committed on subscriber B [10:12:43.655](0.024s) not ok 7 - transaction is committed on subscriber C [10:12:43.656](0.000s) # Failed test 'transaction is committed on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 164. [10:12:43.656](0.000s) # got: '1' # expected: '0' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/155FE28 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15624D0 on node_B done [10:12:43.794](0.138s) ok 8 - transaction is prepared on subscriber B [10:12:44.132](0.338s) ok 9 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/155FE78 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1562528 on node_B done [10:12:44.343](0.212s) ok 10 - Row inserted via 2PC is not present on subscriber B [10:12:44.366](0.023s) ok 11 - Row inserted via 2PC is not present on subscriber C [10:12:44.381](0.015s) ok 12 - transaction is ended on subscriber B [10:12:44.406](0.024s) ok 13 - transaction is ended on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/15600B0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15626B0 on node_B done [10:12:44.526](0.120s) ok 14 - transaction is prepared on subscriber B [10:12:44.541](0.015s) ok 15 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/15600E8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15626B0 on node_B done [10:12:44.702](0.161s) ok 16 - transaction is ended on subscriber B [10:12:44.725](0.023s) ok 17 - transaction is ended on subscriber C [10:12:44.745](0.020s) ok 18 - Rows committed are present on subscriber B [10:12:44.759](0.014s) ok 19 - Rows committed are present on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16DA640 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1740000 on node_B done [10:12:45.365](0.606s) ok 20 - transaction is prepared on subscriber B [10:12:45.376](0.011s) not ok 21 - transaction is prepared on subscriber C [10:12:45.376](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. [10:12:45.376](0.000s) # got: '0' # expected: '1' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16DA688 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17454F0 on node_B done [10:12:45.501](0.125s) ok 22 - Rows inserted by 2PC have committed on subscriber B, and extra columns have local defaults [10:12:45.517](0.015s) ok 23 - Rows inserted by 2PC have committed on subscriber C, and extra columns have local defaults [10:12:45.530](0.014s) ok 24 - transaction is committed on subscriber B [10:12:45.541](0.011s) ok 25 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/18801F0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17B10A0 on node_B done [10:12:45.861](0.320s) ok 26 - transaction is prepared on subscriber B [10:12:45.873](0.012s) ok 27 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1880228 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17B10A0 on node_B done [10:12:45.979](0.105s) ok 28 - transaction is ended on subscriber B [10:12:45.997](0.018s) not ok 29 - transaction is ended on subscriber C [10:12:45.997](0.000s) # Failed test 'transaction is ended on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 404. [10:12:45.997](0.000s) # got: '1' # expected: '0' [10:12:46.015](0.018s) ok 30 - Rows committed are present on subscriber B [10:12:46.037](0.022s) ok 31 - Rows committed are present on subscriber B [10:12:46.059](0.022s) ok 32 - Rows committed are present on subscriber C [10:12:46.073](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 [10:12:46.147](0.075s) ok 34 - check subscription was dropped on subscriber node C [10:12:46.175](0.027s) ok 35 - check subscription relation status was dropped on subscriber node C [10:12:46.201](0.026s) ok 36 - check replication origin was dropped on subscriber node C [10:12:46.225](0.024s) 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 [10:12:46.302](0.077s) ok 38 - check subscription was dropped on subscriber node B [10:12:46.325](0.023s) ok 39 - check subscription relation status was dropped on subscriber node B [10:12:46.343](0.017s) ok 40 - check replication origin was dropped on subscriber node B [10:12:46.367](0.024s) 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" [10:12:46.683](0.316s) 1..41 [10:12:46.684](0.002s) # Looks like you failed 4 tests of 41.