Hi,

attached you will find a new version of the patch, removing the ctid
text but leaving the ctid itself in the message.

On 23/02/14 11:14, Amit Kapila wrote:
> >> In general, why I am suggesting to restrict display of newly added
> >> context for the case it is added to ensure that it doesn't get started
> >> displaying in other cases where it might make sense or might not
> >> make sense.
> >
> > Anything failing while inside an XactLockTableWait() et al. will benefit
> > from the context. In which scenarios could that be unneccessary?
> 
> This path is quite deep, so I have not verified that whether
> this new context can make sense for all error cases.
> For example, in below path (error message), it doesn't seem to
> make any sense (I have tried to generate it through debugger,
> actual message will vary).
> 
> XactLockTableWait->SubTransGetParent->SimpleLruReadPage_ReadOnly->SimpleLruReadPage->SlruReportIOError
> 
> ERROR:  could not access status of transaction 927
> DETAIL:  Could not open file "pg_subtrans/0000": No error.
> CONTEXT:  relation "public"."t1"
> tuple ctid (0,2)

To be honest, I don't like the idea of setting up this error context
only for log_lock_wait messages. This sounds unnecessary complex to me
and I think that in the few cases where this message doesn't add a
value (and thus is useless) don't justify such complexity.

> I have not checked that, but the reason I mentioned about database name
> is due to display of database oid in similar message, please see the
> message below. I think in below context we get it from lock tag and
> I think for the patch case also, it might be better to display, but not
> a mandatory thing. Consider it as a suggestion which if you also feel
> good, then do it, else ignore it.
> 
> LOG:  process 4656 still waiting for ExclusiveLock on tuple (0,1) of relation 
> 57
> 513 of database 12045 after 1046.000 ms

After thinking a bit about this I added the database name to the
context message, see attached patch.

> >> > Currently I simply display the whole tuple with truncating long
> >> > fields. This is plain easy, no distinction necessary. I did some code
> >> > reading and it seems somewhat complex to get the PK columns and it
> >> > seems that we need another lock for this, too - maybe not the best
> >> > idea when we are already in locking trouble, do you disagree?
> >>
> >> I don't think you need to take another lock for this, it must already
> >> have appropriate lock by that time. There should not be any problem
> >> in calling relationHasPrimaryKey except that currently it is static, you
> >> need to expose it.
> >
> > Other locations that deal with similar things (notably
> > ExecBuildSlotValueDescription()) doesn't either. I don't think this
> > patch should introduce it then.
> 
> Displaying whole tuple doesn't seem to be the most right way
> to get debug information and especially in this case we are
> already displaying tuple offset(ctid) which is unique identity
> to identify a tuple. It seems to me that it is sufficient to display
> unique value of tuple if present.
> I understand that there is no clear issue here, so may be if others also
> share their opinion then it will be quite easy to take a call.

That would be nice. I didn't change it, yet.

Best regards,

-- 
 Christian Kruse               http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services

diff --git a/src/backend/access/heap/heapam.c b/src/backend/access/heap/heapam.c
index a771ccb..a04414e 100644
--- a/src/backend/access/heap/heapam.c
+++ b/src/backend/access/heap/heapam.c
@@ -107,6 +107,8 @@ static TransactionId MultiXactIdGetUpdateXid(TransactionId xmax,
 						uint16 t_infomask);
 static void MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
 				int *remaining, uint16 infomask);
+static void MultiXactIdWaitWithErrorContext(Relation rel, HeapTuple tup, MultiXactId multi,
+					MultiXactStatus status, int *remaining, uint16 infomask);
 static bool ConditionalMultiXactIdWait(MultiXactId multi,
 						   MultiXactStatus status, int *remaining,
 						   uint16 infomask);
