# Checking port 24692
# Found port 24692
Name: primary
Version: 19devel
Data directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_primary_data/pgdata
Backup directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_primary_data/backup
Archive directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_primary_data/archives
Connection string: port=24692 host=C:/Windows/TEMP/lJjdcfEAXo
Log file: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\log/049_wait_for_lsn_primary.log
[14:59:31.637](0.223s) # initializing database system by copying initdb template
# Running: robocopy /E /NJS /NJH /NFL /NDL /NP C:/cirrus/build/tmp_install/initdb-template C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_primary_data/pgdata

# Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_primary_data/pgdata
### Starting node "primary"
# Running: pg_ctl --wait --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_primary_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 6412
# Taking pg_basebackup my_backup from node "primary"
# Running: pg_basebackup --no-sync --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_primary_data/backup/my_backup --host C:/Windows/TEMP/lJjdcfEAXo --port 24692 --checkpoint fast
# Backup finished
# Checking port 24693
# Found port 24693
Name: standby
Version: 19devel
Data directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_standby_data/pgdata
Backup directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_standby_data/backup
Archive directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_standby_data/archives
Connection string: port=24693 host=C:/Windows/TEMP/lJjdcfEAXo
Log file: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_standby_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 1304
[14:59:40.080](8.443s) ok 1 - standby reached the same LSN as primary after WAIT FOR
[14:59:41.442](1.361s) ok 2 - standby reached the same LSN as primary
[14:59:41.974](0.532s) ok 3 - standby wrote WAL up to target LSN after WAIT FOR with MODE 'standby_write'
[14:59:42.681](0.707s) ok 4 - standby flushed WAL up to target LSN after WAIT FOR with MODE 'standby_flush'
[14:59:43.337](0.656s) ok 5 - primary flushed WAL up to target LSN after WAIT FOR with MODE 'primary_flush'
[14:59:45.791](2.455s) ok 6 - get timeout on waiting for unreachable LSN
[14:59:46.047](0.255s) ok 7 - WAIT FOR returns correct status after successful waiting
[14:59:46.244](0.197s) ok 8 - WAIT FOR returns correct status after timeout
[14:59:46.591](0.347s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[14:59:47.122](0.532s) ok 9 - canceled WAIT FOR LSN in subtransaction
[14:59:47.291](0.168s) ok 10 - query cancel interrupted WAIT FOR LSN in subtransaction
[14:59:47.292](0.001s) ok 11 - second WAIT FOR LSN timed out after savepoint rollback
[14:59:47.295](0.002s) ok 12 - WAIT FOR LSN after savepoint rollback did not disconnect
[14:59:47.494](0.199s) ok 13 - get an error when running standby_flush on the primary
[14:59:47.701](0.207s) ok 14 - get an error when running primary_flush on the standby
1
[14:59:48.148](0.448s) 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/0300F888 on primary
done
[14:59:49.835](1.686s) ok 16 - get an error when running within a function
[14:59:49.996](0.161s) ok 17 - get an error when running within a procedure
[14:59:50.371](0.375s) ok 18 - get an error when running within a DO block
[14:59:50.802](0.431s) ok 19 - get error for negative timeout
[14:59:51.024](0.222s) ok 20 - get error for unknown parameter
[14:59:51.168](0.144s) ok 21 - get error for duplicate TIMEOUT parameter
[14:59:51.917](0.749s) ok 22 - get error for duplicate NO_THROW parameter
[14:59:52.362](0.444s) ok 23 - get syntax error when options specified without WITH keyword
[14:59:52.499](0.138s) ok 24 - get syntax error for missing LSN
[14:59:52.728](0.229s) ok 25 - get error for invalid LSN format
[14:59:52.880](0.151s) ok 26 - get error for invalid timeout format
[14:59:53.047](0.168s) ok 27 - WAIT FOR WITH clause syntax works correctly
[14:59:53.450](0.403s) ok 28 - WAIT FOR WITH clause returns correct timeout status
[14:59:53.658](0.207s) ok 29 - get error for invalid WITH clause option
[14:59:53.901](0.243s) ok 30 - get error for invalid MODE value
[14:59:54.026](0.125s) ok 31 - get error for duplicate MODE parameter
[14:59:58.137](4.111s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[14:59:59.499](1.362s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:00.899](1.400s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:01.651](0.751s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:02.340](0.689s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:02.838](0.498s) ok 32 - multiple standby_replay waiters reported consistent data
[15:00:05.625](2.787s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:05.819](0.194s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:06.093](0.274s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:06.312](0.220s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:06.574](0.262s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:08.033](1.459s) ok 33 - multiple standby_write waiters: standby wrote WAL up to target LSN
[15:00:10.523](2.490s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:10.870](0.347s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:11.351](0.481s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:12.951](1.600s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:14.265](1.313s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:16.483](2.219s) ok 34 - multiple standby_flush waiters: standby flushed WAL up to target LSN
[15:00:19.016](2.533s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:19.442](0.426s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:19.883](0.441s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:20.238](0.355s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:20.576](0.338s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:21.138](0.562s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:22.969](1.831s) ok 35 - mixed mode waiters: all modes completed and reached target LSN
[15:00:25.333](2.364s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:25.769](0.436s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:26.100](0.332s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:26.446](0.346s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:26.806](0.360s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:27.510](0.704s) ok 36 - multiple primary_flush waiters: primary flushed WAL up to target LSN
[15:00:32.504](4.994s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:34.024](1.521s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:34.856](0.832s) # 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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_standby_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\log/049_wait_for_lsn_standby.log promote
waiting for server to promote.... done
server promoted
[15:00:38.435](3.579s) ok 37 - promotion interrupted all wait modes
[15:00:38.630](0.194s) ok 38 - wait for already replayed LSN exits immediately even after promotion
[15:00:38.779](0.150s) ok 39 - WAIT FOR returns correct status after standby promotion
### Stopping node "standby" using mode fast
# Running: pg_ctl --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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 24694
# Found port 24694
Name: arc_primary
Version: 19devel
Data directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_arc_primary_data/pgdata
Backup directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_arc_primary_data/backup
Archive directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_arc_primary_data/archives
Connection string: port=24694 host=C:/Windows/TEMP/lJjdcfEAXo
Log file: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\log/049_wait_for_lsn_arc_primary.log
[15:00:39.422](0.642s) # initializing database system by copying initdb template
# Running: robocopy /E /NJS /NJH /NFL /NDL /NP C:/cirrus/build/tmp_install/initdb-template C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_arc_primary_data/pgdata

# Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_arc_primary_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 940
# Taking pg_basebackup arc_backup from node "arc_primary"
# Running: pg_basebackup --no-sync --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_arc_primary_data/backup/arc_backup --host C:/Windows/TEMP/lJjdcfEAXo --port 24694 --checkpoint fast
# Backup finished
# Checking port 24695
# Found port 24695
Name: arc_standby
Version: 19devel
Data directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_arc_standby_data/pgdata
Backup directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_arc_standby_data/backup
Archive directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_arc_standby_data/archives
Connection string: port=24695 host=C:/Windows/TEMP/lJjdcfEAXo
Log file: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_arc_standby_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 5160
[15:00:56.244](16.822s) ok 40 - arc_standby has no walreceiver
[15:00:56.460](0.216s) ok 41 - standby_write succeeds on archive-only standby (getter fallback)
[15:00:56.659](0.200s) ok 42 - standby_flush succeeds on archive-only standby (getter fallback)
[15:00:58.752](2.093s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:00:59.178](0.426s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:01:00.334](1.157s) ok 43 - standby_write waiter woken by replay on archive-only standby
[15:01:00.336](0.002s) ok 44 - standby_flush waiter woken by replay on archive-only standby
### Stopping node "arc_standby" using mode fast
# Running: pg_ctl --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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 24696
# Found port 24696
Name: rcv_primary
Version: 19devel
Data directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_primary_data/pgdata
Backup directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_primary_data/backup
Archive directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_primary_data/archives
Connection string: port=24696 host=C:/Windows/TEMP/lJjdcfEAXo
Log file: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\log/049_wait_for_lsn_rcv_primary.log
[15:01:01.418](1.082s) # initializing database system by copying initdb template
# Running: robocopy /E /NJS /NJH /NFL /NDL /NP C:/cirrus/build/tmp_install/initdb-template C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_primary_data/pgdata

# Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_primary_data/pgdata
### Starting node "rcv_primary"
# Running: pg_ctl --wait --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_primary_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 4596
# Taking pg_basebackup rcv_backup from node "rcv_primary"
# Running: pg_basebackup --no-sync --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_primary_data/backup/rcv_backup --host C:/Windows/TEMP/lJjdcfEAXo --port 24696 --checkpoint fast
# Backup finished
# Checking port 24697
# Found port 24697
Name: rcv_standby
Version: 19devel
Data directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_standby_data/pgdata
Backup directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_standby_data/backup
Archive directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_standby_data/archives
Connection string: port=24697 host=C:/Windows/TEMP/lJjdcfEAXo
Log file: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_standby_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 1792
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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_standby_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 6412
[15:01:21.758](20.340s) ok 45 - replay sits ahead of initial walreceiver flush position
[15:01:21.961](0.203s) ok 46 - initial walreceiver flush position is segment-aligned
[15:01:22.146](0.185s) ok 47 - standby_write succeeds for already-replayed LSN after standby restart
[15:01:22.291](0.145s) ok 48 - standby_flush succeeds for already-replayed LSN after standby restart
### Starting node "rcv_primary"
# Running: pg_ctl --wait --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_rcv_primary_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 6676
Waiting for replication conn rcv_standby's replay_lsn to pass 0/04002E90 on rcv_primary
done
[15:01:27.626](5.335s) ok 49 - standby_replay: target == current succeeds
[15:01:27.993](0.366s) ok 50 - standby_replay: target == current - 1 succeeds
[15:01:29.081](1.088s) ok 51 - standby_replay: target == current + 1 times out
[15:01:29.514](0.433s) ok 52 - standby_flush boundary is not masked by replay floor
[15:01:30.129](0.615s) ok 53 - standby_flush: target == current succeeds
[15:01:30.250](0.121s) ok 54 - standby_flush: target == current - 1 succeeds
[15:01:31.193](0.943s) ok 55 - standby_flush: target == current + 1 times out
[15:01:32.273](1.080s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
[15:01:33.270](0.997s) ok 56 - standby_replay: waiter at current + 1 wakes when replay advances
### Stopping node "rcv_standby" using mode fast
# Running: pg_ctl --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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 24698
# Found port 24698
Name: tl_primary
Version: 19devel
Data directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_primary_data/pgdata
Backup directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_primary_data/backup
Archive directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_primary_data/archives
Connection string: port=24698 host=C:/Windows/TEMP/lJjdcfEAXo
Log file: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\log/049_wait_for_lsn_tl_primary.log
[15:01:34.036](0.766s) # initializing database system by copying initdb template
# Running: robocopy /E /NJS /NJH /NFL /NDL /NP C:/cirrus/build/tmp_install/initdb-template C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_primary_data/pgdata

# Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_primary_data/pgdata
### Starting node "tl_primary"
# Running: pg_ctl --wait --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_primary_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 7212
# Taking pg_basebackup tl_backup from node "tl_primary"
# Running: pg_basebackup --no-sync --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_primary_data/backup/tl_backup --host C:/Windows/TEMP/lJjdcfEAXo --port 24698 --checkpoint fast
# Backup finished
# Checking port 24699
# Found port 24699
Name: tl_standby1
Version: 19devel
Data directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_standby1_data/pgdata
Backup directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_standby1_data/backup
Archive directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_standby1_data/archives
Connection string: port=24699 host=C:/Windows/TEMP/lJjdcfEAXo
Log file: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_standby1_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 5464
# Taking pg_basebackup tl_backup2 from node "tl_standby1"
# Running: pg_basebackup --no-sync --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_standby1_data/backup/tl_backup2 --host C:/Windows/TEMP/lJjdcfEAXo --port 24699 --checkpoint fast
# Backup finished
# Checking port 24700
# Found port 24700
Name: tl_standby2
Version: 19devel
Data directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_standby2_data/pgdata
Backup directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_standby2_data/backup
Archive directory: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_standby2_data/archives
Connection string: port=24700 host=C:/Windows/TEMP/lJjdcfEAXo
Log file: C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_standby2_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\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 1656
Waiting for replication conn tl_standby1's replay_lsn to pass 0/030020D0 on tl_primary
done
Waiting for replication conn tl_standby2's replay_lsn to pass 0/030020D0 on tl_standby1
done
[15:02:03.144](29.108s) # connect output:
# {
#   'stderr' => 'background_psql: ready
# ',
#   'stdout' => 'background_psql: ready
# '
# }
### Promoting node "tl_standby1"
# Running: pg_ctl --pgdata C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/t_049_wait_for_lsn_tl_standby1_data/pgdata --log C:\cirrus\build/testrun/recovery/049_wait_for_lsn\log/049_wait_for_lsn_tl_standby1.log promote
waiting for server to promote.... done
server promoted
[15:02:05.318](2.174s) 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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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 C:\cirrus\build/testrun/recovery/049_wait_for_lsn\data/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:02:06.522](1.204s) 1..57