v6-0001_add_log_lock_failure.patch

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index a8866292d4..68fcc80c29 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7589,6 +7589,25 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
       </listitem>
      </varlistentry>
 
+     <varlistentry id="guc-log-lock-failure" xreflabel="log_lock_failure">
+      <term><varname>log_lock_failure</varname> (<type>boolean</type>)
+      <indexterm>
+       <primary><varname>log_lock_failure</varname> configuration parameter</primary>
+      </indexterm>
+      </term>
+      <listitem>
+       <para>
+        Controls whether a log message is produced when a lock acquisition
+        fails.  This is useful for analyzing the causes of lock failures.
+        Currently, only lock failures due to <literal>NOWAIT</literal> and
+        <literal>SKIP LOCKED</literal> are supported.  The default is
+        <literal>off</literal>.  Only superusers and users with the
+        appropriate <literal>SET</literal> privilege can change this setting.
+       </para>
+      </listitem>
+     </varlistentry>
+
+
      <varlistentry id="guc-log-recovery-conflict-waits" xreflabel="log_recovery_conflict_waits">
       <term><varname>log_recovery_conflict_waits</varname> (<type>boolean</type>)
       <indexterm>
diff --git a/src/backend/storage/lmgr/lmgr.c b/src/backend/storage/lmgr/lmgr.c
index 68271cb640..73cf835c93 100644
--- a/src/backend/storage/lmgr/lmgr.c
+++ b/src/backend/storage/lmgr/lmgr.c
@@ -1332,3 +1332,59 @@ GetLockNameFromTagType(uint16 locktag_type)
 		return "???";
 	return LockTagTypeNames[locktag_type];
 }
+
+/*
+ * 		CollectLockHoldersAndWaiters
+ *
+ * we loop over the lock's procLocks to gather a list of all
+ * holders and waiters. Thus we will be able to provide more
+ * detailed information for lock debugging purposes.
+ *
+ * lock->procLocks contains all processes which hold or wait for
+ * this lock.
+ */
+void
+CollectLockHoldersAndWaiters(LOCK *lock, StringInfo lock_holders_sbuf, StringInfo lock_waiters_sbuf, int *lockHoldersNum)
+{
+	bool first_holder = true;
+	bool first_waiter = true;
+	dlist_iter proc_iter;
+	PROCLOCK *curproclock;
+
+	dlist_foreach(proc_iter, &lock->procLocks)
+	{
+		curproclock =
+			dlist_container(PROCLOCK, lockLink, proc_iter.cur);
+
+		/*
+		* we are a waiter if myProc->waitProcLock == curproclock; we
+		* are a holder if it is NULL or something different
+		*/
+		if (curproclock->tag.myProc->waitProcLock == curproclock)
+		{
+			if (first_waiter)
+			{
+				appendStringInfo(lock_waiters_sbuf, "%d",
+									curproclock->tag.myProc->pid);
+				first_waiter = false;
+			}
+			else
+				appendStringInfo(lock_waiters_sbuf, ", %d",
+									curproclock->tag.myProc->pid);
+		}
+		else
+		{
+			if (first_holder)
+			{
+				appendStringInfo(lock_holders_sbuf, "%d",
+									curproclock->tag.myProc->pid);
+				first_holder = false;
+			}
+			else
+				appendStringInfo(lock_holders_sbuf, ", %d",
+									curproclock->tag.myProc->pid);
+
+			(*lockHoldersNum)++;
+		}
+	}
+}
\ No newline at end of file
diff --git a/src/backend/storage/lmgr/lock.c b/src/backend/storage/lmgr/lock.c
index 3e2f98b371..eee3c3f585 100644
--- a/src/backend/storage/lmgr/lock.c
+++ b/src/backend/storage/lmgr/lock.c
@@ -39,6 +39,7 @@
 #include "access/xlogutils.h"
 #include "miscadmin.h"
 #include "pg_trace.h"
