aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorIngo Molnar <mingo@elte.hu>2007-10-17 02:26:08 -0400
committerLinus Torvalds <torvalds@woody.linux-foundation.org>2007-10-17 11:42:47 -0400
commit43581a10075492445f65234384210492ff333eba (patch)
tree2bcec45ff17207f57f8c4f4744b22411d1aeae6c
parentad3b82795f3f6e641081790409a051312622f2a6 (diff)
softlockup: improve debug output
Improve the debuggability of kernel lockups by enhancing the debug output of the softlockup detector: print the task that causes the lockup and try to print a more intelligent backtrace. The old format was: BUG: soft lockup detected on CPU#1! [<c0105e4a>] show_trace_log_lvl+0x19/0x2e [<c0105f43>] show_trace+0x12/0x14 [<c0105f59>] dump_stack+0x14/0x16 [<c015f6bc>] softlockup_tick+0xbe/0xd0 [<c013457d>] run_local_timers+0x12/0x14 [<c01346b8>] update_process_times+0x3e/0x63 [<c0145fb8>] tick_sched_timer+0x7c/0xc0 [<c0140a75>] hrtimer_interrupt+0x135/0x1ba [<c011bde7>] smp_apic_timer_interrupt+0x6e/0x80 [<c0105aa3>] apic_timer_interrupt+0x33/0x38 [<c0104f8a>] syscall_call+0x7/0xb ======================= The new format is: BUG: soft lockup detected on CPU#1! [prctl:2363] Pid: 2363, comm: prctl EIP: 0060:[<c013915f>] CPU: 1 EIP is at sys_prctl+0x24/0x18c EFLAGS: 00000213 Not tainted (2.6.22-cfs-v20 #26) EAX: 00000001 EBX: 000003e7 ECX: 00000001 EDX: f6df0000 ESI: 000003e7 EDI: 000003e7 EBP: f6df0fb0 DS: 007b ES: 007b FS: 00d8 CR0: 8005003b CR2: 4d8c3340 CR3: 3731d000 CR4: 000006d0 [<c0105e4a>] show_trace_log_lvl+0x19/0x2e [<c0105f43>] show_trace+0x12/0x14 [<c01040be>] show_regs+0x1ab/0x1b3 [<c015f807>] softlockup_tick+0xef/0x108 [<c013457d>] run_local_timers+0x12/0x14 [<c01346b8>] update_process_times+0x3e/0x63 [<c0145fcc>] tick_sched_timer+0x7c/0xc0 [<c0140a89>] hrtimer_interrupt+0x135/0x1ba [<c011bde7>] smp_apic_timer_interrupt+0x6e/0x80 [<c0105aa3>] apic_timer_interrupt+0x33/0x38 [<c0104f8a>] syscall_call+0x7/0xb ======================= Note that in the old format we only knew that some system call locked up, we didnt know _which_. With the new format we know that it's at a specific place in sys_prctl(). [which was where i created an artificial kernel lockup to test the new format.] This is also useful if the lockup happens in user-space - the user-space EIP (and other registers) will be printed too. (such a lockup would either suggest that the task was running at SCHED_FIFO:99 and looping for more than 10 seconds, or that the softlockup detector has a false-positive.) The task name is printed too first, just in case we dont manage to print a useful backtrace. [satyam@infradead.org: fix warning] Signed-off-by: Ingo Molnar <mingo@elte.hu> Signed-off-by: Satyam Sharma <satyam@infradead.org> Signed-off-by: Andrew Morton <akpm@linux-foundation.org> Signed-off-by: Linus Torvalds <torvalds@linux-foundation.org>
-rw-r--r--kernel/softlockup.c20
1 files changed, 13 insertions, 7 deletions
diff --git a/kernel/softlockup.c b/kernel/softlockup.c
index e423b3a918fd..65839c54abf5 100644
--- a/kernel/softlockup.c
+++ b/kernel/softlockup.c
@@ -15,6 +15,8 @@
15#include <linux/notifier.h> 15#include <linux/notifier.h>
16#include <linux/module.h> 16#include <linux/module.h>
17 17
18#include <asm/irq_regs.h>
19
18static DEFINE_SPINLOCK(print_lock); 20static DEFINE_SPINLOCK(print_lock);
19 21
20static DEFINE_PER_CPU(unsigned long, touch_timestamp); 22static DEFINE_PER_CPU(unsigned long, touch_timestamp);
@@ -72,6 +74,7 @@ void softlockup_tick(void)
72 int this_cpu = smp_processor_id(); 74 int this_cpu = smp_processor_id();
73 unsigned long touch_timestamp = per_cpu(touch_timestamp, this_cpu); 75 unsigned long touch_timestamp = per_cpu(touch_timestamp, this_cpu);
74 unsigned long print_timestamp; 76 unsigned long print_timestamp;
77 struct pt_regs *regs = get_irq_regs();
75 unsigned long now; 78 unsigned long now;
76 79
77 if (touch_timestamp == 0) { 80 if (touch_timestamp == 0) {
@@ -101,15 +104,18 @@ void softlockup_tick(void)
101 wake_up_process(per_cpu(watchdog_task, this_cpu)); 104 wake_up_process(per_cpu(watchdog_task, this_cpu));
102 105
103 /* Warn about unreasonable 10+ seconds delays: */ 106 /* Warn about unreasonable 10+ seconds delays: */
104 if (now > (touch_timestamp + 10)) { 107 if (now <= (touch_timestamp + 10))
105 per_cpu(print_timestamp, this_cpu) = touch_timestamp; 108 return;
106 109
107 spin_lock(&print_lock); 110 per_cpu(print_timestamp, this_cpu) = touch_timestamp;
108 printk(KERN_ERR "BUG: soft lockup detected on CPU#%d!\n", 111
109 this_cpu); 112 spin_lock(&print_lock);
113 printk(KERN_ERR "BUG: soft lockup detected on CPU#%d!\n", this_cpu);
114 if (regs)
115 show_regs(regs);
116 else
110 dump_stack(); 117 dump_stack();
111 spin_unlock(&print_lock); 118 spin_unlock(&print_lock);
112 }
113} 119}
114 120
115/* 121/*