# Checking port 20157
# Found port 20157
Name: publisher
Version: 19devel
Data directory: C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_publisher_data/pgdata
Backup directory: C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_publisher_data/backup
Archive directory: C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_publisher_data/archives
Connection string: port=20157 host=C:/Windows/TEMP/ZSIft5BrMu
Log file: C:\cirrus\build/testrun/subscription/001_rep_changes\log/001_rep_changes_publisher.log
[15:07:32.145](0.096s) # 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/001_rep_changes\data/t_001_rep_changes_publisher_data/pgdata

# Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_publisher_data/pgdata
### Starting node "publisher"
# Running: pg_ctl --wait --pgdata C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_publisher_data/pgdata --log C:\cirrus\build/testrun/subscription/001_rep_changes\log/001_rep_changes_publisher.log --options --cluster-name=publisher start
waiting for server to start.... done
server started
# Postmaster PID for node "publisher" is 7332
# Checking port 20158
# Found port 20158
Name: subscriber
Version: 19devel
Data directory: C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_subscriber_data/pgdata
Backup directory: C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_subscriber_data/backup
Archive directory: C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_subscriber_data/archives
Connection string: port=20158 host=C:/Windows/TEMP/ZSIft5BrMu
Log file: C:\cirrus\build/testrun/subscription/001_rep_changes\log/001_rep_changes_subscriber.log
[15:07:34.646](2.501s) # 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/001_rep_changes\data/t_001_rep_changes_subscriber_data/pgdata

# Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_subscriber_data/pgdata
### Starting node "subscriber"
# Running: pg_ctl --wait --pgdata C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_subscriber_data/pgdata --log C:\cirrus\build/testrun/subscription/001_rep_changes\log/001_rep_changes_subscriber.log --options --cluster-name=subscriber start
waiting for server to start.... done
server started
# Postmaster PID for node "subscriber" is 8452
#### Begin standard error
psql:<stdin>:1: 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/01815D38 on publisher
done
done
[15:07:46.134](11.488s) ok 1 - check non-replicated table is empty on subscriber
[15:07:46.337](0.203s) ok 2 - check initial data was copied to subscriber
Waiting for replication conn tap_sub's replay_lsn to pass 0/0182C060 on publisher
done
[15:07:49.438](3.102s) ok 3 - check replicated inserts on subscriber
[15:07:49.624](0.186s) ok 4 - check replicated changes on subscriber
[15:07:50.177](0.553s) ok 5 - check replicated changes with different column order
[15:07:50.341](0.164s) ok 6 - check replicated changes with REPLICA IDENTITY NOTHING
[15:07:50.449](0.109s) ok 7 - check replicated changes with primary key index with included columns
[15:07:50.665](0.215s) ok 8 - value replicated to subscriber without replica identity index
[15:07:50.900](0.236s) ok 9 - check replicated changes for table having no columns
[15:07:51.401](0.501s) ok 10 - check rows on subscriber before table drop from publication
Waiting for replication conn tap_sub's replay_lsn to pass 0/0182C5F8 on publisher
done
[15:07:52.574](1.173s) ok 11 - check rows on subscriber after table drop from publication
#### Begin standard error
psql:<stdin>:1: NOTICE:  created replication slot "tap_sub_temp1" on publisher
#### End standard error
Waiting for all subscriptions in "subscriber" to synchronize data
Waiting for replication conn tap_sub_temp1's replay_lsn to pass 0/018302C8 on publisher
done
done
[15:07:56.630](4.056s) ok 12 - check initial rows on subscriber with multiple publications
Waiting for replication conn tap_sub_temp1's replay_lsn to pass 0/01830338 on publisher
done
[15:07:57.807](1.178s) ok 13 - check rows on subscriber with multiple publications
#### Begin standard error
psql:<stdin>:1: NOTICE:  dropped replication slot "tap_sub_temp1" on publisher
#### End standard error
Waiting for replication conn tap_sub's replay_lsn to pass 0/01832B18 on publisher
done
[15:08:01.285](3.478s) ok 14 - update works with REPLICA IDENTITY FULL and duplicate tuples
[15:08:01.440](0.155s) ok 15 - update works with REPLICA IDENTITY FULL and text datums
[15:08:01.644](0.205s) ok 16 - update works with different column order and subscriber local values
[15:08:01.816](0.172s) ok 17 - update works with REPLICA IDENTITY FULL and a primary key
Waiting for replication conn tap_sub's replay_lsn to pass 0/01832CF0 on publisher
[15:14:39.270](397.454s) # poll_query_until timed out executing this query:
# SELECT '0/01832CF0' <= 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:
[15:14:39.386](0.116s) # Last pg_stat_replication contents:
[15:14:39.387](0.001s) # die: timed out waiting for catchup at C:/cirrus/src/test/subscription/t/001_rep_changes.pl line 365.
[15:14:39.388](0.001s) 1..17
timed out waiting for catchup at C:/cirrus/src/test/subscription/t/001_rep_changes.pl line 365.
# Postmaster PID for node "publisher" is 7332
### Stopping node "publisher" using mode immediate
# Running: pg_ctl --pgdata C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_publisher_data/pgdata --mode immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "publisher"
# No postmaster PID for node "subscriber"
[15:14:39.530](0.142s) # Looks like your test exited with 2 just after 17.