# Running: pg_createsubscriber --help
[07:10:09.584](0.130s) ok 1 - pg_createsubscriber --help exit code 0
[07:10:09.591](0.007s) ok 2 - pg_createsubscriber --help goes to stdout
[07:10:09.591](0.000s) ok 3 - pg_createsubscriber --help nothing to stderr
[07:10:09.591](0.000s) ok 4 - pg_createsubscriber --help maximum line length
# Running: pg_createsubscriber --version
[07:10:09.635](0.044s) ok 5 - pg_createsubscriber --version exit code 0
[07:10:09.647](0.011s) ok 6 - pg_createsubscriber --version goes to stdout
[07:10:09.647](0.001s) ok 7 - pg_createsubscriber --version nothing to stderr
# Running: pg_createsubscriber --not-a-valid-option
[07:10:09.667](0.020s) ok 8 - pg_createsubscriber with invalid option nonzero exit code
[07:10:09.667](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.
[07:10:09.680](0.014s) ok 10 - no subscriber data directory specified
# Running: pg_createsubscriber --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_4e8N
pg_createsubscriber: error: no publisher connection string specified
pg_createsubscriber: hint: Try "pg_createsubscriber --help" for more information.
[07:10:09.693](0.012s) ok 11 - no publisher connection string specified
# Running: pg_createsubscriber --verbose --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_4e8N --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.
[07:10:09.705](0.012s) ok 12 - no database name specified
# Running: pg_createsubscriber --verbose --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_4e8N --publisher-server port=5432 --database pg1 --database pg1
pg_createsubscriber: error: duplicate database "pg1"
[07:10:09.717](0.012s) ok 13 - duplicate database name
# Running: pg_createsubscriber --verbose --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_4e8N --publisher-server port=5432 --publication foo1 --publication foo1 --database pg1 --database pg2
pg_createsubscriber: error: duplicate publication "foo1"
[07:10:09.730](0.014s) ok 14 - duplicate publication name
# Running: pg_createsubscriber --verbose --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_4e8N --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).
[07:10:09.741](0.011s) ok 15 - wrong number of publication names
# Running: pg_createsubscriber --verbose --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_4e8N --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).
[07:10:09.751](0.010s) ok 16 - wrong number of subscription names
# Running: pg_createsubscriber --verbose --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/tmp_test_4e8N --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).
[07:10:09.762](0.011s) ok 17 - wrong number of replication slot names
# Checking port 55465
# Found port 55465
Name: node_p
Data directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata
Backup directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/backup
Archive directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/archives
Connection string: port=55465 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ
Log file: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_p.log
[07:10:09.769](0.008s) # initializing database system by copying initdb template
# Running: cp -RPp /Users/admin/pgsql/build/tmp_install/initdb-template /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata
# Running: /Users/admin/pgsql/build/src/test/regress/pg_regress --config-auth /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata -l /Users/admin/pgsql/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 28734
# Checking port 55466
# Found port 55466
Name: node_f
Data directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/pgdata
Backup directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/backup
Archive directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/archives
Connection string: port=55466 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ
Log file: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/log/040_pg_createsubscriber_node_f.log
[07:10:10.679](0.910s) # initializing database system by running initdb
# Running: initdb -D /Users/admin/pgsql/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 "admin".
This user must also own the server process.

The database cluster will be initialized with this locale configuration:
  locale provider:   libc
  LC_COLLATE:  en_US.UTF-8
  LC_CTYPE:    en_US.UTF-8
  LC_MESSAGES: C
  LC_MONETARY: en_US.UTF-8
  LC_NUMERIC:  en_US.UTF-8
  LC_TIME:     en_US.UTF-8
The default database encoding has accordingly been set to "UTF8".
The default text search configuration will be set to "english".

Data page checksums are disabled.

creating directory /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/pgdata ... ok
creating subdirectories ... ok
selecting dynamic shared memory implementation ... posix
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default time zone ... UTC
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok

Sync to disk skipped.
The data directory might become corrupt if the operating system crashes.

Success. You can now start the database server using:

    pg_ctl -D /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/pgdata -l logfile start

# Running: /Users/admin/pgsql/build/src/test/regress/pg_regress --config-auth /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/backup/backup_1 -h /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ -p 55465 --checkpoint fast --no-sync
# Backup finished
# Checking port 55467
# Found port 55467
Name: node_s
Data directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata
Backup directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/backup
Archive directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/archives
Connection string: port=55467 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ
Log file: /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata -l /Users/admin/pgsql/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 30612
# Checking port 55468
# Found port 55468
Name: node_t
Data directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata
Backup directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/backup
Archive directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/archives
Connection string: port=55468 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ
Log file: /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata -l /Users/admin/pgsql/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 30655
### Promoting node "node_t"
# Running: pg_ctl -D /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata -l /Users/admin/pgsql/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 /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata --publisher-server port=55465 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ dbname='pg1' --socket-directory /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ --subscriber-port 55468 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/Users/admin/pgsql/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 7360213544004204734 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7360213544004204734 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-21 07:10:44.673 UTC [30733][postmaster] LOG:  starting PostgreSQL 17devel on aarch64-darwin, compiled by clang-14.0.3, 64-bit
2024-04-21 07:10:44.673 UTC [30733][postmaster] LOG:  listening on Unix socket "/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ/.s.PGSQL.55468"
2024-04-21 07:10:44.690 UTC [30741][startup] LOG:  database system was shut down at 2024-04-21 07:10:44 UTC
2024-04-21 07:10:44.696 UTC [30733][postmaster] LOG:  database system is ready to accept connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-21 07:10:44.763 UTC [30754][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:44.763 UTC [30754][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_t_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:44.763 UTC [30754][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=admin database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:44.766 UTC [30754][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-21 07:10:44.767 UTC [30754][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-21 07:10:44.768 UTC [30754][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=admin database=pg1 host=[local]
2024-04-21 07:10:44.779 UTC [30733][postmaster] LOG:  received fast shutdown request
2024-04-21 07:10:44.779 UTC [30733][postmaster] LOG:  aborting any active transactions
2024-04-21 07:10:44.780 UTC [30733][postmaster] LOG:  background worker "logical replication launcher" (PID 30747) exited with exit code 1
2024-04-21 07:10:44.780 UTC [30737][checkpointer] LOG:  shutting down
2024-04-21 07:10:44.780 UTC [30737][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-21 07:10:44.781 UTC [30737][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-21 07:10:44.782 UTC [30733][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[07:10:44.959](34.280s) ok 18 - target server is not in recovery
# Running: pg_createsubscriber --verbose --dry-run --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55465 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ dbname='pg1' --socket-directory /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ --subscriber-port 55467 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/Users/admin/pgsql/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 7360213544004204734 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7360213544004204734 on subscriber
pg_createsubscriber: error: standby is up and running
pg_createsubscriber: hint: Stop the standby and try again.
[07:10:44.982](0.024s) ok 19 - standby is up and running
# Running: pg_createsubscriber --verbose --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_f_data/pgdata --publisher-server port=55465 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ dbname='pg1' --socket-directory /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ --subscriber-port 55466 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/Users/admin/pgsql/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 7360213544004204734 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7360214205343133865 on subscriber
pg_createsubscriber: error: subscriber data directory is not a copy of the source database cluster
[07:10:45.006](0.023s) 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 /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/backup/backup_2 -h /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ -p 55467 --checkpoint fast --no-sync
# Backup finished
# Checking port 55469
# Found port 55469
Name: node_c
Data directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_c_data/pgdata
Backup directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_c_data/backup
Archive directory: /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_c_data/archives
Connection string: port=55469 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ
Log file: /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_c_data/pgdata --publisher-server port=55467 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ dbname='pg1' --socket-directory /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ --subscriber-port 55469 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/Users/admin/pgsql/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 7360213544004204734 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7360213544004204734 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-21 07:10:46.001 UTC [30834][postmaster] LOG:  starting PostgreSQL 17devel on aarch64-darwin, compiled by clang-14.0.3, 64-bit
2024-04-21 07:10:46.002 UTC [30834][postmaster] LOG:  listening on Unix socket "/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ/.s.PGSQL.55469"
2024-04-21 07:10:46.240 UTC [30845][startup] LOG:  database system was interrupted while in recovery at log time 2024-04-21 07:10:35 UTC
2024-04-21 07:10:46.240 UTC [30845][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-21 07:10:46.240 UTC [30845][startup] LOG:  starting backup recovery with redo LSN 0/2000028, checkpoint LSN 0/2000080, on timeline ID 1
2024-04-21 07:10:46.240 UTC [30845][startup] LOG:  entering standby mode
2024-04-21 07:10:46.241 UTC [30845][startup] LOG:  redo starts at 0/2000028
2024-04-21 07:10:46.246 UTC [30845][startup] LOG:  completed backup recovery with redo LSN 0/2000028 and end LSN 0/2000120
2024-04-21 07:10:46.246 UTC [30845][startup] LOG:  consistent recovery state reached at 0/3000060
2024-04-21 07:10:46.246 UTC [30845][startup] LOG:  invalid record length at 0/3000060: expected at least 24, got 0
2024-04-21 07:10:46.249 UTC [30834][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-21 07:10:46.255 UTC [30846][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-21 07:10:46.307 UTC [30855][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:46.308 UTC [30855][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_c_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:46.308 UTC [30855][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=admin database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:46.310 UTC [30855][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-21 07:10:46.311 UTC [30855][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-21 07:10:46.311 UTC [30855][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-21 07:10:46.312 UTC [30855][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=admin database=pg1 host=[local]
pg_createsubscriber: error: primary server cannot be in recovery
2024-04-21 07:10:46.321 UTC [30834][postmaster] LOG:  received fast shutdown request
2024-04-21 07:10:46.321 UTC [30834][postmaster] LOG:  aborting any active transactions
2024-04-21 07:10:46.321 UTC [30846][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-21 07:10:46.322 UTC [30841][checkpointer] LOG:  shutting down
2024-04-21 07:10:46.389 UTC [30834][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[07:10:46.427](1.421s) ok 21 - primary server is in recovery
Waiting for replication conn node_s's replay_lsn to pass 0/3000148 on node_p
done
### Restarting node "node_p"
# Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata -l /Users/admin/pgsql/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 30975
### Stopping node "node_s" using mode fast
# Running: pg_ctl -D /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55465 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ dbname='pg1' --socket-directory /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ --subscriber-port 55467 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/Users/admin/pgsql/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 7360213544004204734 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7360213544004204734 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-21 07:10:48.780 UTC [31018][postmaster] LOG:  starting PostgreSQL 17devel on aarch64-darwin, compiled by clang-14.0.3, 64-bit
2024-04-21 07:10:48.780 UTC [31018][postmaster] LOG:  listening on Unix socket "/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ/.s.PGSQL.55467"
2024-04-21 07:10:48.796 UTC [31026][startup] LOG:  database system was shut down in recovery at 2024-04-21 07:10:48 UTC
2024-04-21 07:10:48.796 UTC [31026][startup] LOG:  entering standby mode
2024-04-21 07:10:48.797 UTC [31026][startup] LOG:  consistent recovery state reached at 0/30001C0
2024-04-21 07:10:48.797 UTC [31026][startup] LOG:  invalid record length at 0/30001C0: expected at least 24, got 0
2024-04-21 07:10:48.797 UTC [31018][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-21 07:10:48.806 UTC [31029][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-04-21 07:10:48.806 UTC [31026][startup] LOG:  redo starts at 0/30001C0
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-21 07:10:48.839 UTC [31046][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:48.840 UTC [31046][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:48.840 UTC [31046][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=admin database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:48.885 UTC [31046][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-21 07:10:48.886 UTC [31046][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-21 07:10:48.886 UTC [31046][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-21 07:10:48.888 UTC [31046][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.048 user=admin 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-21 07:10:49.106 UTC [31018][postmaster] LOG:  received fast shutdown request
2024-04-21 07:10:49.299 UTC [31018][postmaster] LOG:  aborting any active transactions
2024-04-21 07:10:49.300 UTC [31029][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-21 07:10:49.301 UTC [31020][checkpointer] LOG:  shutting down
2024-04-21 07:10:49.308 UTC [31018][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[07:10:49.315](2.888s) ok 22 - primary contains unmet conditions on node P
# Running: pg_createsubscriber --verbose --dry-run --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55465 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ dbname='pg1' --socket-directory /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ --subscriber-port 55467 --database pg1 --database pg2
pg_createsubscriber: validating connection string on publisher
pg_createsubscriber: validating connection string on subscriber
pg_createsubscriber: checking if directory "/Users/admin/pgsql/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 7360213544004204734 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7360213544004204734 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-21 07:10:49.480 UTC [31085][postmaster] LOG:  starting PostgreSQL 17devel on aarch64-darwin, compiled by clang-14.0.3, 64-bit
2024-04-21 07:10:49.480 UTC [31085][postmaster] LOG:  listening on Unix socket "/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ/.s.PGSQL.55467"
2024-04-21 07:10:49.615 UTC [31102][startup] LOG:  database system was shut down in recovery at 2024-04-21 07:10:49 UTC
2024-04-21 07:10:49.615 UTC [31102][startup] LOG:  entering standby mode
2024-04-21 07:10:49.616 UTC [31102][startup] LOG:  redo starts at 0/30001C0
2024-04-21 07:10:49.655 UTC [31102][startup] LOG:  consistent recovery state reached at 0/30046F8
2024-04-21 07:10:49.655 UTC [31102][startup] LOG:  invalid record length at 0/30046F8: expected at least 24, got 0
2024-04-21 07:10:49.655 UTC [31085][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-21 07:10:49.658 UTC [31105][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-21 07:10:49.729 UTC [31108][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:49.729 UTC [31108][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:49.729 UTC [31108][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=admin database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:49.737 UTC [31108][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-21 07:10:49.738 UTC [31108][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-21 07:10:49.739 UTC [31108][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-21 07:10:49.741 UTC [31108][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.012 user=admin database=pg1 host=[local]
2024-04-21 07:10:49.755 UTC [31085][postmaster] LOG:  received fast shutdown request
2024-04-21 07:10:49.755 UTC [31085][postmaster] LOG:  aborting any active transactions
2024-04-21 07:10:49.756 UTC [31105][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-21 07:10:49.756 UTC [31099][checkpointer] LOG:  shutting down
2024-04-21 07:10:49.808 UTC [31085][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[07:10:49.857](0.542s) ok 23 - standby contains unmet conditions on node S
### Restarting node "node_p"
# Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_p_data/pgdata -l /Users/admin/pgsql/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 31137
# Running: pg_createsubscriber --verbose --dry-run --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55465 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ dbname='pg1' --socket-directory /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ --subscriber-port 55467 --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 "/Users/admin/pgsql/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 7360213544004204734 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7360213544004204734 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-21 07:10:51.039 UTC [31161][postmaster] LOG:  starting PostgreSQL 17devel on aarch64-darwin, compiled by clang-14.0.3, 64-bit
2024-04-21 07:10:51.130 UTC [31161][postmaster] LOG:  listening on Unix socket "/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ/.s.PGSQL.55467"
2024-04-21 07:10:51.140 UTC [31170][startup] LOG:  database system was shut down in recovery at 2024-04-21 07:10:49 UTC
2024-04-21 07:10:51.140 UTC [31170][startup] LOG:  entering standby mode
2024-04-21 07:10:51.142 UTC [31170][startup] LOG:  redo starts at 0/30001C0
2024-04-21 07:10:51.151 UTC [31170][startup] LOG:  consistent recovery state reached at 0/30046F8
2024-04-21 07:10:51.151 UTC [31170][startup] LOG:  invalid record length at 0/30046F8: expected at least 24, got 0
2024-04-21 07:10:51.151 UTC [31161][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-21 07:10:51.154 UTC [31172][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-21 07:10:51.250 UTC [31181][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:51.250 UTC [31181][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:51.250 UTC [31181][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=admin database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:51.253 UTC [31181][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-21 07:10:51.255 UTC [31181][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-21 07:10:51.256 UTC [31181][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-21 07:10:51.258 UTC [31181][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=admin database=pg1 host=[local]
pg_createsubscriber: primary has replication slot "physical_slot"
pg_createsubscriber: stopping the subscriber
2024-04-21 07:10:51.275 UTC [31161][postmaster] LOG:  received fast shutdown request
2024-04-21 07:10:51.275 UTC [31161][postmaster] LOG:  aborting any active transactions
2024-04-21 07:10:51.276 UTC [31172][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-21 07:10:51.278 UTC [31167][checkpointer] LOG:  shutting down
2024-04-21 07:10:51.278 UTC [31167][checkpointer] LOG:  restartpoint starting: shutdown immediate
2024-04-21 07:10:51.278 UTC [31167][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/30046F8, redo lsn=0/30046F8
2024-04-21 07:10:51.278 UTC [31167][checkpointer] LOG:  recovery restart point at 0/30046F8
2024-04-21 07:10:51.279 UTC [31161][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-21 07:10:51.467 UTC [31206][postmaster] LOG:  starting PostgreSQL 17devel on aarch64-darwin, compiled by clang-14.0.3, 64-bit
2024-04-21 07:10:51.467 UTC [31206][postmaster] LOG:  listening on Unix socket "/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ/.s.PGSQL.55467"
2024-04-21 07:10:51.663 UTC [31217][startup] LOG:  database system was shut down in recovery at 2024-04-21 07:10:51 UTC
2024-04-21 07:10:51.664 UTC [31217][startup] LOG:  entering standby mode
2024-04-21 07:10:51.665 UTC [31217][startup] LOG:  redo starts at 0/3004770
2024-04-21 07:10:51.749 UTC [31217][startup] LOG:  consistent recovery state reached at 0/30047A8
2024-04-21 07:10:51.749 UTC [31217][startup] LOG:  invalid record length at 0/30047A8: expected at least 24, got 0
2024-04-21 07:10:51.749 UTC [31206][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-21 07:10:51.752 UTC [31219][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-21 07:10:51.795 UTC [31224][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:51.795 UTC [31224][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:51.795 UTC [31224][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=admin database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:51.798 UTC [31224][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-21 07:10:51.798 UTC [31224][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-21 07:10:51.798 UTC [31224][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.003 user=admin database=pg1 host=[local]
2024-04-21 07:10:51.799 UTC [31225][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:51.906 UTC [31225][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:51.906 UTC [31225][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=admin database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:51.907 UTC [31225][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-21 07:10:51.907 UTC [31225][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-21 07:10:51.908 UTC [31225][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.108 user=admin database=pg1 host=[local]
2024-04-21 07:10:51.908 UTC [31226][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:51.909 UTC [31226][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:51.909 UTC [31226][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=admin database=pg2 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:51.911 UTC [31226][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-21 07:10:51.912 UTC [31226][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-21 07:10:51.913 UTC [31226][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=admin database=pg2 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: stopping the subscriber
2024-04-21 07:10:51.921 UTC [31206][postmaster] LOG:  received fast shutdown request
2024-04-21 07:10:51.921 UTC [31206][postmaster] LOG:  aborting any active transactions
2024-04-21 07:10:51.921 UTC [31219][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-21 07:10:51.922 UTC [31215][checkpointer] LOG:  shutting down
2024-04-21 07:10:51.966 UTC [31206][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7360214382532176302 on subscriber
pg_createsubscriber: running pg_resetwal on the subscriber
pg_createsubscriber: Done!
[07:10:52.122](2.264s) ok 24 - run pg_createsubscriber --dry-run on node S
### Starting node "node_s"
# Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata -l /Users/admin/pgsql/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 31244
[07:10:52.921](0.799s) ok 25 - standby is in recovery
### Stopping node "node_s" using mode fast
# Running: pg_ctl -D /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55465 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ dbname='pg1' --socket-directory /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ --subscriber-port 55467 --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 "/Users/admin/pgsql/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 7360213544004204734 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7360213544004204734 on subscriber
pg_createsubscriber: starting the standby with command-line options
2024-04-21 07:10:53.505 UTC [31286][postmaster] LOG:  starting PostgreSQL 17devel on aarch64-darwin, compiled by clang-14.0.3, 64-bit
2024-04-21 07:10:53.507 UTC [31286][postmaster] LOG:  listening on Unix socket "/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ/.s.PGSQL.55467"
2024-04-21 07:10:53.713 UTC [31298][startup] LOG:  database system was shut down in recovery at 2024-04-21 07:10:52 UTC
2024-04-21 07:10:53.776 UTC [31298][startup] LOG:  entering standby mode
2024-04-21 07:10:53.778 UTC [31298][startup] LOG:  redo starts at 0/3004770
2024-04-21 07:10:53.790 UTC [31298][startup] LOG:  consistent recovery state reached at 0/3008CA8
2024-04-21 07:10:53.790 UTC [31298][startup] LOG:  invalid record length at 0/3008CA8: expected at least 24, got 0
2024-04-21 07:10:53.790 UTC [31286][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-21 07:10:53.795 UTC [31303][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-21 07:10:53.823 UTC [31307][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:53.824 UTC [31307][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:53.824 UTC [31307][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=admin database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:53.828 UTC [31307][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-21 07:10:53.828 UTC [31307][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-21 07:10:53.829 UTC [31307][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-21 07:10:53.830 UTC [31307][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=admin database=pg1 host=[local]
pg_createsubscriber: primary has replication slot "physical_slot"
pg_createsubscriber: stopping the subscriber
2024-04-21 07:10:53.851 UTC [31286][postmaster] LOG:  received fast shutdown request
2024-04-21 07:10:53.851 UTC [31286][postmaster] LOG:  aborting any active transactions
2024-04-21 07:10:53.851 UTC [31303][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-21 07:10:53.852 UTC [31296][checkpointer] LOG:  shutting down
2024-04-21 07:10:54.032 UTC [31286][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: creating publication "pg_createsubscriber_16384_a3326b18" on database "pg1"
pg_createsubscriber: creating the replication slot "replslot1" on database "pg1"
pg_createsubscriber: create replication slot "replslot1" on publisher
pg_createsubscriber: starting the subscriber
2024-04-21 07:10:54.106 UTC [31322][postmaster] LOG:  starting PostgreSQL 17devel on aarch64-darwin, compiled by clang-14.0.3, 64-bit
2024-04-21 07:10:54.106 UTC [31322][postmaster] LOG:  listening on Unix socket "/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ/.s.PGSQL.55467"
2024-04-21 07:10:54.259 UTC [31333][startup] LOG:  database system was shut down in recovery at 2024-04-21 07:10:53 UTC
2024-04-21 07:10:54.259 UTC [31333][startup] LOG:  entering standby mode
2024-04-21 07:10:54.261 UTC [31333][startup] LOG:  redo starts at 0/3004770
2024-04-21 07:10:54.284 UTC [31333][startup] LOG:  consistent recovery state reached at 0/3008CA8
2024-04-21 07:10:54.284 UTC [31333][startup] LOG:  invalid record length at 0/3008CA8: expected at least 24, got 0
2024-04-21 07:10:54.284 UTC [31322][postmaster] LOG:  database system is ready to accept read-only connections
2024-04-21 07:10:54.287 UTC [31339][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-21 07:10:54.783 UTC [31343][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:54.784 UTC [31343][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:54.784 UTC [31343][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=admin database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:54.788 UTC [31343][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-21 07:10:54.789 UTC [31343][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-21 07:10:54.789 UTC [31343][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.005 user=admin database=pg1 host=[local]
2024-04-21 07:10:54.791 UTC [31346][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:54.792 UTC [31346][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:54.792 UTC [31346][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=admin database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:54.793 UTC [31346][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_a3326b18" on database "pg1"
pg_createsubscriber: creating subscription "pg_createsubscriber_16384_a3326b18" on database "pg1"
2024-04-21 07:10:54.793 UTC [31346][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_a3326b18' 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_a3326b18" on database "pg1"
2024-04-21 07:10:54.795 UTC [31346][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.003 user=admin database=pg1 host=[local]
pg_createsubscriber: dropping the replication slot "physical_slot" on database "pg1"
pg_createsubscriber: stopping the subscriber
2024-04-21 07:10:54.808 UTC [31322][postmaster] LOG:  received fast shutdown request
2024-04-21 07:10:54.809 UTC [31322][postmaster] LOG:  aborting any active transactions
2024-04-21 07:10:54.809 UTC [31339][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-21 07:10:54.809 UTC [31331][checkpointer] LOG:  shutting down
2024-04-21 07:10:54.824 UTC [31322][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
pg_createsubscriber: modifying system identifier of subscriber
pg_createsubscriber: system identifier is 7360214394371508780 on subscriber
pg_createsubscriber: running pg_resetwal on the subscriber
pg_createsubscriber: Done!
[07:10:54.914](1.994s) ok 26 - run pg_createsubscriber without --databases
# Running: pg_createsubscriber --verbose --verbose --pgdata /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata --publisher-server port=55465 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ dbname='pg1' --socket-directory /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ --subscriber-port 55467 --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:  /Users/admin/pgsql/build/tmp_install/usr/local/pgsql/bin/pg_ctl
pg_createsubscriber: pg_resetwal path is:  /Users/admin/pgsql/build/tmp_install/usr/local/pgsql/bin/pg_resetwal
pg_createsubscriber: checking if directory "/Users/admin/pgsql/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=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ port=55465 dbname=pg1
pg_createsubscriber: subscriber(0): subscription: (auto) ; connection string: port=55467 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ fallback_application_name=pg_createsubscriber dbname=pg1
pg_createsubscriber: publisher(1): publication: Pub2 ; replication slot: replslot2 ; connection string: host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ port=55465 dbname=pg2
pg_createsubscriber: subscriber(1): subscription: (auto) ; connection string: port=55467 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ fallback_application_name=pg_createsubscriber dbname=pg2
pg_createsubscriber: getting system identifier from publisher
pg_createsubscriber: system identifier is 7360213544004204734 on publisher
pg_createsubscriber: getting system identifier from subscriber
pg_createsubscriber: system identifier is 7360213544004204734 on subscriber
pg_createsubscriber: starting the standby with command-line options
pg_createsubscriber: pg_ctl command is: "/Users/admin/pgsql/build/tmp_install/usr/local/pgsql/bin/pg_ctl" start -D "/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" -s -o "-p 55467" -o "-c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ'"
2024-04-21 07:10:55.184 UTC [31369][postmaster] LOG:  starting PostgreSQL 17devel on aarch64-darwin, compiled by clang-14.0.3, 64-bit
2024-04-21 07:10:55.184 UTC [31369][postmaster] LOG:  listening on Unix socket "/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/4t2hREErCQ/.s.PGSQL.55467"
2024-04-21 07:10:55.265 UTC [31376][startup] LOG:  database system was shut down in recovery at 2024-04-21 07:10:54 UTC
2024-04-21 07:10:55.265 UTC [31376][startup] LOG:  entering standby mode
2024-04-21 07:10:55.267 UTC [31376][startup] LOG:  redo starts at 0/3004770
2024-04-21 07:10:55.407 UTC [31376][startup] LOG:  consistent recovery state reached at 0/3008CA8
2024-04-21 07:10:55.407 UTC [31376][startup] LOG:  invalid record length at 0/3008CA8: expected at least 24, got 0
2024-04-21 07:10:55.407 UTC [31369][postmaster] LOG:  database system is ready to accept read-only connections
pg_createsubscriber: server was started
pg_createsubscriber: checking settings on subscriber
2024-04-21 07:10:55.556 UTC [31382][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-21 07:10:55.557 UTC [31382][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="admin" method=trust (/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata/pg_hba.conf:117)
2024-04-21 07:10:55.557 UTC [31382][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=admin database=pg1 application_name=040_pg_createsubscriber.pl
2024-04-21 07:10:55.559 UTC [31382][client backend] [040_pg_createsubscriber.pl][0/2:0] LOG:  statement: SELECT pg_catalog.set_config('search_path', '', false);
2024-04-21 07:10:55.567 UTC [31382][client backend] [040_pg_createsubscriber.pl][0/3:0] LOG:  statement: SELECT pg_catalog.pg_is_in_recovery()
2024-04-21 07:10:55.580 UTC [31382][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-21 07:10:55.582 UTC [31382][client backend] [040_pg_createsubscriber.pl][:0] LOG:  disconnection: session time: 0:00:00.025 user=admin 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: 0
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: "/Users/admin/pgsql/build/tmp_install/usr/local/pgsql/bin/pg_ctl" stop -D "/Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata" -s
2024-04-21 07:10:55.616 UTC [31369][postmaster] LOG:  received fast shutdown request
2024-04-21 07:10:55.617 UTC [31369][postmaster] LOG:  aborting any active transactions
2024-04-21 07:10:55.629 UTC [31378][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-04-21 07:10:55.629 UTC [31374][checkpointer] LOG:  shutting down
2024-04-21 07:10:55.630 UTC [31369][postmaster] LOG:  database system is shut down
pg_createsubscriber: server was stopped
[07:10:55.739](0.825s) not ok 27 - run pg_createsubscriber on node S
[07:10:55.739](0.000s) #   Failed test 'run pg_createsubscriber on node S'
#   at /Users/admin/pgsql/src/bin/pg_basebackup/t/040_pg_createsubscriber.pl line 297.
[07:10:55.751](0.012s) not ok 28 - the physical replication slot used as primary_slot_name has been removed
[07:10:55.752](0.000s) #   Failed test 'the physical replication slot used as primary_slot_name has been removed'
#   at /Users/admin/pgsql/src/bin/pg_basebackup/t/040_pg_createsubscriber.pl line 318.
[07:10:55.752](0.000s) #          got: '1'
#     expected: '0'
### Starting node "node_s"
# Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/pg_basebackup/040_pg_createsubscriber/data/t_040_pg_createsubscriber_node_s_data/pgdata -l /Users/admin/pgsql/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 31431
Waiting for all subscriptions in "node_s" to synchronize data
subscription name must be specified at /Users/admin/pgsql/src/bin/pg_basebackup/t/040_pg_createsubscriber.pl line 337.
# Postmaster PID for node "node_p" is 31137
### Stopping node "node_p" using mode immediate
# Running: pg_ctl -D /Users/admin/pgsql/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 31431
### Stopping node "node_s" using mode immediate
# Running: pg_ctl -D /Users/admin/pgsql/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"
[07:10:56.827](1.075s) # Tests were run but no plan was declared and done_testing() was not seen.
[07:10:56.827](0.000s) # Looks like your test exited with 29 just after 28.