Skip to contentSkip to conversation

hung_task: show the blocker task if the task is hung on rtmutex

PATCH In review ruipengqi 3 participants 6 messages Aug 8 – Aug 24

Subsystems (4)
lore
Share & tools
lore

ruipengqi

author
#0 lore raw

v2 cover 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 lock implementations 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.

Add rt_mutex_task_owner() to get the task's lock owner when a task is blocked by an rtmutex-based lock implementation.

Since the LSBs of task->blocker pointer are already fully utilized and leave no room for new blocker types, this version avoids adding a new blocker type by directly leveraging rt_mutex_task_owner() to retrieve the lock owner information.

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>

---
v2 changes:
- Reduce #ifdef-ery by using rt_mutex_task_owner() instead of adding a new blocker type, suggested by Petr.
- Remove the unused function debug_trace_blocker(), suggested by Xusheng.
- Clean up and update relevant comments.
- https://lore.kernel.org/all/[email protected]/

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/rtmutex.h             |  2 ++
 kernel/hung_task.c                  | 26 +++++++++++++--
 kernel/locking/rtmutex_api.c        | 29 +++++++++++++++++
 lib/Kconfig.debug                   |  1 -
 samples/Kconfig                     |  2 +-
 samples/hung_task/hung_task_tests.c | 50 ++++++++++++++++++++++++++---
 6 files changed, 101 insertions(+), 9 deletions(-)
Signature · 1 line
2.25.1
author
#1 lore raw

PATCH v2 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 lock implementations 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.

Add rt_mutex_task_owner() to get the task's lock owner when a task is blocked by an rtmutex-based lock implementation.

Since the LSBs of task->blocker pointer are already fully utilized and leave no room for new blocker types, this version avoids adding a new blocker type by directly leveraging rt_mutex_task_owner() to retrieve the lock owner information.

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>

---
v2 changes:
- Reduce #ifdef-ery by using rt_mutex_task_owner() instead of adding a new blocker type.
- Remove the unused function debug_trace_blocker().
- Clean up and update relevant comments.

---
 include/linux/rtmutex.h      |  2 ++
 kernel/hung_task.c           | 26 +++++++++++++++++++++++---
 kernel/locking/rtmutex_api.c | 29 +++++++++++++++++++++++++++++
 lib/Kconfig.debug            |  1 -
 4 files changed, 54 insertions(+), 4 deletions(-)
include/linux/rtmutex.h +2 -0
index 9e1f012f89db89..c179f946d2d040 100644
@@ -53,6 +53,8 @@ static inline struct task_struct *rt_mutex_owner(struct rt_mutex_base *lock)
 
 	return (struct task_struct *) (owner & ~RT_MUTEX_HAS_WAITERS);
 }
+
+extern struct task_struct *rt_mutex_task_owner(struct task_struct *task);
 #endif
 extern void rt_mutex_base_init(struct rt_mutex_base *rtb);
 
kernel/hung_task.c +23 -3
index 6fcc94ce4ca9d2..9467011f878c95 100644
@@ -27,6 +27,7 @@
 #include <linux/sys_info.h>
 
 #include <trace/events/sched.h>
