# Checking port 17746
# Found port 17746
Name: publisher
Version: 19devel
Data directory: /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_publisher_data/pgdata
Backup directory: /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_publisher_data/backup
Archive directory: /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_publisher_data/archives
Connection string: port=17746 host=/tmp/tiYAS3seIg
Log file: /home/postgres/postgres/build/testrun/subscription/001_rep_changes/log/001_rep_changes_publisher.log
[14:59:51.052](0.045s) # initializing database system by copying initdb template
# Running: cp -RPp /home/postgres/postgres/build/tmp_install/initdb-template /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_publisher_data/pgdata
# Running: /home/postgres/postgres/build/src/test/regress/pg_regress --config-auth /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_publisher_data/pgdata
### Starting node "publisher"
# Running: pg_ctl --wait --pgdata /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_publisher_data/pgdata --log /home/postgres/postgres/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 16566
# Checking port 17747
# Found port 17747
Name: subscriber
Version: 19devel
Data directory: /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_subscriber_data/pgdata
Backup directory: /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_subscriber_data/backup
Archive directory: /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_subscriber_data/archives
Connection string: port=17747 host=/tmp/tiYAS3seIg
Log file: /home/postgres/postgres/build/testrun/subscription/001_rep_changes/log/001_rep_changes_subscriber.log
[14:59:51.620](0.568s) # initializing database system by copying initdb template
# Running: cp -RPp /home/postgres/postgres/build/tmp_install/initdb-template /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_subscriber_data/pgdata
# Running: /home/postgres/postgres/build/src/test/regress/pg_regress --config-auth /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_subscriber_data/pgdata
### Starting node "subscriber"
# Running: pg_ctl --wait --pgdata /home/postgres/postgres/build/testrun/subscription/001_rep_changes/data/t_001_rep_changes_subscriber_data/pgdata --log /home/postgres/postgres/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 5949
#### 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/01803AF8 on publisher
done
done
[14:59:56.411](4.791s) ok 1 - check non-replicated table is empty on subscriber
[14:59:56.453](0.042s) ok 2 - check initial data was copied to subscriber
Waiting for replication conn tap_sub's replay_lsn to pass 0/01819E08 on publisher
done
[14:59:57.546](1.093s) ok 3 - check replicated inserts on subscriber
[14:59:57.610](0.064s) ok 4 - check replicated changes on subscriber
[14:59:57.647](0.037s) ok 5 - check replicated changes with different column order
[14:59:57.767](0.120s) ok 6 - check replicated changes with REPLICA IDENTITY NOTHING
[14:59:57.815](0.047s) ok 7 - check replicated changes with primary key index with included columns
[14:59:57.866](0.052s) ok 8 - value replicated to subscriber without replica identity index
[14:59:57.934](0.068s) ok 9 - check replicated changes for table having no columns
[14:59:58.224](0.290s) ok 10 - check rows on subscriber before table drop from publication
Waiting for replication conn tap_sub's replay_lsn to pass 0/0181A380 on publisher
done
[14:59:58.879](0.655s) 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/0181E050 on publisher
done
done
[15:00:00.360](1.481s) ok 12 - check initial rows on subscriber with multiple publications
Waiting for replication conn tap_sub_temp1's replay_lsn to pass 0/0181E0C0 on publisher
done
[15:00:00.634](0.273s) 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/018208A0 on publisher
done
[15:00:03.123](2.490s) ok 14 - update works with REPLICA IDENTITY FULL and duplicate tuples
[15:00:03.195](0.072s) ok 15 - update works with REPLICA IDENTITY FULL and text datums
[15:00:03.277](0.082s) ok 16 - update works with different column order and subscriber local values
[15:00:03.317](0.040s) ok 17 - update works with REPLICA IDENTITY FULL and a primary key
Waiting for replication conn tap_sub's replay_lsn to pass 0/01820A78 on publisher
[15:04:51.216](287.899s) # poll_query_until timed out executing this query:
# SELECT '0/01820A78' <= 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:04:51.257](0.041s) # Last pg_stat_replication contents:
[15:04:51.258](0.001s) # die: timed out waiting for catchup at /home/postgres/postgres/src/test/subscription/t/001_rep_changes.pl line 365.
[15:04:51.258](0.000s) 1..17
timed out waiting for catchup at /home/postgres/postgres/src/test/subscription/t/001_rep_changes.pl line 365.
# Postmaster PID for node "publisher" is 16566
### Stopping node "publisher" using mode immediate
# Running: pg_ctl --pgdata /home/postgres/postgres/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:04:51.379](0.121s) # Looks like your test exited with 4 just after 17.