# Checking port 61577
# Found port 61577
Name: london
Data directory: /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata
Backup directory: /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/backup
Archive directory: /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/archives
Connection string: port=61577 host=/tmp/ID9zHHIQxW
Log file: /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/log/009_twophase_london.log
[12:41:47.619](0.014s) # initializing database system by copying initdb template
# Running: cp -RPp /tmp/cirrus-ci-build/build/tmp_install/initdb-template /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata
# Running: /tmp/cirrus-ci-build/build/src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata
### Starting node "london"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/log/009_twophase_london.log -o --cluster-name=london start
pg_ctl: another server might be running; trying to start server anyway
waiting for server to start.... done
server started
# Postmaster PID for node "london" is 23529
# Taking pg_basebackup london_backup from node "london"
# Running: pg_basebackup -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/backup/london_backup -h /tmp/ID9zHHIQxW -p 61577 --checkpoint fast --no-sync
# Backup finished
# Checking port 61578
# Found port 61578
Name: paris
Data directory: /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_paris_data/pgdata
Backup directory: /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_paris_data/backup
Archive directory: /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_paris_data/archives
Connection string: port=61578 host=/tmp/ID9zHHIQxW
Log file: /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/log/009_twophase_paris.log
# Initializing node "paris" from backup "london_backup" of node "london"
### Enabling streaming replication for node "paris"
### Starting node "paris"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_paris_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/log/009_twophase_paris.log -o --cluster-name=paris start
waiting for server to start.... done
server started
# Postmaster PID for node "paris" is 23607
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
[12:41:47.987](0.368s) not ok 1 - reload node london with synchronous_standby_names = 'paris'
[12:41:47.987](0.000s) #   Failed test 'reload node london with synchronous_standby_names = 'paris''
#   at /tmp/cirrus-ci-build/src/test/recovery/t/009_twophase.pl line 55.
[12:41:47.987](0.000s) #          got: ''
#     expected: 't'
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61578" failed: FATAL:  database "postgres" does not exist
[12:41:47.994](0.007s) not ok 2 - reload node paris with synchronous_standby_names = 'london'
[12:41:47.995](0.000s) #   Failed test 'reload node paris with synchronous_standby_names = 'london''
#   at /tmp/cirrus-ci-build/src/test/recovery/t/009_twophase.pl line 56.
[12:41:47.995](0.000s) #          got: ''
#     expected: 't'
[12:41:47.995](0.000s) # Initially, london is primary and paris is standby
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
### Stopping node "london" using mode fast
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -m fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "london"
### Starting node "london"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/log/009_twophase_london.log -o --cluster-name=london start
waiting for server to start.... done
server started
# Postmaster PID for node "london" is 23703
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
[12:41:48.357](0.362s) not ok 3 - Commit prepared transaction after restart
[12:41:48.357](0.000s) #   Failed test 'Commit prepared transaction after restart'
#   at /tmp/cirrus-ci-build/src/test/recovery/t/009_twophase.pl line 89.
[12:41:48.357](0.000s) #          got: '2'
#     expected: '0'
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
[12:41:48.401](0.043s) not ok 4 - Rollback prepared transaction after restart
[12:41:48.401](0.000s) #   Failed test 'Rollback prepared transaction after restart'
#   at /tmp/cirrus-ci-build/src/test/recovery/t/009_twophase.pl line 92.
[12:41:48.401](0.000s) #          got: '2'
#     expected: '0'
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
### Stopping node "london" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "london"
### Starting node "london"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/log/009_twophase_london.log -o --cluster-name=london start
waiting for server to start.... done
server started
# Postmaster PID for node "london" is 23837
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
[12:41:48.701](0.300s) not ok 5 - Commit prepared transaction after teardown
[12:41:48.701](0.000s) #   Failed test 'Commit prepared transaction after teardown'
#   at /tmp/cirrus-ci-build/src/test/recovery/t/009_twophase.pl line 117.
[12:41:48.701](0.000s) #          got: '2'
#     expected: '0'
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
[12:41:48.744](0.043s) not ok 6 - Rollback prepared transaction after teardown
[12:41:48.744](0.000s) #   Failed test 'Rollback prepared transaction after teardown'
#   at /tmp/cirrus-ci-build/src/test/recovery/t/009_twophase.pl line 120.
[12:41:48.745](0.000s) #          got: '2'
#     expected: '0'
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
### Stopping node "london" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "london"
### Starting node "london"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/log/009_twophase_london.log -o --cluster-name=london start
waiting for server to start.... done
server started
# Postmaster PID for node "london" is 23964
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
[12:41:49.068](0.324s) not ok 7 - Replay several transactions with same GID
[12:41:49.069](0.000s) #   Failed test 'Replay several transactions with same GID'
#   at /tmp/cirrus-ci-build/src/test/recovery/t/009_twophase.pl line 144.
[12:41:49.069](0.000s) #          got: '2'
#     expected: '0'
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
### Stopping node "london" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -m immediate stop
waiting for server to shut down... done
server stopped
# No postmaster PID for node "london"
### Starting node "london"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/log/009_twophase_london.log -o --cluster-name=london start
waiting for server to start.... done
server started
# Postmaster PID for node "london" is 24053
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
[12:41:49.281](0.213s) not ok 8 - Cleanup of shared memory state for 2PC commit
[12:41:49.282](0.000s) #   Failed test 'Cleanup of shared memory state for 2PC commit'
#   at /tmp/cirrus-ci-build/src/test/recovery/t/009_twophase.pl line 170.
[12:41:49.282](0.000s) #          got: '2'
#     expected: '0'
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61578" failed: FATAL:  database "postgres" does not exist
[12:41:49.394](0.113s) not ok 9 - Cleanup of shared memory state on running standby without checkpoint
[12:41:49.395](0.000s) #   Failed test 'Cleanup of shared memory state on running standby without checkpoint'
#   at /tmp/cirrus-ci-build/src/test/recovery/t/009_twophase.pl line 190.
[12:41:49.395](0.000s) #          got: ''
#     expected: '0'
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61578" failed: FATAL:  database "postgres" does not exist
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61578" failed: FATAL:  database "postgres" does not exist
[12:41:49.540](0.145s) not ok 10 - Cleanup of shared memory state on running standby after checkpoint
[12:41:49.540](0.000s) #   Failed test 'Cleanup of shared memory state on running standby after checkpoint'
#   at /tmp/cirrus-ci-build/src/test/recovery/t/009_twophase.pl line 211.
[12:41:49.540](0.000s) #          got: ''
#     expected: '0'
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577" failed: FATAL:  database "postgres" does not exist
### Stopping node "london" using mode immediate
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "london"
### Promoting node "paris"
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_paris_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/log/009_twophase_paris.log promote
waiting for server to promote.... done
server promoted
[12:41:49.790](0.250s) # Now paris is primary and london is standby
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61578" failed: FATAL:  database "postgres" does not exist
[12:41:49.833](0.043s) not ok 11 - Restore of prepared transaction on promoted standby
[12:41:49.833](0.000s) #   Failed test 'Restore of prepared transaction on promoted standby'
#   at /tmp/cirrus-ci-build/src/test/recovery/t/009_twophase.pl line 237.
[12:41:49.833](0.000s) #          got: '2'
#     expected: '0'
### Enabling streaming replication for node "london"
### Starting node "london"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/log/009_twophase_london.log -o --cluster-name=london start
waiting for server to start.... done
server started
# Postmaster PID for node "london" is 24285
psql: error: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61578" failed: FATAL:  database "postgres" does not exist
### Stopping node "paris" using mode fast
# Running: pg_ctl -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_paris_data/pgdata -m fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "paris"
### Restarting node "london"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/log/009_twophase_london.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... stopped waiting
pg_ctl: could not start server
Examine the log output.
# pg_ctl restart failed; logfile:
2024-03-17 12:41:47.679 UTC [23529][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-17 12:41:47.679 UTC [23529][postmaster] LOG:  listening on Unix socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577"
2024-03-17 12:41:47.681 UTC [23536][startup] LOG:  database system was interrupted; last known up at 2024-03-17 12:41:45 UTC
2024-03-17 12:41:47.681 UTC [23536][startup] LOG:  database system was not properly shut down; automatic recovery in progress
2024-03-17 12:41:47.681 UTC [23536][startup] LOG:  redo starts at 0/10B1BB0
2024-03-17 12:41:47.684 UTC [23536][startup] LOG:  invalid record length at 0/1171CD0: expected at least 24, got 0
2024-03-17 12:41:47.684 UTC [23536][startup] LOG:  redo done at 0/1171C78 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
2024-03-17 12:41:47.684 UTC [23534][checkpointer] LOG:  checkpoint starting: end-of-recovery immediate wait
2024-03-17 12:41:47.704 UTC [23534][checkpointer] LOG:  checkpoint complete: wrote 113 buffers (88.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.021 s; sync files=0, longest=0.000 s, average=0.000 s; distance=768 kB, estimate=768 kB; lsn=0/1171CD0, redo lsn=0/1171CD0
2024-03-17 12:41:47.706 UTC [23529][postmaster] LOG:  database system is ready to accept connections
2024-03-17 12:41:47.776 UTC [23571][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:47.777 UTC [23571][walsender] [[unknown]][22/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:124)
2024-03-17 12:41:47.777 UTC [23571][walsender] [[unknown]][22/1:0] LOG:  replication connection authorized: user=postgres application_name=009_twophase.pl
2024-03-17 12:41:47.777 UTC [23571][walsender] [009_twophase.pl][22/0:0] LOG:  received replication command: SHOW data_directory_mode
2024-03-17 12:41:47.777 UTC [23571][walsender] [009_twophase.pl][22/0:0] STATEMENT:  SHOW data_directory_mode
2024-03-17 12:41:47.777 UTC [23571][walsender] [009_twophase.pl][22/0:0] LOG:  received replication command: SHOW wal_segment_size
2024-03-17 12:41:47.777 UTC [23571][walsender] [009_twophase.pl][22/0:0] STATEMENT:  SHOW wal_segment_size
2024-03-17 12:41:47.777 UTC [23571][walsender] [009_twophase.pl][22/0:0] LOG:  received replication command: IDENTIFY_SYSTEM
2024-03-17 12:41:47.777 UTC [23571][walsender] [009_twophase.pl][22/0:0] STATEMENT:  IDENTIFY_SYSTEM
2024-03-17 12:41:47.777 UTC [23571][walsender] [009_twophase.pl][22/0:0] LOG:  received replication command: BASE_BACKUP ( LABEL 'pg_basebackup base backup',  PROGRESS,  CHECKPOINT 'fast',  WAIT 0,  MANIFEST 'yes',  TARGET 'client')
2024-03-17 12:41:47.777 UTC [23571][walsender] [009_twophase.pl][22/0:0] STATEMENT:  BASE_BACKUP ( LABEL 'pg_basebackup base backup',  PROGRESS,  CHECKPOINT 'fast',  WAIT 0,  MANIFEST 'yes',  TARGET 'client')
2024-03-17 12:41:47.782 UTC [23534][checkpointer] LOG:  checkpoint starting: immediate force wait
2024-03-17 12:41:47.798 UTC [23534][checkpointer] LOG:  checkpoint complete: wrote 9 buffers (7.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.001 s, sync=0.001 s, total=0.017 s; sync files=0, longest=0.000 s, average=0.000 s; distance=14904 kB, estimate=14904 kB; lsn=0/2000080, redo lsn=0/2000028
2024-03-17 12:41:47.801 UTC [23582][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:47.801 UTC [23582][walsender] [[unknown]][23/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:124)
2024-03-17 12:41:47.801 UTC [23582][walsender] [[unknown]][23/1:0] LOG:  replication connection authorized: user=postgres application_name=009_twophase.pl
2024-03-17 12:41:47.801 UTC [23582][walsender] [009_twophase.pl][23/0:0] LOG:  received replication command: SHOW data_directory_mode
2024-03-17 12:41:47.801 UTC [23582][walsender] [009_twophase.pl][23/0:0] STATEMENT:  SHOW data_directory_mode
2024-03-17 12:41:47.802 UTC [23582][walsender] [009_twophase.pl][23/0:0] LOG:  received replication command: CREATE_REPLICATION_SLOT "pg_basebackup_23582" TEMPORARY PHYSICAL ( RESERVE_WAL)
2024-03-17 12:41:47.802 UTC [23582][walsender] [009_twophase.pl][23/0:0] STATEMENT:  CREATE_REPLICATION_SLOT "pg_basebackup_23582" TEMPORARY PHYSICAL ( RESERVE_WAL)
2024-03-17 12:41:47.802 UTC [23582][walsender] [009_twophase.pl][23/0:0] LOG:  released physical replication slot "pg_basebackup_23582"
2024-03-17 12:41:47.802 UTC [23582][walsender] [009_twophase.pl][23/0:0] STATEMENT:  CREATE_REPLICATION_SLOT "pg_basebackup_23582" TEMPORARY PHYSICAL ( RESERVE_WAL)
2024-03-17 12:41:47.804 UTC [23582][walsender] [009_twophase.pl][23/0:0] LOG:  received replication command: IDENTIFY_SYSTEM
2024-03-17 12:41:47.804 UTC [23582][walsender] [009_twophase.pl][23/0:0] STATEMENT:  IDENTIFY_SYSTEM
2024-03-17 12:41:47.804 UTC [23582][walsender] [009_twophase.pl][23/0:0] LOG:  received replication command: START_REPLICATION SLOT "pg_basebackup_23582" 0/2000000 TIMELINE 1
2024-03-17 12:41:47.804 UTC [23582][walsender] [009_twophase.pl][23/0:0] STATEMENT:  START_REPLICATION SLOT "pg_basebackup_23582" 0/2000000 TIMELINE 1
2024-03-17 12:41:47.804 UTC [23582][walsender] [009_twophase.pl][23/0:0] LOG:  acquired physical replication slot "pg_basebackup_23582"
2024-03-17 12:41:47.804 UTC [23582][walsender] [009_twophase.pl][23/0:0] STATEMENT:  START_REPLICATION SLOT "pg_basebackup_23582" 0/2000000 TIMELINE 1
2024-03-17 12:41:47.827 UTC [23582][walsender] [009_twophase.pl][23/0:0] LOG:  released physical replication slot "pg_basebackup_23582"
2024-03-17 12:41:47.827 UTC [23582][walsender] [009_twophase.pl][23/0:0] STATEMENT:  START_REPLICATION SLOT "pg_basebackup_23582" 0/2000000 TIMELINE 1
2024-03-17 12:41:47.828 UTC [23571][walsender] [009_twophase.pl][:0] LOG:  disconnection: session time: 0:00:00.051 user=postgres database= host=[local]
2024-03-17 12:41:47.828 UTC [23582][walsender] [009_twophase.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=postgres database= host=[local]
2024-03-17 12:41:47.893 UTC [23614][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:47.894 UTC [23614][walsender] [[unknown]][24/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:124)
2024-03-17 12:41:47.894 UTC [23614][walsender] [[unknown]][24/1:0] LOG:  replication connection authorized: user=postgres application_name=paris
2024-03-17 12:41:47.894 UTC [23614][walsender] [paris][24/0:0] LOG:  received replication command: IDENTIFY_SYSTEM
2024-03-17 12:41:47.894 UTC [23614][walsender] [paris][24/0:0] STATEMENT:  IDENTIFY_SYSTEM
2024-03-17 12:41:47.894 UTC [23614][walsender] [paris][24/0:0] LOG:  received replication command: START_REPLICATION 0/3000000 TIMELINE 1
2024-03-17 12:41:47.894 UTC [23614][walsender] [paris][24/0:0] STATEMENT:  START_REPLICATION 0/3000000 TIMELINE 1
2024-03-17 12:41:47.985 UTC [23627][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:47.986 UTC [23627][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:47.986 UTC [23627][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:47.986 UTC [23627][client backend] [[unknown]][0/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:48.000 UTC [23632][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:48.001 UTC [23632][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:48.001 UTC [23632][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:48.001 UTC [23632][client backend] [[unknown]][1/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:48.044 UTC [23645][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:48.045 UTC [23645][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:48.045 UTC [23645][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:48.045 UTC [23645][client backend] [[unknown]][2/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:48.099 UTC [23529][postmaster] LOG:  received fast shutdown request
2024-03-17 12:41:48.099 UTC [23529][postmaster] LOG:  aborting any active transactions
2024-03-17 12:41:48.101 UTC [23529][postmaster] LOG:  background worker "logical replication launcher" (PID 23555) exited with exit code 1
2024-03-17 12:41:48.101 UTC [23534][checkpointer] LOG:  shutting down
2024-03-17 12:41:48.111 UTC [23534][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-17 12:41:48.111 UTC [23534][checkpointer] LOG:  checkpoint complete: wrote 0 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=16384 kB, estimate=16384 kB; lsn=0/3000028, redo lsn=0/3000028
2024-03-17 12:41:48.141 UTC [23614][walsender] [paris][:0] LOG:  disconnection: session time: 0:00:00.248 user=postgres database= host=[local]
2024-03-17 12:41:48.143 UTC [23529][postmaster] LOG:  database system is shut down
2024-03-17 12:41:48.225 UTC [23703][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-17 12:41:48.225 UTC [23703][postmaster] LOG:  listening on Unix socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577"
2024-03-17 12:41:48.227 UTC [23711][startup] LOG:  database system was shut down at 2024-03-17 12:41:48 UTC
2024-03-17 12:41:48.230 UTC [23703][postmaster] LOG:  database system is ready to accept connections
2024-03-17 12:41:48.321 UTC [23752][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:48.321 UTC [23752][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:48.321 UTC [23752][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:48.321 UTC [23752][client backend] [[unknown]][0/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:48.368 UTC [23767][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:48.368 UTC [23767][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:48.368 UTC [23767][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:48.368 UTC [23767][client backend] [[unknown]][1/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:48.414 UTC [23774][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:48.414 UTC [23774][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:48.414 UTC [23774][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:48.414 UTC [23774][client backend] [[unknown]][2/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:48.445 UTC [23703][postmaster] LOG:  received immediate shutdown request
2024-03-17 12:41:48.447 UTC [23703][postmaster] LOG:  database system is shut down
2024-03-17 12:41:48.571 UTC [23837][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-17 12:41:48.571 UTC [23837][postmaster] LOG:  listening on Unix socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577"
2024-03-17 12:41:48.573 UTC [23845][startup] LOG:  database system was interrupted; last known up at 2024-03-17 12:41:48 UTC
2024-03-17 12:41:48.573 UTC [23845][startup] LOG:  database system was not properly shut down; automatic recovery in progress
2024-03-17 12:41:48.573 UTC [23845][startup] LOG:  invalid record length at 0/30000A0: expected at least 24, got 0
2024-03-17 12:41:48.573 UTC [23845][startup] LOG:  redo is not required
2024-03-17 12:41:48.573 UTC [23843][checkpointer] LOG:  checkpoint starting: end-of-recovery immediate wait
2024-03-17 12:41:48.574 UTC [23843][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (2.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/30000A0, redo lsn=0/30000A0
2024-03-17 12:41:48.575 UTC [23837][postmaster] LOG:  database system is ready to accept connections
2024-03-17 12:41:48.646 UTC [23891][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:48.649 UTC [23891][walsender] [[unknown]][22/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:124)
2024-03-17 12:41:48.649 UTC [23891][walsender] [[unknown]][22/1:0] LOG:  replication connection authorized: user=postgres application_name=paris
2024-03-17 12:41:48.650 UTC [23891][walsender] [paris][22/0:0] LOG:  received replication command: IDENTIFY_SYSTEM
2024-03-17 12:41:48.650 UTC [23891][walsender] [paris][22/0:0] STATEMENT:  IDENTIFY_SYSTEM
2024-03-17 12:41:48.650 UTC [23891][walsender] [paris][22/0:0] LOG:  received replication command: START_REPLICATION 0/3000000 TIMELINE 1
2024-03-17 12:41:48.650 UTC [23891][walsender] [paris][22/0:0] STATEMENT:  START_REPLICATION 0/3000000 TIMELINE 1
2024-03-17 12:41:48.650 UTC [23891][walsender] [paris][22/0:0] LOG:  standby "paris" is now a synchronous standby with priority 1
2024-03-17 12:41:48.650 UTC [23891][walsender] [paris][22/0:0] STATEMENT:  START_REPLICATION 0/3000000 TIMELINE 1
2024-03-17 12:41:48.664 UTC [23897][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:48.665 UTC [23897][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:48.665 UTC [23897][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:48.665 UTC [23897][client backend] [[unknown]][0/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:48.707 UTC [23904][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:48.707 UTC [23904][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:48.707 UTC [23904][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:48.707 UTC [23904][client backend] [[unknown]][1/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:48.755 UTC [23923][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:48.755 UTC [23923][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:48.755 UTC [23923][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:48.755 UTC [23923][client backend] [[unknown]][2/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:48.792 UTC [23837][postmaster] LOG:  received immediate shutdown request
2024-03-17 12:41:48.795 UTC [23837][postmaster] LOG:  database system is shut down
2024-03-17 12:41:48.937 UTC [23964][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-17 12:41:48.937 UTC [23964][postmaster] LOG:  listening on Unix socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577"
2024-03-17 12:41:48.944 UTC [23969][startup] LOG:  database system was interrupted; last known up at 2024-03-17 12:41:48 UTC
2024-03-17 12:41:48.944 UTC [23969][startup] LOG:  database system was not properly shut down; automatic recovery in progress
2024-03-17 12:41:48.944 UTC [23969][startup] LOG:  invalid record length at 0/3000118: expected at least 24, got 0
2024-03-17 12:41:48.944 UTC [23969][startup] LOG:  redo is not required
2024-03-17 12:41:48.944 UTC [23967][checkpointer] LOG:  checkpoint starting: end-of-recovery immediate wait
2024-03-17 12:41:48.945 UTC [23967][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (2.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/3000118, redo lsn=0/3000118
2024-03-17 12:41:48.946 UTC [23964][postmaster] LOG:  database system is ready to accept connections
2024-03-17 12:41:49.034 UTC [24003][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:49.034 UTC [24003][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:49.034 UTC [24003][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:49.034 UTC [24003][client backend] [[unknown]][0/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:49.075 UTC [24018][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:49.076 UTC [24018][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:49.076 UTC [24018][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:49.076 UTC [24018][client backend] [[unknown]][1/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:49.117 UTC [23964][postmaster] LOG:  received immediate shutdown request
2024-03-17 12:41:49.119 UTC [23964][postmaster] LOG:  database system is shut down
2024-03-17 12:41:49.146 UTC [24053][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-17 12:41:49.146 UTC [24053][postmaster] LOG:  listening on Unix socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577"
2024-03-17 12:41:49.193 UTC [24061][startup] LOG:  database system was interrupted; last known up at 2024-03-17 12:41:48 UTC
2024-03-17 12:41:49.193 UTC [24061][startup] LOG:  database system was not properly shut down; automatic recovery in progress
2024-03-17 12:41:49.193 UTC [24061][startup] LOG:  invalid record length at 0/3000190: expected at least 24, got 0
2024-03-17 12:41:49.193 UTC [24061][startup] LOG:  redo is not required
2024-03-17 12:41:49.193 UTC [24059][checkpointer] LOG:  checkpoint starting: end-of-recovery immediate wait
2024-03-17 12:41:49.227 UTC [24059][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (2.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.034 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/3000190, redo lsn=0/3000190
2024-03-17 12:41:49.234 UTC [24053][postmaster] LOG:  database system is ready to accept connections
2024-03-17 12:41:49.245 UTC [24089][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:49.245 UTC [24089][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:49.246 UTC [24089][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:49.246 UTC [24089][client backend] [[unknown]][0/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:49.288 UTC [24092][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:49.289 UTC [24092][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:49.289 UTC [24092][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:49.289 UTC [24092][client backend] [[unknown]][1/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:49.336 UTC [24104][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:49.336 UTC [24104][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:49.336 UTC [24104][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:49.336 UTC [24104][client backend] [[unknown]][2/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:49.405 UTC [24124][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:49.405 UTC [24124][client backend] [[unknown]][3/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:49.405 UTC [24124][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:49.405 UTC [24124][client backend] [[unknown]][3/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:49.494 UTC [24172][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:49.495 UTC [24172][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:49.495 UTC [24172][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:49.495 UTC [24172][client backend] [[unknown]][4/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:49.546 UTC [24189][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-17 12:41:49.547 UTC [24189][client backend] [[unknown]][5/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/recovery/009_twophase/data/t_009_twophase_london_data/pgdata/pg_hba.conf:117)
2024-03-17 12:41:49.547 UTC [24189][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=009_twophase.pl
2024-03-17 12:41:49.547 UTC [24189][client backend] [[unknown]][5/1:0] FATAL:  database "postgres" does not exist
2024-03-17 12:41:49.585 UTC [24053][postmaster] LOG:  received immediate shutdown request
2024-03-17 12:41:49.587 UTC [24053][postmaster] LOG:  database system is shut down
2024-03-17 12:41:49.857 UTC [24285][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-17 12:41:49.857 UTC [24285][postmaster] LOG:  listening on Unix socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577"
2024-03-17 12:41:49.879 UTC [24296][startup] LOG:  database system was interrupted; last known up at 2024-03-17 12:41:49 UTC
2024-03-17 12:41:49.879 UTC [24296][startup] LOG:  entering standby mode
2024-03-17 12:41:49.879 UTC [24296][startup] LOG:  database system was not properly shut down; automatic recovery in progress
2024-03-17 12:41:49.879 UTC [24296][startup] LOG:  invalid record length at 0/3000208: expected at least 24, got 0
2024-03-17 12:41:49.879 UTC [24296][startup] LOG:  consistent recovery state reached at 0/3000208
2024-03-17 12:41:49.879 UTC [24285][postmaster] LOG:  database system is ready to accept read-only connections
2024-03-17 12:41:49.898 UTC [24297][walreceiver] LOG:  fetching timeline history file for timeline 2 from primary server
2024-03-17 12:41:49.898 UTC [24297][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.898 UTC [24297][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.898 UTC [24297][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.899 UTC [24297][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.899 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.903 UTC [24308][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.903 UTC [24308][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.903 UTC [24308][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.903 UTC [24308][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.903 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.903 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.906 UTC [24312][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.906 UTC [24312][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.906 UTC [24312][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.906 UTC [24312][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.906 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.906 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.908 UTC [24317][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.909 UTC [24317][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.909 UTC [24317][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.909 UTC [24317][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.909 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.909 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.911 UTC [24319][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.911 UTC [24319][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.911 UTC [24319][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.911 UTC [24319][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.911 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.911 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.915 UTC [24321][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.915 UTC [24321][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.915 UTC [24321][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.915 UTC [24321][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.915 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.915 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.918 UTC [24323][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.918 UTC [24323][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.918 UTC [24323][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.918 UTC [24323][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.918 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.918 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.920 UTC [24326][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.920 UTC [24326][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.920 UTC [24326][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.920 UTC [24326][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.920 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.920 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.923 UTC [24328][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.923 UTC [24328][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.923 UTC [24328][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.923 UTC [24328][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.923 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.923 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.927 UTC [24331][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.927 UTC [24331][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.927 UTC [24331][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.927 UTC [24331][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.927 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.927 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.930 UTC [24333][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.930 UTC [24333][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.930 UTC [24333][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.930 UTC [24333][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.930 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.930 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.933 UTC [24339][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.933 UTC [24339][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.933 UTC [24339][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.933 UTC [24339][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.933 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.933 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.936 UTC [24341][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.936 UTC [24341][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.936 UTC [24341][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.936 UTC [24341][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.936 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.936 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.938 UTC [24343][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.938 UTC [24343][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.938 UTC [24343][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.938 UTC [24343][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.938 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.938 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.941 UTC [24345][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.941 UTC [24345][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.941 UTC [24345][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.941 UTC [24345][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.941 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.941 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.943 UTC [24347][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.944 UTC [24347][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.944 UTC [24347][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.944 UTC [24347][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.944 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.944 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.946 UTC [24349][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.946 UTC [24349][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.946 UTC [24349][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.946 UTC [24349][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.946 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.946 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.949 UTC [24351][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.949 UTC [24351][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.949 UTC [24351][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.949 UTC [24351][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.949 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.949 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.951 UTC [24354][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.951 UTC [24354][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.951 UTC [24354][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.951 UTC [24354][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.951 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.951 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.954 UTC [24357][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.954 UTC [24357][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.954 UTC [24357][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.954 UTC [24357][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.954 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.954 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.957 UTC [24360][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.957 UTC [24360][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.957 UTC [24360][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.957 UTC [24360][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.957 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.957 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.959 UTC [24363][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.959 UTC [24363][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.959 UTC [24363][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.959 UTC [24363][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.959 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.959 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.962 UTC [24365][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.962 UTC [24365][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.962 UTC [24365][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.962 UTC [24365][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.962 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.962 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.965 UTC [24367][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.965 UTC [24367][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.965 UTC [24367][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.965 UTC [24367][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.965 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.965 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.967 UTC [24369][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.967 UTC [24369][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.967 UTC [24369][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.967 UTC [24369][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.967 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.967 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.970 UTC [24371][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.970 UTC [24371][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.970 UTC [24371][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.970 UTC [24371][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.970 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.970 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.974 UTC [24373][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.975 UTC [24373][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.975 UTC [24373][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.975 UTC [24373][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.975 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.975 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:49.988 UTC [24379][walreceiver] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2024-03-17 12:41:49.988 UTC [24379][walreceiver] LOG:  replication terminated by primary server
2024-03-17 12:41:49.988 UTC [24379][walreceiver] DETAIL:  End of WAL reached on timeline 1 at 0/3000118.
2024-03-17 12:41:49.988 UTC [24379][walreceiver] FATAL:  terminating walreceiver process due to administrator command
2024-03-17 12:41:49.991 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:49.991 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:50.000 UTC [24390][walreceiver] FATAL:  could not connect to the primary server: connection to server on socket "/tmp/ID9zHHIQxW/.s.PGSQL.61578" failed: FATAL:  the database system is shutting down
2024-03-17 12:41:50.001 UTC [24296][startup] LOG:  new timeline 2 forked off current database system timeline 1 before current recovery point 0/3000208
2024-03-17 12:41:50.001 UTC [24296][startup] LOG:  waiting for WAL to become available at 0/3000220
2024-03-17 12:41:50.093 UTC [24285][postmaster] LOG:  received fast shutdown request
2024-03-17 12:41:50.093 UTC [24285][postmaster] LOG:  aborting any active transactions
2024-03-17 12:41:50.094 UTC [24294][checkpointer] LOG:  shutting down
2024-03-17 12:41:50.095 UTC [24285][postmaster] LOG:  database system is shut down
2024-03-17 12:41:50.206 UTC [24452][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit
2024-03-17 12:41:50.206 UTC [24452][postmaster] LOG:  listening on Unix socket "/tmp/ID9zHHIQxW/.s.PGSQL.61577"
2024-03-17 12:41:50.217 UTC [24458][startup] LOG:  database system was shut down in recovery at 2024-03-17 12:41:50 UTC
2024-03-17 12:41:50.217 UTC [24458][startup] LOG:  entering standby mode
2024-03-17 12:41:50.217 UTC [24458][startup] FATAL:  requested timeline 2 is not a child of this server's history
2024-03-17 12:41:50.217 UTC [24458][startup] DETAIL:  Latest checkpoint is at 0/3000190 on timeline 1, but in the history of the requested timeline, the server forked off from that timeline at 0/3000118.
2024-03-17 12:41:50.218 UTC [24452][postmaster] LOG:  startup process (PID 24458) exited with exit code 1
2024-03-17 12:41:50.218 UTC [24452][postmaster] LOG:  aborting startup due to startup process failure
2024-03-17 12:41:50.218 UTC [24452][postmaster] LOG:  database system is shut down
# No postmaster PID for node "london"
[12:41:50.294](0.461s) Bail out!  pg_ctl restart failed
# No postmaster PID for node "london"
# No postmaster PID for node "paris"