This patch adds functionality to see how long a posix lock is alive or is in waiting or pending state. It can be used to filter out interesting locks which are stuck in e.g. waiting state to know that a user space process probably has contention on it. The logging information will printout additional lock information to do more search and find to get more information about it's corosync or kernel communication. --- dlm_controld/plock.c | 48 ++++++++++++++++++++++++++++++-------------- 1 file changed, 33 insertions(+), 15 deletions(-)
diff --git a/dlm_controld/plock.c b/dlm_controld/plock.c index d83a79d2..20c2a1e9 100644 --- a/dlm_controld/plock.c +++ b/dlm_controld/plock.c @@ -72,6 +72,7 @@ struct resource { struct posix_lock { struct list_head list; /* resource locks or waiters list */ + struct timeval list_time; uint32_t pid; uint64_t owner; uint64_t start; @@ -83,6 +84,7 @@ struct posix_lock { struct lock_waiter { struct list_head list; + struct timeval list_time; uint32_t flags; struct dlm_plock_info info; }; @@ -209,9 +211,11 @@ static uint64_t dt_usec(const struct timeval *start, const struct timeval *stop) } static void plock_print_lock_add_state(const struct lockspace *ls, - const struct lock_waiter *w, + struct lock_waiter *w, const char *state) { + gettimeofday(&w->list_time, NULL); + log_dlock(ls, "state: add %s %llx %llx-%llx %d/%u/%llx", state, (unsigned long long)w->info.number, @@ -225,13 +229,20 @@ static void plock_print_lock_clear_state(const struct lockspace *ls, const struct lock_waiter *w, const char *state) { - log_dlock(ls, "state: clear %s %llx %llx-%llx %d/%u/%llx", + struct timeval now; + uint64_t usec; + + gettimeofday(&now, NULL); + usec = dt_usec(&w->list_time, &now); + + log_dlock(ls, "state: clear %s %llx %llx-%llx %d/%u/%llx %.3f", state, (unsigned long long)w->info.number, (unsigned long long)w->info.start, (unsigned long long)w->info.end, w->info.nodeid, w->info.pid, - (unsigned long long)w->info.owner); + (unsigned long long)w->info.owner, + usec * 1.e-6); } #define plock_print_add_waiter(ls, w) \ @@ -245,23 +256,30 @@ static void plock_print_lock_clear_state(const struct lockspace *ls, plock_print_lock_clear_state(ls, w, "pending") static void plock_print_add_plock(const struct lockspace *ls, - const struct posix_lock *plock) + struct posix_lock *po) { - log_dlock(ls, "state: add plock NA %llx-%llx %d/%u/%llx", - (unsigned long long)plock->start, - (unsigned long long)plock->end, - plock->nodeid, plock->pid, - (unsigned long long)plock->owner); + gettimeofday(&po->list_time, NULL); + log_dlock(ls, "state: add plock %llx-%llx %d/%u/%llx %.3f", + (unsigned long long)po->start, + (unsigned long long)po->end, + po->nodeid, po->pid, + (unsigned long long)po->owner); } static void plock_print_del_plock(const struct lockspace *ls, - const struct posix_lock *plock) + const struct posix_lock *po) { - log_dlock(ls, "state: del plock NA %llx-%llx %d/%u/%llx", - (unsigned long long)plock->start, - (unsigned long long)plock->end, - plock->nodeid, plock->pid, - (unsigned long long)plock->owner); + struct timeval now; + uint64_t usec; + + gettimeofday(&now, NULL); + usec = dt_usec(&po->list_time, &now); + log_dlock(ls, "state: clear plock %llx-%llx %d/%u/%llx %.3f", + (unsigned long long)po->start, + (unsigned long long)po->end, + po->nodeid, po->pid, + (unsigned long long)po->owner, + usec * 1.e-6); } static struct resource * rb_search_plock_resource(struct lockspace *ls, uint64_t number) -- 2.31.1