Add GUC log_lock_waits to log long wait times.
authorBruce Momjian
Sat, 3 Mar 2007 18:46:40 +0000 (18:46 +0000)
committerBruce Momjian
Sat, 3 Mar 2007 18:46:40 +0000 (18:46 +0000)
Simon Riggs

doc/src/sgml/config.sgml
src/backend/storage/lmgr/deadlock.c
src/backend/storage/lmgr/proc.c
src/backend/utils/misc/guc.c
src/backend/utils/misc/postgresql.conf.sample
src/include/storage/lock.h
src/include/storage/proc.h

index d3f09f6376948fc61cb05e8b026eb69078cfb916..2059fed863a4fc119fd8e8f5b1389f0e72546779 100644 (file)
@@ -1,4 +1,4 @@
-
+
 
 
   Server Configuration
@@ -2946,6 +2946,21 @@ SELECT * FROM parent WHERE key = 2400;
       
      
 
+     
+      log_lock_waits (boolean)
+      
+       log_lock_waits configuration parameter
+      
+      
+       
+        Controls whether a log message is produced when a statement waits
+        longer than  to acquire a
+        lock.  This is useful in determining if lock waits are causing
+        poor performance.  The default is off.
+       
+      
+     
+
      
       log_temp_files (integer)
       
@@ -3980,17 +3995,18 @@ dynamic_library_path = 'C:\tools\postgresql;H:\my_project\lib;$libdir'
         This is the amount of time, in milliseconds, to wait on a lock
         before checking to see if there is a deadlock condition. The
         check for deadlock is relatively slow, so the server doesn't run
-        it every time it waits for a lock. We (optimistically?) assume
+        it every time it waits for a lock. We optimistically assume
         that deadlocks are not common in production applications and
         just wait on the lock for a while before starting the check for a
         deadlock. Increasing this value reduces the amount of time
         wasted in needless deadlock checks, but slows down reporting of
         real deadlock errors. The default is one second (1s),
         which is probably about the smallest value you would want in
-        practice. On a heavily loaded server you might want to raise it.
+        practice.  Set  to log deadlock
+        checks.  On a heavily loaded server you might want to raise it.
         Ideally the setting should exceed your typical transaction time,
-        so as to improve the odds that a lock will be released before
-        the waiter decides to check for deadlock.
+        so as to improve the odds that a lock will be released before the
+        waiter decides to check for deadlock.
        
       
      
index 6a4b64c973c518e6089213bebb49f8e424e2bedb..ddbadfa0369dd0e2fbb28953bc92a90cca0014ee 100644 (file)
@@ -12,7 +12,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/storage/lmgr/deadlock.c,v 1.44 2007/01/05 22:19:38 momjian Exp $
+ *   $PostgreSQL: pgsql/src/backend/storage/lmgr/deadlock.c,v 1.45 2007/03/03 18:46:40 momjian Exp $
  *
  * Interface:
  *
@@ -187,13 +187,14 @@ InitDeadLockChecking(void)
  * deadlock.  If resolution is impossible, return TRUE --- the caller
  * is then expected to abort the given proc's transaction.
  *
- * Caller must already have locked all partitions of the lock tables.
+ * Caller must already have locked all partitions of the lock tables,
+ * so standard error logging/reporting code is handled by caller.
  *
  * On failure, deadlock details are recorded in deadlockDetails[] for
  * subsequent printing by DeadLockReport().  That activity is separate
  * because we don't want to do it while holding all those LWLocks.
  */
-bool
+DeadlockState
 DeadLockCheck(PGPROC *proc)
 {
    int         i,
@@ -204,6 +205,11 @@ DeadLockCheck(PGPROC *proc)
    nPossibleConstraints = 0;
    nWaitOrders = 0;
 
+#ifdef LOCK_DEBUG
+   if (Debug_deadlocks)
+       DumpAllLocks();
+#endif
+
    /* Search for deadlocks and possible fixes */
    if (DeadLockCheckRecurse(proc))
    {
@@ -217,7 +223,7 @@ DeadLockCheck(PGPROC *proc)
        if (!FindLockCycle(proc, possibleConstraints, &nSoftEdges))
            elog(FATAL, "deadlock seems to have disappeared");
 
-       return true;            /* cannot find a non-deadlocked state */
+       return DS_HARD_DEADLOCK;    /* cannot find a non-deadlocked state */
    }
 
    /* Apply any needed rearrangements of wait queues */
@@ -249,7 +255,11 @@ DeadLockCheck(PGPROC *proc)
        /* See if any waiters for the lock can be woken up now */
        ProcLockWakeup(GetLocksMethodTable(lock), lock);
    }
