v1-0001-Rate-limit-repeated-still-waiting-on-lock-log-mes.patch

From aa9e5748f055b9ca76eff9a5e57f7cbfc01ca4aa Mon Sep 17 00:00:00 2001
From: Fujii Masao <fujii@postgresql.org>
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