Add wait events for server logging destination writes

Hi,

cfbot caught a build failure on v1, in the SanityCheck task on Linux
and Windows: elog.c uses pgstat_report_wait_start()/end() and the
WAIT_EVENT_* constants but didn't include utils/wait_event.h. It only
built here because of an accidental transitive include on my machine;
on the CI images the declarations weren't visible.

v2 fixes that by adding the missing #include "utils/wait_event.h" to
elog.c, folded into 0001 so that patch builds on its own. No other
changes; the wait events and the reported write paths are the same as
in v1.

v2-0001 adds the two events and covers the write(2) paths.
v2-0002 covers the Windows WriteConsoleW() path, split out as before.

Applies cleanly on current master; full build passes locally.

Thanks,
Seongjun Shin

2026년 5월 31일 (일) 오후 5:50, 신성준 <shinsj4653@gmail.com>님이 작성:

On Sun, May 31, 2026 at 4:50 AM 신성준 <shinsj4653@gmail.com> wrote:

Hi hackers,

The write(2) calls that flush server log output aren't covered by wait
events. When a backend logs something, the writes go out in:

- write_pipe_chunks(): write(2) to the syslogger pipe
- write_console(): write(2) to stderr (WriteConsoleW() on Windows)

If one of those blocks -- syslogger pipe full, slow console, slow log
device -- pg_stat_activity just shows wait_event = NULL until it
returns. Since NULL usually reads as "on CPU", a backend stuck writing
logs looks like it's doing work, so logging-related stalls are easy to
miss.

Attached is a short series that adds two WaitEventIO events and reports
them around those writes:

IO / SysloggerWrite - write(2) to the syslogger pipe
IO / StderrWrite - write(2) to stderr, and WriteConsoleW()

0001 adds the events and covers the write(2) paths. 0002 does the
Windows WriteConsoleW() path, split out since it's platform-specific.

It only wraps the leaf write call and uses the existing
pgstat_report_wait_start()/end() helpers, so it stays allocation-free
and safe to call from inside the error-reporting path.

I did a quick before/after to make sure the events show up: 8 backends
each emitting large RAISE LOG lines, sampling wait_event from
pg_stat_activity every 50 ms for 20 s.

- logging_collector = on (syslogger pipe):
master: NULL 100.0% (2184/2184)
patched: IO/SysloggerWrite 99.1% (2204/2224), NULL 0.9%

- logging_collector = off (stderr):
master: NULL 100.0% (2144/2144)
patched: IO/StderrWrite 90.7% (1952/2152), NULL 9.3%

On master that wait time is just invisible; with the patch it lands on
the new events. I can send the scripts and raw samples if anyone wants
to reproduce it.

+1
Nice. We have too many waits that are registered as CPU.

On Sun, May 31, 2026 at 07:42:41PM +0900, 신성준 wrote:

cfbot caught a build failure on v1, in the SanityCheck task on Linux
and Windows: elog.c uses pgstat_report_wait_start()/end() and the
WAIT_EVENT_* constants but didn't include utils/wait_event.h. It only
built here because of an accidental transitive include on my machine;
on the CI images the declarations weren't visible.

v2 fixes that by adding the missing #include "utils/wait_event.h" to
elog.c, folded into 0001 so that patch builds on its own. No other
changes; the wait events and the reported write paths are the same as
in v1.

v2-0001 adds the two events and covers the write(2) paths.
v2-0002 covers the Windows WriteConsoleW() path, split out as before.

Applies cleanly on current master; full build passes locally.

Hmm. Usually we split the event numbers so as there is one for each
code path, but here we are just dealing with the same routine that
sends chunks. Using the same numbers seem fine by me.

If others have any thoughts or comments, feel free.
--
Michael

Hello.

At Sun, 31 May 2026 17:50:08 +0900, 신성준 <shinsj4653@gmail.com> wrote in

Attached is a short series that adds two WaitEventIO events and reports
them around those writes:

IO / SysloggerWrite - write(2) to the syslogger pipe
IO / StderrWrite - write(2) to stderr, and WriteConsoleW()

0001 adds the events and covers the write(2) paths. 0002 does the
Windows WriteConsoleW() path, split out since it's platform-specific.

Should we also consider instrumenting ReportEventW()/ReportEventA()?
They seem to be another Windows-specific logging output path.

Also, if the intention is to cover all places where logging output can
block, I wonder whether the syslog() calls should be covered as
well. If they are intentionally excluded, perhaps a short comment
explaining the rationale would be useful.

Regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

Hi,

Thanks Kirk, glad it's useful.

Kyotaro Horiguchi wrote:

Should we also consider instrumenting ReportEventW()/ReportEventA()?
They seem to be another Windows-specific logging output path.

Also, if the intention is to cover all places where logging output
can block, I wonder whether the syslog() calls should be covered as
well.

Good points -- both are blocking output paths and there's no real
reason to leave them out, so v3 instruments them rather than excluding
them with a comment. The intent is exactly to cover the places where
logging output can block, so this makes the series consistent.

v3 adds two more WaitEventIO events:

IO / SyslogWrite - syslog(3) in write_syslog()
IO / EventlogWrite - ReportEventW()/ReportEventA() in write_eventlog()

Same approach as before: the wait is reported only around the leaf
call, using the existing pgstat_report_wait_start()/end() helpers, so
it stays allocation-free and safe on the error-reporting path, and the
series still touches just elog.c and wait_event_names.txt.

This also matches Michael's point on v2 -- each event covers a routine
rather than a single call site, so SyslogWrite wraps the syslog(3)
calls in write_syslog() and EventlogWrite wraps both ReportEvent
variants in write_eventlog(), the same way SysloggerWrite already
covers the two writes in write_pipe_chunks().