+#include <linux/rtmutex.h>
 
 /*
  * The number of tasks checked:
@@ -139,9 +140,19 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
 	struct task_struct *g, *t;
 	unsigned long owner, blocker, blocker_type;
 	const char *rwsem_blocked_by, *rwsem_blocked_as;
+	bool is_rtmutex = false;
 
 	RCU_LOCKDEP_WARN(!rcu_read_lock_held(), "No rcu lock held");
 
+#if defined(CONFIG_RT_MUTEXES)
+	owner = (unsigned long)rt_mutex_task_owner(task);
+	if (owner) {
+		is_rtmutex = true;
+		blocker_type = -1;
+		goto found;
+	}
+#endif
+
 	blocker = READ_ONCE(task->blocker);
 	if (!blocker)
 		return;
@@ -149,12 +160,13 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
 	blocker_type = hung_task_get_blocker_type(blocker);
 
 	switch (blocker_type) {
-	case BLOCKER_TYPE_MUTEX:
-		owner = mutex_get_owner(hung_task_blocker_to_lock(blocker));
-		break;
 	case BLOCKER_TYPE_SEM:
 		owner = sem_last_holder(hung_task_blocker_to_lock(blocker));
 		break;
+#ifndef CONFIG_PREEMPT_RT
+	case BLOCKER_TYPE_MUTEX:
+		owner = mutex_get_owner(hung_task_blocker_to_lock(blocker));
+		break;
 	case BLOCKER_TYPE_RWSEM_READER:
 	case BLOCKER_TYPE_RWSEM_WRITER:
 		owner = (unsigned long)rwsem_owner(
@@ -165,6 +177,7 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
 					hung_task_blocker_to_lock(blocker)) ?
 					"reader" : "writer";
 		break;
+#endif
 	default:
 		WARN_ON_ONCE(1);
 		return;
@@ -190,6 +203,7 @@ static void debug_show_blocker(struct task_struct *task, unsigned long timeout)
 		return;
 	}
 
+found:
 	/* Ensure the owner information is correct. */
 	for_each_process_thread(g, t) {
 		if ((unsigned long)t != owner)
@@ -210,6 +224,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;
+		default:
+			if (is_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;
 		}
 		/* Avoid duplicated task dump, skip if the task is also hung. */
 		if (!task_is_hung(t, timeout))
kernel/locking/rtmutex_api.c +29 -0
index 5d48d64725b125..d0826b31a148c0 100644
@@ -530,6 +530,35 @@ void __sched rt_mutex_postunlock(struct rt_wake_q_head *wqh)
 	rt_mutex_wake_up_q(wqh);
 }
 
