# Running: pg_createsubscriber --help
[14:55:52.770](0.049s) ok 1 - pg_createsubscriber --help exit code 0
[14:55:52.770](0.000s) ok 2 - pg_createsubscriber --help goes to stdout
[14:55:52.770](0.000s) ok 3 - pg_createsubscriber --help nothing to stderr
[14:55:52.770](0.000s) ok 4 - pg_createsubscriber --help maximum line length
# Running: pg_createsubscriber --version
[14:55:52.800](0.029s) ok 5 - pg_createsubscriber --version exit code 0
[14:55:52.800](0.000s) ok 6 - pg_createsubscriber --version goes to stdout
[14:55:52.800](0.000s) ok 7 - pg_createsubscriber --version nothing to stderr
# Running: pg_createsubscriber --not-a-valid-option
[14:55:52.806](0.006s) ok 8 - pg_createsubscriber with invalid option nonzero exit code
[14:55:52.807](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.
[14:55:52.826](0.019s) 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_24yJ
pg_createsubscriber: error: no publisher connection string specified
pg_createsubscriber: hint: Try "pg_createsubscriber --help" for more information.
[14:55:52.841](0.015s) 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_24yJ --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.
[14:55:52.855](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_24yJ --publisher-server port=5432 --database pg1 --database pg1
pg_createsubscriber: error: duplicate database "pg1"
[14:55:52.868](0.013s) ok 13 - duplicate database name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_24yJ --publisher-server port=5432 --publication foo1 --publication foo1 --database pg1 --database pg2
pg_createsubscriber: error: duplicate publication "foo1"
[14:55:52.883](0.015s) ok 14 - duplicate publication name
# Running: pg_createsubscriber --verbose --pgdata /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_24yJ --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).
[14:55:52.926](0.044s) 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_24yJ --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).
[14:55:52.941](0.015s) 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_24yJ --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).
[14:55:52.951](0.010s) ok 17 - wrong number of replication slot names
# Checking port 62626
# Found port 62626
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=62626 host=/tmp/eaBXGL6n8d
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_p.log
[14:55:52.957](0.006s) # initializing database system by copying initdb template
# Running: cp -RPp /tmp/cirrus-ci-build/build/tmp_install/initdb-template /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata
# Running: /tmp/cirrus-ci-build/build/src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata
### Starting node "node_p"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_p.log -o --cluster-name=node_p start
waiting for server to start.... done
server started
# Postmaster PID for node "node_p" is 37072
# Checking port 62627
# Found port 62627
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=62627 host=/tmp/eaBXGL6n8d
Log file: /tmp/cirrus-ci-build/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_f.log
[14:55:53.268](0.311s) # 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/eaBXGL6n8d -p 62626 --checkpoint fast --no-sync
# Backup finished
# Checking port 62628
# Found port 62628
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=62628 host=/tmp/eaBXGL6n8d
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 37533
# Checking port 62629
# Found port 62629
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=62629 host=/tmp/eaBXGL6n8d
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 37599
### 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=62626 host=/tmp/eaBXGL6n8d dbname='pg1' --socket-directory /tmp/eaBXGL6n8d --subscriber-port 62629 --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 7362560282632033994 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7362560282632033994 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-27 14:55:56.771 UTC [37704][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-27 14:55:56.772 UTC [37704][postmaster] LOG:  listening on Unix socket "/tmp/eaBXGL6n8d/.s.PGSQL.62629"
2024-04-27 14:55:56.779 UTC [37712][startup] LOG:  database system was shut down at 2024-04-27 14:55:56 UTC
2024-04-27 14:55:56.784 UTC [37704][postmaster] LOG:  database system is ready to accept connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-27 14:55:56.845 UTC [37733][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:55:56.846 UTC [37733][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-27 14:55:56.846 UTC [37733][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-27 14:55:56.851 UTC [37733][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-27 14:55:56.851 UTC [37733][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-27 14:55:56.852 UTC [37733][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=postgres database=pg1 host=[local]
2024-04-27 14:55:56.883 UTC [37704][postmaster] LOG:  received fast shutdown request
2024-04-27 14:55:56.883 UTC [37704][postmaster] LOG:  aborting any active transactions
2024-04-27 14:55:56.884 UTC [37704][postmaster] LOG:  background worker "logical replication launcher" (PID 37717) exited with exit code 1
2024-04-27 14:55:56.885 UTC [37710][checkpointer] LOG:  shutting down
2024-04-27 14:55:56.885 UTC [37710][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-27 14:55:56.885 UTC [37710][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-27 14:55:56.887 UTC [37704][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[14:55:56.986](3.718s) 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=62626 host=/tmp/eaBXGL6n8d dbname='pg1' --socket-directory /tmp/eaBXGL6n8d --subscriber-port 62628 --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 7362560282632033994 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7362560282632033994 on subscriber
pg_createsubscriber: error: standby is up and running
pg_createsubscriber: hint: Stop the standby and try again.
[14:55:57.009](0.023s) 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=62626 host=/tmp/eaBXGL6n8d dbname='pg1' --socket-directory /tmp/eaBXGL6n8d --subscriber-port 62627 --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 7362560282632033994 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7362560728783663386 on subscriber
pg_createsubscriber: error: subscriber data directory is not a copy of the source database cluster
[14:55:57.070](0.061s) 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/eaBXGL6n8d -p 62628 --checkpoint fast --no-sync
# Backup finished
# Checking port 62630
# Found port 62630
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=62630 host=/tmp/eaBXGL6n8d
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=62628 host=/tmp/eaBXGL6n8d dbname='pg1' --socket-directory /tmp/eaBXGL6n8d --subscriber-port 62630 --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 7362560282632033994 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7362560282632033994 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-27 14:55:57.753 UTC [37949][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-27 14:55:57.753 UTC [37949][postmaster] LOG:  listening on Unix socket "/tmp/eaBXGL6n8d/.s.PGSQL.62630"
2024-04-27 14:55:57.762 UTC [37958][startup] LOG:  database system was interrupted while in recovery at log time 2024-04-27 14:55:55 UTC
2024-04-27 14:55:57.762 UTC [37958][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-27 14:55:57.762 UTC [37958][startup] LOG:  starting backup recovery with redo LSN 0/2000028, checkpoint LSN 0/2000080, on timeline ID 1
2024-04-27 14:55:57.762 UTC [37958][startup] LOG:  entering standby mode
2024-04-27 14:55:57.763 UTC [37958][startup] LOG:  redo starts at 0/2000028
2024-04-27 14:55:57.763 UTC [37958][startup] LOG:  completed backup recovery with redo LSN 0/2000028 and end LSN 0/2000120
2024-04-27 14:55:57.763 UTC [37958][startup] LOG:  consistent recovery state reached at 0/3000000
2024-04-27 14:55:57.763 UTC [37949][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-27 14:55:57.791 UTC [37963][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-27 14:55:57.894 UTC [37991][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:55:57.894 UTC [37991][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-27 14:55:57.894 UTC [37991][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-27 14:55:57.900 UTC [37991][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-27 14:55:57.900 UTC [37991][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:55:57.901 UTC [37991][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-27 14:55:57.904 UTC [37991][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=postgres database=pg1 host=[local]
pg_createsubscriber: error: primary server cannot be in recovery
2024-04-27 14:55:57.930 UTC [37949][postmaster] LOG:  received fast shutdown request
2024-04-27 14:55:57.930 UTC [37949][postmaster] LOG:  aborting any active transactions
2024-04-27 14:55:57.931 UTC [37963][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-27 14:55:57.932 UTC [37955][checkpointer] LOG:  shutting down
2024-04-27 14:55:57.934 UTC [37949][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[14:55:58.033](0.963s) 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 38111
### 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=62626 host=/tmp/eaBXGL6n8d dbname='pg1' --socket-directory /tmp/eaBXGL6n8d --subscriber-port 62628 --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 7362560282632033994 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7362560282632033994 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-27 14:55:58.615 UTC [38236][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-27 14:55:58.615 UTC [38236][postmaster] LOG:  listening on Unix socket "/tmp/eaBXGL6n8d/.s.PGSQL.62628"
2024-04-27 14:55:58.725 UTC [38261][startup] LOG:  database system was shut down in recovery at 2024-04-27 14:55:58 UTC
2024-04-27 14:55:58.725 UTC [38261][startup] LOG:  entering standby mode
2024-04-27 14:55:58.726 UTC [38261][startup] LOG:  consistent recovery state reached at 0/3000188
2024-04-27 14:55:58.726 UTC [38236][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-27 14:55:58.726 UTC [38261][startup] LOG:  invalid record length at 0/3000188: expected at least 24, got 0
2024-04-27 14:55:58.730 UTC [38262][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-04-27 14:55:58.730 UTC [38261][startup] LOG:  redo starts at 0/3000188
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-27 14:55:58.824 UTC [38286][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:55:58.824 UTC [38286][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-27 14:55:58.824 UTC [38286][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-27 14:55:58.831 UTC [38286][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-27 14:55:58.832 UTC [38286][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:55:58.832 UTC [38286][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-27 14:55:58.835 UTC [38286][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: 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-27 14:55:58.861 UTC [38236][postmaster] LOG:  received fast shutdown request
2024-04-27 14:55:58.861 UTC [38236][postmaster] LOG:  aborting any active transactions
2024-04-27 14:55:58.862 UTC [38262][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-27 14:55:58.863 UTC [38259][checkpointer] LOG:  shutting down
2024-04-27 14:55:58.865 UTC [38236][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[14:55:58.966](0.933s) 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=62626 host=/tmp/eaBXGL6n8d dbname='pg1' --socket-directory /tmp/eaBXGL6n8d --subscriber-port 62628 --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 7362560282632033994 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7362560282632033994 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-27 14:55:59.027 UTC [38329][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-27 14:55:59.027 UTC [38329][postmaster] LOG:  listening on Unix socket "/tmp/eaBXGL6n8d/.s.PGSQL.62628"
2024-04-27 14:55:59.061 UTC [38336][startup] LOG:  database system was shut down in recovery at 2024-04-27 14:55:58 UTC
2024-04-27 14:55:59.062 UTC [38336][startup] LOG:  entering standby mode
2024-04-27 14:55:59.063 UTC [38336][startup] LOG:  redo starts at 0/3000188
2024-04-27 14:55:59.064 UTC [38336][startup] LOG:  consistent recovery state reached at 0/30046C0
2024-04-27 14:55:59.064 UTC [38329][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-27 14:55:59.064 UTC [38336][startup] LOG:  invalid record length at 0/30046C0: expected at least 24, got 0
2024-04-27 14:55:59.074 UTC [38337][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-27 14:55:59.111 UTC [38346][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:55:59.111 UTC [38346][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-27 14:55:59.111 UTC [38346][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-27 14:55:59.118 UTC [38346][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-27 14:55:59.119 UTC [38346][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:55:59.119 UTC [38346][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-27 14:55:59.127 UTC [38346][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.016 user=postgres database=pg1 host=[local]
2024-04-27 14:55:59.130 UTC [38329][postmaster] LOG:  received fast shutdown request
2024-04-27 14:55:59.130 UTC [38329][postmaster] LOG:  aborting any active transactions
2024-04-27 14:55:59.130 UTC [38337][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-27 14:55:59.132 UTC [38334][checkpointer] LOG:  shutting down
2024-04-27 14:55:59.133 UTC [38329][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[14:55:59.231](0.266s) 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 38378
# 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=62626 host=/tmp/eaBXGL6n8d dbname='pg1' --socket-directory /tmp/eaBXGL6n8d --subscriber-port 62628 --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 7362560282632033994 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7362560282632033994 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-27 14:55:59.693 UTC [38403][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-27 14:55:59.701 UTC [38403][postmaster] LOG:  listening on Unix socket "/tmp/eaBXGL6n8d/.s.PGSQL.62628"
2024-04-27 14:55:59.784 UTC [38415][startup] LOG:  database system was shut down in recovery at 2024-04-27 14:55:59 UTC
2024-04-27 14:55:59.784 UTC [38415][startup] LOG:  entering standby mode
2024-04-27 14:55:59.785 UTC [38415][startup] LOG:  redo starts at 0/3000188
2024-04-27 14:55:59.786 UTC [38415][startup] LOG:  consistent recovery state reached at 0/30046C0
2024-04-27 14:55:59.786 UTC [38403][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-27 14:55:59.786 UTC [38415][startup] LOG:  invalid record length at 0/30046C0: expected at least 24, got 0
2024-04-27 14:55:59.789 UTC [38421][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-27 14:55:59.816 UTC [38431][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:55:59.817 UTC [38431][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-27 14:55:59.817 UTC [38431][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-27 14:55:59.827 UTC [38431][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-27 14:55:59.827 UTC [38431][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:55:59.828 UTC [38431][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-27 14:55:59.830 UTC [38431][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.014 user=postgres database=pg1 host=[local]
pg_createsubscriber: primary has replication slot "physical_slot"
pg_createsubscriber: stopping the subscriber
2024-04-27 14:55:59.844 UTC [38403][postmaster] LOG:  received fast shutdown request
2024-04-27 14:55:59.844 UTC [38403][postmaster] LOG:  aborting any active transactions
2024-04-27 14:55:59.845 UTC [38421][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-27 14:55:59.847 UTC [38413][checkpointer] LOG:  shutting down
2024-04-27 14:55:59.847 UTC [38413][checkpointer] LOG:  restartpoint starting: shutdown immediate
2024-04-27 14:55:59.847 UTC [38413][checkpointer] LOG:  restartpoint complete: wrote 4 buffers (3.1%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=17 kB, estimate=17 kB; lsn=0/30046C0, redo lsn=0/30046C0
2024-04-27 14:55:59.847 UTC [38413][checkpointer] LOG:  recovery restart point at 0/30046C0
2024-04-27 14:55:59.849 UTC [38403][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-27 14:56:00.023 UTC [38474][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-27 14:56:00.023 UTC [38474][postmaster] LOG:  listening on Unix socket "/tmp/eaBXGL6n8d/.s.PGSQL.62628"
2024-04-27 14:56:00.031 UTC [38477][startup] LOG:  database system was shut down in recovery at 2024-04-27 14:55:59 UTC
2024-04-27 14:56:00.032 UTC [38477][startup] LOG:  entering standby mode
2024-04-27 14:56:00.033 UTC [38477][startup] LOG:  redo starts at 0/3004738
2024-04-27 14:56:00.033 UTC [38477][startup] LOG:  consistent recovery state reached at 0/3004770
2024-04-27 14:56:00.033 UTC [38477][startup] LOG:  invalid record length at 0/3004770: expected at least 24, got 0
2024-04-27 14:56:00.033 UTC [38474][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-27 14:56:00.044 UTC [38478][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-27 14:56:00.085 UTC [38485][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:56:00.086 UTC [38485][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-27 14:56:00.086 UTC [38485][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-27 14:56:00.091 UTC [38485][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-27 14:56:00.091 UTC [38485][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-27 14:56:00.092 UTC [38485][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.006 user=postgres database=pg1 host=[local]
2024-04-27 14:56:00.093 UTC [38486][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:56:00.094 UTC [38486][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-27 14:56:00.094 UTC [38486][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-27 14:56:00.094 UTC [38486][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-27 14:56:00.095 UTC [38486][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-27 14:56:00.096 UTC [38486][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.003 user=postgres database=pg1 host=[local]
2024-04-27 14:56:00.098 UTC [38487][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:56:00.098 UTC [38487][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-27 14:56:00.098 UTC [38487][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=pg2 application_name=040_pg_createsubscriber.pl
2024-04-27 14:56:00.184 UTC [38487][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-27 14:56:00.184 UTC [38487][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-27 14:56:00.185 UTC [38487][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.087 user=postgres database=pg2 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: stopping the subscriber
2024-04-27 14:56:00.197 UTC [38474][postmaster] LOG:  received fast shutdown request
2024-04-27 14:56:00.197 UTC [38474][postmaster] LOG:  aborting any active transactions
2024-04-27 14:56:00.197 UTC [38478][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-27 14:56:00.198 UTC [38475][checkpointer] LOG:  shutting down
2024-04-27 14:56:00.202 UTC [38474][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7362560758248068598 on subscriber
pg_createsubscriber: running pg_resetwal on the subscriber
pg_createsubscriber: Done!
[14:56:00.298](1.067s) 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 38520
[14:56:00.459](0.161s) 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=62626 host=/tmp/eaBXGL6n8d dbname='pg1' --socket-directory /tmp/eaBXGL6n8d --subscriber-port 62628 --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 7362560282632033994 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7362560282632033994 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-27 14:56:00.718 UTC [38570][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-27 14:56:00.718 UTC [38570][postmaster] LOG:  listening on Unix socket "/tmp/eaBXGL6n8d/.s.PGSQL.62628"
2024-04-27 14:56:00.809 UTC [38586][startup] LOG:  database system was shut down in recovery at 2024-04-27 14:56:00 UTC
2024-04-27 14:56:00.809 UTC [38586][startup] LOG:  entering standby mode
2024-04-27 14:56:00.811 UTC [38586][startup] LOG:  redo starts at 0/3004738
2024-04-27 14:56:00.811 UTC [38586][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-04-27 14:56:00.811 UTC [38570][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-27 14:56:00.811 UTC [38586][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-27 14:56:00.820 UTC [38597][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:56:00.821 UTC [38597][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-27 14:56:00.821 UTC [38597][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-27 14:56:00.827 UTC [38597][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-27 14:56:00.827 UTC [38597][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:00.827 UTC [38597][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-27 14:56:00.830 UTC [38597][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=postgres database=pg1 host=[local]
pg_createsubscriber: error: could not obtain replication slot information: got 0 rows, expected 1 row
2024-04-27 14:56:00.844 UTC [38590][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-04-27 14:56:00.846 UTC [38570][postmaster] LOG:  received fast shutdown request
2024-04-27 14:56:00.846 UTC [38570][postmaster] LOG:  aborting any active transactions
2024-04-27 14:56:00.846 UTC [38590][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-27 14:56:00.848 UTC [38584][checkpointer] LOG:  shutting down
2024-04-27 14:56:00.850 UTC [38570][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[14:56:00.954](0.495s) not ok 26 - run pg_createsubscriber without --databases
[14:56:00.955](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=62626 host=/tmp/eaBXGL6n8d dbname='pg1' --socket-directory /tmp/eaBXGL6n8d --subscriber-port 62628 --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/eaBXGL6n8d port=62626 dbname=pg1
pg_createsubscriber: subscriber(0): subscription: (auto) ; connection string: port=62628 host=/tmp/eaBXGL6n8d fallback_application_name=pg_createsubscriber dbname=pg1
pg_createsubscriber: publisher(1): publication: Pub2 ; replication slot: replslot2 ; connection string: host=/tmp/eaBXGL6n8d port=62626 dbname=pg2
pg_createsubscriber: subscriber(1): subscription: (auto) ; connection string: port=62628 host=/tmp/eaBXGL6n8d fallback_application_name=pg_createsubscriber dbname=pg2
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7362560282632033994 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7362560282632033994 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 62628" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/tmp/eaBXGL6n8d'"
2024-04-27 14:56:01.202 UTC [38646][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-27 14:56:01.202 UTC [38646][postmaster] LOG:  listening on Unix socket "/tmp/eaBXGL6n8d/.s.PGSQL.62628"
2024-04-27 14:56:01.219 UTC [38660][startup] LOG:  database system was shut down in recovery at 2024-04-27 14:56:00 UTC
2024-04-27 14:56:01.220 UTC [38660][startup] LOG:  entering standby mode
2024-04-27 14:56:01.251 UTC [38660][startup] LOG:  redo starts at 0/3004738
2024-04-27 14:56:01.251 UTC [38660][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-04-27 14:56:01.251 UTC [38660][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
2024-04-27 14:56:01.257 UTC [38646][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-27 14:56:01.300 UTC [38674][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-27 14:56:01.362 UTC [38689][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:56:01.362 UTC [38689][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-27 14:56:01.362 UTC [38689][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-27 14:56:01.368 UTC [38689][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-27 14:56:01.368 UTC [38689][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:01.369 UTC [38689][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-27 14:56:01.371 UTC [38689][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.009 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-27 14:56:01.384 UTC [38646][postmaster] LOG:  received fast shutdown request
2024-04-27 14:56:01.384 UTC [38646][postmaster] LOG:  aborting any active transactions
2024-04-27 14:56:01.384 UTC [38674][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-27 14:56:01.385 UTC [38657][checkpointer] LOG:  shutting down
2024-04-27 14:56:01.386 UTC [38646][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/eaBXGL6n8d'' port=62626 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 62628" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/tmp/eaBXGL6n8d'"
2024-04-27 14:56:01.807 UTC [38753][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-04-27 14:56:01.807 UTC [38753][postmaster] LOG:  listening on Unix socket "/tmp/eaBXGL6n8d/.s.PGSQL.62628"
2024-04-27 14:56:01.810 UTC [38759][startup] LOG:  database system was shut down in recovery at 2024-04-27 14:56:01 UTC
2024-04-27 14:56:01.810 UTC [38759][startup] LOG:  entering standby mode
2024-04-27 14:56:01.812 UTC [38759][startup] LOG:  redo starts at 0/3004738
2024-04-27 14:56:01.812 UTC [38759][startup] LOG:  consistent recovery state reached at 0/3008C70
2024-04-27 14:56:01.812 UTC [38753][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-27 14:56:01.812 UTC [38759][startup] LOG:  invalid record length at 0/3008C70: expected at least 24, got 0
2024-04-27 14:56:01.831 UTC [38760][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-27 14:56:01.864 UTC [38763][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:56:01.864 UTC [38763][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-27 14:56:01.865 UTC [38763][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-27 14:56:01.877 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-27 14:56:01.878 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:01.878 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/4:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:02.879 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/5:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:02.879 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/6:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:03.880 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/7:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:03.880 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/8:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:04.880 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/9:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:04.881 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/10:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:05.882 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/11:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:05.882 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/12:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:06.883 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/13:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:06.883 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/14:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:07.883 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/15:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:07.884 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/16:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:08.884 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/17:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:08.884 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/18:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:09.885 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/19:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:09.885 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/20:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:10.885 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/21:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:10.886 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/22:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:11.886 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/23:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:11.886 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/24:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:12.887 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/25:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:12.887 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/26:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:13.887 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/27:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-27 14:56:13.888 UTC [38763][client backend] [040_pg_createsubscriber.pl][0/28:0] LOG:  statement: SELECT 1 FROM pg_catalog.pg_stat_wal_receiver
2024-04-27 14:56:14.451 UTC [38759][startup] LOG:  recovery stopping after WAL location (LSN) "0/30092C0"
2024-04-27 14:56:14.451 UTC [38759][startup] LOG:  redo done at 0/30092C0 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 12.63 s
2024-04-27 14:56:14.451 UTC [38759][startup] LOG:  last completed transaction was at log time 2024-04-27 14:56:01.567863+00
2024-04-27 14:56:14.451 UTC [38760][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-27 14:56:14.454 UTC [38759][startup] LOG:  selected new timeline ID: 2
2024-04-27 14:56:14.464 UTC [38759][startup] LOG:  archive recovery complete
2024-04-27 14:56:14.469 UTC [38757][checkpointer] LOG:  checkpoint starting: end-of-recovery immediate wait
2024-04-27 14:56:14.469 UTC [38757][checkpointer] LOG:  checkpoint complete: wrote 16 buffers (12.5%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=19 kB, estimate=19 kB; lsn=0/30092F8, redo lsn=0/30092F8
2024-04-27 14:56:14.471 UTC [38753][postmaster] LOG:  database system is ready to accept connections
2024-04-27 14:56:14.888 UTC [38763][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-27 14:56:14.889 UTC [38763][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:13.025 user=postgres database=pg1 host=[local]
2024-04-27 14:56:14.893 UTC [41519][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:56:14.893 UTC [41519][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-27 14:56:14.893 UTC [41519][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-27 14:56:14.894 UTC [41519][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-27 14:56:14.901 UTC [41519][client backend] [040_pg_createsubscriber.pl][1/3:0] LOG:  statement: DROP PUBLICATION "pub1"
pg_createsubscriber: creating subscription "pg_createsubscriber_16384_af42edfd" on database "pg1"
pg_createsubscriber: command is: CREATE SUBSCRIPTION "pg_createsubscriber_16384_af42edfd" CONNECTION 'host=/tmp/eaBXGL6n8d port=62626 dbname=pg1' PUBLICATION "pub1" WITH (create_slot = false, enabled = false, slot_name = 'replslot1', copy_data = false)
2024-04-27 14:56:14.902 UTC [41519][client backend] [040_pg_createsubscriber.pl][1/4:0] LOG:  statement: CREATE SUBSCRIPTION "pg_createsubscriber_16384_af42edfd" CONNECTION 'host=/tmp/eaBXGL6n8d port=62626 dbname=pg1' PUBLICATION "pub1" WITH (create_slot = false, enabled = false, slot_name = 'replslot1', copy_data = false)
2024-04-27 14:56:14.934 UTC [41519][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_af42edfd' 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-27 14:56:14.936 UTC [41519][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_af42edfd" on database "pg1"
pg_createsubscriber: command is: ALTER SUBSCRIPTION "pg_createsubscriber_16384_af42edfd" ENABLE
2024-04-27 14:56:14.936 UTC [41519][client backend] [040_pg_createsubscriber.pl][1/7:0] LOG:  statement: ALTER SUBSCRIPTION "pg_createsubscriber_16384_af42edfd" ENABLE
2024-04-27 14:56:14.937 UTC [41519][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.046 user=postgres database=pg1 host=[local]
2024-04-27 14:56:14.945 UTC [41534][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-27 14:56:14.946 UTC [41534][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-27 14:56:14.946 UTC [41534][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=pg2 application_name=040_pg_createsubscriber.pl
2024-04-27 14:56:14.946 UTC [41535][logical replication apply worker] LOG:  logical replication apply worker for subscription "pg_createsubscriber_16384_af42edfd" has started
2024-04-27 14:56:14.961 UTC [41534][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-27 14:56:14.961 UTC [41534][client backend] [040_pg_createsubscriber.pl][2/3:0] LOG:  statement: DROP PUBLICATION "Pub2"
pg_createsubscriber: creating subscription "pg_createsubscriber_16385_7bd51321" on database "pg2"
pg_createsubscriber: command is: CREATE SUBSCRIPTION "pg_createsubscriber_16385_7bd51321" CONNECTION 'host=/tmp/eaBXGL6n8d port=62626 dbname=pg2' PUBLICATION "Pub2" WITH (create_slot = false, enabled = false, slot_name = 'replslot2', copy_data = false)
2024-04-27 14:56:14.962 UTC [41534][client backend] [040_pg_createsubscriber.pl][2/4:0] LOG:  statement: CREATE SUBSCRIPTION "pg_createsubscriber_16385_7bd51321" CONNECTION 'host=/tmp/eaBXGL6n8d port=62626 dbname=pg2' PUBLICATION "Pub2" WITH (create_slot = false, enabled = false, slot_name = 'replslot2', copy_data = false)
2024-04-27 14:56:14.976 UTC [41534][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_7bd51321' 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-27 14:56:14.977 UTC [41534][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_7bd51321" on database "pg2"
pg_createsubscriber: command is: ALTER SUBSCRIPTION "pg_createsubscriber_16385_7bd51321" ENABLE
2024-04-27 14:56:14.978 UTC [41534][client backend] [040_pg_createsubscriber.pl][2/7:0] LOG:  statement: ALTER SUBSCRIPTION "pg_createsubscriber_16385_7bd51321" ENABLE
2024-04-27 14:56:14.979 UTC [41534][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.033 user=postgres database=pg2 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: command is: SELECT pg_catalog.pg_drop_replication_slot('physical_slot')
2024-04-27 14:56:14.992 UTC [41547][logical replication apply worker] LOG:  logical replication apply worker for subscription "pg_createsubscriber_16385_7bd51321" has started
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-27 14:56:15.000 UTC [38753][postmaster] LOG:  received fast shutdown request
2024-04-27 14:56:15.000 UTC [38753][postmaster] LOG:  aborting any active transactions
2024-04-27 14:56:15.000 UTC [41547][logical replication apply worker] FATAL:  terminating logical replication worker due to administrator command
2024-04-27 14:56:15.001 UTC [38753][postmaster] LOG:  background worker "logical replication apply worker" (PID 41547) exited with exit code 1
2024-04-27 14:56:15.001 UTC [41535][logical replication apply worker] FATAL:  terminating logical replication worker due to administrator command
2024-04-27 14:56:15.002 UTC [38753][postmaster] LOG:  background worker "logical replication apply worker" (PID 41535) exited with exit code 1
2024-04-27 14:56:15.003 UTC [38753][postmaster] LOG:  background worker "logical replication launcher" (PID 41386) exited with exit code 1
2024-04-27 14:56:15.004 UTC [38757][checkpointer] LOG:  shutting down
2024-04-27 14:56:15.004 UTC [38757][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-27 14:56:15.004 UTC [38757][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-27 14:56:15.006 UTC [38753][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7362560821865903840 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!
[14:56:15.221](14.266s) ok 27 - run pg_createsubscriber on node S
[14:56:15.252](0.031s) 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 41594
Waiting for all subscriptions in "node_s" to synchronize data
Waiting for replication conn pg_createsubscriber_16384_af42edfd'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_7bd51321's replay_lsn to pass 0/3009480 on node_p
done
done
[14:56:15.782](0.531s) ok 29 - logical replication works on database pg1
[14:56:15.825](0.043s) ok 30 - logical replication works on database pg2
[14:56:15.880](0.055s) 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"
[14:56:16.020](0.140s) 1..31
[14:56:16.022](0.002s) # Looks like you failed 1 test of 31.