Messages in this thread Patch in this message | | | From | Mintu Patel <> | Subject | [PATCH v2] rt_spin_lock: To list the correct owner of rt_spin_lock | Date | Mon, 27 Jun 2022 21:41:38 +0530 |
| |
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@gmail.com> Signed-off-by: Chinmoy Ghosh <chinmoyghosh2001@gmail.com> Signed-off-by: Vishal Badole <badolevishal1116@gmail.com> Signed-off-by: Vimal Kumar <vimal.kumar32@gmail.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 + struct rt_mutex_waiter { struct rb_node tree_entry; struct rb_node pi_tree_entry; -- 2.25.1
| |