Re: Add wait events for server logging destination writes

From: 신성준 <shinsj4653(at)gmail(dot)com>
To: Jakub Wartak <jakub(dot)wartak(at)enterprisedb(dot)com>, jian(dot)universality(at)gmail(dot)com
Cc: Nikolay Samokhvalov <nik(at)postgres(dot)ai>, assam258(at)gmail(dot)com, Andrey Borodin <x4mmm(at)yandex-team(dot)ru>, pgsql-hackers mailing list <pgsql-hackers(at)lists(dot)postgresql(dot)org>, Kirk Wolak <wolakk(at)gmail(dot)com>, Kyotaro Horiguchi <horikyota(dot)ntt(at)gmail(dot)com>, Andreas Karlsson <andreas(at)proxel(dot)se>
Subject: Re: Add wait events for server logging destination writes
Date: 2026-09-05 12:13:02
Message-ID: CACdN0M5XJWEhJ7wssSHNh99B0rFx7CgxOFDSouUWHL0nNZA_7w@mail.gmail.com
Views: Whole Thread | Raw Message | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

On Mon, Aug 10, 2026 at 6:48 PM Jakub Wartak
<jakub(dot)wartak(at)enterprisedb(dot)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(at)gmail(dot)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

Attachment Content-Type Size
v7-0002-Add-wait-events-for-Windows-specific-logging-outp.patch application/octet-stream 4.2 KB
v7-0001-Add-wait-events-for-server-logging-destination-wr.patch application/octet-stream 9.7 KB

In response to

Browse pgsql-hackers by date

  From Date Subject
Next Message Hannu Krosing 2026-09-05 12:24:50 Direct TOAST v2, faster, smaller and no migration needed
Previous Message Sehrope Sarkuni 2026-09-05 12:04:09 Re: [PATCH] Fix getopt_long() argument handling and add tests