On 07.01.2012 09:58, Heikki Linnakangas wrote:
Here's the patch,
*sigh*, and here's the forgotten attachment.
--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com
diff --git a/src/backend/storage/lmgr/lwlock.c b/src/backend/storage/lmgr/lwlock.c
index 079eb29..c38a884 100644
--- a/src/backend/storage/lmgr/lwlock.c
+++ b/src/backend/storage/lmgr/lwlock.c
@@ -1,3 +1,4 @@
+#define LWLOCK_PROFILING
/*-------------------------------------------------------------------------
*
* lwlock.c
@@ -21,6 +22,11 @@
*/
#include "postgres.h"
+#ifdef LWLOCK_PROFILING
+#include <signal.h>
+#include <time.h>
+#endif
+
#include "access/clog.h"
#include "access/multixact.h"
#include "access/subtrans.h"
@@ -90,6 +95,17 @@ static LWLockId held_lwlocks[MAX_SIMUL_LWLOCKS];
static int lock_addin_request = 0;
static bool lock_addin_request_allowed = true;
+#ifdef LWLOCK_PROFILING
+
+static int acquiring_lockid;
+static int releasing_lockid;
+static int waiting_lockid;
+
+static int *timed_counts = NULL;
+static int idle_count = 0;
+
+#endif
+
#ifdef LWLOCK_STATS
static int counts_for_pid = 0;
static int *sh_acquire_counts;
@@ -145,6 +161,42 @@ print_lwlock_stats(int code, Datum arg)
}
#endif /* LWLOCK_STATS */
+#ifdef LWLOCK_PROFILING
+
+static void
+print_lwlock_profile(int code, Datum arg)
+{
+ int i;
+ int total;
+ int *LWLockCounter = (int *) ((char *) LWLockArray - 2 * sizeof(int));
+ int numLocks = LWLockCounter[1];
+
+ /* Grab an LWLock to keep different backends from mixing reports */
+ LWLockAcquire(0, LW_EXCLUSIVE);
+
+ total = 0;
+ for (i = 0; i < numLocks; i++)
+ {
+ total += timed_counts[i];
+ }
+ total += idle_count;
+
+ if (total > 100)
+ {
+ for (i = 0; i < numLocks; i++)
+ {
+ if (timed_counts[i] > total / 100)
+ fprintf(stderr, "PID %d lwlock %d: busy %f (%d / %d)\n",
+ MyProcPid, i,
+ (double) timed_counts[i] / (double) total,
+ timed_counts[i], total);
+ }
+ }
+
+ LWLockRelease(0);
+}
+#endif /* LWLOCK_PROFILING */
+
/*
* Compute number of LWLocks to allocate.
@@ -312,6 +364,21 @@ LWLockAssign(void)
}
+#ifdef LWLOCK_PROFILING
+static void
+prof_timer_interrupt(union sigval si)
+{
+ if (acquiring_lockid != -1)
+ timed_counts[acquiring_lockid]++;
+ else if (releasing_lockid != -1)
+ timed_counts[releasing_lockid]++;
+ else if (waiting_lockid != -1)
+ timed_counts[waiting_lockid]++;
+ else
+ idle_count++;
+}
+#endif
+
/*
* LWLockAcquire - acquire a lightweight lock in the specified mode
*
@@ -349,6 +416,40 @@ LWLockAcquire(LWLockId lockid, LWLockMode mode)
sh_acquire_counts[lockid]++;
#endif /* LWLOCK_STATS */
+
+#ifdef LWLOCK_PROFILING
+ if (timed_counts == NULL && IsUnderPostmaster)
+ {
+ timer_t timerid;
+ struct itimerspec interval;
+ struct sigevent se;
+
+ elog(LOG, "arming timer on pid %u", MyProcPid);
+
+ timed_counts = calloc(NumLWLocks(), sizeof(int));
+ idle_count = 0;
+ acquiring_lockid = releasing_lockid = waiting_lockid = -1;
+
+ se.sigev_notify = SIGEV_THREAD;
+ se.sigev_value.sival_ptr = NULL;
+ se.sigev_notify_function = prof_timer_interrupt;
+ se.sigev_notify_attributes = NULL;
+
+ if (timer_create(CLOCK_REALTIME, &se, &timerid) == -1)
+ elog(WARNING, "failed to create timer: %m");
+
+ interval.it_value.tv_sec = 1;
+ interval.it_value.tv_nsec = 0;
+ interval.it_interval.tv_sec = 0;
+ interval.it_interval.tv_nsec = 10000000; /* 10 ms */
+
+ if (timer_settime(timerid, 0, &interval, NULL) == -1)
+ elog(WARNING, "failed to set timer: %m");
+
+ on_shmem_exit(print_lwlock_profile, 0);
+ }
+#endif /* LWLOCK_PROFILING */
+
/*
* We can't wait if we haven't got a PGPROC. This should only occur
* during bootstrap or shared memory initialization. Put an Assert here
@@ -360,6 +461,10 @@ LWLockAcquire(LWLockId lockid, LWLockMode mode)
if (num_held_lwlocks >= MAX_SIMUL_LWLOCKS)
elog(ERROR, "too many LWLocks taken");
+#ifdef LWLOCK_PROFILING
+ acquiring_lockid = lockid;
+#endif
+
/*
* Lock out cancel/die interrupts until we exit the code section protected
* by the LWLock. This ensures that interrupts will not interfere with
@@ -460,6 +565,8 @@ LWLockAcquire(LWLockId lockid, LWLockMode mode)
#endif
TRACE_POSTGRESQL_LWLOCK_WAIT_START(lockid, mode);
+ waiting_lockid = lockid;
+ acquiring_lockid = -1;
for (;;)
{
@@ -470,6 +577,9 @@ LWLockAcquire(LWLockId lockid, LWLockMode mode)
extraWaits++;
}
+ waiting_lockid = -1;
+ acquiring_lockid = lockid;
+
TRACE_POSTGRESQL_LWLOCK_WAIT_DONE(lockid, mode);
LOG_LWDEBUG("LWLockAcquire", lockid, "awakened");
@@ -491,6 +601,8 @@ LWLockAcquire(LWLockId lockid, LWLockMode mode)
*/
while (extraWaits-- > 0)
PGSemaphoreUnlock(&proc->sem);
+
+ acquiring_lockid = -1;
}
/*
@@ -577,6 +689,8 @@ LWLockRelease(LWLockId lockid)
PRINT_LWDEBUG("LWLockRelease", lockid, lock);
+ releasing_lockid = lockid;
+
/*
* Remove lock from list of locks held. Usually, but not always, it will
* be the latest-acquired lock; so search array backwards.
@@ -662,6 +776,8 @@ LWLockRelease(LWLockId lockid)
* Now okay to allow cancel/die interrupts.
*/
RESUME_INTERRUPTS();
+
+ releasing_lockid = -1;
}
--
Sent via pgsql-hackers mailing list ([email protected])
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
