# Checking port 60408
# Found port 60408
Name: primary
Data directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata
Backup directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/backup
Archive directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/archives
Connection string: port=60408 host=/tmp/xnH2_WN6pE
Log file: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_primary.log
# Checking port 60409
# Found port 60409
Name: standby
Data directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata
Backup directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/backup
Archive directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/archives
Connection string: port=60409 host=/tmp/xnH2_WN6pE
Log file: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_standby.log
# Checking port 60410
# Found port 60410
Name: cascading_standby
Data directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_cascading_standby_data/pgdata
Backup directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_cascading_standby_data/backup
Archive directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_cascading_standby_data/archives
Connection string: port=60410 host=/tmp/xnH2_WN6pE
Log file: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_cascading_standby.log
# Checking port 60411
# Found port 60411
Name: subscriber
Data directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_subscriber_data/pgdata
Backup directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_subscriber_data/backup
Archive directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_subscriber_data/archives
Connection string: port=60411 host=/tmp/xnH2_WN6pE
Log file: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_subscriber.log
[10:53:40.645](0.944s) # initializing database system by copying initdb template
# Running: cp -RPp /home/vagrant/postgresql/tmp_install/initdb-template /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata
# Running: /home/vagrant/postgresql/src/test/recovery_1/../../../src/test/regress/pg_regress --config-auth /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata
### Enabling WAL archiving for node "primary"
Name: primary
Version: 17devel
Data directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata
Backup directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/backup
Archive directory: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/archives
Connection string: port=60408 host=/tmp/xnH2_WN6pE
Log file: /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_primary.log
### Starting node "primary"
# Running: pg_ctl -w -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_primary.log -o --cluster-name=primary start
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 783317
[10:54:38.620](57.975s) ok 1 - Physical slot reports conflict_reason as NULL
# Taking pg_basebackup b1 from node "primary"
# Running: pg_basebackup -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/backup/b1 -h /tmp/xnH2_WN6pE -p 60408 --checkpoint fast --no-sync
# 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 -w -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_standby.log -o --cluster-name=standby start
waiting for server to start....... done
server started
# Postmaster PID for node "standby" is 785095
Waiting for replication conn standby's replay_lsn to pass 0/3019998 on primary
done
[10:57:23.460](164.840s) # initializing database system by copying initdb template
# Running: cp -RPp /home/vagrant/postgresql/tmp_install/initdb-template /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_subscriber_data/pgdata
# Running: /home/vagrant/postgresql/src/test/recovery_1/../../../src/test/regress/pg_regress --config-auth /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_subscriber_data/pgdata
### Starting node "subscriber"
# Running: pg_ctl -w -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_subscriber_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_subscriber.log -o --cluster-name=subscriber start
waiting for server to start..... done
server started
# Postmaster PID for node "subscriber" is 786088
[10:58:12.477](49.017s) ok 2 - behaves_ok_inactiveslot on standby created
[10:58:14.029](1.552s) ok 3 - behaves_ok_activeslot on standby created
Waiting for replication conn standby's replay_lsn to pass 0/3025970 on primary
done
[10:58:15.476](1.447s) ok 4 - Decoding produced 14 rows (2 BEGIN/COMMIT and 10 rows)
Waiting for replication conn standby's replay_lsn to pass 0/3025AA0 on primary
done
[10:58:16.151](0.675s) ok 5 - got expected output from SQL decoding session
Waiting for replication conn standby's replay_lsn to pass 0/3026668 on primary
done
[10:58:17.129](0.978s) ok 6 - got same expected output from pg_recvlogical decoding session
[10:58:18.103](0.974s) ok 7 - pg_recvlogical acknowledged changes
Waiting for replication conn standby's replay_lsn to pass 0/3458670 on primary
done
[10:58:45.890](27.786s) ok 8 - replaying logical slot from another database fails
Waiting for replication conn standby's replay_lsn to pass 0/347F860 on primary
done
Waiting for all subscriptions in "subscriber" to synchronize data
Waiting for replication conn tap_sub's replay_lsn to pass 0/347F8D0 on standby
done
done
Waiting for replication conn standby's replay_lsn to pass 0/347FE60 on primary
done
Waiting for replication conn tap_sub's replay_lsn to pass 0/347FE60 on standby
done
[10:59:08.264](22.375s) ok 9 - 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 -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_subscriber_data/pgdata -m fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "subscriber"


