diff options
author | Ingo Molnar <mingo@elte.hu> | 2009-08-02 05:28:21 -0400 |
---|---|---|
committer | Ingo Molnar <mingo@elte.hu> | 2009-08-02 07:27:17 -0400 |
commit | c1dc0b9c0c8979ce4d411caadff5c0d79dee58bc (patch) | |
tree | 6822205799a6cf8928623d60aa226c95534a20f9 | |
parent | ed680c4ad478d0fee9740f7d029087f181346564 (diff) |
debug lockups: Improve lockup detection
When debugging a recent lockup bug i found various deficiencies
in how our current lockup detection helpers work:
- SysRq-L is not very efficient as it uses a workqueue, hence
it cannot punch through hard lockups and cannot see through
most soft lockups either.
- The SysRq-L code depends on the NMI watchdog - which is off
by default.
- We dont print backtraces from the RCU code's built-in
'RCU state machine is stuck' debug code. This debug
code tends to be one of the first (and only) mechanisms
that show that a lockup has occured.
This patch changes the code so taht we:
- Trigger the NMI backtrace code from SysRq-L instead of using
a workqueue (which cannot punch through hard lockups)
- Trigger print-all-CPU-backtraces from the RCU lockup detection
code
Also decouple the backtrace printing code from the NMI watchdog:
- Dont use variable size cpumasks (it might not be initialized
and they are a bit more fragile anyway)
- Trigger an NMI immediately via an IPI, instead of waiting
for the NMI tick to occur. This is a lot faster and can
produce more relevant backtraces. It will also work if the
NMI watchdog is disabled.
- Dont print the 'dazed and confused' message when we print
a backtrace from the NMI
- Do a show_regs() plus a dump_stack() to get maximum info
out of the dump. Worst-case we get two stacktraces - which
is not a big deal. Sometimes, if register content is
corrupted, the precise stack walker in show_regs() wont
give us a full backtrace - in this case dump_stack() will
do it.
Cc: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Linus Torvalds <torvalds@linux-foundation.org>
LKML-Reference: <new-submission>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
-rw-r--r-- | arch/x86/kernel/apic/nmi.c | 18 | ||||
-rw-r--r-- | drivers/char/sysrq.c | 8 | ||||
-rw-r--r-- | kernel/rcutree.c | 7 |
3 files changed, 20 insertions, 13 deletions
diff --git a/arch/x86/kernel/apic/nmi.c b/arch/x86/kernel/apic/nmi.c index b3025b43b63a..1bb1ac20e9ec 100644 --- a/arch/x86/kernel/apic/nmi.c +++ b/arch/x86/kernel/apic/nmi.c | |||
@@ -39,7 +39,7 @@ | |||
39 | int unknown_nmi_panic; | 39 | int unknown_nmi_panic; |
40 | int nmi_watchdog_enabled; | 40 | int nmi_watchdog_enabled; |
41 | 41 | ||
42 | static cpumask_var_t backtrace_mask; | 42 | static cpumask_t backtrace_mask __read_mostly; |
43 | 43 | ||
44 | /* nmi_active: | 44 | /* nmi_active: |
45 | * >0: the lapic NMI watchdog is active, but can be disabled | 45 | * >0: the lapic NMI watchdog is active, but can be disabled |
@@ -138,7 +138,6 @@ int __init check_nmi_watchdog(void) | |||
138 | if (!prev_nmi_count) | 138 | if (!prev_nmi_count) |
139 | goto error; | 139 | goto error; |
140 | 140 | ||
141 | alloc_cpumask_var(&backtrace_mask, GFP_KERNEL|__GFP_ZERO); | ||
142 | printk(KERN_INFO "Testing NMI watchdog ... "); | 141 | printk(KERN_INFO "Testing NMI watchdog ... "); |
143 | 142 | ||
144 | #ifdef CONFIG_SMP | 143 | #ifdef CONFIG_SMP |
@@ -415,14 +414,17 @@ nmi_watchdog_tick(struct pt_regs *regs, unsigned reason) | |||
415 | } | 414 | } |
416 | 415 | ||
417 | /* We can be called before check_nmi_watchdog, hence NULL check. */ | 416 | /* We can be called before check_nmi_watchdog, hence NULL check. */ |
418 | if (backtrace_mask != NULL && cpumask_test_cpu(cpu, backtrace_mask)) { | 417 | if (cpumask_test_cpu(cpu, &backtrace_mask)) { |
419 | static DEFINE_SPINLOCK(lock); /* Serialise the printks */ | 418 | static DEFINE_SPINLOCK(lock); /* Serialise the printks */ |
420 | 419 | ||
421 | spin_lock(&lock); | 420 | spin_lock(&lock); |
422 | printk(KERN_WARNING "NMI backtrace for cpu %d\n", cpu); | 421 | printk(KERN_WARNING "NMI backtrace for cpu %d\n", cpu); |
422 | show_regs(regs); | ||
423 | dump_stack(); | 423 | dump_stack(); |
424 | spin_unlock(&lock); | 424 | spin_unlock(&lock); |
425 | cpumask_clear_cpu(cpu, backtrace_mask); | 425 | cpumask_clear_cpu(cpu, &backtrace_mask); |
426 | |||
427 | rc = 1; | ||
426 | } | 428 | } |
427 | 429 | ||
428 | /* Could check oops_in_progress here too, but it's safer not to */ | 430 | /* Could check oops_in_progress here too, but it's safer not to */ |
@@ -556,10 +558,14 @@ void __trigger_all_cpu_backtrace(void) | |||
556 | { | 558 | { |
557 | int i; | 559 | int i; |
558 | 560 | ||
559 | cpumask_copy(backtrace_mask, cpu_online_mask); | 561 | cpumask_copy(&backtrace_mask, cpu_online_mask); |
562 | |||
563 | printk(KERN_INFO "sending NMI to all CPUs:\n"); | ||
564 | apic->send_IPI_all(NMI_VECTOR); | ||
565 | |||
560 | /* Wait for up to 10 seconds for all CPUs to do the backtrace */ | 566 | /* Wait for up to 10 seconds for all CPUs to do the backtrace */ |
561 | for (i = 0; i < 10 * 1000; i++) { | 567 | for (i = 0; i < 10 * 1000; i++) { |
562 | if (cpumask_empty(backtrace_mask)) | 568 | if (cpumask_empty(&backtrace_mask)) |
563 | break; | 569 | break; |
564 | mdelay(1); | 570 | mdelay(1); |
565 | } | 571 | } |
diff --git a/drivers/char/sysrq.c b/drivers/char/sysrq.c index 5d7a02f63e1c..165f307f30e8 100644 --- a/drivers/char/sysrq.c +++ b/drivers/char/sysrq.c | |||
@@ -24,6 +24,7 @@ | |||
24 | #include <linux/sysrq.h> | 24 | #include <linux/sysrq.h> |
25 | #include <linux/kbd_kern.h> | 25 | #include <linux/kbd_kern.h> |
26 | #include <linux/proc_fs.h> | 26 | #include <linux/proc_fs.h> |
27 | #include <linux/nmi.h> | ||
27 | #include <linux/quotaops.h> | 28 | #include <linux/quotaops.h> |
28 | #include <linux/perf_counter.h> | 29 | #include <linux/perf_counter.h> |
29 | #include <linux/kernel.h> | 30 | #include <linux/kernel.h> |
@@ -222,12 +223,7 @@ static DECLARE_WORK(sysrq_showallcpus, sysrq_showregs_othercpus); | |||
222 | 223 | ||
223 | static void sysrq_handle_showallcpus(int key, struct tty_struct *tty) | 224 | static void sysrq_handle_showallcpus(int key, struct tty_struct *tty) |
224 | { | 225 | { |
225 | struct pt_regs *regs = get_irq_regs(); | 226 | trigger_all_cpu_backtrace(); |
226 | if (regs) { | ||
227 | printk(KERN_INFO "CPU%d:\n", smp_processor_id()); | ||
228 | show_regs(regs); | ||
229 | } | ||
230 | schedule_work(&sysrq_showallcpus); | ||
231 | } | 227 | } |
232 | 228 | ||
233 | static struct sysrq_key_op sysrq_showallcpus_op = { | 229 | static struct sysrq_key_op sysrq_showallcpus_op = { |
diff --git a/kernel/rcutree.c b/kernel/rcutree.c index 7717b95c2027..9c5fa9fc57ec 100644 --- a/kernel/rcutree.c +++ b/kernel/rcutree.c | |||
@@ -35,6 +35,7 @@ | |||
35 | #include <linux/rcupdate.h> | 35 | #include <linux/rcupdate.h> |
36 | #include <linux/interrupt.h> | 36 | #include <linux/interrupt.h> |
37 | #include <linux/sched.h> | 37 | #include <linux/sched.h> |
38 | #include <linux/nmi.h> | ||
38 | #include <asm/atomic.h> | 39 | #include <asm/atomic.h> |
39 | #include <linux/bitops.h> | 40 | #include <linux/bitops.h> |
40 | #include <linux/module.h> | 41 | #include <linux/module.h> |
@@ -469,6 +470,8 @@ static void print_other_cpu_stall(struct rcu_state *rsp) | |||
469 | } | 470 | } |
470 | printk(" (detected by %d, t=%ld jiffies)\n", | 471 | printk(" (detected by %d, t=%ld jiffies)\n", |
471 | smp_processor_id(), (long)(jiffies - rsp->gp_start)); | 472 | smp_processor_id(), (long)(jiffies - rsp->gp_start)); |
473 | trigger_all_cpu_backtrace(); | ||
474 | |||
472 | force_quiescent_state(rsp, 0); /* Kick them all. */ | 475 | force_quiescent_state(rsp, 0); /* Kick them all. */ |
473 | } | 476 | } |
474 | 477 | ||
@@ -479,12 +482,14 @@ static void print_cpu_stall(struct rcu_state *rsp) | |||
479 | 482 | ||
480 | printk(KERN_ERR "INFO: RCU detected CPU %d stall (t=%lu jiffies)\n", | 483 | printk(KERN_ERR "INFO: RCU detected CPU %d stall (t=%lu jiffies)\n", |
481 | smp_processor_id(), jiffies - rsp->gp_start); | 484 | smp_processor_id(), jiffies - rsp->gp_start); |
482 | dump_stack(); | 485 | trigger_all_cpu_backtrace(); |
486 | |||
483 | spin_lock_irqsave(&rnp->lock, flags); | 487 | spin_lock_irqsave(&rnp->lock, flags); |
484 | if ((long)(jiffies - rsp->jiffies_stall) >= 0) | 488 | if ((long)(jiffies - rsp->jiffies_stall) >= 0) |
485 | rsp->jiffies_stall = | 489 | rsp->jiffies_stall = |
486 | jiffies + RCU_SECONDS_TILL_STALL_RECHECK; | 490 | jiffies + RCU_SECONDS_TILL_STALL_RECHECK; |
487 | spin_unlock_irqrestore(&rnp->lock, flags); | 491 | spin_unlock_irqrestore(&rnp->lock, flags); |
492 | |||
488 | set_need_resched(); /* kick ourselves to get things going. */ | 493 | set_need_resched(); /* kick ourselves to get things going. */ |
489 | } | 494 | } |
490 | 495 | ||