[prev in list] [next in list] [prev in thread] [next in thread] 

List:       postgresql-general
Subject:    Re: WAL File Recovery on Standby Server Stops Before End of WAL Files
From:       Kyotaro Horiguchi <horikyota.ntt () gmail ! com>
Date:       2021-10-29 1:44:46
Message-ID: 20211029.104446.382302278518357208.horikyota.ntt () gmail ! com
[Download RAW message or body]

At Thu, 28 Oct 2021 13:52:36 +0000, "Ryan, Les" <Les.Ryan@wsp.com> wrote in 
> Hi Kyotaro and Dilip,
> 
> Thank you for getting back to me.
> 
> Kyotaro: I ran pg_dump and the output was "pg_waldump: fatal: could not read file \
> "00000001000004190000005A": read 50 of 8192".  I'm guessing that it means that wal \
> file 00000001000004190000005A is corrupted and that is why the recovery process \
> stops there.  Is there any way to fix the file?

No way, unless the segment is still living in the primary's
pg_wal. Your archive storage is unstable or archive_command is not
performing its task reliably enough.

> Dilip:   setting the log level to debug2 did not provide any additional \
> information.  Here are the log entries: 
> 2021-10-28 06:51:06.166 MDT [7556] LOG:  restored log file \
> "000000010000041900000059" from archive 2021-10-28 06:51:06.464 MDT [7556] DEBUG:  \
> got WAL segment from archive 2021-10-28 06:51:06.579 MDT [7556] LOG:  restored log \
> file "00000001000004190000005A" from archive 2021-10-28 06:51:06.854 MDT [7556] \
> DEBUG:  got WAL segment from archive 2021-10-28 06:51:07.107 MDT [7556] LOG:  \
> consistent recovery state reached at 419/5ABFFFF8 2021-10-28 06:51:07.107 MDT \
> [7556] DEBUG:  switched WAL source from archive to stream after failure 2021-10-28 \
> 06:51:07.109 MDT [7844] LOG:  database system is ready to accept read only \
> connections 2021-10-28 06:51:07.152 MDT [7844] DEBUG:  forked new backend, pid=6900 \
> socket=6068 
> I set the log level to debug5 and here is what I got:
> 
> 2021-10-28 06:25:41.262 MDT [6288] CONTEXT:  WAL redo at 419/5ABFFF60 for \
> Btree/INSERT_LEAF: off 130 2021-10-28 06:25:41.262 MDT [6288] DEBUG:  record known \
> xact 33776257 latestObservedXid 33776257 2021-10-28 06:25:41.262 MDT [6288] \
> CONTEXT:  WAL redo at 419/5ABFFFA0 for Heap/INSERT: off 95 flags 0x00 2021-10-28 \
> 06:25:41.262 MDT [6288] LOG:  consistent recovery state reached at 419/5ABFFFF8 \
> 2021-10-28 06:25:41.263 MDT [6288] DEBUG:  switched WAL source from archive to \
> stream after failure 2021-10-28 06:25:41.264 MDT [5512] LOG:  database system is \
> ready to accept read only connections 
> Does the "switched WAL source from archive to stream after failure" indicate a \
> problem with the WAL file?

Actually the message says that some trouble happend while reading file
but that happens always at the end of wal.  We might need a bit more
detailed message about the trouble in higher debug level messages.

> Anyway, it looks like I need to restore the standby server from a new backup.  \
> Thank you both for your help.

Unfortunately I think so, too.

> Sincerely,
> -Les

-- 
Kyotaro Horiguchi
NTT Open Source Software Center


[prev in list] [next in list] [prev in thread] [next in thread]