[10:59:16.185](7.921s) ok 10 - vacuum_full_inactiveslot on standby created
[10:59:18.990](2.804s) ok 11 - vacuum_full_activeslot on standby created
### Reloading node "standby"
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/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, 420 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.13 s.
#### End standard error
Waiting for replication conn standby's replay_lsn to pass 0/34B1068 on primary
done
[10:59:31.223](12.234s) ok 12 - inactiveslot slot invalidation is logged with vacuum FULL on pg_class
[10:59:31.224](0.001s) ok 13 - activeslot slot invalidation is logged with vacuum FULL on pg_class
[10:59:32.979](1.755s) ok 14 - confl_active_logicalslot updated
[10:59:33.292](0.313s) ok 15 - vacuum_full_activeslot conflict_reason is rows_removed
[10:59:33.399](0.106s) ok 16 - vacuum_full_inactiveslot conflict_reason is rows_removed
[10:59:34.122](0.723s) ok 17 - pg_recvlogical exited non-zero
[10:59:34.122](0.000s) ok 18 - slot has been invalidated
### Reloading node "standby"
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata reload
server signaled
### Restarting node "standby"
# Running: pg_ctl -w -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_1/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 789077
[10:59:58.460](24.338s) ok 19 - vacuum_full_activeslot conflict_reason is rows_removed
[10:59:58.712](0.252s) ok 20 - vacuum_full_inactiveslot conflict_reason is rows_removed
Waiting for replication conn standby's replay_lsn to pass 0/40000F8 on primary
done


[11:00:07.955](9.243s) ok 21 - row_removal_inactiveslot on standby created
[11:00:11.313](3.358s) ok 22 - row_removal_activeslot on standby created
### Reloading node "standby"
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/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)
tuples: 4 removed, 419 remain, 0 are dead but not yet removable
removable cutoff: 754, which was 0 XIDs old when operation ended
frozen: 0 pages from table (0.00% of total) had 0 tuples frozen
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: 0.306 MB/s, avg write rate: 0.656 MB/s
buffer usage: 78 hits, 7 misses, 15 dirtied
WAL usage: 28 records, 15 full page images, 122841 bytes
system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.17 s
#### End standard error
Waiting for replication conn standby's replay_lsn to pass 0/403E6C0 on primary
done
[11:00:17.517](6.204s) ok 23 - inactiveslot slot invalidation is logged with vacuum on pg_class
[11:00:17.517](0.000s) ok 24 - activeslot slot invalidation is logged with vacuum on pg_class
[11:00:18.336](0.819s) ok 25 - confl_active_logicalslot updated
[11:00:18.951](0.615s) ok 26 - row_removal_activeslot conflict_reason is rows_removed
[11:00:29.112](10.161s) ok 27 - row_removal_inactiveslot conflict_reason is rows_removed
[11:00:30.143](1.031s) ok 28 - pg_recvlogical exited non-zero
[11:00:30.144](0.001s) ok 29 - slot has been invalidated


[11:00:37.882](7.738s) ok 30 - shared_row_removal_inactiveslot on standby created
[11:00:41.710](3.828s) ok 31 - shared_row_removal_activeslot on standby created
### Reloading node "standby"
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/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_authid"
psql:<stdin>:1: INFO:  finished vacuuming "testdb.pg_catalog.pg_authid": index scans: 1
pages: 0 removed, 1 remain, 1 scanned (100.00% of total)
tuples: 1 removed, 15 remain, 0 are dead but not yet removable
removable cutoff: 758, which was 0 XIDs old when operation ended
new relfrozenxid: 758, which is 30 XIDs ahead of previous value
frozen: 0 pages from table (0.00% of total) had 0 tuples frozen
index scan needed: 1 pages from table (100.00% of total) had 1 dead item identifiers removed
index "pg_authid_rolname_index": pages: 2 in total, 0 newly deleted, 0 currently deleted, 0 reusable
index "pg_authid_oid_index": pages: 2 in total, 0 newly deleted, 0 currently deleted, 0 reusable
avg read rate: 79.618 MB/s, avg write rate: 19.904 MB/s
buffer usage: 29 hits, 8 misses, 2 dirtied
WAL usage: 6 records, 1 full page images, 8692 bytes
system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
psql:<stdin>:1: INFO:  vacuuming "testdb.pg_toast.pg_toast_1260"
psql:<stdin>:1: INFO:  finished vacuuming "testdb.pg_toast.pg_toast_1260": index scans: 0
pages: 0 removed, 0 remain, 0 scanned (100.00% of total)
tuples: 0 removed, 0 remain, 0 are dead but not yet removable
removable cutoff: 758, which was 0 XIDs old when operation ended
new relfrozenxid: 758, which is 30 XIDs ahead of previous value
frozen: 0 pages from table (100.00% of total) had 0 tuples frozen
index scan not needed: 0 pages from table (100.00% of total) had 0 dead item identifiers removed
avg read rate: 41.778 MB/s, avg write rate: 41.778 MB/s
buffer usage: 24 hits, 1 misses, 1 dirtied
WAL usage: 1 records, 0 full page images, 188 bytes
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/4041A20 on primary
done
[11:00:47.941](6.232s) ok 32 - inactiveslot slot invalidation is logged with vacuum on pg_authid
[11:00:47.942](0.000s) ok 33 - activeslot slot invalidation is logged with vacuum on pg_authid
[11:00:49.083](1.142s) ok 34 - confl_active_logicalslot updated
[11:00:49.447](0.364s) ok 35 - shared_row_removal_activeslot conflict_reason is rows_removed
[11:00:49.695](0.248s) ok 36 - shared_row_removal_inactiveslot conflict_reason is rows_removed
[11:00:51.197](1.501s) ok 37 - pg_recvlogical exited non-zero
[11:00:51.197](0.001s) ok 38 - slot has been invalidated


