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 (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers