Re: xlog min recovery request 7C5C/96D5C550 is past current point

> On 28/05/2023 13:45 CEST Victor Sudakov <vas(at)sibptus(dot)ru> wrote:
>
> Dear Colleagues,
>
> After starting a Postgres 13.11 cluster from a pg_basebackup'ed
> directory, it started its recovery with lots of these messages in the log:
>
> 2024-05-26 03:30:26.526 MST [394116] WARNING: xlog min recovery request 7C5B/8AC06EA0 is past current point 7C5B/839449E8
> 2023-05-26 03:30:26.526 MST [394116] CONTEXT: writing block 23 of relation base/1653520455/1653526563_fsm
> WAL redo at 7C5B/83944978 for Heap/UPDATE: off 126 xmax 1873090085 flags 0x02 ; new off 3 xmax 0
> 2023-05-26 03:30:30.438 MST [394116] WARNING: xlog min recovery request 7C5B/8AC06EA0 is past current point 7C5B/8847C348
> 2023-05-26 03:30:30.438 MST [394116] CONTEXT: writing block 23 of relation base/1653520455/1653526563_fsm
> WAL redo at 7C5B/8847A420 for XLOG/FPI_FOR_HINT:
> 2023-05-26 03:30:33.612 MST [394116] WARNING: xlog min recovery request 7C5B/BD1CC550 is past current point 7C5B/8A3CF248
> 2023-05-26 03:30:33.612 MST [394116] CONTEXT: writing block 2 of relation base/1653520455/1653527229_fsm
> WAL redo at 7C5B/8A3CF208 for Heap2/VISIBLE: cutoff xid 1873088629 flags 0x01
> 2023-05-26 03:30:42.836 MST [394116] WARNING: xlog min recovery request 7C5B/BA11C7D8 is past current point 7C5B/8C7830E8
> 2023-05-26 03:30:42.836 MST [394116] CONTEXT: writing block 0 of relation base/1653520455/1653554782_vm
> WAL redo at 7C5B/8C7830B0 for Heap2/CLEAN: remxid 1873090422
> 2023-05-26 03:30:48.174 MST [394116] WARNING: xlog min recovery request 7C5C/3E4F06F8 is past current point 7C5B/8EC92C70
> 2023-05-26 03:30:48.174 MST [394116] CONTEXT: writing block 126 of relation base/1653520455/1653524986_fsm
> WAL redo at 7C5B/8EC92B90 for Heap2/CLEAN: remxid 1873087613
>
>
> Eventually the cluster reached the consistent state and reported
> "ready to accept connections" but I'm wondering what could have caused
> these messages and what they are about. Googling did not bring much
> enlightenment.
>
> Most of these messages seem to be about the FSMs, but not all of them.
>
> Any ideas? Should I be worried?

The relevant code comment says that corrupted heap pages could be the cause. [0]
But searching the lists I found [1] which names the visibility map code as one
cause. But this is just a guess, I don't know if that explanation is still
valid.

[0] https://git.postgresql.org/gitweb/?p=postgresql.git;a=blob;f=src/backend/access/transam/xlog.c;h=a1ceded9e092f40e2559a020bd9675856a428edb;hb=2faab87390b03929a8cbb5a9336a04faa45a27c5#l2823
[1] https://www.postgresql.org/message-id/CAB7nPqTQkW%2BFZYQbbPBoaoge1HkQCD7gxKfGGigF6E88mvYKfw%40mail.gmail.com

> The basebackup command was very simple, I was actually making a copy
> of the running cluster for experimental purposes to another zpool:
>
> pg_basebackup -D /pg_data0/13/test2 -c fast -X stream -U repmgr -P

--
Erik