diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c index 1dac695..fbe2b78 100644 --- a/src/backend/postmaster/postmaster.c +++ b/src/backend/postmaster/postmaster.c @@ -4183,6 +4183,8 @@ SubPostmasterMain(int argc, char *argv[]) static void ExitPostmaster(int status) { + LWLockDumpHistograms(); + /* should cleanup shared memory and kill all backends */ /* diff --git a/src/backend/storage/lmgr/lwlock.c b/src/backend/storage/lmgr/lwlock.c index f152376..acbf70b 100644 --- a/src/backend/storage/lmgr/lwlock.c +++ b/src/backend/storage/lmgr/lwlock.c @@ -27,6 +27,7 @@ #include "commands/async.h" #include "miscadmin.h" #include "pg_trace.h" +#include "portability/instr_time.h" #include "storage/ipc.h" #include "storage/predicate.h" #include "storage/proc.h" @@ -45,6 +46,7 @@ typedef struct LWLock int shared; /* # of shared holders (0..MaxBackends) */ PGPROC *head; /* head of list of waiting PGPROCs */ PGPROC *tail; /* tail of list of waiting PGPROCs */ + uint64 histogram[33]; /* gigantic! */ /* tail is undefined when head is NULL */ } LWLock; @@ -60,7 +62,7 @@ typedef struct LWLock * LWLock is between 16 and 32 bytes on all known platforms, so these two * cases are sufficient. */ -#define LWLOCK_PADDED_SIZE (sizeof(LWLock) <= 16 ? 16 : 32) +#define LWLOCK_PADDED_SIZE 512 typedef union LWLockPadded { @@ -342,8 +344,10 @@ LWLockAcquire(LWLockId lockid, LWLockMode mode) PGPROC *proc = MyProc; bool retry = false; int extraWaits = 0; + instr_time start_time; PRINT_LWDEBUG("LWLockAcquire", lockid, lock); + INSTR_TIME_SET_ZERO(start_time); #ifdef LWLOCK_STATS /* Set up local count state first time through in a given process */ @@ -462,6 +466,9 @@ LWLockAcquire(LWLockId lockid, LWLockMode mode) */ LOG_LWDEBUG("LWLockAcquire", lockid, "waiting"); + if (INSTR_TIME_IS_ZERO(start_time)) + INSTR_TIME_SET_CURRENT(start_time); + #ifdef LWLOCK_STATS block_counts[lockid]++; #endif @@ -485,6 +492,19 @@ LWLockAcquire(LWLockId lockid, LWLockMode mode) retry = true; } + if (!INSTR_TIME_IS_ZERO(start_time)) + { + instr_time end_time; + int64 time_elapsed; + int f; + + INSTR_TIME_SET_CURRENT(end_time); + INSTR_TIME_SUBTRACT(end_time, start_time); + time_elapsed = INSTR_TIME_GET_MICROSEC(end_time); + f = fls((int) time_elapsed); + lock->histogram[f]++; + } + /* We are done updating shared state of the lock itself. */ SpinLockRelease(&lock->mutex); @@ -878,3 +898,37 @@ LWLockHeldByMe(LWLockId lockid) } return false; } + +void +LWLockDumpHistograms(void) +{ + int i; + int k; + char buffer[2048]; + char *s; + int *LWLockCounter = (int *) ((char *) LWLockArray - 2 * sizeof(int)); + int numLocks = LWLockCounter[1]; + + for (i = 0; i < numLocks; i++) + { + volatile LWLock *lock = &(LWLockArray[i].lock); + buffer[0] = '\0'; + s = buffer; + + for (k = 0; k < 32; ++k) + { + if (!lock->histogram[k]) + continue; + if (s != buffer) + { + *s++ = ','; + *s++ = ' '; + } + sprintf(s, "%d:%llu", k, + (long long unsigned) lock->histogram[k]); + s += strlen(buffer); + } + if (s != buffer) + elog(LOG, "lock %d: %s", i, buffer); + } +} diff --git a/src/include/storage/lwlock.h b/src/include/storage/lwlock.h index 57a4f66..ddfa524 100644 --- a/src/include/storage/lwlock.h +++ b/src/include/storage/lwlock.h @@ -118,5 +118,6 @@ extern Size LWLockShmemSize(void); extern void CreateLWLocks(void); extern void RequestAddinLWLocks(int n); +extern void LWLockDumpHistograms(void); #endif /* LWLOCK_H */