Re: Hot Backup with rsync fails at pg_clog if under load

On Fri, Sep 23, 2011 at 9:45 AM, Robert Haas <robertmhaas(at)gmail(dot)com> wrote:
> On Fri, Sep 23, 2011 at 11:43 AM, Aidan Van Dyk <aidan(at)highrise(dot)ca> wrote:
>> On Fri, Sep 23, 2011 at 4:41 AM, Heikki Linnakangas
>> <heikki(dot)linnakangas(at)enterprisedb(dot)com> wrote:
>>
>>>> Unfortunately, it's impossible, because the error message "Could not read
>>>> from file "pg_clog/0001" at offset 32768: Success" is shown (and startup
>>>> aborted) before the turn for "redo starts at" message arrives.
>>>
>>> It looks to me that pg_clog/0001 exists, but it shorter than recovery
>>> expects. Which shouldn't happen, of course, because the start-backup
>>> checkpoint should flush all the clog that's needed by recovery to disk
>>> before the backup procedure begins to them.
>>
>> I think the point here is that recover *never starts*.  Something in
>> the standby startup is looking for a value in a clog block that
>> recovery hadn't had a chance to replay (produce) yet.
>
> Ah.  I think you are right - Heikki made the same point.  Maybe some
> of the stuff that happens just after this comment:
>
>        /*
>         * Initialize for Hot Standby, if enabled. We won't let backends in
>         * yet, not until we've reached the min recovery point specified in
>         * control file and we've established a recovery snapshot from a
>         * running-xacts WAL record.
>         */
>
>
> ...actually needs to be postponed until after we've reached consistency?

We have a number of backups that are like this, and the problem is
entirely reproducible for those. We always get around it by disabling
hot standby for a while (until consistency is reached) I poked at
xlog.c a bit, and to me seems entirely likely that StartupCLOG is
being called early -- way too early, or at least parts of it.
Presumably(?) it is being called so early in the hot standby path so
that the status of transactions can be known for the purposes of
querying, but it's happening before consistency is reached, ergo not
many invariants (outside of checkpointed things like pg_controldata)
are likely to hold...such as clog being the right size to locate the
transaction status of a page.

Anyway, sorry for dropping the ball on pushing that one; we've been
using this workaround for a while after taking a look at the mechanism
and deciding it was probably not a problem (except for a sound night's
sleep). We've now seen this dozens of times.

--
fdr