# Checking port 50971
# Found port 50971
Name: publisher
Data directory: /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_publisher_data/pgdata
Backup directory: /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_publisher_data/backup
Archive directory: /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_publisher_data/archives
Connection string: port=50971 host=/tmp/IOv2JroZH5
Log file: /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/log/021_twophase_publisher.log
[10:12:18.294](0.018s) # 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/021_twophase/data/t_021_twophase_publisher_data/pgdata
# Running: /tmp/cirrus-ci-build/build/src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_publisher_data/pgdata
### Starting node "publisher"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_publisher_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/log/021_twophase_publisher.log -o --cluster-name=publisher start
waiting for server to start.... done
server started
# Postmaster PID for node "publisher" is 30324
# Checking port 50972
# Found port 50972
Name: subscriber
Data directory: /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/pgdata
Backup directory: /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/backup
Archive directory: /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/archives
Connection string: port=50972 host=/tmp/IOv2JroZH5
Log file: /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/log/021_twophase_subscriber.log
[10:12:18.460](0.166s) # 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/021_twophase/data/t_021_twophase_subscriber_data/pgdata
# Running: /tmp/cirrus-ci-build/build/src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/pgdata
### Starting node "subscriber"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/log/021_twophase_subscriber.log -o --cluster-name=subscriber start
waiting for server to start.... done
server started
# Postmaster PID for node "subscriber" is 30392
#### 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" on publisher
#### End standard error
Waiting for all subscriptions in "subscriber" to synchronize data
Waiting for replication conn tap_sub's replay_lsn to pass 0/1544DA0 on publisher
done
done
Waiting for replication conn tap_sub's replay_lsn to pass 0/1544F28 on publisher
done
[10:12:19.144](0.684s) ok 1 - transaction is prepared on subscriber
Waiting for replication conn tap_sub's replay_lsn to pass 0/1544F78 on publisher
done
[10:12:19.192](0.048s) ok 2 - Row inserted via 2PC has committed on subscriber
[10:12:19.205](0.013s) ok 3 - transaction is committed on subscriber
Waiting for replication conn tap_sub's replay_lsn to pass 0/1545100 on publisher
done
[10:12:19.458](0.253s) ok 4 - transaction is prepared on subscriber
Waiting for replication conn tap_sub's replay_lsn to pass 0/1545150 on publisher
done
[10:12:19.537](0.079s) ok 5 - Row inserted via 2PC is not present on subscriber
[10:12:19.556](0.019s) ok 6 - transaction is aborted on subscriber
### Stopping node "subscriber" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "subscriber"
### Stopping node "publisher" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_publisher_data/pgdata -m immediate stop
waiting for server to shut down... done
server stopped
# No postmaster PID for node "publisher"
### Starting node "publisher"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_publisher_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/log/021_twophase_publisher.log -o --cluster-name=publisher start
waiting for server to start.... done
server started
# Postmaster PID for node "publisher" is 30959
### Starting node "subscriber"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/log/021_twophase_subscriber.log -o --cluster-name=subscriber start
waiting for server to start.... done
server started
# Postmaster PID for node "subscriber" is 31035
Waiting for replication conn tap_sub's replay_lsn to pass 0/15492F8 on publisher
done
[10:12:20.008](0.452s) ok 7 - Rows rolled back are not on the subscriber
### Stopping node "subscriber" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "subscriber"
### Stopping node "publisher" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_publisher_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "publisher"
### Starting node "publisher"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_publisher_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/log/021_twophase_publisher.log -o --cluster-name=publisher start
waiting for server to start.... done
server started
# Postmaster PID for node "publisher" is 31258
### Starting node "subscriber"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/log/021_twophase_subscriber.log -o --cluster-name=subscriber start
waiting for server to start.... done
server started
# Postmaster PID for node "subscriber" is 31393
Waiting for replication conn tap_sub's replay_lsn to pass 0/154B8F0 on publisher
done
[10:12:20.761](0.753s) ok 8 - Rows inserted via 2PC are visible on the subscriber
### Stopping node "subscriber" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "subscriber"
### Starting node "subscriber"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/log/021_twophase_subscriber.log -o --cluster-name=subscriber start
waiting for server to start.... done
server started
# Postmaster PID for node "subscriber" is 31608
Waiting for replication conn tap_sub's replay_lsn to pass 0/154BF38 on publisher
[10:15:53.872](213.111s) # poll_query_until timed out executing this query:
# SELECT '0/154BF38' <= replay_lsn AND state = 'streaming'
#          FROM pg_catalog.pg_stat_replication
#          WHERE application_name IN ('tap_sub', 'walreceiver')
# expecting this output:
# t
# last actual query output:
# 
# with stderr:
timed out waiting for catchup at /tmp/cirrus-ci-build/src/test/subscription/t/021_twophase.pl line 205.
# Postmaster PID for node "publisher" is 31258
### Stopping node "publisher" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_publisher_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "publisher"
# Postmaster PID for node "subscriber" is 31608
### Stopping node "subscriber" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/subscription/021_twophase/data/t_021_twophase_subscriber_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "subscriber"
[10:15:54.091](0.220s) # Tests were run but no plan was declared and done_testing() was not seen.
[10:15:54.092](0.000s) # Looks like your test exited with 29 just after 8.