v-3-0001-Show-queries-in-log_lock_wait_log.patch

From 2ee0866d06d78f29b971c97a399b11261bd61861 Mon Sep 17 00:00:00 2001
From: Alexey Orlov <aporlov@tender.pro>
Date: Thu, 3 Oct 2024 12:02:47 +0300
Subject: [PATCH v=3] Show queries in log_lock_wait_log

---
 src/backend/storage/lmgr/deadlock.c         |  2 +-
 src/backend/storage/lmgr/proc.c             | 22 ++++++++++----
 src/backend/utils/activity/backend_status.c |  4 ++-
 src/backend/utils/misc/guc_tables.c         | 33 +++++++++++++++------
 src/include/storage/proc.h                  |  9 +++++-
 src/include/utils/backend_status.h          |  2 +-
 6 files changed, 54 insertions(+), 18 deletions(-)

diff --git a/src/backend/storage/lmgr/deadlock.c b/src/backend/storage/lmgr/deadlock.c
index fcb874d234..96c96b3dab 100644
--- a/src/backend/storage/lmgr/deadlock.c
+++ b/src/backend/storage/lmgr/deadlock.c
@@ -1122,7 +1122,7 @@ DeadLockReport(void)
 		appendStringInfo(&logbuf,
 						 _("Process %d: %s"),
 						 info->pid,
-						 pgstat_get_backend_current_activity(info->pid, false));
+						 pgstat_get_backend_current_activity(info->pid, false, false));
 	}
 
 	pgstat_report_deadlock();
diff --git a/src/backend/storage/lmgr/proc.c b/src/backend/storage/lmgr/proc.c
index 0d8162a2cc..09a4430eff 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, true));
+					}
 					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/activity/backend_status.c b/src/backend/utils/activity/backend_status.c
index 34a55e2177..43080b1a2c 100644
--- a/src/backend/utils/activity/backend_status.c
+++ b/src/backend/utils/activity/backend_status.c
@@ -882,7 +882,7 @@ pgstat_read_current_status(void)
  * ----------
  */
 const char *
-pgstat_get_backend_current_activity(int pid, bool checkUser)
+pgstat_get_backend_current_activity(int pid, bool checkUser, bool checkDeadLockTimeout)
 {
 	PgBackendStatus *beentry;
 	int			i;
@@ -929,6 +929,8 @@ pgstat_get_backend_current_activity(int pid, bool checkUser)
 				return "<insufficient privilege>";
 			else if (*(beentry->st_activity_raw) == '\0')
 				return "<command string not enabled>";
+			else if (checkDeadLockTimeout && !TimestampDifferenceExceeds(beentry->st_activity_start_timestamp, GetCurrentTimestamp(), DeadlockTimeout))
+				return "<command string has been changed>";
 			else
 			{
 				/* this'll leak a bit of memory, but that seems acceptable */
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;
diff --git a/src/include/utils/backend_status.h b/src/include/utils/backend_status.h
index 97874300c3..f0fba3b0f6 100644
--- a/src/include/utils/backend_status.h
+++ b/src/include/utils/backend_status.h
@@ -319,7 +319,7 @@ extern void pgstat_report_query_id(uint64 query_id, bool force);
 extern void pgstat_report_tempfile(size_t filesize);
 extern void pgstat_report_appname(const char *appname);
 extern void pgstat_report_xact_timestamp(TimestampTz tstamp);
-extern const char *pgstat_get_backend_current_activity(int pid, bool checkUser);
+extern const char *pgstat_get_backend_current_activity(int pid, bool checkUser, bool checkDeadLockTimeout);
 extern const char *pgstat_get_crashed_backend_activity(int pid, char *buffer,
 													   int buflen);
 extern uint64 pgstat_get_my_query_id(void);
-- 
2.44.0