# Running: pg_createsubscriber --help
[08:37:52.466](0.027s) ok 1 - pg_createsubscriber --help exit code 0
[08:37:52.466](0.000s) ok 2 - pg_createsubscriber --help goes to stdout
[08:37:52.466](0.000s) ok 3 - pg_createsubscriber --help nothing to stderr
[08:37:52.466](0.000s) ok 4 - pg_createsubscriber --help maximum line length
# Running: pg_createsubscriber --version
[08:37:52.479](0.013s) ok 5 - pg_createsubscriber --version exit code 0
[08:37:52.479](0.000s) ok 6 - pg_createsubscriber --version goes to stdout
[08:37:52.479](0.000s) ok 7 - pg_createsubscriber --version nothing to stderr
# Running: pg_createsubscriber --not-a-valid-option
[08:37:52.494](0.015s) ok 8 - pg_createsubscriber with invalid option nonzero exit code
[08:37:52.495](0.000s) ok 9 - pg_createsubscriber with invalid option prints error message
# Running: pg_createsubscriber
pg_createsubscriber: error: no subscriber data directory specified
pg_createsubscriber: hint: Try "pg_createsubscriber --help" for more information.
[08:37:52.500](0.005s) ok 10 - no subscriber data directory specified
# Running: pg_createsubscriber --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_BeqB
pg_createsubscriber: error: no publisher connection string specified
pg_createsubscriber: hint: Try "pg_createsubscriber --help" for more information.
[08:37:52.518](0.018s) ok 11 - no publisher connection string specified
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_BeqB --publisher-server port=5432
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: no database was specified
pg_createsubscriber: error: no database name specified
pg_createsubscriber: hint: Try "pg_createsubscriber --help" for more information.
[08:37:52.533](0.015s) ok 12 - no database name specified
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_BeqB --publisher-server port=5432 --database pg1 --database pg1
pg_createsubscriber: error: duplicate database "pg1"
[08:37:52.545](0.012s) ok 13 - duplicate database name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_BeqB --publisher-server port=5432 --publication foo1 --publication foo1 --database pg1 --database pg2
pg_createsubscriber: error: duplicate publication "foo1"
[08:37:52.559](0.014s) ok 14 - duplicate publication name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_BeqB --publisher-server port=5432 --publication foo1 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: error: wrong number of publication names
pg_createsubscriber: hint: Number of publication names (1) must match number of database names (2).
[08:37:52.563](0.005s) ok 15 - wrong number of publication names
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_BeqB --publisher-server port=5432 --publication foo1 --publication foo2 --subscription bar1 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: error: wrong number of subscription names
pg_createsubscriber: hint: Number of subscription names (1) must match number of database names (2).
[08:37:52.575](0.011s) ok 16 - wrong number of subscription names
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_BeqB --publisher-server port=5432 --publication foo1 --publication foo2 --subscription bar1 --subscription bar2 --replication-slot baz1 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: error: wrong number of replication slot names
pg_createsubscriber: hint: Number of replication slot names (1) must match number of database names (2).
[08:37:52.579](0.005s) ok 17 - wrong number of replication slot names
# Checking port 55458
# Found port 55458
Name: node_p
Data directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata
Backup directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/backup
Archive directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/archives
Connection string: port=55458 host=/tmp/nSiycYJWMV
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_p.log
[08:37:52.583](0.003s) # 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/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata
# Running: /tmp/cirrus-ci-build/build/src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata
### Starting node "node_p"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_p.log -o --cluster-name=node_p start
waiting for server to start.... done
server started
# Postmaster PID for node "node_p" is 39605
# Checking port 55459
# Found port 55459
Name: node_f
Data directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/pgdata
Backup directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/backup
Archive directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/archives
Connection string: port=55459 host=/tmp/nSiycYJWMV
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_f.log
[08:37:52.825](0.242s) # initializing database system by running initdb
# Running: initdb -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/pgdata -A trust -N
The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.

The database cluster will be initialized with this locale configuration:
  locale provider:   libc
  LC_COLLATE:  C.UTF-8
  LC_CTYPE:    C.UTF-8
  LC_MESSAGES: C
  LC_MONETARY: C.UTF-8
  LC_NUMERIC:  C.UTF-8
  LC_TIME:     C.UTF-8
The default database encoding has accordingly been set to "UTF8".
The default text search configuration will be set to "english".

Data page checksums are disabled.

creating directory /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/pgdata ... ok
creating subdirectories ... ok
selecting dynamic shared memory implementation ... posix
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default time zone ... Etc/UTC
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok

Sync to disk skipped.
The data directory might become corrupt if the operating system crashes.

Success. You can now start the database server using:

    pg_ctl -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/pgdata -l logfile start

