# Checking port 21026
# Found port 21026
Name: primary
Version: 19devel
Data directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata
Backup directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_primary_data/backup
Archive directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_primary_data/archives
Connection string: port=21026 host=/tmp/r3aRC7ZVb2
Log file: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/log/035_standby_logical_decoding_primary.log
# Checking port 21027
# Found port 21027
Name: standby
Version: 19devel
Data directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata
Backup directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/backup
Archive directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/archives
Connection string: port=21027 host=/tmp/r3aRC7ZVb2
Log file: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/log/035_standby_logical_decoding_standby.log
# Checking port 21028
# Found port 21028
Name: cascading_standby
Version: 19devel
Data directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_cascading_standby_data/pgdata
Backup directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_cascading_standby_data/backup
Archive directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_cascading_standby_data/archives
Connection string: port=21028 host=/tmp/r3aRC7ZVb2
Log file: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/log/035_standby_logical_decoding_cascading_standby.log
# Checking port 21029
# Found port 21029
Name: subscriber
Version: 19devel
Data directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_subscriber_data/pgdata
Backup directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_subscriber_data/backup
Archive directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_subscriber_data/archives
Connection string: port=21029 host=/tmp/r3aRC7ZVb2
Log file: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/log/035_standby_logical_decoding_subscriber.log
[20:33:58.534](0.018s) # initializing database system by copying initdb template
# Running: cp -RPp /pgtest/postgresql.chk/tmp_install/initdb-template /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata
# Running: /pgtest/postgresql.chk/src/test/recovery_2/../../../src/test/regress/pg_regress --config-auth /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata
### Enabling WAL archiving for node "primary"
Name: primary
Version: 19devel
Data directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata
Backup directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_primary_data/backup
Archive directory: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_primary_data/archives
Connection string: port=21026 host=/tmp/r3aRC7ZVb2
Log file: /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/log/035_standby_logical_decoding_primary.log
### Starting node "primary"
# Running: pg_ctl --wait --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata --log /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/log/035_standby_logical_decoding_primary.log --options --cluster-name=primary start
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 839582
[20:34:00.175](1.641s) ok 1 - Physical slot reports conflicting as NULL
# Taking pg_basebackup b1 from node "primary"
# Running: pg_basebackup --no-sync --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_primary_data/backup/b1 --host /tmp/r3aRC7ZVb2 --port 21026 --checkpoint fast
# Backup finished
# Initializing node "standby" from backup "b1" of node "primary"
### Enabling streaming replication for node "standby"
### Enabling WAL restore for node "standby"
### Starting node "standby"
# Running: pg_ctl --wait --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata --log /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/log/035_standby_logical_decoding_standby.log --options --cluster-name=standby start
waiting for server to start........ done
server started
# Postmaster PID for node "standby" is 840305
Waiting for replication conn standby's replay_lsn to pass 0/03015B40 on primary
done
[20:34:10.297](10.122s) # initializing database system by copying initdb template
# Running: cp -RPp /pgtest/postgresql.chk/tmp_install/initdb-template /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_subscriber_data/pgdata
# Running: /pgtest/postgresql.chk/src/test/recovery_2/../../../src/test/regress/pg_regress --config-auth /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_subscriber_data/pgdata
### Starting node "subscriber"
# Running: pg_ctl --wait --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_subscriber_data/pgdata --log /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/log/035_standby_logical_decoding_subscriber.log --options --cluster-name=subscriber start
waiting for server to start.... done
server started
# Postmaster PID for node "subscriber" is 840910
[20:34:10.680](0.383s) ok 2 - restart_test on standby created
### Stopping node "standby" using mode fast
# Running: pg_ctl --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "standby"
# Running: pg_ctl --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata --log /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/log/035_standby_logical_decoding_standby.log start
waiting for server to start.... done
server shut down because of recovery target settings
[20:34:11.288](0.608s) ok 3 - the standby ends with an error during startup because hot_standby was disabled
### Starting node "standby"
# Running: pg_ctl --wait --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata --log /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/log/035_standby_logical_decoding_standby.log --options --cluster-name=standby start
waiting for server to start.... done
server started
# Postmaster PID for node "standby" is 841466
[20:34:11.484](0.195s) ok 4 - behaves_ok_inactiveslot on standby created
[20:34:11.682](0.198s) ok 5 - behaves_ok_activeslot on standby created
Waiting for replication conn standby's replay_lsn to pass 0/03021210 on primary
done
[20:34:11.715](0.033s) ok 6 - Decoding produced 14 rows (2 BEGIN/COMMIT and 10 rows)
Waiting for replication conn standby's replay_lsn to pass 0/03021340 on primary
done
[20:34:11.740](0.025s) ok 7 - got expected output from SQL decoding session
Waiting for replication conn standby's replay_lsn to pass 0/03021EF0 on primary
done
[20:34:11.771](0.032s) ok 8 - got same expected output from pg_recvlogical decoding session
[20:34:11.784](0.012s) ok 9 - pg_recvlogical acknowledged changes
Waiting for replication conn standby's replay_lsn to pass 0/034706E8 on primary
done
[20:34:11.835](0.051s) ok 10 - replaying logical slot from another database fails
Waiting for replication conn standby's replay_lsn to pass 0/03491DD0 on primary
done
Waiting for all subscriptions in "subscriber" to synchronize data
Waiting for replication conn tap_sub's replay_lsn to pass 0/03491E08 on standby
done
done
Waiting for replication conn standby's replay_lsn to pass 0/034923B0 on primary
done
Waiting for replication conn tap_sub's replay_lsn to pass 0/034923B0 on standby
done
[20:34:12.274](0.438s) ok 11 - check replicated inserts after subscription on standby
#### Begin standard error
psql:<stdin>:1: NOTICE:  dropped replication slot "tap_sub" on publisher
#### End standard error
### Stopping node "subscriber" using mode fast
# Running: pg_ctl --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_subscriber_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "subscriber"


