Skip to contentSkip to conversation

hung_task: extend blocking task stacktrace dump to rtmutex

PATCH Superseded ruipengqi 4 participants 7 messages Jul 30 – Aug 3

Subsystems (4)

v1 of 2 Superseded Latest is v2 →

lore
Share & tools
lore

ruipengqi

author
#0 lore raw

cover hung_task: extend blocking task stacktrace dump to rtmutex

From: Ruipeng Qi <[email protected]>

Currently, debug_show_blocker() only tracks mutex, semaphore and rwsem lock types. Extend it to also cover rtmutex or rt_mutex-based implementations locks on PREEMPT_RT, so that when a task is hung on an rtmutex, the hung task detector can identify and report which task holds the lock.

On 64-bit systems, lock pointers are 8-byte aligned, so their three least significant bits are always zero. Use these bits to encode the blocker type.

Unlike semaphores, rtmutex has built-in owner tracking via lock->owner, so no additional bookkeeping is needed. The owner can be read with rt_mutex_owner().

With this change, the hung task detector can now show blocker task's info like below:

[ 3000.899985] INFO: task cat:195 blocked for more than 120 seconds.
[ 3000.900561]       Not tainted 7.2.0-rc4-00366-gf339a6eb59f3-dirty #22
[ 3000.900930] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 3000.901376] task:cat             state:D stack:13784 pid:195   tgid:195   ppid:1      task_flags:0x400000 flags:0x00080000
[ 3000.902081] Call Trace:
[ 3000.902233]  <TASK>
[ 3000.902383]  __schedule+0x514/0xf50
[ 3000.902677]  rt_mutex_schedule+0x1b/0x30
[ 3000.902916]  rt_mutex_slowlock_block.constprop.0+0x3b/0x1c0
[ 3000.903242]  __rt_mutex_slowlock_locked.constprop.0+0xa8/0x200
[ 3000.903716]  rt_mutex_slowlock.constprop.0+0x48/0xb0
[ 3000.904023]  rt_mutex_lock+0x32/0x40
[ 3000.904249]  read_dummy_rtmutex+0x2a/0x60 [hung_task_tests]
[ 3000.904647]  full_proxy_read+0x5b/0x90
[ 3000.904843]  vfs_read+0xb0/0x370
[ 3000.905051]  ? vm_mmap_pgoff+0xf1/0x1b0
[ 3000.905293]  ? vm_mmap_pgoff+0x122/0x1b0
[ 3000.905684]  ksys_read+0x68/0xe0
[ 3000.905980]  do_syscall_64+0xf9/0x540
[ 3000.906213]  entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 3000.906643] RIP: 0033:0x49a182
[ 3000.906844] RSP: 002b:00007ffc431f6528 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 3000.907251] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000049a182
[ 3000.907673] RDX: 0000000000010000 RSI: 00007f69b2166000 RDI: 0000000000000003
[ 3000.908044] RBP: 00007f69b2166000 R08: 00000000ffffffff R09: 0000000000000000
[ 3000.908485] R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000010000
[ 3000.908816] R13: 0000000000000003 R14: 0000000000000001 R15: 0000000001000000
[ 3000.909206]  </TASK>
[ 3000.909351] INFO: task cat:195 is blocked on a rtmutex likely owned by task cat:194.
[ 3000.909832] task:cat             state:S stack:13784 pid:194   tgid:194   ppid:1      task_flags:0x400000 flags:0x00080000
[ 3000.910426] Call Trace:
[ 3000.910618]  <TASK>
[ 3000.910727]  __schedule+0x514/0xf50
[ 3000.910912]  schedule+0x22/0xa0
[ 3000.911064]  schedule_timeout+0x81/0x100
[ 3000.911254]  ? __pfx_process_timeout+0x10/0x10
[ 3000.911522]  msleep_interruptible+0x28/0x50
[ 3000.911754]  read_dummy_rtmutex+0x34/0x60 [hung_task_tests]
[ 3000.912019]  full_proxy_read+0x5b/0x90
[ 3000.912212]  vfs_read+0xb0/0x370
[ 3000.912378]  ? vm_mmap_pgoff+0xf1/0x1b0
[ 3000.912630]  ? vm_mmap_pgoff+0x122/0x1b0
[ 3000.912839]  ksys_read+0x68/0xe0
[ 3000.913007]  do_syscall_64+0xf9/0x540
[ 3000.913187]  entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 3000.913461] RIP: 0033:0x49a182
[ 3000.913618] RSP: 002b:00007ffd0b4cf048 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 3000.913972] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000049a182
[ 3000.914294] RDX: 0000000000010000 RSI: 00007fbf49a0d000 RDI: 0000000000000003
[ 3000.914648] RBP: 00007fbf49a0d000 R08: 00000000ffffffff R09: 0000000000000000
[ 3000.914955] R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000010000
[ 3000.915208] R13: 0000000000000003 R14: 0000000000000001 R15: 0000000001000000
[ 3000.915439]  </TASK>

