pg.ddx.io pgsql-admin@postgresql.org mailing list archive
help / color / mirror / Atom feedxlog min recovery request 7C5C/96D5C550 is past current point
3+ messages / 2 participants
[nested] [flat]
* xlog min recovery request 7C5C/96D5C550 is past current point
@ 2023-05-28 11:45 Victor Sudakov <vas@sibptus.ru>
0 siblings, 1 reply; 3+ messages in thread
From: Victor Sudakov @ 2023-05-28 11:45 UTC (permalink / raw)
To: pgsql-admin@lists.postgresql.org
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 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
--
Victor Sudakov VAS4-RIPE
http://vas.tomsk.ru/
2:5005/49@fidonet
^ permalink raw reply [nested|flat] 3+ messages in thread
* Re: xlog min recovery request 7C5C/96D5C550 is past current point
@ 2023-05-30 19:26 Erik Wienhold <ewie@ewie.name>
parent: Victor Sudakov <vas@sibptus.ru>
0 siblings, 1 reply; 3+ messages in thread
From: Erik Wienhold @ 2023-05-30 19:26 UTC (permalink / raw)
To: Victor Sudakov <vas@sibptus.ru>; pgsql-admin@lists.postgresql.org
> On 28/05/2023 13:45 CEST Victor Sudakov <vas@sibptus.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=a1c...
[1] https://www.postgresql.org/message-id/CAB7nPqTQkW%2BFZYQbbPBoaoge1HkQCD7gxKfGGigF6E88mvYKfw%40mail.g...
> 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
^ permalink raw reply [nested|flat] 3+ messages in thread
* Re: xlog min recovery request 7C5C/96D5C550 is past current point
@ 2023-06-02 08:11 Victor Sudakov <vas@sibptus.ru>
parent: Erik Wienhold <ewie@ewie.name>
0 siblings, 0 replies; 3+ messages in thread
From: Victor Sudakov @ 2023-06-02 08:11 UTC (permalink / raw)
To: pgsql-admin@lists.postgresql.org
Erik Wienhold wrote:
> > On 28/05/2023 13:45 CEST Victor Sudakov <vas@sibptus.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=a1c...
> [1] https://www.postgresql.org/message-id/CAB7nPqTQkW%2BFZYQbbPBoaoge1HkQCD7gxKfGGigF6E88mvYKfw%40mail.g...
Thanks for the links, and wow! If it is still the same problem it must
be at least 9 years old and noone has fixed it.
BTW seeing the messages not only about VM's, but about FSM's as well.
I only have to trust that these messages are indeed harmless. After
all, AFAIR VMs and FSMs will be rebuilt by autovacuum sooner or later.
--
Victor Sudakov VAS4-RIPE
http://vas.tomsk.ru/
2:5005/49@fidonet
^ permalink raw reply [nested|flat] 3+ messages in thread
end of thread, other threads:[~2023-06-02 08:11 UTC | newest]
Thread overview: 3+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2023-05-28 11:45 xlog min recovery request 7C5C/96D5C550 is past current point Victor Sudakov <vas@sibptus.ru>
2023-05-30 19:26 ` Erik Wienhold <ewie@ewie.name>
2023-06-02 08:11 ` Victor Sudakov <vas@sibptus.ru>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox