Skip to content

Commit f88d4cf

Browse files
alvherrealvherre
committed
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
1 parent ea8c7e9 commit f88d4cf

File tree

9 files changed

+189
-34
lines changed

9 files changed

+189
-34
lines changed

‎src/backend/access/heap/heapam.c

+56-24
Original file line numberDiff line numberDiff line change
@@ -105,11 +105,12 @@ static void GetMultiXactIdHintBits(MultiXactId multi, uint16 *new_infomask,
105105
uint16 *new_infomask2);
106106
static TransactionId MultiXactIdGetUpdateXid(TransactionId xmax,
107107
uint16 t_infomask);
108-
static void MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
109-
int *remaining, uint16 infomask);
110-
static bool ConditionalMultiXactIdWait(MultiXactId multi,
111-
MultiXactStatus status, int *remaining,
112-
uint16 infomask);
108+
static void MultiXactIdWait(MultiXactId multi, MultiXactStatus status, uint16 infomask,
109+
Relation rel, ItemPointer ctid, XLTW_Oper oper,
110+
int *remaining);
111+
static bool ConditionalMultiXactIdWait(MultiXactId multi, MultiXactStatus status,
112+
uint16 infomask, Relation rel, ItemPointer ctid,
113+
XLTW_Oper oper, int *remaining);
113114
static XLogRecPtr log_heap_new_cid(Relation relation, HeapTuple tup);
114115
static HeapTuple ExtractReplicaIdentity(Relation rel, HeapTuple tup, bool key_modified,
115116
bool *copy);
@@ -2714,8 +2715,9 @@ heap_delete(Relation relation, ItemPointer tid,
27142715
if (infomask & HEAP_XMAX_IS_MULTI)
27152716
{
27162717
/* wait for multixact */
2717-
MultiXactIdWait((MultiXactId) xwait, MultiXactStatusUpdate,
2718-
NULL, infomask);
2718+
MultiXactIdWait((MultiXactId) xwait, MultiXactStatusUpdate, infomask,
2719+
relation, &tp.t_data->t_ctid, XLTW_Delete,
2720+
NULL);
27192721
LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
27202722

27212723
/*
@@ -2741,7 +2743,7 @@ heap_delete(Relation relation, ItemPointer tid,
27412743
else
27422744
{
27432745
/* wait for regular transaction to end */
2744-
XactLockTableWait(xwait);
2746+
XactLockTableWait(xwait, relation, &tp.t_data->t_ctid, XLTW_Delete);
27452747
LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
27462748

27472749
/*
@@ -3266,8 +3268,9 @@ heap_update(Relation relation, ItemPointer otid, HeapTuple newtup,
32663268
int remain;
32673269

32683270
/* wait for multixact */
3269-
MultiXactIdWait((MultiXactId) xwait, mxact_status, &remain,
3270-
infomask);
3271+
MultiXactIdWait((MultiXactId) xwait, mxact_status, infomask,
3272+
relation, &oldtup.t_data->t_ctid, XLTW_Update,
3273+
&remain);
32713274
LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
32723275

32733276
/*
@@ -3341,7 +3344,8 @@ heap_update(Relation relation, ItemPointer otid, HeapTuple newtup,
33413344
else
33423345
{
33433346
/* wait for regular transaction to end */
3344-
XactLockTableWait(xwait);
3347+
XactLockTableWait(xwait, relation, &oldtup.t_data->t_ctid,
3348+
XLTW_Update);
33453349
LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
33463350

33473351
/*
@@ -4402,14 +4406,18 @@ heap_lock_tuple(Relation relation, HeapTuple tuple,
44024406
if (nowait)
44034407
{
44044408
if (!ConditionalMultiXactIdWait((MultiXactId) xwait,
4405-
status, NULL, infomask))
4409+
status, infomask, relation,
4410+
&tuple->t_data->t_ctid,
4411+
XLTW_Lock, NULL))
44064412
ereport(ERROR,
44074413
(errcode(ERRCODE_LOCK_NOT_AVAILABLE),
44084414
errmsg("could not obtain lock on row in relation \"%s\"",
44094415
RelationGetRelationName(relation))));
44104416
}
44114417
else
4412-
MultiXactIdWait((MultiXactId) xwait, status, NULL, infomask);
4418+
MultiXactIdWait((MultiXactId) xwait, status, infomask,
4419+
relation, &tuple->t_data->t_ctid,
4420+
XLTW_Lock, NULL);
44134421

44144422
/* if there are updates, follow the update chain */
44154423
if (follow_updates &&
@@ -4464,7 +4472,8 @@ heap_lock_tuple(Relation relation, HeapTuple tuple,
44644472
RelationGetRelationName(relation))));
44654473
}
44664474
else
4467-
XactLockTableWait(xwait);
4475+
XactLockTableWait(xwait, relation, &tuple->t_data->t_ctid,
4476+
XLTW_Lock);
44684477