-   return false;
+
+   if (nWaitOrders > 0)
+       return DS_SOFT_DEADLOCK;
+   else
+       return DS_DEADLOCK_NOT_FOUND;
 }
 
 /*
@@ -896,7 +906,7 @@ DescribeLockTag(StringInfo buf, const LOCKTAG *lock)
 }
 
 /*
- * Report a detected deadlock, with available details.
+ * Report a detected DS_HARD_DEADLOCK, with available details.
  */
 void
 DeadLockReport(void)
index d32ae45c6befc8fd7ee8d2b3bca3e74f1525d5df..b8831f68c4040752a1d41f230d56574253018a20 100644 (file)
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/storage/lmgr/proc.c,v 1.184 2007/02/15 23:23:23 alvherre Exp $
+ *   $PostgreSQL: pgsql/src/backend/storage/lmgr/proc.c,v 1.185 2007/03/03 18:46:40 momjian Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -48,6 +48,7 @@
 /* GUC variables */
 int            DeadlockTimeout = 1000;
 int            StatementTimeout = 0;
+bool       log_lock_waits = false;
 
 /* Pointer to this process's PGPROC struct, if any */
 PGPROC    *MyProc = NULL;
@@ -979,6 +980,7 @@ static void
 CheckDeadLock(void)
 {
    int         i;
+   DeadlockState deadlock_state = DS_DEADLOCK_NOT_FOUND;
 
    /*
     * Acquire exclusive lock on the entire shared lock data structures. Must
@@ -1004,60 +1006,77 @@ CheckDeadLock(void)
     * This is quicker than checking our semaphore's state, since no kernel
     * call is needed, and it is safe because we hold the lock partition lock.
     */
-   if (MyProc->links.prev == INVALID_OFFSET ||
-       MyProc->links.next == INVALID_OFFSET)
-       goto check_done;
-
-#ifdef LOCK_DEBUG
-   if (Debug_deadlocks)
-       DumpAllLocks();
-#endif
-
-   if (!DeadLockCheck(MyProc))
+   if (MyProc->links.prev != INVALID_OFFSET &&
+       MyProc->links.next != INVALID_OFFSET)
+       deadlock_state = DeadLockCheck(MyProc);
+   
+   if (deadlock_state == DS_HARD_DEADLOCK)
    {
-       /* No deadlock, so keep waiting */
-       goto check_done;
-   }
-
-   /*
-    * Oops.  We have a deadlock.
-    *
-    * Get this process out of wait state.  (Note: we could do this more
-    * efficiently by relying on lockAwaited, but use this coding to preserve
-    * the flexibility to kill some other transaction than the one detecting
-    * the deadlock.)
-    *
-    * RemoveFromWaitQueue sets MyProc->waitStatus to STATUS_ERROR, so
-    * ProcSleep will report an error after we return from the signal handler.
-    */
-   Assert(MyProc->waitLock != NULL);
-   RemoveFromWaitQueue(MyProc, LockTagHashCode(&(MyProc->waitLock->tag)));
+       /*
+        * Oops.  We have a deadlock.
+        *
+        * Get this process out of wait state.  (Note: we could do this more
+        * efficiently by relying on lockAwaited, but use this coding to preserve
+        * the flexibility to kill some other transaction than the one detecting
+        * the deadlock.)
+        *
+        * RemoveFromWaitQueue sets MyProc->waitStatus to STATUS_ERROR, so
+        * ProcSleep will report an error after we return from the signal handler.
+        */
+       Assert(MyProc->waitLock != NULL);
+       RemoveFromWaitQueue(MyProc, LockTagHashCode(&(MyProc->waitLock->tag)));
 
-   /*
-    * Unlock my semaphore so that the interrupted ProcSleep() call can
-    * finish.
-    */
-   PGSemaphoreUnlock(&MyProc->sem);
+       /*
+        * Unlock my semaphore so that the interrupted ProcSleep() call can
+        * finish.
+        */
+       PGSemaphoreUnlock(&MyProc->sem);
 
-   /*
-    * We're done here.  Transaction abort caused by the error that ProcSleep
-    * will raise will cause any other locks we hold to be released, thus
-    * allowing other processes to wake up; we don't need to do that here.
-    * NOTE: an exception is that releasing locks we hold doesn't consider the
-    * possibility of waiters that were blocked behind us on the lock we just
-    * failed to get, and might now be wakable because we're not in front of
-    * them anymore.  However, RemoveFromWaitQueue took care of waking up any
-    * such processes.
-    */
+       /*
+        * We're done here.  Transaction abort caused by the error that ProcSleep
+        * will raise will cause any other locks we hold to be released, thus
+        * allowing other processes to wake up; we don't need to do that here.
+        * NOTE: an exception is that releasing locks we hold doesn't consider the
+        * possibility of waiters that were blocked behind us on the lock we just
+        * failed to get, and might now be wakable because we're not in front of
+        * them anymore.  However, RemoveFromWaitQueue took care of waking up any
+        * such processes.
+        */
+   }
 
    /*
     * Release locks acquired at head of routine.  Order is not critical, so
     * do it back-to-front to avoid waking another CheckDeadLock instance
     * before it can get all the locks.
     */