@@ -2703,8 +2705,8 @@ l1:
 		if (infomask & HEAP_XMAX_IS_MULTI)
 		{
 			/* wait for multixact */
-			MultiXactIdWait((MultiXactId) xwait, MultiXactStatusUpdate,
-							NULL, infomask);
+			MultiXactIdWaitWithErrorContext(relation, &tp, (MultiXactId) xwait,
+									  MultiXactStatusUpdate, NULL, infomask);
 			LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
 
 			/*
@@ -2730,7 +2732,7 @@ l1:
 		else
 		{
 			/* wait for regular transaction to end */
-			XactLockTableWait(xwait);
+			XactLockTableWaitWithInfo(relation, &tp, xwait);
 			LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
 
 			/*
@@ -3255,8 +3257,8 @@ l2:
 			int			remain;
 
 			/* wait for multixact */
-			MultiXactIdWait((MultiXactId) xwait, mxact_status, &remain,
-							infomask);
+			MultiXactIdWaitWithErrorContext(relation, &oldtup,
+					   (MultiXactId) xwait, mxact_status, &remain, infomask);
 			LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
 
 			/*
@@ -3330,7 +3332,7 @@ l2:
 			else
 			{
 				/* wait for regular transaction to end */
-				XactLockTableWait(xwait);
+				XactLockTableWaitWithInfo(relation, &oldtup, xwait);
 				LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
 
 				/*
@@ -4398,7 +4400,8 @@ l3:
 										RelationGetRelationName(relation))));
 				}
 				else
-					MultiXactIdWait((MultiXactId) xwait, status, NULL, infomask);
+					MultiXactIdWaitWithErrorContext(relation, tuple,
+								(MultiXactId) xwait, status, NULL, infomask);
 
 				/* if there are updates, follow the update chain */
 				if (follow_updates &&
@@ -4453,7 +4456,7 @@ l3:
 										RelationGetRelationName(relation))));
 				}
 				else
-					XactLockTableWait(xwait);
+					XactLockTableWaitWithInfo(relation, tuple, xwait);
 
 				/* if there are updates, follow the update chain */
 				if (follow_updates &&
@@ -5140,7 +5143,7 @@ l4:
 					if (needwait)
 					{
 						LockBuffer(buf, BUFFER_LOCK_UNLOCK);
-						XactLockTableWait(members[i].xid);
+						XactLockTableWaitWithInfo(rel, &mytup, members[i].xid);
 						pfree(members);
 						goto l4;
 					}
@@ -5200,7 +5203,7 @@ l4:
 				if (needwait)
 				{
 					LockBuffer(buf, BUFFER_LOCK_UNLOCK);
-					XactLockTableWait(rawxmax);
+					XactLockTableWaitWithInfo(rel, &mytup, rawxmax);
 					goto l4;
 				}
 				if (res != HeapTupleMayBeUpdated)
@@ -6158,6 +6161,33 @@ MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
 }
 
 /*
+ * MultiXactIdWaitWithErrorContext
+ *		Sets up the error context callback for reporting tuple
+ *		information and relation for a lock to aquire
+ *
+ * Use this instead of calling MultiXactIdWait()
+ */
+static void
+MultiXactIdWaitWithErrorContext(Relation rel, HeapTuple tup, MultiXactId multi,
+					 MultiXactStatus status, int *remaining, uint16 infomask)
+{
+	struct XactLockTableWaitLockInfo info;
+	ErrorContextCallback callback;
+
+	info.rel = rel;
+	info.tuple = tup;
+
+	callback.callback = XactLockTableWaitErrorContextCallback;
+	callback.arg = &info;
+	callback.previous = error_context_stack;
+	error_context_stack = &callback;
+
+	MultiXactIdWait(multi, status, remaining, infomask);
+
+	error_context_stack = callback.previous;
+}
+
+/*
  * ConditionalMultiXactIdWait
  *		As above, but only lock if we can get the lock without blocking.
  *
diff --git a/src/backend/access/nbtree/nbtinsert.c b/src/backend/access/nbtree/nbtinsert.c
index 9140749..7b80006 100644
--- a/src/backend/access/nbtree/nbtinsert.c
+++ b/src/backend/access/nbtree/nbtinsert.c
@@ -164,7 +164,7 @@ top:
 		{
 			/* Have to wait for the other guy ... */
 			_bt_relbuf(rel, buf);
-			XactLockTableWait(xwait);
+			XactLockTableWaitWithInfo(rel, NULL, xwait);
 			/* start over... */
 			_bt_freestack(stack);
 			goto top;
diff --git a/src/backend/catalog/index.c b/src/backend/catalog/index.c
index cebca95..46df88b 100644
--- a/src/backend/catalog/index.c
+++ b/src/backend/catalog/index.c
@@ -2295,7 +2295,8 @@ IndexBuildHeapScan(Relation heapRelation,
 							 * Must drop the lock on the buffer before we wait
 							 */
 							LockBuffer(scan->rs_cbuf, BUFFER_LOCK_UNLOCK);
-							XactLockTableWait(xwait);
+							XactLockTableWaitWithInfo(heapRelation,
+													  heapTuple, xwait);
 							goto recheck;
 						}
 					}
