MIME-Version: 1.0
References: 
 <CACdN0M78U+GvpqA7oey-GA7fFSYM636aDp6H9FVvCztv9zXxSA@mail.gmail.com>
In-Reply-To: 
 <CACdN0M78U+GvpqA7oey-GA7fFSYM636aDp6H9FVvCztv9zXxSA@mail.gmail.com>
From: =?UTF-8?B?7Iug7ISx7KSA?= <shinsj4653@gmail.com>
Date: Sun, 31 May 2026 19:42:41 +0900
Message-ID: 
 <CACdN0M4ENFV0Hg4zbBkP+ScRHdeN9NdYx9QV79h5BM_eN9YxHA@mail.gmail.com>
Subject: Re: Add wait events for server logging destination writes
To: pgsql-hackers@lists.postgresql.org
Cc: Kirk Wolak <wolakk@gmail.com>, Andrey Borodin <x4mmm@yandex-team.ru>,
	Andreas Karlsson <andreas@proxel.se>, Nikolay Samokhvalov <nik@postgres.ai>
Content-Type: multipart/mixed; boundary="0000000000007902f406531abd1a"
Archived-At: 
 <https://www.postgresql.org/message-id/CACdN0M4ENFV0Hg4zbBkP%2BScRHdeN9NdYx9QV79h5BM_eN9YxHA%40mail.gmail.com>
Precedence: bulk

--0000000000007902f406531abd1a
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

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=EB=85=84 5=EC=9B=94 31=EC=9D=BC (=EC=9D=BC) =EC=98=A4=ED=9B=84 5:50, =
=EC=8B=A0=EC=84=B1=EC=A4=80 <shinsj4653@gmail.com>=EB=8B=98=EC=9D=B4 =EC=9E=
=91=EC=84=B1:
>
> 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 =3D 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 =3D on (syslogger pipe):
>     master:  NULL                100.0%  (2184/2184)
>     patched: IO/SysloggerWrite     99.1%  (2204/2224), NULL 0.9%
>
>   - logging_collector =3D 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.
>
> Applies on current master. A couple of things I'm unsure about and
> would appreciate input on: whether the event names fit the surrounding
> conventions, and whether splitting the Windows path into its own patch
> is the right call.
>
> Thanks,
> Seongjun Shin

--0000000000007902f406531abd1a
Content-Type: application/octet-stream;
	name="v2-0001-Add-wait-events-for-server-logging-destination-wr.patch"
Content-Disposition: attachment;
	filename="v2-0001-Add-wait-events-for-server-logging-destination-wr.patch"
Content-Transfer-Encoding: base64
Content-ID: <f_mptnhu360>
X-Attachment-Id: f_mptnhu360

