# Checking port 61321 # Found port 61321 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=61321 host=/tmp/oKfNuAnYrT Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_A.log [07:10:46.445](0.014s) # 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 32254 # Checking port 61322 # Found port 61322 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=61322 host=/tmp/oKfNuAnYrT Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_B.log [07:10:46.600](0.155s) # 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 32348 # Checking port 61323 # Found port 61323 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=61323 host=/tmp/oKfNuAnYrT Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_C.log [07:10:46.795](0.195s) # 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 32438 #### 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/1540A48 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15430C8 on node_B done [07:10:47.282](0.487s) ok 1 - Cascade setup is complete Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1540BD0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1543250 on node_B done [07:10:47.403](0.121s) ok 2 - transaction is prepared on subscriber B [07:10:47.417](0.014s) ok 3 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1540C20 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15432A8 on node_B done [07:10:47.694](0.277s) ok 4 - Row inserted via 2PC has committed on subscriber B [07:10:47.702](0.007s) ok 5 - Row inserted via 2PC has committed on subscriber C [07:10:47.710](0.008s) ok 6 - transaction is committed on subscriber B [07:10:47.718](0.008s) ok 7 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1540DA8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1543430 on node_B done [07:10:47.782](0.064s) ok 8 - transaction is prepared on subscriber B [07:10:47.792](0.010s) ok 9 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1540DF8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1543488 on node_B done [07:10:47.868](0.076s) ok 10 - Row inserted via 2PC is not present on subscriber B [07:10:47.879](0.011s) ok 11 - Row inserted via 2PC is not present on subscriber C [07:10:47.889](0.010s) ok 12 - transaction is ended on subscriber B [07:10:47.909](0.019s) ok 13 - transaction is ended on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1541018 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1543610 on node_B done [07:10:47.999](0.090s) ok 14 - transaction is prepared on subscriber B [07:10:48.010](0.011s) ok 15 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1541050 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1543668 on node_B done [07:10:48.307](0.297s) ok 16 - transaction is ended on subscriber B [07:10:48.317](0.010s) ok 17 - transaction is ended on subscriber C [07:10:48.326](0.009s) ok 18 - Rows committed are present on subscriber B [07:10:48.337](0.012s) ok 19 - Rows committed are present on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16BB5A8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1720000 on node_B done [07:10:49.609](1.271s) ok 20 - transaction is prepared on subscriber B [07:10:49.619](0.010s) not ok 21 - transaction is prepared on subscriber C [07:10:49.619](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. [07:10:49.619](0.000s) # got: '0' # expected: '1' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16BB5F0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17264C0 on node_B done [07:10:50.342](0.723s) ok 22 - Rows inserted by 2PC have committed on subscriber B, and extra columns have local defaults [07:10:50.354](0.012s) ok 23 - Rows inserted by 2PC have committed on subscriber C, and extra columns have local defaults [07:10:50.373](0.019s) ok 24 - transaction is committed on subscriber B [07:10:50.386](0.013s) ok 25 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1861150 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1790000 on node_B done [07:10:51.502](1.116s) ok 26 - transaction is prepared on subscriber B [07:10:51.533](0.031s) ok 27 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/1861188 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1791EA0 on node_B done [07:10:51.648](0.115s) ok 28 - transaction is ended on subscriber B [07:10:51.663](0.015s) not ok 29 - transaction is ended on subscriber C [07:10:51.664](0.001s) # Failed test 'transaction is ended on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 404. [07:10:51.664](0.000s) # got: '1' # expected: '0' [07:10:51.675](0.011s) ok 30 - Rows committed are present on subscriber B [07:10:51.699](0.024s) ok 31 - Rows committed are present on subscriber B [07:10:51.713](0.014s) not ok 32 - Rows committed are present on subscriber C [07:10:51.716](0.002s) # Failed test 'Rows committed are present on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 416. [07:10:51.716](0.000s) # got: '0' # expected: '1' [07:10:51.736](0.020s) not ok 33 - Rows committed are present on subscriber C [07:10:51.737](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 418. [07:10:51.737](0.001s) # got: '2' # expected: '3' #### Begin standard error psql::1: NOTICE: dropped replication slot "tap_sub_c" on publisher #### End standard error [07:10:51.784](0.046s) ok 34 - check subscription was dropped on subscriber node C [07:10:51.793](0.009s) ok 35 - check subscription relation status was dropped on subscriber node C [07:10:51.806](0.013s) ok 36 - check replication origin was dropped on subscriber node C [07:10:51.824](0.018s) 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:10:51.861](0.037s) ok 38 - check subscription was dropped on subscriber node B [07:10:51.876](0.016s) ok 39 - check subscription relation status was dropped on subscriber node B [07:10:51.887](0.011s) ok 40 - check replication origin was dropped on subscriber node B [07:10:51.899](0.012s) 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" [07:10:52.235](0.336s) 1..41 [07:10:52.238](0.003s) # Looks like you failed 4 tests of 41.