Setup error context callback for transaction lock waits

With this in place, a session blocking behind another one because of
tuple locks will get a context line mentioning the relation name, tuple
TID, and operation being done on tuple.  For example:

LOG:  process 11367 still waiting for ShareLock on transaction 717 after 1000.108 ms
DETAIL:  Process holding the lock: 11366. Wait queue: 11367.
CONTEXT:  while updating tuple (0,2) in relation "foo"
STATEMENT:  UPDATE foo SET value = 3;

Most usefully, the new line is displayed by log entries due to
log_lock_waits, although of course it will be printed by any other log
message as well.

Author: Christian Kruse, some tweaks by Álvaro Herrera
Reviewed-by: Amit Kapila, Andres Freund, Tom Lane, Robert Haas

src/backend/access/heap/heapam.c

@@ -105,11 +105,12 @@ static void GetMultiXactIdHintBits(MultiXactId multi, uint16 *new_infomask,
 					   uint16 *new_infomask2);
 static TransactionId MultiXactIdGetUpdateXid(TransactionId xmax,
 						uint16 t_infomask);
-static void MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
+static void MultiXactIdWait(MultiXactId multi, MultiXactStatus status, uint16 infomask,
-				int *remaining, uint16 infomask);
+				Relation rel, ItemPointer ctid, XLTW_Oper oper,
-static bool ConditionalMultiXactIdWait(MultiXactId multi,
+				int *remaining);
-						   MultiXactStatus status, int *remaining,
+static bool ConditionalMultiXactIdWait(MultiXactId multi, MultiXactStatus status,
-						   uint16 infomask);
+						   uint16 infomask, Relation rel, ItemPointer ctid,
+						   XLTW_Oper oper, int *remaining);
 static XLogRecPtr log_heap_new_cid(Relation relation, HeapTuple tup);
 static HeapTuple ExtractReplicaIdentity(Relation rel, HeapTuple tup, bool key_modified,
 										bool *copy);
@@ -2714,8 +2715,9 @@ l1:
 		if (infomask & HEAP_XMAX_IS_MULTI)
 		{
 			/* wait for multixact */
-			MultiXactIdWait((MultiXactId) xwait, MultiXactStatusUpdate,
+			MultiXactIdWait((MultiXactId) xwait, MultiXactStatusUpdate, infomask,
-							NULL, infomask);
+							relation, &tp.t_data->t_ctid, XLTW_Delete,
+							NULL);
 			LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
 
 			/*
@@ -2741,7 +2743,7 @@ l1:
 		else
 		{
 			/* wait for regular transaction to end */
-			XactLockTableWait(xwait);
+			XactLockTableWait(xwait, relation, &tp.t_data->t_ctid, XLTW_Delete);
 			LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
 
 			/*
@@ -3266,8 +3268,9 @@ l2:
 			int			remain;
 
 			/* wait for multixact */
-			MultiXactIdWait((MultiXactId) xwait, mxact_status, &remain,
+			MultiXactIdWait((MultiXactId) xwait, mxact_status, infomask,
-							infomask);
+							relation, &oldtup.t_data->t_ctid, XLTW_Update,
+							&remain);
 			LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
 
 			/*
@@ -3341,7 +3344,8 @@ l2:
 			else
 			{
 				/* wait for regular transaction to end */
-				XactLockTableWait(xwait);
+				XactLockTableWait(xwait, relation, &oldtup.t_data->t_ctid,
+								  XLTW_Update);
 				LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
 
 				/*
@@ -4402,14 +4406,18 @@ l3:
 				if (nowait)
 				{
 					if (!ConditionalMultiXactIdWait((MultiXactId) xwait,
-													status, NULL, infomask))
+												  status, infomask, relation,
+													&tuple->t_data->t_ctid,
+													XLTW_Lock, NULL))
 						ereport(ERROR,
 								(errcode(ERRCODE_LOCK_NOT_AVAILABLE),
 								 errmsg("could not obtain lock on row in relation \"%s\"",
 										RelationGetRelationName(relation))));
 				}
 				else
-					MultiXactIdWait((MultiXactId) xwait, status, NULL, infomask);
+					MultiXactIdWait((MultiXactId) xwait, status, infomask,
+									relation, &tuple->t_data->t_ctid,
+									XLTW_Lock, NULL);
 
 				/* if there are updates, follow the update chain */
 				if (follow_updates &&
@@ -4464,7 +4472,8 @@ l3:
 										RelationGetRelationName(relation))));
 				}
 				else
