# Running: pg_createsubscriber --help
[21:13:34.067](0.026s) ok 1 - pg_createsubscriber --help exit code 0
[21:13:34.067](0.000s) ok 2 - pg_createsubscriber --help goes to stdout
[21:13:34.067](0.000s) ok 3 - pg_createsubscriber --help nothing to stderr
[21:13:34.067](0.000s) ok 4 - pg_createsubscriber --help maximum line length
# Running: pg_createsubscriber --version
[21:13:34.086](0.019s) ok 5 - pg_createsubscriber --version exit code 0
[21:13:34.087](0.000s) ok 6 - pg_createsubscriber --version goes to stdout
[21:13:34.087](0.000s) ok 7 - pg_createsubscriber --version nothing to stderr
# Running: pg_createsubscriber --not-a-valid-option
[21:13:34.112](0.025s) ok 8 - pg_createsubscriber with invalid option nonzero exit code
[21:13:34.112](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.
[21:13:34.120](0.008s) 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_PEps
pg_createsubscriber: error: no publisher connection string specified
pg_createsubscriber: hint: Try "pg_createsubscriber --help" for more information.
[21:13:34.142](0.022s) 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_PEps --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.
[21:13:34.156](0.014s) 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_PEps --publisher-server port=5432 --database pg1 --database pg1
pg_createsubscriber: error: duplicate database "pg1"
[21:13:34.177](0.021s) ok 13 - duplicate database name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_PEps --publisher-server port=5432 --publication foo1 --publication foo1 --database pg1 --database pg2
pg_createsubscriber: error: duplicate publication "foo1"
[21:13:34.191](0.014s) ok 14 - duplicate publication name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_PEps --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).
[21:13:34.210](0.019s) 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_PEps --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).
[21:13:34.224](0.013s) 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_PEps --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).
[21:13:34.232](0.008s) ok 17 - wrong number of replication slot names
# Checking port 65491
# Found port 65491
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=65491 host=/tmp/Ss0CneMFdl
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_p.log
[21:13:34.242](0.010s) # 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 32094
# Checking port 65492
# Found port 65492
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=65492 host=/tmp/Ss0CneMFdl
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_f.log
[21:13:34.512](0.270s) # 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/Ss0CneMFdl -p 65491 --checkpoint fast --no-sync
# Backup finished
# Checking port 65493
# Found port 65493
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=65493 host=/tmp/Ss0CneMFdl
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 32552
# Checking port 65494
# Found port 65494
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=65494 host=/tmp/Ss0CneMFdl
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 32616
### 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=65491 host=/tmp/Ss0CneMFdl dbname='pg1' --socket-directory /tmp/Ss0CneMFdl --subscriber-port 65494 --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 7358204605143950215 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7358204605143950215 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-15 21:13:38.117 UTC [32703][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-15 21:13:38.117 UTC [32703][postmaster] LOG:  listening on Unix socket "/tmp/Ss0CneMFdl/.s.PGSQL.65494"
2024-04-15 21:13:38.123 UTC [32716][startup] LOG:  database system was shut down at 2024-04-15 21:13:37 UTC
2024-04-15 21:13:38.129 UTC [32703][postmaster] LOG:  database system is ready to accept connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-15 21:13:38.216 UTC [32732][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:38.216 UTC [32732][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-15 21:13:38.216 UTC [32732][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:38.237 UTC [32732][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-15 21:13:38.239 UTC [32732][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-15 21:13:38.240 UTC [32732][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=postgres database=pg1 host=[local]
2024-04-15 21:13:38.245 UTC [32703][postmaster] LOG:  received fast shutdown request
2024-04-15 21:13:38.245 UTC [32703][postmaster] LOG:  aborting any active transactions
2024-04-15 21:13:38.246 UTC [32703][postmaster] LOG:  background worker "logical replication launcher" (PID 32723) exited with exit code 1
2024-04-15 21:13:38.249 UTC [32714][checkpointer] LOG:  shutting down
2024-04-15 21:13:38.249 UTC [32714][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-15 21:13:38.250 UTC [32714][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-15 21:13:38.252 UTC [32703][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[21:13:38.347](3.835s) 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=65491 host=/tmp/Ss0CneMFdl dbname='pg1' --socket-directory /tmp/Ss0CneMFdl --subscriber-port 65493 --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 7358204605143950215 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7358204605143950215 on subscriber
pg_createsubscriber: error: standby is up and running
pg_createsubscriber: hint: Stop the standby and try again.
[21:13:38.400](0.054s) 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=65491 host=/tmp/Ss0CneMFdl dbname='pg1' --socket-directory /tmp/Ss0CneMFdl --subscriber-port 65492 --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 7358204605143950215 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7358205035980086689 on subscriber
pg_createsubscriber: error: subscriber data directory is not a copy of the source database cluster
[21:13:38.425](0.025s) 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/Ss0CneMFdl -p 65493 --checkpoint fast --no-sync
# Backup finished
# Checking port 65495
# Found port 65495
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=65495 host=/tmp/Ss0CneMFdl
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=65493 host=/tmp/Ss0CneMFdl dbname='pg1' --socket-directory /tmp/Ss0CneMFdl --subscriber-port 65495 --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 7358204605143950215 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7358204605143950215 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-15 21:13:39.155 UTC [32917][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-15 21:13:39.155 UTC [32917][postmaster] LOG:  listening on Unix socket "/tmp/Ss0CneMFdl/.s.PGSQL.65495"
2024-04-15 21:13:39.158 UTC [32934][startup] LOG:  database system was interrupted while in recovery at log time 2024-04-15 21:13:36 UTC
2024-04-15 21:13:39.158 UTC [32934][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-15 21:13:39.158 UTC [32934][startup] LOG:  starting backup recovery with redo LSN 0/2000028, checkpoint LSN 0/2000080, on timeline ID 1
2024-04-15 21:13:39.158 UTC [32934][startup] LOG:  entering standby mode
2024-04-15 21:13:39.159 UTC [32934][startup] LOG:  redo starts at 0/2000028
2024-04-15 21:13:39.159 UTC [32934][startup] LOG:  completed backup recovery with redo LSN 0/2000028 and end LSN 0/2000120
2024-04-15 21:13:39.159 UTC [32934][startup] LOG:  consistent recovery state reached at 0/3000000
2024-04-15 21:13:39.159 UTC [32917][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-15 21:13:39.177 UTC [32936][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-15 21:13:39.231 UTC [32952][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:39.232 UTC [32952][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-15 21:13:39.232 UTC [32952][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:39.246 UTC [32952][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-15 21:13:39.247 UTC [32952][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:39.247 UTC [32952][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-15 21:13:39.252 UTC [32952][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=postgres database=pg1 host=[local]
pg_createsubscriber: error: primary server cannot be in recovery
2024-04-15 21:13:39.286 UTC [32917][postmaster] LOG:  received fast shutdown request
2024-04-15 21:13:39.286 UTC [32917][postmaster] LOG:  aborting any active transactions
2024-04-15 21:13:39.288 UTC [32936][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-15 21:13:39.290 UTC [32932][checkpointer] LOG:  shutting down
2024-04-15 21:13:39.291 UTC [32917][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[21:13:39.387](0.962s) 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 33039
### 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=65491 host=/tmp/Ss0CneMFdl dbname='pg1' --socket-directory /tmp/Ss0CneMFdl --subscriber-port 65493 --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 7358204605143950215 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7358204605143950215 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-15 21:13:39.967 UTC [33139][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-15 21:13:39.967 UTC [33139][postmaster] LOG:  listening on Unix socket "/tmp/Ss0CneMFdl/.s.PGSQL.65493"
2024-04-15 21:13:40.025 UTC [33159][startup] LOG:  database system was shut down in recovery at 2024-04-15 21:13:39 UTC
2024-04-15 21:13:40.025 UTC [33159][startup] LOG:  entering standby mode
2024-04-15 21:13:40.030 UTC [33159][startup] LOG:  consistent recovery state reached at 0/3000188
2024-04-15 21:13:40.030 UTC [33139][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-15 21:13:40.030 UTC [33159][startup] LOG:  invalid record length at 0/3000188: expected at least 24, got 0
2024-04-15 21:13:40.041 UTC [33165][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-04-15 21:13:40.042 UTC [33159][startup] LOG:  redo starts at 0/3000188
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-15 21:13:40.060 UTC [33174][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:40.061 UTC [33174][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-15 21:13:40.061 UTC [33174][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:40.069 UTC [33174][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-15 21:13:40.074 UTC [33174][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:40.075 UTC [33174][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-15 21:13:40.082 UTC [33174][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.025 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-15 21:13:40.104 UTC [33139][postmaster] LOG:  received fast shutdown request
2024-04-15 21:13:40.104 UTC [33139][postmaster] LOG:  aborting any active transactions
2024-04-15 21:13:40.105 UTC [33165][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-15 21:13:40.106 UTC [33157][checkpointer] LOG:  shutting down
2024-04-15 21:13:40.109 UTC [33139][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[21:13:40.212](0.825s) 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=65491 host=/tmp/Ss0CneMFdl dbname='pg1' --socket-directory /tmp/Ss0CneMFdl --subscriber-port 65493 --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 7358204605143950215 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7358204605143950215 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-15 21:13:40.306 UTC [33200][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-15 21:13:40.306 UTC [33200][postmaster] LOG:  listening on Unix socket "/tmp/Ss0CneMFdl/.s.PGSQL.65493"
2024-04-15 21:13:40.329 UTC [33205][startup] LOG:  database system was shut down in recovery at 2024-04-15 21:13:40 UTC
2024-04-15 21:13:40.329 UTC [33205][startup] LOG:  entering standby mode
2024-04-15 21:13:40.330 UTC [33205][startup] LOG:  redo starts at 0/3000188
2024-04-15 21:13:40.330 UTC [33205][startup] LOG:  consistent recovery state reached at 0/30046C0
2024-04-15 21:13:40.330 UTC [33205][startup] LOG:  invalid record length at 0/30046C0: expected at least 24, got 0
2024-04-15 21:13:40.330 UTC [33200][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-15 21:13:40.335 UTC [33206][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-15 21:13:40.396 UTC [33217][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:40.397 UTC [33217][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-15 21:13:40.397 UTC [33217][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:40.402 UTC [33217][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-15 21:13:40.403 UTC [33217][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:40.403 UTC [33217][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-15 21:13:40.411 UTC [33217][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.014 user=postgres database=pg1 host=[local]
2024-04-15 21:13:40.418 UTC [33200][postmaster] LOG:  received fast shutdown request
2024-04-15 21:13:40.418 UTC [33200][postmaster] LOG:  aborting any active transactions
2024-04-15 21:13:40.420 UTC [33206][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-15 21:13:40.422 UTC [33203][checkpointer] LOG:  shutting down
2024-04-15 21:13:40.424 UTC [33200][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[21:13:40.519](0.307s) 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 33246
# 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=65491 host=/tmp/Ss0CneMFdl dbname='pg1' --socket-directory /tmp/Ss0CneMFdl --subscriber-port 65493 --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 7358204605143950215 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7358204605143950215 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-15 21:13:40.942 UTC [33272][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-15 21:13:40.942 UTC [33272][postmaster] LOG:  listening on Unix socket "/tmp/Ss0CneMFdl/.s.PGSQL.65493"
2024-04-15 21:13:40.945 UTC [33276][startup] LOG:  database system was shut down in recovery at 2024-04-15 21:13:40 UTC
2024-04-15 21:13:41.019 UTC [33276][startup] LOG:  entering standby mode
2024-04-15 21:13:41.020 UTC [33276][startup] LOG:  redo starts at 0/3000188
2024-04-15 21:13:41.020 UTC [33276][startup] LOG:  consistent recovery state reached at 0/30046C0
2024-04-15 21:13:41.020 UTC [33276][startup] LOG:  invalid record length at 0/30046C0: expected at least 24, got 0
2024-04-15 21:13:41.021 UTC [33272][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-15 21:13:41.026 UTC [33282][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-15 21:13:41.121 UTC [33294][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:41.123 UTC [33294][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-15 21:13:41.123 UTC [33294][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:41.129 UTC [33294][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-15 21:13:41.131 UTC [33294][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:41.131 UTC [33294][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-15 21:13:41.142 UTC [33294][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=postgres database=pg1 host=[local]
pg_createsubscriber: primary has replication slot "physical_slot"
pg_createsubscriber: stopping the subscriber
2024-04-15 21:13:41.180 UTC [33272][postmaster] LOG:  received fast shutdown request
2024-04-15 21:13:41.180 UTC [33272][postmaster] LOG:  aborting any active transactions
2024-04-15 21:13:41.183 UTC [33282][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-15 21:13:41.186 UTC [33274][checkpointer] LOG:  shutting down
2024-04-15 21:13:41.186 UTC [33274][checkpointer] LOG:  restartpoint starting: shutdown immediate
2024-04-15 21:13:41.187 UTC [33274][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.002 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-15 21:13:41.188 UTC [33274][checkpointer] LOG:  recovery restart point at 0/30046C0
2024-04-15 21:13:41.192 UTC [33272][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: creating publication "pub1" on database "pg1"
pg_createsubscriber: creating the replication slot "sub1" on database "pg1"
pg_createsubscriber: create replication slot "sub1" on publisher
pg_createsubscriber: creating publication "pub2" on database "pg2"
pg_createsubscriber: creating the replication slot "sub2" on database "pg2"
pg_createsubscriber: create replication slot "sub2" on publisher
pg_createsubscriber: starting the subscriber
2024-04-15 21:13:41.497 UTC [33353][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-15 21:13:41.497 UTC [33353][postmaster] LOG:  listening on Unix socket "/tmp/Ss0CneMFdl/.s.PGSQL.65493"
2024-04-15 21:13:41.528 UTC [33365][startup] LOG:  database system was shut down in recovery at 2024-04-15 21:13:41 UTC
2024-04-15 21:13:41.528 UTC [33365][startup] LOG:  entering standby mode
2024-04-15 21:13:41.530 UTC [33365][startup] LOG:  redo starts at 0/3004738
2024-04-15 21:13:41.530 UTC [33365][startup] LOG:  consistent recovery state reached at 0/3004770
2024-04-15 21:13:41.530 UTC [33365][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
2024-04-15 21:13:41.530 UTC [33353][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-15 21:13:41.567 UTC [33367][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-15 21:13:41.588 UTC [33384][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:41.589 UTC [33384][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-15 21:13:41.589 UTC [33384][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:41.630 UTC [33384][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-15 21:13:41.630 UTC [33384][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-15 21:13:41.631 UTC [33384][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.042 user=postgres database=pg1 host=[local]
2024-04-15 21:13:41.643 UTC [33391][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:41.643 UTC [33391][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-15 21:13:41.643 UTC [33391][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:41.644 UTC [33391][client backend] [040_pg_createsubscriber.pl][1/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
pg_createsubscriber: dropping publication "pub1" on database "pg1"
pg_createsubscriber: creating subscription "sub1" on database "pg1"
2024-04-15 21:13:41.645 UTC [33391][client backend] [040_pg_createsubscriber.pl][1/3:0] LOG:  statement: SELECT s.oid FROM pg_catalog.pg_subscription s INNER JOIN pg_catalog.pg_database d ON (s.subdbid = d.oid) WHERE s.subname = 'sub1' AND d.datname = 'pg1'
pg_createsubscriber: setting the replication progress (node name "pg_0" ; LSN 0/0) on database "pg1"
pg_createsubscriber: enabling subscription "sub1" on database "pg1"
2024-04-15 21:13:41.647 UTC [33391][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.006 user=postgres database=pg1 host=[local]
2024-04-15 21:13:41.661 UTC [33395][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:41.662 UTC [33395][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-15 21:13:41.662 UTC [33395][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=pg2 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:41.707 UTC [33395][client backend] [040_pg_createsubscriber.pl][2/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
pg_createsubscriber: dropping publication "pub2" on database "pg2"
pg_createsubscriber: creating subscription "sub2" on database "pg2"
2024-04-15 21:13:41.708 UTC [33395][client backend] [040_pg_createsubscriber.pl][2/3:0] LOG:  statement: SELECT s.oid FROM pg_catalog.pg_subscription s INNER JOIN pg_catalog.pg_database d ON (s.subdbid = d.oid) WHERE s.subname = 'sub2' AND d.datname = 'pg2'
pg_createsubscriber: setting the replication progress (node name "pg_0" ; LSN 0/0) on database "pg2"
pg_createsubscriber: enabling subscription "sub2" on database "pg2"
2024-04-15 21:13:41.709 UTC [33395][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.048 user=postgres database=pg2 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: stopping the subscriber
2024-04-15 21:13:41.753 UTC [33353][postmaster] LOG:  received fast shutdown request
2024-04-15 21:13:41.753 UTC [33353][postmaster] LOG:  aborting any active transactions
2024-04-15 21:13:41.755 UTC [33367][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-15 21:13:41.758 UTC [33363][checkpointer] LOG:  shutting down
2024-04-15 21:13:41.759 UTC [33353][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7358205066690519530 on subscriber
pg_createsubscriber: running pg_resetwal on the subscriber
pg_createsubscriber: Done!
[21:13:41.855](1.335s) ok 24 - run pg_createsubscriber --dry-run on node S
### Starting node "node_s"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_s.log -o --cluster-name=node_s start
waiting for server to start.... done
server started
# Postmaster PID for node "node_s" is 33455
[21:13:42.027](0.172s) 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=65491 host=/tmp/Ss0CneMFdl dbname='pg1' --socket-directory /tmp/Ss0CneMFdl --subscriber-port 65493 --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 7358204605143950215 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7358204605143950215 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-15 21:13:42.329 UTC [33525][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-15 21:13:42.329 UTC [33525][postmaster] LOG:  listening on Unix socket "/tmp/Ss0CneMFdl/.s.PGSQL.65493"
2024-04-15 21:13:42.344 UTC [33530][startup] LOG:  database system was shut down in recovery at 2024-04-15 21:13:42 UTC
2024-04-15 21:13:42.344 UTC [33530][startup] LOG:  entering standby mode
2024-04-15 21:13:42.346 UTC [33530][startup] LOG:  redo starts at 0/3004738
2024-04-15 21:13:42.346 UTC [33530][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-04-15 21:13:42.346 UTC [33530][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
2024-04-15 21:13:42.346 UTC [33525][postmaster] LOG:  database system is ready to accept read-only connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-15 21:13:42.359 UTC [33533][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:42.360 UTC [33533][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-15 21:13:42.360 UTC [33533][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:42.366 UTC [33533][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-15 21:13:42.367 UTC [33533][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:42.367 UTC [33533][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-15 21:13:42.370 UTC [33533][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.011 user=postgres database=pg1 host=[local]
pg_createsubscriber: error: could not obtain replication slot information: got 0 rows, expected 1 row
2024-04-15 21:13:42.389 UTC [33525][postmaster] LOG:  received fast shutdown request
2024-04-15 21:13:42.389 UTC [33525][postmaster] LOG:  aborting any active transactions
2024-04-15 21:13:42.390 UTC [33531][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-15 21:13:42.391 UTC [33528][checkpointer] LOG:  shutting down
2024-04-15 21:13:42.392 UTC [33525][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[21:13:42.490](0.463s) not ok 26 - run pg_createsubscriber without --databases
[21:13:42.491](0.000s) #   Failed test 'run pg_createsubscriber without --databases'
#   at /tmp/cirrus-ci-build/src/bin/pg_basebackup/t/040_pg_createsubscriber.pl line 284.
# 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=65491 host=/tmp/Ss0CneMFdl dbname='pg1' --socket-directory /tmp/Ss0CneMFdl --subscriber-port 65493 --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/Ss0CneMFdl port=65491 dbname=pg1
pg_createsubscriber: subscriber(0): subscription: (auto) ; connection string: port=65493 host=/tmp/Ss0CneMFdl fallback_application_name=pg_createsubscriber dbname=pg1
pg_createsubscriber: publisher(1): publication: Pub2 ; replication slot: replslot2 ; connection string: host=/tmp/Ss0CneMFdl port=65491 dbname=pg2
pg_createsubscriber: subscriber(1): subscription: (auto) ; connection string: port=65493 host=/tmp/Ss0CneMFdl fallback_application_name=pg_createsubscriber dbname=pg2
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7358204605143950215 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7358204605143950215 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 65493" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/tmp/Ss0CneMFdl'"
2024-04-15 21:13:42.534 UTC [33565][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-15 21:13:42.534 UTC [33565][postmaster] LOG:  listening on Unix socket "/tmp/Ss0CneMFdl/.s.PGSQL.65493"
2024-04-15 21:13:42.543 UTC [33572][startup] LOG:  database system was shut down in recovery at 2024-04-15 21:13:42 UTC
2024-04-15 21:13:42.543 UTC [33572][startup] LOG:  entering standby mode
2024-04-15 21:13:42.545 UTC [33572][startup] LOG:  redo starts at 0/3004738
2024-04-15 21:13:42.545 UTC [33572][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-04-15 21:13:42.545 UTC [33565][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-15 21:13:42.545 UTC [33572][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
2024-04-15 21:13:42.548 UTC [33574][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-15 21:13:42.627 UTC [33578][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:42.699 UTC [33578][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-15 21:13:42.699 UTC [33578][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:42.736 UTC [33578][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-15 21:13:42.737 UTC [33578][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:42.737 UTC [33578][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-15 21:13:42.759 UTC [33578][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.132 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-15 21:13:42.819 UTC [33565][postmaster] LOG:  received fast shutdown request
2024-04-15 21:13:42.819 UTC [33565][postmaster] LOG:  aborting any active transactions
2024-04-15 21:13:42.821 UTC [33574][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-15 21:13:42.823 UTC [33570][checkpointer] LOG:  shutting down
2024-04-15 21:13:42.825 UTC [33565][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/Ss0CneMFdl'' port=65491 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 65493" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/tmp/Ss0CneMFdl'"
2024-04-15 21:13:43.078 UTC [33603][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-15 21:13:43.079 UTC [33603][postmaster] LOG:  listening on Unix socket "/tmp/Ss0CneMFdl/.s.PGSQL.65493"
2024-04-15 21:13:43.121 UTC [33607][startup] LOG:  database system was shut down in recovery at 2024-04-15 21:13:42 UTC
2024-04-15 21:13:43.122 UTC [33607][startup] LOG:  entering standby mode
2024-04-15 21:13:43.125 UTC [33607][startup] LOG:  redo starts at 0/3004738
2024-04-15 21:13:43.125 UTC [33607][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-04-15 21:13:43.125 UTC [33603][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-15 21:13:43.126 UTC [33607][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
2024-04-15 21:13:43.135 UTC [33609][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-15 21:13:43.194 UTC [33616][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:43.194 UTC [33616][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-15 21:13:43.194 UTC [33616][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:43.208 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-15 21:13:43.208 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:43.208 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/4:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:44.215 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/5:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:44.216 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/6:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:45.216 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/7:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:45.289 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/8:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:46.289 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/9:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:46.289 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/10:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:47.290 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/11:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:47.290 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/12:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:48.291 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/13:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:48.291 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/14:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:49.291 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/15:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:49.292 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/16:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:50.292 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/17:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:50.292 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/18:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:51.293 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/19:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:51.293 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/20:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:52.293 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/21:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:52.294 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/22:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:53.294 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/23:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:53.294 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/24:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:54.295 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/25:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:54.295 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/26:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:55.296 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/27:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-15 21:13:55.296 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/28:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-15 21:13:55.722 UTC [33607][startup] LOG:  recovery stopping after WAL location (LSN) "0/30092C0"
2024-04-15 21:13:55.722 UTC [33607][startup] LOG:  redo done at 0/30092C0 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 12.59 s
2024-04-15 21:13:55.722 UTC [33607][startup] LOG:  last completed transaction was at log time 2024-04-15 21:13:42.941915+00
2024-04-15 21:13:55.722 UTC [33609][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-15 21:13:55.724 UTC [33607][startup] LOG:  selected new timeline ID: 2
2024-04-15 21:13:55.738 UTC [33607][startup] LOG:  archive recovery complete
2024-04-15 21:13:55.738 UTC [33605][checkpointer] LOG:  checkpoint starting: end-of-recovery immediate wait
2024-04-15 21:13:55.814 UTC [33605][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.077 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-15 21:13:55.816 UTC [33603][postmaster] LOG:  database system is ready to accept connections
2024-04-15 21:13:56.297 UTC [33616][client backend] [040_pg_createsubscriber.pl][0/29:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
pg_createsubscriber: target server reached the consistent state
pg_createsubscriber: hint: If pg_createsubscriber fails after this point, you must recreate the physical replica before continuing.
2024-04-15 21:13:56.297 UTC [33616][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:13.106 user=postgres database=pg1 host=[local]
2024-04-15 21:13:56.307 UTC [36002][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:56.308 UTC [36002][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-15 21:13:56.308 UTC [36002][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:56.310 UTC [36002][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-15 21:13:56.311 UTC [36002][client backend] [040_pg_createsubscriber.pl][1/3:0] LOG:  statement: DROP PUBLICATION "pub1"
pg_createsubscriber: creating subscription "pg_createsubscriber_16384_35372800" on database "pg1"
pg_createsubscriber: command is: CREATE SUBSCRIPTION "pg_createsubscriber_16384_35372800" CONNECTION 'host=/tmp/Ss0CneMFdl port=65491 dbname=pg1' PUBLICATION "pub1" WITH (create_slot = false, enabled = false, slot_name = 'replslot1', copy_data = false)
2024-04-15 21:13:56.313 UTC [36002][client backend] [040_pg_createsubscriber.pl][1/4:0] LOG:  statement: CREATE SUBSCRIPTION "pg_createsubscriber_16384_35372800" CONNECTION 'host=/tmp/Ss0CneMFdl port=65491 dbname=pg1' PUBLICATION "pub1" WITH (create_slot = false, enabled = false, slot_name = 'replslot1', copy_data = false)
2024-04-15 21:13:56.338 UTC [36002][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_35372800' 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-15 21:13:56.340 UTC [36002][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_35372800" on database "pg1"
pg_createsubscriber: command is: ALTER SUBSCRIPTION "pg_createsubscriber_16384_35372800" ENABLE
2024-04-15 21:13:56.340 UTC [36002][client backend] [040_pg_createsubscriber.pl][1/7:0] LOG:  statement: ALTER SUBSCRIPTION "pg_createsubscriber_16384_35372800" ENABLE
2024-04-15 21:13:56.340 UTC [36002][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.033 user=postgres database=pg1 host=[local]
2024-04-15 21:13:56.352 UTC [36008][logical replication apply worker] LOG:  logical replication apply worker for subscription "pg_createsubscriber_16384_35372800" has started
2024-04-15 21:13:56.355 UTC [36009][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-15 21:13:56.356 UTC [36009][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-15 21:13:56.356 UTC [36009][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=pg2 application_name=040_pg_createsubscriber.pl
2024-04-15 21:13:56.365 UTC [36009][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-15 21:13:56.367 UTC [36009][client backend] [040_pg_createsubscriber.pl][2/3:0] LOG:  statement: DROP PUBLICATION "Pub2"
pg_createsubscriber: creating subscription "pg_createsubscriber_16385_68a77bd4" on database "pg2"
pg_createsubscriber: command is: CREATE SUBSCRIPTION "pg_createsubscriber_16385_68a77bd4" CONNECTION 'host=/tmp/Ss0CneMFdl port=65491 dbname=pg2' PUBLICATION "Pub2" WITH (create_slot = false, enabled = false, slot_name = 'replslot2', copy_data = false)
2024-04-15 21:13:56.368 UTC [36009][client backend] [040_pg_createsubscriber.pl][2/4:0] LOG:  statement: CREATE SUBSCRIPTION "pg_createsubscriber_16385_68a77bd4" CONNECTION 'host=/tmp/Ss0CneMFdl port=65491 dbname=pg2' PUBLICATION "Pub2" WITH (create_slot = false, enabled = false, slot_name = 'replslot2', copy_data = false)
2024-04-15 21:13:56.416 UTC [36009][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_68a77bd4' 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-15 21:13:56.417 UTC [36009][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_68a77bd4" on database "pg2"
pg_createsubscriber: command is: ALTER SUBSCRIPTION "pg_createsubscriber_16385_68a77bd4" ENABLE
2024-04-15 21:13:56.418 UTC [36009][client backend] [040_pg_createsubscriber.pl][2/7:0] LOG:  statement: ALTER SUBSCRIPTION "pg_createsubscriber_16385_68a77bd4" ENABLE
2024-04-15 21:13:56.418 UTC [36009][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.066 user=postgres database=pg2 host=[local]
2024-04-15 21:13:56.441 UTC [36022][logical replication apply worker] LOG:  logical replication apply worker for subscription "pg_createsubscriber_16385_68a77bd4" 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-15 21:13:56.465 UTC [33603][postmaster] LOG:  received fast shutdown request
2024-04-15 21:13:56.465 UTC [33603][postmaster] LOG:  aborting any active transactions
2024-04-15 21:13:56.465 UTC [36022][logical replication apply worker] FATAL:  terminating logical replication worker due to administrator command
2024-04-15 21:13:56.465 UTC [36008][logical replication apply worker] FATAL:  terminating logical replication worker due to administrator command
2024-04-15 21:13:56.468 UTC [33603][postmaster] LOG:  background worker "logical replication launcher" (PID 35921) exited with exit code 1
2024-04-15 21:13:56.468 UTC [33603][postmaster] LOG:  background worker "logical replication apply worker" (PID 36008) exited with exit code 1
2024-04-15 21:13:56.468 UTC [33603][postmaster] LOG:  background worker "logical replication apply worker" (PID 36022) exited with exit code 1
2024-04-15 21:13:56.468 UTC [33605][checkpointer] LOG:  shutting down
2024-04-15 21:13:56.468 UTC [33605][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-15 21:13:56.469 UTC [33605][checkpointer] LOG:  checkpoint complete: wrote 11 buffers (8.6%); 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-15 21:13:56.470 UTC [33603][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7358205129933046547 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!
[21:13:56.618](14.127s) ok 27 - run pg_createsubscriber on node S
[21:13:56.632](0.014s) 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 36133
Waiting for all subscriptions in "node_s" to synchronize data
Waiting for replication conn pg_createsubscriber_16384_35372800'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_68a77bd4's replay_lsn to pass 0/3009480 on node_p
done
done
[21:13:57.217](0.585s) ok 29 - logical replication works on database pg1
[21:13:57.259](0.042s) ok 30 - logical replication works on database pg2
[21:13:57.295](0.036s) 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"
[21:13:57.516](0.221s) 1..31
[21:13:57.518](0.002s) # Looks like you failed 1 test of 31.