Patch from Massimo Dal Zotto <dz@cs.unitn.it>

The following patches add to the backend a new debugging flag -K which prints
a debug trace of all locking operations on user relations (those with oid
greater than 20000). The code is compiled only if LOCK_MGR_DEBUG is defined,
so the patch should be harmless if not explicitly enabled.
I'm using the code to trace deadlock conditions caused by application queries
using the command "$POSTMASTER -D $PGDATA -o '-d 1 -K 1'.
The patches are for version 6.0 dated 970126.
This commit is contained in:
Marc G. Fournier 1997-02-12 05:25:13 +00:00
parent ba82bb3eac
commit fb70587c1d
4 changed files with 161 additions and 40 deletions

View File

@ -7,7 +7,7 @@
*
*
* IDENTIFICATION
* $Header: /cvsroot/pgsql/src/backend/storage/lmgr/lock.c,v 1.6 1996/12/26 17:50:26 momjian Exp $
* $Header: /cvsroot/pgsql/src/backend/storage/lmgr/lock.c,v 1.7 1997/02/12 05:23:49 scrappy Exp $
*
* NOTES
* Outside modules can create a lock table and acquire/release
@ -57,41 +57,65 @@
#else /* LOCK_MGR_DEBUG */
int lockDebug = 0;
#ifndef LOCK_DEBUG_OID_MIN
/*
* This is totally arbitrary. It is the minimum relation oid
* which will trigger the locking debug when the -K option
* is given to the backend. This is done to avoid tracing
* locks on system relations.
*/
#define LOCK_DEBUG_OID_MIN 20000
#endif
#define LOCK_PRINT(where,tag,type)\
elog(NOTICE, "%s: rel (%d) dbid (%d) tid (%d,%d) type (%d)\n",where, \
tag->relId, tag->dbId, \
( (tag->tupleId.ip_blkid.data[0] >= 0) ? \
BlockIdGetBlockNumber(&tag->tupleId.ip_blkid) : -1 ), \
tag->tupleId.ip_posid, \
type);
if ((lockDebug >= 1) && (tag->relId >= LOCK_DEBUG_OID_MIN)) \
elog(DEBUG, \
"%s: pid (%d) rel (%d) dbid (%d) tid (%d,%d) type (%d)",where, \
getpid(),\
tag->relId, tag->dbId, \
((tag->tupleId.ip_blkid.bi_hi<<16)+\
tag->tupleId.ip_blkid.bi_lo),\
tag->tupleId.ip_posid, \
type);
#define LOCK_DUMP(where,lock,type)\
elog(NOTICE, "%s: rel (%d) dbid (%d) tid (%d,%d) nHolding (%d) holders (%d,%d,%d,%d,%d) type (%d)\n",where, \
lock->tag.relId, lock->tag.dbId, \
((lock->tag.tupleId.ip_blkid.data[0] >= 0) ? \
BlockIdGetBlockNumber(&lock->tag.tupleId.ip_blkid) : -1 ), \
lock->tag.tupleId.ip_posid, \
lock->nHolding,\
lock->holders[1],\
lock->holders[2],\
lock->holders[3],\
lock->holders[4],\
lock->holders[5],\
type);
if ((lockDebug >= 1) && (lock->tag.relId >= LOCK_DEBUG_OID_MIN)) \
elog(DEBUG, \
"%s: pid (%d) rel (%d) dbid (%d) tid (%d,%d) nHolding (%d) "\
"holders (%d,%d,%d,%d,%d) type (%d)",where, \
getpid(),\
lock->tag.relId, lock->tag.dbId, \
((lock->tag.tupleId.ip_blkid.bi_hi<<16)+\
lock->tag.tupleId.ip_blkid.bi_lo),\
lock->tag.tupleId.ip_posid, \
lock->nHolding,\
lock->holders[1],\
lock->holders[2],\
lock->holders[3],\
lock->holders[4],\
lock->holders[5],\
type);
#define XID_PRINT(where,xidentP)\
elog(NOTICE,\
"%s:xid (%d) pid (%d) lock (%x) nHolding (%d) holders (%d,%d,%d,%d,%d)",\
where,\
xidentP->tag.xid,\
xidentP->tag.pid,\
xidentP->tag.lock,\
xidentP->nHolding,\
xidentP->holders[1],\
xidentP->holders[2],\
xidentP->holders[3],\
xidentP->holders[4],\
xidentP->holders[5]);
if ((lockDebug >= 2) && \
(((LOCK *)MAKE_PTR(xidentP->tag.lock))->tag.relId \
>= LOCK_DEBUG_OID_MIN)) \
elog(DEBUG,\
"%s: pid (%d) xid (%d) pid (%d) lock (%x) nHolding (%d) "\
"holders (%d,%d,%d,%d,%d)",\
where,\
getpid(),\
xidentP->tag.xid,\
xidentP->tag.pid,\
xidentP->tag.lock,\
xidentP->nHolding,\
xidentP->holders[1],\
xidentP->holders[2],\
xidentP->holders[3],\
xidentP->holders[4],\
xidentP->holders[5]);
#endif /* LOCK_MGR_DEBUG */
@ -528,7 +552,7 @@ LockAcquire(LockTableId tableId, LOCKTAG *lockName, LOCKT lockt)
}
if (!found)
{
XID_PRINT("queueing XidEnt LockAcquire:", result);
XID_PRINT("LockAcquire: queueing XidEnt", result);
ProcAddLock(&result->queue);
result->nHolding = 0;
memset((char *)result->holders, 0, sizeof(int)*MAX_LOCKTYPES);
@ -1102,7 +1126,7 @@ LockReleaseAll(LockTableId tableId, SHM_QUEUE *lockQueue)
#endif
SHMQueueFirst(lockQueue,(Pointer*)&xidLook,&xidLook->queue);
XID_PRINT("LockReleaseAll:", xidLook);
XID_PRINT("LockReleaseAll", xidLook);
#ifndef USER_LOCKS
SpinAcquire(masterLock);
@ -1322,3 +1346,75 @@ LockingDisabled()
{
return LockingIsDisabled;
}
#ifdef DEADLOCK_DEBUG
/*
* Dump all locks. Must have already acquired the masterLock.
*/
void
DumpLocks()
{
SHMEM_OFFSET location;
PROC *proc;
SHM_QUEUE *lockQueue;
int done;
XIDLookupEnt *xidLook = NULL;
XIDLookupEnt *tmp = NULL;
SHMEM_OFFSET end;
SPINLOCK masterLock;
int nLockTypes;
LOCK *lock;
int pid, count;
int tableId = 1;
LOCKTAB *ltable;
pid = getpid();
ShmemPIDLookup(pid,&location);
if (location == INVALID_OFFSET)
return;
proc = (PROC *) MAKE_PTR(location);
if (proc != MyProc)
return;
lockQueue = &proc->lockQueue;
Assert (tableId < NumTables);
ltable = AllTables[tableId];
if (!ltable)
return;
nLockTypes = ltable->ctl->nLockTypes;
masterLock = ltable->ctl->masterLock;
if (SHMQueueEmpty(lockQueue))
return;
SHMQueueFirst(lockQueue,(Pointer*)&xidLook,&xidLook->queue);
end = MAKE_OFFSET(lockQueue);
LOCK_DUMP("DumpLocks", MyProc->waitLock, 0);
XID_PRINT("DumpLocks", xidLook);
for (count=0;;) {
/* ---------------------------
* XXX Here we assume the shared memory queue is circular and
* that we know its internal structure. Should have some sort of
* macros to allow one to walk it. mer 20 July 1991
* ---------------------------
*/
done = (xidLook->queue.next == end);
lock = (LOCK *) MAKE_PTR(xidLook->tag.lock);
LOCK_DUMP("DumpLocks",lock,0);
if (count++ > 2000) {
elog(NOTICE,"DumpLocks: xid loop detected, giving up");
break;
}
if (done)
break;
SHMQueueFirst(&xidLook->queue,(Pointer*)&tmp,&tmp->queue);
xidLook = tmp;
}
}
#endif

View File

@ -7,7 +7,7 @@
*
*
* IDENTIFICATION
* $Header: /cvsroot/pgsql/src/backend/storage/lmgr/proc.c,v 1.14 1997/02/11 23:05:38 momjian Exp $
* $Header: /cvsroot/pgsql/src/backend/storage/lmgr/proc.c,v 1.15 1997/02/12 05:23:54 scrappy Exp $
*
*-------------------------------------------------------------------------
*/
@ -46,7 +46,7 @@
* This is so that we can support more backends. (system-wide semaphore
* sets run out pretty fast.) -ay 4/95
*
* $Header: /cvsroot/pgsql/src/backend/storage/lmgr/proc.c,v 1.14 1997/02/11 23:05:38 momjian Exp $
* $Header: /cvsroot/pgsql/src/backend/storage/lmgr/proc.c,v 1.15 1997/02/12 05:23:54 scrappy Exp $
*/
#include <sys/time.h>
#ifndef WIN32
@ -685,6 +685,10 @@ HandleDeadLock(int sig)
lock = MyProc->waitLock;
size = lock->waitProcs.size; /* so we can look at this in the core */
#ifdef DEADLOCK_DEBUG
DumpLocks();
#endif
/* ------------------------
* Get this process off the lock's wait queue
* ------------------------

View File

@ -7,7 +7,7 @@
*
*
* IDENTIFICATION
* $Header: /cvsroot/pgsql/src/backend/tcop/postgres.c,v 1.29 1997/02/03 04:43:31 scrappy Exp $
* $Header: /cvsroot/pgsql/src/backend/tcop/postgres.c,v 1.30 1997/02/12 05:24:22 scrappy Exp $
*
* NOTES
* this is the "main" module of the postgres backend and
@ -91,6 +91,9 @@ static bool DebugPrintRewrittenParsetree = false;
/*static bool EnableRewrite = true; , never changes why have it*/
CommandDest whereToSendOutput;
#ifdef LOCK_MGR_DEBUG
extern int lockDebug;
#endif
extern int lockingOff;
extern int NBuffers;
@ -757,6 +760,9 @@ static void usage(char* progname)
fprintf(stderr, " F: turn off fsync\n");
fprintf(stderr, " f: forbid plantype generation\n");
fprintf(stderr, " i: don't execute the query, just show the plan tree\n");
#ifdef LOCK_MGR_DEBUG
fprintf(stderr, " K: set locking debug level [0|1|2]\n");
#endif
fprintf(stderr, " L: turn off locking\n");
fprintf(stderr, " m: set up a listening backend at portno to support multiple front-ends\n");
fprintf(stderr, " M: start as postmaster\n");
@ -846,7 +852,10 @@ PostgresMain(int argc, char *argv[])
*/
flagC = flagQ = flagS = flagE = flagEu = ShowStats = 0;
ShowParserStats = ShowPlannerStats = ShowExecutorStats = 0;
#ifdef LOCK_MGR_DEBUG
lockDebug = 0;
#endif
/* get hostname is either the environment variable PGHOST
or 'localhost' */
if (!(hostName = getenv("PGHOST"))) {
@ -858,7 +867,7 @@ PostgresMain(int argc, char *argv[])
DataDir = getenv("PGDATA"); /* default */
multiplexedBackend = false; /* default */
while ((flag = getopt(argc, argv, "B:bCD:d:Eef:iLm:MNo:P:pQSst:x:F"))
while ((flag = getopt(argc, argv, "B:bCD:d:Eef:iK:Lm:MNo:P:pQSst:x:F"))
!= EOF)
switch (flag) {
@ -955,6 +964,14 @@ PostgresMain(int argc, char *argv[])
dontExecute = 1;
break;
case 'K':
#ifdef LOCK_MGR_DEBUG
lockDebug = atoi(optarg);
#else
fprintf(stderr, "Lock debug not compiled in\n");
#endif
break;
case 'L':
/* --------------------
* turn off locking
@ -1283,7 +1300,7 @@ PostgresMain(int argc, char *argv[])
*/
if (IsUnderPostmaster == false) {
puts("\nPOSTGRES backend interactive interface");
puts("$Revision: 1.29 $ $Date: 1997/02/03 04:43:31 $");
puts("$Revision: 1.30 $ $Date: 1997/02/12 05:24:22 $");
}
/* ----------------

View File

@ -6,7 +6,7 @@
*
* Copyright (c) 1994, Regents of the University of California
*
* $Id: lock.h,v 1.3 1996/11/05 06:11:00 scrappy Exp $
* $Id: lock.h,v 1.4 1997/02/12 05:25:13 scrappy Exp $
*
*-------------------------------------------------------------------------
*/
@ -211,4 +211,8 @@ extern bool LockReleaseAll(LockTableId tableId, SHM_QUEUE *lockQueue);
extern int LockShmemSize(void);
extern bool LockingDisabled(void);
#ifdef DEADLOCK_DEBUG
extern void DumpLocks(void);
#endif
#endif /* LOCK_H */