Re: [HACKERS] Hot Standby startup with overflowed snapshots
On Fri, Oct 28, 2011 at 3:42 AM, Chris Redekop ch...@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 -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Hot Standby startup with overflowed snapshots
oopsreply-to-all -- Forwarded message -- From: Chris Redekop ch...@replicon.com Date: Wed, Nov 2, 2011 at 8:41 AM Subject: Re: [HACKERS] Hot Standby startup with overflowed snapshots To: Simon Riggs si...@2ndquadrant.com Sure, I've got quite a few logs lying around - I've attached 3 of 'em...let me know if there are any specific things you'd like me to do or look for next time it happens On Wed, Nov 2, 2011 at 2:59 AM, Simon Riggs si...@2ndquadrant.com wrote: On Fri, Oct 28, 2011 at 3:42 AM, Chris Redekop ch...@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 postgresql-2011-10-27_202007.log Description: Binary data postgresql-2011-10-31_152925.log Description: Binary data postgresql-2011-11-01_094501.log Description: Binary data -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Hot Standby startup with overflowed snapshots
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/9520 On Thu, Oct 27, 2011 at 7:26 AM, Simon Riggs si...@2ndquadrant.com wrote: 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 -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Hot Standby startup with overflowed snapshots
On Thu, Oct 27, 2011 at 5:26 PM, Chris Redekop ch...@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/9520 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 faster_hot_standby_startup_withsubxacts.v2.patch Description: Binary data -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Hot Standby startup with overflowed snapshots
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 attemptswith 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? On Thu, Oct 27, 2011 at 11:27 AM, Simon Riggs si...@2ndquadrant.com wrote: On Thu, Oct 27, 2011 at 5:26 PM, Chris Redekop ch...@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/9520 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
Re: [HACKERS] Hot Standby startup with overflowed snapshots
On Thu, Oct 27, 2011 at 10:09 PM, Chris Redekop ch...@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 attemptswith 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 -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Hot Standby startup with overflowed snapshots
Sorry...designed was poor choice of words, I meant not unexpected. Doing the checkpoint right after pg_stop_backup() looks like it will work perfectly for me, so thanks for all your help! 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 :) On Thu, Oct 27, 2011 at 4:55 PM, Simon Riggs si...@2ndquadrant.com wrote: On Thu, Oct 27, 2011 at 10:09 PM, Chris Redekop ch...@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 attemptswith 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
Re: [HACKERS] Hot Standby startup with overflowed snapshots
On Thu, Oct 27, 2011 at 6:55 PM, Simon Riggs si...@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 -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
