# Checking port 53543 # Found port 53543 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=53543 host=/tmp/rctI1oQLhM Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_A.log [04:46:41.803](0.013s) # 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 31086 # Checking port 53544 # Found port 53544 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=53544 host=/tmp/rctI1oQLhM Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_B.log [04:46:41.956](0.153s) # 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 31110 # Checking port 53545 # Found port 53545 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=53545 host=/tmp/rctI1oQLhM Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_C.log [04:46:42.106](0.150s) # 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 31151 #### 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/154E4B0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1550B38 on node_B done [04:46:42.694](0.589s) ok 1 - Cascade setup is complete Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154E638 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1550B38 on node_B done [04:46:42.765](0.070s) ok 2 - transaction is prepared on subscriber B [04:46:42.775](0.010s) ok 3 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154E688 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1550CC0 on node_B done [04:46:42.839](0.064s) ok 4 - Row inserted via 2PC has committed on subscriber B [04:46:42.846](0.007s) not ok 5 - Row inserted via 2PC has committed on subscriber C [04:46:42.846](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. [04:46:42.847](0.000s) # got: '0' # expected: '1' [04:46:42.854](0.008s) ok 6 - transaction is committed on subscriber B [04:46:42.862](0.008s) ok 7 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154E810 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1550D18 on node_B done [04:46:42.924](0.062s) ok 8 - transaction is prepared on subscriber B [04:46:42.933](0.008s) ok 9 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154E860 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1550EF8 on node_B done [04:46:42.993](0.060s) ok 10 - Row inserted via 2PC is not present on subscriber B [04:46:43.003](0.010s) ok 11 - Row inserted via 2PC is not present on subscriber C [04:46:43.012](0.009s) ok 12 - transaction is ended on subscriber B [04:46:43.023](0.011s) ok 13 - transaction is ended on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154EA80 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1551080 on node_B done [04:46:43.083](0.061s) ok 14 - transaction is prepared on subscriber B [04:46:43.091](0.008s) ok 15 - transaction is prepared on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154EAB8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1551080 on node_B done [04:46:43.144](0.053s) ok 16 - transaction is ended on subscriber B [04:46:43.152](0.008s) not ok 17 - transaction is ended on subscriber C [04:46:43.152](0.000s) # Failed test 'transaction is ended on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 249. [04:46:43.152](0.000s) # got: '1' # expected: '0' [04:46:43.159](0.007s) ok 18 - Rows committed are present on subscriber B [04:46:43.166](0.007s) not ok 19 - Rows committed are present on subscriber C [04:46:43.166](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. [04:46:43.167](0.000s) # got: '' # expected: '21' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16C9010 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1732000 on node_B done [04:46:44.380](1.213s) ok 20 - transaction is prepared on subscriber B [04:46:44.389](0.009s) not ok 21 - transaction is prepared on subscriber C [04:46:44.390](0.001s) # Failed test 'transaction is prepared on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 325. [04:46:44.390](0.000s) # got: '0' # expected: '1' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16C9058 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1733EC0 on node_B done [04:46:45.032](0.642s) ok 22 - Rows inserted by 2PC have committed on subscriber B, and extra columns have local defaults [04:46:45.044](0.011s) ok 23 - Rows inserted by 2PC have committed on subscriber C, and extra columns have local defaults [04:46:45.056](0.012s) ok 24 - transaction is committed on subscriber B [04:46:45.067](0.012s) ok 25 - transaction is committed on subscriber C Waiting for replication conn tap_sub_B's replay_lsn to pass 0/186EBC0 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1798D38 on node_B done [04:46:45.526](0.458s) ok 26 - transaction is prepared on subscriber B [04:46:45.534](0.009s) not ok 27 - transaction is prepared on subscriber C [04:46:45.535](0.000s) # Failed test 'transaction is prepared on subscriber C' # at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 390. [04:46:45.535](0.000s) # got: '0' # expected: '1' Waiting for replication conn tap_sub_B's replay_lsn to pass 0/186EBF8 on node_A done Waiting for replication conn tap_sub_C's replay_lsn to pass 0/179FAC8 on node_B done [04:46:45.941](0.407s) ok 28 - transaction is ended on subscriber B [04:46:45.951](0.010s) ok 29 - transaction is ended on subscriber C [04:46:45.961](0.009s) ok 30 - Rows committed are present on subscriber B [04:46:45.968](0.008s) ok 31 - Rows committed are present on subscriber B [04:46:45.976](0.008s) ok 32 - Rows committed are present on subscriber C [04:46:45.984](0.007s) 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 [04:46:46.011](0.027s) ok 34 - check subscription was dropped on subscriber node C [04:46:46.018](0.007s) ok 35 - check subscription relation status was dropped on subscriber node C [04:46:46.026](0.008s) ok 36 - check replication origin was dropped on subscriber node C [04:46:46.036](0.009s) 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 [04:46:46.063](0.027s) ok 38 - check subscription was dropped on subscriber node B [04:46:46.070](0.007s) ok 39 - check subscription relation status was dropped on subscriber node B [04:46:46.077](0.007s) ok 40 - check replication origin was dropped on subscriber node B [04:46:46.085](0.008s) 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" [04:46:46.394](0.310s) 1..41 [04:46:46.396](0.001s) # Looks like you failed 5 tests of 41.