# Checking port 59957 # Found port 59957 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=59957 host=/tmp/CrqnO0hTtf Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_A.log [05:08:53.088](0.051s) # 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 31056 # Checking port 59958 # Found port 59958 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=59958 host=/tmp/CrqnO0hTtf Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_B.log [05:08:53.303](0.216s) # 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 31167 # Checking port 59959 # Found port 59959 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=59959 host=/tmp/CrqnO0hTtf Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_C.log [05:08:53.527](0.224s) # 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 31252 #### 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/15423D8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15449E8 on node_B done [05:08:54.475](0.947s) ok 1 - Cascade setup is complete Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1542560 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15449E8 on node_B done [05:08:54.706](0.232s) ok 2 - transaction is prepared on subscriber B [05:08:54.732](0.026s) ok 3 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/15425B0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1544B70 on node_B done [05:08:54.883](0.151s) ok 4 - Row inserted via 2PC has committed on subscriber B [05:08:54.898](0.015s) ok 5 - Row inserted via 2PC has committed on subscriber C [05:08:54.955](0.057s) ok 6 - transaction is committed on subscriber B [05:08:55.003](0.048s) ok 7 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1542738 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1544D50 on node_B done [05:08:55.222](0.219s) ok 8 - transaction is prepared on subscriber B [05:08:55.240](0.018s) ok 9 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1542788 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1544DA8 on node_B done [05:08:55.393](0.153s) ok 10 - Row inserted via 2PC is not present on subscriber B [05:08:55.408](0.016s) ok 11 - Row inserted via 2PC is not present on subscriber C [05:08:55.424](0.015s) ok 12 - transaction is ended on subscriber B [05:08:55.452](0.028s) ok 13 - transaction is ended on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/15429A8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1544F30 on node_B done [05:08:55.604](0.152s) ok 14 - transaction is prepared on subscriber B [05:08:55.628](0.023s) ok 15 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/15429E0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1544F88 on node_B done [05:08:55.839](0.211s) ok 16 - transaction is ended on subscriber B [05:08:55.867](0.028s) ok 17 - transaction is ended on subscriber C [05:08:55.886](0.019s) ok 18 - Rows committed are present on subscriber B [05:08:55.900](0.015s) ok 19 - Rows committed are present on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16BCF38 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1727D70 on node_B done [05:08:58.471](2.571s) ok 20 - transaction is prepared on subscriber B [05:08:58.484](0.013s) ok 21 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16BCF80 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1727D70 on node_B done [05:08:58.659](0.175s) ok 22 - Rows inserted by 2PC have committed on subscriber B, and extra columns have local defaults [05:08:58.679](0.020s) ok 23 - Rows inserted by 2PC have committed on subscriber C, and extra columns have local defaults [05:08:58.694](0.015s) ok 24 - transaction is committed on subscriber B [05:08:58.712](0.018s) ok 25 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1862AE0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17937C0 on node_B done [05:08:59.705](0.993s) ok 26 - transaction is prepared on subscriber B [05:08:59.731](0.026s) ok 27 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1862B18 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17937C0 on node_B done [05:08:59.849](0.118s) ok 28 - transaction is ended on subscriber B [05:08:59.862](0.013s) not ok 29 - transaction is ended on subscriber C [05:08:59.867](0.004s) # Failed test 'transaction is ended on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 404. [05:08:59.867](0.000s) # got: '1' # expected: '0' [05:08:59.892](0.025s) ok 30 - Rows committed are present on subscriber B [05:08:59.910](0.018s) ok 31 - Rows committed are present on subscriber B [05:08:59.927](0.017s) not ok 32 - Rows committed are present on subscriber C [05:08:59.928](0.001s) # Failed test 'Rows committed are present on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 416. [05:08:59.928](0.000s) # got: '0' # expected: '1' [05:08:59.947](0.019s) 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 [05:09:00.054](0.108s) ok 34 - check subscription was dropped on subscriber node C [05:09:00.119](0.064s) ok 35 - check subscription relation status was dropped on subscriber node C [05:09:00.148](0.029s) ok 36 - check replication origin was dropped on subscriber node C [05:09:00.199](0.051s) 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 [05:09:00.249](0.050s) ok 38 - check subscription was dropped on subscriber node B [05:09:00.275](0.026s) ok 39 - check subscription relation status was dropped on subscriber node B [05:09:00.295](0.019s) ok 40 - check replication origin was dropped on subscriber node B [05:09:00.312](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/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" [05:09:00.639](0.328s) 1..41 [05:09:00.642](0.003s) # Looks like you failed 2 tests of 41.