Обсуждение: Hot Standby startup with overflowed snapshots

Chris Redekop's recent report of slow startup for Hot Standby has made
me revisit the code there.

Although there isn't a bug, there is a missed opportunity for starting
up faster which could be the source of Chris' annoyance.

The following patch allows a faster startup in some circumstances.

The patch also alters the log levels for messages and gives a single
simple message for this situation. The log will now say

  LOG:  recovery snapshot waiting for non-overflowed snapshot or until
oldest active xid on standby is at least %u (now %u)
  ...multiple times until snapshot non-overflowed or xid reached...

whereas before the first LOG message shown was

  LOG:  consistent state delayed because recovery snapshot incomplete
  and only later, at DEBUG2 do you see
  LOG:  recovery snapshot waiting for %u oldest active xid on standby is %u
  ...multiple times until xid reached...

Comments please.

--
 Simon Riggs                   http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services

On Thu, Oct 27, 2011 at 5:26 PM, Chris Redekop <chris@replicon.com> wrote:

> Thanks for the patch Simon, but unfortunately it does not resolve the issue
> I am seeing.  The standby still refuses to finish starting up until long
> after all clients have disconnected from the primary (>10 minutes).  I do
> see your new log statement on startup, but only once - it does not repeat.
>  Is there any way for me to see  what the oldest xid on the standby is via
> controldata or something like that?  The standby does stream to keep up with
> the primary while the primary has load, and then it becomes idle when the
> primary becomes idle (when I kill all the connections)....so it appears to
> be current...but it just doesn't finish starting up
> I'm not sure if it's relevant, but after it has sat idle for a couple
> minutes I start seeing these statements in the log (with the same offset
> every time):
> DEBUG:  skipping restartpoint, already performed at 9/95000020

OK, so it looks like there are 2 opportunities to improve, not just one.

Try this.

--
 Simon Riggs                   http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services

On Thu, Oct 27, 2011 at 10:09 PM, Chris Redekop <chris@replicon.com> wrote:

> hrmz, still basically the same behaviour.  I think it might be a *little*
> better with this patch.  Before when under load it would start up quickly
> maybe 2 or 3 times out of 10 attempts....with this patch it might be up to 4
> or 5 times out of 10...ish...or maybe it was just fluke *shrug*.  I'm still
> only seeing your log statement a single time (I'm running at debug2).  I
> have discovered something though - when the standby is in this state if I
> force a checkpoint on the primary then the standby comes right up.  Is there
> anything I check or try for you to help figure this out?....or is it
> actually as designed that it could take 10-ish minutes to start up even
> after all clients have disconnected from the primary?

Thanks for testing. The improvements cover specific cases, so its not
subject to chance; its not a performance patch.

It's not "designed" to act the way you describe, but it does.

The reason this occurs is that you have a transaction heavy workload
with occasional periods of complete quiet and a base backup time that
is much less than checkpoint_timeout. If your base backup was slower
the checkpoint would have hit naturally before recovery had reached a
consistent state. Which seems fairly atypical. I guess you're doing
this on a test system.

It seems cheap to add in a call to LogStandbySnapshot() after each
call to pg_stop_backup().

Does anyone think this case is worth adding code for? Seems like one
more thing to break.

--
 Simon Riggs                   http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services

On Thu, Oct 27, 2011 at 6:55 PM, Simon Riggs <simon@2ndquadrant.com> wrote:
> It seems cheap to add in a call to LogStandbySnapshot() after each
> call to pg_stop_backup().
>
> Does anyone think this case is worth adding code for? Seems like one
> more thing to break.

Why at that particular time?

It would maybe nice if the master could notice when it has a plausible
(non-overflowed) snapshot and log it then.  But that might be more
code than the problem is worth.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

On Fri, Oct 28, 2011 at 3:42 AM, Chris Redekop <chris@replicon.com> wrote:

> On a side note I am sporadically seeing another error on hotstandby startup.
>  I'm not terribly concerned about it as it is pretty rare and it will work
> on a retry so it's not a big deal.  The error is "FATAL:  out-of-order XID
> insertion in KnownAssignedXids".  If you think it might be a bug and are
> interested in hunting it down let me know and I'll help any way I can...but
> if you're not too worried about it then neither am I :)

I'd be interested to see further details of this if you see it again,
or have access to previous logs.

--
 Simon Riggs                   http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services