Messages in this thread Patch in this message | | | From | Vegard Nossum <> | Subject | [PATCH] sched/core: make "Preemption disabled at" message more useful | Date | Sat, 23 Jul 2016 09:58:13 +0200 |
| |
This message is currently really useless since it always prints a value that comes from the printk() we just did, e.g.:
BUG: sleeping function called from invalid context at mm/slab.h:388 in_atomic(): 0, irqs_disabled(): 0, pid: 31996, name: trinity-c1 Preemption disabled at:[<ffffffff8119db33>] down_trylock+0x13/0x80
BUG: sleeping function called from invalid context at include/linux/freezer.h:56 in_atomic(): 0, irqs_disabled(): 0, pid: 31996, name: trinity-c1 Preemption disabled at:[<ffffffff811aaa37>] console_unlock+0x2f7/0x930
Here, both down_trylock() and console_unlock() is somewhere in the printk() path.
We should save the value before calling printk() and use the saved value instead. That immediately reveals the offending callsite:
BUG: sleeping function called from invalid context at mm/slab.h:388 in_atomic(): 0, irqs_disabled(): 0, pid: 14971, name: trinity-c2 Preemption disabled at:[<ffffffff819bcd46>] rhashtable_walk_start+0x46/0x150
(Bug report: http://marc.info/?l=linux-netdev&m=146925979821849&w=2)
Cc: Peter Zijlstra <peterz@infradead.org> Cc: Paul E. McKenney <paulmck@linux.vnet.ibm.com> Cc: Thomas Gleixner <tglx@linutronix.de> Cc: Ingo Molnar <mingo@kernel.org> Cc: Rusty Russel <rusty@rustcorp.com.au> Signed-off-by: Vegard Nossum <vegard.nossum@oracle.com> --- kernel/sched/core.c | 21 +++++++++++++++++++-- 1 file changed, 19 insertions(+), 2 deletions(-)
diff --git a/kernel/sched/core.c b/kernel/sched/core.c index 7171cf9..87689a6 100644 --- a/kernel/sched/core.c +++ b/kernel/sched/core.c @@ -3144,9 +3144,18 @@ static inline void preempt_latency_stop(int val) { } */ static noinline void __schedule_bug(struct task_struct *prev) { +#ifdef CONFIG_DEBUG_PREEMPT + unsigned long preempt_disable_ip; +#endif + if (oops_in_progress) return; +#ifdef CONFIG_DEBUG_PREEMPT + /* Save this before calling printk(), since that will clobber it */ + preempt_disable_ip = current->preempt_disable_ip; +#endif + printk(KERN_ERR "BUG: scheduling while atomic: %s/%d/0x%08x\n", prev->comm, prev->pid, preempt_count()); @@ -3157,7 +3166,7 @@ static noinline void __schedule_bug(struct task_struct *prev) #ifdef CONFIG_DEBUG_PREEMPT if (in_atomic_preempt_off()) { pr_err("Preemption disabled at:"); - print_ip_sym(current->preempt_disable_ip); + print_ip_sym(preempt_disable_ip); pr_cont("\n"); } #endif @@ -7541,6 +7550,9 @@ EXPORT_SYMBOL(__might_sleep); void ___might_sleep(const char *file, int line, int preempt_offset) { static unsigned long prev_jiffy; /* ratelimiting */ +#ifdef CONFIG_DEBUG_PREEMPT + unsigned long preempt_disable_ip; +#endif rcu_sleep_check(); /* WARN_ON_ONCE() by default, no rate limit reqd. */ if ((preempt_count_equals(preempt_offset) && !irqs_disabled() && @@ -7551,6 +7563,11 @@ void ___might_sleep(const char *file, int line, int preempt_offset) return; prev_jiffy = jiffies; +#ifdef CONFIG_DEBUG_PREEMPT + /* Save this before calling printk(), since that will clobber it */ + preempt_disable_ip = current->preempt_disable_ip; +#endif + printk(KERN_ERR "BUG: sleeping function called from invalid context at %s:%d\n", file, line); @@ -7568,7 +7585,7 @@ void ___might_sleep(const char *file, int line, int preempt_offset) #ifdef CONFIG_DEBUG_PREEMPT if (!preempt_count_equals(preempt_offset)) { pr_err("Preemption disabled at:"); - print_ip_sym(current->preempt_disable_ip); + print_ip_sym(preempt_disable_ip); pr_cont("\n"); } #endif -- 1.9.1
| |