RnJvbSBlODAwYzFkZTdkZTQwYTZkZTQyZDIzNzQyZTg5OTIyMzU2NzkzNWVmIE1vbiBTZXAgMTcg
MDA6MDA6MDAgMjAwMQpGcm9tOiBTZW9uZ2p1biBTaGluIDxzaGluc2o0NjUzQGdtYWlsLmNvbT4K
RGF0ZTogRnJpLCAyOSBNYXkgMjAyNiAxNDo0NToyMyArMDkwMApTdWJqZWN0OiBbUEFUQ0ggdjIg
MS8yXSBBZGQgd2FpdCBldmVudHMgZm9yIHNlcnZlciBsb2dnaW5nIGRlc3RpbmF0aW9uIHdyaXRl
cwoKV2hlbiBhIGJhY2tlbmQgd3JpdGVzIHRvIHRoZSBzeXNsb2dnZXIgcGlwZSBpbiB3cml0ZV9w
aXBlX2NodW5rcygpIG9yCnRvIHN0ZGVyciBpbiB3cml0ZV9jb25zb2xlKCksIHRoZSB1bmRlcmx5
aW5nIHdyaXRlKDIpIGNhbiBibG9jayBvbmNlCnRoZSBwaXBlIGJ1ZmZlciBmaWxscyB1cCBvciB0
aGUgb3V0cHV0IGRldmljZSBpcyBzbG93LiAgVGhlc2UgYmxvY2tpbmcKc3lzY2FsbHMgd2VyZSBu
b3QgaW5zdHJ1bWVudGVkLCBzbyBwZ19zdGF0X2FjdGl2aXR5IHJlcG9ydGVkCndhaXRfZXZlbnQg
SVMgTlVMTCBkdXJpbmcgdGhhdCB0aW1lLiAgTWFueSBtb25pdG9yaW5nIHRvb2xzIGludGVycHJl
dApOVUxMIGFzIG9uLUNQVSB3b3JrLCB3aGljaCBtYWRlIGhlYXZ5LWxvZ2dpbmcgc3RhbGxzIGhh
cmQgdG8KYXR0cmlidXRlLgoKQWRkIHR3byBuZXcgV2FpdEV2ZW50SU8gZXZlbnRzIGFuZCByZXBv
cnQgdGhlbSBhcm91bmQgdGhlIHJlbGV2YW50CndyaXRlKDIpIGNhbGxzOgoKICBJTyAvIFN5c2xv
Z2dlcldyaXRlIC0gd3JpdGUoMikgdG8gdGhlIHN5c2xvZ2dlciBwaXBlIGluc2lkZQogICAgICAg
ICAgICAgICAgICAgICAgICB3cml0ZV9waXBlX2NodW5rcygpLgogIElPIC8gU3RkZXJyV3JpdGUg
ICAgLSB3cml0ZSgyKSB0byBzdGRlcnIgaW5zaWRlIHdyaXRlX2NvbnNvbGUoKS4KClRoZSBpbnN0
cnVtZW50YXRpb24gaXMgbGltaXRlZCB0byB0aGUgbGVhZiB3cml0ZSBjYWxsLiAgSXQgdXNlcyBv
bmx5CnRoZSBleGlzdGluZyBwZ3N0YXRfcmVwb3J0X3dhaXRfc3RhcnQoKS9lbmQoKSBpbmxpbmUg
aGVscGVycywgd2hpY2gKYXJlIGFsbG9jYXRpb24tZnJlZSBhbmQgc2FmZSB0byBjYWxsIGJlZm9y
ZSBNeVByb2MgaXMgc2V0IHVwLCBzbyB0aGlzCnJlbWFpbnMgc2FmZSB0byBpbnZva2UgZnJvbSB3
aXRoaW4gZXJyb3IgcmVwb3J0aW5nIHBhdGhzLgotLS0KIHNyYy9iYWNrZW5kL3V0aWxzL2FjdGl2
aXR5L3dhaXRfZXZlbnRfbmFtZXMudHh0IHwgMiArKwogc3JjL2JhY2tlbmQvdXRpbHMvZXJyb3Iv
ZWxvZy5jICAgICAgICAgICAgICAgICAgfCA3ICsrKysrKysKIDIgZmlsZXMgY2hhbmdlZCwgOSBp
bnNlcnRpb25zKCspCgpkaWZmIC0tZ2l0IGEvc3JjL2JhY2tlbmQvdXRpbHMvYWN0aXZpdHkvd2Fp
dF9ldmVudF9uYW1lcy50eHQgYi9zcmMvYmFja2VuZC91dGlscy9hY3Rpdml0eS93YWl0X2V2ZW50
X25hbWVzLnR4dAppbmRleCA1NTM3YTJkMjUzMC4uY2UzMzgwN2MzZmUgMTAwNjQ0Ci0tLSBhL3Ny
Yy9iYWNrZW5kL3V0aWxzL2FjdGl2aXR5L3dhaXRfZXZlbnRfbmFtZXMudHh0CisrKyBiL3NyYy9i
YWNrZW5kL3V0aWxzL2FjdGl2aXR5L3dhaXRfZXZlbnRfbmFtZXMudHh0CkBAIC0yNTMsNiArMjUz
LDggQEAgU0xSVV9XUklURQkiV2FpdGluZyBmb3IgYSB3cml0ZSBvZiBhbiBTTFJVIHBhZ2UuIgog
U05BUEJVSUxEX1JFQUQJIldhaXRpbmcgZm9yIGEgcmVhZCBvZiBhIHNlcmlhbGl6ZWQgaGlzdG9y
aWNhbCBjYXRhbG9nIHNuYXBzaG90LiIKIFNOQVBCVUlMRF9TWU5DCSJXYWl0aW5nIGZvciBhIHNl
cmlhbGl6ZWQgaGlzdG9yaWNhbCBjYXRhbG9nIHNuYXBzaG90IHRvIHJlYWNoIGR1cmFibGUgc3Rv
cmFnZS4iCiBTTkFQQlVJTERfV1JJVEUJIldhaXRpbmcgZm9yIGEgd3JpdGUgb2YgYSBzZXJpYWxp
emVkIGhpc3RvcmljYWwgY2F0YWxvZyBzbmFwc2hvdC4iCitTVERFUlJfV1JJVEUJIldhaXRpbmcg
Zm9yIGEgd3JpdGUgdG8gdGhlIHNlcnZlcidzIHN0YW5kYXJkIGVycm9yIHN0cmVhbS4iCitTWVNM
T0dHRVJfV1JJVEUJIldhaXRpbmcgZm9yIGEgd3JpdGUgdG8gdGhlIHN5c2xvZ2dlciBwaXBlLiIK
IFRJTUVMSU5FX0hJU1RPUllfRklMRV9TWU5DCSJXYWl0aW5nIGZvciBhIHRpbWVsaW5lIGhpc3Rv
cnkgZmlsZSByZWNlaXZlZCB2aWEgc3RyZWFtaW5nIHJlcGxpY2F0aW9uIHRvIHJlYWNoIGR1cmFi
bGUgc3RvcmFnZS4iCiBUSU1FTElORV9ISVNUT1JZX0ZJTEVfV1JJVEUJIldhaXRpbmcgZm9yIGEg
d3JpdGUgb2YgYSB0aW1lbGluZSBoaXN0b3J5IGZpbGUgcmVjZWl2ZWQgdmlhIHN0cmVhbWluZyBy
ZXBsaWNhdGlvbi4iCiBUSU1FTElORV9ISVNUT1JZX1JFQUQJIldhaXRpbmcgZm9yIGEgcmVhZCBv
ZiBhIHRpbWVsaW5lIGhpc3RvcnkgZmlsZS4iCmRpZmYgLS1naXQgYS9zcmMvYmFja2VuZC91dGls
cy9lcnJvci9lbG9nLmMgYi9zcmMvYmFja2VuZC91dGlscy9lcnJvci9lbG9nLmMKaW5kZXggYWE1
MzBkMzY4NWUuLmQ0YzQxZmExMjYzIDEwMDY0NAotLS0gYS9zcmMvYmFja2VuZC91dGlscy9lcnJv
ci9lbG9nLmMKKysrIGIvc3JjL2JhY2tlbmQvdXRpbHMvZXJyb3IvZWxvZy5jCkBAIC04NCw2ICs4
NCw3IEBACiAjaW5jbHVkZSAidXRpbHMvbWVtdXRpbHMuaCIKICNpbmNsdWRlICJ1dGlscy9wc19z
dGF0dXMuaCIKICNpbmNsdWRlICJ1dGlscy92YXJsZW5hLmgiCisjaW5jbHVkZSAidXRpbHMvd2Fp
dF9ldmVudC5oIgogCiAKIC8qIEluIHRoaXMgbW9kdWxlLCBhY2Nlc3MgZ2V0dGV4dCgpIHZpYSBl
cnJfZ2V0dGV4dCgpICovCkBAIC0yNjYyLDcgKzI2NjMsOSBAQCB3cml0ZV9jb25zb2xlKGNvbnN0
IGNoYXIgKmxpbmUsIGludCBsZW4pCiAJICogV2UgaWdub3JlIGFueSBlcnJvciBmcm9tIHdyaXRl
KCkgaGVyZS4gIFdlIGhhdmUgbm8gdXNlZnVsIHdheSB0byByZXBvcnQKIAkgKiBpdCAuLi4gY2Vy
dGFpbmx5IHdoaW5pbmcgb24gc3RkZXJyIGlzbid0IGxpa2VseSB0byBiZSBwcm9kdWN0aXZlLgog
CSAqLworCXBnc3RhdF9yZXBvcnRfd2FpdF9zdGFydChXQUlUX0VWRU5UX1NUREVSUl9XUklURSk7
CiAJcmMgPSB3cml0ZShmaWxlbm8oc3RkZXJyKSwgbGluZSwgbGVuKTsKKwlwZ3N0YXRfcmVwb3J0
X3dhaXRfZW5kKCk7CiAJKHZvaWQpIHJjOwogfQogCkBAIC0zNTAzLDcgKzM1MDYsOSBAQCB3cml0
ZV9waXBlX2NodW5rcyhjaGFyICpkYXRhLCBpbnQgbGVuLCBpbnQgZGVzdCkKIAkJLyogbm8gbmVl
ZCB0byBzZXQgUElQRV9QUk9UT19JU19MQVNUIHlldCAqLwogCQlwLnByb3RvLmxlbiA9IFBJUEVf
TUFYX1BBWUxPQUQ7CiAJCW1lbWNweShwLnByb3RvLmRhdGEsIGRhdGEsIFBJUEVfTUFYX1BBWUxP
QUQpOworCQlwZ3N0YXRfcmVwb3J0X3dhaXRfc3RhcnQoV0FJVF9FVkVOVF9TWVNMT0dHRVJfV1JJ
VEUpOwogCQlyYyA9IHdyaXRlKGZkLCAmcCwgUElQRV9IRUFERVJfU0laRSArIFBJUEVfTUFYX1BB
WUxPQUQpOworCQlwZ3N0YXRfcmVwb3J0X3dhaXRfZW5kKCk7CiAJCSh2b2lkKSByYzsKIAkJZGF0
YSArPSBQSVBFX01BWF9QQVlMT0FEOwogCQlsZW4gLT0gUElQRV9NQVhfUEFZTE9BRDsKQEAgLTM1
MTMsNyArMzUxOCw5IEBAIHdyaXRlX3BpcGVfY2h1bmtzKGNoYXIgKmRhdGEsIGludCBsZW4sIGlu
dCBkZXN0KQogCXAucHJvdG8uZmxhZ3MgfD0gUElQRV9QUk9UT19JU19MQVNUOwogCXAucHJvdG8u
bGVuID0gbGVuOwogCW1lbWNweShwLnByb3RvLmRhdGEsIGRhdGEsIGxlbik7CisJcGdzdGF0X3Jl
cG9ydF93YWl0X3N0YXJ0KFdBSVRfRVZFTlRfU1lTTE9HR0VSX1dSSVRFKTsKIAlyYyA9IHdyaXRl
KGZkLCAmcCwgUElQRV9IRUFERVJfU0laRSArIGxlbik7CisJcGdzdGF0X3JlcG9ydF93YWl0X2Vu
ZCgpOwogCSh2b2lkKSByYzsKIH0KIAotLSAKMi41MC4xIChBcHBsZSBHaXQtMTU1KQoK
--0000000000007902f406531abd1a
Content-Type: application/octet-stream;
	name="v2-0002-Report-StderrWrite-wait-event-around-WriteConsole.patch"
