On Tue, Oct 1, 2024 at 11:45 AM wenhui qiu <[email protected]> wrote:
>
> Hi Alexey Orlov
> Thank you for your work on this path,The lock information is recorded in
> detail,Easy to trace the lock competition at that time there is a detailed
> lock competition log，But I have a concern,Frequent calls to this function
> (pgstat_get_backend_current_activity) in heavy lock contention or high
> concurrency environments may cause performance degradation, especially when
> processes frequently enter and exit lock waits. Can you add a guc parameter
> to turn this feature on or off?After all communities for this parameter(
> log_lock_waits )default values set to on many people concern
> (https://commitfest.postgresql.org/49/4718/)
>
>
>
> Thanks
>
Yeah, agree, thank you. I just think changing the parameter type would
be nice too.
typedef enum
{
LOG_LOCK_WAIT_NONE = 0,
LOG_LOCK_WAIT_TERSE,
LOG_LOCK_WAIT_VERBOSE,
} LogLockWaitVerbosity;
LOG_LOCK_WAIT_NONE is "off", LOG_LOCK_WAIT_TERSE is "on",
LOG_LOCK_WAIT_VERBOSE enables writing the query to to the log.
I've attached a slightly modified patch to use the new log_lock_wait values.
--
Regards,
Alexey Orlov!
From 0e1835146df63f104f6d4460ffb357a93732eefa Mon Sep 17 00:00:00 2001
From: Alexey Orlov <[email protected]>
Date: Wed, 2 Oct 2024 12:08:13 +0300
Subject: [PATCH v=2] Show queries in log_lock_wait
---
src/backend/storage/lmgr/proc.c | 22 ++++++++++++++-----
src/backend/utils/misc/guc_tables.c | 33 +++++++++++++++++++++--------
src/include/storage/proc.h | 9 +++++++-
3 files changed, 49 insertions(+), 15 deletions(-)
diff --git a/src/backend/storage/lmgr/proc.c b/src/backend/storage/lmgr/proc.c
index 0d8162a2cc..60b749b140 100644
--- a/src/backend/storage/lmgr/proc.c
+++ b/src/backend/storage/lmgr/proc.c
@@ -61,7 +61,7 @@ int LockTimeout = 0;
int IdleInTransactionSessionTimeout = 0;
int TransactionTimeout = 0;
int IdleSessionTimeout = 0;
-bool log_lock_waits = false;
+int log_lock_waits = LOG_LOCK_WAIT_NONE;
/* Pointer to this process's PGPROC struct, if any */
PGPROC *MyProc = NULL;
@@ -1514,7 +1514,8 @@ ProcSleep(LOCALLOCK *locallock, LockMethod lockMethodTable, bool dontWait)
{
StringInfoData buf,
lock_waiters_sbuf,
- lock_holders_sbuf;
+ lock_holders_sbuf,
+ lock_queries_sbuf;
const char *modename;
long secs;
int usecs;
@@ -1528,6 +1529,7 @@ ProcSleep(LOCALLOCK *locallock, LockMethod lockMethodTable, bool dontWait)
initStringInfo(&buf);
initStringInfo(&lock_waiters_sbuf);
initStringInfo(&lock_holders_sbuf);
+ initStringInfo(&lock_queries_sbuf);
DescribeLockTag(&buf, &locallock->tag.lock);
modename = GetLockmodeName(locallock->tag.lock.locktag_lockmethodid,
@@ -1572,6 +1574,15 @@ ProcSleep(LOCALLOCK *locallock, LockMethod lockMethodTable, bool dontWait)
}
else
{
+ if (log_lock_waits == LOG_LOCK_WAIT_VERBOSE && myWaitStatus == PROC_WAIT_STATUS_WAITING)
+ {
+ appendStringInfoChar(&lock_queries_sbuf, '\n');
+
+ appendStringInfo(&lock_queries_sbuf,
+ _("Process %d: %s"),
+ curproclock->tag.myProc->pid,
+ pgstat_get_backend_current_activity(curproclock->tag.myProc->pid, false));
+ }
if (first_holder)
{
appendStringInfo(&lock_holders_sbuf, "%d",
@@ -1616,9 +1627,9 @@ ProcSleep(LOCALLOCK *locallock, LockMethod lockMethodTable, bool dontWait)
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))));
+ (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.%s",
+ "Processes holding the lock: %s. Wait queue: %s.%s",
+ lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data, lock_queries_sbuf.data))));
else if (myWaitStatus == PROC_WAIT_STATUS_OK)
ereport(LOG,
(errmsg("process %d acquired %s on %s after %ld.%03d ms",
@@ -1654,6 +1665,7 @@ ProcSleep(LOCALLOCK *locallock, LockMethod lockMethodTable, bool dontWait)
pfree(buf.data);
pfree(lock_holders_sbuf.data);
pfree(lock_waiters_sbuf.data);
+ pfree(lock_queries_sbuf.data);
}
} while (myWaitStatus == PROC_WAIT_STATUS_WAITING);
diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c
index 686309db58..1eddaaf0e5 100644
--- a/src/backend/utils/misc/guc_tables.c
+++ b/src/backend/utils/misc/guc_tables.c
@@ -474,6 +474,20 @@ static const struct config_enum_entry wal_compression_options[] = {
{NULL, 0, false}
};
+static const struct config_enum_entry log_lock_waits_options[] = {
+ {"verbose", LOG_LOCK_WAIT_VERBOSE, false},
+ {"terse", LOG_LOCK_WAIT_TERSE, false},
+ {"on", LOG_LOCK_WAIT_TERSE, false},
+ {"off", LOG_LOCK_WAIT_NONE, false},
+ {"true", LOG_LOCK_WAIT_TERSE, true},
+ {"false", LOG_LOCK_WAIT_NONE, true},
+ {"yes", LOG_LOCK_WAIT_TERSE, true},
+ {"no", LOG_LOCK_WAIT_NONE, true},
+ {"1", LOG_LOCK_WAIT_TERSE, true},
+ {"0", LOG_LOCK_WAIT_NONE, true},
+ {NULL, 0, false}
+};
+
/*
* Options for enum values stored in other modules
*/
@@ -1552,15 +1566,6 @@ struct config_bool ConfigureNamesBool[] =
},
#endif
- {
- {"log_lock_waits", PGC_SUSET, LOGGING_WHAT,
- gettext_noop("Logs long lock waits."),
- NULL
- },
- &log_lock_waits,
- false,
- NULL, NULL, NULL
- },
{
{"log_recovery_conflict_waits", PGC_SIGHUP, LOGGING_WHAT,
gettext_noop("Logs standby recovery conflict waits."),
@@ -5022,6 +5027,16 @@ struct config_enum ConfigureNamesEnum[] =
NULL, NULL, NULL
},
+ {
+ {"log_lock_waits", PGC_SUSET, LOGGING_WHAT,
+ gettext_noop("Logs long lock waits."),
+ NULL
+ },
+ &log_lock_waits,
+ LOG_LOCK_WAIT_NONE, log_lock_waits_options,
+ NULL, NULL, NULL
+ },
+
{
{"wal_level", PGC_POSTMASTER, WAL_SETTINGS,
gettext_noop("Sets the level of information written to the WAL."),
diff --git a/src/include/storage/proc.h b/src/include/storage/proc.h
index ebcf0ad403..fca95196e4 100644
--- a/src/include/storage/proc.h
+++ b/src/include/storage/proc.h
@@ -132,6 +132,13 @@ typedef enum
PROC_WAIT_STATUS_ERROR,
} ProcWaitStatus;
+typedef enum
+{
+ LOG_LOCK_WAIT_NONE = 0,
+ LOG_LOCK_WAIT_TERSE,
+ LOG_LOCK_WAIT_VERBOSE,
+} LogLockWaitVerbosity;
+
/*
* Each backend has a PGPROC struct in shared memory. There is also a list of
* currently-unused PGPROC structs that will be reallocated to new backends.
@@ -456,7 +463,7 @@ extern PGDLLIMPORT int LockTimeout;
extern PGDLLIMPORT int IdleInTransactionSessionTimeout;
extern PGDLLIMPORT int TransactionTimeout;
extern PGDLLIMPORT int IdleSessionTimeout;
-extern PGDLLIMPORT bool log_lock_waits;
+extern PGDLLIMPORT int log_lock_waits;
#ifdef EXEC_BACKEND
extern PGDLLIMPORT slock_t *ProcStructLock;
--
2.44.0