+#include "storage/lmgr.h"
 #include "storage/proc.h"
 #include "storage/procarray.h"
 #include "storage/spin.h"
@@ -47,9 +48,10 @@
 #include "utils/ps_status.h"
 #include "utils/resowner.h"
 
+/* GUC variables. */
+int			max_locks_per_xact; /* This configuration variable is used to set the lock table size */
+bool		log_lock_failure = false;
 
-/* This configuration variable is used to set the lock table size */
-int			max_locks_per_xact; /* set by guc.c */
 
 #define NLOCKENTS() \
 	mul_size(max_locks_per_xact, add_size(MaxBackends, max_prepared_xacts))
@@ -1145,6 +1147,37 @@ LockAcquireExtended(const LOCKTAG *locktag,
 
 		if (dontWait)
 		{
+			if (log_lock_failure)
+			{
+				StringInfoData buf,
+							lock_waiters_sbuf,
+							lock_holders_sbuf;
+				const char *modename;
+				int			lockHoldersNum = 0;
+				initStringInfo(&buf);
+				initStringInfo(&lock_waiters_sbuf);
+				initStringInfo(&lock_holders_sbuf);
+
+				LWLockAcquire(partitionLock, LW_SHARED);
+				DescribeLockTag(&buf, &locallock->tag.lock);
+				modename = GetLockmodeName(locallock->tag.lock.locktag_lockmethodid,
+											lockmode);
+
+				/* Collect lock holders and waiters */
+				CollectLockHoldersAndWaiters(lock, &lock_holders_sbuf, &lock_waiters_sbuf, &lockHoldersNum);
+
+				if (lock_waiters_sbuf.len == 0)
+				{
+					appendStringInfoString(&lock_waiters_sbuf, "None");
+				}
+				ereport(LOG,
+								(errmsg("process %d could not obtain %s on %s",
+										MyProcPid, modename, buf.data),
+								(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))));
+				LWLockRelease(partitionLock);
+			}
 			if (locallockp)
 				*locallockp = NULL;
 			return LOCKACQUIRE_NOT_AVAIL;
diff --git a/src/backend/storage/lmgr/proc.c b/src/backend/storage/lmgr/proc.c
index 49204f91a2..a4c0bf70e8 100644
--- a/src/backend/storage/lmgr/proc.c
+++ b/src/backend/storage/lmgr/proc.c
@@ -1514,10 +1514,6 @@ ProcSleep(LOCALLOCK *locallock)
 			long		secs;
 			int			usecs;
 			long		msecs;
-			dlist_iter	proc_iter;
-			PROCLOCK   *curproclock;
-			bool		first_holder = true,
-						first_waiter = true;
 			int			lockHoldersNum = 0;
 
 			initStringInfo(&buf);
@@ -1533,53 +1529,10 @@ ProcSleep(LOCALLOCK *locallock)
 			msecs = secs * 1000 + usecs / 1000;
 			usecs = usecs % 1000;
 
-			/*
-			 * we loop over the lock's procLocks to gather a list of all
-			 * holders and waiters. Thus we will be able to provide more
-			 * detailed information for lock debugging purposes.
-			 *
-			 * lock->procLocks contains all processes which hold or wait for
-			 * this lock.
-			 */
-
 			LWLockAcquire(partitionLock, LW_SHARED);
 
-			dlist_foreach(proc_iter, &lock->procLocks)
-			{
-				curproclock =
-					dlist_container(PROCLOCK, lockLink, proc_iter.cur);
-
-				/*
-				 * we are a waiter if myProc->waitProcLock == curproclock; we
-				 * are a holder if it is NULL or something different
-				 */
-				if (curproclock->tag.myProc->waitProcLock == curproclock)
-				{
-					if (first_waiter)
-					{
-						appendStringInfo(&lock_waiters_sbuf, "%d",
-										 curproclock->tag.myProc->pid);
-						first_waiter = false;
-					}
-					else
-						appendStringInfo(&lock_waiters_sbuf, ", %d",
-										 curproclock->tag.myProc->pid);
-				}
-				else
-				{
-					if (first_holder)
-					{
-						appendStringInfo(&lock_holders_sbuf, "%d",
-										 curproclock->tag.myProc->pid);
-						first_holder = false;
-					}
-					else
-						appendStringInfo(&lock_holders_sbuf, ", %d",
-										 curproclock->tag.myProc->pid);
-
-					lockHoldersNum++;
-				}
-			}
+			/* Collect lock holders and waiters */
+			CollectLockHoldersAndWaiters(lock, &lock_holders_sbuf, &lock_waiters_sbuf, &lockHoldersNum);
 
 			LWLockRelease(partitionLock);
 
diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c
index 38cb9e970d..3aa4cdac26 100644
--- a/src/backend/utils/misc/guc_tables.c
+++ b/src/backend/utils/misc/guc_tables.c
@@ -1572,6 +1572,15 @@ struct config_bool ConfigureNamesBool[] =
 		false,
 		NULL, NULL, NULL
 	},