Ruipeng Qi (2):
hung_task: show the blocker task if the task is hung on rtmutex
samples: enhance hung_task detector test with rtmutex support

 include/linux/hung_task.h           | 31 +++++++++++++-----
 kernel/hung_task.c                  | 22 +++++++++++++
 kernel/locking/mutex.c              |  4 +--
 kernel/locking/rtmutex.c            | 13 ++++++++
 kernel/locking/rwsem.c              |  8 ++---
 kernel/locking/semaphore.c          |  4 +--
 lib/Kconfig.debug                   |  1 -
 samples/Kconfig                     |  2 +-
 samples/hung_task/hung_task_tests.c | 50 ++++++++++++++++++++++++++---
 9 files changed, 113 insertions(+), 22 deletions(-)
Signature · 1 line
2.25.1
author
#1 lore raw

PATCH 1/2 hung_task: show the blocker task if the task is hung on rtmutex

From: Ruipeng Qi <[email protected]>

Currently, debug_show_blocker() only tracks mutex, semaphore and rwsem lock types. Extend it to also cover rtmutex or rt_mutex-based implementations locks on PREEMPT_RT, so that when a task is hung on an rtmutex, the hung task detector can identify and report which task holds the lock.

On 64-bit systems, lock pointers are 8-byte aligned, so their three least significant bits are always zero. Use these bits to encode the blocker type.

Unlike semaphores, rtmutex has built-in owner tracking via lock->owner, so no additional bookkeeping is needed. The owner can be read with rt_mutex_owner().

With this change, the hung task detector can now show blocker task's info like below:

[ 3000.899985] INFO: task cat:195 blocked for more than 120 seconds.
[ 3000.900561]       Not tainted 7.2.0-rc4-00366-gf339a6eb59f3-dirty #22
[ 3000.900930] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 3000.901376] task:cat             state:D stack:13784 pid:195   tgid:195   ppid:1      task_flags:0x400000 flags:0x00080000
[ 3000.902081] Call Trace:
[ 3000.902233]  <TASK>
[ 3000.902383]  __schedule+0x514/0xf50
[ 3000.902677]  rt_mutex_schedule+0x1b/0x30
[ 3000.902916]  rt_mutex_slowlock_block.constprop.0+0x3b/0x1c0
[ 3000.903242]  __rt_mutex_slowlock_locked.constprop.0+0xa8/0x200
[ 3000.903716]  rt_mutex_slowlock.constprop.0+0x48/0xb0
[ 3000.904023]  rt_mutex_lock+0x32/0x40
[ 3000.904249]  read_dummy_rtmutex+0x2a/0x60 [hung_task_tests]
[ 3000.904647]  full_proxy_read+0x5b/0x90
[ 3000.904843]  vfs_read+0xb0/0x370
[ 3000.905051]  ? vm_mmap_pgoff+0xf1/0x1b0
[ 3000.905293]  ? vm_mmap_pgoff+0x122/0x1b0
[ 3000.905684]  ksys_read+0x68/0xe0
[ 3000.905980]  do_syscall_64+0xf9/0x540
[ 3000.906213]  entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 3000.906643] RIP: 0033:0x49a182
[ 3000.906844] RSP: 002b:00007ffc431f6528 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 3000.907251] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000049a182
[ 3000.907673] RDX: 0000000000010000 RSI: 00007f69b2166000 RDI: 0000000000000003
[ 3000.908044] RBP: 00007f69b2166000 R08: 00000000ffffffff R09: 0000000000000000
[ 3000.908485] R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000010000
[ 3000.908816] R13: 0000000000000003 R14: 0000000000000001 R15: 0000000001000000
[ 3000.909206]  </TASK>
[ 3000.909351] INFO: task cat:195 is blocked on a rtmutex likely owned by task cat:194.
[ 3000.909832] task:cat             state:S stack:13784 pid:194   tgid:194   ppid:1      task_flags:0x400000 flags:0x00080000
[ 3000.910426] Call Trace:
[ 3000.910618]  <TASK>
[ 3000.910727]  __schedule+0x514/0xf50
[ 3000.910912]  schedule+0x22/0xa0
[ 3000.911064]  schedule_timeout+0x81/0x100
[ 3000.911254]  ? __pfx_process_timeout+0x10/0x10
[ 3000.911522]  msleep_interruptible+0x28/0x50
[ 3000.911754]  read_dummy_rtmutex+0x34/0x60 [hung_task_tests]
[ 3000.912019]  full_proxy_read+0x5b/0x90
[ 3000.912212]  vfs_read+0xb0/0x370
[ 3000.912378]  ? vm_mmap_pgoff+0xf1/0x1b0
[ 3000.912630]  ? vm_mmap_pgoff+0x122/0x1b0
[ 3000.912839]  ksys_read+0x68/0xe0
[ 3000.913007]  do_syscall_64+0xf9/0x540
[ 3000.913187]  entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 3000.913461] RIP: 0033:0x49a182
[ 3000.913618] RSP: 002b:00007ffd0b4cf048 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 3000.913972] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000049a182
[ 3000.914294] RDX: 0000000000010000 RSI: 00007fbf49a0d000 RDI: 0000000000000003
[ 3000.914648] RBP: 00007fbf49a0d000 R08: 00000000ffffffff R09: 0000000000000000
[ 3000.914955] R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000010000
[ 3000.915208] R13: 0000000000000003 R14: 0000000000000001 R15: 0000000001000000
[ 3000.915439]  </TASK>
---
 include/linux/hung_task.h  | 31 +++++++++++++++++++++++--------
 kernel/hung_task.c         | 22 ++++++++++++++++++++++
 kernel/locking/mutex.c     |  4 ++--
 kernel/locking/rtmutex.c   | 13 +++++++++++++
 kernel/locking/rwsem.c     |  8 ++++----
 kernel/locking/semaphore.c |  4 ++--
 lib/Kconfig.debug          |  1 -
 7 files changed, 66 insertions(+), 17 deletions(-)
