From 27c225bab6750bfeadb780b9758ac868d80bff6f Mon Sep 17 00:00:00 2001 From: Pavel Borisov Date: Tue, 1 Nov 2022 14:36:05 +0400 Subject: [PATCH] Print lwlock stats on CAS repeats (Separately for exclusive, shared, and wait-until-free lockers) --- src/backend/storage/lmgr/lwlock.c | 114 +++++++++++++++++++++++++++--- 1 file changed, 104 insertions(+), 10 deletions(-) diff --git a/src/backend/storage/lmgr/lwlock.c b/src/backend/storage/lmgr/lwlock.c index 9164d3ca466..91c3c2e2e2d 100644 --- a/src/backend/storage/lmgr/lwlock.c +++ b/src/backend/storage/lmgr/lwlock.c @@ -89,6 +89,8 @@ #include "storage/spin.h" #include "utils/memutils.h" +#define LWLOCK_STATS + #ifdef LWLOCK_STATS #include "utils/hsearch.h" #endif @@ -287,8 +289,13 @@ typedef struct lwlock_stats lwlock_stats_key key; int sh_acquire_count; int ex_acquire_count; + int acq_sh_cas_repeat; + int rel_sh_cas_repeat; + int acq_ex_cas_repeat; + int rel_ex_cas_repeat; + int acq_wuf_cas_repeat; + int rel_wuf_cas_repeat; int block_count; - int dequeue_self_count; int spin_delay_count; } lwlock_stats; @@ -395,11 +402,14 @@ print_lwlock_stats(int code, Datum arg) while ((lwstats = (lwlock_stats *) hash_seq_search(&scan)) != NULL) { fprintf(stderr, - "PID %d lwlock %s %p: shacq %u exacq %u blk %u spindelay %u dequeue self %u\n", + "PID %d lwlock %s %p: shacq %u exacq %u blk %u spindelay %u acq_sh_cas_repeat %u rel_sh_cas_repeat %u acq_ex_cas_repeat %u rel_ex_cas_repeat %u acq_wuf_cas_repeat %u rel_wuf_cas_repeat %u\n", MyProcPid, GetLWTrancheName(lwstats->key.tranche), lwstats->key.instance, lwstats->sh_acquire_count, lwstats->ex_acquire_count, lwstats->block_count, - lwstats->spin_delay_count, lwstats->dequeue_self_count); + lwstats->spin_delay_count, + lwstats->acq_sh_cas_repeat, lwstats->rel_sh_cas_repeat, + lwstats->acq_ex_cas_repeat, lwstats->rel_ex_cas_repeat, + lwstats->acq_wuf_cas_repeat, lwstats->rel_wuf_cas_repeat); } LWLockRelease(&MainLWLockArray[0].lock); @@ -430,8 +440,13 @@ get_lwlock_stats_entry(LWLock *lock) lwstats->sh_acquire_count = 0; lwstats->ex_acquire_count = 0; lwstats->block_count = 0; - lwstats->dequeue_self_count = 0; lwstats->spin_delay_count = 0; + lwstats->acq_sh_cas_repeat = 0; + lwstats->rel_sh_cas_repeat = 0; + lwstats->acq_ex_cas_repeat = 0; + lwstats->rel_ex_cas_repeat = 0; + lwstats->acq_wuf_cas_repeat = 0; + lwstats->rel_wuf_cas_repeat = 0; } return lwstats; } @@ -836,7 +851,7 @@ GetLWLockIdentifier(uint32 classId, uint16 eventId) */ static bool LWLockAttemptLock(LWLock *lock, LWLockMode mode, LWLockMode waitMode, - bool queue_ok, bool wakeup) + bool queue_ok, bool wakeup, void *lwstats) { uint64 old_state; @@ -964,7 +979,22 @@ LWLockAttemptLock(LWLock *lock, LWLockMode mode, LWLockMode waitMode, } } else + { +#ifdef LWLOCK_STATS + switch(waitMode) + { + case LW_EXCLUSIVE: + ((lwlock_stats*)lwstats)->acq_ex_cas_repeat++; + break; + case LW_SHARED: + ((lwlock_stats*)lwstats)->acq_sh_cas_repeat++; + break; + case LW_WAIT_UNTIL_FREE: + ((lwlock_stats*)lwstats)->acq_wuf_cas_repeat++; + } +#endif MyProc->lwWaiting = false; + } } pg_unreachable(); } @@ -1039,7 +1069,11 @@ LWLockAcquire(LWLock *lock, LWLockMode mode) */ for (;;) { - if (!LWLockAttemptLock(lock, mode, mode, true, wakeup)) +#ifdef LWLOCK_STATS + if (!LWLockAttemptLock(lock, mode, mode, true, wakeup, lwstats)) +#else + if (!LWLockAttemptLock(lock, mode, mode, true, wakeup, NULL)) +#endif { LOG_LWDEBUG("LWLockAcquire", lock, "immediately acquired lock"); break; /* got the lock */ @@ -1118,6 +1152,11 @@ bool LWLockConditionalAcquire(LWLock *lock, LWLockMode mode) { bool mustwait; +#ifdef LWLOCK_STATS + lwlock_stats *lwstats; + + lwstats = get_lwlock_stats_entry(lock); +#endif Assert(mode == LW_SHARED || mode == LW_EXCLUSIVE); @@ -1135,7 +1174,12 @@ LWLockConditionalAcquire(LWLock *lock, LWLockMode mode) HOLD_INTERRUPTS(); /* Check for the lock */ - mustwait = LWLockAttemptLock(lock, mode, mode, false, false); +#ifdef LWLOCK_STATS + mustwait = LWLockAttemptLock(lock, mode, mode, false, false, lwstats); +#else + mustwait = LWLockAttemptLock(lock, mode, mode, false, false, NULL); +#endif + if (mustwait) { @@ -1202,7 +1246,11 @@ LWLockAcquireOrWait(LWLock *lock, LWLockMode mode) * NB: We're using nearly the same twice-in-a-row lock acquisition * protocol as LWLockAcquire(). Check its comments for details. */ - mustwait = LWLockAttemptLock(lock, mode, LW_WAIT_UNTIL_FREE, true, false); +#ifdef LWLOCK_STATS + mustwait = LWLockAttemptLock(lock, mode, LW_WAIT_UNTIL_FREE, true, false, lwstats); +#else + mustwait = LWLockAttemptLock(lock, mode, LW_WAIT_UNTIL_FREE, true, false, NULL); +#endif if (mustwait) { @@ -1317,7 +1365,7 @@ LWLockConflictsWithVar(LWLock *lock, old_state = pg_atomic_read_u64(&lock->state); } #ifdef LWLOCK_STATS - delays += delayStatus.delays; +// delays += delayStatus.delays; #endif finish_spin_delay(&delayStatus); } @@ -1520,7 +1568,7 @@ lockVar(LWLock *lock) oldState = pg_atomic_read_u64(&lock->state); } #ifdef LWLOCK_STATS - delays += delayStatus.delays; +// delays += delayStatus.delays; #endif finish_spin_delay(&delayStatus); @@ -1597,6 +1645,11 @@ LWLockUpdateVar(LWLock *lock, uint64 *valptr, uint64 val) oldTail = INVALID_LOCK_PROCNO, oldReplaceHead = INVALID_LOCK_PROCNO, wakeupTail = INVALID_LOCK_PROCNO; + LWLockMode waitMode; +#ifdef LWLOCK_STATS + lwlock_stats *lwstats; + lwstats = get_lwlock_stats_entry(lock); +#endif PRINT_LWDEBUG("LWLockUpdateVar", lock, LW_EXCLUSIVE); @@ -1620,6 +1673,7 @@ LWLockUpdateVar(LWLock *lock, uint64 *valptr, uint64 val) * processes from release queue. */ + while (true) { uint64 newState = oldState; @@ -1703,6 +1757,7 @@ LWLockUpdateVar(LWLock *lock, uint64 *valptr, uint64 val) /* Remove LW_WAIT_UNTIL_FREE from the list head */ if (CurWaitMode(pgprocno) == LW_WAIT_UNTIL_FREE) { + waitMode = LW_WAIT_UNTIL_FREE; newHead = nextPgprocno; if (newHead == INVALID_LOCK_PROCNO) newTail = newHead; @@ -1718,6 +1773,7 @@ LWLockUpdateVar(LWLock *lock, uint64 *valptr, uint64 val) * At the tail part of a list there could be only LW_EXCLUSIVE * or LW_SHARED */ + waitMode = CurWaitMode(pgprocno); break; } @@ -1733,6 +1789,24 @@ LWLockUpdateVar(LWLock *lock, uint64 *valptr, uint64 val) { break; } + else + { +#ifdef LWLOCK_STATS + { + switch(waitMode) + { + case LW_EXCLUSIVE: + lwstats->rel_ex_cas_repeat++; + break; + case LW_SHARED: + lwstats->rel_sh_cas_repeat++; + break; + case LW_WAIT_UNTIL_FREE: + lwstats->rel_wuf_cas_repeat++; + } + } +#endif + } } /* Awaken any waiters removed from the queue. */ @@ -1760,6 +1834,10 @@ LWLockRelease(LWLock *lock) bool new_release_ok = true; bool wakeup = false; LWLockMode lastMode = LW_WAIT_UNTIL_FREE; +#ifdef LWLOCK_STATS + lwlock_stats *lwstats; + lwstats = get_lwlock_stats_entry(lock); +#endif /* * Remove lock from list of locks held. Usually, but not always, it will @@ -2021,6 +2099,22 @@ LWLockRelease(LWLock *lock) if (pg_atomic_compare_exchange_u64(&lock->state, &oldState, newState)) break; + else + { +#ifdef LWLOCK_STATS + switch(lastMode) + { + case LW_EXCLUSIVE: + lwstats->rel_ex_cas_repeat++; + break; + case LW_SHARED: + lwstats->rel_sh_cas_repeat++; + break; + case LW_WAIT_UNTIL_FREE: + lwstats->rel_wuf_cas_repeat++; + } +#endif + } } /* Awaken any waiters removed from the queue. */ -- 2.24.3 (Apple Git-128)