44694478
/* if there are updates, follow the update chain */
44704479
if (follow_updates &&
@@ -5151,7 +5160,9 @@ heap_lock_updated_tuple_rec(Relation rel, ItemPointer tid, TransactionId xid,
51515160
if (needwait)
51525161
{
51535162
LockBuffer(buf, BUFFER_LOCK_UNLOCK);
5154-
XactLockTableWait(members[i].xid);
5163+
XactLockTableWait(members[i].xid, rel,
5164+
&mytup.t_data->t_ctid,
5165+
XLTW_LockUpdated);
51555166
pfree(members);
51565167
goto l4;
51575168
}
@@ -5211,7 +5222,8 @@ heap_lock_updated_tuple_rec(Relation rel, ItemPointer tid, TransactionId xid,
52115222
if (needwait)
52125223
{
52135224
LockBuffer(buf, BUFFER_LOCK_UNLOCK);
5214-
XactLockTableWait(rawxmax);
5225+
XactLockTableWait(rawxmax, rel, &mytup.t_data->t_ctid,
5226+
XLTW_LockUpdated);
52155227
goto l4;
52165228
}
52175229
if (res != HeapTupleMayBeUpdated)
@@ -6076,6 +6088,15 @@ HeapTupleGetUpdateXid(HeapTupleHeader tuple)
60766088
* Do_MultiXactIdWait
60776089
* Actual implementation for the two functions below.
60786090
*
6091+
* 'multi', 'status' and 'infomask' indicate what to sleep on (the status is
6092+
* needed to ensure we only sleep on conflicting members, and the infomask is
6093+
* used to optimize multixact access in case it's a lock-only multi); 'nowait'
6094+
* indicates whether to use conditional lock acquisition, to allow callers to
6095+
* fail if lock is unavailable. 'rel', 'ctid' and 'oper' are used to set up
6096+
* context information for error messages. 'remaining', if not NULL, receives
6097+
* the number of members that are still running, including any (non-aborted)
6098+
* subtransactions of our own transaction.
6099+
*
60796100
* We do this by sleeping on each member using XactLockTableWait. Any
60806101
* members that belong to the current backend are *not* waited for, however;
60816102
* this would not merely be useless but would lead to Assert failure inside
@@ -6093,7 +6114,9 @@ HeapTupleGetUpdateXid(HeapTupleHeader tuple)
60936114
*/
60946115
static bool
60956116
Do_MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
6096-
int *remaining, uint16 infomask, bool nowait)
6117+
uint16 infomask, bool nowait,
6118+
Relation rel, ItemPointer ctid, XLTW_Oper oper,
6119+
int *remaining)
60976120
{
60986121
bool allow_old;
60996122
bool result = true;
@@ -6130,6 +6153,12 @@ Do_MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
61306153
/*
61316154
* This member conflicts with our multi, so we have to sleep (or
61326155
* return failure, if asked to avoid waiting.)
6156+
*
6157+
* Note that we don't set up an error context callback ourselves,
6158+
* but instead we pass the info down to XactLockTableWait. This
6159+
* might seem a bit wasteful because the context is set up and
6160+
* tore down for each member of the multixact, but in reality it
6161+
* should be barely noticeable, and it avoids duplicate code.
61336162
*/
61346163
if (nowait)
61356164
{
@@ -6138,7 +6167,7 @@ Do_MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
61386167
break;
61396168
}
61406169
else
6141-
XactLockTableWait(memxid);
6170+
XactLockTableWait(memxid, rel, ctid, oper);
61426171
}
61436172

61446173
pfree(members);
@@ -6159,13 +6188,14 @@ Do_MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
61596188
*
61606189
* We return (in *remaining, if not NULL) the number of members that are still
61616190
* running, including any (non-aborted) subtransactions of our own transaction.
6162-
*
61636191
*/
61646192
static void
6165-
MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
6166-
int *remaining, uint16 infomask)
6193+
MultiXactIdWait(MultiXactId multi, MultiXactStatus status, uint16 infomask,
6194+
Relation rel, ItemPointer ctid, XLTW_Oper oper,
6195+
int *remaining)
61676196
{
6168-
Do_MultiXactIdWait(multi, status, remaining, infomask, false);
6197+
(void) Do_MultiXactIdWait(multi, status, infomask, false,
6198+
rel, ctid, oper, remaining);
61696199
}
61706200

61716201
/*
@@ -6183,9 +6213,11 @@ MultiXactIdWait(MultiXactId multi, MultiXactStatus status,
61836213
*/
61846214
static bool
61856215
ConditionalMultiXactIdWait(MultiXactId multi, MultiXactStatus status,
6186-
int *remaining, uint16 infomask)
6216+
uint16 infomask, Relation rel, ItemPointer ctid,
6217+
XLTW_Oper oper, int *remaining)
61876218
{
6188-
return Do_MultiXactIdWait(multi, status, remaining, infomask, true);
6219+
return Do_MultiXactIdWait(multi, status, infomask, true,
6220+
rel, ctid, oper, remaining);
61896221
}
61906222