As before, 0001 is the portable part and 0002 is the Windows part
(WriteConsoleW plus the new EventlogWrite).

One caveat: EventlogWrite is Windows-only, so I couldn't get a runtime
before/after for it here -- I've only confirmed it builds (cfbot's
Windows task should cover that). The other events still show up in the
sampling I posted earlier. If someone on Windows can exercise the
event-log path I'd appreciate a confirmation.

Applies cleanly on current master; full build passes locally on both
Autoconf and Meson, with no new warnings.

Thanks,
Seongjun Shin

2026년 6월 1일 (월) 오후 2:49, Kyotaro Horiguchi <horikyota.ntt@gmail.com>님이 작성:

Hi,

cfbot flagged v3 as needing a rebase -- it stopped applying after the
recent changes to elog.c (the switch to a const WCHAR pointer in
write_eventlog(), pgindent, etc.) and the new COPY pipe wait events in
wait_event_names.txt.

v4 is the same change rebased over current master, no functional
difference from v3. The only real conflict was in write_eventlog(),
where the EventlogWrite wrapping now sits on top of the const
utf16_const pointer; everything else merged cleanly.

Still applies as two patches:
v4-0001 - portable part (SysloggerWrite, StderrWrite, SyslogWrite)
v4-0002 - Windows part (WriteConsoleW plus EventlogWrite)

Builds clean on current master with both Autoconf and Meson, no new
warnings.

Thanks,
Seongjun Shin

2026년 6월 7일 (일) 오전 1:25, 신성준 <shinsj4653@gmail.com>님이 작성:

On 6 Jun 2026, at 21:52, 신성준 <shinsj4653@gmail.com> wrote:

Hi Seongjun,

Naming is a hard thing. Anyone who can tell syslog from syslogger
without checking man is probably a computer themselves.

+1: a blocking logging write shows as wait_event IS NULL today, which
most tools read as on-CPU. This is very real for us. In our managed
Postgres the root filesystem that holds the logs sits on slow
network-backed HDD, so when the syslogger pipe backs up the backends
stall on the log write and the whole node looks like a CPU overload.
This patch would have made that directly visible.

Worth a line in the commit message: the call that actually blocks on a
slow log device is write_syslogger_file() in the syslogger, which has no
shared memory and isn't in pg_stat_activity. It surfaces on backends as
the pipe fills and they block on the pipe write (SysloggerWrite), so
the backend side is the right, visible layer.

One thing worth checking: wait events are single-slot by design (no
nesting - discussed back in 2016 [0]/messages/by-id/CANP8+jKsS6SDo011AUWrLdBcBMv0KJha69t7eFGqEtqx9FVfag@mail.gmail.com), and pgstat_report_wait_end()
just writes 0. So if any ereport() path runs while a wait event is
already set, instrumenting the logging write here clobbers that outer
event. Probably rare, but I'm not sure it never happens.

EventlogWrite necessarily shows up in the event list on all platforms
(the generator has no per-platform gating), but the description already
says "Windows event log", so that seems fine...

Thanks for working on this!

Best regards, Andrey Borodin.

[0]: /messages/by-id/CANP8+jKsS6SDo011AUWrLdBcBMv0KJha69t7eFGqEtqx9FVfag@mail.gmail.com

Hi Andrey,

+1: a blocking logging write shows as wait_event IS NULL today, which most
tools read as on-CPU. This is very real for us. In our managed Postgres the
root filesystem that holds the logs sits on slow network-backed HDD, so when
the syslogger pipe backs up the backends stall on the log write and the whole
node looks like a CPU overload. This patch would have made that directly
visible.

Thanks for the review, and for the production example. That node-looks-like-a-
CPU-overload case is exactly what this is meant to make visible.

Worth a line in the commit message: the call that actually blocks on a slow
log device is write_syslogger_file() in the syslogger, which has no shared
memory and isn't in pg_stat_activity. It surfaces on backends as the pipe
fills and they block on the pipe write (SysloggerWrite), so the backend side
is the right, visible layer.

Agreed. In v5 I'll add that to the commit message, and a short code comment to
the same effect: the syslogger does the file write in write_syslogger_file()
and isn't in pg_stat_activity, so the backend-side SysloggerWrite is where the
stall becomes visible.

Naming is a hard thing. Anyone who can tell syslog from syslogger without
checking man is probably a computer themselves.

Fair. I kept each name aligned with the routine it wraps, and the descriptions
spell out the difference, so I'd lean toward leaving them unless others object.

One thing worth checking: wait events are single-slot by design (no nesting -
discussed back in 2016 [0]), and pgstat_report_wait_end() just writes 0. So
if any ereport() path runs while a wait event is already set, instrumenting
the logging write here clobbers that outer event. Probably rare, but I'm not
sure it never happens.

Right about the mechanism. pgstat_report_wait_end() unconditionally writes 0,
so a log message emitted while an outer wait event is set would briefly mask
that event until the outer code reports its own end.

Two things, though. First, this is a pre-existing property of the subsystem,
not something the patch introduces: every pgstat_report_wait_start()/end() pair
behaves this way, and as the 2016 thread you linked concluded, the single
unsynchronized write is what keeps the mechanism cheap enough to stay on by
default, so nesting was deliberately left out. The patch follows that
convention rather than diverging from it. Second, the wrapped regions are tight
and log output is normally emitted outside them, so the overlap window should
be rare in practice, though I agree it isn't provably never.

So I'd prefer not to add save/restore here, since that would diverge from what
the rest of the tree relies on. I'll add a brief comment at these sites noting
the single-slot behavior. If reviewers would rather have a guard, a minimal
option that stays within the single-write model is to report the logging event
only when the slot is currently 0, which preserves the outer event at the cost
of not showing the logging write while nested. Happy to go that way if that's
the consensus.

