public inbox for [email protected]  

help / color / mirror / Atom feed

From: Michael Paquier <[email protected]>
To: Kambam Vinay <[email protected]>
Cc: [email protected]
Subject: Re: Fix for timestamp lag issue from emit_log_hook when GUC log_line_prefix has '%m'
Date: Mon, 11 Mar 2024 16:43:06 +0900
Message-ID: <[email protected]> (raw)
In-Reply-To: <CANiRfmsK36A0i8mnQtzaxhSm3CUCimPwJPp4WQNq53OdSNkgWg@mail.gmail.com>
References: <CANiRfmsK36A0i8mnQtzaxhSm3CUCimPwJPp4WQNq53OdSNkgWg@mail.gmail.com>

On Sat, Mar 09, 2024 at 09:09:39PM +0530, Kambam Vinay wrote:
> We observed a slight lag in timestamp for a few logs from the emit_log_hook
> hook implementation when the log_line_prefix GUC has '%m'.
> 
> Upon debugging, we found that the saved_timeval_set variable is set to
> 'true' in get_formatted_log_time() but is not reset to 'false' until the
> next call to send_message_to_server_log(). Due to this, saved_timeval_set
> will be true during the execution of hook emit_log_hook() which prefixes
> the saved timestamp 'saved_timeval' from the previous log line (our hook
> implementation calls log_line_prefix()).
> 
> Attached patch sets the saved_timeval_set to false before executing the
> emit_log_hook()

Indeed.  If you rely on log_line_prefix() in your hook before the
server side elog, the saved timestamp would not match with what could
be computed in the follow-up send_message_to_server_log or
send_message_to_frontend.

Hmm.  Shouldn't we remove the forced reset of formatted_log_time for
the 'm' case in log_status_format() and remove the reset done at the
beginning of send_message_to_server_log()?  One problem with your
patch is that we would still finish with a different saved_timeval in
the hook and in send_message_to_server_log(), but we should do things
so as the timestamps are the same for the whole duration of
EmitErrorReport(), no?  It seems to me that a more correct solution
would be to reset saved_timeval_set and formatted_log_time[0] once
before the hook, at the beginning of EmitErrorReport().
--
Michael


Attachments:

  [application/pgp-signature] signature.asc (833B, ../[email protected]/2-signature.asc)
  download

view thread (6+ messages)  latest in thread

reply

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Reply to all the recipients using the --to and --cc options:
  reply via email

  To: [email protected]
  Cc: [email protected], [email protected]
  Subject: Re: Fix for timestamp lag issue from emit_log_hook when GUC log_line_prefix has '%m'
  In-Reply-To: <[email protected]>

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox