# Checking port 60285 # Found port 60285 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=60285 host=/tmp/boQbKJ47sy Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_A.log [13:03:19.380](0.017s) # 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 41653 # Checking port 60286 # Found port 60286 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=60286 host=/tmp/boQbKJ47sy Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_B.log [13:03:19.656](0.276s) # 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 41736 # Checking port 60287 # Found port 60287 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=60287 host=/tmp/boQbKJ47sy Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_C.log [13:03:19.955](0.300s) # 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 41844 #### 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/155DE88 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1560378 on node_B done [13:03:20.767](0.811s) ok 1 - Cascade setup is complete Waiting for replication conn tap_sub_B's replay_lsn to pass 0/155E028 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1560678 on node_B done [13:03:20.958](0.191s) ok 2 - transaction is prepared on subscriber B [13:03:20.988](0.030s) ok 3 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/155E078 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15606D0 on node_B done [13:03:21.174](0.186s) ok 4 - Row inserted via 2PC has committed on subscriber B [13:03:21.201](0.027s) ok 5 - Row inserted via 2PC has committed on subscriber C [13:03:21.231](0.030s) ok 6 - transaction is committed on subscriber B [13:03:21.246](0.015s) ok 7 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/155E200 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1560858 on node_B done [13:03:21.340](0.093s) ok 8 - transaction is prepared on subscriber B [13:03:21.366](0.026s) ok 9 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/155E250 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15608B0 on node_B done [13:03:21.487](0.122s) ok 10 - Row inserted via 2PC is not present on subscriber B [13:03:21.501](0.013s) ok 11 - Row inserted via 2PC is not present on subscriber C [13:03:21.513](0.013s) ok 12 - transaction is ended on subscriber B [13:03:21.538](0.025s) ok 13 - transaction is ended on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/155E470 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15608B0 on node_B done [13:03:21.662](0.123s) ok 14 - transaction is prepared on subscriber B [13:03:21.677](0.016s) not ok 15 - transaction is prepared on subscriber C [13:03:21.677](0.000s) # Failed test 'transaction is prepared on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 235. [13:03:21.678](0.000s) # got: '0' # expected: '1' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/155E4A8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1560A90 on node_B done [13:03:21.822](0.144s) ok 16 - transaction is ended on subscriber B [13:03:21.849](0.027s) ok 17 - transaction is ended on subscriber C [13:03:21.878](0.029s) ok 18 - Rows committed are present on subscriber B [13:03:21.906](0.028s) ok 19 - Rows committed are present on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16D8A00 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1740000 on node_B done [13:03:22.783](0.877s) ok 20 - transaction is prepared on subscriber B [13:03:22.797](0.014s) ok 21 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16D8A48 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1743878 on node_B done [13:03:22.918](0.121s) ok 22 - Rows inserted by 2PC have committed on subscriber B, and extra columns have local defaults [13:03:22.948](0.030s) ok 23 - Rows inserted by 2PC have committed on subscriber C, and extra columns have local defaults [13:03:22.961](0.014s) ok 24 - transaction is committed on subscriber B [13:03:22.974](0.013s) ok 25 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/187E5B0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17AE000 on node_B done [13:03:23.422](0.448s) ok 26 - transaction is prepared on subscriber B [13:03:23.438](0.016s) ok 27 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/187E5E8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17AF480 on node_B done [13:03:23.546](0.108s) ok 28 - transaction is ended on subscriber B [13:03:23.559](0.013s) ok 29 - transaction is ended on subscriber C [13:03:23.572](0.013s) ok 30 - Rows committed are present on subscriber B [13:03:23.610](0.038s) ok 31 - Rows committed are present on subscriber B [13:03:23.630](0.020s) ok 32 - Rows committed are present on subscriber C [13:03:23.650](0.021s) 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 [13:03:23.707](0.057s) ok 34 - check subscription was dropped on subscriber node C [13:03:23.740](0.033s) ok 35 - check subscription relation status was dropped on subscriber node C [13:03:23.759](0.020s) ok 36 - check replication origin was dropped on subscriber node C [13:03:23.785](0.025s) 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 [13:03:23.845](0.061s) ok 38 - check subscription was dropped on subscriber node B [13:03:23.869](0.024s) ok 39 - check subscription relation status was dropped on subscriber node B [13:03:23.892](0.023s) ok 40 - check replication origin was dropped on subscriber node B [13:03:23.916](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" [13:03:24.242](0.326s) 1..41 [13:03:24.243](0.001s) # Looks like you failed 1 test of 41.