# Checking port 13118
# Found port 13118
Name: primary
Version: 19devel
Data directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_primary_data/pgdata
Backup directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_primary_data/backup
Archive directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_primary_data/archives
Connection string: port=13118 host=/tmp/xNmpuMxaO5
Log file: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_primary.log
[15:00:21.247](0.022s) # initializing database system by copying initdb template
# Running: cp -RPp /tmp/cirrus-ci-build/tmp_install/initdb-template /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_primary_data/pgdata
# Running: /tmp/cirrus-ci-build/src/test/recovery/../../../src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_primary_data/pgdata
### Starting node "primary"
# Running: pg_ctl --wait --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_primary_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_primary.log --options --cluster-name=primary start
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 74451
# Taking pg_basebackup my_backup from node "primary"
# Running: pg_basebackup --no-sync --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_primary_data/backup/my_backup --host /tmp/xNmpuMxaO5 --port 13118 --checkpoint fast
# Backup finished
# Checking port 13119
# Found port 13119
Name: standby
Version: 19devel
Data directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_standby_data/pgdata
Backup directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_standby_data/backup
Archive directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_standby_data/archives
Connection string: port=13119 host=/tmp/xNmpuMxaO5
Log file: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_standby.log
# Initializing node "standby" from backup "my_backup" of node "primary"
### Enabling streaming replication for node "standby"
### Starting node "standby"
# Running: pg_ctl --wait --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_standby_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_standby.log --options --cluster-name=standby start
waiting for server to start.... done
server started
# Postmaster PID for node "standby" is 74477
[15:00:22.929](1.682s) ok 1 - standby reached the same LSN as primary after WAIT FOR
[15:00:23.957](1.028s) ok 2 - standby reached the same LSN as primary
[15:00:24.030](0.073s) ok 3 - standby wrote WAL up to target LSN after WAIT FOR with MODE 'standby_write'
[15:00:24.105](0.075s) ok 4 - standby flushed WAL up to target LSN after WAIT FOR with MODE 'standby_flush'
[15:00:24.184](0.079s) ok 5 - primary flushed WAL up to target LSN after WAIT FOR with MODE 'primary_flush'
[15:00:25.256](1.072s) ok 6 - get timeout on waiting for unreachable LSN
[15:00:25.280](0.024s) ok 7 - WAIT FOR returns correct status after successful waiting
[15:00:25.313](0.033s) ok 8 - WAIT FOR returns correct status after timeout
[15:00:25.360](0.047s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:25.422](0.062s) ok 9 - canceled WAIT FOR LSN in subtransaction
[15:00:25.432](0.010s) ok 10 - query cancel interrupted WAIT FOR LSN in subtransaction
[15:00:25.432](0.000s) ok 11 - second WAIT FOR LSN timed out after savepoint rollback
[15:00:25.432](0.000s) ok 12 - WAIT FOR LSN after savepoint rollback did not disconnect
[15:00:25.456](0.023s) ok 13 - get an error when running standby_flush on the primary
[15:00:25.481](0.025s) ok 14 - get an error when running primary_flush on the standby
1
[15:00:25.506](0.024s) ok 15 - get an error when running in a transaction with an isolation level higher than REPEATABLE READ
Waiting for replication conn standby's replay_lsn to pass 0/030133E0 on primary
done
[15:00:26.560](1.055s) ok 16 - get an error when running within a function
[15:00:26.585](0.025s) ok 17 - get an error when running within a procedure
[15:00:26.609](0.024s) ok 18 - get an error when running within a DO block
[15:00:26.655](0.046s) ok 19 - get error for negative timeout
[15:00:26.678](0.023s) ok 20 - get error for unknown parameter
[15:00:26.700](0.022s) ok 21 - get error for duplicate TIMEOUT parameter
[15:00:26.723](0.023s) ok 22 - get error for duplicate NO_THROW parameter
[15:00:26.746](0.023s) ok 23 - get syntax error when options specified without WITH keyword
[15:00:26.768](0.022s) ok 24 - get syntax error for missing LSN
[15:00:26.790](0.022s) ok 25 - get error for invalid LSN format
[15:00:26.813](0.022s) ok 26 - get error for invalid timeout format
[15:00:26.836](0.023s) ok 27 - WAIT FOR WITH clause syntax works correctly
[15:00:26.960](0.123s) ok 28 - WAIT FOR WITH clause returns correct timeout status
[15:00:26.983](0.023s) ok 29 - get error for invalid WITH clause option
[15:00:27.005](0.022s) ok 30 - get error for invalid MODE value
[15:00:27.027](0.023s) ok 31 - get error for duplicate MODE parameter
[15:00:27.146](0.119s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:27.214](0.067s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:27.283](0.070s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:27.351](0.068s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:27.419](0.068s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:28.462](1.043s) ok 32 - multiple standby_replay waiters reported consistent data
[15:00:28.783](0.321s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:28.803](0.020s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:28.823](0.020s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:28.842](0.019s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:28.862](0.019s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:28.993](0.131s) ok 33 - multiple standby_write waiters: standby wrote WAL up to target LSN
[15:00:30.061](1.068s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:30.082](0.021s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:30.103](0.021s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:30.124](0.021s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:30.144](0.020s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:30.273](0.130s) ok 34 - multiple standby_flush waiters: standby flushed WAL up to target LSN
[15:00:31.183](0.910s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:31.203](0.020s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:31.224](0.021s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:31.244](0.020s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:31.266](0.021s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:31.286](0.020s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:32.266](0.980s) ok 35 - mixed mode waiters: all modes completed and reached target LSN
[15:00:32.522](0.256s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:32.542](0.020s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:32.561](0.019s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:32.580](0.019s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:32.600](0.020s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:32.639](0.039s) ok 36 - multiple primary_flush waiters: primary flushed WAL up to target LSN
[15:00:32.705](0.066s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:32.724](0.019s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:32.744](0.020s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
Waiting for replication conn standby's replay_lsn to pass 0/04000000 on primary
done
### Promoting node "standby"
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_standby_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_standby.log promote
waiting for server to promote.... done
server promoted
[15:00:33.590](0.846s) ok 37 - promotion interrupted all wait modes
[15:00:33.613](0.023s) ok 38 - wait for already replayed LSN exits immediately even after promotion
[15:00:33.636](0.023s) ok 39 - WAIT FOR returns correct status after standby promotion
### Stopping node "standby" using mode fast
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_standby_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "standby"
### Stopping node "primary" using mode fast
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_primary_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "primary"
# Checking port 13120
# Found port 13120
Name: arc_primary
Version: 19devel
Data directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_primary_data/pgdata
Backup directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_primary_data/backup
Archive directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_primary_data/archives
Connection string: port=13120 host=/tmp/xNmpuMxaO5
Log file: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_arc_primary.log
[15:00:33.863](0.227s) # initializing database system by copying initdb template
# Running: cp -RPp /tmp/cirrus-ci-build/tmp_install/initdb-template /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_primary_data/pgdata
# Running: /tmp/cirrus-ci-build/src/test/recovery/../../../src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_primary_data/pgdata
### Enabling WAL archiving for node "arc_primary"
### Starting node "arc_primary"
# Running: pg_ctl --wait --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_primary_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_arc_primary.log --options --cluster-name=arc_primary start
waiting for server to start.... done
server started
# Postmaster PID for node "arc_primary" is 75029
# Taking pg_basebackup arc_backup from node "arc_primary"
# Running: pg_basebackup --no-sync --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_primary_data/backup/arc_backup --host /tmp/xNmpuMxaO5 --port 13120 --checkpoint fast
# Backup finished
# Checking port 13121
# Found port 13121
Name: arc_standby
Version: 19devel
Data directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_standby_data/pgdata
Backup directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_standby_data/backup
Archive directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_standby_data/archives
Connection string: port=13121 host=/tmp/xNmpuMxaO5
Log file: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_arc_standby.log
# Initializing node "arc_standby" from backup "arc_backup" of node "arc_primary"
### Enabling WAL restore for node "arc_standby"
### Starting node "arc_standby"
# Running: pg_ctl --wait --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_standby_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_arc_standby.log --options --cluster-name=arc_standby start
waiting for server to start.... done
server started
# Postmaster PID for node "arc_standby" is 75076
[15:00:34.739](0.875s) ok 40 - arc_standby has no walreceiver
[15:00:34.763](0.024s) ok 41 - standby_write succeeds on archive-only standby (getter fallback)
[15:00:34.786](0.023s) ok 42 - standby_flush succeeds on archive-only standby (getter fallback)
[15:00:34.967](0.181s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:34.988](0.020s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:35.327](0.340s) ok 43 - standby_write waiter woken by replay on archive-only standby
[15:00:35.327](0.000s) ok 44 - standby_flush waiter woken by replay on archive-only standby
### Stopping node "arc_standby" using mode fast
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_standby_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "arc_standby"
### Stopping node "arc_primary" using mode fast
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_arc_primary_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "arc_primary"
# Checking port 13122
# Found port 13122
Name: rcv_primary
Version: 19devel
Data directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_primary_data/pgdata
Backup directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_primary_data/backup
Archive directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_primary_data/archives
Connection string: port=13122 host=/tmp/xNmpuMxaO5
Log file: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_rcv_primary.log
[15:00:35.555](0.228s) # initializing database system by copying initdb template
# Running: cp -RPp /tmp/cirrus-ci-build/tmp_install/initdb-template /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_primary_data/pgdata
# Running: /tmp/cirrus-ci-build/src/test/recovery/../../../src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_primary_data/pgdata
### Starting node "rcv_primary"
# Running: pg_ctl --wait --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_primary_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_rcv_primary.log --options --cluster-name=rcv_primary start
waiting for server to start.... done
server started
# Postmaster PID for node "rcv_primary" is 75165
# Taking pg_basebackup rcv_backup from node "rcv_primary"
# Running: pg_basebackup --no-sync --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_primary_data/backup/rcv_backup --host /tmp/xNmpuMxaO5 --port 13122 --checkpoint fast
# Backup finished
# Checking port 13123
# Found port 13123
Name: rcv_standby
Version: 19devel
Data directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_standby_data/pgdata
Backup directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_standby_data/backup
Archive directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_standby_data/archives
Connection string: port=13123 host=/tmp/xNmpuMxaO5
Log file: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_rcv_standby.log
# Initializing node "rcv_standby" from backup "rcv_backup" of node "rcv_primary"
### Enabling streaming replication for node "rcv_standby"
### Starting node "rcv_standby"
# Running: pg_ctl --wait --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_standby_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_rcv_standby.log --options --cluster-name=rcv_standby start
waiting for server to start.... done
server started
# Postmaster PID for node "rcv_standby" is 75189
Waiting for replication conn rcv_standby's replay_lsn to pass 0/040002D0 on rcv_primary
done
### Stopping node "rcv_standby" using mode fast
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_standby_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "rcv_standby"
### Stopping node "rcv_primary" using mode fast
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_primary_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "rcv_primary"
### Starting node "rcv_standby"
# Running: pg_ctl --wait --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_standby_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_rcv_standby.log --options --cluster-name=rcv_standby start
waiting for server to start.... done
server started
# Postmaster PID for node "rcv_standby" is 75222
[15:00:36.927](1.372s) ok 45 - replay sits ahead of initial walreceiver flush position
[15:00:36.957](0.030s) ok 46 - initial walreceiver flush position is segment-aligned
[15:00:36.981](0.024s) ok 47 - standby_write succeeds for already-replayed LSN after standby restart
[15:00:37.005](0.024s) ok 48 - standby_flush succeeds for already-replayed LSN after standby restart
### Starting node "rcv_primary"
# Running: pg_ctl --wait --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_primary_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_rcv_primary.log --options --cluster-name=rcv_primary start
waiting for server to start.... done
server started
# Postmaster PID for node "rcv_primary" is 75261
Waiting for replication conn rcv_standby's replay_lsn to pass 0/04002E58 on rcv_primary
done
[15:00:37.571](0.566s) ok 49 - standby_replay: target == current succeeds
[15:00:37.595](0.025s) ok 50 - standby_replay: target == current - 1 succeeds
[15:00:38.120](0.525s) ok 51 - standby_replay: target == current + 1 times out
[15:00:38.172](0.052s) ok 52 - standby_flush boundary is not masked by replay floor
[15:00:38.248](0.076s) ok 53 - standby_flush: target == current succeeds
[15:00:38.272](0.024s) ok 54 - standby_flush: target == current - 1 succeeds
[15:00:38.797](0.525s) ok 55 - standby_flush: target == current + 1 times out
[15:00:38.842](0.045s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:38.950](0.109s) ok 56 - standby_replay: waiter at current + 1 wakes when replay advances
### Stopping node "rcv_standby" using mode fast
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_standby_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "rcv_standby"
### Stopping node "rcv_primary" using mode fast
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_rcv_primary_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "rcv_primary"
# Checking port 13124
# Found port 13124
Name: tl_primary
Version: 19devel
Data directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_primary_data/pgdata
Backup directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_primary_data/backup
Archive directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_primary_data/archives
Connection string: port=13124 host=/tmp/xNmpuMxaO5
Log file: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_tl_primary.log
[15:00:39.176](0.226s) # initializing database system by copying initdb template
# Running: cp -RPp /tmp/cirrus-ci-build/tmp_install/initdb-template /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_primary_data/pgdata
# Running: /tmp/cirrus-ci-build/src/test/recovery/../../../src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_primary_data/pgdata
### Starting node "tl_primary"
# Running: pg_ctl --wait --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_primary_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_tl_primary.log --options --cluster-name=tl_primary start
waiting for server to start.... done
server started
# Postmaster PID for node "tl_primary" is 75370
# Taking pg_basebackup tl_backup from node "tl_primary"
# Running: pg_basebackup --no-sync --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_primary_data/backup/tl_backup --host /tmp/xNmpuMxaO5 --port 13124 --checkpoint fast
# Backup finished
# Checking port 13125
# Found port 13125
Name: tl_standby1
Version: 19devel
Data directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby1_data/pgdata
Backup directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby1_data/backup
Archive directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby1_data/archives
Connection string: port=13125 host=/tmp/xNmpuMxaO5
Log file: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_tl_standby1.log
# Initializing node "tl_standby1" from backup "tl_backup" of node "tl_primary"
### Enabling streaming replication for node "tl_standby1"
### Starting node "tl_standby1"
# Running: pg_ctl --wait --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby1_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_tl_standby1.log --options --cluster-name=tl_standby1 start
waiting for server to start.... done
server started
# Postmaster PID for node "tl_standby1" is 75396
# Taking pg_basebackup tl_backup2 from node "tl_standby1"
# Running: pg_basebackup --no-sync --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby1_data/backup/tl_backup2 --host /tmp/xNmpuMxaO5 --port 13125 --checkpoint fast
# Backup finished
# Checking port 13126
# Found port 13126
Name: tl_standby2
Version: 19devel
Data directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby2_data/pgdata
Backup directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby2_data/backup
Archive directory: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby2_data/archives
Connection string: port=13126 host=/tmp/xNmpuMxaO5
Log file: /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_tl_standby2.log
# Initializing node "tl_standby2" from backup "tl_backup2" of node "tl_standby1"
### Enabling streaming replication for node "tl_standby2"
### Starting node "tl_standby2"
# Running: pg_ctl --wait --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby2_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_tl_standby2.log --options --cluster-name=tl_standby2 start
waiting for server to start.... done
server started
# Postmaster PID for node "tl_standby2" is 75418
Waiting for replication conn tl_standby1's replay_lsn to pass 0/03002098 on tl_primary
done
Waiting for replication conn tl_standby2's replay_lsn to pass 0/03002098 on tl_standby1
done
[15:00:40.512](1.336s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
### Promoting node "tl_standby1"
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby1_data/pgdata --log /tmp/cirrus-ci-build/src/test/recovery/tmp_check/log/049_wait_for_lsn_tl_standby1.log promote
waiting for server to promote.... done
server promoted
[15:00:40.764](0.252s) ok 57 - WAIT FOR LSN survives upstream promotion and timeline switch on cascade standby
### Stopping node "tl_standby2" using mode fast
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby2_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "tl_standby2"
### Stopping node "tl_standby1" using mode fast
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_standby1_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "tl_standby1"
### Stopping node "tl_primary" using mode fast
# Running: pg_ctl --pgdata /tmp/cirrus-ci-build/src/test/recovery/tmp_check/t_049_wait_for_lsn_tl_primary_data/pgdata --mode fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "tl_primary"
[15:00:41.092](0.327s) 1..57