EventlogWrite necessarily shows up in the event list on all platforms (the
generator has no per-platform gating), but the description already says
"Windows event log", so that seems fine...

Agreed, I'll leave it as-is.

I'll hold v5 until Nikolay's Linux and Windows testing comments land too, so I
can fold everything into one revision.

Thanks again,
Seongjun

2026년 6월 15일 (월) 오전 3:49, Andrey Borodin <x4mmm@yandex-team.ru>님이 작성:

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

Hi Henson,

Thanks for the review, and for tracing through
pgstat_report_wait_start()/end() first -- once the helpers are just a
single store, placement is the only thing left to check, and thanks for
going through all four events against their descriptions.

the comment you plan to add at the wrapped sites in v5 looks right
[...] it belongs in a separate change rather than this patch.

Agreed. v5 adds that comment and leaves any general depth-counter
handling out.

v5 folds in the review:

- a short comment at each wrapped site noting the single-slot
behavior;
- Andrey's commit-message point that the real blocking call is
write_syslogger_file() in the syslogger (no PGPROC, not in
pg_stat_activity), so the backend-side SysloggerWrite is where the
stall shows up -- now in the 0001 commit message and a comment on
write_pipe_chunks().

No functional change from v4.

I'd said I'd hold v5 for platform testing, but since the review has
landed I'd rather post it than sit on the thread. Testing is still
welcome, especially the Windows EventlogWrite path -- cfbot confirms it
builds, but I can't exercise the runtime event-log write here. I'll fold
anything that turns up into a follow-up.

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

Applies on current master; builds clean under Autoconf and Meson.

Thanks again,
Seongjun Shin

On Tue, Jun 30, 2026 at 10:02 AM 신성준 <shinsj4653@gmail.com> wrote:

Hi Henson,

Thanks for the review, and for tracing through
pgstat_report_wait_start()/end() first -- once the helpers are just a
single store, placement is the only thing left to check, and thanks for
going through all four events against their descriptions.

the comment you plan to add at the wrapped sites in v5 looks right
[...] it belongs in a separate change rather than this patch.

Agreed. v5 adds that comment and leaves any general depth-counter
handling out.

v5 folds in the review:

- a short comment at each wrapped site noting the single-slot
behavior;
- Andrey's commit-message point that the real blocking call is
write_syslogger_file() in the syslogger (no PGPROC, not in
pg_stat_activity), so the backend-side SysloggerWrite is where the
stall shows up -- now in the 0001 commit message and a comment on
write_pipe_chunks().

No functional change from v4.

I'd said I'd hold v5 for platform testing, but since the review has
landed I'd rather post it than sit on the thread. Testing is still
welcome, especially the Windows EventlogWrite path -- cfbot confirms it
builds, but I can't exercise the runtime event-log write here. I'll fold
anything that turns up into a follow-up.

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

Applies on current master; builds clean under Autoconf and Meson.

Thanks again,
Seongjun Shin

Hi Seongjun,

(I reviewed and tested v4 back in June but never sent the results;
now doing it for v5.)

I ran runtime tests of this patch set on Linux, macOS, and Windows;
results below. tl;dr: both v5 patches apply cleanly (git am) to
current master (11ed011ae22) and build clean, and all four events
show up in pg_stat_activity under load -- including EventlogWrite on
Windows, which I believe was the one path previously only
build-verified. +1 from me.

** Methodology **

8 backends each run a plpgsql loop of 50k RAISE LOG calls with an
8 kB payload, while a separate connection samples pg_stat_activity
every ~2 ms and tallies wait_event. The driver scripts and the
Windows CI job are public:

https://github.com/NikolayS/postgres/tree/ci/windows-waitevents
workflow: .github/workflows/windows-waitevents.yml

** Results **

Linux (tested June 15 with v4; gcc 13, meson debug; I did not rerun
since the v4->v5 code delta is comment-only):

logging_collector = on -> IO/SysloggerWrite 3652 (46.3% of all
samples, null wait_event included)
logging_collector = off -> IO/StderrWrite 1376 (17.6%)

macOS (v5 on master@11ed011ae22; clang 17, meson debug):

logging_collector = on -> IO/SysloggerWrite 47362 samples
(the only wait event observed)
logging_collector = off -> IO/StderrWrite 13710 samples

Windows (v5 on master@11ed011ae22; MSVC/meson, windows-latest,
log_destination = 'stderr,eventlog'):

IO/EventlogWrite 20091 samples
IO/StderrWrite 642 samples

Run: https://github.com/NikolayS/postgres/actions/runs/29425495163
(the job fails hard if EventlogWrite is never sampled; it passed)

Counts are pg_stat_activity rows summed over sampler ticks and
backends, and run lengths differed, so they are not comparable
across platforms.

One caveat on Windows coverage: GitHub Actions redirects stderr, so
the WriteConsoleW branch of write_console() is not truly exercised
there -- the samples above go through the write(fileno(stderr))
branch plus write_eventlog(). I don't see it as blocking -- the
WriteConsoleW wrapping is mechanically identical to its sibling.

The NULL share varies with how fast the log device is: these are
debug builds on fast storage, so backends spend most of their time
formatting on-CPU. On a saturated pipe or a slow log device --
exactly Andrey's network-HDD case -- the attributable share grows,
which is precisely what the patch makes visible.

** Review notes on v5 **

I checked the v4->v5 delta -- comments and commit-message text only
(single-slot masking notes at each wrapped site, and the explanation
that the on-disk write happens in write_syslogger_file() in the
syslogger, which has no PGPROC, so the backend-side SysloggerWrite on
the pipe write is where a stall becomes visible). That addresses the
points from Andrey's and Henson's reviews, thank you.