include/linux/hung_task.h +23 -8
index c4403eeb714424..1bec5fae6dbddb 100644
@@ -16,7 +16,7 @@
  * @blocker: Combines lock address and blocking type.
  *
  * Since lock pointers are at least 4-byte aligned(32-bit) or 8-byte
- * aligned(64-bit). This leaves the 2 least bits (LSBs) of the pointer
+ * aligned(64-bit). This leaves the 2/3 least bits (LSBs) of the pointer
  * always zero. So we can use these bits to encode the specific blocking
  * type.
  *
@@ -29,21 +29,28 @@
  * 01 - Blocked on semaphore			(BLOCKER_TYPE_SEM)
  * 10 - Blocked on rw-semaphore as READER	(BLOCKER_TYPE_RWSEM_READER)
  * 11 - Blocked on rw-semaphore as WRITER	(BLOCKER_TYPE_RWSEM_WRITER)
+ * 100 - Blocked on rtmutex			(BLOCKER_TYPE_RTMUTEX if pointer is 8-byte aligned)
  */
 #define BLOCKER_TYPE_MUTEX		0x00UL
 #define BLOCKER_TYPE_SEM		0x01UL
 #define BLOCKER_TYPE_RWSEM_READER	0x02UL
 #define BLOCKER_TYPE_RWSEM_WRITER	0x03UL
 
+#ifdef CONFIG_64BIT
+#define BLOCKER_TYPE_RTMUTEX		0x04UL
+#define BLOCKER_TYPE_MASK		0x07UL
+#else
 #define BLOCKER_TYPE_MASK		0x03UL
+#endif
 
 #ifdef CONFIG_DETECT_HUNG_TASK_BLOCKER
