Re: Add wait events for server logging destination writes

Hi Nik,

Thanks for building the extension case. That is the test I did not
have, and it settles the point.

On Tue, Sep 15, 2026 at 12:32 PM Nikolay Samokhvalov <nik(at)postgres(dot)ai> wrote:
> unpatched active | Extension | HarnessOuterWait
> v8 active | NULL | NULL
>
> So v8 clears the outer event after logging returns. It is not briefly
> masked; it remains lost.

Agreed, and "briefly masks" in v8 was wrong as a description of what
happens. pgstat_report_wait_end() writes 0, so once the log write has
ended its own region the outer one is gone for as long as it lasts.
The measurement in v8 only asked whether a log write is reached from
inside a region in core, and the one case it found exits right after
logging, so the loss never had a chance to show. Your extension keeps
waiting after the log call, and there it is.

> I think the new logging sites should preserve the old event, or this
> patch should wait for the general fix. The longjmp cleanup sites can
> use a separate reset helper.

v9 does the first. Every wrapped site saves the published event before
the write and puts it back afterwards, through two inline helpers added
to wait_event.h:

pgstat_report_wait_start_nested(info) publishes info and returns
what was published before
pgstat_report_wait_end_nested(outer) publishes outer again

They are start()/end() with the restore added, so they keep the same
properties: one store, no allocation, safe before MyProc exists. With
no outer region the saved value is 0 and end_nested() does exactly what
end() does. If end() ever learns to restore the previous event itself,
these two collapse back into start()/end() and nothing else changes.

I did not want to make this patch wait for the general fix. What I
have for that today is a debug-only nesting check, not a restore; a
restore inside end() means a real stack in production builds and a
look at every site that relies on end() clearing the field, which is a
bigger discussion than this patch should carry. Agreed on the reset
helper for the longjmp sites; that is how the check patch handles them.

I rebuilt your table here with a small module whose SQL-callable
function does no more than this:

uint32 outer = WaitEventExtensionNew("HarnessOuterWait");

pgstat_report_wait_start(outer);
ereport(LOG, (errmsg("harness: logging from inside HarnessOuterWait")));
pg_usleep(6 * 1000000L);
pgstat_report_wait_end();

Another session sampled pg_stat_activity 2.5 s after the call started,
that is, after ereport(LOG) had returned and while the function was
still sleeping inside its region, for each destination the patch
touches:

unpatched v8 v9
stderr, logging_collector=off HarnessOuterWait NULL HarnessOuterWait
stderr, logging_collector=on HarnessOuterWait NULL HarnessOuterWait
syslog HarnessOuterWait NULL HarnessOuterWait

(wait_event column; wait_event_type is Extension or NULL to match, and
state is active throughout.)

Changes from v8:

- wait_event.h: the two helpers above, so 0001 now touches three
files instead of two;
- elog.c: the nine wrapped calls use the nested pair instead of
start()/end(); in write_console() the WriteConsoleW() result goes
through a local so the pair is not repeated across the success and
fallback branches;
- the "briefly masks" comments are gone; write_console() carries the
explanation and the other sites point at it;
- 0001's commit message describes the extension case and the restore,
and drops the claim that the masking is brief.

v9 is attached, rebased onto current master (1a3e782e762).

v9-0001 - portable part (SysloggerWrite, StderrWrite, SyslogWrite)
v9-0002 - Windows part (WriteConsoleW plus EventlogWrite)

I checked it by:

- git am of both patches onto 1a3e782e762, clean;
- full Meson build (cassert, debug) -- no warnings;
- 0001 building on its own;
- pgindent on elog.c and wait_event.h -- no changes;
- regression, isolation and TAP suites green: 362 tests, 0 failures.
52 are skipped here, none for a reason this patch affects: 17 behind
PG_TEST_EXTRA, 17 wanting an injection-points build, 16 expensive
checksum tests, plus ICU and SSPI. (More than in v8 because master
has gained tests in those groups since.)

I still cannot run the Windows part here; cfbot will at least build
it. If a retest is convenient on your side that would be very welcome,
and if the restore is not the shape you had in mind I am happy to do
another round.

Regards,
Seongjun Shin