One optional thought on write_syslog(): openlog() is called with
LOG_NDELAY, so the connection to the syslog socket is opened right
there on the first call in each process, and in principle that can
block too (e.g. glibc's stream-socket fallback with a busy syslog
daemon). That call could also be wrapped with SyslogWrite. It is
once per process, so take it or leave it -- not blocking.

Nik

Hi Seongjun,

(I reviewed and tested v4 back in June but never sent the results;
now doing it for v5.)

I ran runtime tests of this patch set on Linux, macOS, and Windows;
results below. tl;dr: both v5 patches apply cleanly (git am) to
current master (11ed011ae22) and build clean, and all four events
show up in pg_stat_activity under load -- including EventlogWrite on
Windows, which I believe was the one path previously only
build-verified. +1 from me.

** Methodology **

8 backends each run a plpgsql loop of 50k RAISE LOG calls with an
8 kB payload, while a separate connection samples pg_stat_activity
every ~2 ms and tallies wait_event. The driver scripts and the
Windows CI job are public:

https://github.com/NikolayS/postgres/tree/ci/windows-waitevents
workflow: .github/workflows/windows-waitevents.yml

** Results **

Linux (tested June 15 with v4; gcc 13, meson debug; I did not rerun
since the v4->v5 code delta is comment-only):

logging_collector = on -> IO/SysloggerWrite 3652 (46.3% of all
samples, null wait_event included)
logging_collector = off -> IO/StderrWrite 1376 (17.6%)

macOS (v5 on master@11ed011ae22; clang 17, meson debug):

logging_collector = on -> IO/SysloggerWrite 47362 samples
(the only wait event observed)
logging_collector = off -> IO/StderrWrite 13710 samples

Windows (v5 on master@11ed011ae22; MSVC/meson, windows-latest,
log_destination = 'stderr,eventlog'):

IO/EventlogWrite 20091 samples
IO/StderrWrite 642 samples

Run: https://github.com/NikolayS/postgres/actions/runs/29425495163
(the job fails hard if EventlogWrite is never sampled; it passed)

Counts are pg_stat_activity rows summed over sampler ticks and
backends, and run lengths differed, so they are not comparable
across platforms.

One caveat on Windows coverage: GitHub Actions redirects stderr, so
the WriteConsoleW branch of write_console() is not truly exercised
there -- the samples above go through the write(fileno(stderr))
branch plus write_eventlog(). I don't see it as blocking -- the
WriteConsoleW wrapping is mechanically identical to its sibling.

The NULL share varies with how fast the log device is: these are
debug builds on fast storage, so backends spend most of their time
formatting on-CPU. On a saturated pipe or a slow log device --
exactly Andrey's network-HDD case -- the attributable share grows,
which is precisely what the patch makes visible.

** Review notes on v5 **

I checked the v4->v5 delta -- comments and commit-message text only
(single-slot masking notes at each wrapped site, and the explanation
that the on-disk write happens in write_syslogger_file() in the
syslogger, which has no PGPROC, so the backend-side SysloggerWrite on
the pipe write is where a stall becomes visible). That addresses the
points from Andrey's and Henson's reviews, thank you.

One optional thought on write_syslog(): openlog() is called with
LOG_NDELAY, so the connection to the syslog socket is opened right
there on the first call in each process, and in principle that can
block too (e.g. glibc's stream-socket fallback with a busy syslog
daemon). That call could also be wrapped with SyslogWrite. It is
once per process, so take it or leave it -- not blocking.

Nik

Hi Nik,

Thanks for running this on all three platforms.

EventlogWrite is the one I'm happiest to see. It's Windows-only
(ReportEventW/A), so until now I could only confirm it compiles. Seeing
it in pg_stat_activity -- 20091 samples, with the job set to fail if
it's never sampled -- is the runtime check the thread was missing, and
it closes the last open item.

Agreed on the WriteConsoleW caveat. I've written the coverage into the
commit messages rather than leave it implicit: SysloggerWrite,
StderrWrite and SyslogWrite sampled at runtime on Linux and macOS, and
EventlogWrite confirmed on Windows via your CI run; WriteConsoleW is
covered by build and review only, since it needs a real console. Your
results are credited there. (And +1 on the NULL share -- it's small
on fast debug builds and grows once the log device is the bottleneck,
which is the case the patch is for.)

Good catch on openlog(). With LOG_NDELAY the socket is connected on the
first log in each process, so it can block the same way the syslog()
calls can; wrapping those but not this felt inconsistent. v6 wraps it,
reusing SyslogWrite since it's the same write_syslog() routine.

That openlog() wrap is the only functional change from v5; otherwise v6
is a rebase plus the commit-message note. I checked it by:

- git am of both patches onto current master (5174d157a03), clean;
- full Meson build (cassert, debug) -- no warnings;
- regression and isolation suites green (245 and 130 tests).

v6-0001 - portable part (SysloggerWrite, StderrWrite, SyslogWrite, now
including the openlog() call)
v6-0002 - Windows part (WriteConsoleW plus EventlogWrite)

Henson, the only change since your v5 review is the openlog() wrap
above. Final comments from anyone are welcome.

Thanks again for the testing and the review.

Seongjun

The following review has been posted through the commitfest application:
make installcheck-world: tested, passed
Implements feature: tested, passed
Spec compliant: tested, passed
Documentation: tested, passed

Hi Seongjun,

I tested v6. Reading back through the thread, the runtime testing so far has
covered SysloggerWrite, StderrWrite and EventlogWrite, but I could not find a
report of anyone running with log_destination = 'syslog', so SyslogWrite -- and
the openlog() call added in v6 -- looked like the parts still resting on code
reading alone. Those are what I concentrated on.

