025_stuck_on_old_timeline_standby.log
application/octet-stream
Filename: 025_stuck_on_old_timeline_standby.log
Type: application/octet-stream
Part: 4
Message:
Re: Race condition in recovery?
2021-06-03 16:16:51.950 EDT [47753] LOG: starting PostgreSQL 14beta1 on x86_64-apple-darwin19.6.0, compiled by clang version 5.0.2 (tags/RELEASE_502/final), 64-bit 2021-06-03 16:16:51.951 EDT [47753] LOG: listening on Unix socket "/var/folders/jh/925hn4t97mb_sby_1s37k7dc0000gs/T/sdk3QMgbuK/.s.PGSQL.50637" 2021-06-03 16:16:51.956 EDT [47754] LOG: database system was interrupted; last known up at 2021-06-03 16:16:51 EDT 2021-06-03 16:16:51.956 EDT [47754] LOG: entering standby mode 2021-06-03 16:16:51.960 EDT [47754] LOG: redo starts at 0/2000028 2021-06-03 16:16:51.960 EDT [47754] LOG: consistent recovery state reached at 0/2000100 2021-06-03 16:16:51.960 EDT [47753] LOG: database system is ready to accept read only connections 2021-06-03 16:16:51.967 EDT [47758] LOG: started streaming WAL from primary at 0/3000000 on timeline 1 2021-06-03 16:16:52.042 EDT [47761] 025_stuck_on_old_timeline.pl LOG: received replication command: SHOW data_directory_mode 2021-06-03 16:16:52.042 EDT [47761] 025_stuck_on_old_timeline.pl STATEMENT: SHOW data_directory_mode 2021-06-03 16:16:52.042 EDT [47761] 025_stuck_on_old_timeline.pl LOG: received replication command: SHOW wal_segment_size 2021-06-03 16:16:52.042 EDT [47761] 025_stuck_on_old_timeline.pl STATEMENT: SHOW wal_segment_size 2021-06-03 16:16:52.042 EDT [47761] 025_stuck_on_old_timeline.pl LOG: received replication command: IDENTIFY_SYSTEM 2021-06-03 16:16:52.042 EDT [47761] 025_stuck_on_old_timeline.pl STATEMENT: IDENTIFY_SYSTEM 2021-06-03 16:16:52.042 EDT [47761] 025_stuck_on_old_timeline.pl LOG: received replication command: BASE_BACKUP LABEL 'pg_basebackup base backup' PROGRESS FAST MANIFEST 'yes' 2021-06-03 16:16:52.042 EDT [47761] 025_stuck_on_old_timeline.pl STATEMENT: BASE_BACKUP LABEL 'pg_basebackup base backup' PROGRESS FAST MANIFEST 'yes' 2021-06-03 16:16:52.876 EDT [47764] 025_stuck_on_old_timeline.pl LOG: statement: SELECT pg_promote() 2021-06-03 16:16:52.878 EDT [47754] LOG: received promote request 2021-06-03 16:16:52.879 EDT [47758] FATAL: terminating walreceiver process due to administrator command 2021-06-03 16:16:52.879 EDT [47754] LOG: redo done at 0/2000100 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.91 s 2021-06-03 16:16:52.881 EDT [47754] LOG: selected new timeline ID: 2 2021-06-03 16:16:52.961 EDT [47754] LOG: archive recovery complete 2021-06-03 16:16:52.968 EDT [47753] LOG: database system is ready to accept connections 2021-06-03 16:16:53.127 EDT [47772] 025_stuck_on_old_timeline.pl LOG: statement: SELECT pg_walfile_name(pg_current_wal_lsn()); 2021-06-03 16:16:53.144 EDT [47774] 025_stuck_on_old_timeline.pl LOG: statement: SELECT pg_switch_wal() 2021-06-03 16:16:53.171 EDT [47777] 025_stuck_on_old_timeline.pl LOG: statement: SELECT '000000020000000000000003' <= last_archived_wal FROM pg_stat_archiver; 2021-06-03 16:16:53.310 EDT [47781] 025_stuck_on_old_timeline.pl LOG: statement: SELECT '000000020000000000000003' <= last_archived_wal FROM pg_stat_archiver; 2021-06-03 16:16:53.434 EDT [47783] 025_stuck_on_old_timeline.pl LOG: statement: SELECT '000000020000000000000003' <= last_archived_wal FROM pg_stat_archiver; 2021-06-03 16:16:53.558 EDT [47785] 025_stuck_on_old_timeline.pl LOG: statement: SELECT '000000020000000000000003' <= last_archived_wal FROM pg_stat_archiver; 2021-06-03 16:16:53.682 EDT [47787] 025_stuck_on_old_timeline.pl LOG: statement: SELECT '000000020000000000000003' <= last_archived_wal FROM pg_stat_archiver; 2021-06-03 16:16:53.816 EDT [47797] cascade LOG: received replication command: IDENTIFY_SYSTEM 2021-06-03 16:16:53.816 EDT [47797] cascade STATEMENT: IDENTIFY_SYSTEM 2021-06-03 16:16:53.816 EDT [47797] cascade LOG: received replication command: START_REPLICATION 0/2000000 TIMELINE 1 2021-06-03 16:16:53.816 EDT [47797] cascade STATEMENT: START_REPLICATION 0/2000000 TIMELINE 1 2021-06-03 16:16:53.983 EDT [47797] cascade LOG: received replication command: IDENTIFY_SYSTEM 2021-06-03 16:16:53.983 EDT [47797] cascade STATEMENT: IDENTIFY_SYSTEM 2021-06-03 16:16:53.983 EDT [47797] cascade LOG: received replication command: START_REPLICATION 0/3000000 TIMELINE 2 2021-06-03 16:16:53.983 EDT [47797] cascade STATEMENT: START_REPLICATION 0/3000000 TIMELINE 2 2021-06-03 16:16:54.042 EDT [47807] 025_stuck_on_old_timeline.pl LOG: statement: CREATE TABLE tab_int AS SELECT 1 AS a 2021-06-03 16:16:54.135 EDT [47809] 025_stuck_on_old_timeline.pl LOG: statement: SELECT pg_last_wal_replay_lsn() 2021-06-03 16:16:54.154 EDT [47811] 025_stuck_on_old_timeline.pl LOG: statement: SELECT '0/3000000' <= replay_lsn AND state = 'streaming' FROM pg_catalog.pg_stat_replication WHERE application_name = 'cascade'; 2021-06-03 16:16:54.313 EDT [47753] LOG: received immediate shutdown request 2021-06-03 16:16:54.319 EDT [47753] LOG: database system is shut down