# Running: pg_createsubscriber --help
[20:30:37.860](0.031s) ok 1 - pg_createsubscriber --help exit code 0
[20:30:37.861](0.001s) ok 2 - pg_createsubscriber --help goes to stdout
[20:30:37.867](0.006s) ok 3 - pg_createsubscriber --help nothing to stderr
[20:30:37.867](0.000s) ok 4 - pg_createsubscriber --help maximum line length
# Running: pg_createsubscriber --version
[20:30:37.873](0.006s) ok 5 - pg_createsubscriber --version exit code 0
[20:30:37.873](0.000s) ok 6 - pg_createsubscriber --version goes to stdout
[20:30:37.874](0.000s) ok 7 - pg_createsubscriber --version nothing to stderr
# Running: pg_createsubscriber --not-a-valid-option
[20:30:37.900](0.026s) ok 8 - pg_createsubscriber with invalid option nonzero exit code
[20:30:37.901](0.002s) 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.
[20:30:37.909](0.007s) 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_2fBW
pg_createsubscriber: error: no publisher connection string specified
pg_createsubscriber: hint: Try "pg_createsubscriber --help" for more information.
[20:30:37.930](0.021s) 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_2fBW --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.
[20:30:37.935](0.005s) 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_2fBW --publisher-server port=5432 --database pg1 --database pg1
pg_createsubscriber: error: duplicate database "pg1"
[20:30:37.939](0.004s) ok 13 - duplicate database name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_2fBW --publisher-server port=5432 --publication foo1 --publication foo1 --database pg1 --database pg2
pg_createsubscriber: error: duplicate publication "foo1"
[20:30:37.945](0.005s) ok 14 - duplicate publication name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_2fBW --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).
[20:30:37.952](0.007s) 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_2fBW --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).
[20:30:37.960](0.008s) 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_2fBW --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).
[20:30:37.964](0.005s) ok 17 - wrong number of replication slot names
# Checking port 51827
# Found port 51827
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=51827 host=/tmp/K7vOx6Kx2S
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_p.log
[20:30:37.968](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 22194
# Checking port 51828
# Found port 51828
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=51828 host=/tmp/K7vOx6Kx2S
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_f.log
[20:30:38.139](0.172s) # 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:  en_US.UTF-8
  LC_CTYPE:    en_US.UTF-8
  LC_MESSAGES: C
  LC_MONETARY: en_US.UTF-8
  LC_NUMERIC:  en_US.UTF-8
  LC_TIME:     en_US.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 ... 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
#### Begin standard error
psql:<stdin>:2: WARNING:  databases created by regression test cases should have names including "regression"
psql:<stdin>:3: WARNING:  databases created by regression test cases should have names including "regression"
#### End standard error
# 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/K7vOx6Kx2S -p 51827 --checkpoint fast --no-sync
# Backup finished
# Checking port 51829
# Found port 51829
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=51829 host=/tmp/K7vOx6Kx2S
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 22505
# Checking port 51830
# Found port 51830
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=51830 host=/tmp/K7vOx6Kx2S
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 22552
### 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=51827 host=/tmp/K7vOx6Kx2S dbname='pg1' --socket-directory /tmp/K7vOx6Kx2S --subscriber-port 51830 --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 7356338187978947184 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7356338187978947184 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-10 20:30:40.676 UTC [22623][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-freebsd, compiled by clang-14.0.5, 64-bit
2024-04-10 20:30:40.676 UTC [22623][postmaster] LOG:  listening on Unix socket "/tmp/K7vOx6Kx2S/.s.PGSQL.51830"
2024-04-10 20:30:40.686 UTC [22631][startup] LOG:  database system was shut down at 2024-04-10 20:30:40 UTC
2024-04-10 20:30:40.691 UTC [22623][postmaster] LOG:  database system is ready to accept connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-10 20:30:40.776 UTC [22647][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:40.776 UTC [22647][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-10 20:30:40.776 UTC [22647][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:40.822 UTC [22647][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-10 20:30:40.823 UTC [22647][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-10 20:30:40.823 UTC [22647][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.046 user=postgres database=pg1 host=[local]
2024-04-10 20:30:40.827 UTC [22623][postmaster] LOG:  received fast shutdown request
2024-04-10 20:30:40.827 UTC [22623][postmaster] LOG:  aborting any active transactions
2024-04-10 20:30:40.829 UTC [22623][postmaster] LOG:  background worker "logical replication launcher" (PID 22634) exited with exit code 1
2024-04-10 20:30:40.829 UTC [22629][checkpointer] LOG:  shutting down
2024-04-10 20:30:40.829 UTC [22629][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-10 20:30:40.830 UTC [22629][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-10 20:30:40.839 UTC [22623][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[20:30:40.933](2.794s) 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=51827 host=/tmp/K7vOx6Kx2S dbname='pg1' --socket-directory /tmp/K7vOx6Kx2S --subscriber-port 51829 --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 7356338187978947184 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7356338187978947184 on subscriber
pg_createsubscriber: error: standby is up and running
pg_createsubscriber: hint: Stop the standby and try again.
[20:30:40.954](0.021s) 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=51827 host=/tmp/K7vOx6Kx2S dbname='pg1' --socket-directory /tmp/K7vOx6Kx2S --subscriber-port 51828 --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 7356338187978947184 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7356338544479512268 on subscriber
pg_createsubscriber: error: subscriber data directory is not a copy of the source database cluster
[20:30:40.978](0.024s) 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/K7vOx6Kx2S -p 51829 --checkpoint fast --no-sync
# Backup finished
# Checking port 51831
# Found port 51831
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=51831 host=/tmp/K7vOx6Kx2S
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=51829 host=/tmp/K7vOx6Kx2S dbname='pg1' --socket-directory /tmp/K7vOx6Kx2S --subscriber-port 51831 --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 7356338187978947184 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7356338187978947184 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-10 20:30:41.411 UTC [22758][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-freebsd, compiled by clang-14.0.5, 64-bit
2024-04-10 20:30:41.411 UTC [22758][postmaster] LOG:  listening on Unix socket "/tmp/K7vOx6Kx2S/.s.PGSQL.51831"
2024-04-10 20:30:41.413 UTC [22762][startup] LOG:  database system was interrupted while in recovery at log time 2024-04-10 20:30:39 UTC
2024-04-10 20:30:41.413 UTC [22762][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-10 20:30:41.413 UTC [22762][startup] LOG:  starting backup recovery with redo LSN 0/2000028, checkpoint LSN 0/2000080, on timeline ID 1
2024-04-10 20:30:41.413 UTC [22762][startup] LOG:  entering standby mode
2024-04-10 20:30:41.421 UTC [22762][startup] LOG:  redo starts at 0/2000028
2024-04-10 20:30:41.421 UTC [22762][startup] LOG:  completed backup recovery with redo LSN 0/2000028 and end LSN 0/2000120
2024-04-10 20:30:41.421 UTC [22762][startup] LOG:  consistent recovery state reached at 0/3000000
2024-04-10 20:30:41.421 UTC [22758][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-10 20:30:41.437 UTC [22766][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-10 20:30:41.537 UTC [22806][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:41.538 UTC [22806][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-10 20:30:41.538 UTC [22806][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:41.564 UTC [22806][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-10 20:30:41.571 UTC [22806][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:41.578 UTC [22806][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
2024-04-10 20:30:41.582 UTC [22806][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.044 user=postgres database=pg1 host=[local]
pg_createsubscriber: checking settings on publisher
pg_createsubscriber: error: primary server cannot be in recovery
2024-04-10 20:30:41.599 UTC [22758][postmaster] LOG:  received fast shutdown request
2024-04-10 20:30:41.599 UTC [22758][postmaster] LOG:  aborting any active transactions
2024-04-10 20:30:41.601 UTC [22766][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-10 20:30:41.602 UTC [22760][checkpointer] LOG:  shutting down
2024-04-10 20:30:41.608 UTC [22758][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[20:30:41.704](0.726s) 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 22867
### 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=51827 host=/tmp/K7vOx6Kx2S dbname='pg1' --socket-directory /tmp/K7vOx6Kx2S --subscriber-port 51829 --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 7356338187978947184 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7356338187978947184 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-10 20:30:42.377 UTC [22893][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-freebsd, compiled by clang-14.0.5, 64-bit
2024-04-10 20:30:42.377 UTC [22893][postmaster] LOG:  listening on Unix socket "/tmp/K7vOx6Kx2S/.s.PGSQL.51829"
2024-04-10 20:30:42.385 UTC [22896][startup] LOG:  database system was shut down in recovery at 2024-04-10 20:30:42 UTC
2024-04-10 20:30:42.385 UTC [22896][startup] LOG:  entering standby mode
2024-04-10 20:30:42.386 UTC [22896][startup] LOG:  consistent recovery state reached at 0/3000188
2024-04-10 20:30:42.386 UTC [22896][startup] LOG:  invalid record length at 0/3000188: expected at least 24, got 0
2024-04-10 20:30:42.386 UTC [22893][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-10 20:30:42.390 UTC [22897][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-04-10 20:30:42.390 UTC [22896][startup] LOG:  redo starts at 0/3000188
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-10 20:30:42.462 UTC [22905][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:42.462 UTC [22905][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-10 20:30:42.462 UTC [22905][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:42.502 UTC [22905][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-10 20:30:42.503 UTC [22905][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:42.515 UTC [22905][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
2024-04-10 20:30:42.522 UTC [22905][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.060 user=postgres database=pg1 host=[local]
pg_createsubscriber: checking settings on publisher
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-10 20:30:42.565 UTC [22893][postmaster] LOG:  received fast shutdown request
2024-04-10 20:30:42.565 UTC [22893][postmaster] LOG:  aborting any active transactions
2024-04-10 20:30:42.567 UTC [22897][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-10 20:30:42.579 UTC [22894][checkpointer] LOG:  shutting down
2024-04-10 20:30:42.596 UTC [22893][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[20:30:42.673](0.969s) 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=51827 host=/tmp/K7vOx6Kx2S dbname='pg1' --socket-directory /tmp/K7vOx6Kx2S --subscriber-port 51829 --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 7356338187978947184 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7356338187978947184 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-10 20:30:42.894 UTC [22937][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-freebsd, compiled by clang-14.0.5, 64-bit
2024-04-10 20:30:42.894 UTC [22937][postmaster] LOG:  listening on Unix socket "/tmp/K7vOx6Kx2S/.s.PGSQL.51829"
2024-04-10 20:30:42.899 UTC [22940][startup] LOG:  database system was shut down in recovery at 2024-04-10 20:30:42 UTC
2024-04-10 20:30:42.899 UTC [22940][startup] LOG:  entering standby mode
2024-04-10 20:30:42.924 UTC [22940][startup] LOG:  redo starts at 0/3000188
2024-04-10 20:30:42.924 UTC [22940][startup] LOG:  invalid magic number 0000 in WAL segment 000000010000000000000003, LSN 0/3004000, offset 16384
2024-04-10 20:30:42.924 UTC [22940][startup] LOG:  consistent recovery state reached at 0/3002758
2024-04-10 20:30:42.924 UTC [22937][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-10 20:30:42.924 UTC [22940][startup] LOG:  invalid magic number 0000 in WAL segment 000000010000000000000003, LSN 0/3004000, offset 16384
2024-04-10 20:30:42.939 UTC [22941][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-10 20:30:42.993 UTC [22943][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:42.994 UTC [22943][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-10 20:30:42.994 UTC [22943][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:43.010 UTC [22943][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-10 20:30:43.012 UTC [22943][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:43.019 UTC [22943][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
2024-04-10 20:30:43.023 UTC [22943][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=postgres database=pg1 host=[local]
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-10 20:30:43.029 UTC [22937][postmaster] LOG:  received fast shutdown request
2024-04-10 20:30:43.029 UTC [22937][postmaster] LOG:  aborting any active transactions
2024-04-10 20:30:43.031 UTC [22941][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-10 20:30:43.036 UTC [22938][checkpointer] LOG:  shutting down
2024-04-10 20:30:43.042 UTC [22937][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[20:30:43.136](0.462s) 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 22976
# 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=51827 host=/tmp/K7vOx6Kx2S dbname='pg1' --socket-directory /tmp/K7vOx6Kx2S --subscriber-port 51829 --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 7356338187978947184 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7356338187978947184 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-10 20:30:43.484 UTC [23005][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-freebsd, compiled by clang-14.0.5, 64-bit
2024-04-10 20:30:43.484 UTC [23005][postmaster] LOG:  listening on Unix socket "/tmp/K7vOx6Kx2S/.s.PGSQL.51829"
2024-04-10 20:30:43.524 UTC [23011][startup] LOG:  database system was shut down in recovery at 2024-04-10 20:30:43 UTC
2024-04-10 20:30:43.524 UTC [23011][startup] LOG:  entering standby mode
2024-04-10 20:30:43.533 UTC [23011][startup] LOG:  redo starts at 0/3000188
2024-04-10 20:30:43.533 UTC [23011][startup] LOG:  consistent recovery state reached at 0/30046C0
2024-04-10 20:30:43.533 UTC [23005][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-10 20:30:43.536 UTC [23011][startup] LOG:  invalid record length at 0/30046C0: expected at least 24, got 0
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-10 20:30:43.588 UTC [23016][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:43.589 UTC [23016][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-10 20:30:43.589 UTC [23016][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:43.615 UTC [23016][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-10 20:30:43.615 UTC [23016][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:43.616 UTC [23016][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-10 20:30:43.620 UTC [23016][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=postgres database=pg1 host=[local]
pg_createsubscriber: error: could not obtain replication slot information: got 0 rows, expected 1 row
2024-04-10 20:30:43.644 UTC [23005][postmaster] LOG:  received fast shutdown request
2024-04-10 20:30:43.644 UTC [23005][postmaster] LOG:  aborting any active transactions
2024-04-10 20:30:43.648 UTC [23014][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-10 20:30:43.648 UTC [23009][checkpointer] LOG:  shutting down
2024-04-10 20:30:43.653 UTC [23005][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[20:30:43.752](0.616s) not ok 24 - run pg_createsubscriber --dry-run on node S
[20:30:43.753](0.002s) #   Failed test 'run pg_createsubscriber --dry-run on node S'
#   at /tmp/cirrus-ci-build/src/bin/pg_basebackup/t/040_pg_createsubscriber.pl line 260.
### 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 23042
[20:30:43.901](0.148s) 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=51827 host=/tmp/K7vOx6Kx2S dbname='pg1' --socket-directory /tmp/K7vOx6Kx2S --subscriber-port 51829 --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 7356338187978947184 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7356338187978947184 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-10 20:30:44.082 UTC [23084][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-freebsd, compiled by clang-14.0.5, 64-bit
2024-04-10 20:30:44.082 UTC [23084][postmaster] LOG:  listening on Unix socket "/tmp/K7vOx6Kx2S/.s.PGSQL.51829"
2024-04-10 20:30:44.084 UTC [23087][startup] LOG:  database system was shut down in recovery at 2024-04-10 20:30:43 UTC
2024-04-10 20:30:44.084 UTC [23087][startup] LOG:  entering standby mode
2024-04-10 20:30:44.085 UTC [23087][startup] LOG:  redo starts at 0/3004738
2024-04-10 20:30:44.085 UTC [23087][startup] LOG:  consistent recovery state reached at 0/3004770
2024-04-10 20:30:44.085 UTC [23084][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-10 20:30:44.085 UTC [23087][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
2024-04-10 20:30:44.092 UTC [23088][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-10 20:30:44.184 UTC [23094][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:44.184 UTC [23094][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-10 20:30:44.185 UTC [23094][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:44.193 UTC [23094][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-10 20:30:44.194 UTC [23094][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:44.194 UTC [23094][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
2024-04-10 20:30:44.197 UTC [23094][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=postgres database=pg1 host=[local]
pg_createsubscriber: checking settings on publisher
pg_createsubscriber: primary has replication slot "physical_slot"
pg_createsubscriber: stopping the subscriber
2024-04-10 20:30:44.241 UTC [23084][postmaster] LOG:  received fast shutdown request
2024-04-10 20:30:44.241 UTC [23084][postmaster] LOG:  aborting any active transactions
2024-04-10 20:30:44.246 UTC [23088][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-10 20:30:44.251 UTC [23085][checkpointer] LOG:  shutting down
2024-04-10 20:30:44.255 UTC [23084][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: creating publication "pg_createsubscriber_16384_eddacca6" 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-10 20:30:44.398 UTC [23120][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-freebsd, compiled by clang-14.0.5, 64-bit
2024-04-10 20:30:44.398 UTC [23120][postmaster] LOG:  listening on Unix socket "/tmp/K7vOx6Kx2S/.s.PGSQL.51829"
2024-04-10 20:30:44.402 UTC [23124][startup] LOG:  database system was shut down in recovery at 2024-04-10 20:30:44 UTC
2024-04-10 20:30:44.402 UTC [23124][startup] LOG:  entering standby mode
2024-04-10 20:30:44.404 UTC [23124][startup] LOG:  redo starts at 0/3004738
2024-04-10 20:30:44.404 UTC [23124][startup] LOG:  consistent recovery state reached at 0/3004770
2024-04-10 20:30:44.404 UTC [23120][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-10 20:30:44.404 UTC [23124][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
2024-04-10 20:30:44.421 UTC [23125][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-10 20:30:44.493 UTC [23132][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:44.494 UTC [23132][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-10 20:30:44.494 UTC [23132][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:44.499 UTC [23132][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-10 20:30:44.500 UTC [23132][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:44.501 UTC [23132][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=postgres database=pg1 host=[local]
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-10 20:30:44.502 UTC [23134][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:44.503 UTC [23134][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-10 20:30:44.503 UTC [23134][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:44.503 UTC [23134][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_eddacca6" on database "pg1"
pg_createsubscriber: creating subscription "pg_createsubscriber_16384_eddacca6" on database "pg1"
2024-04-10 20:30:44.504 UTC [23134][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_eddacca6' 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_eddacca6" on database "pg1"
2024-04-10 20:30:44.511 UTC [23134][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=postgres database=pg1 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: stopping the subscriber
2024-04-10 20:30:44.522 UTC [23120][postmaster] LOG:  received fast shutdown request
2024-04-10 20:30:44.522 UTC [23120][postmaster] LOG:  aborting any active transactions
2024-04-10 20:30:44.527 UTC [23125][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-10 20:30:44.528 UTC [23122][checkpointer] LOG:  shutting down
2024-04-10 20:30:44.543 UTC [23120][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7356338571776920098 on subscriber
pg_createsubscriber: running pg_resetwal on the subscriber
pg_createsubscriber: Done!
[20:30:44.632](0.731s) 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=51827 host=/tmp/K7vOx6Kx2S dbname='pg1' --socket-directory /tmp/K7vOx6Kx2S --subscriber-port 51829 --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/K7vOx6Kx2S port=51827 dbname=pg1
pg_createsubscriber: subscriber(0): subscription: (auto) ; connection string: port=51829 host=/tmp/K7vOx6Kx2S fallback_application_name=pg_createsubscriber dbname=pg1
pg_createsubscriber: publisher(1): publication: Pub2 ; replication slot: replslot2 ; connection string: host=/tmp/K7vOx6Kx2S port=51827 dbname=pg2
pg_createsubscriber: subscriber(1): subscription: (auto) ; connection string: port=51829 host=/tmp/K7vOx6Kx2S fallback_application_name=pg_createsubscriber dbname=pg2
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7356338187978947184 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7356338187978947184 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 51829" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/tmp/K7vOx6Kx2S'"
2024-04-10 20:30:44.689 UTC [23164][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-freebsd, compiled by clang-14.0.5, 64-bit
2024-04-10 20:30:44.689 UTC [23164][postmaster] LOG:  listening on Unix socket "/tmp/K7vOx6Kx2S/.s.PGSQL.51829"
2024-04-10 20:30:44.696 UTC [23168][startup] LOG:  database system was shut down in recovery at 2024-04-10 20:30:44 UTC
2024-04-10 20:30:44.696 UTC [23168][startup] LOG:  entering standby mode
2024-04-10 20:30:44.697 UTC [23168][startup] LOG:  redo starts at 0/3004738
2024-04-10 20:30:44.697 UTC [23168][startup] LOG:  consistent recovery state reached at 0/3004770
2024-04-10 20:30:44.697 UTC [23164][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-10 20:30:44.700 UTC [23168][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
2024-04-10 20:30:44.712 UTC [23171][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-10 20:30:44.791 UTC [23183][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:44.792 UTC [23183][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-10 20:30:44.792 UTC [23183][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:44.806 UTC [23183][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-10 20:30:44.813 UTC [23183][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:44.814 UTC [23183][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-10 20:30:44.818 UTC [23183][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.026 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-10 20:30:44.837 UTC [23164][postmaster] LOG:  received fast shutdown request
2024-04-10 20:30:44.837 UTC [23164][postmaster] LOG:  aborting any active transactions
2024-04-10 20:30:44.840 UTC [23171][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-10 20:30:44.841 UTC [23166][checkpointer] LOG:  shutting down
2024-04-10 20:30:44.849 UTC [23164][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/K7vOx6Kx2S'' port=51827 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 51829" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/tmp/K7vOx6Kx2S'"
2024-04-10 20:30:45.049 UTC [23215][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-freebsd, compiled by clang-14.0.5, 64-bit
2024-04-10 20:30:45.049 UTC [23215][postmaster] LOG:  listening on Unix socket "/tmp/K7vOx6Kx2S/.s.PGSQL.51829"
2024-04-10 20:30:45.074 UTC [23221][startup] LOG:  database system was shut down in recovery at 2024-04-10 20:30:44 UTC
2024-04-10 20:30:45.074 UTC [23221][startup] LOG:  entering standby mode
2024-04-10 20:30:45.079 UTC [23221][startup] LOG:  redo starts at 0/3004738
2024-04-10 20:30:45.079 UTC [23221][startup] LOG:  consistent recovery state reached at 0/3004770
2024-04-10 20:30:45.079 UTC [23215][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-10 20:30:45.079 UTC [23221][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
2024-04-10 20:30:45.104 UTC [23227][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-10 20:30:45.164 UTC [23236][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:45.164 UTC [23236][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-10 20:30:45.164 UTC [23236][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:45.176 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-10 20:30:45.182 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:45.188 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/4:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:46.195 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/5:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:46.196 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/6:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:47.209 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/7:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:47.209 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/8:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:48.215 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/9:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:48.215 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/10:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:49.231 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/11:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:49.231 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/12:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:50.235 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/13:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:50.235 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/14:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:51.245 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/15:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:51.245 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/16:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:52.263 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/17:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:52.263 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/18:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:53.265 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/19:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:53.265 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/20:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:54.275 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/21:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:54.275 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/22:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:55.286 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/23:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:55.286 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/24:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:56.299 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/25:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:56.299 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/26:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:57.310 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/27:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:57.310 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/28:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:58.307 UTC [23221][startup] LOG:  recovery stopping after WAL location (LSN) "0/30092C0"
2024-04-10 20:30:58.307 UTC [23221][startup] LOG:  redo done at 0/30092C0 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 13.22 s
2024-04-10 20:30:58.307 UTC [23221][startup] LOG:  last completed transaction was at log time 2024-04-10 20:30:45.015512+00
2024-04-10 20:30:58.307 UTC [23227][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-10 20:30:58.309 UTC [23221][startup] LOG:  selected new timeline ID: 2
2024-04-10 20:30:58.317 UTC [23221][startup] LOG:  archive recovery complete
2024-04-10 20:30:58.318 UTC [23217][checkpointer] LOG:  checkpoint starting: end-of-recovery immediate wait
2024-04-10 20:30:58.318 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/29:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-10 20:30:58.318 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/30:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-10 20:30:58.318 UTC [23217][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-10 20:30:58.320 UTC [23215][postmaster] LOG:  database system is ready to accept connections
2024-04-10 20:30:59.326 UTC [23236][client backend] [040_pg_createsubscriber.pl][0/31: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-10 20:30:59.326 UTC [23236][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:14.162 user=postgres database=pg1 host=[local]
2024-04-10 20:30:59.327 UTC [25570][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:59.327 UTC [25570][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-10 20:30:59.327 UTC [25570][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:59.328 UTC [25570][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-10 20:30:59.329 UTC [25570][client backend] [040_pg_createsubscriber.pl][1/3:0] LOG:  statement: DROP PUBLICATION "pub1"
pg_createsubscriber: creating subscription "pg_createsubscriber_16384_b44844f9" on database "pg1"
pg_createsubscriber: command is: CREATE SUBSCRIPTION "pg_createsubscriber_16384_b44844f9" CONNECTION 'host=/tmp/K7vOx6Kx2S port=51827 dbname=pg1' PUBLICATION "pub1" WITH (create_slot = false, enabled = false, slot_name = 'replslot1', copy_data = false)
2024-04-10 20:30:59.330 UTC [25570][client backend] [040_pg_createsubscriber.pl][1/4:0] LOG:  statement: CREATE SUBSCRIPTION "pg_createsubscriber_16384_b44844f9" CONNECTION 'host=/tmp/K7vOx6Kx2S port=51827 dbname=pg1' PUBLICATION "pub1" WITH (create_slot = false, enabled = false, slot_name = 'replslot1', copy_data = false)
2024-04-10 20:30:59.330 UTC [25570][client backend] [040_pg_createsubscriber.pl][1/4:0] WARNING:  subscriptions created by regression test cases should have names starting with "regress_"
WARNING:  subscriptions created by regression test cases should have names starting with "regress_"
2024-04-10 20:30:59.342 UTC [25570][client backend] [040_pg_createsubscriber.pl][1/5: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_b44844f9' AND d.datname = 'pg1'
pg_createsubscriber: setting the replication progress (node name "pg_24588" ; LSN 0/30092C0) on database "pg1"
pg_createsubscriber: command is: SELECT pg_catalog.pg_replication_origin_advance('pg_24588', '0/30092C0')
2024-04-10 20:30:59.345 UTC [25570][client backend] [040_pg_createsubscriber.pl][1/6:0] LOG:  statement: SELECT pg_catalog.pg_replication_origin_advance('pg_24588', '0/30092C0')
pg_createsubscriber: enabling subscription "pg_createsubscriber_16384_b44844f9" on database "pg1"
pg_createsubscriber: command is: ALTER SUBSCRIPTION "pg_createsubscriber_16384_b44844f9" ENABLE
2024-04-10 20:30:59.346 UTC [25570][client backend] [040_pg_createsubscriber.pl][1/7:0] LOG:  statement: ALTER SUBSCRIPTION "pg_createsubscriber_16384_b44844f9" ENABLE
2024-04-10 20:30:59.346 UTC [25570][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=postgres database=pg1 host=[local]
2024-04-10 20:30:59.347 UTC [25576][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-10 20:30:59.347 UTC [25576][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-10 20:30:59.347 UTC [25576][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=pg2 application_name=040_pg_createsubscriber.pl
2024-04-10 20:30:59.351 UTC [25575][logical replication apply worker] LOG:  logical replication apply worker for subscription "pg_createsubscriber_16384_b44844f9" has started
2024-04-10 20:30:59.351 UTC [25576][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: command is: DROP PUBLICATION "Pub2"
2024-04-10 20:30:59.352 UTC [25576][client backend] [040_pg_createsubscriber.pl][2/3:0] LOG:  statement: DROP PUBLICATION "Pub2"
pg_createsubscriber: creating subscription "pg_createsubscriber_16385_690d442" on database "pg2"
pg_createsubscriber: command is: CREATE SUBSCRIPTION "pg_createsubscriber_16385_690d442" CONNECTION 'host=/tmp/K7vOx6Kx2S port=51827 dbname=pg2' PUBLICATION "Pub2" WITH (create_slot = false, enabled = false, slot_name = 'replslot2', copy_data = false)
2024-04-10 20:30:59.353 UTC [25576][client backend] [040_pg_createsubscriber.pl][2/4:0] LOG:  statement: CREATE SUBSCRIPTION "pg_createsubscriber_16385_690d442" CONNECTION 'host=/tmp/K7vOx6Kx2S port=51827 dbname=pg2' PUBLICATION "Pub2" WITH (create_slot = false, enabled = false, slot_name = 'replslot2', copy_data = false)
2024-04-10 20:30:59.353 UTC [25576][client backend] [040_pg_createsubscriber.pl][2/4:0] WARNING:  subscriptions created by regression test cases should have names starting with "regress_"
WARNING:  subscriptions created by regression test cases should have names starting with "regress_"
2024-04-10 20:30:59.366 UTC [25576][client backend] [040_pg_createsubscriber.pl][2/5: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_16385_690d442' AND d.datname = 'pg2'
pg_createsubscriber: setting the replication progress (node name "pg_24589" ; LSN 0/30092C0) on database "pg2"
pg_createsubscriber: command is: SELECT pg_catalog.pg_replication_origin_advance('pg_24589', '0/30092C0')
2024-04-10 20:30:59.368 UTC [25576][client backend] [040_pg_createsubscriber.pl][2/6:0] LOG:  statement: SELECT pg_catalog.pg_replication_origin_advance('pg_24589', '0/30092C0')
pg_createsubscriber: enabling subscription "pg_createsubscriber_16385_690d442" on database "pg2"
pg_createsubscriber: command is: ALTER SUBSCRIPTION "pg_createsubscriber_16385_690d442" ENABLE
2024-04-10 20:30:59.369 UTC [25576][client backend] [040_pg_createsubscriber.pl][2/7:0] LOG:  statement: ALTER SUBSCRIPTION "pg_createsubscriber_16385_690d442" ENABLE
2024-04-10 20:30:59.369 UTC [25576][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=postgres database=pg2 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: command is: SELECT pg_catalog.pg_drop_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-10 20:30:59.374 UTC [23215][postmaster] LOG:  received fast shutdown request
2024-04-10 20:30:59.374 UTC [23215][postmaster] LOG:  aborting any active transactions
2024-04-10 20:30:59.374 UTC [25575][logical replication apply worker] FATAL:  terminating logical replication worker due to administrator command
2024-04-10 20:30:59.374 UTC [25581][logical replication apply worker] LOG:  logical replication apply worker for subscription "pg_createsubscriber_16385_690d442" has started
2024-04-10 20:30:59.374 UTC [25581][logical replication apply worker] FATAL:  terminating logical replication worker due to administrator command
2024-04-10 20:30:59.375 UTC [23215][postmaster] LOG:  background worker "logical replication apply worker" (PID 25581) exited with exit code 1
2024-04-10 20:30:59.375 UTC [23215][postmaster] LOG:  background worker "logical replication launcher" (PID 25388) exited with exit code 1
2024-04-10 20:30:59.376 UTC [23215][postmaster] LOG:  background worker "logical replication apply worker" (PID 25575) exited with exit code 1
2024-04-10 20:30:59.376 UTC [23217][checkpointer] LOG:  shutting down
2024-04-10 20:30:59.376 UTC [23217][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-10 20:30:59.376 UTC [23217][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=23 kB, estimate=23 kB; lsn=0/300F1E8, redo lsn=0/300F1E8
2024-04-10 20:30:59.378 UTC [23215][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7356338635560323694 on subscriber
pg_createsubscriber: running pg_resetwal on the subscriber
pg_createsubscriber: pg_resetwal command is: "/tmp/cirrus-ci-build/build/tmp_install/usr/local/pgsql/bin/pg_resetwal" -D "/tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" > "/dev/null"
pg_createsubscriber: subscriber successfully changed the system identifier
pg_createsubscriber: Done!
[20:30:59.487](14.855s) ok 27 - run pg_createsubscriber on node S
[20:30:59.499](0.012s) ok 28 - the physical replication slot used as primary_slot_name has been removed
### 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 25625
Waiting for all subscriptions in "node_s" to synchronize data
Waiting for replication conn pg_createsubscriber_16384_b44844f9's replay_lsn to pass 0/3009480 on node_p
done
done
Waiting for all subscriptions in "node_s" to synchronize data
Waiting for replication conn pg_createsubscriber_16385_690d442's replay_lsn to pass 0/3009480 on node_p
done
done
[20:30:59.909](0.411s) ok 29 - logical replication works on database pg1
[20:30:59.925](0.015s) ok 30 - logical replication works on database pg2
[20:30:59.945](0.021s) ok 31 - system identifier was changed
### Stopping node "node_p" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "node_p"
### Stopping node "node_s" using mode immediate
# 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 immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "node_s"
[20:31:00.162](0.216s) 1..31
[20:31:00.164](0.002s) # Looks like you failed 1 test of 31.