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 <[email protected]>님이 작성: > > > > > On 6 Jun 2026, at 21:52, 신성준 <[email protected]> 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]), 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] > https://www.postgresql.org/message-id/CANP8%2BjKsS6SDo011AUWrLdBcBMv0KJha69t7eFGqEtqx9FVfag%40mail.gmail.com > >
