# Checking port 52920
# Found port 52920
Name: publisher
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=52920 host=C:/Windows/TEMP/8JMRhWsmHp
Log file: C:\cirrus\build/testrun/subscription/001_rep_changes\log/001_rep_changes_publisher.log
[20:45:41.032](0.080s) # 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 -w -D C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_publisher_data/pgdata -l C:\cirrus\build/testrun/subscription/001_rep_changes\log/001_rep_changes_publisher.log -o --cluster-name=publisher start
waiting for server to start.... done
server started
# Postmaster PID for node "publisher" is 6492
# Checking port 52921
# Found port 52921
Name: subscriber
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=52921 host=C:/Windows/TEMP/8JMRhWsmHp
Log file: C:\cirrus\build/testrun/subscription/001_rep_changes\log/001_rep_changes_subscriber.log
[20:45:43.061](2.029s) # 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 -w -D C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_subscriber_data/pgdata -l C:\cirrus\build/testrun/subscription/001_rep_changes\log/001_rep_changes_subscriber.log -o --cluster-name=subscriber start
waiting for server to start.... done
server started
# Postmaster PID for node "subscriber" is 7860
#### 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/1569350 on publisher
done
done
[20:45:53.806](10.746s) ok 1 - check non-replicated table is empty on subscriber
[20:45:54.050](0.243s) ok 2 - check initial data was copied to subscriber
Waiting for replication conn tap_sub's replay_lsn to pass 0/157F660 on publisher
done
[20:45:57.420](3.370s) ok 3 - check replicated inserts on subscriber
[20:45:57.687](0.267s) ok 4 - check replicated changes on subscriber
[20:45:57.897](0.210s) ok 5 - check replicated changes with different column order
[20:45:58.203](0.306s) ok 6 - check replicated changes with REPLICA IDENTITY NOTHING
[20:45:58.377](0.174s) ok 7 - check replicated changes with primary key index with included columns
[20:45:58.622](0.245s) ok 8 - value replicated to subscriber without replica identity index
[20:45:58.860](0.238s) ok 9 - check replicated changes for table having no columns
[20:45:59.143](0.283s) ok 10 - check rows on subscriber before table drop from publication
Waiting for replication conn tap_sub's replay_lsn to pass 0/157FBF8 on publisher
done
[20:46:00.596](1.453s) 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/1583868 on publisher
done
done
[20:46:03.959](3.363s) ok 12 - check initial rows on subscriber with multiple publications
Waiting for replication conn tap_sub_temp1's replay_lsn to pass 0/15838D8 on publisher
done
[20:46:04.616](0.657s) 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/15860C0 on publisher
done
[20:46:09.846](5.230s) ok 14 - update works with REPLICA IDENTITY FULL and duplicate tuples
[20:46:10.029](0.183s) ok 15 - update works with REPLICA IDENTITY FULL and text datums
[20:46:10.260](0.231s) ok 16 - update works with different column order and subscriber local values
[20:46:10.393](0.133s) ok 17 - update works with REPLICA IDENTITY FULL and a primary key
### Reloading node "subscriber"
# Running: pg_ctl -D C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_subscriber_data/pgdata reload
server signaled
Waiting for replication conn tap_sub's replay_lsn to pass 0/15861C8 on publisher
done
[20:46:11.599](1.207s) ok 18 - update target row is missing
[20:46:11.599](0.000s) ok 19 - delete target row is missing
### Reloading node "subscriber"
# Running: pg_ctl -D C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_subscriber_data/pgdata reload
server signaled
Waiting for replication conn tap_sub's replay_lsn to pass 0/1587AE8 on publisher
done
[20:46:12.585](0.985s) ok 20 - update transmits large column value
Waiting for replication conn tap_sub's replay_lsn to pass 0/1587BB0 on publisher
done
[20:46:13.805](1.221s) ok 21 - update with non-transmitted large column value
Waiting for replication conn tap_sub's replay_lsn to pass 0/1588140 on publisher
done
[20:46:15.480](1.675s) ok 22 - update works with dropped publisher column
Waiting for replication conn tap_sub's replay_lsn to pass 0/1588200 on publisher
done
[20:46:16.546](1.065s) ok 23 - update works with dropped subscriber column
### Stopping node "publisher" using mode fast
# Running: pg_ctl -D C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_publisher_data/pgdata -m fast 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/001_rep_changes\data/t_001_rep_changes_publisher_data/pgdata -l C:\cirrus\build/testrun/subscription/001_rep_changes\log/001_rep_changes_publisher.log -o --cluster-name=publisher start
waiting for server to start.... done
server started
# Postmaster PID for node "publisher" is 7800
Waiting for replication conn tap_sub's replay_lsn to pass 0/1590000 on publisher
[20:52:26.432](369.886s) # poll_query_until timed out executing this query:
# SELECT '0/1590000' <= 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/001_rep_changes.pl line 461.
# Postmaster PID for node "publisher" is 7800
### Stopping node "publisher" using mode immediate
# Running: pg_ctl -D C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_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 7860
### Stopping node "subscriber" using mode immediate
# Running: pg_ctl -D C:\cirrus\build/testrun/subscription/001_rep_changes\data/t_001_rep_changes_subscriber_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "subscriber"
[20:52:26.681](0.249s) # Tests were run but no plan was declared and done_testing() was not seen.
[20:52:26.681](0.000s) # Looks like your test exited with 25 just after 23.