[11:00:54.267](3.070s) ok 39 - no_conflict_inactiveslot on standby created
[11:00:56.851](2.584s) ok 40 - no_conflict_activeslot on standby created
### Reloading node "standby"
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata reload
server signaled

#### Begin standard error
psql:<stdin>:1: INFO:  vacuuming "testdb.public.conflict_test"
psql:<stdin>:1: INFO:  finished vacuuming "testdb.public.conflict_test": index scans: 0
pages: 0 removed, 1 remain, 1 scanned (100.00% of total)
tuples: 4 removed, 4 remain, 0 are dead but not yet removable
removable cutoff: 763, which was 0 XIDs old when operation ended
new relfrozenxid: 761, which is 2 XIDs ahead of previous value
frozen: 0 pages from table (0.00% of total) had 0 tuples frozen
index scan not needed: 0 pages from table (0.00% of total) had 0 dead item identifiers removed
avg read rate: 0.026 MB/s, avg write rate: 0.035 MB/s
buffer usage: 19 hits, 3 misses, 4 dirtied
WAL usage: 6 records, 4 full page images, 33238 bytes
system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.88 s
psql:<stdin>:1: INFO:  vacuuming "testdb.pg_toast.pg_toast_16418"
psql:<stdin>:1: INFO:  finished vacuuming "testdb.pg_toast.pg_toast_16418": index scans: 0
pages: 0 removed, 0 remain, 0 scanned (100.00% of total)
tuples: 0 removed, 0 remain, 0 are dead but not yet removable
removable cutoff: 763, which was 0 XIDs old when operation ended
new relfrozenxid: 763, which is 4 XIDs ahead of previous value
frozen: 0 pages from table (100.00% of total) had 0 tuples frozen
index scan not needed: 0 pages from table (100.00% of total) had 0 dead item identifiers removed
avg read rate: 0.038 MB/s, avg write rate: 0.000 MB/s
buffer usage: 24 hits, 1 misses, 0 dirtied
WAL usage: 1 records, 0 full page images, 188 bytes
system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.20 s
#### End standard error
Waiting for replication conn standby's replay_lsn to pass 0/404DC20 on primary
done
[11:01:04.923](8.072s) ok 41 - inactiveslot slot invalidation is not logged with vacuum on conflict_test
[11:01:04.923](0.000s) ok 42 - activeslot slot invalidation is not logged with vacuum on conflict_test
[11:01:05.739](0.816s) ok 43 - confl_active_logicalslot not updated
[11:01:06.054](0.315s) ok 44 - Logical slots are reported as non conflicting
### Reloading node "standby"
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata reload
server signaled
### Restarting node "standby"
# Running: pg_ctl -w -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_1/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 792441


[11:01:22.361](16.306s) ok 45 - pruning_inactiveslot on standby created
[11:01:24.541](2.181s) ok 46 - pruning_activeslot on standby created
### Reloading node "standby"
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata reload
server signaled

Waiting for replication conn standby's replay_lsn to pass 0/405A1B0 on primary
done
[11:01:44.739](20.198s) ok 47 - inactiveslot slot invalidation is logged with on-access pruning
[11:01:44.740](0.000s) ok 48 - activeslot slot invalidation is logged with on-access pruning
[11:01:45.155](0.416s) ok 49 - confl_active_logicalslot updated
[11:01:45.983](0.828s) ok 50 - pruning_activeslot conflict_reason is rows_removed
[11:01:46.400](0.417s) ok 51 - pruning_inactiveslot conflict_reason is rows_removed
[11:01:46.554](0.154s) ok 52 - pg_recvlogical exited non-zero
[11:01:46.554](0.000s) ok 53 - slot has been invalidated
### Reloading node "standby"
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata reload
server signaled


[11:01:53.860](7.306s) ok 54 - wal_level_inactiveslot on standby created
[11:01:55.976](2.117s) ok 55 - wal_level_activeslot on standby created