-check_done:
    for (i = NUM_LOCK_PARTITIONS; --i >= 0;)
        LWLockRelease(FirstLockMgrLock + i);
+
+   /*
+    * Issue any log messages requested.
+    *
+    * Deadlock ERROR messages are issued as part of transaction abort, so 
+    * these messages should not raise error states intentionally.
+    */
+   if (log_lock_waits)
+   {
+       switch (deadlock_state)
+       {
+           case DS_SOFT_DEADLOCK:
+               ereport(LOG,
+                   (errmsg("deadlock avoided by rearranging lock order")));
+               break;
+           case DS_DEADLOCK_NOT_FOUND:
+               ereport(LOG,
+                   (errmsg("statement waiting for lock for at least %d ms",
+                               DeadlockTimeout)));
+               break;
+           case DS_HARD_DEADLOCK:
+               break;  /* ERROR message handled during abort */
+           default:
+               break;
+       }
+   }
 }
 
 
index 12d5ecf181f62a9c4f0dfad7f2a31f94692b8042..173e9903c50e800a5719cc234c5e2d80df1da7e8 100644 (file)
@@ -10,7 +10,7 @@
  * Written by Peter Eisentraut .
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/utils/misc/guc.c,v 1.377 2007/02/23 21:36:18 momjian Exp $
+ *   $PostgreSQL: pgsql/src/backend/utils/misc/guc.c,v 1.378 2007/03/03 18:46:40 momjian Exp $
  *
  *--------------------------------------------------------------------
  */
@@ -811,6 +811,14 @@ static struct config_bool ConfigureNamesBool[] =
    },
 #endif
 
+   {
+       {"log_lock_waits", PGC_SIGHUP, LOGGING_WHAT,
+           gettext_noop("Logs long lock wait events."),
+           NULL
+       },
+       &log_lock_waits,
+       false, NULL, NULL
+   },
    {
        {"log_hostname", PGC_SIGHUP, LOGGING_WHAT,
            gettext_noop("Logs the host name in the connection logs."),
index 77a86f0020b3b5551cb7c0a5aa61c46c23ffbb70..7ee8d417c00944b687e96280151e8e303719a05d 100644 (file)
                    # e.g. '<%u%%%d> '
 #log_statement = 'none'            # none, ddl, mod, all
 #log_hostname = off
-
+#log_lock_waits = off          # Log lock waits longer than deadlock_timeout
 #log_temp_files = -1           # Log temporary files equal or larger
                    # than the specified number of kilobytes.
                    # -1 disables;  0 logs all temp files
index 5b258ab454b74c44fbaa87e456f56aacddab74ac..79494e65020cd1de9be5f2027707e3e9be553ea2 100644 (file)
@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1996-2007, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/include/storage/lock.h,v 1.103 2007/01/05 22:19:58 momjian Exp $
+ * $PostgreSQL: pgsql/src/include/storage/lock.h,v 1.104 2007/03/03 18:46:40 momjian Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -394,6 +394,13 @@ typedef enum
    LOCKACQUIRE_ALREADY_HELD    /* incremented count for lock already held */
 } LockAcquireResult;
 
+/* Deadlock states identified by DeadlockCheck() */
+typedef enum
+{
+   DS_DEADLOCK_NOT_FOUND,      /* no deadlock found within database server */
+   DS_SOFT_DEADLOCK,           /* deadlock, but lock queues rearrangeable */
+   DS_HARD_DEADLOCK            /* deadlock, no way out but ERROR */
+} DeadlockState;
 
 /*
  * The lockmgr's shared hash tables are partitioned to reduce contention.
@@ -442,7 +449,7 @@ extern void lock_twophase_postcommit(TransactionId xid, uint16 info,
 extern void lock_twophase_postabort(TransactionId xid, uint16 info,
                        void *recdata, uint32 len);
 
-extern bool DeadLockCheck(PGPROC *proc);
+extern DeadlockState DeadLockCheck(PGPROC *proc);
 extern void DeadLockReport(void);
 extern void RememberSimpleDeadLock(PGPROC *proc1,
                       LOCKMODE lockmode,
index 3e296fb0a3a8ffe3e41ca6dbd5542419c2047369..eeae751d828d6405ec99cc2db2a2cae5ba32cc33 100644 (file)
@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1996-2007, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/include/storage/proc.h,v 1.94 2007/02/15 23:23:23 alvherre Exp $
+ * $PostgreSQL: pgsql/src/include/storage/proc.h,v 1.95 2007/03/03 18:46:40 momjian Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -127,6 +127,7 @@ typedef struct PROC_HDR
 /* configurable options */
 extern int DeadlockTimeout;
 extern int StatementTimeout;
+extern bool    log_lock_waits;
 
 extern volatile bool cancel_from_timeout;