Scope: I tested the Unix paths in 0001 only. I did not test the Windows paths
in 0002 (EventlogWrite, WriteConsoleW); those still rest on Nikolay's CI run and
on code review.

Environment
-----------
Ubuntu 24.04.4 LTS on aarch64, glibc 2.39, gcc 13.3.0, meson 1.3.2 / ninja
1.11.1, configured with -Dcassert=true -Dbuildtype=debug.

v6-0001 and v6-0002 still apply cleanly to today's master (74276e685dd0), build
with no compiler warnings, and "meson test" is green: 350 passed, 0 failed,
33 skipped. All four events are present in pg_wait_events.

For each scenario below I ran the identical procedure against an unpatched build
of that same commit and took a backtrace of a blocked backend in both, so the
"before" and "after" can be compared at the same call site. Sampling is
pg_stat_activity every ~2ms, tallied over 25-30s, following the method Nikolay
used upthread so the numbers are comparable.

1. syslog(3) -- IO / SyslogWrite
--------------------------------
To make syslog(3) block deterministically I replaced /dev/log with a SOCK_DGRAM
listener that never recv()s (scripts attached). Once its receive buffer fills,
glibc's syslog() blocks in send(2). Server configured with
log_destination = 'syslog', logging_collector = off; load is 8 backends emitting
8kB LOG lines.

write_syslog() has two syslog() call sites, and they are selected by
syslog_split_messages, so I ran it both ways.

syslog_split_messages = on (chunked path, elog.c:2909)
unpatched NULL 81160 samples 100.0%
v6 IO / SyslogWrite 81008 samples 100.0%

syslog_split_messages = off (unchunked path, elog.c:2923)
unpatched NULL 54280 samples 100.0%
v6 IO / SyslogWrite 67416 samples 100.0%

Both builds have the same stack, e.g. for the chunked path:

#0 __libc_send () at ../sysdeps/unix/sysv/linux/send.c:28
#1 __vsyslog_internal () at ./misc/syslog.c:288
#2 __syslog () at ./misc/syslog.c:91
#3 write_syslog (level=6, ...) at ../src/backend/utils/error/elog.c:2909
#4 send_message_to_server_log () at ../src/backend/utils/error/elog.c:3848
#5 EmitErrorReport () at ../src/backend/utils/error/elog.c:1925

With the openlog() case below, that covers all three wrapped call sites in
write_syslog().

2. openlog(3) -- the v6 delta
-----------------------------
To reach the stream-socket fallback you described, I replaced /dev/log with a
SOCK_STREAM listener with a backlog of 0 that never accept()s. openlog() then
tries SOCK_DGRAM, gets EPROTOTYPE, retries with SOCK_STREAM, and blocks in
connect(2) once the single queue slot is taken.

unpatched 6 of 6 probe backends: state = active, wait_event IS NULL
v6 6 of 6 probe backends: IO / SyslogWrite

and in both builds those backends are here:

#0 __libc_connect () at ../sysdeps/unix/sysv/linux/connect.c:26
#1 openlog_internal () at ./misc/syslog.c:357
#2 openlog () at ./misc/syslog.c:386
#3 write_syslog (level=6, ...) at ../src/backend/utils/error/elog.c:2827
#4 send_message_to_server_log () at ../src/backend/utils/error/elog.c:3848
#5 EmitErrorReport () at ../src/backend/utils/error/elog.c:1925

So the openlog() wrapping does what it is meant to do.

Getting there took one step that may be worth reflecting in the commit message:
with fork()-based backends, openlog_done and the syslog fd are inherited from
the postmaster, so a backend does not normally reach openlog() at all -- the
postmaster opens the connection for its own first message and every child
inherits it. The way to reach it in a backend is to change syslog_ident or
syslog_facility and reload, since assign_syslog_facility() does closelog() +
openlog_done = false in every process that applies the reload. (A backend also
only applies a pending reload when it returns to its main loop, not mid-query,
which matters when writing a test for this.) So on Unix the backend-visible
openlog() case is real but narrow, and the postmaster case never appears in
pg_stat_activity anyway. Wrapping it still looks right to me -- it costs
nothing and it is the same routine -- but the current wording reads as though
the call is reached on any first log message in each process.

3. syslogger pipe -- IO / SysloggerWrite
----------------------------------------
Same idea for the case Andrey described. With logging_collector = on I
SIGSTOPed the syslogger so the pipe fills and backends block in the pipe write:

unpatched NULL 91360 samples 100.0%
v6 IO / SysloggerWrite 92992 samples 100.0%

with an identical stack in both (write_pipe_chunks -> __libc_write). This is
the "the node looks CPU-bound but it is really the log device" case, and it is
much starker than the numbers from a healthy log device: 100% of the
active-backend samples are unattributed before the patch.

4. The single-slot masking question
-----------------------------------
Since this was the one open design point, I tried to settle it from the source
rather than by argument. For an outer wait event to be masked, an ereport()
that RETURNS -- LOG, WARNING, NOTICE, INFO, DEBUGn, but not ERROR and above,
which unwind -- has to be reachable between a pgstat_report_wait_start() and its
matching pgstat_report_wait_end(). I scanned src/backend, src/common and
src/port for exactly that (script attached):

files scanned 1022
wait-event regions paired 98
starts the pairing could not resolve 2
regions containing a directly reachable
ereport/elog at a returning level 1

The two unresolved starts are the LWLockReportWaitStart() helper itself, whose
matching end is in a different function, and a mention in a comment header;
neither is a region.

The single hit is in AddToDataDirLockFile():

pgstat_report_wait_start(WAIT_EVENT_LOCK_FILE_ADDTODATADIR_SYNC);
if (pg_fsync(fd) != 0)
ereport(LOG, (errcode_for_file_access(), ...));
pgstat_report_wait_end();