-					XactLockTableWait(xwait);
+					XactLockTableWait(xwait, relation, &tuple->t_data->t_ctid,
+									  XLTW_Lock);
 
 				/* if there are updates, follow the update chain */
 				if (follow_updates &&
@@ -5151,7 +5160,9 @@ l4:
 					if (needwait)
 					{
 						LockBuffer(buf, BUFFER_LOCK_UNLOCK);
-						XactLockTableWait(members[i].xid);
+						XactLockTableWait(members[i].xid, rel,
+										  &mytup.t_data->t_ctid,
+										  XLTW_LockUpdated);
 						pfree(members);
 						goto l4;
 					}
@@ -5211,7 +5222,8 @@ l4:
 				if (needwait)
 				{
 					LockBuffer(buf, BUFFER_LOCK_UNLOCK);
-					XactLockTableWait(rawxmax);
+					XactLockTableWait(rawxmax, rel, &mytup.t_data->t_ctid,
+									  XLTW_LockUpdated);
 					goto l4;
 				}
 				if (res != HeapTupleMayBeUpdated)
@@ -6076,6 +6088,15 @@ HeapTupleGetUpdateXid(HeapTupleHeader tuple)
  * Do_MultiXactIdWait
  *		Actual implementation for the two functions below.
  *
+ * 'multi', 'status' and 'infomask' indicate what to sleep on (the status is
+ * needed to ensure we only sleep on conflicting members, and the infomask is
+ * used to optimize multixact access in case it's a lock-only multi); 'nowait'
+ * indicates whether to use conditional lock acquisition, to allow callers to
+ * fail if lock is unavailable.  'rel', 'ctid' and 'oper' are used to set up
+ * context information for error messages.	'remaining', if not NULL, receives
+ * the number of members that are still running, including any (non-aborted)
+ * subtransactions of our own transaction.
+ *
  * We do this by sleeping on each member using XactLockTableWait.  Any
  * members that belong to the current backend are *not* waited for, however;
  * this would not merely be useless but would lead to Assert failure inside
@@ -6093,7 +6114,9 @@ HeapTupleGetUpdateXid(HeapTupleHeader tuple)
  */
 static bool
 Do_MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
-				   int *remaining, uint16 infomask, bool nowait)
+				   uint16 infomask, bool nowait,
+				   Relation rel, ItemPointer ctid, XLTW_Oper oper,
+				   int *remaining)
 {
 	bool		allow_old;
 	bool		result = true;
@@ -6130,6 +6153,12 @@ Do_MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
 			/*
 			 * This member conflicts with our multi, so we have to sleep (or
 			 * return failure, if asked to avoid waiting.)
+			 *
+			 * Note that we don't set up an error context callback ourselves,
+			 * but instead we pass the info down to XactLockTableWait.	This
+			 * might seem a bit wasteful because the context is set up and
+			 * tore down for each member of the multixact, but in reality it
+			 * should be barely noticeable, and it avoids duplicate code.
 			 */
 			if (nowait)
 			{
@@ -6138,7 +6167,7 @@ Do_MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
 					break;
 			}
 			else
-				XactLockTableWait(memxid);
+				XactLockTableWait(memxid, rel, ctid, oper);
 		}
 
 		pfree(members);
@@ -6159,13 +6188,14 @@ Do_MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
  *
  * We return (in *remaining, if not NULL) the number of members that are still
  * running, including any (non-aborted) subtransactions of our own transaction.
- *
  */
 static void
-MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
+MultiXactIdWait(MultiXactId multi, MultiXactStatus status, uint16 infomask,
-				int *remaining, uint16 infomask)
+				Relation rel, ItemPointer ctid, XLTW_Oper oper,
+				int *remaining)
 {
-	Do_MultiXactIdWait(multi, status, remaining, infomask, false);
+	(void) Do_MultiXactIdWait(multi, status, infomask, false,
+							  rel, ctid, oper, remaining);
 }
 
 /*
@@ -6183,9 +6213,11 @@ MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
  */
 static bool
 ConditionalMultiXactIdWait(MultiXactId multi, MultiXactStatus status,
-						   int *remaining, uint16 infomask)
+						   uint16 infomask, Relation rel, ItemPointer ctid,
+						   XLTW_Oper oper, int *remaining)
 {
-	return Do_MultiXactIdWait(multi, status, remaining, infomask, true);
+	return Do_MultiXactIdWait(multi, status, infomask, true,
+							  rel, ctid, oper, remaining);
 }
 
 /*

src/backend/access/nbtree/nbtinsert.c

@@ -168,7 +168,7 @@ top:
 		{
 			/* Have to wait for the other guy ... */
 			_bt_relbuf(rel, buf);
-			XactLockTableWait(xwait);
+			XactLockTableWait(xwait, rel, &itup->t_tid, XLTW_InsertIndex);
 			/* start over... */
 			_bt_freestack(stack);
 			goto top;