### Restarting node "primary"
# Running: pg_ctl -w -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_primary.log restart
waiting for server to shut down....... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 794314
Waiting for replication conn standby's replay_lsn to pass 0/50000D8 on primary
done
[11:02:04.952](8.975s) ok 56 - inactiveslot slot invalidation is logged due to wal_level
[11:02:04.952](0.000s) ok 57 - activeslot slot invalidation is logged due to wal_level
[11:02:05.580](0.628s) ok 58 - confl_active_logicalslot updated
[11:02:06.186](0.606s) ok 59 - wal_level_activeslot conflict_reason is wal_level_insufficient
[11:02:06.588](0.403s) ok 60 - wal_level_inactiveslot conflict_reason is wal_level_insufficient
[11:02:07.073](0.485s) ok 61 - pg_recvlogical exited non-zero
[11:02:07.132](0.059s) ok 62 - slot has been invalidated
### Restarting node "primary"
# Running: pg_ctl -w -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_primary.log restart
waiting for server to shut down.................... done
server stopped
waiting for server to start....... done
server started
# Postmaster PID for node "primary" is 795613
Waiting for replication conn standby's replay_lsn to pass 0/60000D8 on primary
done
[11:02:35.754](28.622s) ok 63 - pg_recvlogical exited non-zero
[11:02:35.754](0.000s) ok 64 - slot has been invalidated


[11:02:42.781](7.027s) ok 65 - drop_db_inactiveslot on standby created
[11:02:44.028](1.247s) ok 66 - drop_db_activeslot on standby created
[11:02:46.088](2.059s) ok 67 - otherslot on standby created
Waiting for replication conn standby's replay_lsn to pass 0/60007C8 on primary
done
[11:02:58.995](12.908s) ok 68 - database dropped on standby
[11:02:59.284](0.289s) ok 69 - inactiveslot on standby dropped
[11:02:59.393](0.108s) ok 70 - activeslot on standby dropped
[11:02:59.393](0.001s) ok 71 - pg_recvlogical exited non-zero
[11:02:59.393](0.000s) ok 72 - slot has been invalidated
[11:02:59.595](0.201s) ok 73 - otherslot on standby not dropped

### Reloading node "standby"
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata reload
server signaled
Waiting for replication conn standby's replay_lsn to pass 0/6437010 on primary
done
# Taking pg_basebackup b1 from node "standby"
# Running: pg_basebackup -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/backup/b1 -h /tmp/xnH2_WN6pE -p 60409 --checkpoint fast --no-sync
# Backup finished
# Initializing node "cascading_standby" from backup "b1" of node "standby"
### Enabling streaming replication for node "cascading_standby"
### Enabling WAL restore for node "cascading_standby"
### Starting node "cascading_standby"
# Running: pg_ctl -w -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_cascading_standby_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_cascading_standby.log -o --cluster-name=cascading_standby start
waiting for server to start....... done
server started
# Postmaster PID for node "cascading_standby" is 799052
[11:06:07.782](188.188s) ok 74 - promotion_inactiveslot on standby created
[11:06:08.466](0.684s) ok 75 - promotion_activeslot on standby created
Waiting for replication conn cascading_standby's replay_lsn to pass 0/64370B8 on standby
done
[11:06:10.252](1.786s) ok 76 - promotion_inactiveslot on standby created
[11:06:11.488](1.236s) ok 77 - promotion_activeslot on standby created
Waiting for replication conn standby's replay_lsn to pass 0/6437290 on primary
done
Waiting for replication conn cascading_standby's replay_lsn to pass 0/6437290 on standby
done
### Promoting node "standby"
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_1/tmp_check/log/035_standby_logical_decoding_standby.log promote
waiting for server to promote..... done
server promoted
Waiting for replication conn cascading_standby's replay_lsn to pass 0/6439A90 on standby
done
[11:06:22.453](10.964s) ok 78 - got expected output from SQL decoding session on promoted standby
[11:06:22.453](0.000s) ok 79 - got 2 COMMIT from pg_recvlogical output
[11:06:22.453](0.000s) ok 80 - got same expected output from pg_recvlogical decoding session
[11:06:22.646](0.192s) ok 81 - got expected output from SQL decoding session on cascading standby
[11:06:22.646](0.000s) ok 82 - got 2 COMMIT from pg_recvlogical output
[11:06:22.646](0.000s) ok 83 - got same expected output from pg_recvlogical decoding session on cascading standby
[11:06:22.647](0.001s) 1..83
### Stopping node "primary" using mode immediate
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_primary_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "primary"
### Stopping node "standby" using mode immediate
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_standby_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "standby"
### Stopping node "cascading_standby" using mode immediate
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_1/tmp_check/t_035_standby_logical_decoding_cascading_standby_data/pgdata -m immediate stop
waiting for server to shut down........ done
server stopped
# No postmaster PID for node "cascading_standby"
