# Running: pg_createsubscriber --help
[16:04:31.119](0.024s) ok 1 - pg_createsubscriber --help exit code 0
[16:04:31.119](0.000s) ok 2 - pg_createsubscriber --help goes to stdout
[16:04:31.119](0.000s) ok 3 - pg_createsubscriber --help nothing to stderr
[16:04:31.119](0.000s) ok 4 - pg_createsubscriber --help maximum line length
# Running: pg_createsubscriber --version
[16:04:31.132](0.012s) ok 5 - pg_createsubscriber --version exit code 0
[16:04:31.132](0.000s) ok 6 - pg_createsubscriber --version goes to stdout
[16:04:31.132](0.000s) ok 7 - pg_createsubscriber --version nothing to stderr
# Running: pg_createsubscriber --not-a-valid-option
[16:04:31.138](0.006s) ok 8 - pg_createsubscriber with invalid option nonzero exit code
[16:04:31.138](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.
[16:04:31.144](0.006s) 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_aHJr
pg_createsubscriber: error: no publisher connection string specified
pg_createsubscriber: hint: Try "pg_createsubscriber --help" for more information.
[16:04:31.150](0.006s) 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_aHJr --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.
[16:04:31.166](0.016s) 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_aHJr --publisher-server port=5432 --database pg1 --database pg1
pg_createsubscriber: error: duplicate database "pg1"
[16:04:31.175](0.009s) ok 13 - duplicate database name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_aHJr --publisher-server port=5432 --publication foo1 --publication foo1 --database pg1 --database pg2
pg_createsubscriber: error: duplicate publication "foo1"
[16:04:31.185](0.010s) ok 14 - duplicate publication name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_aHJr --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).
[16:04:31.193](0.008s) 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_aHJr --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).
[16:04:31.203](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_aHJr --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).
[16:04:31.226](0.022s) ok 17 - wrong number of replication slot names
# Checking port 62327
# Found port 62327
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=62327 host=/tmp/U5ln7oXdkc
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_p.log
[16:04:31.232](0.006s) # 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 35207
# Checking port 62328
# Found port 62328
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=62328 host=/tmp/U5ln7oXdkc
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_f.log
[16:04:31.493](0.262s) # 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/U5ln7oXdkc -p 62327 --checkpoint fast --no-sync
# Backup finished
# Checking port 62329
# Found port 62329
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=62329 host=/tmp/U5ln7oXdkc
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 35629
# Checking port 62330
# Found port 62330
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=62330 host=/tmp/U5ln7oXdkc
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 35706
### 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=62327 host=/tmp/U5ln7oXdkc dbname='pg1' --socket-directory /tmp/U5ln7oXdkc --subscriber-port 62330 --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 7361093670900416430 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7361093670900416430 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-23 16:04:34.469 UTC [35771][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-23 16:04:34.469 UTC [35771][postmaster] LOG:  listening on Unix socket "/tmp/U5ln7oXdkc/.s.PGSQL.62330"
2024-04-23 16:04:34.478 UTC [35778][startup] LOG:  database system was shut down at 2024-04-23 16:04:34 UTC
2024-04-23 16:04:34.481 UTC [35771][postmaster] LOG:  database system is ready to accept connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-23 16:04:34.553 UTC [35796][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:34.553 UTC [35796][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-23 16:04:34.553 UTC [35796][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:34.562 UTC [35796][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-23 16:04:34.562 UTC [35796][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-23 16:04:34.563 UTC [35796][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.012 user=postgres database=pg1 host=[local]
2024-04-23 16:04:34.565 UTC [35771][postmaster] LOG:  received fast shutdown request
2024-04-23 16:04:34.565 UTC [35771][postmaster] LOG:  aborting any active transactions
2024-04-23 16:04:34.566 UTC [35771][postmaster] LOG:  background worker "logical replication launcher" (PID 35781) exited with exit code 1
2024-04-23 16:04:34.571 UTC [35775][checkpointer] LOG:  shutting down
2024-04-23 16:04:34.571 UTC [35775][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-23 16:04:34.571 UTC [35775][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-23 16:04:34.573 UTC [35771][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[16:04:34.668](3.174s) 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=62327 host=/tmp/U5ln7oXdkc dbname='pg1' --socket-directory /tmp/U5ln7oXdkc --subscriber-port 62329 --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 7361093670900416430 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7361093670900416430 on subscriber
pg_createsubscriber: error: standby is up and running
pg_createsubscriber: hint: Stop the standby and try again.
[16:04:34.741](0.074s) 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=62327 host=/tmp/U5ln7oXdkc dbname='pg1' --socket-directory /tmp/U5ln7oXdkc --subscriber-port 62328 --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 7361093670900416430 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7361094075869972942 on subscriber
pg_createsubscriber: error: subscriber data directory is not a copy of the source database cluster
[16:04:34.817](0.076s) 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/U5ln7oXdkc -p 62329 --checkpoint fast --no-sync
# Backup finished
# Checking port 62331
# Found port 62331
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=62331 host=/tmp/U5ln7oXdkc
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=62329 host=/tmp/U5ln7oXdkc dbname='pg1' --socket-directory /tmp/U5ln7oXdkc --subscriber-port 62331 --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 7361093670900416430 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7361093670900416430 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-23 16:04:35.549 UTC [36035][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-23 16:04:35.549 UTC [36035][postmaster] LOG:  listening on Unix socket "/tmp/U5ln7oXdkc/.s.PGSQL.62331"
2024-04-23 16:04:35.558 UTC [36049][startup] LOG:  database system was interrupted while in recovery at log time 2024-04-23 16:04:33 UTC
2024-04-23 16:04:35.558 UTC [36049][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-23 16:04:35.558 UTC [36049][startup] LOG:  starting backup recovery with redo LSN 0/2000028, checkpoint LSN 0/2000080, on timeline ID 1
2024-04-23 16:04:35.558 UTC [36049][startup] LOG:  entering standby mode
2024-04-23 16:04:35.559 UTC [36049][startup] LOG:  redo starts at 0/2000028
2024-04-23 16:04:35.559 UTC [36049][startup] LOG:  completed backup recovery with redo LSN 0/2000028 and end LSN 0/2000120
2024-04-23 16:04:35.559 UTC [36049][startup] LOG:  consistent recovery state reached at 0/3000000
2024-04-23 16:04:35.559 UTC [36035][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-23 16:04:35.591 UTC [36052][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-23 16:04:35.630 UTC [36070][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:35.630 UTC [36070][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-23 16:04:35.630 UTC [36070][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:35.644 UTC [36070][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-23 16:04:35.644 UTC [36070][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:35.645 UTC [36070][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-23 16:04:35.661 UTC [36070][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=postgres database=pg1 host=[local]
pg_createsubscriber: error: primary server cannot be in recovery
2024-04-23 16:04:35.691 UTC [36035][postmaster] LOG:  received fast shutdown request
2024-04-23 16:04:35.691 UTC [36035][postmaster] LOG:  aborting any active transactions
2024-04-23 16:04:35.691 UTC [36052][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-23 16:04:35.693 UTC [36047][checkpointer] LOG:  shutting down
2024-04-23 16:04:35.695 UTC [36035][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[16:04:35.697](0.880s) 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 36151
### 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=62327 host=/tmp/U5ln7oXdkc dbname='pg1' --socket-directory /tmp/U5ln7oXdkc --subscriber-port 62329 --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 7361093670900416430 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7361093670900416430 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-23 16:04:36.250 UTC [36233][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-23 16:04:36.250 UTC [36233][postmaster] LOG:  listening on Unix socket "/tmp/U5ln7oXdkc/.s.PGSQL.62329"
2024-04-23 16:04:36.306 UTC [36246][startup] LOG:  database system was shut down in recovery at 2024-04-23 16:04:36 UTC
2024-04-23 16:04:36.306 UTC [36246][startup] LOG:  entering standby mode
2024-04-23 16:04:36.307 UTC [36246][startup] LOG:  consistent recovery state reached at 0/3000188
2024-04-23 16:04:36.307 UTC [36233][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-23 16:04:36.307 UTC [36246][startup] LOG:  invalid record length at 0/3000188: expected at least 24, got 0
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-23 16:04:36.324 UTC [36258][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-04-23 16:04:36.324 UTC [36246][startup] LOG:  redo starts at 0/3000188
2024-04-23 16:04:36.327 UTC [36260][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:36.327 UTC [36260][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-23 16:04:36.327 UTC [36260][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:36.332 UTC [36260][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-23 16:04:36.333 UTC [36260][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:36.333 UTC [36260][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-23 16:04:36.335 UTC [36260][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.008 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-23 16:04:36.367 UTC [36233][postmaster] LOG:  received fast shutdown request
2024-04-23 16:04:36.367 UTC [36233][postmaster] LOG:  aborting any active transactions
2024-04-23 16:04:36.368 UTC [36258][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-23 16:04:36.370 UTC [36244][checkpointer] LOG:  shutting down
2024-04-23 16:04:36.371 UTC [36233][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[16:04:36.468](0.771s) 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=62327 host=/tmp/U5ln7oXdkc dbname='pg1' --socket-directory /tmp/U5ln7oXdkc --subscriber-port 62329 --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 7361093670900416430 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7361093670900416430 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-23 16:04:36.519 UTC [36318][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-23 16:04:36.519 UTC [36318][postmaster] LOG:  listening on Unix socket "/tmp/U5ln7oXdkc/.s.PGSQL.62329"
2024-04-23 16:04:36.548 UTC [36329][startup] LOG:  database system was shut down in recovery at 2024-04-23 16:04:36 UTC
2024-04-23 16:04:36.548 UTC [36329][startup] LOG:  entering standby mode
2024-04-23 16:04:36.549 UTC [36329][startup] LOG:  redo starts at 0/3000188
2024-04-23 16:04:36.549 UTC [36329][startup] LOG:  invalid magic number 0000 in WAL segment 000000010000000000000003, LSN 0/3004000, offset 16384
2024-04-23 16:04:36.549 UTC [36329][startup] LOG:  consistent recovery state reached at 0/3002758
2024-04-23 16:04:36.549 UTC [36329][startup] LOG:  invalid magic number 0000 in WAL segment 000000010000000000000003, LSN 0/3004000, offset 16384
2024-04-23 16:04:36.549 UTC [36318][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-23 16:04:36.553 UTC [36330][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-23 16:04:36.606 UTC [36340][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:36.606 UTC [36340][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-23 16:04:36.606 UTC [36340][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:36.611 UTC [36340][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-23 16:04:36.612 UTC [36340][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:36.612 UTC [36340][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-23 16:04:36.614 UTC [36340][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=postgres database=pg1 host=[local]
2024-04-23 16:04:36.622 UTC [36318][postmaster] LOG:  received fast shutdown request
2024-04-23 16:04:36.622 UTC [36318][postmaster] LOG:  aborting any active transactions
2024-04-23 16:04:36.623 UTC [36330][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-23 16:04:36.624 UTC [36327][checkpointer] LOG:  shutting down
2024-04-23 16:04:36.625 UTC [36318][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[16:04:36.724](0.256s) 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 36377
# 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=62327 host=/tmp/U5ln7oXdkc dbname='pg1' --socket-directory /tmp/U5ln7oXdkc --subscriber-port 62329 --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 7361093670900416430 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7361093670900416430 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-23 16:04:37.065 UTC [36477][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-23 16:04:37.065 UTC [36477][postmaster] LOG:  listening on Unix socket "/tmp/U5ln7oXdkc/.s.PGSQL.62329"
2024-04-23 16:04:37.141 UTC [36493][startup] LOG:  database system was shut down in recovery at 2024-04-23 16:04:36 UTC
2024-04-23 16:04:37.142 UTC [36493][startup] LOG:  entering standby mode
2024-04-23 16:04:37.143 UTC [36493][startup] LOG:  redo starts at 0/3000188
2024-04-23 16:04:37.143 UTC [36493][startup] LOG:  consistent recovery state reached at 0/30046C0
2024-04-23 16:04:37.143 UTC [36493][startup] LOG:  invalid record length at 0/30046C0: expected at least 24, got 0
2024-04-23 16:04:37.143 UTC [36477][postmaster] LOG:  database system is ready to accept read-only connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-23 16:04:37.151 UTC [36503][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:37.152 UTC [36503][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-23 16:04:37.152 UTC [36503][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:37.159 UTC [36503][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-23 16:04:37.162 UTC [36503][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:37.163 UTC [36503][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-23 16:04:37.172 UTC [36503][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=postgres database=pg1 host=[local]
pg_createsubscriber: error: could not obtain replication slot information: got 0 rows, expected 1 row
2024-04-23 16:04:37.190 UTC [36501][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-04-23 16:04:37.191 UTC [36477][postmaster] LOG:  received fast shutdown request
2024-04-23 16:04:37.191 UTC [36477][postmaster] LOG:  aborting any active transactions
2024-04-23 16:04:37.191 UTC [36501][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-23 16:04:37.194 UTC [36491][checkpointer] LOG:  shutting down
2024-04-23 16:04:37.194 UTC [36491][checkpointer] LOG:  restartpoint starting: shutdown immediate
2024-04-23 16:04:37.199 UTC [36491][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.006 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-23 16:04:37.199 UTC [36491][checkpointer] LOG:  recovery restart point at 0/30046C0
2024-04-23 16:04:37.206 UTC [36477][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[16:04:37.293](0.569s) not ok 24 - run pg_createsubscriber --dry-run on node S
[16:04:37.293](0.000s) #   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 36539
[16:04:37.436](0.143s) 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=62327 host=/tmp/U5ln7oXdkc dbname='pg1' --socket-directory /tmp/U5ln7oXdkc --subscriber-port 62329 --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 7361093670900416430 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7361093670900416430 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-23 16:04:37.756 UTC [36619][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-23 16:04:37.756 UTC [36619][postmaster] LOG:  listening on Unix socket "/tmp/U5ln7oXdkc/.s.PGSQL.62329"
2024-04-23 16:04:37.764 UTC [36624][startup] LOG:  database system was shut down in recovery at 2024-04-23 16:04:37 UTC
2024-04-23 16:04:37.806 UTC [36624][startup] LOG:  entering standby mode
2024-04-23 16:04:37.813 UTC [36624][startup] LOG:  redo starts at 0/3004738
2024-04-23 16:04:37.813 UTC [36624][startup] LOG:  consistent recovery state reached at 0/3004770
2024-04-23 16:04:37.813 UTC [36619][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-23 16:04:37.814 UTC [36624][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-23 16:04:37.827 UTC [36632][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:37.827 UTC [36631][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-04-23 16:04:37.828 UTC [36632][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-23 16:04:37.828 UTC [36632][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:37.833 UTC [36632][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-23 16:04:37.834 UTC [36632][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:37.834 UTC [36632][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-23 16:04:37.837 UTC [36632][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-23 16:04:37.854 UTC [36619][postmaster] LOG:  received fast shutdown request
2024-04-23 16:04:37.854 UTC [36619][postmaster] LOG:  aborting any active transactions
2024-04-23 16:04:37.856 UTC [36631][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-23 16:04:37.860 UTC [36622][checkpointer] LOG:  shutting down
2024-04-23 16:04:37.862 UTC [36619][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: creating publication "pg_createsubscriber_16384_96339abf" 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-23 16:04:38.037 UTC [36653][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-23 16:04:38.037 UTC [36653][postmaster] LOG:  listening on Unix socket "/tmp/U5ln7oXdkc/.s.PGSQL.62329"
2024-04-23 16:04:38.040 UTC [36656][startup] LOG:  database system was shut down in recovery at 2024-04-23 16:04:37 UTC
2024-04-23 16:04:38.040 UTC [36656][startup] LOG:  entering standby mode
2024-04-23 16:04:38.042 UTC [36656][startup] LOG:  redo starts at 0/3004738
2024-04-23 16:04:38.042 UTC [36656][startup] LOG:  consistent recovery state reached at 0/3004770
2024-04-23 16:04:38.042 UTC [36656][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
2024-04-23 16:04:38.042 UTC [36653][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-23 16:04:38.068 UTC [36657][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-23 16:04:38.149 UTC [36685][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:38.150 UTC [36685][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-23 16:04:38.150 UTC [36685][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:38.155 UTC [36685][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-23 16:04:38.155 UTC [36685][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-23 16:04:38.156 UTC [36685][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=postgres database=pg1 host=[local]
2024-04-23 16:04:38.165 UTC [36690][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:38.166 UTC [36690][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-23 16:04:38.166 UTC [36690][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:38.166 UTC [36690][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_96339abf" on database "pg1"
pg_createsubscriber: creating subscription "pg_createsubscriber_16384_96339abf" on database "pg1"
2024-04-23 16:04:38.167 UTC [36690][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_96339abf' 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_96339abf" on database "pg1"
2024-04-23 16:04:38.168 UTC [36690][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.011 user=postgres database=pg1 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: stopping the subscriber
2024-04-23 16:04:38.192 UTC [36653][postmaster] LOG:  received fast shutdown request
2024-04-23 16:04:38.192 UTC [36653][postmaster] LOG:  aborting any active transactions
2024-04-23 16:04:38.192 UTC [36657][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-23 16:04:38.193 UTC [36654][checkpointer] LOG:  shutting down
2024-04-23 16:04:38.194 UTC [36653][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7361094103821893373 on subscriber
pg_createsubscriber: running pg_resetwal on the subscriber
pg_createsubscriber: Done!
[16:04:38.199](0.763s) 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=62327 host=/tmp/U5ln7oXdkc dbname='pg1' --socket-directory /tmp/U5ln7oXdkc --subscriber-port 62329 --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/U5ln7oXdkc port=62327 dbname=pg1
pg_createsubscriber: subscriber(0): subscription: (auto) ; connection string: port=62329 host=/tmp/U5ln7oXdkc fallback_application_name=pg_createsubscriber dbname=pg1
pg_createsubscriber: publisher(1): publication: Pub2 ; replication slot: replslot2 ; connection string: host=/tmp/U5ln7oXdkc port=62327 dbname=pg2
pg_createsubscriber: subscriber(1): subscription: (auto) ; connection string: port=62329 host=/tmp/U5ln7oXdkc fallback_application_name=pg_createsubscriber dbname=pg2
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7361093670900416430 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7361093670900416430 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 62329" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/tmp/U5ln7oXdkc'"
2024-04-23 16:04:38.272 UTC [36726][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-23 16:04:38.272 UTC [36726][postmaster] LOG:  listening on Unix socket "/tmp/U5ln7oXdkc/.s.PGSQL.62329"
2024-04-23 16:04:38.330 UTC [36743][startup] LOG:  database system was shut down in recovery at 2024-04-23 16:04:38 UTC
2024-04-23 16:04:38.330 UTC [36743][startup] LOG:  entering standby mode
2024-04-23 16:04:38.331 UTC [36743][startup] LOG:  redo starts at 0/3004738
2024-04-23 16:04:38.331 UTC [36743][startup] LOG:  consistent recovery state reached at 0/3004770
2024-04-23 16:04:38.331 UTC [36743][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
2024-04-23 16:04:38.331 UTC [36726][postmaster] LOG:  database system is ready to accept read-only connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-23 16:04:38.362 UTC [36753][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:38.362 UTC [36753][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-23 16:04:38.362 UTC [36753][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:38.367 UTC [36753][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-23 16:04:38.368 UTC [36753][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:38.368 UTC [36753][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-23 16:04:38.371 UTC [36753][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=postgres database=pg1 host=[local]
2024-04-23 16:04:38.373 UTC [36745][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
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-23 16:04:38.402 UTC [36726][postmaster] LOG:  received fast shutdown request
2024-04-23 16:04:38.402 UTC [36726][postmaster] LOG:  aborting any active transactions
2024-04-23 16:04:38.402 UTC [36745][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-23 16:04:38.404 UTC [36741][checkpointer] LOG:  shutting down
2024-04-23 16:04:38.405 UTC [36726][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/U5ln7oXdkc'' port=62327 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 62329" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/tmp/U5ln7oXdkc'"
2024-04-23 16:04:38.648 UTC [36787][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-23 16:04:38.648 UTC [36787][postmaster] LOG:  listening on Unix socket "/tmp/U5ln7oXdkc/.s.PGSQL.62329"
2024-04-23 16:04:38.668 UTC [36791][startup] LOG:  database system was shut down in recovery at 2024-04-23 16:04:38 UTC
2024-04-23 16:04:38.669 UTC [36791][startup] LOG:  entering standby mode
2024-04-23 16:04:38.670 UTC [36791][startup] LOG:  redo starts at 0/3004738
2024-04-23 16:04:38.670 UTC [36791][startup] LOG:  consistent recovery state reached at 0/3004770
2024-04-23 16:04:38.670 UTC [36791][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
2024-04-23 16:04:38.670 UTC [36787][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-23 16:04:38.681 UTC [36794][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-23 16:04:38.749 UTC [36808][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:38.852 UTC [36808][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-23 16:04:38.854 UTC [36808][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:38.859 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-23 16:04:38.860 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:38.860 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/4:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:39.861 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/5:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:39.862 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/6:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:40.862 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/7:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:40.862 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/8:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:41.863 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/9:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:41.863 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/10:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:42.863 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/11:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:42.863 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/12:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:43.864 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/13:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:43.864 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/14:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:44.864 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/15:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:44.865 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/16:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:45.865 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/17:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:45.865 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/18:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:46.866 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/19:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:46.866 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/20:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:47.866 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/21:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:47.867 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/22:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:48.867 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/23:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:48.867 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/24:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:49.868 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/25:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:49.868 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/26:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:50.868 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/27:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:50.869 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/28:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:51.869 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/29:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-23 16:04:51.908 UTC [36791][startup] LOG:  recovery stopping after WAL location (LSN) "0/30092C0"
2024-04-23 16:04:51.908 UTC [36791][startup] LOG:  redo done at 0/30092C0 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 13.23 s
2024-04-23 16:04:51.908 UTC [36791][startup] LOG:  last completed transaction was at log time 2024-04-23 16:04:38.60165+00
2024-04-23 16:04:51.908 UTC [36794][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-23 16:04:51.911 UTC [36808][client backend] [040_pg_createsubscriber.pl][0/30:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-23 16:04:51.911 UTC [36791][startup] LOG:  selected new timeline ID: 2
2024-04-23 16:04:51.982 UTC [36791][startup] LOG:  archive recovery complete
2024-04-23 16:04:51.989 UTC [36789][checkpointer] LOG:  checkpoint starting: end-of-recovery immediate wait
2024-04-23 16:04:51.990 UTC [36789][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-23 16:04:51.992 UTC [36787][postmaster] LOG:  database system is ready to accept connections
2024-04-23 16:04:52.912 UTC [36808][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-23 16:04:52.913 UTC [36808][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:14.167 user=postgres database=pg1 host=[local]
2024-04-23 16:04:52.915 UTC [39649][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:52.916 UTC [39649][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-23 16:04:52.916 UTC [39649][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:52.917 UTC [39649][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-23 16:04:52.917 UTC [39649][client backend] [040_pg_createsubscriber.pl][1/3:0] LOG:  statement: DROP PUBLICATION "pub1"
pg_createsubscriber: creating subscription "pg_createsubscriber_16384_a5b7204" on database "pg1"
pg_createsubscriber: command is: CREATE SUBSCRIPTION "pg_createsubscriber_16384_a5b7204" CONNECTION 'host=/tmp/U5ln7oXdkc port=62327 dbname=pg1' PUBLICATION "pub1" WITH (create_slot = false, enabled = false, slot_name = 'replslot1', copy_data = false)
2024-04-23 16:04:52.918 UTC [39649][client backend] [040_pg_createsubscriber.pl][1/4:0] LOG:  statement: CREATE SUBSCRIPTION "pg_createsubscriber_16384_a5b7204" CONNECTION 'host=/tmp/U5ln7oXdkc port=62327 dbname=pg1' PUBLICATION "pub1" WITH (create_slot = false, enabled = false, slot_name = 'replslot1', copy_data = false)
2024-04-23 16:04:52.951 UTC [39649][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_a5b7204' 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-23 16:04:52.953 UTC [39649][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_a5b7204" on database "pg1"
pg_createsubscriber: command is: ALTER SUBSCRIPTION "pg_createsubscriber_16384_a5b7204" ENABLE
2024-04-23 16:04:52.953 UTC [39649][client backend] [040_pg_createsubscriber.pl][1/7:0] LOG:  statement: ALTER SUBSCRIPTION "pg_createsubscriber_16384_a5b7204" ENABLE
2024-04-23 16:04:52.955 UTC [39649][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.040 user=postgres database=pg1 host=[local]
2024-04-23 16:04:52.961 UTC [39659][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-23 16:04:52.962 UTC [39659][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-23 16:04:52.962 UTC [39659][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=pg2 application_name=040_pg_createsubscriber.pl
2024-04-23 16:04:52.973 UTC [39660][logical replication apply worker] LOG:  logical replication apply worker for subscription "pg_createsubscriber_16384_a5b7204" has started
2024-04-23 16:04:52.995 UTC [39659][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-23 16:04:52.996 UTC [39659][client backend] [040_pg_createsubscriber.pl][2/3:0] LOG:  statement: DROP PUBLICATION "Pub2"
pg_createsubscriber: creating subscription "pg_createsubscriber_16385_fafcf27f" on database "pg2"
pg_createsubscriber: command is: CREATE SUBSCRIPTION "pg_createsubscriber_16385_fafcf27f" CONNECTION 'host=/tmp/U5ln7oXdkc port=62327 dbname=pg2' PUBLICATION "Pub2" WITH (create_slot = false, enabled = false, slot_name = 'replslot2', copy_data = false)
2024-04-23 16:04:52.999 UTC [39659][client backend] [040_pg_createsubscriber.pl][2/4:0] LOG:  statement: CREATE SUBSCRIPTION "pg_createsubscriber_16385_fafcf27f" CONNECTION 'host=/tmp/U5ln7oXdkc port=62327 dbname=pg2' PUBLICATION "Pub2" WITH (create_slot = false, enabled = false, slot_name = 'replslot2', copy_data = false)
2024-04-23 16:04:53.029 UTC [39659][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_fafcf27f' 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-23 16:04:53.031 UTC [39659][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_fafcf27f" on database "pg2"
pg_createsubscriber: command is: ALTER SUBSCRIPTION "pg_createsubscriber_16385_fafcf27f" ENABLE
2024-04-23 16:04:53.031 UTC [39659][client backend] [040_pg_createsubscriber.pl][2/7:0] LOG:  statement: ALTER SUBSCRIPTION "pg_createsubscriber_16385_fafcf27f" ENABLE
2024-04-23 16:04:53.032 UTC [39659][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.070 user=postgres database=pg2 host=[local]
2024-04-23 16:04:53.043 UTC [39693][logical replication apply worker] LOG:  logical replication apply worker for subscription "pg_createsubscriber_16385_fafcf27f" has started
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-23 16:04:53.070 UTC [36787][postmaster] LOG:  received fast shutdown request
2024-04-23 16:04:53.070 UTC [36787][postmaster] LOG:  aborting any active transactions
2024-04-23 16:04:53.070 UTC [39693][logical replication apply worker] FATAL:  terminating logical replication worker due to administrator command
2024-04-23 16:04:53.072 UTC [39660][logical replication apply worker] FATAL:  terminating logical replication worker due to administrator command
2024-04-23 16:04:53.074 UTC [36787][postmaster] LOG:  background worker "logical replication launcher" (PID 39404) exited with exit code 1
2024-04-23 16:04:53.074 UTC [36787][postmaster] LOG:  background worker "logical replication apply worker" (PID 39660) exited with exit code 1
2024-04-23 16:04:53.074 UTC [36787][postmaster] LOG:  background worker "logical replication apply worker" (PID 39693) exited with exit code 1
2024-04-23 16:04:53.077 UTC [36789][checkpointer] LOG:  shutting down
2024-04-23 16:04:53.077 UTC [36789][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-23 16:04:53.077 UTC [36789][checkpointer] LOG:  checkpoint complete: wrote 8 buffers (6.2%); 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=14 kB, estimate=18 kB; lsn=0/300CC50, redo lsn=0/300CC50
2024-04-23 16:04:53.079 UTC [36787][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7361094168149147490 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!
[16:04:53.233](15.033s) ok 27 - run pg_createsubscriber on node S
[16:04:53.279](0.046s) 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 39772
Waiting for all subscriptions in "node_s" to synchronize data
Waiting for replication conn pg_createsubscriber_16384_a5b7204'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_fafcf27f's replay_lsn to pass 0/3009480 on node_p
done
done
[16:04:54.026](0.747s) ok 29 - logical replication works on database pg1
[16:04:54.038](0.012s) ok 30 - logical replication works on database pg2
[16:04:54.081](0.043s) 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"
[16:04:54.306](0.226s) 1..31
[16:04:54.308](0.002s) # Looks like you failed 1 test of 31.