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