src/backend/catalog/index.c

@@ -2295,7 +2295,9 @@ IndexBuildHeapScan(Relation heapRelation,
 							 * Must drop the lock on the buffer before we wait
 							 */
 							LockBuffer(scan->rs_cbuf, BUFFER_LOCK_UNLOCK);
-							XactLockTableWait(xwait);
+							XactLockTableWait(xwait, heapRelation,
+											  &heapTuple->t_data->t_ctid,
+											  XLTW_InsertIndexUnique);
 							goto recheck;
 						}
 					}
@@ -2341,7 +2343,9 @@ IndexBuildHeapScan(Relation heapRelation,
 							 * Must drop the lock on the buffer before we wait
 							 */
 							LockBuffer(scan->rs_cbuf, BUFFER_LOCK_UNLOCK);
-							XactLockTableWait(xwait);
+							XactLockTableWait(xwait, heapRelation,
+											  &heapTuple->t_data->t_ctid,
+											  XLTW_InsertIndexUnique);
 							goto recheck;
 						}
 

src/backend/executor/execMain.c

@@ -1982,7 +1982,9 @@ EvalPlanQualFetch(EState *estate, Relation relation, int lockmode,
 			if (TransactionIdIsValid(SnapshotDirty.xmax))
 			{
 				ReleaseBuffer(buffer);
-				XactLockTableWait(SnapshotDirty.xmax);
+				XactLockTableWait(SnapshotDirty.xmax,
+								  relation, &tuple.t_data->t_ctid,
+								  XLTW_FetchUpdated);
 				continue;		/* loop back to repeat heap_fetch */
 			}
 

src/backend/executor/execUtils.c

@@ -1307,7 +1307,8 @@ retry:
 		if (TransactionIdIsValid(xwait))
 		{
 			index_endscan(index_scan);
-			XactLockTableWait(xwait);
+			XactLockTableWait(xwait, heap, &tup->t_data->t_ctid,
+							  XLTW_RecheckExclusionConstr);
 			goto retry;
 		}
 

src/backend/replication/logical/snapbuild.c

@@ -1343,7 +1343,7 @@ SnapBuildFindSnapshot(SnapBuild *builder, XLogRecPtr lsn, xl_running_xacts *runn
 			if (TransactionIdIsCurrentTransactionId(xid))
 				elog(ERROR, "waiting for ourselves");
 
-			XactLockTableWait(xid);
+			XactLockTableWait(xid, NULL, NULL, XLTW_None);
 		}
 
 		/* nothing could have built up so far, so don't perform cleanup */

src/backend/storage/lmgr/lmgr.c

@@ -25,6 +25,21 @@
 #include "utils/inval.h"
 
 
+/*
+ * Struct to hold context info for transaction lock waits.
+ *
+ * 'oper' is the operation that needs to wait for the other transaction; 'rel'
+ * and 'ctid' specify the address of the tuple being waited for.
+ */
+typedef struct XactLockTableWaitInfo
+{
+	XLTW_Oper	oper;
+	Relation	rel;
+	ItemPointer	ctid;
+} XactLockTableWaitInfo;
+
+static void XactLockTableWaitErrorCb(void *arg);
+
 /*
  * RelationInitLockInfo
  *		Initializes the lock information in a relation descriptor.
@@ -471,7 +486,9 @@ XactLockTableDelete(TransactionId xid)
 /*
  *		XactLockTableWait
  *
- * Wait for the specified transaction to commit or abort.
+ * Wait for the specified transaction to commit or abort.  If an operation
+ * is specified, an error context callback is set up.  If 'oper' is passed as
+ * None, no error context callback is set up.
  *
  * Note that this does the right thing for subtransactions: if we wait on a
  * subtransaction, we will exit as soon as it aborts or its top parent commits.
@@ -481,9 +498,31 @@ XactLockTableDelete(TransactionId xid)
  * and if so wait for its parent.
  */
 void
-XactLockTableWait(TransactionId xid)
+XactLockTableWait(TransactionId xid, Relation rel, ItemPointer ctid,
+				  XLTW_Oper oper)
 {
 	LOCKTAG		tag;
+	XactLockTableWaitInfo info;
+	ErrorContextCallback callback;
+
+	/*
+	 * If an operation is specified, set up our verbose error context
+	 * callback.
+	 */
+	if (oper != XLTW_None)
+	{
+		Assert(RelationIsValid(rel));
+		Assert(ItemPointerIsValid(ctid));
+
+		info.rel = rel;
+		info.ctid = ctid;
+		info.oper = oper;
+
+		callback.callback = XactLockTableWaitErrorCb;
+		callback.arg = &info;
+		callback.previous = error_context_stack;
+		error_context_stack = &callback;
+	}
 
 	for (;;)
 	{
@@ -500,6 +539,9 @@ XactLockTableWait(TransactionId xid)
 			break;
 		xid = SubTransGetParent(xid);
 	}
+
+	if (oper != XLTW_None)
+		error_context_stack = callback.previous;
 }
 
 /*
@@ -533,6 +575,62 @@ ConditionalXactLockTableWait(TransactionId xid)
 	return true;
 }
 
+/*
+ * XactLockTableWaitErrorContextCb
+ *		Error context callback for transaction lock waits.
+ */
+static void
+XactLockTableWaitErrorCb(void *arg)
+{
+	XactLockTableWaitInfo *info = (XactLockTableWaitInfo *) arg;
+
+	/*
+	 * We would like to print schema name too, but that would require a
+	 * syscache lookup.
+	 */
+	if (info->oper != XLTW_None &&
+		ItemPointerIsValid(info->ctid) && RelationIsValid(info->rel))
+	{
+		const char *cxt;
+
+		switch (info->oper)
+		{
+			case XLTW_Update:
+				cxt = gettext_noop("while updating tuple (%u,%u) in relation \"%s\"");
+				break;
+			case XLTW_Delete:
+				cxt = gettext_noop("while deleting tuple (%u,%u) in relation \"%s\"");
+				break;
+			case XLTW_Lock:
+				cxt = gettext_noop("while locking tuple (%u,%u) in relation \"%s\"");
+				break;
+			case XLTW_LockUpdated:
+				cxt = gettext_noop("while locking updated version (%u,%u) of tuple in relation \"%s\"");
+				break;
+			case XLTW_InsertIndex:
+				cxt = gettext_noop("while inserting index tuple (%u,%u) in relation \"%s\"");
+				break;
+			case XLTW_InsertIndexUnique:
+				cxt = gettext_noop("while checking uniqueness of tuple (%u,%u) in relation \"%s\"");
+				break;
+			case XLTW_FetchUpdated:
+				cxt = gettext_noop("while rechecking updated tuple (%u,%u) in relation \"%s\"");
+				break;
+			case XLTW_RecheckExclusionConstr:
+				cxt = gettext_noop("while checking exclusion constraint on tuple (%u,%u) in relation \"%s\"");
+				break;
+
+			default:
+				return;
+		}
+
+		errcontext(cxt,
+				   ItemPointerGetBlockNumber(info->ctid),
+				   ItemPointerGetOffsetNumber(info->ctid),
+				   RelationGetRelationName(info->rel));
+	}
+}
+
 /*
  * WaitForLockersMultiple
  *		Wait until no transaction holds locks that conflict with the given

src/include/storage/lmgr.h

@@ -20,6 +20,20 @@
 #include "utils/rel.h"
 
 
+/* XactLockTableWait operations */
+typedef enum XLTW_Oper
+{
+	XLTW_None,
+	XLTW_Update,
+	XLTW_Delete,
+	XLTW_Lock,
+	XLTW_LockUpdated,
+	XLTW_InsertIndex,
+	XLTW_InsertIndexUnique,
+	XLTW_FetchUpdated,
+	XLTW_RecheckExclusionConstr
+} XLTW_Oper;
+
 extern void RelationInitLockInfo(Relation relation);
 
 /* Lock a relation */
@@ -54,7 +68,8 @@ extern void UnlockTuple(Relation relation, ItemPointer tid, LOCKMODE lockmode);
 /* Lock an XID (used to wait for a transaction to finish) */
 extern void XactLockTableInsert(TransactionId xid);
 extern void XactLockTableDelete(TransactionId xid);
-extern void XactLockTableWait(TransactionId xid);
+extern void XactLockTableWait(TransactionId xid, Relation rel,
+				  ItemPointer ctid, XLTW_Oper oper);
 extern bool ConditionalXactLockTableWait(TransactionId xid);
 
 /* Lock VXIDs, specified by conflicting locktags */

src/nls-global.mk

@@ -57,7 +57,10 @@ BACKEND_COMMON_GETTEXT_TRIGGERS = \
     errmsg errmsg_plural:1,2 \
     errdetail errdetail_log errdetail_plural:1,2 \
     errhint \
-    errcontext
+    errcontext \
+    XactLockTableWait:4 \
+    MultiXactIdWait:6 \
+    ConditionalMultiXactIdWait:6
 BACKEND_COMMON_GETTEXT_FLAGS = \
     errmsg:1:c-format errmsg_plural:1:c-format errmsg_plural:2:c-format \
     errdetail:1:c-format errdetail_log:1:c-format errdetail_plural:1:c-format errdetail_plural:2:c-format \