# Running: /tmp/cirrus-ci-build/build/src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/pgdata
# Taking pg_basebackup backup_1 from node "node_p"
# Running: pg_basebackup -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/backup/backup_1 -h /tmp/nSiycYJWMV -p 55458 --checkpoint fast --no-sync
# Backup finished
# Checking port 55460
# Found port 55460
Name: node_s
Data directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata
Backup directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/backup
Archive directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/archives
Connection string: port=55460 host=/tmp/nSiycYJWMV
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_s.log
# Initializing node "node_s" from backup "backup_1" of node "node_p"
### Enabling streaming replication for node "node_s"
### Starting node "node_s"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_s.log -o --cluster-name=node_s start
waiting for server to start.... done
server started
# Postmaster PID for node "node_s" is 40147
# Checking port 55461
# Found port 55461
Name: node_t
Data directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata
Backup directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/backup
Archive directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/archives
Connection string: port=55461 host=/tmp/nSiycYJWMV
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_t.log
# Initializing node "node_t" from backup "backup_1" of node "node_p"
### Enabling streaming replication for node "node_t"
### Starting node "node_t"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_t.log -o --cluster-name=node_t start
waiting for server to start.... done
server started
# Postmaster PID for node "node_t" is 40238
### Promoting node "node_t"
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_t.log promote
waiting for server to promote.... done
server promoted
### Stopping node "node_t" using mode fast
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata -m fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "node_t"
# Running: pg_createsubscriber --verbose --dry-run --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata --publisher-server port=55458 host=/tmp/nSiycYJWMV dbname='pg1' --socket-directory /tmp/nSiycYJWMV --subscriber-port 55461 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata" is a cluster data directory
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7355412330532160869 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7355412330532160869 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-08 08:37:55.765 UTC [40323][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-08 08:37:55.765 UTC [40323][postmaster] LOG:  listening on Unix socket "/tmp/nSiycYJWMV/.s.PGSQL.55461"
2024-04-08 08:37:55.776 UTC [40334][startup] LOG:  database system was shut down at 2024-04-08 08:37:55 UTC
2024-04-08 08:37:55.778 UTC [40323][postmaster] LOG:  database system is ready to accept connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-08 08:37:55.849 UTC [40359][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:37:55.850 UTC [40359][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata/pg_hba.conf:117)
2024-04-08 08:37:55.850 UTC [40359][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:37:55.861 UTC [40359][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-08 08:37:55.861 UTC [40359][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
pg_createsubscriber: error: target server must be a standby
2024-04-08 08:37:55.862 UTC [40359][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.012 user=postgres database=pg1 host=[local]
2024-04-08 08:37:55.884 UTC [40323][postmaster] LOG:  received fast shutdown request
2024-04-08 08:37:55.884 UTC [40323][postmaster] LOG:  aborting any active transactions
2024-04-08 08:37:55.885 UTC [40323][postmaster] LOG:  background worker "logical replication launcher" (PID 40340) exited with exit code 1
2024-04-08 08:37:55.887 UTC [40332][checkpointer] LOG:  shutting down
2024-04-08 08:37:55.887 UTC [40332][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-08 08:37:55.887 UTC [40332][checkpointer] LOG:  checkpoint complete: wrote 6 buffers (4.7%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=17 kB, estimate=17 kB; lsn=0/30046A0, redo lsn=0/30046A0
2024-04-08 08:37:55.888 UTC [40323][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[08:37:55.988](3.163s) ok 18 - target server is not in recovery
# Running: pg_createsubscriber --verbose --dry-run --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55458 host=/tmp/nSiycYJWMV dbname='pg1' --socket-directory /tmp/nSiycYJWMV --subscriber-port 55460 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" is a cluster data directory
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7355412330532160869 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7355412330532160869 on subscriber
pg_createsubscriber: error: standby is up and running
pg_createsubscriber: hint: Stop the standby and try again.
[08:37:56.085](0.097s) ok 19 - standby is up and running
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/pgdata --publisher-server port=55458 host=/tmp/nSiycYJWMV dbname='pg1' --socket-directory /tmp/nSiycYJWMV --subscriber-port 55459 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/pgdata" is a cluster data directory
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7355412330532160869 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7355412698497223433 on subscriber
pg_createsubscriber: error: subscriber data directory is not a copy of the source database cluster
[08:37:56.189](0.105s) ok 20 - subscriber data directory is not a copy of the source database cluster
# Taking pg_basebackup backup_2 from node "node_s"
# Running: pg_basebackup -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/backup/backup_2 -h /tmp/nSiycYJWMV -p 55460 --checkpoint fast --no-sync
# Backup finished
# Checking port 55462
# Found port 55462
Name: node_c
Data directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_c_data/pgdata
Backup directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_c_data/backup
Archive directory: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_c_data/archives
Connection string: port=55462 host=/tmp/nSiycYJWMV
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_c.log
# Initializing node "node_c" from backup "backup_2" of node "node_s"
### Enabling streaming replication for node "node_c"
# Running: pg_createsubscriber --verbose --dry-run --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_c_data/pgdata --publisher-server port=55460 host=/tmp/nSiycYJWMV dbname='pg1' --socket-directory /tmp/nSiycYJWMV --subscriber-port 55462 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_c_data/pgdata" is a cluster data directory
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7355412330532160869 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7355412330532160869 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-08 08:37:56.898 UTC [40530][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-08 08:37:56.898 UTC [40530][postmaster] LOG:  listening on Unix socket "/tmp/nSiycYJWMV/.s.PGSQL.55462"
2024-04-08 08:37:56.903 UTC [40535][startup] LOG:  database system was interrupted while in recovery at log time 2024-04-08 08:37:54 UTC
2024-04-08 08:37:56.903 UTC [40535][startup] HINT:  If this has occurred more than once some data might be corrupted and you might need to choose an earlier recovery target.
2024-04-08 08:37:56.903 UTC [40535][startup] LOG:  starting backup recovery with redo LSN 0/2000028, checkpoint LSN 0/2000080, on timeline ID 1
2024-04-08 08:37:56.903 UTC [40535][startup] LOG:  entering standby mode
2024-04-08 08:37:56.906 UTC [40535][startup] LOG:  redo starts at 0/2000028
2024-04-08 08:37:56.906 UTC [40535][startup] LOG:  completed backup recovery with redo LSN 0/2000028 and end LSN 0/2000120
2024-04-08 08:37:56.906 UTC [40535][startup] LOG:  consistent recovery state reached at 0/3000000
2024-04-08 08:37:56.906 UTC [40530][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-08 08:37:56.934 UTC [40546][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-08 08:37:56.997 UTC [40568][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:37:56.998 UTC [40568][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_c_data/pgdata/pg_hba.conf:117)
2024-04-08 08:37:56.998 UTC [40568][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:37:57.009 UTC [40568][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-08 08:37:57.010 UTC [40568][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:37:57.011 UTC [40568][client backend] [040_pg_createsubscriber.pl][0/4:0] LOG:  statement: SELECT setting FROM pg_catalog.pg_settings WHERE name IN ('max_logical_replication_workers', 'max_replication_slots', 'max_worker_processes', 'primary_slot_name') ORDER BY name
pg_createsubscriber: checking settings on publisher
2024-04-08 08:37:57.016 UTC [40568][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=postgres database=pg1 host=[local]
pg_createsubscriber: error: primary server cannot be in recovery
2024-04-08 08:37:57.055 UTC [40530][postmaster] LOG:  received fast shutdown request
2024-04-08 08:37:57.055 UTC [40530][postmaster] LOG:  aborting any active transactions
2024-04-08 08:37:57.055 UTC [40546][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-08 08:37:57.057 UTC [40533][checkpointer] LOG:  shutting down
2024-04-08 08:37:57.058 UTC [40530][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[08:37:57.156](0.967s) ok 21 - primary server is in recovery
Waiting for replication conn node_s's replay_lsn to pass 0/3000110 on node_p
done
### Restarting node "node_p"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_p.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "node_p" is 40642
### Stopping node "node_s" using mode fast
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata -m fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "node_s"
# Running: pg_createsubscriber --verbose --dry-run --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55458 host=/tmp/nSiycYJWMV dbname='pg1' --socket-directory /tmp/nSiycYJWMV --subscriber-port 55460 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" is a cluster data directory
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7355412330532160869 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7355412330532160869 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-08 08:37:57.857 UTC [40711][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-08 08:37:57.857 UTC [40711][postmaster] LOG:  listening on Unix socket "/tmp/nSiycYJWMV/.s.PGSQL.55460"
2024-04-08 08:37:57.864 UTC [40719][startup] LOG:  database system was shut down in recovery at 2024-04-08 08:37:57 UTC
2024-04-08 08:37:57.864 UTC [40719][startup] LOG:  entering standby mode
2024-04-08 08:37:57.866 UTC [40719][startup] LOG:  consistent recovery state reached at 0/3000188
2024-04-08 08:37:57.866 UTC [40711][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-08 08:37:57.866 UTC [40719][startup] LOG:  invalid record length at 0/3000188: expected at least 24, got 0
2024-04-08 08:37:57.917 UTC [40723][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-04-08 08:37:57.917 UTC [40719][startup] LOG:  redo starts at 0/3000188
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-08 08:37:57.940 UTC [40746][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:37:57.941 UTC [40746][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:37:57.941 UTC [40746][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:37:57.952 UTC [40746][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-08 08:37:57.953 UTC [40746][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:37:57.953 UTC [40746][client backend] [040_pg_createsubscriber.pl][0/4:0] LOG:  statement: SELECT setting FROM pg_catalog.pg_settings WHERE name IN ('max_logical_replication_workers', 'max_replication_slots', 'max_worker_processes', 'primary_slot_name') ORDER BY name
pg_createsubscriber: checking settings on publisher
2024-04-08 08:37:57.956 UTC [40746][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.016 user=postgres database=pg1 host=[local]
pg_createsubscriber: primary has replication slot "physical_slot"
pg_createsubscriber: error: publisher requires wal_level >= "logical"
pg_createsubscriber: error: publisher requires 2 replication slots, but only 0 remain
pg_createsubscriber: hint: Consider increasing max_replication_slots to at least 3.
pg_createsubscriber: error: publisher requires 2 wal sender processes, but only 0 remain
pg_createsubscriber: hint: Consider increasing max_wal_senders to at least 3.
2024-04-08 08:37:57.995 UTC [40711][postmaster] LOG:  received fast shutdown request
2024-04-08 08:37:57.995 UTC [40711][postmaster] LOG:  aborting any active transactions
2024-04-08 08:37:57.996 UTC [40723][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-08 08:37:57.998 UTC [40717][checkpointer] LOG:  shutting down
2024-04-08 08:37:57.999 UTC [40711][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[08:37:58.096](0.940s) ok 22 - primary contains unmet conditions on node P
# Running: pg_createsubscriber --verbose --dry-run --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55458 host=/tmp/nSiycYJWMV dbname='pg1' --socket-directory /tmp/nSiycYJWMV --subscriber-port 55460 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" is a cluster data directory
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7355412330532160869 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7355412330532160869 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-08 08:37:58.244 UTC [40808][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-08 08:37:58.244 UTC [40808][postmaster] LOG:  listening on Unix socket "/tmp/nSiycYJWMV/.s.PGSQL.55460"
2024-04-08 08:37:58.257 UTC [40815][startup] LOG:  database system was shut down in recovery at 2024-04-08 08:37:57 UTC
2024-04-08 08:37:58.257 UTC [40815][startup] LOG:  entering standby mode
2024-04-08 08:37:58.259 UTC [40815][startup] LOG:  redo starts at 0/3000188
2024-04-08 08:37:58.259 UTC [40815][startup] LOG:  invalid magic number 0000 in WAL segment 000000010000000000000003, LSN 0/3004000, offset 16384
2024-04-08 08:37:58.259 UTC [40815][startup] LOG:  consistent recovery state reached at 0/3002758
2024-04-08 08:37:58.259 UTC [40808][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-08 08:37:58.260 UTC [40815][startup] LOG:  invalid magic number 0000 in WAL segment 000000010000000000000003, LSN 0/3004000, offset 16384
2024-04-08 08:37:58.280 UTC [40818][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-08 08:37:58.312 UTC [40822][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:37:58.312 UTC [40822][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:37:58.313 UTC [40822][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:37:58.318 UTC [40822][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-08 08:37:58.318 UTC [40822][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:37:58.318 UTC [40822][client backend] [040_pg_createsubscriber.pl][0/4:0] LOG:  statement: SELECT setting FROM pg_catalog.pg_settings WHERE name IN ('max_logical_replication_workers', 'max_replication_slots', 'max_worker_processes', 'primary_slot_name') ORDER BY name
pg_createsubscriber: error: subscriber requires 2 replication slots, but only 1 remain
pg_createsubscriber: hint: Consider increasing max_replication_slots to at least 2.
pg_createsubscriber: error: subscriber requires 2 logical replication workers, but only 1 remain
pg_createsubscriber: hint: Consider increasing max_logical_replication_workers to at least 2.
pg_createsubscriber: error: subscriber requires 3 worker processes, but only 2 remain
pg_createsubscriber: hint: Consider increasing max_worker_processes to at least 3.
2024-04-08 08:37:58.321 UTC [40822][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=postgres database=pg1 host=[local]
2024-04-08 08:37:58.347 UTC [40808][postmaster] LOG:  received fast shutdown request
2024-04-08 08:37:58.347 UTC [40808][postmaster] LOG:  aborting any active transactions
2024-04-08 08:37:58.348 UTC [40818][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-08 08:37:58.349 UTC [40813][checkpointer] LOG:  shutting down
2024-04-08 08:37:58.350 UTC [40808][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[08:37:58.448](0.352s) ok 23 - standby contains unmet conditions on node S
### Restarting node "node_p"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_p.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "node_p" is 40851
# Running: pg_createsubscriber --verbose --dry-run --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55458 host=/tmp/nSiycYJWMV dbname='pg1' --socket-directory /tmp/nSiycYJWMV --subscriber-port 55460 --publication pub1 --publication pub2 --subscription sub1 --subscription sub2 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" is a cluster data directory
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7355412330532160869 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7355412330532160869 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-08 08:37:58.789 UTC [40909][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-08 08:37:58.789 UTC [40909][postmaster] LOG:  listening on Unix socket "/tmp/nSiycYJWMV/.s.PGSQL.55460"
2024-04-08 08:37:58.800 UTC [40919][startup] LOG:  database system was shut down in recovery at 2024-04-08 08:37:58 UTC
2024-04-08 08:37:58.800 UTC [40919][startup] LOG:  entering standby mode
2024-04-08 08:37:58.801 UTC [40919][startup] LOG:  redo starts at 0/3000188
2024-04-08 08:37:58.801 UTC [40919][startup] LOG:  consistent recovery state reached at 0/30046C0
2024-04-08 08:37:58.801 UTC [40919][startup] LOG:  invalid record length at 0/30046C0: expected at least 24, got 0
2024-04-08 08:37:58.803 UTC [40909][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-08 08:37:58.838 UTC [40923][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-08 08:37:58.867 UTC [40929][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:37:58.867 UTC [40929][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:37:58.867 UTC [40929][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:37:58.943 UTC [40929][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-08 08:37:58.943 UTC [40929][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:37:58.944 UTC [40929][client backend] [040_pg_createsubscriber.pl][0/4:0] LOG:  statement: SELECT setting FROM pg_catalog.pg_settings WHERE name IN ('max_logical_replication_workers', 'max_replication_slots', 'max_worker_processes', 'primary_slot_name') ORDER BY name
pg_createsubscriber: checking settings on publisher
2024-04-08 08:37:58.951 UTC [40929][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.084 user=postgres database=pg1 host=[local]
pg_createsubscriber: primary has replication slot "physical_slot"
pg_createsubscriber: stopping the subscriber
2024-04-08 08:37:58.967 UTC [40909][postmaster] LOG:  received fast shutdown request
2024-04-08 08:37:58.967 UTC [40909][postmaster] LOG:  aborting any active transactions
2024-04-08 08:37:58.967 UTC [40923][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-08 08:37:58.968 UTC [40917][checkpointer] LOG:  shutting down
2024-04-08 08:37:58.968 UTC [40917][checkpointer] LOG:  restartpoint starting: shutdown immediate
2024-04-08 08:37:58.968 UTC [40917][checkpointer] LOG:  restartpoint complete: wrote 4 buffers (3.1%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=17 kB, estimate=17 kB; lsn=0/30046C0, redo lsn=0/30046C0
2024-04-08 08:37:58.968 UTC [40917][checkpointer] LOG:  recovery restart point at 0/30046C0
2024-04-08 08:37:58.969 UTC [40909][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: creating publication "pub1" on database "pg1"
pg_createsubscriber: creating the replication slot "sub1" on database "pg1"
pg_createsubscriber: create replication slot "sub1" on publisher
pg_createsubscriber: creating publication "pub2" on database "pg2"
pg_createsubscriber: creating the replication slot "sub2" on database "pg2"
pg_createsubscriber: create replication slot "sub2" on publisher
pg_createsubscriber: starting the subscriber
2024-04-08 08:37:59.187 UTC [40991][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-08 08:37:59.187 UTC [40991][postmaster] LOG:  listening on Unix socket "/tmp/nSiycYJWMV/.s.PGSQL.55460"
2024-04-08 08:37:59.197 UTC [40998][startup] LOG:  database system was shut down in recovery at 2024-04-08 08:37:58 UTC
2024-04-08 08:37:59.197 UTC [40998][startup] LOG:  entering standby mode
2024-04-08 08:37:59.198 UTC [40998][startup] LOG:  redo starts at 0/3004738
2024-04-08 08:37:59.198 UTC [40998][startup] LOG:  consistent recovery state reached at 0/3004770
2024-04-08 08:37:59.198 UTC [40998][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
2024-04-08 08:37:59.198 UTC [40991][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-08 08:37:59.201 UTC [41001][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
pg_createsubscriber: server was started
pg_createsubscriber: waiting for the target server to reach the consistent state
2024-04-08 08:37:59.282 UTC [41032][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:37:59.283 UTC [41032][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:37:59.283 UTC [41032][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:37:59.288 UTC [41032][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-08 08:37:59.288 UTC [41032][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
pg_createsubscriber: target server reached the consistent state
pg_createsubscriber: hint: If pg_createsubscriber fails after this point, you must recreate the physical replica before continuing.
2024-04-08 08:37:59.288 UTC [41032][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.006 user=postgres database=pg1 host=[local]
2024-04-08 08:37:59.296 UTC [41036][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:37:59.296 UTC [41036][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:37:59.296 UTC [41036][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:37:59.299 UTC [41036][client backend] [040_pg_createsubscriber.pl][1/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
pg_createsubscriber: dropping publication "pub1" on database "pg1"
pg_createsubscriber: creating subscription "sub1" on database "pg1"
2024-04-08 08:37:59.300 UTC [41036][client backend] [040_pg_createsubscriber.pl][1/3:0] LOG:  statement: SELECT s.oid FROM pg_catalog.pg_subscription s INNER JOIN pg_catalog.pg_database d ON (s.subdbid = d.oid) WHERE s.subname = 'sub1' AND d.datname = 'pg1'
pg_createsubscriber: setting the replication progress (node name "pg_0" ; LSN 0/0) on database "pg1"
pg_createsubscriber: enabling subscription "sub1" on database "pg1"
2024-04-08 08:37:59.303 UTC [41036][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=postgres database=pg1 host=[local]
2024-04-08 08:37:59.320 UTC [41038][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:37:59.321 UTC [41038][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:37:59.321 UTC [41038][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=pg2 application_name=040_pg_createsubscriber.pl
2024-04-08 08:37:59.325 UTC [41038][client backend] [040_pg_createsubscriber.pl][2/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
pg_createsubscriber: dropping publication "pub2" on database "pg2"
pg_createsubscriber: creating subscription "sub2" on database "pg2"
2024-04-08 08:37:59.326 UTC [41038][client backend] [040_pg_createsubscriber.pl][2/3:0] LOG:  statement: SELECT s.oid FROM pg_catalog.pg_subscription s INNER JOIN pg_catalog.pg_database d ON (s.subdbid = d.oid) WHERE s.subname = 'sub2' AND d.datname = 'pg2'
pg_createsubscriber: setting the replication progress (node name "pg_0" ; LSN 0/0) on database "pg2"
pg_createsubscriber: enabling subscription "sub2" on database "pg2"
2024-04-08 08:37:59.328 UTC [41038][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.014 user=postgres database=pg2 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: stopping the subscriber
2024-04-08 08:37:59.364 UTC [40991][postmaster] LOG:  received fast shutdown request
2024-04-08 08:37:59.364 UTC [40991][postmaster] LOG:  aborting any active transactions
2024-04-08 08:37:59.364 UTC [41001][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-08 08:37:59.370 UTC [40996][checkpointer] LOG:  shutting down
2024-04-08 08:37:59.371 UTC [40991][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7355412726473498536 on subscriber
pg_createsubscriber: running pg_resetwal on the subscriber
pg_createsubscriber: Done!
[08:37:59.467](1.019s) ok 24 - run pg_createsubscriber --dry-run on node S
### Starting node "node_s"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_s.log -o --cluster-name=node_s start
waiting for server to start.... done
server started
# Postmaster PID for node "node_s" is 41074
[08:37:59.640](0.174s) ok 25 - standby is in recovery
### Stopping node "node_s" using mode fast
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata -m fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "node_s"
# Running: pg_createsubscriber --verbose --dry-run --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55458 host=/tmp/nSiycYJWMV dbname='pg1' --socket-directory /tmp/nSiycYJWMV --subscriber-port 55460 --replication-slot replslot1
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: no database was specified
pg_createsubscriber: database "pg1" was extracted from the publisher connection string
pg_createsubscriber: checking if directory "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" is a cluster data directory
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7355412330532160869 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7355412330532160869 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-08 08:37:59.861 UTC [41115][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-08 08:37:59.869 UTC [41115][postmaster] LOG:  listening on Unix socket "/tmp/nSiycYJWMV/.s.PGSQL.55460"
2024-04-08 08:37:59.879 UTC [41125][startup] LOG:  database system was shut down in recovery at 2024-04-08 08:37:59 UTC
2024-04-08 08:37:59.879 UTC [41125][startup] LOG:  entering standby mode
2024-04-08 08:37:59.882 UTC [41125][startup] LOG:  redo starts at 0/3004738
2024-04-08 08:37:59.882 UTC [41125][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-04-08 08:37:59.882 UTC [41115][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-08 08:37:59.883 UTC [41125][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
2024-04-08 08:37:59.889 UTC [41129][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-08 08:37:59.944 UTC [41149][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:37:59.945 UTC [41149][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:37:59.945 UTC [41149][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:37:59.953 UTC [41149][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-08 08:37:59.954 UTC [41149][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:37:59.954 UTC [41149][client backend] [040_pg_createsubscriber.pl][0/4:0] LOG:  statement: SELECT setting FROM pg_catalog.pg_settings WHERE name IN ('max_logical_replication_workers', 'max_replication_slots', 'max_worker_processes', 'primary_slot_name') ORDER BY name
pg_createsubscriber: checking settings on publisher
2024-04-08 08:37:59.956 UTC [41149][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.011 user=postgres database=pg1 host=[local]
pg_createsubscriber: primary has replication slot "physical_slot"
pg_createsubscriber: stopping the subscriber
2024-04-08 08:37:59.989 UTC [41115][postmaster] LOG:  received fast shutdown request
2024-04-08 08:37:59.989 UTC [41115][postmaster] LOG:  aborting any active transactions
2024-04-08 08:37:59.989 UTC [41129][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-08 08:37:59.990 UTC [41123][checkpointer] LOG:  shutting down
2024-04-08 08:37:59.991 UTC [41115][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: creating publication "pg_createsubscriber_16384_c6518723" on database "pg1"
pg_createsubscriber: creating the replication slot "replslot1" on database "pg1"
pg_createsubscriber: create replication slot "replslot1" on publisher
pg_createsubscriber: starting the subscriber
2024-04-08 08:38:00.198 UTC [41201][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-08 08:38:00.198 UTC [41201][postmaster] LOG:  listening on Unix socket "/tmp/nSiycYJWMV/.s.PGSQL.55460"
2024-04-08 08:38:00.202 UTC [41206][startup] LOG:  database system was shut down in recovery at 2024-04-08 08:37:59 UTC
2024-04-08 08:38:00.208 UTC [41206][startup] LOG:  entering standby mode
2024-04-08 08:38:00.210 UTC [41206][startup] LOG:  redo starts at 0/3004738
2024-04-08 08:38:00.210 UTC [41206][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-04-08 08:38:00.210 UTC [41206][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
2024-04-08 08:38:00.210 UTC [41201][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-08 08:38:00.216 UTC [41208][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
pg_createsubscriber: server was started
pg_createsubscriber: waiting for the target server to reach the consistent state
2024-04-08 08:38:00.246 UTC [41219][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:38:00.247 UTC [41219][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:38:00.247 UTC [41219][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:38:00.252 UTC [41219][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-08 08:38:00.252 UTC [41219][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
pg_createsubscriber: target server reached the consistent state
pg_createsubscriber: hint: If pg_createsubscriber fails after this point, you must recreate the physical replica before continuing.
2024-04-08 08:38:00.253 UTC [41219][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.006 user=postgres database=pg1 host=[local]
2024-04-08 08:38:00.254 UTC [41224][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:38:00.255 UTC [41224][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:38:00.255 UTC [41224][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:38:00.256 UTC [41224][client backend] [040_pg_createsubscriber.pl][1/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
pg_createsubscriber: dropping publication "pg_createsubscriber_16384_c6518723" on database "pg1"
pg_createsubscriber: creating subscription "pg_createsubscriber_16384_c6518723" on database "pg1"
2024-04-08 08:38:00.256 UTC [41224][client backend] [040_pg_createsubscriber.pl][1/3:0] LOG:  statement: SELECT s.oid FROM pg_catalog.pg_subscription s INNER JOIN pg_catalog.pg_database d ON (s.subdbid = d.oid) WHERE s.subname = 'pg_createsubscriber_16384_c6518723' AND d.datname = 'pg1'
pg_createsubscriber: setting the replication progress (node name "pg_0" ; LSN 0/0) on database "pg1"
pg_createsubscriber: enabling subscription "pg_createsubscriber_16384_c6518723" on database "pg1"
2024-04-08 08:38:00.258 UTC [41224][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.003 user=postgres database=pg1 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: stopping the subscriber
2024-04-08 08:38:00.262 UTC [41201][postmaster] LOG:  received fast shutdown request
2024-04-08 08:38:00.262 UTC [41201][postmaster] LOG:  aborting any active transactions
2024-04-08 08:38:00.263 UTC [41208][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-08 08:38:00.264 UTC [41204][checkpointer] LOG:  shutting down
2024-04-08 08:38:00.266 UTC [41201][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7355412730352173193 on subscriber
pg_createsubscriber: running pg_resetwal on the subscriber
pg_createsubscriber: Done!
[08:38:00.365](0.725s) ok 26 - run pg_createsubscriber without --databases
# Running: pg_createsubscriber --verbose --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55458 host=/tmp/nSiycYJWMV dbname='pg1' --socket-directory /tmp/nSiycYJWMV --subscriber-port 55460 --publication pub1 --publication Pub2 --replication-slot replslot1 --replication-slot replslot2 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: pg_ctl path is:  /tmp/cirrus-ci-build/build/tmp_install/usr/local/pgsql/bin/pg_ctl
pg_createsubscriber: pg_resetwal path is:  /tmp/cirrus-ci-build/build/tmp_install/usr/local/pgsql/bin/pg_resetwal
pg_createsubscriber: checking if directory "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" is a cluster data directory
pg_createsubscriber: publisher(0): publication: pub1 ; replication slot: replslot1 ; connection string: host=/tmp/nSiycYJWMV port=55458 dbname=pg1
pg_createsubscriber: subscriber(0): subscription: (auto) ; connection string: port=55460 host=/tmp/nSiycYJWMV fallback_application_name=pg_createsubscriber dbname=pg1
pg_createsubscriber: publisher(1): publication: Pub2 ; replication slot: replslot2 ; connection string: host=/tmp/nSiycYJWMV port=55458 dbname=pg2
pg_createsubscriber: subscriber(1): subscription: (auto) ; connection string: port=55460 host=/tmp/nSiycYJWMV fallback_application_name=pg_createsubscriber dbname=pg2
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7355412330532160869 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7355412330532160869 on subscriber
pg_createsubscriber: starting the standby with command-line options
pg_createsubscriber: pg_ctl command is: "/tmp/cirrus-ci-build/build/tmp_install/usr/local/pgsql/bin/pg_ctl" start -D "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" -s -o "-p 55460" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/tmp/nSiycYJWMV'"
2024-04-08 08:38:00.408 UTC [41287][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-08 08:38:00.408 UTC [41287][postmaster] LOG:  listening on Unix socket "/tmp/nSiycYJWMV/.s.PGSQL.55460"
2024-04-08 08:38:00.414 UTC [41295][startup] LOG:  database system was shut down in recovery at 2024-04-08 08:38:00 UTC
2024-04-08 08:38:00.415 UTC [41295][startup] LOG:  entering standby mode
2024-04-08 08:38:00.416 UTC [41295][startup] LOG:  redo starts at 0/3004738
2024-04-08 08:38:00.416 UTC [41295][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-04-08 08:38:00.416 UTC [41295][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
2024-04-08 08:38:00.416 UTC [41287][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-08 08:38:00.419 UTC [41296][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-08 08:38:00.493 UTC [41310][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:38:00.493 UTC [41310][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:38:00.493 UTC [41310][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:38:00.521 UTC [41310][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-08 08:38:00.521 UTC [41310][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:00.522 UTC [41310][client backend] [040_pg_createsubscriber.pl][0/4:0] LOG:  statement: SELECT setting FROM pg_catalog.pg_settings WHERE name IN ('max_logical_replication_workers', 'max_replication_slots', 'max_worker_processes', 'primary_slot_name') ORDER BY name
pg_createsubscriber: subscriber: max_logical_replication_workers: 4
pg_createsubscriber: subscriber: max_replication_slots: 10
pg_createsubscriber: subscriber: max_worker_processes: 8
pg_createsubscriber: subscriber: primary_slot_name: physical_slot
pg_createsubscriber: checking settings on publisher
2024-04-08 08:38:00.524 UTC [41310][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=postgres database=pg1 host=[local]
pg_createsubscriber: publisher: wal_level: logical
pg_createsubscriber: publisher: max_replication_slots: 10
pg_createsubscriber: publisher: current replication slots: 1
pg_createsubscriber: publisher: max_wal_senders: 10
pg_createsubscriber: publisher: current wal senders: 1
pg_createsubscriber: command is: SELECT 1 FROM pg_catalog.pg_replication_slots WHERE active AND slot_name = 'physical_slot'
pg_createsubscriber: primary has replication slot "physical_slot"
pg_createsubscriber: stopping the subscriber
pg_createsubscriber: pg_ctl command is: "/tmp/cirrus-ci-build/build/tmp_install/usr/local/pgsql/bin/pg_ctl" stop -D "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" -s
2024-04-08 08:38:00.552 UTC [41287][postmaster] LOG:  received fast shutdown request
2024-04-08 08:38:00.552 UTC [41287][postmaster] LOG:  aborting any active transactions
2024-04-08 08:38:00.553 UTC [41296][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-08 08:38:00.554 UTC [41293][checkpointer] LOG:  shutting down
2024-04-08 08:38:00.557 UTC [41287][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: creating publication "pub1" on database "pg1"
pg_createsubscriber: command is: CREATE PUBLICATION "pub1" FOR ALL TABLES
pg_createsubscriber: creating the replication slot "replslot1" on database "pg1"
pg_createsubscriber: command is: SELECT lsn FROM pg_catalog.pg_create_logical_replication_slot('replslot1', 'pgoutput', false, false, false)
pg_createsubscriber: create replication slot "replslot1" on publisher
pg_createsubscriber: creating publication "Pub2" on database "pg2"
pg_createsubscriber: command is: CREATE PUBLICATION "Pub2" FOR ALL TABLES
pg_createsubscriber: creating the replication slot "replslot2" on database "pg2"
pg_createsubscriber: command is: SELECT lsn FROM pg_catalog.pg_create_logical_replication_slot('replslot2', 'pgoutput', false, false, false)
pg_createsubscriber: create replication slot "replslot2" on publisher
pg_createsubscriber: recovery parameters:
primary_conninfo = 'user=postgres passfile=''/home/postgres/.pgpass'' channel_binding=prefer host=''/tmp/nSiycYJWMV'' port=55458 application_name=040_pg_createsubscriber.pl sslmode=prefer sslnegotiation=postgres sslcompression=0 sslcertmode=allow sslsni=1 ssl_min_protocol_version=TLSv1.2 gssencmode=prefer krbsrvname=postgres gssdelegation=0 target_session_attrs=any load_balance_hosts=disable'
recovery_target = ''
recovery_target_timeline = 'latest'
recovery_target_inclusive = true
recovery_target_action = promote
recovery_target_name = ''
recovery_target_time = ''
recovery_target_xid = ''
recovery_target_lsn = '0/30092C0'
pg_createsubscriber: starting the subscriber
pg_createsubscriber: pg_ctl command is: "/tmp/cirrus-ci-build/build/tmp_install/usr/local/pgsql/bin/pg_ctl" start -D "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" -s -o "-p 55460" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/tmp/nSiycYJWMV'"
2024-04-08 08:38:00.944 UTC [41401][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-08 08:38:00.944 UTC [41401][postmaster] LOG:  listening on Unix socket "/tmp/nSiycYJWMV/.s.PGSQL.55460"
2024-04-08 08:38:01.024 UTC [41406][startup] LOG:  database system was shut down in recovery at 2024-04-08 08:38:00 UTC
2024-04-08 08:38:01.024 UTC [41406][startup] LOG:  entering standby mode
2024-04-08 08:38:01.025 UTC [41406][startup] LOG:  redo starts at 0/3004738
2024-04-08 08:38:01.026 UTC [41406][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-04-08 08:38:01.026 UTC [41401][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-08 08:38:01.026 UTC [41406][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
pg_createsubscriber: server was started
pg_createsubscriber: waiting for the target server to reach the consistent state
2024-04-08 08:38:01.042 UTC [41411][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:38:01.085 UTC [41411][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:38:01.085 UTC [41411][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:38:01.088 UTC [41408][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-04-08 08:38:01.090 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-08 08:38:01.090 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:01.090 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/4:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:02.091 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/5:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:02.091 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/6:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:03.092 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/7:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:03.092 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/8:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:04.092 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/9:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:04.093 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/10:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:05.093 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/11:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:05.093 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/12:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:06.093 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/13:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:06.094 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/14:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:07.094 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/15:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:07.094 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/16:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:08.095 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/17:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:08.095 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/18:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:09.095 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/19:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:09.096 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/20:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:10.096 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/21:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:10.096 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/22:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:11.096 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/23:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:11.097 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/24:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:12.097 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/25:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:12.098 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/26:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:13.103 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/27:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-08 08:38:13.103 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/28:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-08 08:38:13.630 UTC [41406][startup] LOG:  recovery stopping after WAL location (LSN) "0/30092C0"
2024-04-08 08:38:13.630 UTC [41406][startup] LOG:  redo done at 0/30092C0 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 12.60 s
2024-04-08 08:38:13.630 UTC [41406][startup] LOG:  last completed transaction was at log time 2024-04-08 08:38:00.866333+00
2024-04-08 08:38:13.630 UTC [41408][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-08 08:38:13.632 UTC [41406][startup] LOG:  selected new timeline ID: 2
2024-04-08 08:38:13.646 UTC [41406][startup] LOG:  archive recovery complete
2024-04-08 08:38:13.646 UTC [41404][checkpointer] LOG:  checkpoint starting: end-of-recovery immediate wait
2024-04-08 08:38:13.646 UTC [41404][checkpointer] LOG:  checkpoint complete: wrote 16 buffers (12.5%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=19 kB, estimate=19 kB; lsn=0/30092F8, redo lsn=0/30092F8
2024-04-08 08:38:13.651 UTC [41401][postmaster] LOG:  database system is ready to accept connections
2024-04-08 08:38:14.103 UTC [41411][client backend] [040_pg_createsubscriber.pl][0/29:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
pg_createsubscriber: target server reached the consistent state
pg_createsubscriber: hint: If pg_createsubscriber fails after this point, you must recreate the physical replica before continuing.
2024-04-08 08:38:14.104 UTC [41411][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:13.065 user=postgres database=pg1 host=[local]
2024-04-08 08:38:14.121 UTC [44074][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-08 08:38:14.122 UTC [44074][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-08 08:38:14.122 UTC [44074][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-08 08:38:14.133 UTC [44074][client backend] [040_pg_createsubscriber.pl][1/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
pg_createsubscriber: dropping publication "pub1" on database "pg1"
pg_createsubscriber: command is: DROP PUBLICATION "pub1"
2024-04-08 08:38:14.134 UTC [44074][client backend] [040_pg_createsubscriber.pl][1/3:0] LOG:  statement: DROP PUBLICATION "pub1"
pg_createsubscriber: creating subscription "pg_createsubscriber_16384_4f5993e3" on database "pg1"
pg_createsubscriber: command is: CREATE SUBSCRIPTION "pg_createsubscriber_16384_4f5993e3" CONNECTION 'host=/tmp/nSiycYJWMV port=55458 dbname=pg1' PUBLICATION "pub1" WITH (create_slot = false, enabled = false, slot_name = 'replslot1', copy_data = false)
2024-04-08 08:38:14.134 UTC [44074][client backend] [040_pg_createsubscriber.pl][1/4:0] LOG:  statement: CREATE SUBSCRIPTION "pg_createsubscriber_16384_4f5993e3" CONNECTION 'host=/tmp/nSiycYJWMV port=55458 dbname=pg1' PUBLICATION "pub1" WITH (create_slot = false, enabled = false, slot_name = 'replslot1', copy_data = false)
2024-04-08 08:38:14.135 UTC [44074][client backend] [040_pg_createsubscriber.pl][1/4:748] ERROR:  could not connect to the publisher: connection to server on socket "/tmp/nSiycYJWMV/.s.PGSQL.55458" failed: No such file or directory
		Is the server running locally and accepting connections on that socket?
2024-04-08 08:38:14.135 UTC [44074][client backend] [040_pg_createsubscriber.pl][1/4:748] STATEMENT:  CREATE SUBSCRIPTION "pg_createsubscriber_16384_4f5993e3" CONNECTION 'host=/tmp/nSiycYJWMV port=55458 dbname=pg1' PUBLICATION "pub1" WITH (create_slot = false, enabled = false, slot_name = 'replslot1', copy_data = false)
pg_createsubscriber: error: could not create subscription "pg_createsubscriber_16384_4f5993e3" on database "pg1": ERROR:  could not connect to the publisher: connection to server on socket "/tmp/nSiycYJWMV/.s.PGSQL.55458" failed: No such file or directory
	Is the server running locally and accepting connections on that socket?
pg_createsubscriber: warning: failed after the end of recovery
pg_createsubscriber: hint: The target server cannot be used as a physical replica anymore.  You must recreate the physical replica before continuing.
pg_createsubscriber: error: connection to database failed: connection to server on socket "/tmp/nSiycYJWMV/.s.PGSQL.55458" failed: No such file or directory
	Is the server running locally and accepting connections on that socket?
pg_createsubscriber: warning: publication "pub1" in database "pg1" on primary might be left behind
pg_createsubscriber: hint: Consider dropping this publication before trying again.
pg_createsubscriber: warning: replication slot "replslot1" in database "pg1" on primary might be left behind
pg_createsubscriber: hint: Drop this replication slot soon to avoid retention of WAL files.
pg_createsubscriber: error: connection to database failed: connection to server on socket "/tmp/nSiycYJWMV/.s.PGSQL.55458" failed: No such file or directory
	Is the server running locally and accepting connections on that socket?
pg_createsubscriber: warning: publication "Pub2" in database "pg2" on primary might be left behind
pg_createsubscriber: hint: Consider dropping this publication before trying again.
pg_createsubscriber: warning: replication slot "replslot2" in database "pg2" on primary might be left behind
pg_createsubscriber: hint: Drop this replication slot soon to avoid retention of WAL files.
pg_createsubscriber: pg_ctl command is: "/tmp/cirrus-ci-build/build/tmp_install/usr/local/pgsql/bin/pg_ctl" stop -D "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" -s
2024-04-08 08:38:14.136 UTC [44074][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=postgres database=pg1 host=[local]
2024-04-08 08:38:14.146 UTC [41401][postmaster] LOG:  received fast shutdown request
2024-04-08 08:38:14.146 UTC [41401][postmaster] LOG:  aborting any active transactions
2024-04-08 08:38:14.148 UTC [41401][postmaster] LOG:  background worker "logical replication launcher" (PID 44020) exited with exit code 1
2024-04-08 08:38:14.148 UTC [41404][checkpointer] LOG:  shutting down
2024-04-08 08:38:14.148 UTC [41404][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-08 08:38:14.148 UTC [41404][checkpointer] LOG:  checkpoint complete: wrote 12 buffers (9.4%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=1 kB, estimate=17 kB; lsn=0/3009A98, redo lsn=0/3009A98
2024-04-08 08:38:14.149 UTC [41401][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[08:38:14.248](13.883s) not ok 27 - run pg_createsubscriber on node S
[08:38:14.249](0.000s) #   Failed test 'run pg_createsubscriber on node S'
#   at /tmp/cirrus-ci-build/src/bin/pg_basebackup/t/040_pg_createsubscriber.pl line 297.
connection error: 'psql: error: connection to server on socket "/tmp/nSiycYJWMV/.s.PGSQL.55458" failed: No such file or directory
	Is the server running locally and accepting connections on that socket?'
while running 'psql -XAtq -d port=55458 host=/tmp/nSiycYJWMV dbname='pg1' -f - -v ON_ERROR_STOP=1' at /tmp/cirrus-ci-build/src/test/perl/PostgreSQL/Test/Cluster.pm line 2040.
# No postmaster PID for node "node_p"
# No postmaster PID for node "node_f"
# No postmaster PID for node "node_s"
# No postmaster PID for node "node_t"
# No postmaster PID for node "node_c"
[08:38:14.268](0.020s) # Tests were run but no plan was declared and done_testing() was not seen.
[08:38:14.268](0.000s) # Looks like your test exited with 4 just after 27.