Re: Add Information during standby recovery conflicts

Masahiko Sawada <masahiko.sawada@2ndquadrant.com>

From: Masahiko Sawada <masahiko.sawada@2ndquadrant.com>
To: "Drouvot, Bertrand" <bdrouvot@amazon.com>
Cc: PostgreSQL-development <pgsql-hackers@postgresql.org>
Date: 2020-08-27T08:16:35Z
Lists: pgsql-hackers
On Mon, 10 Aug 2020 at 23:43, Drouvot, Bertrand <bdrouvot@amazon.com> wrote:
>
> Hi,
>
> On 7/31/20 7:12 AM, Masahiko Sawada wrote:
> > +   tmpWaitlist = waitlist;
> > +   while (VirtualTransactionIdIsValid(*tmpWaitlist))
> > +   {
> > +       tmpWaitlist++;
> > +   }
> > +
> > +   num_waitlist_entries = (tmpWaitlist - waitlist);
> > +
> > +   /* display wal record information */
> > +   if (log_recovery_conflicts &&
> > (TimestampDifferenceExceeds(recovery_conflicts_log_time,
> > GetCurrentTimestamp(),
> > +                                   DeadlockTimeout))) {
> > +       LogBlockedWalRecordInfo(num_waitlist_entries, reason);
> > +       recovery_conflicts_log_time = GetCurrentTimestamp();
> > +   }
> >
> > recovery_conflicts_log_time is not initialized. And shouldn't we
> > compare the current timestamp to the timestamp when the startup
> > process started waiting?
> >
> > I think we should call LogBlockedWalRecordInfo() inside of the inner
> > while loop rather than at the beginning of
> > ResolveRecoveryConflictWithVirtualXIDs(). In lock conflict cases, the
> > startup process waits until 'ltime', then enters
> > ResolveRecoveryConflictWithVirtualXIDs() after reaching 'ltime'.
> > Therefore, it makes sense to call LogBlockedWalRecordInfo() at the
> > beginning of ResolveRecoveryConflictWithVirtualXIDs(). However, in
> > snapshot and tablespace conflict cases (i.g.
> > ResolveRecoveryConflictWithSnapshot() and
> > ResolveRecoveryConflictWithTablespace()), it enters
> > ResolveRecoveryConflictWithVirtualXIDs() without waits and waits for
> > reaching ‘ltime’ inside of the inner while look. So the above
> > condition could always be false.
>
> That would make the information being displayed after
> max_standby_streaming_delay is reached for the multiple cases you just
> described.

Sorry, it should be deadlock_timeout, not max_standby_streaming_delay.
Otherwise, the recovery conflict log message is printed when
resolution, which seems not to achieve the original purpose. Am I
missing something?

Regards,

-- 
Masahiko Sawada            http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services



Commits

  1. Log long wait time on recovery conflict when it's resolved.

  2. Add GUC to log long wait times on recovery conflicts.

  3. Detect the deadlocks between backends and the startup process.

  4. Get rid of the dedicated latch for signaling the startup process.

  5. Add block information in error context of WAL REDO apply loop