@@ -2341,7 +2342,8 @@ IndexBuildHeapScan(Relation heapRelation,
 							 * Must drop the lock on the buffer before we wait
 							 */
 							LockBuffer(scan->rs_cbuf, BUFFER_LOCK_UNLOCK);
-							XactLockTableWait(xwait);
+							XactLockTableWaitWithInfo(heapRelation,
+													  heapTuple, xwait);
 							goto recheck;
 						}
 
diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index 6b5f198..2e0c0e4 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -1981,7 +1981,8 @@ EvalPlanQualFetch(EState *estate, Relation relation, int lockmode,
 			if (TransactionIdIsValid(SnapshotDirty.xmax))
 			{
 				ReleaseBuffer(buffer);
-				XactLockTableWait(SnapshotDirty.xmax);
+				XactLockTableWaitWithInfo(relation, &tuple,
+										  SnapshotDirty.xmax);
 				continue;		/* loop back to repeat heap_fetch */
 			}
 
diff --git a/src/backend/executor/execUtils.c b/src/backend/executor/execUtils.c
index 46895b2..37f9f1a 100644
--- a/src/backend/executor/execUtils.c
+++ b/src/backend/executor/execUtils.c
@@ -1307,7 +1307,7 @@ retry:
 		if (TransactionIdIsValid(xwait))
 		{
 			index_endscan(index_scan);
-			XactLockTableWait(xwait);
+			XactLockTableWaitWithInfo(heap, tup, xwait);
 			goto retry;
 		}
 
diff --git a/src/backend/storage/lmgr/lmgr.c b/src/backend/storage/lmgr/lmgr.c
index 4c61a6f..9e120e4 100644
--- a/src/backend/storage/lmgr/lmgr.c
+++ b/src/backend/storage/lmgr/lmgr.c
@@ -18,12 +18,15 @@
 #include "access/subtrans.h"
 #include "access/transam.h"
 #include "access/xact.h"
+#include "access/htup_details.h"
 #include "catalog/catalog.h"
 #include "miscadmin.h"
 #include "storage/lmgr.h"
 #include "storage/procarray.h"
 #include "utils/inval.h"
-
+#include "utils/lsyscache.h"
+#include "mb/pg_wchar.h"
+#include "commands/dbcommands.h"
 
 /*
  * RelationInitLockInfo
@@ -534,6 +537,129 @@ ConditionalXactLockTableWait(TransactionId xid)
 }
 
 /*
+ * XactLockTableWaitErrorContextCallback
+ *		error context callback set up by
+ *		XactLockTableWaitWithInfo. It reports some
+ *		tuple information and the relation of a lock to aquire
+ *
+ */
+void
+XactLockTableWaitErrorContextCallback(void *arg)
+{
+	StringInfoData buf;
+	int			i;
+	bool		write_comma = false;
+	int			maxfieldlen = 30;
+	struct XactLockTableWaitLockInfo *info = (struct XactLockTableWaitLockInfo *) arg;
+
+	if (info->rel != NULL)
+	{
+		errcontext("database %s",
+				   get_database_name(info->rel->rd_node.dbNode));
+
+		errcontext("relation \"%s\".\"%s\"",
+				   get_namespace_name(RelationGetNamespace(info->rel)),
+				   RelationGetRelationName(info->rel));
+	}
+
+	if (info->tuple != NULL)
+	{
+		/*
+		 * Can't produce an error message including the tuple if we're in a
+		 * possibly aborted transaction state, database access might not be
+		 * safe.
+		 */
+		if (geterrlevel() >= ERROR)
+		{
+			errcontext("tuple (%u,%u)",
+					   BlockIdGetBlockNumber(&(info->tuple->t_self.ip_blkid)),
+					   info->tuple->t_self.ip_posid);
+		}
+		else
+		{
+			TupleDesc	desc = RelationGetDescr(info->rel);
+			Datum	   *values = palloc(desc->natts * sizeof(*values));
+			bool	   *nulls = palloc(desc->natts * sizeof(*values));
+
+			heap_deform_tuple(info->tuple, desc, values, nulls);
+
+			initStringInfo(&buf);
+			appendStringInfoChar(&buf, '(');
+
+			for (i = 0; i < desc->natts; i++)
+			{
+				char	   *val;
+				int			vallen;
+
+				if (nulls[i])
+					val = "null";
+				else
+				{
+					Oid			foutoid;
+					bool		typisvarlena;
+
+					getTypeOutputInfo(desc->attrs[i]->atttypid,
+									  &foutoid, &typisvarlena);
+
+					val = OidOutputFunctionCall(foutoid, values[i]);
+				}
+
+				if (write_comma)
+					appendStringInfoString(&buf, ", ");
+				else
+					write_comma = true;
+
+				vallen = strlen(val);
+				if (vallen <= maxfieldlen)
+					appendStringInfoString(&buf, val);
+				else
+				{
+					vallen = pg_mbcliplen(val, vallen, maxfieldlen);
+					appendBinaryStringInfo(&buf, val, vallen);
+					appendStringInfoString(&buf, "...");
+				}
+			}
+
+			appendStringInfoChar(&buf, ')');
+
+			errcontext("tuple (%u,%u): %s",
+					   BlockIdGetBlockNumber(&(info->tuple->t_self.ip_blkid)),
+					   info->tuple->t_self.ip_posid, buf.data);
+
+			pfree(buf.data);
+			pfree(values);
+			pfree(nulls);
+		}
+	}
+}
+
+/*
+ * XactLockTableWaitWithInfo
+ *		Sets up the error context callback for reporting tuple
+ *		information and relation for a lock to aquire
+ *
+ * Use this instead of calling XactTableLockWait()
+ */
+void
+XactLockTableWaitWithInfo(Relation rel, HeapTuple tuple, TransactionId xid)
+{
+	struct XactLockTableWaitLockInfo info;
+	ErrorContextCallback callback;
+
+	info.rel = rel;
+	info.tuple = tuple;
+
+	callback.callback = XactLockTableWaitErrorContextCallback;
+	callback.arg = &info;
+	callback.previous = error_context_stack;
+	error_context_stack = &callback;
+
+	XactLockTableWait(xid);
+
+	error_context_stack = callback.previous;
+}
+
+/*
  * WaitForLockersMultiple
  *		Wait until no transaction holds locks that conflict with the given
  *		locktags at the given lockmode.
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index 8705586..6231db6 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -1216,6 +1216,23 @@ geterrposition(void)
 }
 
 /*
+ * geterrlevel --- return the currently set error level
+ *
+ * This is only intended for use in error callback subroutines, since there
+ * is no other place outside elog.c where the concept is meaningful.
+ */
+int
+geterrlevel(void)
+{
+	ErrorData  *edata = &errordata[errordata_stack_depth];
+
+	/* we don't bother incrementing recursion_depth */
+	CHECK_STACK_DEPTH();
+
+	return edata->elevel;
+}
+
+/*
  * getinternalerrposition --- same for internal error position
  *
  * This is only intended for use in error callback subroutines, since there
diff --git a/src/include/storage/lmgr.h b/src/include/storage/lmgr.h
index e74ae21..5055072 100644
--- a/src/include/storage/lmgr.h
+++ b/src/include/storage/lmgr.h
@@ -18,6 +18,13 @@
 #include "storage/itemptr.h"
 #include "storage/lock.h"
 #include "utils/rel.h"
+#include "access/htup.h"
+
+struct XactLockTableWaitLockInfo
+{
+	Relation	rel;
+	HeapTuple	tuple;
+};
 
 
 extern void RelationInitLockInfo(Relation relation);
@@ -57,6 +64,10 @@ extern void XactLockTableDelete(TransactionId xid);
 extern void XactLockTableWait(TransactionId xid);
 extern bool ConditionalXactLockTableWait(TransactionId xid);
 
+extern void XactLockTableWaitWithInfo(Relation rel, HeapTuple tuple,
+						  TransactionId xid);
+extern void XactLockTableWaitErrorContextCallback(void *arg);
+
 /* Lock VXIDs, specified by conflicting locktags */
 extern void WaitForLockers(LOCKTAG heaplocktag, LOCKMODE lockmode);
 extern void WaitForLockersMultiple(List *locktags, LOCKMODE lockmode);
diff --git a/src/include/utils/elog.h b/src/include/utils/elog.h
index d7916c2..04fd3a2 100644
--- a/src/include/utils/elog.h
+++ b/src/include/utils/elog.h
@@ -224,6 +224,7 @@ extern int	err_generic_string(int field, const char *str);
 
 extern int	geterrcode(void);
 extern int	geterrposition(void);
+extern int	geterrlevel(void);
 extern int	getinternalerrposition(void);
 
 

Attachment: pgpetEOd7uSkg.pgp
Description: PGP signature

Reply via email to