[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20231206173659.GA8874@Mahakal>
Date: Wed, 6 Dec 2023 23:07:00 +0530
From: "<Vishal Badole>" <badolevishal1116@...il.com>
To: peterz@...radead.org
Cc: Steven Rostedt <rostedt@...dmis.org>,
Mintu Patel <mintupatel89@...il.com>,
chinmoyghosh2001@...il.com, linux-kernel@...r.kernel.org,
mingo@...hat.com, peterz@...radead.org, vimal.kumar32@...il.com,
will@...nel.org
Subject: Re: [PATCH v2] rt_spin_lock: To list the correct owner of
rt_spin_lock
On Fri, Jul 08, 2022 at 04:21:58PM -0400, Steven Rostedt wrote:
> On Mon, 27 Jun 2022 21:41:38 +0530
> Mintu Patel <mintupatel89@...il.com> wrote:
>
> Hi Mintu,
>
> FYI, a v2 should never be a reply to the v1. It should always start its own
> thread, otherwise tooling and such will miss it.
>
> > rt_spin_lock is actually mutex on RT Kernel so it goes for contention
> > for lock. Currently owners of rt_spin_lock are decided before actual
> > acquiring of lock. This patch would depict the correct owner of
> > rt_spin_lock. The patch would help in solving crashes and deadlock
> > due to race condition of lock
> >
> > acquiring rt_spin_lock acquired the lock released the lock
> > <--------> <------->
> > contention period Held period
> >
> > Thread1 Thread2
> > _try_to_take_rt_mutex+0x95c+0x74 enqueue_task_dl+0x8cc/0x8dc
> > rt_spin_lock_slowlock_locked+0xac+2 rt_mutex_setprio+0x28c/0x574
> > rt_spin_lock_slowlock+0x5c/0x90 task_blocks_rt_mutex+0x240/0x310
> > rt_spin_lock+0x58/0x5c rt_spin_lock_slowlock_locked+0xac/0x2
> > driverA_acquire_lock+0x28/0x56 rt_spin_lock_slowlock+0x5c/0x90
> > rt_spin_lock+0x58/0x5c
> > driverB_acquire_lock+0x48/0x6c
> >
> > As per above call traces sample, Thread1 acquired the rt_spin_lock and
> > went to critical section on the other hand Thread2 kept trying to acquire
> > the same rt_spin_lock held by Thread1 ie contention period is too high.
> > Finally Thread2 entered to dl queue due to high held time of the lock by
> > Thread1. The below patch would help us to know the correct owner of
> > rt_spin_lock and point us the driver's critical section. Respective
> > driver need to be debugged for longer held period of lock.
> >
> > ex: cat /sys/kernel/debug/tracing/trace
> >
> > kworker/u13:0-150 [003] .....11 202.761025: rt_spinlock_acquire:
> > Process: kworker/u13:0 is acquiring lock: &kbdev->hwaccess_lock
> > kworker/u13:0-150 [003] .....11 202.761039: rt_spinlock_acquired:
> > Process: kworker/u13:0 has acquired lock: &kbdev->hwaccess_lock
> > kworker/u13:0-150 [003] .....11 202.761042: rt_spinlock_released:
> > Process: kworker/u13:0 has released lock: &kbdev->hwaccess_lock
> >
> > Signed-off-by: Mintu Patel <mintupatel89@...il.com>
> > Signed-off-by: Chinmoy Ghosh <chinmoyghosh2001@...il.com>
> > Signed-off-by: Vishal Badole <badolevishal1116@...il.com>
> > Signed-off-by: Vimal Kumar <vimal.kumar32@...il.com>
> > ---
> > include/trace/events/lock.h | 38 +++++++++++++++++++++++++++++++++
> > kernel/locking/rtmutex.c | 4 ++++
> > kernel/locking/rtmutex_common.h | 14 ++++++++++++
> > 3 files changed, 56 insertions(+)
> >
> > diff --git a/include/trace/events/lock.h b/include/trace/events/lock.h
> > index d7512129a324..0564474341c8 100644
> > --- a/include/trace/events/lock.h
> > +++ b/include/trace/events/lock.h
> > @@ -36,6 +36,44 @@ TRACE_EVENT(lock_acquire,
> > __get_str(name))
> > );
> >
> > +DECLARE_EVENT_CLASS(rt_lock_class,
> > +
> > + TP_PROTO(struct lockdep_map *lock, struct task_struct *pname),
> > +
> > + TP_ARGS(lock, pname),
> > +
> > + TP_STRUCT__entry(
> > + __string(name, lock->name)
> > + __string(process_name, pname->comm)
> > + ),
> > +
> > + TP_fast_assign(
> > + __assign_str(name, lock->name);
> > + __assign_str(process_name, pname->comm);
> > + ),
> > +
> > + TP_printk("Process: %s is acquiring lock: %s", __get_str(process_name),
> > + __get_str(name))
> > +);
> > +
> > +DEFINE_EVENT(rt_lock_class, rt_spinlock_acquire,
> > + TP_PROTO(struct lockdep_map *lock, struct task_struct *pname),
> > + TP_ARGS(lock, pname));
> > +
> > +DEFINE_EVENT_PRINT(rt_lock_class, rt_spinlock_acquired,
> > + TP_PROTO(struct lockdep_map *lock, struct task_struct *pname),
> > + TP_ARGS(lock, pname),
> > + TP_printk("Process: %s has acquired lock: %s", __get_str(process_name),
> > + __get_str(name))
> > + );
> > +
> > +DEFINE_EVENT_PRINT(rt_lock_class, rt_spinlock_released,
> > + TP_PROTO(struct lockdep_map *lock, struct task_struct *pname),
> > + TP_ARGS(lock, pname),
> > + TP_printk("Process: %s has released lock: %s", __get_str(process_name),
> > + __get_str(name))
> > + );
> > +
> > DECLARE_EVENT_CLASS(lock,
> >
> > TP_PROTO(struct lockdep_map *lock, unsigned long ip),
> > diff --git a/kernel/locking/rtmutex.c b/kernel/locking/rtmutex.c
> > index 602eb7821a1b..80ba2c0d7923 100644
> > --- a/kernel/locking/rtmutex.c
> > +++ b/kernel/locking/rtmutex.c
> > @@ -26,6 +26,7 @@
> > #include <linux/timer.h>
> > #include <linux/ww_mutex.h>
> > #include <linux/blkdev.h>
> > +#include <trace/events/lock.h>
> >
> > #include "rtmutex_common.h"
> >
> > @@ -1144,7 +1145,9 @@ void __lockfunc rt_spin_lock(spinlock_t *lock)
> > rcu_read_lock();
> > migrate_disable();
> > spin_acquire(&lock->dep_map, 0, 0, _RET_IP_);
> > + do_trace_rt_spinlock_acquire(lock, current);
> > rt_spin_lock_fastlock(&lock->lock, rt_spin_lock_slowlock);
> > + do_trace_rt_spinlock_acquired(lock, current);
> > }
> > EXPORT_SYMBOL(rt_spin_lock);
> >
> > @@ -1169,6 +1172,7 @@ void __lockfunc rt_spin_unlock(spinlock_t *lock)
> > {
> > /* NOTE: we always pass in '1' for nested, for simplicity */
> > spin_release(&lock->dep_map, 1, _RET_IP_);
> > + do_trace_rt_spinlock_released(lock, current);
> > rt_spin_lock_fastunlock(&lock->lock, rt_spin_lock_slowunlock);
> > migrate_enable();
> > rcu_read_unlock();
> > diff --git a/kernel/locking/rtmutex_common.h b/kernel/locking/rtmutex_common.h
> > index 546aaf058b9e..185ffc1e7015 100644
> > --- a/kernel/locking/rtmutex_common.h
> > +++ b/kernel/locking/rtmutex_common.h
> > @@ -25,6 +25,20 @@
> > * @pi_tree_entry: pi node to enqueue into the mutex owner waiters tree
> > * @task: task reference to the blocked task
> > */
> > +
> > +#ifdef CONFIG_RT_SPIN_LOCK_TRACING
> > +#define do_trace_rt_spinlock_acquire(lock, task) \
> > + trace_rt_spinlock_acquire(&lock->dep_map, task)
> > +#define do_trace_rt_spinlock_acquired(lock, task) \
> > + trace_rt_spinlock_acquired(&lock->dep_map, task)
> > +#define do_trace_rt_spinlock_released(lock, task) \
> > + trace_rt_spinlock_released(&lock->dep_map, task)
> > +#else
> > +#define do_trace_rt_spinlock_acquire(lock, task) do {} while(0)
> > +#define do_trace_rt_spinlock_acquired(lock, task) do {} while(0)
> > +#define do_trace_rt_spinlock_released(lock, task) do {} while(0)
> > +#endif
> > +
>
> Acked-by: Steven Rostedt (Google) <rostedt@...dmis.org>
>
> Although it will need to be accepted by Peter Zijlstra.
>
> -- Steve
>
>
> > struct rt_mutex_waiter {
> > struct rb_node tree_entry;
> > struct rb_node pi_tree_entry;
>
Hi Peter,
Could you please review this patch.
Regards,
Vishal Badole
Powered by blists - more mailing lists