MIME-Version: 1.0
References: 
 <CACdN0M78U+GvpqA7oey-GA7fFSYM636aDp6H9FVvCztv9zXxSA@mail.gmail.com>
 <20260601.144922.658666928129832364.horikyota.ntt@gmail.com>
 <CACdN0M6WCA32MKK30-TS3CgGRTRKZpXRB9o3oHt2LGrB_CHDmA@mail.gmail.com>
 <CACdN0M65jfGbOcBDm5rM_3nGVYNan7EQ9vQ1WAyk6Xx8X10Wrw@mail.gmail.com>
 <378001C2-12FE-47F5-8188-05900EF53F62@yandex-team.ru>
In-Reply-To: <378001C2-12FE-47F5-8188-05900EF53F62@yandex-team.ru>
From: =?UTF-8?B?7Iug7ISx7KSA?= <shinsj4653@gmail.com>
Date: Wed, 17 Jun 2026 01:10:18 +0900
Message-ID: 
 <CACdN0M56C8VA8URZxkjuKBU8bT-Fu0+sej66pHSqoM2BYrq8zg@mail.gmail.com>
Subject: Re: Add wait events for server logging destination writes
To: Andrey Borodin <x4mmm@yandex-team.ru>
Cc: pgsql-hackers mailing list <pgsql-hackers@lists.postgresql.org>,
 Kirk Wolak <wolakk@gmail.com>,
	Kyotaro Horiguchi <horikyota.ntt@gmail.com>,
 Andreas Karlsson <andreas@proxel.se>, nik@postgres.ai
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable
Archived-At: 
 <https://www.postgresql.org/message-id/CACdN0M56C8VA8URZxkjuKBU8bT-Fu0%2Bsej66pHSqoM2BYrq8zg%40mail.gmail.com>
Precedence: bulk

Hi Andrey,

> +1: a blocking logging write shows as wait_event IS NULL today, which mos=
t
> tools read as on-CPU. This is very real for us. In our managed Postgres t=
he
> root filesystem that holds the logs sits on slow network-backed HDD, so w=
hen
> the syslogger pipe backs up the backends stall on the log write and the w=
hole
> 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 sl=
ow
> log device is write_syslogger_file() in the syslogger, which has no share=
d
> 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 s=
ide
> 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 descripti=
ons
spell out the difference, so I'd lean toward leaving them unless others obj=
ect.

> One thing worth checking: wait events are single-slot by design (no nesti=
ng -
> 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, instrumenti=
ng
> 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 mas=
k
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 t=
ight
and log output is normally emitted outside them, so the overlap window shou=
ld
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 w=
hat
the rest of the tree relies on. I'll add a brief comment at these sites not=
ing
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 ev=
ent
only when the slot is currently 0, which preserves the outer event at the c=
ost
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 (th=
e
> 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, s=
o I
can fold everything into one revision.

Thanks again,
Seongjun

2026=EB=85=84 6=EC=9B=94 15=EC=9D=BC (=EC=9B=94) =EC=98=A4=EC=A0=84 3:49, A=
ndrey Borodin <x4mmm@yandex-team.ru>=EB=8B=98=EC=9D=B4 =EC=9E=91=EC=84=B1:
>
>
>
> > On 6 Jun 2026, at 21:52, =EC=8B=A0=EC=84=B1=EC=A4=80 <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]), 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%2BjKsS6SDo011AUWrLdBcBMv0=
KJha69t7eFGqEtqx9FVfag%40mail.gmail.com
>
>