Re: Add Information during standby recovery conflicts

Drouvot, Bertrand <bdrouvot@amazon.com>

From: "Drouvot, Bertrand" <bdrouvot@amazon.com>
To: Masahiko Sawada <sawada.mshk@gmail.com>
Cc: Alvaro Herrera <alvherre@alvh.no-ip.org>, Fujii Masao <masao.fujii@oss.nttdata.com>, Masahiko Sawada <masahiko.sawada@2ndquadrant.com>, Kyotaro Horiguchi <horikyota.ntt@gmail.com>, PostgreSQL-development <pgsql-hackers@postgresql.org>
Date: 2020-11-30T06:45:59Z
Lists: pgsql-hackers

Attachments

Hi,

On 11/30/20 4:41 AM, Masahiko Sawada wrote:
> On Sun, Nov 29, 2020 at 3:47 PM Drouvot, Bertrand <bdrouvot@amazon.com> wrote:
>> Hi Alvaro,
>>
>> On 11/28/20 6:36 PM, Alvaro Herrera wrote:
>>> Hi Bertrand,
>>>
>>> On 2020-Nov-28, Drouvot, Bertrand wrote:
>>>
>>>> +             if (nprocs > 0)
>>>> +             {
>>>> +                     ereport(LOG,
>>>> +                                     (errmsg("recovery still waiting after %ld.%03d ms: %s",
>>>> +                                                     msecs, usecs, _(get_recovery_conflict_desc(reason))),
>>>> +                                      (errdetail_log_plural("Conflicting process: %s.",
>>>> +                                                                                "Conflicting processes: %s.",
>>>> +                                                                                nprocs, buf.data))));
>>>> +             }
>>>> +             else
>>>> +             {
>>>> +                     ereport(LOG,
>>>> +                                     (errmsg("recovery still waiting after %ld.%03d ms: %s",
>>>> +                                                     msecs, usecs, _(get_recovery_conflict_desc(reason)))));
>>>> +             }
>>>> +
>>>> +             pfree(buf.data);
>>>> +     }
>>>> +     else
>>>> +             ereport(LOG,
>>>> +                             (errmsg("recovery still waiting after %ld.%03d ms: %s",
>>>> +                                             msecs, usecs, _(get_recovery_conflict_desc(reason)))));
>>>> +}
>>> Another trivial stylistic point is that you can collapse all these
>>> ereport calls into one, with something like
>>>
>>>     ereport(LOG,
>>>             errmsg("recovery still waiting after ...", opts),
>>>             waitlist != NULL ? errdetail_log_plural("foo bar baz", opts) : 0);
>>>
>>> where the "waitlist" has been constructed beforehand, or is set to NULL
>>> if there's no process list.
>> Nice!
>>
>>>> +     switch (reason)
>>>> +     {
>>>> +             case PROCSIG_RECOVERY_CONFLICT_BUFFERPIN:
>>>> +                     reasonDesc = gettext_noop("for recovery conflict on buffer pin");
>>>> +                     break;
>>> Pure bikeshedding after discussing this with my pillow: I think I'd get
>>> rid of the initial "for" in these messages.
>> both comments implemented in the new attached version.
>>
> Thank you for updating the patch!
>
> +       /* Also, set deadlock timeout for logging purpose if necessary */
> +       if (log_recovery_conflict_waits && !need_log)
> +       {
> +           timeouts[cnt].id = STANDBY_TIMEOUT;
> +           timeouts[cnt].type = TMPARAM_AFTER;
> +           timeouts[cnt].delay_ms = DeadlockTimeout;
> +           cnt++;
> +       }
>
> You changed to 'need_log' but this condition seems not correct. I
> think we need to set this timeout when both log_recovery_conflict and
> need_log is true.

Nice catch!

In fact it behaves correctly, that's jut the 'need_log' name that is 
miss leading: I renamed it to 'already_logged' in the new attached version.

> The rest of the patch looks good to me.

Great!

Thanks

Bertrand

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