Thanks Michael for the review. Agree with your comment on the patch. updated the patch with recommended change.
Thanks, Vinay On Mon, Mar 11, 2024 at 1:13 PM Michael Paquier <mich...@paquier.xyz> wrote: > 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 >
0001-set-saved_timeval_set-to-false-before-executing-emit.patch
Description: Binary data
