# Checking port 53679
# Found port 53679
Name: publisher
Data directory: C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_publisher_data/pgdata
Backup directory: C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_publisher_data/backup
Archive directory: C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_publisher_data/archives
Connection string: port=53679 host=C:/Windows/TEMP/svvBoR88FK
Log file: C:\cirrus\build/testrun/subscription/021_twophase\log/021_twophase_publisher.log
[06:33:26.188](0.102s) # initializing database system by copying initdb template
# Running: robocopy /E /NJS /NJH /NFL /NDL /NP C:/cirrus/build/tmp_install/initdb-template C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_publisher_data/pgdata

# Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_publisher_data/pgdata
### Starting node "publisher"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_publisher_data/pgdata -l C:\cirrus\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 4324
# Checking port 53680
# Found port 53680
Name: subscriber
Data directory: C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_subscriber_data/pgdata
Backup directory: C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_subscriber_data/backup
Archive directory: C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_subscriber_data/archives
Connection string: port=53680 host=C:/Windows/TEMP/svvBoR88FK
Log file: C:\cirrus\build/testrun/subscription/021_twophase\log/021_twophase_subscriber.log
[06:33:28.216](2.028s) # initializing database system by copying initdb template
# Running: robocopy /E /NJS /NJH /NFL /NDL /NP C:/cirrus/build/tmp_install/initdb-template C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_subscriber_data/pgdata

# Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_subscriber_data/pgdata
### Starting node "subscriber"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_subscriber_data/pgdata -l C:\cirrus\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 6352
#### Begin standard error
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/152C538 on publisher
done
done
Waiting for replication conn tap_sub's replay_lsn to pass 0/152C6C0 on publisher
done
[06:33:32.973](4.757s) ok 1 - transaction is prepared on subscriber
Waiting for replication conn tap_sub's replay_lsn to pass 0/152C710 on publisher
done
[06:33:33.803](0.830s) ok 2 - Row inserted via 2PC has committed on subscriber
[06:33:33.901](0.098s) ok 3 - transaction is committed on subscriber
Waiting for replication conn tap_sub's replay_lsn to pass 0/152C898 on publisher
done
[06:33:34.866](0.965s) ok 4 - transaction is prepared on subscriber
Waiting for replication conn tap_sub's replay_lsn to pass 0/152C8E8 on publisher
done
[06:33:35.554](0.688s) ok 5 - Row inserted via 2PC is not present on subscriber
[06:33:35.721](0.167s) ok 6 - transaction is aborted on subscriber
### Stopping node "subscriber" using mode immediate
# Running: pg_ctl -D C:\cirrus\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 C:\cirrus\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 C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_publisher_data/pgdata -l C:\cirrus\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 1012
### Starting node "subscriber"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_subscriber_data/pgdata -l C:\cirrus\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 1916
Waiting for replication conn tap_sub's replay_lsn to pass 0/1530A90 on publisher
done
[06:33:38.575](2.853s) ok 7 - Rows rolled back are not on the subscriber
### Stopping node "subscriber" using mode immediate
# Running: pg_ctl -D C:\cirrus\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 C:\cirrus\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 C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_publisher_data/pgdata -l C:\cirrus\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 5316
### Starting node "subscriber"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_subscriber_data/pgdata -l C:\cirrus\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 4632
Waiting for replication conn tap_sub's replay_lsn to pass 0/1533088 on publisher
done
[06:33:40.762](2.188s) ok 8 - Rows inserted via 2PC are visible on the subscriber
### Stopping node "subscriber" using mode immediate
# Running: pg_ctl -D C:\cirrus\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 C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_subscriber_data/pgdata -l C:\cirrus\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 6808
Waiting for replication conn tap_sub's replay_lsn to pass 0/15336D0 on publisher
done
[06:33:42.704](1.941s) ok 9 - Rows inserted via 2PC are visible on the subscriber
### Stopping node "publisher" using mode immediate
# Running: pg_ctl -D C:\cirrus\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 C:\cirrus\build/testrun/subscription/021_twophase\data/t_021_twophase_publisher_data/pgdata -l C:\cirrus\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 6792
Waiting for replication conn tap_sub's replay_lsn to pass 0/15354F0 on publisher
[06:39:25.292](342.588s) # poll_query_until timed out executing this query:
# SELECT '0/15354F0' <= 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 C:/cirrus/src/test/subscription/t/021_twophase.pl line 230.
# Postmaster PID for node "publisher" is 6792
### Stopping node "publisher" using mode immediate
# Running: pg_ctl -D C:\cirrus\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 6808
### Stopping node "subscriber" using mode immediate
# Running: pg_ctl -D C:\cirrus\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"
[06:39:25.543](0.251s) # Tests were run but no plan was declared and done_testing() was not seen.
[06:39:25.543](0.000s) # Looks like your test exited with 25 just after 9.