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 <[email protected]> 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

Attachment: v9-0001-Add-wait-events-for-server-logging-destination-wr.patch
Description: Binary data

Attachment: v9-0002-Add-wait-events-for-Windows-specific-logging-outp.patch
Description: Binary data

Reply via email to