(The pg_pwrite() case just above it calls pgstat_report_wait_end() before its
ereport; the fsync case does not.) Every caller of AddToDataDirLockFile() is in
the postmaster -- postmaster.c and PGSharedMemoryCreate() -- which is exactly
the case Henson carved out: no PGPROC, so my_wait_event_info points at the
process-local dummy and nothing observable changes. Even setting that aside, it
is an fsync-failure path, and the event it would clear is its own, after the
fsync has already returned.

Limitations, so this is not read as more than it is: the scan is lexical and
intra-procedural. It does not follow calls made inside a region, so an
ereport() in a callee would not be found.

As a sanity check I also compared wait-event profiles under a heavy-logging but
healthy-log-device workload (pgbench -c 8 -j 4 for 60s, with
log_min_duration_statement = 0, log_checkpoints = on,
log_autovacuum_min_duration = 0, log_lock_waits = on), three runs per build,
alternating. Share of each run's total:

event unpatched v6
-----------------------------------------------------
NULL 43.4 - 44.1 41.4 - 44.1
LWLock / WALWrite 24.8 - 25.4 23.0 - 25.1
Client / ClientRead 11.5 - 11.9 11.7 - 11.9
IO / WalSync 11.0 - 11.1 10.9 - 11.0
Lock / transactionid 6.3 - 6.6 5.9 - 6.6
IO / SysloggerWrite -- 2.3 - 2.4

Every existing event's range overlaps between the two builds; only the new event
separates them. I would not push this further than that: the total sample count
varied from 149844 to 199272 across runs, so the percentages share a moving
denominator, and this method cannot resolve an effect smaller than the
run-to-run spread of roughly two points. The source scan is the part I would
rely on.

One non-blocking suggestion
---------------------------
Now that openlog() is wrapped with SyslogWrite, this description

SYSLOG_WRITE "Waiting for a write to the system logger (syslog)."

is not quite accurate at that call site: openlog() is establishing the
connection, not writing. The string is user-visible in pg_wait_events and in
the documentation table, and operationally "syslog is slow to accept writes" and
"we cannot connect to the syslog daemon at all" point at different things.

Michael already said upthread that sharing an event within one routine is fine,
so I am not proposing a separate event -- just a wording tweak, if you agree:

SYSLOG_WRITE "Waiting for a write to the system logger (syslog), including connection setup."

Neither this nor the commit-message wording above looks blocking to me; both
could equally be folded in at commit time.

Attached are the scripts I used, in case anyone wants to reproduce these:
blackhole_dgram.py and blackhole_stream.py (the two /dev/log listeners),
devlog_takeover.sh / devlog_restore.sh, sample_wait_events.sql,
run_scenario.sh, run_openlog_scenario.sh, run_masking_check.sh, and
audit_wait_regions.py.

A warning about them: the two listeners replace the host's /dev/log, so any
process on that machine which logs through syslog(3) -- sudo included -- can
block while they are running. Please run them in a throwaway VM or container,
not anywhere you care about.

Nothing here looks blocking to me, so I have marked the entry Ready for
Committer. Henson, Nik -- please move it back if you disagree.

Tested-by: Jihyun Bahn <rring0727@gmail.com>

Regards,
Jihyun Bahn

On Fri, Jul 17, 2026 at 5:55 PM 신성준 <shinsj4653@gmail.com> wrote:
[..]

v6-0001 - portable part (SysloggerWrite, StderrWrite, SyslogWrite, now
including the openlog() call)
v6-0002 - Windows part (WriteConsoleW plus EventlogWrite)

Hi Seongjun,

I think it's worthy addition as functionality and the code is basically just
wrapping pgstat_report_wait_start/pgstat_report_wait_endt(). I've seen at
least one case of bank being taken down due to similiar issues (rsyslogd stuck
due to stuck sync TCP remote connection, backpropagating to backends), AFAIR
wait_events were NULL (so useless), but strack-trace collection showed
processing stuck on syslog(). I've tested this using:

1) LD_PRELOAD for syslog() with sleep(1s) and started server that way
2) log_connections=on
3) and pgbench -c N -j N --connect so basically each new connection was stuck on
this, and in the pg_stat_active I could see this new "SyslogWrite" event, so
+1 from me the functionality.

As for review:

a. I have no idea why this is split into two patches, it could be just one to
make things easier to process?

b. if we have nested use, let's say:

pgstat_report_wait_start(WAIT_EVENT_BLAH);
something()
while(work) {
ereport(LOG, ..) {
NEW: pgstat_report_wait_start(WAIT_EVENT_SYSLOG_WRITE);
syslog(..); // or some other write(2) to log
NEW: pgstat_report_wait_end(); // wait_event=0
}
some_important_stuff_that_may_also_hang();
}
pgstat_report_wait_wait_end();

this "NEW" code-path is going to zero-out WAIT_EVENT_BLAH:

* if it get stuck SYSLOG_WRITE and learn this that way, great, but ..

* but if something else is stuck in the
some_important_stuff_that_may_also_hang() that gets lost because wait_event
is going to be zero rather than WAIT_EVENT_BLAH and how do we find out?

The other reviewer (Jihyun) in the parallel subthread I thnink also mentioned
this danger when discussing AddToDataDirLockFile(), but I'm not sure if I
understood him fully, but it has this pattern of wait_event_start(),
pg_fsync() which has nested wait_event_start for fsync , then _end(), and then
yet another _end(), but it seems to be the only place like that (?)

What about extensions using ereport() ? No idea..