61916223
/*

‎src/backend/access/nbtree/nbtinsert.c

+1-1
Original file line numberDiff line numberDiff line change
@@ -168,7 +168,7 @@ _bt_doinsert(Relation rel, IndexTuple itup,
168168
{
169169
/* Have to wait for the other guy ... */
170170
_bt_relbuf(rel, buf);
171-
XactLockTableWait(xwait);
171+
XactLockTableWait(xwait, rel, &itup->t_tid, XLTW_InsertIndex);
172172
/* start over... */
173173
_bt_freestack(stack);
174174
goto top;

‎src/backend/catalog/index.c

+6-2
Original file line numberDiff line numberDiff line change
@@ -2295,7 +2295,9 @@ IndexBuildHeapScan(Relation heapRelation,
22952295
* Must drop the lock on the buffer before we wait
22962296
*/
22972297
LockBuffer(scan->rs_cbuf, BUFFER_LOCK_UNLOCK);
2298-
XactLockTableWait(xwait);
2298+
XactLockTableWait(xwait, heapRelation,
2299+
&heapTuple->t_data->t_ctid,
2300+
XLTW_InsertIndexUnique);
22992301
goto recheck;
23002302
}
23012303
}
@@ -2341,7 +2343,9 @@ IndexBuildHeapScan(Relation heapRelation,
23412343
* Must drop the lock on the buffer before we wait
23422344
*/
23432345
LockBuffer(scan->rs_cbuf, BUFFER_LOCK_UNLOCK);
2344-
XactLockTableWait(xwait);
2346+
XactLockTableWait(xwait, heapRelation,
2347+
&heapTuple->t_data->t_ctid,
2348+
XLTW_InsertIndexUnique);
23452349
goto recheck;
23462350
}
23472351

‎src/backend/executor/execMain.c

