Hi, On Mon, Jan 30, 2023 at 2:24 PM Alexander Aring <aahri...@redhat.com> wrote: > > 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",
removed "%.3f" for plock_print_add_plock(), it's only necessary for clear. We probably need to add some format(printf, 2, 3) gcc attribute to see such mistakes... - Alex