Re: Add wait events for server logging destination writes

Hi Seongjun,

Thanks for the patch -- I picked this up as the registered reviewer.

Since the patch just brackets the existing log writes with
pgstat_report_wait_start()/end(), I started by pinning down what those
two do.

Each is a single store through my_wait_event_info -- start writes the
event id, end unconditionally writes 0 -- and the pointer is statically
initialized to &local_my_wait_event_info, so it is never NULL.

A normal or aux backend later repoints it at shared memory
(MyProc->wait_event_info) in InitProcess()/InitAuxiliaryProcess(); the
postmaster and other pre-PGPROC contexts never do, and keep writing to
the local dummy.

The read side is asymmetric: no code reads the my_wait_event_info
pointer itself; pg_stat_activity has another backend read the target
backend's MyProc->wait_event_info (shared memory) directly
(pgstatfuncs.c).

So pgstat_report_wait_start()/end() only set and clear an integer and
are safe in themselves; for this patch the only thing left to review is
whether the instrumentation is placed correctly.

The patch adds four wait events. The start/end pairing is fine, so I
checked whether each event matches what it actually instruments and what
the wait_event_names.txt description claims, one by one:

- SYSLOG_WRITE -- "Waiting for a write to the system logger (syslog)."
write_syslog() instruments the libc syslog() call to the OS syslog
daemon. Target and description match.
- EVENTLOG_WRITE -- "Waiting for a write to the Windows event log."
write_eventlog() instruments ReportEventW/A, i.e. the Windows event
log write. Accurate. (The instrumentation is WIN32-only, but the name
is exposed in the catalog on all platforms; the description says
"Windows", so there's no confusion.)
- STDERR_WRITE -- "Waiting for a write to the server's standard error
stream."
write_console() instruments the stderr write. Matches.
- SYSLOGGER_WRITE -- "Waiting for a write to the syslogger pipe."
write_pipe_chunks() instruments the backend->pipe write. The
description is scoped to "pipe", so it is literally accurate.

In short, setting aside scope changes such as adding or removing events,
I agree on the correctness of where the instrumentation is placed (the
code) and of the per-event descriptions (the message).

On the single-slot point Andrey raised: I agree it is real -- a log line
emitted while an unrelated outer wait event is already set will have
these events overwrite that slot and then zero it
(pgstat_report_wait_end writes 0 unconditionally). In
practice, though, core has essentially no place where a *returning* LOG
is emitted while a distinct outer event is set: most waits are bracketed
inside WaitEventSetWait and the log line comes out after it returns, and
the one spot that does log with its own event still set
(AddToDataDirLockFile) runs in the postmaster, where no outer event is
present, so it is harmless.

It is a property of the single-slot mechanism rather than something
specific to this patch, so the comment you plan to add at the wrapped
sites in v5 looks right. If it were to be handled in general, your own
"report only when the slot is 0" idea could be generalized with a small
depth counter -- set on 0->1, clear on 1->0 -- to preserve the outer
event. But that makes the nested logging wait invisible and touches the
mechanism broadly, so it belongs in a separate change rather than this
patch.

Thanks for working on this.

Regards,
Henson