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

Reply via email to