[20:34:12.487](0.213s) ok 12 - vacuum_full_inactiveslot on standby created
[20:34:12.683](0.197s) ok 13 - vacuum_full_activeslot on standby created
### Reloading node "standby"
# Running: pg_ctl --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata reload
server signaled

#### Begin standard error
psql:<stdin>:1: INFO:  vacuuming "pg_catalog.pg_class"
psql:<stdin>:1: INFO:  "pg_catalog.pg_class": found 5 removable, 422 nonremovable row versions in 14 pages
DETAIL:  0 dead row versions cannot be removed yet.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
#### End standard error
Waiting for replication conn standby's replay_lsn to pass 0/034E49A8 on primary
done
[20:34:12.956](0.273s) ok 14 - inactiveslot slot invalidation is logged with vacuum FULL on pg_class
[20:34:12.956](0.000s) ok 15 - activeslot slot invalidation is logged with vacuum FULL on pg_class
[20:34:12.966](0.010s) ok 16 - confl_active_logicalslot updated
[20:34:12.977](0.011s) ok 17 - vacuum_full_activeslot reason for conflict is rows_removed
[20:34:12.988](0.011s) ok 18 - vacuum_full_inactiveslot reason for conflict is rows_removed
[20:34:12.996](0.009s) ok 19 - invalidated slot cannot be altered
[20:34:13.008](0.012s) ok 20 - replication slot stats not removed after invalidation
[20:34:13.016](0.008s) ok 21 - pg_recvlogical exited non-zero
[20:34:13.016](0.000s) ok 22 - slot has been invalidated
[20:34:13.022](0.006s) ok 23 - invalidated slot cannot be copied
### Reloading node "standby"
# Running: pg_ctl --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata reload
server signaled
### Restarting node "standby"
# Running: pg_ctl --wait --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata --log /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/log/035_standby_logical_decoding_standby.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "standby" is 844670
[20:34:13.246](0.225s) ok 24 - vacuum_full_activeslot reason for conflict is rows_removed
[20:34:13.255](0.008s) ok 25 - vacuum_full_inactiveslot reason for conflict is rows_removed
Waiting for replication conn standby's replay_lsn to pass 0/04000100 on primary
done
[20:34:13.729](0.474s) ok 26 - invalidated logical slots do not lead to retaining WAL


[20:34:13.885](0.156s) ok 27 - row_removal_inactiveslot on standby created
[20:34:14.085](0.199s) ok 28 - row_removal_activeslot on standby created
### Reloading node "standby"
# Running: pg_ctl --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata reload
server signaled

#### Begin standard error
psql:<stdin>:1: INFO:  vacuuming "testdb.pg_catalog.pg_class"
psql:<stdin>:1: INFO:  finished vacuuming "testdb.pg_catalog.pg_class": index scans: 1
pages: 0 removed, 11 remain, 11 scanned (100.00% of total), 0 eagerly scanned
tuples: 0 removed, 421 remain, 0 are dead but not yet removable
removable cutoff: 749, which was 0 XIDs old when operation ended
frozen: 0 pages from table (0.00% of total) had 0 tuples frozen
visibility map: 11 pages set all-visible, 10 pages set all-frozen (0 were all-visible)
index scan needed: 3 pages from table (27.27% of total) had 5 dead item identifiers removed
index "pg_class_oid_index": pages: 4 in total, 0 newly deleted, 0 currently deleted, 0 reusable
index "pg_class_relname_nsp_index": pages: 5 in total, 0 newly deleted, 0 currently deleted, 0 reusable
index "pg_class_tblspc_relfilenode_index": pages: 2 in total, 0 newly deleted, 0 currently deleted, 0 reusable
avg read rate: 152.853 MB/s, avg write rate: 254.755 MB/s
buffer usage: 89 hits, 9 reads, 15 dirtied
WAL usage: 24 records, 15 full page images, 122842 bytes, 120560 full page image bytes, 8 buffers full
memory usage: dead item storage 0.03 MB accumulated across 1 reset (limit 64.00 MB each)
system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
#### End standard error
Waiting for replication conn standby's replay_lsn to pass 0/0403F950 on primary
[20:37:26.816](192.731s) # poll_query_until timed out executing this query:
# SELECT '0/0403F950' <= replay_lsn AND state = 'streaming'
#          FROM pg_catalog.pg_stat_replication
#          WHERE application_name IN ('standby', 'walreceiver')
# expecting this output:
# t
# last actual query output:
# f
# with stderr:
[20:37:26.824](0.008s) # Last pg_stat_replication contents:
# 844827|10|law|standby|||-1|2026-03-03 20:34:13.175574+02||streaming|0/0403F950|0/0403F950|0/0403F950|0/040214F0|00:00:00.000108|00:00:00.000108|00:03:10.132196|0|async|2026-03-03 20:37:24.258376+02
timed out waiting for catchup at t/035_standby_logical_decoding.pl line 281.
# Postmaster PID for node "primary" is 839582
### Stopping node "primary" using mode immediate
# Running: pg_ctl --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata --mode immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "primary"
# Postmaster PID for node "standby" is 844670
### Stopping node "standby" using mode immediate
# Running: pg_ctl --pgdata /pgtest/postgresql.chk/src/test/recovery_2/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata --mode immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "standby"
# No postmaster PID for node "cascading_standby"
# No postmaster PID for node "subscriber"
[20:37:27.030](0.206s) # Tests were run but no plan was declared and done_testing() was not seen.
[20:37:27.030](0.000s) # Looks like your test exited with 29 just after 28.
