MIME-Version: 1.0
From: =?UTF-8?B?7Iug7ISx7KSA?= <shinsj4653@gmail.com>
Date: Sun, 31 May 2026 17:50:08 +0900
Message-ID: 
 <CACdN0M78U+GvpqA7oey-GA7fFSYM636aDp6H9FVvCztv9zXxSA@mail.gmail.com>
Subject: 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="000000000000f276910653192ad7"
Archived-At: 
 <https://www.postgresql.org/message-id/CACdN0M78U%2BGvpqA7oey-GA7fFSYM636aDp6H9FVvCztv9zXxSA%40mail.gmail.com>
Precedence: bulk

--000000000000f276910653192ad7
Content-Type: text/plain; charset="UTF-8"

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.

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

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

RnJvbSA5YzU5MDdiMTFlNWYyMGY5NDI0NzU3ZjQ3NGY4YjljYjhjM2I0MjY2IE1vbiBTZXAgMTcg
MDA6MDA6MDAgMjAwMQpGcm9tOiBTZW9uZ2p1biBTaGluIDxzaGluc2o0NjUzQGdtYWlsLmNvbT4K
RGF0ZTogRnJpLCAyOSBNYXkgMjAyNiAxNDo0NToyMyArMDkwMApTdWJqZWN0OiBbUEFUQ0ggdjEg
MS8yXSBBZGQgd2FpdCBldmVudHMgZm9yIHNlcnZlciBsb2dnaW5nIGRlc3RpbmF0aW9uIHdyaXRl
cwoKV2hlbiBhIGJhY2tlbmQgd3JpdGVzIHRvIHRoZSBzeXNsb2dnZXIgcGlwZSBpbiB3cml0ZV9w
aXBlX2NodW5rcygpIG9yCnRvIHN0ZGVyciBpbiB3cml0ZV9jb25zb2xlKCksIHRoZSB1bmRlcmx5
aW5nIHdyaXRlKDIpIGNhbiBibG9jayBvbmNlCnRoZSBwaXBlIGJ1ZmZlciBmaWxscyB1cCBvciB0
aGUgb3V0cHV0IGRldmljZSBpcyBzbG93LiAgVGhlc2UgYmxvY2tpbmcKc3lzY2FsbHMgd2VyZSBu
b3QgaW5zdHJ1bWVudGVkLCBzbyBwZ19zdGF0X2FjdGl2aXR5IHJlcG9ydGVkCndhaXRfZXZlbnQg
SVMgTlVMTCBkdXJpbmcgdGhhdCB0aW1lLiAgTWFueSBtb25pdG9yaW5nIHRvb2xzIGludGVycHJl
dApOVUxMIGFzIG9uLUNQVSB3b3JrLCB3aGljaCBtYWRlIGhlYXZ5LWxvZ2dpbmcgc3RhbGxzIGhh
cmQgdG8KYXR0cmlidXRlLgoKQWRkIHR3byBuZXcgV2FpdEV2ZW50SU8gZXZlbnRzIGFuZCByZXBv
cnQgdGhlbSBhcm91bmQgdGhlIHJlbGV2YW50CndyaXRlKDIpIGNhbGxzOgoKICBJTyAvIFN5c2xv
Z2dlcldyaXRlIC0gd3JpdGUoMikgdG8gdGhlIHN5c2xvZ2dlciBwaXBlIGluc2lkZQogICAgICAg
ICAgICAgICAgICAgICAgICB3cml0ZV9waXBlX2NodW5rcygpLgogIElPIC8gU3RkZXJyV3JpdGUg
ICAgLSB3cml0ZSgyKSB0byBzdGRlcnIgaW5zaWRlIHdyaXRlX2NvbnNvbGUoKS4KClRoZSBpbnN0
cnVtZW50YXRpb24gaXMgbGltaXRlZCB0byB0aGUgbGVhZiB3cml0ZSBjYWxsLiAgSXQgdXNlcyBv
bmx5CnRoZSBleGlzdGluZyBwZ3N0YXRfcmVwb3J0X3dhaXRfc3RhcnQoKS9lbmQoKSBpbmxpbmUg
aGVscGVycywgd2hpY2gKYXJlIGFsbG9jYXRpb24tZnJlZSBhbmQgc2FmZSB0byBjYWxsIGJlZm9y
ZSBNeVByb2MgaXMgc2V0IHVwLCBzbyB0aGlzCnJlbWFpbnMgc2FmZSB0byBpbnZva2UgZnJvbSB3
aXRoaW4gZXJyb3IgcmVwb3J0aW5nIHBhdGhzLgotLS0KIHNyYy9iYWNrZW5kL3V0aWxzL2FjdGl2
aXR5L3dhaXRfZXZlbnRfbmFtZXMudHh0IHwgMiArKwogc3JjL2JhY2tlbmQvdXRpbHMvZXJyb3Iv
ZWxvZy5jICAgICAgICAgICAgICAgICAgfCA2ICsrKysrKwogMiBmaWxlcyBjaGFuZ2VkLCA4IGlu
c2VydGlvbnMoKykKCmRpZmYgLS1naXQgYS9zcmMvYmFja2VuZC91dGlscy9hY3Rpdml0eS93YWl0
X2V2ZW50X25hbWVzLnR4dCBiL3NyYy9iYWNrZW5kL3V0aWxzL2FjdGl2aXR5L3dhaXRfZXZlbnRf
bmFtZXMudHh0CmluZGV4IDU1MzdhMmQyNTMwLi5jZTMzODA3YzNmZSAxMDA2NDQKLS0tIGEvc3Jj
L2JhY2tlbmQvdXRpbHMvYWN0aXZpdHkvd2FpdF9ldmVudF9uYW1lcy50eHQKKysrIGIvc3JjL2Jh
Y2tlbmQvdXRpbHMvYWN0aXZpdHkvd2FpdF9ldmVudF9uYW1lcy50eHQKQEAgLTI1Myw2ICsyNTMs
OCBAQCBTTFJVX1dSSVRFCSJXYWl0aW5nIGZvciBhIHdyaXRlIG9mIGFuIFNMUlUgcGFnZS4iCiBT
TkFQQlVJTERfUkVBRAkiV2FpdGluZyBmb3IgYSByZWFkIG9mIGEgc2VyaWFsaXplZCBoaXN0b3Jp
Y2FsIGNhdGFsb2cgc25hcHNob3QuIgogU05BUEJVSUxEX1NZTkMJIldhaXRpbmcgZm9yIGEgc2Vy
aWFsaXplZCBoaXN0b3JpY2FsIGNhdGFsb2cgc25hcHNob3QgdG8gcmVhY2ggZHVyYWJsZSBzdG9y
YWdlLiIKIFNOQVBCVUlMRF9XUklURQkiV2FpdGluZyBmb3IgYSB3cml0ZSBvZiBhIHNlcmlhbGl6
ZWQgaGlzdG9yaWNhbCBjYXRhbG9nIHNuYXBzaG90LiIKK1NUREVSUl9XUklURQkiV2FpdGluZyBm
b3IgYSB3cml0ZSB0byB0aGUgc2VydmVyJ3Mgc3RhbmRhcmQgZXJyb3Igc3RyZWFtLiIKK1NZU0xP
R0dFUl9XUklURQkiV2FpdGluZyBmb3IgYSB3cml0ZSB0byB0aGUgc3lzbG9nZ2VyIHBpcGUuIgog
VElNRUxJTkVfSElTVE9SWV9GSUxFX1NZTkMJIldhaXRpbmcgZm9yIGEgdGltZWxpbmUgaGlzdG9y
eSBmaWxlIHJlY2VpdmVkIHZpYSBzdHJlYW1pbmcgcmVwbGljYXRpb24gdG8gcmVhY2ggZHVyYWJs
ZSBzdG9yYWdlLiIKIFRJTUVMSU5FX0hJU1RPUllfRklMRV9XUklURQkiV2FpdGluZyBmb3IgYSB3
cml0ZSBvZiBhIHRpbWVsaW5lIGhpc3RvcnkgZmlsZSByZWNlaXZlZCB2aWEgc3RyZWFtaW5nIHJl
cGxpY2F0aW9uLiIKIFRJTUVMSU5FX0hJU1RPUllfUkVBRAkiV2FpdGluZyBmb3IgYSByZWFkIG9m
IGEgdGltZWxpbmUgaGlzdG9yeSBmaWxlLiIKZGlmZiAtLWdpdCBhL3NyYy9iYWNrZW5kL3V0aWxz
L2Vycm9yL2Vsb2cuYyBiL3NyYy9iYWNrZW5kL3V0aWxzL2Vycm9yL2Vsb2cuYwppbmRleCBhYTUz
MGQzNjg1ZS4uZmEzOGQ2YzZkZjggMTAwNjQ0Ci0tLSBhL3NyYy9iYWNrZW5kL3V0aWxzL2Vycm9y
L2Vsb2cuYworKysgYi9zcmMvYmFja2VuZC91dGlscy9lcnJvci9lbG9nLmMKQEAgLTI2NjIsNyAr
MjY2Miw5IEBAIHdyaXRlX2NvbnNvbGUoY29uc3QgY2hhciAqbGluZSwgaW50IGxlbikKIAkgKiBX
ZSBpZ25vcmUgYW55IGVycm9yIGZyb20gd3JpdGUoKSBoZXJlLiAgV2UgaGF2ZSBubyB1c2VmdWwg
d2F5IHRvIHJlcG9ydAogCSAqIGl0IC4uLiBjZXJ0YWlubHkgd2hpbmluZyBvbiBzdGRlcnIgaXNu
J3QgbGlrZWx5IHRvIGJlIHByb2R1Y3RpdmUuCiAJICovCisJcGdzdGF0X3JlcG9ydF93YWl0X3N0
YXJ0KFdBSVRfRVZFTlRfU1RERVJSX1dSSVRFKTsKIAlyYyA9IHdyaXRlKGZpbGVubyhzdGRlcnIp
LCBsaW5lLCBsZW4pOworCXBnc3RhdF9yZXBvcnRfd2FpdF9lbmQoKTsKIAkodm9pZCkgcmM7CiB9
CiAKQEAgLTM1MDMsNyArMzUwNSw5IEBAIHdyaXRlX3BpcGVfY2h1bmtzKGNoYXIgKmRhdGEsIGlu
dCBsZW4sIGludCBkZXN0KQogCQkvKiBubyBuZWVkIHRvIHNldCBQSVBFX1BST1RPX0lTX0xBU1Qg
eWV0ICovCiAJCXAucHJvdG8ubGVuID0gUElQRV9NQVhfUEFZTE9BRDsKIAkJbWVtY3B5KHAucHJv
dG8uZGF0YSwgZGF0YSwgUElQRV9NQVhfUEFZTE9BRCk7CisJCXBnc3RhdF9yZXBvcnRfd2FpdF9z
dGFydChXQUlUX0VWRU5UX1NZU0xPR0dFUl9XUklURSk7CiAJCXJjID0gd3JpdGUoZmQsICZwLCBQ
SVBFX0hFQURFUl9TSVpFICsgUElQRV9NQVhfUEFZTE9BRCk7CisJCXBnc3RhdF9yZXBvcnRfd2Fp
dF9lbmQoKTsKIAkJKHZvaWQpIHJjOwogCQlkYXRhICs9IFBJUEVfTUFYX1BBWUxPQUQ7CiAJCWxl
biAtPSBQSVBFX01BWF9QQVlMT0FEOwpAQCAtMzUxMyw3ICszNTE3LDkgQEAgd3JpdGVfcGlwZV9j
aHVua3MoY2hhciAqZGF0YSwgaW50IGxlbiwgaW50IGRlc3QpCiAJcC5wcm90by5mbGFncyB8PSBQ
SVBFX1BST1RPX0lTX0xBU1Q7CiAJcC5wcm90by5sZW4gPSBsZW47CiAJbWVtY3B5KHAucHJvdG8u
ZGF0YSwgZGF0YSwgbGVuKTsKKwlwZ3N0YXRfcmVwb3J0X3dhaXRfc3RhcnQoV0FJVF9FVkVOVF9T
WVNMT0dHRVJfV1JJVEUpOwogCXJjID0gd3JpdGUoZmQsICZwLCBQSVBFX0hFQURFUl9TSVpFICsg
bGVuKTsKKwlwZ3N0YXRfcmVwb3J0X3dhaXRfZW5kKCk7CiAJKHZvaWQpIHJjOwogfQogCi0tIAoy
LjUwLjEgKEFwcGxlIEdpdC0xNTUpCgo=
--000000000000f276910653192ad7
Content-Type: application/octet-stream;
	name="v1-0002-Report-StderrWrite-wait-event-around-WriteConsole.patch"
