# Checking port 54807
# Found port 54807
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=54807 host=/tmp/P7XRRStqbl
Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_A.log
[00:25:56.522](0.012s) # 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 31179
# Checking port 54808
# Found port 54808
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=54808 host=/tmp/P7XRRStqbl
Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_B.log
[00:25:56.670](0.147s) # 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 31208
# Checking port 54809
# Found port 54809
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=54809 host=/tmp/P7XRRStqbl
Log file: /tmp/cirrus-ci-build/build/testrun/subscription/022_twophase_cascade/log/022_twophase_cascade_node_C.log
[00:25:56.815](0.145s) # 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 31241
#### Begin standard error
psql:<stdin>:5: WARNING:  subscriptions created by regression test cases should have names starting with "regress_"
psql:<stdin>:5: NOTICE:  created replication slot "tap_sub_b" on publisher
#### End standard error
#### Begin standard error
psql:<stdin>:5: WARNING:  subscriptions created by regression test cases should have names starting with "regress_"
psql:<stdin>: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/154E768 on node_A
done
Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1550DF8 on node_B
done
[00:25:57.408](0.593s) ok 1 - Cascade setup is complete
Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154E8F0 on node_A
done
Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1550DF8 on node_B
done
[00:25:57.468](0.060s) ok 2 - transaction is prepared on subscriber B
[00:25:57.476](0.008s) ok 3 - transaction is prepared on subscriber C
Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154E940 on node_A
done
Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1550F80 on node_B
done
[00:25:57.530](0.053s) ok 4 - Row inserted via 2PC has committed on subscriber B
[00:25:57.537](0.007s) not ok 5 - Row inserted via 2PC has committed on subscriber C
[00:25:57.537](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.
[00:25:57.537](0.000s) #          got: '0'
#     expected: '1'
[00:25:57.545](0.008s) ok 6 - transaction is committed on subscriber B
[00:25:57.553](0.008s) not ok 7 - transaction is committed on subscriber C
[00:25:57.554](0.000s) #   Failed test 'transaction is committed on subscriber C'
#   at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 164.
[00:25:57.554](0.000s) #          got: '1'
#     expected: '0'
Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154EAC8 on node_A
done
Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1550FD8 on node_B
done
[00:25:57.611](0.057s) ok 8 - transaction is prepared on subscriber B
[00:25:57.619](0.008s) ok 9 - transaction is prepared on subscriber C
Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154EB18 on node_A
done
Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15511B8 on node_B
done
[00:25:57.672](0.053s) ok 10 - Row inserted via 2PC is not present on subscriber B
[00:25:57.679](0.007s) ok 11 - Row inserted via 2PC is not present on subscriber C
[00:25:57.688](0.009s) ok 12 - transaction is ended on subscriber B
[00:25:57.697](0.009s) ok 13 - transaction is ended on subscriber C
Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154ED38 on node_A
done
Waiting for replication conn tap_sub_C's replay_lsn to pass 0/15511B8 on node_B
done
[00:25:57.758](0.061s) ok 14 - transaction is prepared on subscriber B
[00:25:57.767](0.009s) ok 15 - transaction is prepared on subscriber C
Waiting for replication conn tap_sub_B's replay_lsn to pass 0/154ED70 on node_A
done
Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1551340 on node_B
done
[00:25:57.822](0.054s) ok 16 - transaction is ended on subscriber B
[00:25:57.830](0.008s) not ok 17 - transaction is ended on subscriber C
[00:25:57.830](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.
[00:25:57.830](0.000s) #          got: '1'
#     expected: '0'
[00:25:57.837](0.007s) ok 18 - Rows committed are present on subscriber B
[00:25:57.844](0.007s) not ok 19 - Rows committed are present on subscriber C
[00:25:57.844](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.
[00:25:57.844](0.000s) #          got: ''
#     expected: '21'
Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16C92C8 on node_A
done
Waiting for replication conn tap_sub_C's replay_lsn to pass 0/1731AB0 on node_B
done
[00:25:58.788](0.944s) ok 20 - transaction is prepared on subscriber B
[00:25:58.797](0.009s) not ok 21 - transaction is prepared on subscriber C
[00:25:58.798](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.
[00:25:58.798](0.000s) #          got: '0'
#     expected: '1'
Waiting for replication conn tap_sub_B's replay_lsn to pass 0/16C9310 on node_A
done
Waiting for replication conn tap_sub_C's replay_lsn to pass 0/17341F0 on node_B
done
[00:25:59.535](0.737s) ok 22 - Rows inserted by 2PC have committed on subscriber B, and extra columns have local defaults
[00:25:59.544](0.009s) ok 23 - Rows inserted by 2PC have committed on subscriber C, and extra columns have local defaults
[00:25:59.553](0.009s) ok 24 - transaction is committed on subscriber B
[00:25:59.561](0.008s) ok 25 - transaction is committed on subscriber C
Waiting for replication conn tap_sub_B's replay_lsn to pass 0/186EE78 on node_A
done
Waiting for replication conn tap_sub_C's replay_lsn to pass 0/179A000 on node_B
done
[00:26:00.140](0.579s) ok 26 - transaction is prepared on subscriber B
[00:26:00.151](0.011s) not ok 27 - transaction is prepared on subscriber C
[00:26:00.152](0.001s) #   Failed test 'transaction is prepared on subscriber C'
#   at /tmp/cirrus-ci-build/src/test/subscription/t/022_twophase_cascade.pl line 390.
[00:26:00.152](0.000s) #          got: '0'
#     expected: '1'
Waiting for replication conn tap_sub_B's replay_lsn to pass 0/186EEB0 on node_A
done
Waiting for replication conn tap_sub_C's replay_lsn to pass 0/179FD30 on node_B
done
[00:26:00.451](0.299s) ok 28 - transaction is ended on subscriber B
[00:26:00.460](0.009s) ok 29 - transaction is ended on subscriber C
[00:26:00.469](0.009s) ok 30 - Rows committed are present on subscriber B
[00:26:00.478](0.009s) ok 31 - Rows committed are present on subscriber B
[00:26:00.486](0.009s) ok 32 - Rows committed are present on subscriber C
[00:26:00.494](0.008s) ok 33 - Rows committed are present on subscriber C
#### Begin standard error
psql:<stdin>:1: NOTICE:  dropped replication slot "tap_sub_c" on publisher
#### End standard error
[00:26:00.523](0.029s) ok 34 - check subscription was dropped on subscriber node C
[00:26:00.531](0.008s) ok 35 - check subscription relation status was dropped on subscriber node C
[00:26:00.538](0.007s) ok 36 - check replication origin was dropped on subscriber node C
[00:26:00.546](0.009s) ok 37 - check replication slot was dropped on publisher node B
#### Begin standard error
psql:<stdin>:1: NOTICE:  dropped replication slot "tap_sub_b" on publisher
#### End standard error
[00:26:00.573](0.027s) ok 38 - check subscription was dropped on subscriber node B
[00:26:00.580](0.007s) ok 39 - check subscription relation status was dropped on subscriber node B
[00:26:00.586](0.007s) ok 40 - check replication origin was dropped on subscriber node B
[00:26:00.595](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"
[00:26:00.908](0.313s) 1..41
[00:26:00.909](0.001s) # Looks like you failed 6 tests of 41.