+	{
+		{"log_lock_failure", PGC_SUSET, LOGGING_WHAT,
+			gettext_noop("Logs lock failed."),
+			NULL
+		},
+		&log_lock_failure,
+		false,
+		NULL, NULL, NULL
+	},
 	{
 		{"log_recovery_conflict_waits", PGC_SIGHUP, LOGGING_WHAT,
 			gettext_noop("Logs standby recovery conflict waits."),
diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample
index 079efa1baa..7f17f0ca1e 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -601,6 +601,7 @@
 					#   %% = '%'
 					# e.g. '<%u%%%d> '
 #log_lock_waits = off			# log lock waits >= deadlock_timeout
+#log_lock_failure = off			# log lock failed
 #log_recovery_conflict_waits = off	# log standby recovery conflict waits
 					# >= deadlock_timeout
 #log_parameter_max_length = -1		# when logging statements, limit logged
diff --git a/src/include/storage/lmgr.h b/src/include/storage/lmgr.h
index 728260c1cc..57a8f3992e 100644
--- a/src/include/storage/lmgr.h
+++ b/src/include/storage/lmgr.h
@@ -123,4 +123,7 @@ extern void DescribeLockTag(StringInfo buf, const LOCKTAG *tag);
 
 extern const char *GetLockNameFromTagType(uint16 locktag_type);
 
+/* Collect LockHolders and Waiters for error messages */
+extern void CollectLockHoldersAndWaiters(LOCK *lock, StringInfo lock_holders_sbuf, StringInfo lock_waiters_sbuf, int *lockHoldersNum);
+
 #endif							/* LMGR_H */
diff --git a/src/include/storage/lock.h b/src/include/storage/lock.h
index 1076995518..f023656ea3 100644
--- a/src/include/storage/lock.h
+++ b/src/include/storage/lock.h
@@ -30,6 +30,7 @@ typedef struct PGPROC PGPROC;
 
 /* GUC variables */
 extern PGDLLIMPORT int max_locks_per_xact;
+extern PGDLLIMPORT bool log_lock_failure;
 
 #ifdef LOCK_DEBUG
 extern PGDLLIMPORT int Trace_lock_oidmin;
diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c
index 61a234ae21..cefd24f16c 100644
--- a/src/test/regress/pg_regress.c
+++ b/src/test/regress/pg_regress.c
@@ -2404,6 +2404,7 @@ regression_main(int argc, char *argv[],
 		fputs("log_checkpoints = on\n", pg_conf);
 		fputs("log_line_prefix = '%m %b[%p] %q%a '\n", pg_conf);
 		fputs("log_lock_waits = on\n", pg_conf);
+		fputs("log_lock_failure = on\n", pg_conf);
 		fputs("log_temp_files = 128kB\n", pg_conf);
 		fputs("max_prepared_transactions = 2\n", pg_conf);