Probably correct way to address would be to find a way for _end() to bring
back saved prior wait event, so perhaps it should not just _end() to 0, but
return it back to the previous one if that was set (I'm assuming this is
in code paths never being in hot-paths so simple if() shouldn't matter), but
I'm not 100% sure if that's good way, maybe others can express their opinion
on this one (we would require new conditional
pgstat_report_wait_start($previous_wait_event) if wait_event !=0 in this
patchset if we choose that route).

-J.

On Mon, Aug 10, 2026 at 6:48 PM Jakub Wartak
<jakub.wartak@enterprisedb.com> wrote:

a. I have no idea why this is split into two patches, it could be just
one to make things easier to process?

Hello,
Thanks for the review jakub and jian.

The split is by platform, not by feature: 0002 is entirely inside
#ifdef WIN32, and most reviewers cannot run it. Keeping it separate
lets a reviewer state exactly what they covered -- Jihyun did that in
the parallel subthread, testing the Unix paths in 0001 and leaving the
Windows paths to Nikolay's CI run.

That said, this is not something I feel strongly about. If a committer
would rather have one patch, I am happy to squash them.

b. if we have nested use, let's say:

[...]

* but if something else is stuck in the
some_important_stuff_that_may_also_hang() that gets lost because
wait_event is going to be zero rather than WAIT_EVENT_BLAH and how do
we find out?

You are right that the pattern is real, and I do not think Jihyun's
scan settles it -- as that review says itself, it is lexical and
intra-procedural, so it only sees an ereport() written directly inside
the region. Your example has the ereport() in a callee, which is
exactly what that scan cannot see.

So I extended it to follow calls made inside a region, looking for an
ereport()/elog() at a level that returns (DEBUGn, INFO, NOTICE, LOG,
WARNING; ERROR and above unwind, so they cannot mask anything).

The intra-procedural part reproduces: over src/backend, src/common and
src/port I get the same single hit Jihyun reported,
AddToDataDirLockFile(), whose callers are all in the postmaster. The
two call sites in read_relmap_file() that report at a variable elevel
resolve to ERROR or FATAL at every caller, so they are not masking
candidates either.

Following callees one level down flags five regions. Going through
them:

- FileWriteback() -> pg_flush_data(). Real: pg_flush_data() can
ereport(WARNING, "could not flush dirty data") when
sync_file_range() fails with ENOSYS, and WARNING returns.

- ReorderBufferSerializeChange() and SnapBuildSerialize() (three
regions between them) -> CloseTransientFile(), which has an
elog(WARNING, "fd passed to CloseTransientFile was not obtained
from OpenTransientFile"). Reachable only on the write()/fsync()
failure branch, which ereports at ERROR immediately afterwards, so
the region is unwound rather than continued.

- RestoreArchivedFile() -> proc_exit(), which does not return.

Deeper than that, the only additional paths are the Windows
pg_pread()/pg_pwrite() wrappers reaching _dosmaperr(), which reports at
DEBUG5/LOG when the OS returns an error code that is not in its
mapping table.

So the conclusion is not "this cannot happen". It is that in every
case above, nothing blocking follows the log write inside the region --
our regions wrap a single call and then end. Masking is bounded to the
tail of the region, and the case you describe, where a stall after the
log write gets misattributed, needs a region that keeps working
afterwards. I could not find one.

But that is a property of how the regions happen to be written, not
something the mechanism enforces, and your suggestion would make it
enforced. I think it is worth doing. My hesitation about putting it
in this patch set is scope: pgstat_report_wait_end() is an inline
helper used across the whole tree, and saving a previous value needs
somewhere to put it. Henson made the same point reviewing v5, that a
general fix belongs in its own patch, so I would rather not fold it in
here. If there is interest I will write it up separately; I would
rather it were judged on its own merits than as a rider on this one.

The scan is an approximation: it resolves calls by name, so it misses
function pointers, and it does not reason about which branches are
reachable. I am happy to post the script if anyone wants to check the
numbers.

I've seen at least one case of bank being taken down due to similiar
issues (rsyslogd stuck due to stuck sync TCP remote connection,
backpropagating to backends), AFAIR wait_events were NULL (so
useless), but strack-trace collection showed processing stuck on
syslog().

That is the case this patch exists for, and it is a better motivation
than what the commit message had. I have added it to 0001 in general
terms -- a remote syslog destination that stops accepting data, the
stall propagating back into the backends, wait_event NULL throughout,
the cause found only from stack traces -- without naming the site or
the software. Please tell me if you would rather I dropped it or
worded it differently, and likewise for the Tested-by; both are easy to
change.

What about extensions using ereport() ? No idea..

An extension calling ereport() inside a wait event region is in the
same position as core code doing it, so this patch does not change
anything for them either way. It is another argument for fixing this
in the mechanism rather than at each call site.

On Tue, Jul 28, 2026 at 12:47 PM jihyun bahn <rring0727@gmail.com>
wrote:

Getting there took one step that may be worth reflecting in the commit
message: with fork()-based backends, openlog_done and the syslog fd
are inherited from the postmaster [...]

Thank you for testing the syslog paths -- those were the ones still
resting on code reading, and the blackhole /dev/log setup is a neat way
to pin them down.

You are right about the commit message and about the description
string. Both are in v7:

- the openlog() paragraph now says the connection is normally
inherited from the postmaster, and that a backend reaches openlog()
only after syslog_ident or syslog_facility changes and the reload
is applied, via assign_syslog_facility(). The code comment says
the same;

- SYSLOG_WRITE is now "Waiting for a write to the system logger
(syslog), including connection setup."

I have also added a Tested-by for you on 0001, and left 0002 with
Nikolay's only, since you were explicit about not having tested the
Windows paths. Let me know if you would rather not be credited.

On the CommitFest status: you marked the entry Ready for Committer
before Jakub's mail arrived, and the move to PG20-2 reset it to Needs
review. That suits me while the point above is open -- please mark it
again once you think it is settled.

v7 is attached. Apart from the description string it is comments and
commit messages; there is no functional change from v6.

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

I checked it by:

- git am of both patches onto current master (6a857156827), clean;
- full Meson build (cassert, debug) -- no warnings;
- 0001 building on its own;
- regression and isolation suites green (243 and 132 tests).

Regards,
Seongjun Shin

Hello.

v8 replaces an argument in 0001's commit message with a measurement,
after off-list review from Andrey Borodin and Kirk Wolak on the nesting
point Jakub raised.

On Mon, Aug 10, 2026 at 6:48 PM Jakub Wartak
<jakub.wartak@enterprisedb.com> wrote:

* but if something else is stuck in the
some_important_stuff_that_may_also_hang() that gets lost because
wait_event is going to be zero rather than WAIT_EVENT_BLAH and how do
we find out?

I answered this in v7 by scanning for an ereport() reachable from
inside a wait event region, and said I could not find a region that
goes on to block afterwards. That was the wrong tool and I would
rather correct it here than leave the result in the archives.

Instead of reading the source I instrumented the mechanism: a
debug-only stack that pushes on pgstat_report_wait_start() and pops on
pgstat_report_wait_end(), with the depth capped at one so that opening
a region inside another one fails an assertion. Running the test
suite that way, the only log write that turns up inside another region
is one the scan could not have found:

PostgresMain -> pq_getbyte -> pq_recvbuf -> secure_read
-> WaitEventSetWait [ClientRead published]
-> SIGQUIT -> quickdie
-> ereport(WARNING, "terminating connection because of
unexpected SIGQUIT signal")
-> send_message_to_server_log
-> write_console [StderrWrite]

quickdie() reports from a signal handler, so it can land inside
whatever region the backend happens to be sitting in. A signal
handler is not in anyone's call graph, which is why counting callees
the way I did in v7 was never going to settle this.

It is specifically the PMQUIT_NOT_SENT branch that gets there, that
is, a SIGQUIT sent to the backend directly rather than by the
postmaster. The two postmaster-initiated branches report at
WARNING_CLIENT_ONLY, which never reaches the server log at all.

It does not change the conclusion for these events, but it does change
the reason. quickdie() calls _exit(2) immediately afterwards, so the
masked ClientRead is never read back by anything. v8's commit message
says that, and drops the claim that the regions in the tree wrap a
single call and then end.

Two caveats on the measurement. The assertion aborts at the first
nested region, so this finds the first case per process rather than
all of them; and it only covers what the suite exercises.

On the general fix: the follow-up I promised in v7 now exists as a
patch. It is the check above, plus one thing the check forced into
the open -- "close the region I opened" and "reset the field after a
longjmp out of a region that may not have been open" are both spelled
pgstat_report_wait_end() today, and a stack cannot treat them the
same. Ten call sites are the second kind (AbortTransaction,
AbortSubTransaction, ShutdownAuxiliaryProcess, WalSndErrorCleanup and
the sigsetjmp blocks of the aux processes). As I said in v7 I will
put that on its own thread rather than fold it in here.

v8 is attached. There is no code change from v7; the only difference
is the commit message paragraph described above, plus a rebase onto
current master (8c7a74c3239).

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

I checked it by:

- git am of both patches onto 8c7a74c3239, clean;
- full Meson build (cassert, debug) -- no warnings;
- 0001 building on its own;
- regression, isolation and TAP suites green: 361 tests, 0 failures.
40 are skipped here, none of them for a reason this patch affects:
17 behind PG_TEST_EXTRA, 16 wanting an injection-points build, 5
expensive checksum tests, plus ICU and SSPI.

Regards,
Seongjun Shin

Hi Seongjun,

this patch does not change anything for them either way.

I tested the extension case with stderr logging and
logging_collector=off. A small extension sets
Extension/HarnessOuterWait, calls ereport(LOG), then keeps waiting.
The observer samples only after ereport(LOG) returns:

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.

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.

My AI harness tested v8 on master at c68cba09dd7f: cassert build,
regression, isolation and relevant TAP tests passed. SysloggerWrite
also worked as intended. I did not rerun Windows.

This looks close. I think this edge case needs one more iteration
before commit. Happy to retest.

Thanks,
Nik

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@postgres.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

A follow-up on the Windows side. v9 said I could not run that part
here; Nik pointed out off-list that a GitHub Actions runner does the
job, so I did the same thing he did in July: a throwaway branch on my
fork with v9 applied on 1a3e782e762 plus a small test module and a
workflow, run on windows-2022 (MSVC, meson, cassert).

The module is the one from my previous mail (publish
Extension/HarnessOuterWait, ereport(LOG), sleep). The workflow starts
a cluster per log destination, calls it from one session and samples
pg_stat_activity from another 3 s later, after ereport(LOG) has
returned, and fails the job unless every sample still shows the outer
event. It passed:

log_destination = eventlog Extension / HarnessOuterWait
stderr, logging_collector = off Extension / HarnessOuterWait
stderr, logging_collector = on Extension / HarnessOuterWait

The eventlog row did go through write_eventlog(): the workflow's last
step reads the Windows Application log back and fails unless the
harness line is there under the PostgreSQL source, and it found it:

2026-09-15 15:26:10.400 UTC [2232] LOG: harness: logging from
inside HarnessOuterWait

The stderr row is the write() fallback, as in July; stderr is
redirected on a runner, so WriteConsoleW() is still not exercised at
runtime.

Run: https://github.com/shinsj4653/postgres/actions/runs/34988125975
Branch: shinsj4653/postgres, ci/win-waitevents-v9 (fe909ac)

So the restore behaves the same on Windows, for the two portable paths
and for EventlogWrite. Nothing changes in the patches; this only fills
in the Windows column that was missing from v9.