# Checking port 51286 # Found port 51286 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=51286 host=/tmp/njLXpXpTx0 Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_A.log [22:14:59.268](0.048s) # 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 32057 # Checking port 51287 # Found port 51287 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=51287 host=/tmp/njLXpXpTx0 Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_B.log [22:14:59.457](0.190s) # 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 32166 # Checking port 51288 # Found port 51288 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=51288 host=/tmp/njLXpXpTx0 Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_C.log [22:14:59.667](0.210s) # 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 32272 #### 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/15416F8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1543D78 on node_B done [22:15:00.476](0.809s) ok 1 - Cascade setup is complete Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1541880 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1543D78 on node_B done [22:15:00.638](0.162s) ok 2 - transaction is prepared on subscriber B [22:15:00.653](0.015s) ok 3 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/15418D0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1543F00 on node_B done [22:15:00.760](0.107s) ok 4 - Row inserted via 2PC has committed on subscriber B [22:15:00.775](0.015s) not ok 5 - Row inserted via 2PC has committed on subscriber C [22:15:00.775](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. [22:15:00.775](0.000s) # got: '0' # expected: '1' [22:15:00.796](0.020s) ok 6 - transaction is committed on subscriber B [22:15:00.815](0.019s) not ok 7 - transaction is committed on subscriber C [22:15:00.815](0.001s) # Failed test 'transaction is committed on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 164. [22:15:00.816](0.000s) # got: '1' # expected: '0' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1541A58 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1544000 on node_B done [22:15:01.158](0.342s) ok 8 - transaction is prepared on subscriber B [22:15:01.172](0.013s) ok 9 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1541AA8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1544150 on node_B done [22:15:01.274](0.102s) ok 10 - Row inserted via 2PC is not present on subscriber B [22:15:01.285](0.011s) ok 11 - Row inserted via 2PC is not present on subscriber C [22:15:01.296](0.012s) ok 12 - transaction is ended on subscriber B [22:15:01.311](0.015s) ok 13 - transaction is ended on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1541CC8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1544150 on node_B done [22:15:01.458](0.146s) ok 14 - transaction is prepared on subscriber B [22:15:01.473](0.015s) ok 15 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1541D00 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15442D8 on node_B done [22:15:01.575](0.101s) ok 16 - transaction is ended on subscriber B [22:15:01.595](0.020s) not ok 17 - transaction is ended on subscriber C [22:15:01.596](0.001s) # Failed test 'transaction is ended on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 249. [22:15:01.598](0.003s) # got: '1' # expected: '0' [22:15:01.612](0.014s) ok 18 - Rows committed are present on subscriber B [22:15:01.632](0.021s) not ok 19 - Rows committed are present on subscriber C [22:15:01.633](0.000s) # Failed test 'Rows committed are present on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 259. [22:15:01.633](0.000s) # got: '' # expected: '21' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16BC270 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1727118 on node_B done [22:15:03.911](2.277s) ok 20 - transaction is prepared on subscriber B [22:15:03.924](0.014s) ok 21 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16BC2B8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1727170 on node_B done [22:15:04.107](0.183s) ok 22 - Rows inserted by 2PC have committed on subscriber B, and extra columns have local defaults [22:15:04.136](0.029s) ok 23 - Rows inserted by 2PC have committed on subscriber C, and extra columns have local defaults [22:15:04.161](0.025s) ok 24 - transaction is committed on subscriber B [22:15:04.177](0.016s) ok 25 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1861E00 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1784000 on node_B done [22:15:04.879](0.701s) ok 26 - transaction is prepared on subscriber B [22:15:04.897](0.019s) not ok 27 - transaction is prepared on subscriber C [22:15:04.902](0.005s) # Failed test 'transaction is prepared on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 390. [22:15:04.902](0.000s) # got: '0' # expected: '1' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1861E38 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1792BC0 on node_B done [22:15:05.409](0.506s) ok 28 - transaction is ended on subscriber B [22:15:05.424](0.016s) ok 29 - transaction is ended on subscriber C [22:15:05.436](0.012s) ok 30 - Rows committed are present on subscriber B [22:15:05.448](0.012s) ok 31 - Rows committed are present on subscriber B [22:15:05.459](0.011s) ok 32 - Rows committed are present on subscriber C [22:15:05.470](0.010s) 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 [22:15:05.572](0.102s) ok 34 - check subscription was dropped on subscriber node C [22:15:05.587](0.015s) ok 35 - check subscription relation status was dropped on subscriber node C [22:15:05.599](0.012s) ok 36 - check replication origin was dropped on subscriber node C [22:15:05.625](0.026s) 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 [22:15:05.687](0.062s) ok 38 - check subscription was dropped on subscriber node B [22:15:05.705](0.018s) ok 39 - check subscription relation status was dropped on subscriber node B [22:15:05.721](0.017s) ok 40 - check replication origin was dropped on subscriber node B [22:15:05.737](0.015s) 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" [22:15:06.068](0.331s) 1..41 [22:15:06.069](0.002s) # Looks like you failed 5 tests of 41.