+3-1
Original file line numberDiff line numberDiff line change
@@ -1982,7 +1982,9 @@ EvalPlanQualFetch(EState *estate, Relation relation, int lockmode,
19821982
if (TransactionIdIsValid(SnapshotDirty.xmax))
19831983
{
19841984
ReleaseBuffer(buffer);
1985-
XactLockTableWait(SnapshotDirty.xmax);
1985+
XactLockTableWait(SnapshotDirty.xmax,
1986+
relation, &tuple.t_data->t_ctid,
1987+
XLTW_FetchUpdated);
19861988
continue; /* loop back to repeat heap_fetch */
19871989
}
19881990

‎src/backend/executor/execUtils.c

+2-1
Original file line numberDiff line numberDiff line change
@@ -1307,7 +1307,8 @@ check_exclusion_constraint(Relation heap, Relation index, IndexInfo *indexInfo,
13071307
if (TransactionIdIsValid(xwait))
13081308
{
13091309
index_endscan(index_scan);
1310-
XactLockTableWait(xwait);
1310+
XactLockTableWait(xwait, heap, &tup->t_data->t_ctid,
1311+
XLTW_RecheckExclusionConstr);
13111312
goto retry;
13121313
}
13131314

‎src/backend/replication/logical/snapbuild.c

+1-1
Original file line numberDiff line numberDiff line change
@@ -1343,7 +1343,7 @@ SnapBuildFindSnapshot(SnapBuild *builder, XLogRecPtr lsn, xl_running_xacts *runn
13431343
if (TransactionIdIsCurrentTransactionId(xid))
13441344
elog(ERROR, "waiting for ourselves");
13451345

1346-
XactLockTableWait(xid);
1346+
XactLockTableWait(xid, NULL, NULL, XLTW_None);
13471347
}
13481348

13491349
/* nothing could have built up so far, so don't perform cleanup */

‎src/backend/storage/lmgr/lmgr.c

+100-2
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,21 @@
2525
#include "utils/inval.h"
2626

2727

28+
/*
29+
* Struct to hold context info for transaction lock waits.
30+
*
31+
* 'oper' is the operation that needs to wait for the other transaction; 'rel'
32+
* and 'ctid' specify the address of the tuple being waited for.
33+
*/
34+
typedef struct XactLockTableWaitInfo
35+
{
36+
XLTW_Oper oper;
37+
Relation rel;
38+
ItemPointer ctid;
39+
} XactLockTableWaitInfo;
40+
41+
static void XactLockTableWaitErrorCb(void *arg);
42+
2843
/*
2944
* RelationInitLockInfo
3045
* Initializes the lock information in a relation descriptor.
@@ -471,7 +486,9 @@ XactLockTableDelete(TransactionId xid)
471486
/*
472487
* XactLockTableWait
473488
*
474-
* Wait for the specified transaction to commit or abort.
489+
* Wait for the specified transaction to commit or abort. If an operation
490+
* is specified, an error context callback is set up. If 'oper' is passed as
491+
* None, no error context callback is set up.
475492
*
476493
* Note that this does the right thing for subtransactions: if we wait on a
477494
* subtransaction, we will exit as soon as it aborts or its top parent commits.
@@ -481,9 +498,31 @@ XactLockTableDelete(TransactionId xid)
481498
* and if so wait for its parent.
482499
*/
483500
void
484-
XactLockTableWait(TransactionId xid)
501+
XactLockTableWait(TransactionId xid, Relation rel, ItemPointer ctid,
502+
XLTW_Oper oper)
485503
{
486504
LOCKTAG tag;
505+
XactLockTableWaitInfo info;
506+
ErrorContextCallback callback;
507+
508+
/*
509+
* If an operation is specified, set up our verbose error context
510+
* callback.
511+
*/
512+
if (oper != XLTW_None)
513+
{
514+
Assert(RelationIsValid(rel));
515+
Assert(ItemPointerIsValid(ctid));
516+
517+
info.rel = rel;
518+
info.ctid = ctid;
519+
info.oper = oper;
520+
521+
callback.callback = XactLockTableWaitErrorCb;
522+
callback.arg = &info;
523+
callback.previous = error_context_stack;
524+
error_context_stack = &callback;
525+
}
487526

488527
for (;;)
489528
{
@@ -500,6 +539,9 @@ XactLockTableWait(TransactionId xid)
500539
break;
501540
xid = SubTransGetParent(xid);
502541
}
542+
543+
if (oper != XLTW_None)
544+
error_context_stack = callback.previous;
503545
}
504546

505547
/*
@@ -533,6 +575,62 @@ ConditionalXactLockTableWait(TransactionId xid)
533575
return true;
534576
}
535577

578+
/*
579+
* XactLockTableWaitErrorContextCb
580+
* Error context callback for transaction lock waits.
581+
*/
582+
static void
583+
XactLockTableWaitErrorCb(void *arg)
584+
{
585+
XactLockTableWaitInfo *info = (XactLockTableWaitInfo *) arg;
586+
587+
/*
588+
* We would like to print schema name too, but that would require a
589+
* syscache lookup.
590+
*/
591+
if (info->oper != XLTW_None &&
592+
ItemPointerIsValid(info->ctid) && RelationIsValid(info->rel))
593+
{
594+
const char *cxt;
595+
596+
switch (info->oper)
597+
{
598+
case XLTW_Update:
599+
cxt = gettext_noop("while updating tuple (%u,%u) in relation \"%s\"");
600+
break;
601+
case XLTW_Delete:
602+
cxt = gettext_noop("while deleting tuple (%u,%u) in relation \"%s\"");
603+
break;
604+
case XLTW_Lock:
605+
cxt = gettext_noop("while locking tuple (%u,%u) in relation \"%s\"");
606+
break;
607+
case XLTW_LockUpdated:
608+
cxt = gettext_noop("while locking updated version (%u,%u) of tuple in relation \"%s\"");
609+
break;
610+
case XLTW_InsertIndex:
611+
cxt = gettext_noop("while inserting index tuple (%u,%u) in relation \"%s\"");
612+
break;
613+
case XLTW_InsertIndexUnique:
614+
cxt = gettext_noop("while checking uniqueness of tuple (%u,%u) in relation \"%s\"");
615+
break;
616+
case XLTW_FetchUpdated:
617+
cxt = gettext_noop("while rechecking updated tuple (%u,%u) in relation \"%s\"");
618+
break;
619+
case XLTW_RecheckExclusionConstr:
620+
cxt = gettext_noop("while checking exclusion constraint on tuple (%u,%u) in relation \"%s\"");
621+
break;
622+
623+
default:
624+
return;
625+
}
626+
627+
errcontext(cxt,
628+
ItemPointerGetBlockNumber(info->ctid),
629+
ItemPointerGetOffsetNumber(info->ctid),
630+
RelationGetRelationName(info->rel));
631+
}
632+
}
633+
536634
/*
537635
* WaitForLockersMultiple
538636
* Wait until no transaction holds locks that conflict with the given

0 commit comments

Comments
 (0)