+/**
+ * rt_mutex_task_owner - Get the lock owner a task is blocked on
+ * @task: Task to inspect.
+ *
+ * Caller must hold an RCU read lock. The owner value is a snapshot read
+ * without exclusion, so it may become stale immediately. Use only for
+ * best-effort diagnostics (e.g., hung task detection).
+ *
+ * Return: The task_struct owning the lock, or NULL if not blocked.
+ */
+struct task_struct *rt_mutex_task_owner(struct task_struct *task)
+{
+        struct task_struct *owner = NULL;
+        struct rt_mutex_base *lock;
+        unsigned long flags;
+
+	lockdep_assert(rcu_read_lock_held());
+
+        raw_spin_lock_irqsave(&task->pi_lock, flags);
+        lock = task_blocked_on_lock(task);
+
+        if (lock)
+                owner = rt_mutex_owner(lock);
+        raw_spin_unlock_irqrestore(&task->pi_lock, flags);
+
+        return owner;
+}
+EXPORT_SYMBOL(rt_mutex_task_owner);
+
 #ifdef CONFIG_DEBUG_RT_MUTEXES
 void rt_mutex_debug_task_free(struct task_struct *task)
 {
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
author
#2 lore raw

PATCH v2 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
#3 lore raw

Re: [PATCH v2 2/2] samples: enhance hung_task detector test with rtmutex support

Thank you for your contribution! Sashiko AI review found 1 potential issue(s) to consider:

Thank you for your contribution! Sashiko AI review found 1 potential issue(s) to consider:

Pre-existing issues:
- [High] Missing .owner = THIS_MODULE in struct file_operations allows the module to be unloaded while debugfs files are open, leading to a use-after-free on module unload. This problem wasn't introduced by this patch, but the patch replicates the flawed pattern. --

--- Patch [2]: [PATCH v2 2/2] samples: enhance hung_task detector test with rtmutex support --- commit 1b388ec83d8aff9dc25159e4fe36a84b7c7583d7
Author: Ruipeng Qi <[email protected]>

samples: enhance hung_task detector test with rtmutex support

This commit extends the hung_task detector test module with an rtmutex test. When CONFIG_RT_MUTEXES is enabled, it creates an additional rtmutex debugfs file to allow testing hung-task reporting for rtmutex waits.

Quoted 4 lines
samples/hung_task/hung_task_tests.c +0 -0
index 0360ec916890b..87346d65f860a 100644

[ ... ]

samples/hung_task/hung_task_tests.c static const struct file_operations hung_task_mutex_fops = { · line 155

Quoted 10 lines
samples/hung_task/hung_task_tests.c +6 -0
@@ -116,6 +147,13 @@ static const struct file_operations hung_task_mutex_fops = {
 	.read = read_dummy_mutex,
 };
 
+#ifdef CONFIG_RT_MUTEXES
+/* File operations for rtmutex */
+static const struct file_operations hung_task_rtmutex_fops = {
+	.read = read_dummy_rtmutex,
+};
+#endif

[Severity: High]
This is a pre-existing issue, but this new rtmutex file operations struct (as well as the existing mutex one above it) omits the .owner field.

Without .owner = THIS_MODULE, fops_get() in the debugfs open proxy does not increment the module reference count. If a user opens the debugfs file and concurrently unloads the module via rmmod, the module is successfully unloaded because debugfs_remove_recursive() does not block merely open files.

When the file is eventually closed, full_proxy_release() will unconditionally dereference real_fops->release. Since real_fops points to the unloaded module's memory, can this trigger a use-after-free crash on module unload?

Signature · 1 line
Sashiko AI review · https://sashiko.dev/#/patchset/[email protected]?part=2
maintainer
#4 lore raw
In reply to ruipengqi

Hi Ruipeng,

Guess I'll have to be the bad guy here ...

Already raised this in v1 [1], but never got an answer ...

This touches locking too, and Peter has already made it pretty clear he doesn't want this kind of debug code there.

Please don't send another version unless Peter is on board. Otherwise, just spinning wheels ...

[1] https://lore.kernel.org/all/[email protected]/

Thanks, Lance

Quoted 97 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 lock implementations 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.

Add rt_mutex_task_owner() to get the task's lock owner when a task is blocked by an rtmutex-based lock implementation.

Since the LSBs of task->blocker pointer are already fully utilized and leave no room for new blocker types, this version avoids adding a new blocker type by directly leveraging rt_mutex_task_owner() to retrieve the lock owner information.

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>

---
v2 changes:
- Reduce #ifdef-ery by using rt_mutex_task_owner() instead of adding a new blocker type, suggested by Petr.
- Remove the unused function debug_trace_blocker(), suggested by Xusheng.
- Clean up and update relevant comments.
- https://lore.kernel.org/all/[email protected]/

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/rtmutex.h             |  2 ++
kernel/hung_task.c                  | 26 +++++++++++++--
kernel/locking/rtmutex_api.c        | 29 +++++++++++++++++
lib/Kconfig.debug                   |  1 -
samples/Kconfig                     |  2 +-
samples/hung_task/hung_task_tests.c | 50 ++++++++++++++++++++++++++---
6 files changed, 101 insertions(+), 9 deletions(-)
Signature · 1 line
2.25.1
author
#5 lore raw
Quoted 8 lines · Lance Yang

Hi Ruipeng,

Guess I'll have to be the bad guy here ...

Already raised this in v1 [1], but never got an answer ...

This touches locking too, and Peter has already made it pretty clear he doesn't want this kind of debug code there.

Hi, Lance

Peter remains opposed to this kind of debug code, so I will cease work on this patch series. Thank you.

Best Regards,
Ruipeng

Quoted 105 lines

Please don't send another version unless Peter is on board. Otherwise, just spinning wheels ...

[1]https://lore.kernel.org/all/[email protected]/

Thanks, Lance

Quoted 97 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 lock implementations 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.

Add rt_mutex_task_owner() to get the task's lock owner when a task is blocked by an rtmutex-based lock implementation.

Since the LSBs of task->blocker pointer are already fully utilized and leave no room for new blocker types, this version avoids adding a new blocker type by directly leveraging rt_mutex_task_owner() to retrieve the lock owner information.

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>

---
v2 changes:
- Reduce #ifdef-ery by using rt_mutex_task_owner() instead of adding a new blocker type, suggested by Petr.
- Remove the unused function debug_trace_blocker(), suggested by Xusheng.
- Clean up and update relevant comments. -https://lore.kernel.org/all/[email protected]/

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/rtmutex.h             |  2 ++
kernel/hung_task.c                  | 26 +++++++++++++--
kernel/locking/rtmutex_api.c        | 29 +++++++++++++++++
lib/Kconfig.debug                   |  1 -
samples/Kconfig                     |  2 +-
samples/hung_task/hung_task_tests.c | 50 ++++++++++++++++++++++++++---
6 files changed, 101 insertions(+), 9 deletions(-)
Signature · 1 line
2.25.1