# Running: pg_createsubscriber --help
[03:11:17.747](0.036s) ok 1 - pg_createsubscriber --help exit code 0
[03:11:17.748](0.001s) ok 2 - pg_createsubscriber --help goes to stdout
[03:11:17.748](0.000s) ok 3 - pg_createsubscriber --help nothing to stderr
[03:11:17.748](0.000s) ok 4 - pg_createsubscriber --help maximum line length
# Running: pg_createsubscriber --version
[03:11:17.769](0.021s) ok 5 - pg_createsubscriber --version exit code 0
[03:11:17.770](0.000s) ok 6 - pg_createsubscriber --version goes to stdout
[03:11:17.770](0.000s) ok 7 - pg_createsubscriber --version nothing to stderr
# Running: pg_createsubscriber --not-a-valid-option
[03:11:17.783](0.013s) ok 8 - pg_createsubscriber with invalid option nonzero exit code
[03:11:17.783](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.
[03:11:17.808](0.025s) 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_1uUJ
pg_createsubscriber: error: no publisher connection string specified
pg_createsubscriber: hint: Try "pg_createsubscriber --help" for more information.
[03:11:17.833](0.025s) 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_1uUJ --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.
[03:11:17.856](0.023s) 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_1uUJ --publisher-server port=5432 --database pg1 --database pg1
pg_createsubscriber: error: duplicate database "pg1"
[03:11:17.938](0.081s) ok 13 - duplicate database name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_1uUJ --publisher-server port=5432 --publication foo1 --publication foo1 --database pg1 --database pg2
pg_createsubscriber: error: duplicate publication "foo1"
[03:11:17.985](0.047s) ok 14 - duplicate publication name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_1uUJ --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).
[03:11:18.025](0.041s) 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_1uUJ --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).
[03:11:18.041](0.016s) 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_1uUJ --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).
[03:11:18.055](0.014s) ok 17 - wrong number of replication slot names
# Checking port 53808
# Found port 53808
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=53808 host=/tmp/tnl3B_Sqx7
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_p.log
[03:11:18.060](0.005s) # 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 31187
# Checking port 53809
# Found port 53809
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=53809 host=/tmp/tnl3B_Sqx7
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_f.log
[03:11:18.373](0.313s) # 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/tnl3B_Sqx7 -p 53808 --checkpoint fast --no-sync
# Backup finished
# Checking port 53810
# Found port 53810
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=53810 host=/tmp/tnl3B_Sqx7
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 31517
# Checking port 53811
# Found port 53811
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=53811 host=/tmp/tnl3B_Sqx7
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 31564
### 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=53808 host=/tmp/tnl3B_Sqx7 dbname='pg1' --socket-directory /tmp/tnl3B_Sqx7 --subscriber-port 53811 --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 7350503971144340230 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7350503971144340230 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-03-26 03:11:21.448 UTC [31622][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-26 03:11:21.448 UTC [31622][postmaster] LOG:  listening on Unix socket "/tmp/tnl3B_Sqx7/.s.PGSQL.53811"
2024-03-26 03:11:21.469 UTC [31629][startup] LOG:  database system was shut down at 2024-03-26 03:11:21 UTC
2024-03-26 03:11:21.472 UTC [31622][postmaster] LOG:  database system is ready to accept connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-03-26 03:11:21.538 UTC [31646][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:21.538 UTC [31646][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-03-26 03:11:21.538 UTC [31646][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:21.552 UTC [31646][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-03-26 03:11:21.556 UTC [31646][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-03-26 03:11:21.557 UTC [31646][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=postgres database=pg1 host=[local]
2024-03-26 03:11:21.568 UTC [31622][postmaster] LOG:  received fast shutdown request
2024-03-26 03:11:21.568 UTC [31622][postmaster] LOG:  aborting any active transactions
2024-03-26 03:11:21.569 UTC [31622][postmaster] LOG:  background worker "logical replication launcher" (PID 31634) exited with exit code 1
2024-03-26 03:11:21.571 UTC [31627][checkpointer] LOG:  shutting down
2024-03-26 03:11:21.571 UTC [31627][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-26 03:11:21.572 UTC [31627][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-03-26 03:11:21.573 UTC [31622][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[03:11:21.699](3.327s) 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=53808 host=/tmp/tnl3B_Sqx7 dbname='pg1' --socket-directory /tmp/tnl3B_Sqx7 --subscriber-port 53810 --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 7350503971144340230 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7350503971144340230 on subscriber
pg_createsubscriber: error: standby is up and running
pg_createsubscriber: hint: Stop the standby and try again.
[03:11:21.866](0.167s) 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=53808 host=/tmp/tnl3B_Sqx7 dbname='pg1' --socket-directory /tmp/tnl3B_Sqx7 --subscriber-port 53809 --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 7350503971144340230 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7350504433799903739 on subscriber
pg_createsubscriber: error: subscriber data directory is not a copy of the source database cluster
[03:11:21.900](0.034s) 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/tnl3B_Sqx7 -p 53810 --checkpoint fast --no-sync
# Backup finished
# Checking port 53812
# Found port 53812
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=53812 host=/tmp/tnl3B_Sqx7
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=53810 host=/tmp/tnl3B_Sqx7 dbname='pg1' --socket-directory /tmp/tnl3B_Sqx7 --subscriber-port 53812 --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 7350503971144340230 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7350503971144340230 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-03-26 03:11:22.491 UTC [31784][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-26 03:11:22.491 UTC [31784][postmaster] LOG:  listening on Unix socket "/tmp/tnl3B_Sqx7/.s.PGSQL.53812"
2024-03-26 03:11:22.503 UTC [31794][startup] LOG:  database system was interrupted while in recovery at log time 2024-03-26 03:11:20 UTC
2024-03-26 03:11:22.503 UTC [31794][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-03-26 03:11:22.503 UTC [31794][startup] LOG:  starting backup recovery with redo LSN 0/2000028, checkpoint LSN 0/2000080, on timeline ID 1
2024-03-26 03:11:22.503 UTC [31794][startup] LOG:  entering standby mode
2024-03-26 03:11:22.505 UTC [31794][startup] LOG:  redo starts at 0/2000028
2024-03-26 03:11:22.505 UTC [31794][startup] LOG:  completed backup recovery with redo LSN 0/2000028 and end LSN 0/2000120
2024-03-26 03:11:22.506 UTC [31794][startup] LOG:  consistent recovery state reached at 0/3000000
2024-03-26 03:11:22.506 UTC [31784][postmaster] LOG:  database system is ready to accept read-only connections
2024-03-26 03:11:22.543 UTC [31795][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-03-26 03:11:22.573 UTC [31809][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:22.574 UTC [31809][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-03-26 03:11:22.574 UTC [31809][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:22.589 UTC [31809][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-03-26 03:11:22.592 UTC [31809][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-03-26 03:11:22.592 UTC [31809][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-03-26 03:11:22.599 UTC [31809][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=postgres database=pg1 host=[local]
pg_createsubscriber: error: primary server cannot be in recovery
2024-03-26 03:11:22.629 UTC [31784][postmaster] LOG:  received fast shutdown request
2024-03-26 03:11:22.629 UTC [31784][postmaster] LOG:  aborting any active transactions
2024-03-26 03:11:22.629 UTC [31795][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-26 03:11:22.631 UTC [31790][checkpointer] LOG:  shutting down
2024-03-26 03:11:22.633 UTC [31784][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[03:11:23.044](1.144s) 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 31920
### 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=53808 host=/tmp/tnl3B_Sqx7 dbname='pg1' --socket-directory /tmp/tnl3B_Sqx7 --subscriber-port 53810 --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 7350503971144340230 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7350503971144340230 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-03-26 03:11:23.707 UTC [32003][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-26 03:11:23.707 UTC [32003][postmaster] LOG:  listening on Unix socket "/tmp/tnl3B_Sqx7/.s.PGSQL.53810"
2024-03-26 03:11:23.722 UTC [32007][startup] LOG:  database system was shut down in recovery at 2024-03-26 03:11:23 UTC
2024-03-26 03:11:23.722 UTC [32007][startup] LOG:  entering standby mode
2024-03-26 03:11:23.724 UTC [32007][startup] LOG:  consistent recovery state reached at 0/3000188
2024-03-26 03:11:23.724 UTC [32007][startup] LOG:  invalid record length at 0/3000188: expected at least 24, got 0
2024-03-26 03:11:23.724 UTC [32003][postmaster] LOG:  database system is ready to accept read-only connections
2024-03-26 03:11:23.740 UTC [32008][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-26 03:11:23.740 UTC [32007][startup] LOG:  redo starts at 0/3000188
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-03-26 03:11:23.788 UTC [32024][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:23.790 UTC [32024][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-03-26 03:11:23.790 UTC [32024][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:23.797 UTC [32024][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-03-26 03:11:23.798 UTC [32024][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-03-26 03:11:23.798 UTC [32024][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-03-26 03:11:23.801 UTC [32024][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.013 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-03-26 03:11:23.839 UTC [32003][postmaster] LOG:  received fast shutdown request
2024-03-26 03:11:23.839 UTC [32003][postmaster] LOG:  aborting any active transactions
2024-03-26 03:11:23.840 UTC [32008][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-26 03:11:23.841 UTC [32005][checkpointer] LOG:  shutting down
2024-03-26 03:11:23.843 UTC [32003][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[03:11:24.220](1.176s) 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=53808 host=/tmp/tnl3B_Sqx7 dbname='pg1' --socket-directory /tmp/tnl3B_Sqx7 --subscriber-port 53810 --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 7350503971144340230 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7350503971144340230 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-03-26 03:11:24.364 UTC [32108][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-26 03:11:24.364 UTC [32108][postmaster] LOG:  listening on Unix socket "/tmp/tnl3B_Sqx7/.s.PGSQL.53810"
2024-03-26 03:11:24.452 UTC [32116][startup] LOG:  database system was shut down in recovery at 2024-03-26 03:11:23 UTC
2024-03-26 03:11:24.453 UTC [32116][startup] LOG:  entering standby mode
2024-03-26 03:11:24.454 UTC [32116][startup] LOG:  redo starts at 0/3000188
2024-03-26 03:11:24.454 UTC [32116][startup] LOG:  invalid magic number 0000 in WAL segment 000000010000000000000003, LSN 0/3004000, offset 16384
2024-03-26 03:11:24.455 UTC [32116][startup] LOG:  consistent recovery state reached at 0/3002758
2024-03-26 03:11:24.455 UTC [32108][postmaster] LOG:  database system is ready to accept read-only connections
2024-03-26 03:11:24.455 UTC [32116][startup] LOG:  invalid magic number 0000 in WAL segment 000000010000000000000003, LSN 0/3004000, offset 16384
2024-03-26 03:11:24.464 UTC [32120][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-03-26 03:11:24.558 UTC [32140][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:24.558 UTC [32140][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-03-26 03:11:24.558 UTC [32140][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:24.568 UTC [32140][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-03-26 03:11:24.568 UTC [32140][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-03-26 03:11:24.569 UTC [32140][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-03-26 03:11:24.572 UTC [32140][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.014 user=postgres database=pg1 host=[local]
2024-03-26 03:11:24.576 UTC [32108][postmaster] LOG:  received fast shutdown request
2024-03-26 03:11:24.576 UTC [32108][postmaster] LOG:  aborting any active transactions
2024-03-26 03:11:24.577 UTC [32120][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-26 03:11:24.578 UTC [32113][checkpointer] LOG:  shutting down
2024-03-26 03:11:24.580 UTC [32108][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[03:11:24.861](0.640s) 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 32185
# 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=53808 host=/tmp/tnl3B_Sqx7 dbname='pg1' --socket-directory /tmp/tnl3B_Sqx7 --subscriber-port 53810 --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 7350503971144340230 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7350503971144340230 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-03-26 03:11:25.281 UTC [32208][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-26 03:11:25.281 UTC [32208][postmaster] LOG:  listening on Unix socket "/tmp/tnl3B_Sqx7/.s.PGSQL.53810"
2024-03-26 03:11:25.399 UTC [32215][startup] LOG:  database system was shut down in recovery at 2024-03-26 03:11:24 UTC
2024-03-26 03:11:25.400 UTC [32215][startup] LOG:  entering standby mode
2024-03-26 03:11:25.401 UTC [32215][startup] LOG:  redo starts at 0/3000188
2024-03-26 03:11:25.401 UTC [32215][startup] LOG:  consistent recovery state reached at 0/30046C0
2024-03-26 03:11:25.401 UTC [32208][postmaster] LOG:  database system is ready to accept read-only connections
2024-03-26 03:11:25.401 UTC [32215][startup] LOG:  invalid record length at 0/30046C0: expected at least 24, got 0
2024-03-26 03:11:25.407 UTC [32216][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-03-26 03:11:25.443 UTC [32222][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:25.443 UTC [32222][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-03-26 03:11:25.443 UTC [32222][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:25.450 UTC [32222][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-03-26 03:11:25.450 UTC [32222][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-03-26 03:11:25.450 UTC [32222][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-03-26 03:11:25.454 UTC [32222][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-03-26 03:11:25.469 UTC [32208][postmaster] LOG:  received fast shutdown request
2024-03-26 03:11:25.469 UTC [32208][postmaster] LOG:  aborting any active transactions
2024-03-26 03:11:25.470 UTC [32216][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-26 03:11:25.472 UTC [32213][checkpointer] LOG:  shutting down
2024-03-26 03:11:25.472 UTC [32213][checkpointer] LOG:  restartpoint starting: shutdown immediate
2024-03-26 03:11:25.473 UTC [32213][checkpointer] LOG:  restartpoint complete: wrote 4 buffers (3.1%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=17 kB, estimate=17 kB; lsn=0/30046C0, redo lsn=0/30046C0
2024-03-26 03:11:25.473 UTC [32213][checkpointer] LOG:  recovery restart point at 0/30046C0
2024-03-26 03:11:25.475 UTC [32208][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-03-26 03:11:25.674 UTC [32276][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-26 03:11:25.674 UTC [32276][postmaster] LOG:  listening on Unix socket "/tmp/tnl3B_Sqx7/.s.PGSQL.53810"
2024-03-26 03:11:25.685 UTC [32282][startup] LOG:  database system was shut down in recovery at 2024-03-26 03:11:25 UTC
2024-03-26 03:11:25.685 UTC [32282][startup] LOG:  entering standby mode
2024-03-26 03:11:25.686 UTC [32282][startup] LOG:  redo starts at 0/3004738
2024-03-26 03:11:25.686 UTC [32282][startup] LOG:  consistent recovery state reached at 0/3004770
2024-03-26 03:11:25.686 UTC [32276][postmaster] LOG:  database system is ready to accept read-only connections
2024-03-26 03:11:25.686 UTC [32282][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
2024-03-26 03:11:25.733 UTC [32285][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-03-26 03:11:25.753 UTC [32302][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:25.754 UTC [32302][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-03-26 03:11:25.754 UTC [32302][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:25.760 UTC [32302][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-03-26 03:11:25.761 UTC [32302][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-03-26 03:11:25.761 UTC [32302][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=postgres database=pg1 host=[local]
2024-03-26 03:11:25.767 UTC [32306][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:25.768 UTC [32306][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-03-26 03:11:25.768 UTC [32306][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:25.769 UTC [32306][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-03-26 03:11:25.769 UTC [32306][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-03-26 03:11:25.771 UTC [32306][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=postgres database=pg1 host=[local]
2024-03-26 03:11:25.773 UTC [32309][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:25.773 UTC [32309][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-03-26 03:11:25.773 UTC [32309][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=pg2 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:25.861 UTC [32309][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-03-26 03:11:25.862 UTC [32309][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-03-26 03:11:25.864 UTC [32309][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.091 user=postgres database=pg2 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: stopping the subscriber
2024-03-26 03:11:25.879 UTC [32276][postmaster] LOG:  received fast shutdown request
2024-03-26 03:11:25.879 UTC [32276][postmaster] LOG:  aborting any active transactions
2024-03-26 03:11:25.881 UTC [32285][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-26 03:11:25.882 UTC [32280][checkpointer] LOG:  shutting down
2024-03-26 03:11:25.883 UTC [32276][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7350504465723305414 on subscriber
pg_createsubscriber: running pg_resetwal on the subscriber
pg_createsubscriber: Done!
[03:11:26.211](1.350s) 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 32373
[03:11:26.523](0.312s) 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=53808 host=/tmp/tnl3B_Sqx7 dbname='pg1' --socket-directory /tmp/tnl3B_Sqx7 --subscriber-port 53810 --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 7350503971144340230 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7350503971144340230 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-03-26 03:11:26.892 UTC [32420][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-26 03:11:26.892 UTC [32420][postmaster] LOG:  listening on Unix socket "/tmp/tnl3B_Sqx7/.s.PGSQL.53810"
2024-03-26 03:11:26.898 UTC [32423][startup] LOG:  database system was shut down in recovery at 2024-03-26 03:11:26 UTC
2024-03-26 03:11:26.898 UTC [32423][startup] LOG:  entering standby mode
2024-03-26 03:11:26.900 UTC [32423][startup] LOG:  redo starts at 0/3004738
2024-03-26 03:11:26.900 UTC [32423][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-03-26 03:11:26.900 UTC [32420][postmaster] LOG:  database system is ready to accept read-only connections
2024-03-26 03:11:26.900 UTC [32423][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
2024-03-26 03:11:26.921 UTC [32426][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-03-26 03:11:26.970 UTC [32432][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:26.971 UTC [32432][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-03-26 03:11:26.971 UTC [32432][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:26.977 UTC [32432][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-03-26 03:11:26.977 UTC [32432][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-03-26 03:11:26.977 UTC [32432][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-03-26 03:11:26.981 UTC [32432][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=postgres database=pg1 host=[local]
pg_createsubscriber: primary has replication slot "physical_slot"
pg_createsubscriber: stopping the subscriber
2024-03-26 03:11:26.998 UTC [32420][postmaster] LOG:  received fast shutdown request
2024-03-26 03:11:27.062 UTC [32420][postmaster] LOG:  aborting any active transactions
2024-03-26 03:11:27.062 UTC [32426][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-26 03:11:27.068 UTC [32421][checkpointer] LOG:  shutting down
2024-03-26 03:11:27.097 UTC [32420][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: creating publication "pg_createsubscriber_16384_fe68df1a" 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-03-26 03:11:27.147 UTC [32449][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-26 03:11:27.147 UTC [32449][postmaster] LOG:  listening on Unix socket "/tmp/tnl3B_Sqx7/.s.PGSQL.53810"
2024-03-26 03:11:27.180 UTC [32452][startup] LOG:  database system was shut down in recovery at 2024-03-26 03:11:27 UTC
2024-03-26 03:11:27.180 UTC [32452][startup] LOG:  entering standby mode
2024-03-26 03:11:27.182 UTC [32452][startup] LOG:  redo starts at 0/3004738
2024-03-26 03:11:27.182 UTC [32452][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-03-26 03:11:27.182 UTC [32449][postmaster] LOG:  database system is ready to accept read-only connections
2024-03-26 03:11:27.182 UTC [32452][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
2024-03-26 03:11:27.198 UTC [32453][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-03-26 03:11:27.311 UTC [32460][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:27.312 UTC [32460][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-03-26 03:11:27.312 UTC [32460][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:27.317 UTC [32460][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-03-26 03:11:27.318 UTC [32460][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-03-26 03:11:27.321 UTC [32460][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.015 user=postgres database=pg1 host=[local]
2024-03-26 03:11:27.326 UTC [32461][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:27.326 UTC [32461][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-03-26 03:11:27.326 UTC [32461][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:27.328 UTC [32461][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_fe68df1a" on database "pg1"
pg_createsubscriber: creating subscription "pg_createsubscriber_16384_fe68df1a" on database "pg1"
2024-03-26 03:11:27.332 UTC [32461][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_fe68df1a' 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_fe68df1a" on database "pg1"
2024-03-26 03:11:27.334 UTC [32461][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=postgres database=pg1 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: stopping the subscriber
2024-03-26 03:11:27.340 UTC [32449][postmaster] LOG:  received fast shutdown request
2024-03-26 03:11:27.340 UTC [32449][postmaster] LOG:  aborting any active transactions
2024-03-26 03:11:27.340 UTC [32453][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-26 03:11:27.342 UTC [32450][checkpointer] LOG:  shutting down
2024-03-26 03:11:27.344 UTC [32449][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7350504472103935641 on subscriber
pg_createsubscriber: running pg_resetwal on the subscriber
pg_createsubscriber: Done!
[03:11:27.782](1.259s) 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=53808 host=/tmp/tnl3B_Sqx7 dbname='pg1' --socket-directory /tmp/tnl3B_Sqx7 --subscriber-port 53810 --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/tnl3B_Sqx7 port=53808 dbname=pg1
pg_createsubscriber: subscriber(0): subscription: (auto) ; connection string: port=53810 host=/tmp/tnl3B_Sqx7 fallback_application_name=pg_createsubscriber dbname=pg1
pg_createsubscriber: publisher(1): publication: Pub2 ; replication slot: replslot2 ; connection string: host=/tmp/tnl3B_Sqx7 port=53808 dbname=pg2
pg_createsubscriber: subscriber(1): subscription: (auto) ; connection string: port=53810 host=/tmp/tnl3B_Sqx7 fallback_application_name=pg_createsubscriber dbname=pg2
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7350503971144340230 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7350503971144340230 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 53810" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/tmp/tnl3B_Sqx7'"
2024-03-26 03:11:27.926 UTC [32515][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-26 03:11:27.958 UTC [32515][postmaster] LOG:  listening on Unix socket "/tmp/tnl3B_Sqx7/.s.PGSQL.53810"
2024-03-26 03:11:27.979 UTC [32519][startup] LOG:  database system was shut down in recovery at 2024-03-26 03:11:27 UTC
2024-03-26 03:11:27.979 UTC [32519][startup] LOG:  entering standby mode
2024-03-26 03:11:27.980 UTC [32519][startup] LOG:  redo starts at 0/3004738
2024-03-26 03:11:27.980 UTC [32519][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-03-26 03:11:27.980 UTC [32519][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
2024-03-26 03:11:27.983 UTC [32515][postmaster] LOG:  database system is ready to accept read-only connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-03-26 03:11:28.018 UTC [32534][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-26 03:11:28.019 UTC [32534][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-03-26 03:11:28.019 UTC [32534][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-03-26 03:11:28.024 UTC [32534][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-03-26 03:11:28.025 UTC [32534][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-03-26 03:11:28.025 UTC [32534][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-03-26 03:11:28.028 UTC [32534][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.011 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: error: could not obtain replication slot information: got 0 rows, expected 1 row
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-03-26 03:11:28.040 UTC [32525][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-26 03:11:28.046 UTC [32515][postmaster] LOG:  received fast shutdown request
2024-03-26 03:11:28.046 UTC [32515][postmaster] LOG:  aborting any active transactions
2024-03-26 03:11:28.048 UTC [32525][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-26 03:11:28.049 UTC [32517][checkpointer] LOG:  shutting down
2024-03-26 03:11:28.051 UTC [32515][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[03:11:28.433](0.651s) not ok 27 - run pg_createsubscriber on node S
[03:11:28.434](0.000s) #   Failed test 'run pg_createsubscriber on node S'
#   at /tmp/cirrus-ci-build/src/bin/pg_basebackup/t/040_pg_createsubscriber.pl line 297.
[03:11:28.562](0.129s) not ok 28 - the physical replication slot used as primary_slot_name has been removed
[03:11:28.562](0.000s) #   Failed test 'the physical replication slot used as primary_slot_name has been removed'
#   at /tmp/cirrus-ci-build/src/bin/pg_basebackup/t/040_pg_createsubscriber.pl line 318.
[03:11:28.563](0.000s) #          got: '1'
#     expected: '0'
### 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 32652
Waiting for all subscriptions in "node_s" to synchronize data
subscription name must be specified at /tmp/cirrus-ci-build/src/bin/pg_basebackup/t/040_pg_createsubscriber.pl line 337.
# Postmaster PID for node "node_p" is 32185
### 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"
# No postmaster PID for node "node_f"
# Postmaster PID for node "node_s" is 32652
### 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"
# No postmaster PID for node "node_t"
# No postmaster PID for node "node_c"
[03:11:29.013](0.451s) # Tests were run but no plan was declared and done_testing() was not seen.
[03:11:29.014](0.000s) # Looks like your test exited with 29 just after 28.