Content-Disposition: attachment;
	filename="v1-0002-Report-StderrWrite-wait-event-around-WriteConsole.patch"
Content-Transfer-Encoding: base64
Content-ID: <f_mptjat9g1>
X-Attachment-Id: f_mptjat9g1

RnJvbSA0ZDY3ZDE1YzU2ZGE4MDRiNTQxNDI2ZjU1ODNmOThjOGI3N2NiMTlmIE1vbiBTZXAgMTcg
MDA6MDA6MDAgMjAwMQpGcm9tOiBTZW9uZ2p1biBTaGluIDxzaGluc2o0NjUzQGdtYWlsLmNvbT4K
RGF0ZTogRnJpLCAyOSBNYXkgMjAyNiAxNDo1MjoxMSArMDkwMApTdWJqZWN0OiBbUEFUQ0ggdjEg
Mi8yXSBSZXBvcnQgU3RkZXJyV3JpdGUgd2FpdCBldmVudCBhcm91bmQgV3JpdGVDb25zb2xlVygp
CiBvbiBXaW5kb3dzCgpPbiBXaW5kb3dzLCB3cml0ZV9jb25zb2xlKCkgZW1pdHMgbG9nIG1lc3Nh
Z2VzIHRvIHRoZSBjb25zb2xlIHdpdGgKV3JpdGVDb25zb2xlVygpIHJhdGhlciB0aGFuIHdyaXRl
KDIpLiAgTGlrZSB0aGUgd3JpdGUoMikgcGF0aCwgdGhpcwpjYWxsIGNhbiBibG9jayBvbiBhIHNs
b3cgY29uc29sZSwgbGVhdmluZyB3YWl0X2V2ZW50IElTIE5VTEwgaW4KcGdfc3RhdF9hY3Rpdml0
eS4KCldyYXAgV3JpdGVDb25zb2xlVygpIHdpdGggdGhlIFN0ZGVycldyaXRlIHdhaXQgZXZlbnQg
aW50cm9kdWNlZCBpbgp0aGUgcHJldmlvdXMgcGF0Y2gsIHNvIHRoZSBXaW5kb3dzIGNvbnNvbGUg
cGF0aCBpcyBpbnN0cnVtZW50ZWQKY29uc2lzdGVudGx5IHdpdGggdGhlIHN0ZGVyciB3cml0ZSgy
KSBwYXRoLgotLS0KIHNyYy9iYWNrZW5kL3V0aWxzL2Vycm9yL2Vsb2cuYyB8IDMgKysrCiAxIGZp
bGUgY2hhbmdlZCwgMyBpbnNlcnRpb25zKCspCgpkaWZmIC0tZ2l0IGEvc3JjL2JhY2tlbmQvdXRp
bHMvZXJyb3IvZWxvZy5jIGIvc3JjL2JhY2tlbmQvdXRpbHMvZXJyb3IvZWxvZy5jCmluZGV4IGZh
MzhkNmM2ZGY4Li5kMTllYzZhMzFlOCAxMDA2NDQKLS0tIGEvc3JjL2JhY2tlbmQvdXRpbHMvZXJy
b3IvZWxvZy5jCisrKyBiL3NyYy9iYWNrZW5kL3V0aWxzL2Vycm9yL2Vsb2cuYwpAQCAtMjYzNCwx
MSArMjYzNCwxNCBAQCB3cml0ZV9jb25zb2xlKGNvbnN0IGNoYXIgKmxpbmUsIGludCBsZW4pCiAJ
CQlEV09SRAkJd3JpdHRlbjsKIAogCQkJc3RkSGFuZGxlID0gR2V0U3RkSGFuZGxlKFNURF9FUlJP
Ul9IQU5ETEUpOworCQkJcGdzdGF0X3JlcG9ydF93YWl0X3N0YXJ0KFdBSVRfRVZFTlRfU1RERVJS
X1dSSVRFKTsKIAkJCWlmIChXcml0ZUNvbnNvbGVXKHN0ZEhhbmRsZSwgdXRmMTYsIHV0ZjE2bGVu
LCAmd3JpdHRlbiwgTlVMTCkpCiAJCQl7CisJCQkJcGdzdGF0X3JlcG9ydF93YWl0X2VuZCgpOwog
CQkJCXBmcmVlKHV0ZjE2KTsKIAkJCQlyZXR1cm47CiAJCQl9CisJCQlwZ3N0YXRfcmVwb3J0X3dh
aXRfZW5kKCk7CiAKIAkJCS8qCiAJCQkgKiBJbiBjYXNlIFdyaXRlQ29uc29sZVcoKSBmYWlsZWQs
IGZhbGwgYmFjayB0byB3cml0aW5nIHRoZQotLSAKMi41MC4xIChBcHBsZSBHaXQtMTU1KQoK
--000000000000f276910653192ad7--