Improving deadlock error messages
The error message we currently produce when a deadlock occurs is pretty
unfriendly:
ERROR: deadlock detected
DETAIL: Process 32068 waits for AccessExclusiveLock on relation
16413 of database 16384; blocked by process 32064.
Process 32064 waits for AccessExclusiveLock on relation 16415
of database 16384; blocked by process 32068.
Users encounter this message relatively frequently -- and they often
depend on the information in the errdetail to track down the source of
the deadlock. Presenting numeric OIDs effectively forces the DBA to
resolve the OIDs to the appropriate relation and database names
manually.
I whipped up a quick patch to use names as well as OIDs for the
identifiers in the message, but on reflection the simple approach to
doing this is problematic: when we do syscache lookups to lookup the
identifier names, we might need to acquire an AccessShareLock on various
system catalogs (pg_class, pg_namespace, pg_database). This could fail
(e.g. because of a deadlock involving a system catalog), causing the
deadlock detector to infinitely recurse (albeit slowly).
We could fix this by first conditionally acquiring AccessShareLocks on
the necessary system catalogs. If any of those lock acquisitions fails,
we can just print the numeric OID instead. Since failing to acquire an
AccessShareLock on the system catalogs should not occur frequently in
practise, most users should see a more friendly error message.
Comments? Anyone see a better approach?
-Neil
Neil Conway <neilc@samurai.com> writes:
I whipped up a quick patch to use names as well as OIDs for the
identifiers in the message, but on reflection the simple approach to
doing this is problematic: when we do syscache lookups to lookup the
identifier names, we might need to acquire an AccessShareLock on various
system catalogs (pg_class, pg_namespace, pg_database). This could fail
(e.g. because of a deadlock involving a system catalog), causing the
deadlock detector to infinitely recurse (albeit slowly).
Yup, that's exactly why it doesn't do that already.
We could fix this by first conditionally acquiring AccessShareLocks on
the necessary system catalogs.
I don't think you've thought of quite all of the failure cases. One
that's a bit pressing is that a deadlock isn't necessarily confined to
objects in your own database.
My take on this is that I'd much rather have unfriendly information
than none at all.
regards, tom lane
"Tom Lane" <tgl@sss.pgh.pa.us> writes:
I don't think you've thought of quite all of the failure cases. One
that's a bit pressing is that a deadlock isn't necessarily confined to
objects in your own database.
We could do the syscache lookups for only the object we're waiting on and
store that information in the lock table for others to refer to. We would have
to do the syscache lookup either always or at the point where we first decide
we have to block.
--
Gregory Stark
EnterpriseDB http://www.enterprisedb.com
On Fri, 2007-04-20 at 02:55 -0400, Tom Lane wrote:
I don't think you've thought of quite all of the failure cases. One
that's a bit pressing is that a deadlock isn't necessarily confined to
objects in your own database.
I'm not sure I follow. If we conditionally acquire the locks we need and
always fallback to just printing the numeric OIDs, ISTM we should be
able to avoid the infinite recursion problem. (If necessary, we can
always special-case objects outside our own database, although I'm not
sure that's necessary.)
-Neil
Neil Conway <neilc@samurai.com> writes:
On Fri, 2007-04-20 at 02:55 -0400, Tom Lane wrote:
I don't think you've thought of quite all of the failure cases. One
that's a bit pressing is that a deadlock isn't necessarily confined to
objects in your own database.
I'm not sure I follow. If we conditionally acquire the locks we need and
always fallback to just printing the numeric OIDs, ISTM we should be
able to avoid the infinite recursion problem. (If necessary, we can
always special-case objects outside our own database, although I'm not
sure that's necessary.)
Maybe so, but you're going to be writing quite a lot of duplicative
code, because the existing routines you might have been thinking of
using (lsyscache.c etc) don't behave that way.
The basic objection I've got to this is that it'll introduce a lot of
complexity and fragility into a seldom-taken error-recovery path,
which is almost by definition not well enough tested already.
regards, tom lane
On Sat, 2007-04-21 at 02:38 -0400, Tom Lane wrote:
Maybe so, but you're going to be writing quite a lot of duplicative
code, because the existing routines you might have been thinking of
using (lsyscache.c etc) don't behave that way.
Right, I'm envisioning doing a conditional LockAcquire and then
heap_open() / heap_getnext() by hand. That will be relatively slow, but
code that emits a deadlock error message is almost by definition not
performance critical.
BTW, another alternative would be to set a global variable instructing
LockAcquire() to not block waiting for a lock; instead, it would
longjmp(), a la elog(ERROR). You could even construct something similar
to PG_TRY():
PG_COND_LOCK();
{
/* do various things that might acquire lmgr locks */
}
PG_ACQUIRE_FAILED()
{
/* failed to acquire an lmgr lock */
}
PG_END_COND_LOCK();
The risk would be leaving the LockAcquire() call site in an inconsistent
state when we longjmp(), but since DeadLockReport() is going to
ereport(ERROR) anyway, it might be sufficiently safe. This scheme does
seem a bit fragile, though...
-Neil
On Sat, 2007-04-21 at 17:56 -0400, Neil Conway wrote:
Right, I'm envisioning doing a conditional LockAcquire and then
heap_open() / heap_getnext() by hand. That will be relatively slow, but
code that emits a deadlock error message is almost by definition not
performance critical.
... although it turns out you'd need to conditionally lock a *lot* of
system catalogs to guarantee that you're not going to block on a lock at
some point. Needless to say, that approach would be pretty ugly and
fragile.
BTW, another alternative would be to set a global variable instructing
LockAcquire() to not block waiting for a lock; instead, it would
longjmp(), a la elog(ERROR). You could even construct something similar
to PG_TRY()
Attached is a very quick hack of a patch to do this.
-Neil
Attachments:
deadlock_error_msg-4.patchtext/x-patch; charset=us-ascii; name=deadlock_error_msg-4.patchDownload
Index: src/backend/storage/lmgr/deadlock.c
===================================================================
RCS file: /home/neilc/postgres/cvs_root/pgsql/src/backend/storage/lmgr/deadlock.c,v
retrieving revision 1.47
diff -c -p -r1.47 deadlock.c
*** src/backend/storage/lmgr/deadlock.c 20 Apr 2007 20:15:52 -0000 1.47
--- src/backend/storage/lmgr/deadlock.c 21 Apr 2007 23:43:13 -0000
***************
*** 25,34 ****
--- 25,39 ----
*/
#include "postgres.h"
+ #include "access/htup.h"
+ #include "commands/dbcommands.h"
#include "lib/stringinfo.h"
#include "miscadmin.h"
#include "storage/proc.h"
+ #include "utils/builtins.h"
+ #include "utils/lsyscache.h"
#include "utils/memutils.h"
+ #include "utils/syscache.h"
/* One edge in the waits-for graph */
*************** static bool FindLockCycleRecurse(PGPROC
*** 73,78 ****
--- 78,85 ----
static bool ExpandConstraints(EDGE *constraints, int nConstraints);
static bool TopoSort(LOCK *lock, EDGE *constraints, int nConstraints,
PGPROC **ordering);
+ static char *format_relation(Oid reloid);
+ static const char *format_database(Oid dboid);
#ifdef DEBUG_DEADLOCK
static void PrintLockQueue(LOCK *lock, const char *info);
*************** DescribeLockTag(StringInfo buf, const LO
*** 846,875 ****
{
case LOCKTAG_RELATION:
appendStringInfo(buf,
! _("relation %u of database %u"),
! lock->locktag_field2,
! lock->locktag_field1);
break;
case LOCKTAG_RELATION_EXTEND:
appendStringInfo(buf,
! _("extension of relation %u of database %u"),
! lock->locktag_field2,
! lock->locktag_field1);
break;
case LOCKTAG_PAGE:
appendStringInfo(buf,
! _("page %u of relation %u of database %u"),
lock->locktag_field3,
! lock->locktag_field2,
! lock->locktag_field1);
break;
case LOCKTAG_TUPLE:
appendStringInfo(buf,
! _("tuple (%u,%u) of relation %u of database %u"),
lock->locktag_field3,
lock->locktag_field4,
! lock->locktag_field2,
! lock->locktag_field1);
break;
case LOCKTAG_TRANSACTION:
appendStringInfo(buf,
--- 853,882 ----
{
case LOCKTAG_RELATION:
appendStringInfo(buf,
! _("relation %s of database %s"),
! format_relation(lock->locktag_field2),
! format_database(lock->locktag_field1));
break;
case LOCKTAG_RELATION_EXTEND:
appendStringInfo(buf,
! _("extension of relation %s of database %s"),
! format_relation(lock->locktag_field2),
! format_database(lock->locktag_field1));
break;
case LOCKTAG_PAGE:
appendStringInfo(buf,
! _("page %u of relation %s of database %s"),
lock->locktag_field3,
! format_relation(lock->locktag_field2),
! format_database(lock->locktag_field1));
break;
case LOCKTAG_TUPLE:
appendStringInfo(buf,
! _("tuple (%u,%u) of relation %s of database %s"),
lock->locktag_field3,
lock->locktag_field4,
! format_relation(lock->locktag_field2),
! format_database(lock->locktag_field1));
break;
case LOCKTAG_TRANSACTION:
appendStringInfo(buf,
*************** DescribeLockTag(StringInfo buf, const LO
*** 878,887 ****
break;
case LOCKTAG_OBJECT:
appendStringInfo(buf,
! _("object %u of class %u of database %u"),
lock->locktag_field3,
lock->locktag_field2,
! lock->locktag_field1);
break;
case LOCKTAG_USERLOCK:
/* reserved for old contrib code, now on pgfoundry */
--- 885,894 ----
break;
case LOCKTAG_OBJECT:
appendStringInfo(buf,
! _("object %u of class %u of database %s"),
lock->locktag_field3,
lock->locktag_field2,
! format_database(lock->locktag_field1));
break;
case LOCKTAG_USERLOCK:
/* reserved for old contrib code, now on pgfoundry */
*************** DescribeLockTag(StringInfo buf, const LO
*** 907,912 ****
--- 914,977 ----
}
}
+ static char *
+ format_relation(Oid reloid)
+ {
+ char *result;
+
+ PG_LOCK_NOWAIT();
+ {
+ HeapTuple class_tup;
+
+ class_tup = SearchSysCache(RELOID,
+ ObjectIdGetDatum(reloid),
+ 0, 0, 0);
+
+ if (HeapTupleIsValid(class_tup))
+ {
+ Form_pg_class classform = (Form_pg_class) GETSTRUCT(class_tup);
+ char *relname;
+ char *nspname;
+
+ relname = NameStr(classform->relname);
+ nspname = get_namespace_name(classform->relnamespace);
+ result = quote_qualified_identifier(nspname, relname);
+
+ ReleaseSysCache(class_tup);
+ return result;
+ }
+ }
+ PG_LOCK_FAILED();
+ {
+ ;
+ }
+ PG_END_LOCK_NOWAIT();
+
+ /*
+ * Either we failed to acquire a necessary lmgr lock, or else the
+ * rel isn't in our database, so just return the OID
+ */
+ result = (char *) palloc(NAMEDATALEN);
+ snprintf(result, NAMEDATALEN, "%u", reloid);
+ return result;
+ }
+
+ static const char *
+ format_database(Oid dboid)
+ {
+ PG_LOCK_NOWAIT();
+ {
+ return quote_identifier(get_database_name(dboid));
+ }
+ PG_LOCK_FAILED();
+ {
+ char *result = (char *) palloc(NAMEDATALEN);
+ snprintf(result, NAMEDATALEN, "%u", dboid);
+ return result;
+ }
+ PG_END_LOCK_NOWAIT();
+ }
+
/*
* Report a detected DS_HARD_DEADLOCK, with available details.
*/
Index: src/backend/storage/lmgr/lock.c
===================================================================
RCS file: /home/neilc/postgres/cvs_root/pgsql/src/backend/storage/lmgr/lock.c,v
retrieving revision 1.176
diff -c -p -r1.176 lock.c
*** src/backend/storage/lmgr/lock.c 1 Feb 2007 19:10:28 -0000 1.176
--- src/backend/storage/lmgr/lock.c 21 Apr 2007 23:38:32 -0000
***************
*** 46,51 ****
--- 46,54 ----
/* This configuration variable is used to set the lock table size */
int max_locks_per_xact; /* set by guc.c */
+ int lock_no_wait_count = 0;
+ sigjmp_buf *lock_no_wait_stack = NULL;
+
#define NLOCKENTS() \
mul_size(max_locks_per_xact, add_size(MaxBackends, max_prepared_xacts))
*************** LockAcquire(const LOCKTAG *locktag,
*** 752,758 ****
* blocking, remove useless table entries and return NOT_AVAIL without
* waiting.
*/
! if (dontWait)
{
if (proclock->holdMask == 0)
{
--- 755,761 ----
* blocking, remove useless table entries and return NOT_AVAIL without
* waiting.
*/
! if (dontWait || lock_no_wait_count > 0)
{
if (proclock->holdMask == 0)
{
*************** LockAcquire(const LOCKTAG *locktag,
*** 775,781 ****
LWLockRelease(partitionLock);
if (locallock->nLocks == 0)
RemoveLocalLock(locallock);
! return LOCKACQUIRE_NOT_AVAIL;
}
/*
--- 778,794 ----
LWLockRelease(partitionLock);
if (locallock->nLocks == 0)
RemoveLocalLock(locallock);
!
! if (dontWait)
! return LOCKACQUIRE_NOT_AVAIL;
!
! /*
! * If we're inside a PG_LOCK_NOWAIT() block, longjmp
! * instead of waiting.
! */
! if (lock_no_wait_stack == NULL)
! elog(FATAL, "lmgr nowait lock stack corrupted");
! siglongjmp(*lock_no_wait_stack, 1);
}
/*
Index: src/include/storage/lock.h
===================================================================
RCS file: /home/neilc/postgres/cvs_root/pgsql/src/include/storage/lock.h,v
retrieving revision 1.104
diff -c -p -r1.104 lock.h
*** src/include/storage/lock.h 3 Mar 2007 18:46:40 -0000 1.104
--- src/include/storage/lock.h 21 Apr 2007 23:34:43 -0000
*************** extern void DumpLocks(PGPROC *proc);
*** 462,465 ****
--- 462,491 ----
extern void DumpAllLocks(void);
#endif
+ #define PG_LOCK_NOWAIT() \
+ do { \
+ sigjmp_buf *save_lock_stack = lock_no_wait_stack; \
+ int save_lock_count = lock_no_wait_count; \
+ sigjmp_buf local_sigjmp_buf; \
+ if (sigsetjmp(local_sigjmp_buf, 0) == 0) \
+ { \
+ lock_no_wait_stack = &local_sigjmp_buf; \
+ lock_no_wait_count++
+
+ #define PG_LOCK_FAILED() \
+ } \
+ else \
+ { \
+ lock_no_wait_stack = save_lock_stack; \
+ lock_no_wait_count = save_lock_count;
+
+ #define PG_END_LOCK_NOWAIT() \
+ } \
+ lock_no_wait_stack = save_lock_stack; \
+ lock_no_wait_count = save_lock_count; \
+ } while (0)
+
+ extern int lock_no_wait_count;
+ extern sigjmp_buf *lock_no_wait_stack;
+
#endif /* LOCK_H */
On Sat, 2007-04-21 at 19:43 -0400, Neil Conway wrote:
Attached is a very quick hack of a patch to do this.
Does anyone have any feedback on this approach? If people are satisfied
with this solution, I can get a cleaned up patch ready to apply shortly.
-Neil
Neil Conway <neilc@samurai.com> writes:
On Sat, 2007-04-21 at 19:43 -0400, Neil Conway wrote:
Attached is a very quick hack of a patch to do this.
Does anyone have any feedback on this approach? If people are satisfied
with this solution, I can get a cleaned up patch ready to apply shortly.
I'm really still opposed to the entire concept. You're proposing to put
a lot of fragile-looking code into a seldom-exercised error path.
I fear bugs will survive a long time in there, and the net effect will be
that we get no information when we need it most. The numeric printouts
may be ugly, but they are reliable.
regards, tom lane
On Mon, 2007-04-23 at 17:38 -0400, Tom Lane wrote:
I'm really still opposed to the entire concept. You're proposing to put
a lot of fragile-looking code into a seldom-exercised error path.
There's certainly not a "lot" of code: the patch just adds a few
syscache lookups, wrapped in a PG_LOCK_NOWAIT() block.
As for fragility, I think the important point is whether it's safe to
siglongjmp() out of LockAcquire(); the rest is just window dressing.
-Neil
Neil Conway wrote:
On Mon, 2007-04-23 at 17:38 -0400, Tom Lane wrote:
I'm really still opposed to the entire concept. You're proposing to put
a lot of fragile-looking code into a seldom-exercised error path.There's certainly not a "lot" of code: the patch just adds a few
syscache lookups, wrapped in a PG_LOCK_NOWAIT() block.As for fragility, I think the important point is whether it's safe to
siglongjmp() out of LockAcquire(); the rest is just window dressing.
We have some elog(ERROR) calls in LockAcquire, so yes, there are some
siglongjmp calls already in there.
--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support
On Apr 23, 2007, at 11:38 PM, Tom Lane wrote:
Neil Conway <neilc@samurai.com> writes:
On Sat, 2007-04-21 at 19:43 -0400, Neil Conway wrote:
Attached is a very quick hack of a patch to do this.
Does anyone have any feedback on this approach? If people are
satisfied
with this solution, I can get a cleaned up patch ready to apply
shortly.I'm really still opposed to the entire concept. You're proposing
to put
a lot of fragile-looking code into a seldom-exercised error path.
I fear bugs will survive a long time in there, and the net effect
will be
that we get no information when we need it most. The numeric
printouts
may be ugly, but they are reliable.
If we're that worried about test coverage for deadlocks, what about
adding a test to the regression tests? IIRC the framework can
coordinate between multiple connections now...
--
Jim Nasby jim@nasby.net
EnterpriseDB http://enterprisedb.com 512.569.9461 (cell)