Content-Disposition: attachment;
	filename="v2-0002-Report-StderrWrite-wait-event-around-WriteConsole.patch"
Content-Transfer-Encoding: base64
Content-ID: <f_mptnhu3j1>
X-Attachment-Id: f_mptnhu3j1

RnJvbSA4MjEzNTJhMTE4NzIzOTI1NDdjMGFjNjc5MDg3OGVmMDJkMDI4NGI0IE1vbiBTZXAgMTcg
MDA6MDA6MDAgMjAwMQpGcm9tOiBTZW9uZ2p1biBTaGluIDxzaGluc2o0NjUzQGdtYWlsLmNvbT4K
RGF0ZTogRnJpLCAyOSBNYXkgMjAyNiAxNDo1MjoxMSArMDkwMApTdWJqZWN0OiBbUEFUQ0ggdjIg
Mi8yXSBSZXBvcnQgU3RkZXJyV3JpdGUgd2FpdCBldmVudCBhcm91bmQgV3JpdGVDb25zb2xlVygp
CiBvbiBXaW5kb3dzCgpPbiBXaW5kb3dzLCB3cml0ZV9jb25zb2xlKCkgZW1pdHMgbG9nIG1lc3Nh
Z2VzIHRvIHRoZSBjb25zb2xlIHdpdGgKV3JpdGVDb25zb2xlVygpIHJhdGhlciB0aGFuIHdyaXRl
KDIpLiAgTGlrZSB0aGUgd3JpdGUoMikgcGF0aCwgdGhpcwpjYWxsIGNhbiBibG9jayBvbiBhIHNs
b3cgY29uc29sZSwgbGVhdmluZyB3YWl0X2V2ZW50IElTIE5VTEwgaW4KcGdfc3RhdF9hY3Rpdml0
eS4KCldyYXAgV3JpdGVDb25zb2xlVygpIHdpdGggdGhlIFN0ZGVycldyaXRlIHdhaXQgZXZlbnQg
aW50cm9kdWNlZCBpbgp0aGUgcHJldmlvdXMgcGF0Y2gsIHNvIHRoZSBXaW5kb3dzIGNvbnNvbGUg
cGF0aCBpcyBpbnN0cnVtZW50ZWQKY29uc2lzdGVudGx5IHdpdGggdGhlIHN0ZGVyciB3cml0ZSgy
KSBwYXRoLgotLS0KIHNyYy9iYWNrZW5kL3V0aWxzL2Vycm9yL2Vsb2cuYyB8IDMgKysrCiAxIGZp
bGUgY2hhbmdlZCwgMyBpbnNlcnRpb25zKCspCgpkaWZmIC0tZ2l0IGEvc3JjL2JhY2tlbmQvdXRp
bHMvZXJyb3IvZWxvZy5jIGIvc3JjL2JhY2tlbmQvdXRpbHMvZXJyb3IvZWxvZy5jCmluZGV4IGQ0
YzQxZmExMjYzLi45YWI3NWI5OWY1YyAxMDA2NDQKLS0tIGEvc3JjL2JhY2tlbmQvdXRpbHMvZXJy
b3IvZWxvZy5jCisrKyBiL3NyYy9iYWNrZW5kL3V0aWxzL2Vycm9yL2Vsb2cuYwpAQCAtMjYzNSwx
MSArMjYzNSwxNCBAQCB3cml0ZV9jb25zb2xlKGNvbnN0IGNoYXIgKmxpbmUsIGludCBsZW4pCiAJ
CQlEV09SRAkJd3JpdHRlbjsKIAogCQkJc3RkSGFuZGxlID0gR2V0U3RkSGFuZGxlKFNURF9FUlJP
Ul9IQU5ETEUpOworCQkJcGdzdGF0X3JlcG9ydF93YWl0X3N0YXJ0KFdBSVRfRVZFTlRfU1RERVJS
X1dSSVRFKTsKIAkJCWlmIChXcml0ZUNvbnNvbGVXKHN0ZEhhbmRsZSwgdXRmMTYsIHV0ZjE2bGVu
LCAmd3JpdHRlbiwgTlVMTCkpCiAJCQl7CisJCQkJcGdzdGF0X3JlcG9ydF93YWl0X2VuZCgpOwog
CQkJCXBmcmVlKHV0ZjE2KTsKIAkJCQlyZXR1cm47CiAJCQl9CisJCQlwZ3N0YXRfcmVwb3J0X3dh
aXRfZW5kKCk7CiAKIAkJCS8qCiAJCQkgKiBJbiBjYXNlIFdyaXRlQ29uc29sZVcoKSBmYWlsZWQs
IGZhbGwgYmFjayB0byB3cml0aW5nIHRoZQotLSAKMi41MC4xIChBcHBsZSBHaXQtMTU1KQoK
--0000000000007902f406531abd1a--