From cf7542da3afb01f0eb61031a28c7c8d44f3dc04d Mon Sep 17 00:00:00 2001 From: Seongjun Shin Date: Fri, 29 May 2026 14:45:23 +0900 Subject: [PATCH v4 1/2] Add wait events for server logging destination writes When a backend writes server log output, the underlying call can block: write(2) to the syslogger pipe or to stderr once the pipe buffer fills up or the output device is slow, and syslog(3) when the system logger is slow. These blocking calls were not instrumented, so pg_stat_activity reported wait_event IS NULL during that time. Many monitoring tools interpret NULL as on-CPU work, which made heavy-logging stalls hard to attribute. Add three new WaitEventIO events and report them around the relevant calls: IO / SysloggerWrite - write(2) to the syslogger pipe inside write_pipe_chunks(). IO / StderrWrite - write(2) to stderr inside write_console(). IO / SyslogWrite - syslog(3) inside write_syslog(). The instrumentation is limited to the leaf write/syslog call. It uses only the existing pgstat_report_wait_start()/end() inline helpers, which are allocation-free and safe to call before MyProc is set up, so this remains safe to invoke from within error reporting paths. --- src/backend/utils/activity/wait_event_names.txt | 3 +++ src/backend/utils/error/elog.c | 11 +++++++++++ 2 files changed, 14 insertions(+) diff --git a/src/backend/utils/activity/wait_event_names.txt b/src/backend/utils/activity/wait_event_names.txt index 560659f9568..d4a0f6361ad 100644 --- a/src/backend/utils/activity/wait_event_names.txt +++ b/src/backend/utils/activity/wait_event_names.txt @@ -258,6 +258,9 @@ SLRU_WRITE "Waiting for a write of an SLRU page." SNAPBUILD_READ "Waiting for a read of a serialized historical catalog snapshot." SNAPBUILD_SYNC "Waiting for a serialized historical catalog snapshot to reach durable storage." SNAPBUILD_WRITE "Waiting for a write of a serialized historical catalog snapshot." +STDERR_WRITE "Waiting for a write to the server's standard error stream." +SYSLOGGER_WRITE "Waiting for a write to the syslogger pipe." +SYSLOG_WRITE "Waiting for a write to the system logger (syslog)." TIMELINE_HISTORY_FILE_SYNC "Waiting for a timeline history file received via streaming replication to reach durable storage." TIMELINE_HISTORY_FILE_WRITE "Waiting for a write of a timeline history file received via streaming replication." TIMELINE_HISTORY_READ "Waiting for a read of a timeline history file." diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c index 50c53b571a0..8d659b096f4 100644 --- a/src/backend/utils/error/elog.c +++ b/src/backend/utils/error/elog.c @@ -89,6 +89,7 @@ #include "utils/pg_locale.h" #include "utils/ps_status.h" #include "utils/varlena.h" +#include "utils/wait_event.h" /* In this module, access gettext() via err_gettext() */ @@ -2890,10 +2891,12 @@ write_syslog(int level, const char *line) chunk_nr++; + pgstat_report_wait_start(WAIT_EVENT_SYSLOG_WRITE); if (syslog_sequence_numbers) syslog(level, "[%lu-%d] %s", seq, chunk_nr, buf); else syslog(level, "[%d] %s", chunk_nr, buf); + pgstat_report_wait_end(); line += buflen; len -= buflen; @@ -2902,10 +2905,12 @@ write_syslog(int level, const char *line) else { /* message short enough */ + pgstat_report_wait_start(WAIT_EVENT_SYSLOG_WRITE); if (syslog_sequence_numbers) syslog(level, "[%lu] %s", seq, line); else syslog(level, "%s", line); + pgstat_report_wait_end(); } } #endif /* HAVE_SYSLOG */ @@ -3090,7 +3095,9 @@ write_console(const char *line, int len) * We ignore any error from write() here. We have no useful way to report * it ... certainly whining on stderr isn't likely to be productive. */ + pgstat_report_wait_start(WAIT_EVENT_STDERR_WRITE); rc = write(fileno(stderr), line, len); + pgstat_report_wait_end(); (void) rc; } @@ -3937,7 +3944,9 @@ write_pipe_chunks(char *data, int len, int dest) /* no need to set PIPE_PROTO_IS_LAST yet */ p.proto.len = PIPE_MAX_PAYLOAD; memcpy(p.proto.data, data, PIPE_MAX_PAYLOAD); + pgstat_report_wait_start(WAIT_EVENT_SYSLOGGER_WRITE); rc = write(fd, &p, PIPE_HEADER_SIZE + PIPE_MAX_PAYLOAD); + pgstat_report_wait_end(); (void) rc; data += PIPE_MAX_PAYLOAD; len -= PIPE_MAX_PAYLOAD; @@ -3947,7 +3956,9 @@ write_pipe_chunks(char *data, int len, int dest) p.proto.flags |= PIPE_PROTO_IS_LAST; p.proto.len = len; memcpy(p.proto.data, data, len); + pgstat_report_wait_start(WAIT_EVENT_SYSLOGGER_WRITE); rc = write(fd, &p, PIPE_HEADER_SIZE + len); + pgstat_report_wait_end(); (void) rc; } -- 2.50.1 (Apple Git-155)