-static inline void hung_task_set_blocker(void *lock, unsigned long type)
+static inline void hung_task_set_blocker(struct task_struct *task, void *lock,
+					 unsigned long type)
 {
 	unsigned long lock_ptr = (unsigned long)lock;
 
 	WARN_ON_ONCE(!lock_ptr);
-	WARN_ON_ONCE(READ_ONCE(current->blocker));
+	WARN_ON_ONCE(READ_ONCE(task->blocker));
 
 	/*
 	 * If the lock pointer matches the BLOCKER_TYPE_MASK, return
@@ -52,12 +59,12 @@ static inline void hung_task_set_blocker(void *lock, unsigned long type)
 	if (lock_ptr & BLOCKER_TYPE_MASK)
 		return;
 
-	WRITE_ONCE(current->blocker, lock_ptr | type);
+	WRITE_ONCE(task->blocker, lock_ptr | type);
 }
 
-static inline void hung_task_clear_blocker(void)
+static inline void hung_task_clear_blocker(struct task_struct *task)
 {
-	WRITE_ONCE(current->blocker, 0UL);
+	WRITE_ONCE(task->blocker, 0UL);
 }
 
 /*
@@ -81,11 +88,15 @@ static inline void *hung_task_blocker_to_lock(unsigned long blocker)
 
 	return (void *)(blocker & ~BLOCKER_TYPE_MASK);
 }
+extern void debug_trace_blocker(struct task_struct *task,
+				unsigned long timeout, bool iter);
 #else
-static inline void hung_task_set_blocker(void *lock, unsigned long type)
+static inline void hung_task_set_blocker(struct task_struct *task, void *lock,
+					 unsigned long type)
 {
 }
-static inline void hung_task_clear_blocker(void)
+
+static inline void hung_task_clear_blocker(struct task_struct *task)
 {
 }
 static inline unsigned long hung_task_get_blocker_type(unsigned long blocker)
@@ -96,6 +107,10 @@ static inline void *hung_task_blocker_to_lock(unsigned long blocker)
 {
 	return NULL;
 }
+static inline void debug_trace_blocker(struct task_struct *task,
+				       unsigned long timeout, bool iter)
+{
+}
 #endif
 
 #endif /* __LINUX_HUNG_TASK_H */
kernel/hung_task.c +22 -0
index 6fcc94ce4ca9d2..0ccaac6041d925 100644
@@ -27,6 +27,7 @@
 #include <linux/sys_info.h>
 
 #include <trace/events/sched.h>
+#include <linux/rtmutex.h>
 
 /*
  * The number of tasks checked:
@@ -149,12 +150,15 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
 	blocker_type = hung_task_get_blocker_type(blocker);
 
 	switch (blocker_type) {
+#ifndef CONFIG_PREEMPT_RT
 	case BLOCKER_TYPE_MUTEX:
 		owner = mutex_get_owner(hung_task_blocker_to_lock(blocker));
 		break;
+#endif
 	case BLOCKER_TYPE_SEM:
 		owner = sem_last_holder(hung_task_blocker_to_lock(blocker));
 		break;
+#ifndef CONFIG_PREEMPT_RT
 	case BLOCKER_TYPE_RWSEM_READER:
 	case BLOCKER_TYPE_RWSEM_WRITER:
 		owner = (unsigned long)rwsem_owner(
@@ -165,6 +169,12 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
 					hung_task_blocker_to_lock(blocker)) ?
 					"reader" : "writer";
 		break;
+#endif
+#if defined(CONFIG_64BIT) && defined(CONFIG_RT_MUTEXES)
+	case BLOCKER_TYPE_RTMUTEX:
+		owner = (unsigned long)rt_mutex_owner(hung_task_blocker_to_lock(blocker));
+		break;
+#endif
 	default:
 		WARN_ON_ONCE(1);
 		return;
@@ -186,6 +196,12 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
 			pr_err("INFO: task %s:%d is blocked on an rw-semaphore, but the owner is not found.\n",
 			       task->comm, task->pid);
 			break;
+#if defined(CONFIG_64BIT) && defined(CONFIG_RT_MUTEXES)
+		case BLOCKER_TYPE_RTMUTEX:
+			pr_err("INFO: task %s:%d is blocked on a rtmutex, but the owner is not found.\n",
+			       task->comm, task->pid);
+			break;
+#endif
 		}
 		return;
 	}
@@ -210,6 +226,12 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
 			       task->comm, task->pid, rwsem_blocked_as, t->comm,
 			       t->pid, rwsem_blocked_by);
 			break;
+#if defined(CONFIG_64BIT) && defined(CONFIG_RT_MUTEXES)
+		case BLOCKER_TYPE_RTMUTEX:
+			pr_err("INFO: task %s:%d is blocked on a rtmutex likely owned by task %s:%d.\n",
+			       task->comm, task->pid, t->comm, t->pid);
+			break;
+#endif
 		}
 		/* Avoid duplicated task dump, skip if the task is also hung. */
 		if (!task_is_hung(t, timeout))
kernel/locking/mutex.c +2 -2
index 8a85912d7ee6ce..90b364b2ad5d73 100644
@@ -211,7 +211,7 @@ __mutex_add_waiter(struct mutex *lock, struct mutex_waiter *waiter,
 {
 	struct mutex_waiter *first = lock->first_waiter;
 
-	hung_task_set_blocker(lock, BLOCKER_TYPE_MUTEX);
+	hung_task_set_blocker(current, lock, BLOCKER_TYPE_MUTEX);
 	debug_mutex_add_waiter(lock, waiter, current);
 
 	if (pos) {
@@ -251,7 +251,7 @@ __mutex_remove_waiter(struct mutex *lock, struct mutex_waiter *waiter)
 	}
 
 	debug_mutex_remove_waiter(lock, waiter, current);
-	hung_task_clear_blocker();
+	hung_task_clear_blocker(current);
 }
 
 /*
kernel/locking/rtmutex.c +13 -0
index 4728631ae71940..74aec0773846bf 100644
@@ -23,6 +23,7 @@
 #include <linux/sched/rt.h>
 #include <linux/sched/wake_q.h>
 #include <linux/ww_mutex.h>
+#include <linux/hung_task.h>
 
 #include <trace/events/lock.h>
 
@@ -1183,6 +1184,9 @@ try_to_take_rt_mutex(struct rt_mutex_base *lock, struct task_struct *task,
 	 */
 	raw_spin_lock(&task->pi_lock);
 	task->pi_blocked_on = NULL;
+#if defined(CONFIG_64BIT)
+	hung_task_clear_blocker(task);
+#endif
 	/*
 	 * Finish the lock acquisition. @task is the new owner. If
 	 * other waiters exist we have to insert the highest priority
@@ -1251,6 +1255,9 @@ static int __sched task_blocks_on_rt_mutex(struct rt_mutex_base *lock,
 	rt_mutex_enqueue(lock, waiter);
 
 	task->pi_blocked_on = waiter;
+#if defined(CONFIG_64BIT)
+	hung_task_set_blocker(task, lock, BLOCKER_TYPE_RTMUTEX);
+#endif
 
 	raw_spin_unlock(&task->pi_lock);
 
@@ -1265,6 +1272,9 @@ static int __sched task_blocks_on_rt_mutex(struct rt_mutex_base *lock,
 			raw_spin_lock(&task->pi_lock);
 			rt_mutex_dequeue(lock, waiter);
 			task->pi_blocked_on = NULL;
+#if defined(CONFIG_64BIT)
+			hung_task_clear_blocker(task);
+#endif
 			raw_spin_unlock(&task->pi_lock);
 			return res;
 		}
@@ -1569,6 +1579,9 @@ static void __sched remove_waiter(struct rt_mutex_base *lock,
 	scoped_guard(raw_spinlock, &waiter_task->pi_lock) {
 		rt_mutex_dequeue(lock, waiter);
 		waiter_task->pi_blocked_on = NULL;
+#if defined(CONFIG_64BIT)
+		hung_task_clear_blocker(waiter_task);
+#endif
 	}
 
 	/*
kernel/locking/rwsem.c +4 -4
index b9c180ac1eee7a..9674e46f6dadd1 100644
@@ -1095,7 +1095,7 @@ rwsem_down_read_slowpath(struct rw_semaphore *sem, long count, unsigned int stat
 	set_current_state(state);
 
 	if (state == TASK_UNINTERRUPTIBLE)
-		hung_task_set_blocker(sem, BLOCKER_TYPE_RWSEM_READER);
+		hung_task_set_blocker(current, sem, BLOCKER_TYPE_RWSEM_READER);
 
 	/* wait to be given the lock */
 	for (;;) {
@@ -1117,7 +1117,7 @@ rwsem_down_read_slowpath(struct rw_semaphore *sem, long count, unsigned int stat
 	}
 
 	if (state == TASK_UNINTERRUPTIBLE)
-		hung_task_clear_blocker();
+		hung_task_clear_blocker(current);
 
 	__set_current_state(TASK_RUNNING);
 	lockevent_inc(rwsem_rlock);
@@ -1183,7 +1183,7 @@ rwsem_down_write_slowpath(struct rw_semaphore *sem, int state)
 	trace_contention_begin(sem, LCB_F_WRITE);
 
 	if (state == TASK_UNINTERRUPTIBLE)
-		hung_task_set_blocker(sem, BLOCKER_TYPE_RWSEM_WRITER);
+		hung_task_set_blocker(current, sem, BLOCKER_TYPE_RWSEM_WRITER);
 
 	for (;;) {
 		if (rwsem_try_write_lock(sem, &waiter)) {
@@ -1220,7 +1220,7 @@ rwsem_down_write_slowpath(struct rw_semaphore *sem, int state)
 	}
 
 	if (state == TASK_UNINTERRUPTIBLE)
-		hung_task_clear_blocker();
+		hung_task_clear_blocker(current);
 
 	__set_current_state(TASK_RUNNING);
 	raw_spin_unlock_irq(&sem->wait_lock);
kernel/locking/semaphore.c +2 -2
index 233730c2593308..c53e0753f933c1 100644
@@ -312,13 +312,13 @@ static inline int __sched __down_common(struct semaphore *sem, long state,
 {
 	int ret;
 
-	hung_task_set_blocker(sem, BLOCKER_TYPE_SEM);
+	hung_task_set_blocker(current, sem, BLOCKER_TYPE_SEM);
 
 	trace_contention_begin(sem, 0);
 	ret = ___down_common(sem, state, timeout);
 	trace_contention_end(sem, ret);
 
-	hung_task_clear_blocker();
+	hung_task_clear_blocker(current);
 
 	return ret;
 }
lib/Kconfig.debug +0 -1
index 1244dcac2294ad..92dff380027e78 100644
@@ -1317,7 +1317,6 @@ config BOOTPARAM_HUNG_TASK_PANIC
 config DETECT_HUNG_TASK_BLOCKER
 	bool "Dump Hung Tasks Blocker"
 	depends on DETECT_HUNG_TASK
-	depends on !PREEMPT_RT
 	default y
 	help
 	  Say Y here to show the blocker task's stacktrace who acquires
Signature · 1 line
2.25.1
#2 lore raw

Re: [PATCH 1/2] hung_task: show the blocker task if the task is hung on rtmutex

From: Zhan Xusheng <[email protected]>

Hi Ruipeng,

Nice extension. I traced the set/clear pairing and it looks sound: the blocker is set/cleared alongside every task->pi_blocked_on assignment (all three pi_blocked_on = NULL sites clear it), so there is no stale blocker left behind. Gating the mutex/rwsem cases in debug_show_blocker() under !CONFIG_PREEMPT_RT also matches that their setters (and mutex_get_owner()/ rwsem_owner()) only exist on !RT, while BLOCKER_TYPE_SEM is correctly kept since semaphores stay counting on RT. A few comments:

Quoted 2 lines
include/linux/hung_task.h +2 -0
+extern void debug_trace_blocker(struct task_struct *task,
+	       unsigned long timeout, bool iter);

[...]

include/linux/hung_task.h static inline void *hung_task_blocker_to_lock(unsigned long blocker) · line 113

Quoted 4 lines
include/linux/hung_task.h +4 -0
+static inline void debug_trace_blocker(struct task_struct *task,
+	      unsigned long timeout, bool iter)
+{
+}

debug_trace_blocker() seems to be only declared (and stubbed) here - I can't find any definition or caller in the series or in-tree. Is it a leftover from a larger WIP that should be dropped?

Quoted 6 lines
include/linux/hung_task.h +4 -0
+#ifdef CONFIG_64BIT
+#define BLOCKER_TYPE_RTMUTEX		0x04UL
+#define BLOCKER_TYPE_MASK		0x07UL
+#else

#define BLOCKER_TYPE_MASK 0x03UL
+#endif

Since the 3rd bit is only available on 64-bit, rtmutex blocker tracking is effectively 64-bit only (on 32-bit the two low bits are already taken by mutex/sem/rwsem-r/w). Could the changelog state that explicitly? Also, on PREEMPT_RT spinlock_t/rwlock_t/mutex/rwsem are all rtmutex-based, so this effectively reports every rtmutex-based sleeping-lock wait, not only rt_mutex_lock() - a word about that would keep the "blocked on a rtmutex" line from being surprising for what was a mutex/spinlock at the source level.

kernel/locking/rtmutex.c static int __sched task_blocks_on_rt_mutex(struct rt_mutex_base *lock, · line 1260

Quoted 3 lines
kernel/locking/rtmutex.c +3 -0
+#if defined(CONFIG_64BIT)
+	hung_task_set_blocker(task, lock, BLOCKER_TYPE_RTMUTEX);
+#endif

(and the three matching clear sites)

Would it be cleaner to hide the CONFIG_64BIT-ness inside the hung_task helpers - e.g. a no-op rtmutex set/clear on 32-bit - so rtmutex.c doesn't need the scattered #if at each call site?

Thanks,
Zhan Xusheng

reviewer
#3 lore raw

Re: [PATCH 1/2] hung_task: show the blocker task if the task is hung on rtmutex

In reply to ruipengqi
Quoted 45 lines · ruipengqi

From: Ruipeng Qi <[email protected]>

Currently, debug_show_blocker() only tracks mutex, semaphore and rwsem lock types. Extend it to also cover rtmutex or rt_mutex-based implementations locks on PREEMPT_RT, so that when a task is hung on an rtmutex, the hung task detector can identify and report which task holds the lock.

On 64-bit systems, lock pointers are 8-byte aligned, so their three least significant bits are always zero. Use these bits to encode the blocker type.

Unlike semaphores, rtmutex has built-in owner tracking via lock->owner, so no additional bookkeeping is needed. The owner can be read with rt_mutex_owner().

kernel/hung_task.c +4 -0
@@ -27,6 +27,7 @@
 #include <linux/sys_info.h>
 
 #include <trace/events/sched.h>
+#include <linux/rtmutex.h>
 
 /*
  * The number of tasks checked:
@@ -149,12 +150,15 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
 	blocker_type = hung_task_get_blocker_type(blocker);
 
 	switch (blocker_type) {
+#ifndef CONFIG_PREEMPT_RT
 	case BLOCKER_TYPE_MUTEX:
 		owner = mutex_get_owner(hung_task_blocker_to_lock(blocker));
 		break;
+#endif
 	case BLOCKER_TYPE_SEM:
 		owner = sem_last_holder(hung_task_blocker_to_lock(blocker));
 		break;
+#ifndef CONFIG_PREEMPT_RT
 	case BLOCKER_TYPE_RWSEM_READER:
 	case BLOCKER_TYPE_RWSEM_WRITER:
 		owner = (unsigned long)rwsem_owner(
@@ -165,6 +169,12 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
 					hung_task_blocker_to_lock(blocker)) ?
 					"reader" : "writer";

kernel/hung_task.c static void debug_show_blocker(struct task_struct *task, unsigned long timeout) · line 180

Quoted 10 lines
kernel/hung_task.c +6 -0
 		break;
+#endif
+#if defined(CONFIG_64BIT) && defined(CONFIG_RT_MUTEXES)
+	case BLOCKER_TYPE_RTMUTEX:
+		owner = (unsigned long)rt_mutex_owner(hung_task_blocker_to_lock(blocker));
+		break;
+#endif
 	default:
 		WARN_ON_ONCE(1);
 		return;

On one hand, it is "elegant" to handle rtmutex the same way as the other locks.

On the other hand, this adds a lot of if-deffery and does not work on 32-bit systems.

Alternative solution would use the existing tracking, something like:

	if (rt_mutext_blocking_task(task))
		owner = (unsigned long)rt_mutex_owner(rt_mutex_blocking_task(task));

, where rt_mutex_blocking_task() would be a racy public variant of the existing task_blocked_on_lock(). Something like:

static inline struct rt_mutex_base *rt_mutex_blocking_task(struct task_struct *p)

{
	struct rt_mutex_waiter *waiter;

	waiter = data_race(READ_ONCE(p->pi_blocked_on)

	if (waiter)
		return data_race(READ_ONCE(waiter->lock);

	return NULL;
}

Plus, it would require using WRITE_ONCE() when task->pi_blocked_on is updated to make sure that the value is always consistent (valid pointer or NULL).

It would avoid the duplicate tracking in the rt_mutex code and might be more acceptable for the rt_mutex maintainers.

Best Regards,
Petr

author
#4 lore raw

Re: [PATCH 1/2] hung_task: show the blocker task if the task is hung on rtmutex

Quoted 72 lines · Petr Mladek
Quoted 45 lines · ruipengqi

From: Ruipeng Qi <[email protected]>

Currently, debug_show_blocker() only tracks mutex, semaphore and rwsem lock types. Extend it to also cover rtmutex or rt_mutex-based implementations locks on PREEMPT_RT, so that when a task is hung on an rtmutex, the hung task detector can identify and report which task holds the lock.

On 64-bit systems, lock pointers are 8-byte aligned, so their three least significant bits are always zero. Use these bits to encode the blocker type.

Unlike semaphores, rtmutex has built-in owner tracking via lock->owner, so no additional bookkeeping is needed. The owner can be read with rt_mutex_owner().

kernel/hung_task.c +4 -0
@@ -27,6 +27,7 @@
  #include <linux/sys_info.h>
 
  #include <trace/events/sched.h>
+#include <linux/rtmutex.h>
 
  /*
   * The number of tasks checked:
@@ -149,12 +150,15 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
  	blocker_type = hung_task_get_blocker_type(blocker);
 
  	switch (blocker_type) {
+#ifndef CONFIG_PREEMPT_RT
  	case BLOCKER_TYPE_MUTEX:
  		owner = mutex_get_owner(hung_task_blocker_to_lock(blocker));
  		break;
+#endif
  	case BLOCKER_TYPE_SEM:
  		owner = sem_last_holder(hung_task_blocker_to_lock(blocker));
  		break;
+#ifndef CONFIG_PREEMPT_RT
  	case BLOCKER_TYPE_RWSEM_READER:
  	case BLOCKER_TYPE_RWSEM_WRITER:
  		owner = (unsigned long)rwsem_owner(
@@ -165,6 +169,12 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
  					hung_task_blocker_to_lock(blocker)) ?
  					"reader" : "writer";

kernel/hung_task.c static void debug_show_blocker(struct task_struct *task, unsigned long timeout) · line 180

Quoted 10 lines
kernel/hung_task.c +6 -0
  		break;
+#endif
+#if defined(CONFIG_64BIT) && defined(CONFIG_RT_MUTEXES)
+	case BLOCKER_TYPE_RTMUTEX:
+		owner = (unsigned long)rt_mutex_owner(hung_task_blocker_to_lock(blocker));
+		break;
+#endif
  	default:
  		WARN_ON_ONCE(1);
  		return;

On one hand, it is "elegant" to handle rtmutex the same way as the other locks.

On the other hand, this adds a lot of if-deffery and does not work on 32-bit systems.

Alternative solution would use the existing tracking, something like:

	if (rt_mutext_blocking_task(task))
		owner = (unsigned long)rt_mutex_owner(rt_mutex_blocking_task(task));

, where rt_mutex_blocking_task() would be a racy public variant of the existing task_blocked_on_lock(). Something like:

static inline struct rt_mutex_base *rt_mutex_blocking_task(struct task_struct *p)

Quoted 10 lines
{
	struct rt_mutex_waiter *waiter;

	waiter = data_race(READ_ONCE(p->pi_blocked_on)

	if (waiter)
		return data_race(READ_ONCE(waiter->lock);

	return NULL;
}

Thanks to Petr, Lance, and Xusheng for the feedback.

One concern with the alternative approach is that 'waiter' is typically allocated on the stack (for instance, in __rt_mutex_slowlock_locked()). If the blocked task gets woken up and resumes execution, its stack frame is destroyed and the 'waiter' structure becomes invalid.

Since the hung task detector reads p->pi_blocked_on asynchronously without holding the lock, dereferencing waiter->lock could lead to a UAF race condition if the waiter is destroyed concurrently. Therefore, the first solution (encoding the blocker type in the pointer bits) seems safer, as it avoids dereferencing a potentially stale stack pointer.

I am currently preparing the V2 patch to address the issues you mentioned.

v2 changes:
 - Reduce #ifdef-deffery.
 - Remove the unused function debug_trace_blocker.
 - Clean up and update relevant comments.

Best regards,
Ruipeng

Quoted 9 lines

Plus, it would require using WRITE_ONCE() when task->pi_blocked_on is updated to make sure that the value is always consistent (valid pointer or NULL).

It would avoid the duplicate tracking in the rt_mutex code and might be more acceptable for the rt_mutex maintainers.

Best Regards,
Petr

author
#5 lore raw

PATCH 2/2 samples: enhance hung_task detector test with rtmutex support

In reply to ruipengqi

From: Ruipeng Qi <[email protected]>

Extend the hung_task detector test module with an rtmutex test. When CONFIG_RT_MUTEXES is enabled, the module creates an additional "rtmutex" debugfs file under <debugfs>/hung_task. Concurrent reads hold and contend on an rtmutex for 256 seconds, allowing hung-task and blocker reporting to be tested for rtmutex waits.

Usage is:

> cd /sys/kernel/debug/hung_task
> cat rtmutex & cat rtmutex

Update the module usage comments and Kconfig description to document the rtmutex debugfs file.

---
 samples/Kconfig                     |  2 +-
 samples/hung_task/hung_task_tests.c | 50 ++++++++++++++++++++++++++---
 2 files changed, 47 insertions(+), 5 deletions(-)
samples/Kconfig +1 -1
index a75e8e78330da5..11096dbc43413f 100644
@@ -318,7 +318,7 @@ config SAMPLE_HUNG_TASK
 	depends on DETECT_HUNG_TASK && DEBUG_FS
 	help
 	  Build a module that provides debugfs files (e.g., mutex, semaphore,
-	  rw_semaphore_read, rw_semaphore_write) under <debugfs>/hung_task.
+	  rw_semaphore_read, rw_semaphore_write, rtmutex) under <debugfs>/hung_task.
 	  Reading these files with multiple processes triggers hung task
 	  detection by holding locks for a long time (256 seconds).
 
samples/hung_task/hung_task_tests.c +46 -4

97 lines not on this page · raw message

Signature · 1 line
2.25.1
maintainer
#6 lore raw
In reply to ruipengqi

Afraid Peter may still strongly object to this whole approach:

https://lore.kernel.org/lkml/[email protected]/

Emm ... did you reach out to Peter privately, hash this out off-list, and get his okay to extend it to rtmutex?

Cheers, Lance

Quoted 88 lines · ruipengqi

From: Ruipeng Qi <[email protected]>

Currently, debug_show_blocker() only tracks mutex, semaphore and rwsem lock types. Extend it to also cover rtmutex or rt_mutex-based implementations locks on PREEMPT_RT, so that when a task is hung on an rtmutex, the hung task detector can identify and report which task holds the lock.

On 64-bit systems, lock pointers are 8-byte aligned, so their three least significant bits are always zero. Use these bits to encode the blocker type.

Unlike semaphores, rtmutex has built-in owner tracking via lock->owner, so no additional bookkeeping is needed. The owner can be read with rt_mutex_owner().

With this change, the hung task detector can now show blocker task's info like below:

[ 3000.899985] INFO: task cat:195 blocked for more than 120 seconds.
[ 3000.900561]       Not tainted 7.2.0-rc4-00366-gf339a6eb59f3-dirty #22
[ 3000.900930] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 3000.901376] task:cat             state:D stack:13784 pid:195   tgid:195   ppid:1      task_flags:0x400000 flags:0x00080000
[ 3000.902081] Call Trace:
[ 3000.902233]  <TASK>
[ 3000.902383]  __schedule+0x514/0xf50
[ 3000.902677]  rt_mutex_schedule+0x1b/0x30
[ 3000.902916]  rt_mutex_slowlock_block.constprop.0+0x3b/0x1c0
[ 3000.903242]  __rt_mutex_slowlock_locked.constprop.0+0xa8/0x200
[ 3000.903716]  rt_mutex_slowlock.constprop.0+0x48/0xb0
[ 3000.904023]  rt_mutex_lock+0x32/0x40
[ 3000.904249]  read_dummy_rtmutex+0x2a/0x60 [hung_task_tests]
[ 3000.904647]  full_proxy_read+0x5b/0x90
[ 3000.904843]  vfs_read+0xb0/0x370
[ 3000.905051]  ? vm_mmap_pgoff+0xf1/0x1b0
[ 3000.905293]  ? vm_mmap_pgoff+0x122/0x1b0
[ 3000.905684]  ksys_read+0x68/0xe0
[ 3000.905980]  do_syscall_64+0xf9/0x540
[ 3000.906213]  entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 3000.906643] RIP: 0033:0x49a182
[ 3000.906844] RSP: 002b:00007ffc431f6528 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 3000.907251] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000049a182
[ 3000.907673] RDX: 0000000000010000 RSI: 00007f69b2166000 RDI: 0000000000000003
[ 3000.908044] RBP: 00007f69b2166000 R08: 00000000ffffffff R09: 0000000000000000
[ 3000.908485] R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000010000
[ 3000.908816] R13: 0000000000000003 R14: 0000000000000001 R15: 0000000001000000
[ 3000.909206]  </TASK>
[ 3000.909351] INFO: task cat:195 is blocked on a rtmutex likely owned by task cat:194.
[ 3000.909832] task:cat             state:S stack:13784 pid:194   tgid:194   ppid:1      task_flags:0x400000 flags:0x00080000
[ 3000.910426] Call Trace:
[ 3000.910618]  <TASK>
[ 3000.910727]  __schedule+0x514/0xf50
[ 3000.910912]  schedule+0x22/0xa0
[ 3000.911064]  schedule_timeout+0x81/0x100
[ 3000.911254]  ? __pfx_process_timeout+0x10/0x10
[ 3000.911522]  msleep_interruptible+0x28/0x50
[ 3000.911754]  read_dummy_rtmutex+0x34/0x60 [hung_task_tests]
[ 3000.912019]  full_proxy_read+0x5b/0x90
[ 3000.912212]  vfs_read+0xb0/0x370
[ 3000.912378]  ? vm_mmap_pgoff+0xf1/0x1b0
[ 3000.912630]  ? vm_mmap_pgoff+0x122/0x1b0
[ 3000.912839]  ksys_read+0x68/0xe0
[ 3000.913007]  do_syscall_64+0xf9/0x540
[ 3000.913187]  entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 3000.913461] RIP: 0033:0x49a182
[ 3000.913618] RSP: 002b:00007ffd0b4cf048 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 3000.913972] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000049a182
[ 3000.914294] RDX: 0000000000010000 RSI: 00007fbf49a0d000 RDI: 0000000000000003
[ 3000.914648] RBP: 00007fbf49a0d000 R08: 00000000ffffffff R09: 0000000000000000
[ 3000.914955] R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000010000
[ 3000.915208] R13: 0000000000000003 R14: 0000000000000001 R15: 0000000001000000
[ 3000.915439]  </TASK>

Ruipeng Qi (2):
hung_task: show the blocker task if the task is hung on rtmutex
samples: enhance hung_task detector test with rtmutex support

  include/linux/hung_task.h           | 31 +++++++++++++-----
  kernel/hung_task.c                  | 22 +++++++++++++
  kernel/locking/mutex.c              |  4 +--
  kernel/locking/rtmutex.c            | 13 ++++++++
  kernel/locking/rwsem.c              |  8 ++---
  kernel/locking/semaphore.c          |  4 +--
  lib/Kconfig.debug                   |  1 -
  samples/Kconfig                     |  2 +-
  samples/hung_task/hung_task_tests.c | 50 ++++++++++++++++++++++++++---
  9 files changed, 113 insertions(+), 22 deletions(-)