Re: xlog min recovery request ... is past current point ... - Mailing list pgsql-hackers

From Heikki Linnakangas
Subject Re: xlog min recovery request ... is past current point ...
Date
Msg-id 4F53C562.5060402@enterprisedb.com
Whole thread Raw
In response to xlog min recovery request ... is past current point ...  (Christophe Pettus <xof@thebuild.com>)
Responses Re: xlog min recovery request ... is past current point ...  (Robert Haas <robertmhaas@gmail.com>)
List pgsql-hackers
On 03.02.2012 18:32, Christophe Pettus wrote:
> PostgreSQL 9.0.4:
>
> While bringing up a streaming replica, and while it is working its way through the WAL segments before connecting to
theprimary, I see a lot of messages of the form:
 
>
> 2012-02-01 21:26:13.978 PST,,,24448,,4f2a1e61.5f80,54,,2012-02-01 21:25:53 PST,1/0,0,LOG,00000,"restored log file
""0000000100000DB400000065""from archive",,,,,,,,,""
 
> 2012-02-01 21:26:14.032 PST,,,24448,,4f2a1e61.5f80,55,,2012-02-01 21:25:53 PST,1/0,0,WARNING,01000,"xlog min recovery
requestDB5/42E15098 is past current point DB4/657FA490",,,,,"writing block 5 of relation base/155650/156470_vm
 
> xlog redo insert: rel 1663/155650/1658867; tid 9640/53",,,,""
> 2012-02-01 21:26:14.526 PST,,,24448,,4f2a1e61.5f80,56,,2012-02-01 21:25:53 PST,1/0,0,LOG,00000,"restored log file
""0000000100000DB400000066""from archive",,,,,,,,,""
 
>
> All of these are on _vm relations.  The recovery completed successfully and the secondary connected to the primary
withoutissue, so: Are these messages something to be concerned over?
 

Hmm, I think I see how that can happen:

0. A heap page has its bit set in visibility map to begin with

1. A heap tuple is inserted/updated/deleted. This clears the VM bit.
2. time passes, and more WAL is generated
3. The page is vacuumed, and the visibility map bit is set again.

In the standby, this can happen while replaying the WAL, if you restart 
the standby so that some WAL is re-replayed:

1. The update of the heap tuple is replayed. This clears the VM bit.
2. The VACUUM is replayed, setting the VM bit again, and updating the VM 
page's LSN.
3. Shutdown and restart standby
4. The heap update is replayed again. This again clears the VM bit, but 
does not set the LSN

If the VM page is now evicted from the buffer cache, you get the WARNING 
you saw, because the page is dirty, yet its LSN is beyond the current 
point in recovery.

AFAICS that's totally harmless, but the warning is quite alarming, so 
we'll have to figure out a way to fix that. Not sure how; perhaps we 
need to set the LSN on the VM page when the VM bit is cleared, but I 
don't remember off the top of my head if there was some important reason 
why we don't do that currently.

--   Heikki Linnakangas  EnterpriseDB   http://www.enterprisedb.com


pgsql-hackers by date:

Previous
From: Pavel Stehule
Date:
Subject: Re: review: CHECK FUNCTION statement
Next
From: Tom Lane
Date:
Subject: Re: Our regex vs. POSIX on "longest match"