public inbox for [email protected]
help / color / mirror / Atom feedFrom: Fujii Masao <[email protected]>
To: Tom Lane <[email protected]>
Cc: Jeremy Schneider <[email protected]>
Cc: Jacob Champion <[email protected]>
Cc: [email protected] <[email protected]>
Cc: Marat Buharov <[email protected]>
Cc: Greg Sabino Mullane <[email protected]>
Cc: Thomas Munro <[email protected]>
Subject: Re: client_connection_check_interval default value
Date: Wed, 18 Feb 2026 14:30:22 +0900
Message-ID: <CAHGQGwGw4LhNwOGQT3nbw3uWy8gL94_MB4T39Wfr4_Vgopuovg@mail.gmail.com> (raw)
In-Reply-To: <[email protected]>
References: <[email protected]>
<CAOYmi+nS69LiUExZF=gGZ+NJU-SCNQ59qJTiWtJw96cDdi9iSg@mail.gmail.com>
<[email protected]>
<CAHGQGwHZUmg+r4kMcPYt_Z-txxVX+CJJhfra+qemxKXvAxYbpw@mail.gmail.com>
<[email protected]>
On Fri, Feb 6, 2026 at 9:01 AM Tom Lane <[email protected]> wrote:
> > The issue is that backends blocked in ProcSleep() are woken up every
> > client_connection_check_interval and may emit a "still waiting" message
> > each time if log_lock_waits is enabled. To mitigate this, just one idea is
> > to add a flag to track whether the "still waiting" message has already been
> > emitted during a call to ProcSleep(), and suppress further messages
> > once it has been logged.
>
> Independently of what's the default, it seems like it'd be valuable to
> make that interaction better. I think it is reasonable to keep on
> emitting "still waiting" every so often, but we could probably
> rate-limit that to a lot less than every 2 seconds.
Attached is a patch that rate-limits the "still waiting on lock" message
to at most once every 10s.
I chose 10s instead of the suggested 2s, since 2s felt too short. But we can
discuss the appropriate interval and adjust it if needed. The value is
currently hard-coded, as making it configurable does not seem necessary.
Thoughts?
--
Fujii Masao
Attachments:
[application/octet-stream] v1-0001-Rate-limit-repeated-still-waiting-on-lock-log-mes.patch (3.8K, 2-v1-0001-Rate-limit-repeated-still-waiting-on-lock-log-mes.patch)
download | inline diff:
From aa9e5748f055b9ca76eff9a5e57f7cbfc01ca4aa Mon Sep 17 00:00:00 2001
From: Fujii Masao <[email protected]>
Date: Wed, 18 Feb 2026 00:58:02 +0900
Subject: [PATCH v1] Rate-limit repeated "still waiting on lock" log messages.
When log_lock_waits is enabled, the "still waiting on lock" message is normally
emitted only once while a session continues waiting. However, if the wait is
interrupted, for example by wakeups from client_connection_check_interval,
SIGHUP for configuration reloads, or similar events, the message could be
emitted again each time the wait resumes.
For example, with very small client_connection_check_interval values
(e.g., 100 ms), this behavior could flood the logs with repeated messages,
making them difficult to use.
To prevent this, this commit rate-limits the "still waiting on lock" message to
at most once every 10 seconds. The interval is now hardcoded, as making it
configurable is not considered necessary.
---
src/backend/storage/lmgr/proc.c | 36 +++++++++++++++++++++++++--------
1 file changed, 28 insertions(+), 8 deletions(-)
diff --git a/src/backend/storage/lmgr/proc.c b/src/backend/storage/lmgr/proc.c
index fd8318bdf3d..10f612549f6 100644
--- a/src/backend/storage/lmgr/proc.c
+++ b/src/backend/storage/lmgr/proc.c
@@ -1305,6 +1305,7 @@ ProcSleep(LOCALLOCK *locallock)
TimestampTz standbyWaitStart = 0;
bool allow_autovacuum_cancel = true;
bool logged_recovery_conflict = false;
+ TimestampTz last_logged = 0;
ProcWaitStatus myWaitStatus;
DeadLockState deadlock_state;
@@ -1553,6 +1554,7 @@ ProcSleep(LOCALLOCK *locallock)
lock_waiters_sbuf,
lock_holders_sbuf;
const char *modename;
+ TimestampTz now;
long secs;
int usecs;
long msecs;
@@ -1565,9 +1567,9 @@ ProcSleep(LOCALLOCK *locallock)
DescribeLockTag(&buf, &locallock->tag.lock);
modename = GetLockmodeName(locallock->tag.lock.locktag_lockmethodid,
lockmode);
+ now = GetCurrentTimestamp();
TimestampDifference(get_timeout_start_time(DEADLOCK_TIMEOUT),
- GetCurrentTimestamp(),
- &secs, &usecs);
+ now, &secs, &usecs);
msecs = secs * 1000 + usecs / 1000;
usecs = usecs % 1000;
@@ -1602,12 +1604,30 @@ ProcSleep(LOCALLOCK *locallock)
}
if (myWaitStatus == PROC_WAIT_STATUS_WAITING)
- ereport(LOG,
- (errmsg("process %d still waiting for %s on %s after %ld.%03d ms",
- MyProcPid, modename, buf.data, msecs, usecs),
- (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.",
- "Processes holding the lock: %s. Wait queue: %s.",
- lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data))));
+ {
+ /*
+ * Rate-limit the "still waiting on lock" log message to at
+ * most once every 10 seconds. XXX: This interval is
+ * hardcoded, as making it configurable is unnecessary.
+ *
+ * Without this limit, the message can be emitted whenever the
+ * lock-wait sleep is interrupted (for example by SIGHUP for
+ * config reload or by client_connection_check_interval). For
+ * example, if client_connection_check_interval is set very
+ * low (e.g., 100 ms), the message could be logged repeatedly,
+ * flooding the log and making it difficult to use.
+ */
+ if (TimestampDifferenceExceeds(last_logged, now, 10000))
+ {
+ ereport(LOG,
+ (errmsg("process %d still waiting for %s on %s after %ld.%03d ms",
+ MyProcPid, modename, buf.data, msecs, usecs),
+ (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.",
+ "Processes holding the lock: %s. Wait queue: %s.",
+ lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data))));
+ last_logged = now;
+ }
+ }
else if (myWaitStatus == PROC_WAIT_STATUS_OK)
ereport(LOG,
(errmsg("process %d acquired %s on %s after %ld.%03d ms",
--
2.51.2
view thread (22+ messages) latest in thread
reply
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: [email protected]
Cc: [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected]
Subject: Re: client_connection_check_interval default value
In-Reply-To: <CAHGQGwGw4LhNwOGQT3nbw3uWy8gL94_MB4T39Wfr4_Vgopuovg@mail.gmail.com>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox