NMI Watchdog detected hard LOCKUP on CPU XX in _spin_lock_irqsave.
Environment
- Red Hat Enterprise Linux 6
- Kernel-2.6.32-431.5.1.el6
- EMCpower.LINUX-5.7.1.00.00-029.el6
- EMC Unsigned (U) module "emcp"
Issue
- Kernel panic with following call traces.
Kernel panic - not syncing: Watchdog detected hard LOCKUP on cpu 14
Pid: 35242, comm: oracle Tainted: P --------------- 2.6.32-431.5.1.el6.x86_64 #1
Call Trace:
<NMI> [<ffffffff81527513>] ? panic+0xa7/0x16f
[<ffffffff810153a3>] ? native_sched_clock+0x13/0x80
[<ffffffff810e696d>] ? watchdog_overflow_callback+0xcd/0xd0
[<ffffffff8111c847>] ? __perf_event_overflow+0xa7/0x240
[<ffffffff8101d93d>] ? x86_perf_event_set_period+0xdd/0x170
[<ffffffff8111ce14>] ? perf_event_overflow+0x14/0x20
[<ffffffff81022d87>] ? intel_pmu_handle_irq+0x187/0x2f0
[<ffffffff8152d1f6>] ? kprobe_exceptions_notify+0x16/0x430
[<ffffffff8152bd69>] ? perf_event_nmi_handler+0x39/0xb0
[<ffffffff8152d825>] ? notifier_call_chain+0x55/0x80
[<ffffffff8152d88a>] ? atomic_notifier_call_chain+0x1a/0x20
[<ffffffff810a153e>] ? notify_die+0x2e/0x30
[<ffffffff8152b4eb>] ? do_nmi+0x1bb/0x340
[<ffffffff8152adb0>] ? nmi+0x20/0x30
[<ffffffff8152a50d>] ? _spin_lock_irqsave+0x2d/0x40
<<EOE>> <IRQ> [<ffffffffa02e66df>] ? PowerPlatformTopIodone+0x17f/0x220 [emcp]
[<ffffffffa02ee199>] ? PowerTopIodone+0x29/0x170 [emcp]
[<ffffffffa02ee337>] ? PowerProcessTopIodonePirps+0x57/0xd0 [emcp]
[<ffffffffa02ee6f0>] ? PowerBottomIodoneNew+0x230/0x550 [emcp]
[<ffffffffa02eebe7>] ? PowerPlatformBottomIodone+0xd7/0x140 [emcp]
[<ffffffff812658d7>] ? __blk_run_queue+0x27/0x40
[<ffffffff811c22bd>] ? bio_endio+0x1d/0x40
[<ffffffff81264ebb>] ? req_bio_endio+0x9b/0xe0
[<ffffffff81266437>] ? blk_update_request+0x117/0x490
[<ffffffff812667d7>] ? blk_update_bidi_request+0x27/0xa0
[<ffffffff8127d5c5>] ? __cfq_slice_expired+0x1e5/0x530
[<ffffffff812688cf>] ? blk_end_bidi_request+0x2f/0x80
[<ffffffff81268970>] ? blk_end_request+0x10/0x20
[<ffffffff81389acf>] ? scsi_io_completion+0xaf/0x6c0
[<ffffffff8137ff52>] ? scsi_finish_command+0xc2/0x130
[<ffffffff8138a245>] ? scsi_softirq_done+0x145/0x170
[<ffffffff8126e855>] ? blk_done_softirq+0x85/0xa0
[<ffffffff8127bce0>] ? cfq_kick_queue+0x0/0x60
[<ffffffff8107a8e1>] ? __do_softirq+0xc1/0x1e0
[<ffffffff8100c30c>] ? call_softirq+0x1c/0x30
<EOI> [<ffffffff8100fa75>] ? do_softirq+0x65/0xa0
[<ffffffff8107b5da>] ? local_bh_enable+0x9a/0xb0
[<ffffffff8149123d>] ? __ip_route_output_key+0x17d/0x1b0
[<ffffffff814912a6>] ? ip_route_output_flow+0x36/0x2c0
[<ffffffff81498a00>] ? ip_generic_getfrag+0x0/0xb0
[<ffffffff814bd80a>] ? udp_sendmsg+0x78a/0x930
[<ffffffff814c5eba>] ? inet_sendmsg+0x4a/0xb0
[<ffffffff8122ed0f>] ? selinux_socket_sendmsg+0x1f/0x30
[<ffffffff81448003>] ? sock_sendmsg+0x123/0x150
[<ffffffff81449cb3>] ? sock_recvmsg+0x133/0x160
[<ffffffff8109b290>] ? autoremove_wake_function+0x0/0x40
[<ffffffff8119fec0>] ? pollwake+0x0/0x60
[<ffffffff8119fec0>] ? pollwake+0x0/0x60
[<ffffffff81447e54>] ? move_addr_to_kernel+0x64/0x70
[<ffffffff814497f6>] ? __sys_sendmsg+0x406/0x420
[<ffffffff810129de>] ? copy_user_generic+0xe/0x20
[<ffffffff810179ab>] ? check_for_xstate+0x3b/0x90
[<ffffffff8100b9ce>] ? common_interrupt+0xe/0x13
[<ffffffff810149b9>] ? read_tsc+0x9/0x20
[<ffffffff810a7091>] ? ktime_get_ts+0xb1/0xf0
[<ffffffff81449a19>] ? sys_sendmsg+0x49/0x90
[<ffffffff8100b072>] ? system_call_fastpath+0x16/0x1b
Resolution
- This is an issue in unsigned (U) kernel module
emcpshipped by EMC. - Since Red Hat does not have the source code of unsigned (U) kernel module
emcp. A case would need to be opened with EMC Technical Support Team for further investigation.
Root Cause
-
NMI Watchdog detected LOCKUP on CPU 14 and triggered the kernel panic. The cause of the NMI watchdog crashing the system is due to having IRQs disabled for too long. The timeout for a NMI watchdog to trigger is 30 seconds.
-
The evidence in vmcore indicates that the
emcpmodule has tried to grab a spinlock at PowerPlatformTopIodone+0x17f and has failed to get it for a long time and because of that the system was crashed by hard-lockup NMI watchdog.
Diagnostic Steps
System Information:
crash> sys | grep -e RELEASE -e PANIC
RELEASE: 2.6.32-431.5.1.el6.x86_64
PANIC: "Kernel panic - not syncing: Watchdog detected hard LOCKUP on cpu 14"
Kernel Ring Buffer:
crash> log
Kernel panic - not syncing: Watchdog detected hard LOCKUP on cpu 14
Pid: 35242, comm: oracle Tainted: P --------------- 2.6.32-431.5.1.el6.x86_64 #1
Call Trace:
<NMI> [<ffffffff81527513>] ? panic+0xa7/0x16f
[<ffffffff810153a3>] ? native_sched_clock+0x13/0x80
[<ffffffff810e696d>] ? watchdog_overflow_callback+0xcd/0xd0
[<ffffffff8111c847>] ? __perf_event_overflow+0xa7/0x240
[<ffffffff8101d93d>] ? x86_perf_event_set_period+0xdd/0x170
[<ffffffff8111ce14>] ? perf_event_overflow+0x14/0x20
[<ffffffff81022d87>] ? intel_pmu_handle_irq+0x187/0x2f0
[<ffffffff8152d1f6>] ? kprobe_exceptions_notify+0x16/0x430
[<ffffffff8152bd69>] ? perf_event_nmi_handler+0x39/0xb0
[<ffffffff8152d825>] ? notifier_call_chain+0x55/0x80
[<ffffffff8152d88a>] ? atomic_notifier_call_chain+0x1a/0x20
[<ffffffff810a153e>] ? notify_die+0x2e/0x30
[<ffffffff8152b4eb>] ? do_nmi+0x1bb/0x340
[<ffffffff8152adb0>] ? nmi+0x20/0x30
[<ffffffff8152a50d>] ? _spin_lock_irqsave+0x2d/0x40
<<EOE>> <IRQ> [<ffffffffa02e66df>] ? PowerPlatformTopIodone+0x17f/0x220 [emcp]
[<ffffffffa02ee199>] ? PowerTopIodone+0x29/0x170 [emcp]
[<ffffffffa02ee337>] ? PowerProcessTopIodonePirps+0x57/0xd0 [emcp]
[<ffffffffa02ee6f0>] ? PowerBottomIodoneNew+0x230/0x550 [emcp]
[<ffffffffa02eebe7>] ? PowerPlatformBottomIodone+0xd7/0x140 [emcp]
[<ffffffff812658d7>] ? __blk_run_queue+0x27/0x40
[<ffffffff811c22bd>] ? bio_endio+0x1d/0x40
[<ffffffff81264ebb>] ? req_bio_endio+0x9b/0xe0
[<ffffffff81266437>] ? blk_update_request+0x117/0x490
[<ffffffff812667d7>] ? blk_update_bidi_request+0x27/0xa0
[<ffffffff8127d5c5>] ? __cfq_slice_expired+0x1e5/0x530
[<ffffffff812688cf>] ? blk_end_bidi_request+0x2f/0x80
[<ffffffff81268970>] ? blk_end_request+0x10/0x20
[<ffffffff81389acf>] ? scsi_io_completion+0xaf/0x6c0
[<ffffffff8137ff52>] ? scsi_finish_command+0xc2/0x130
[<ffffffff8138a245>] ? scsi_softirq_done+0x145/0x170
[<ffffffff8126e855>] ? blk_done_softirq+0x85/0xa0
[<ffffffff8127bce0>] ? cfq_kick_queue+0x0/0x60
[<ffffffff8107a8e1>] ? __do_softirq+0xc1/0x1e0
[<ffffffff8100c30c>] ? call_softirq+0x1c/0x30
<EOI> [<ffffffff8100fa75>] ? do_softirq+0x65/0xa0
[<ffffffff8107b5da>] ? local_bh_enable+0x9a/0xb0
[<ffffffff8149123d>] ? __ip_route_output_key+0x17d/0x1b0
[<ffffffff814912a6>] ? ip_route_output_flow+0x36/0x2c0
[<ffffffff81498a00>] ? ip_generic_getfrag+0x0/0xb0
[<ffffffff814bd80a>] ? udp_sendmsg+0x78a/0x930
[<ffffffff814c5eba>] ? inet_sendmsg+0x4a/0xb0
[<ffffffff8122ed0f>] ? selinux_socket_sendmsg+0x1f/0x30
[<ffffffff81448003>] ? sock_sendmsg+0x123/0x150
[<ffffffff81449cb3>] ? sock_recvmsg+0x133/0x160
[<ffffffff8109b290>] ? autoremove_wake_function+0x0/0x40
[<ffffffff8119fec0>] ? pollwake+0x0/0x60
[<ffffffff8119fec0>] ? pollwake+0x0/0x60
[<ffffffff81447e54>] ? move_addr_to_kernel+0x64/0x70
[<ffffffff814497f6>] ? __sys_sendmsg+0x406/0x420
[<ffffffff810129de>] ? copy_user_generic+0xe/0x20
[<ffffffff810179ab>] ? check_for_xstate+0x3b/0x90
[<ffffffff8100b9ce>] ? common_interrupt+0xe/0x13
[<ffffffff810149b9>] ? read_tsc+0x9/0x20
[<ffffffff810a7091>] ? ktime_get_ts+0xb1/0xf0
[<ffffffff81449a19>] ? sys_sendmsg+0x49/0x90
[<ffffffff8100b072>] ? system_call_fastpath+0x16/0x1b
Backtraces:
crash> bt
PID: 35242 TASK: ffff88240a862080 CPU: 14 COMMAND: "oracle"
#0 [ffff8824a2ac7b50] machine_kexec at ffffffff81038f3b
#1 [ffff8824a2ac7bb0] crash_kexec at ffffffff810c5d82
#2 [ffff8824a2ac7c80] panic at ffffffff8152751a
#3 [ffff8824a2ac7d00] watchdog_overflow_callback at ffffffff810e696d
#4 [ffff8824a2ac7d20] __perf_event_overflow at ffffffff8111c847
#5 [ffff8824a2ac7da0] perf_event_overflow at ffffffff8111ce14
#6 [ffff8824a2ac7db0] intel_pmu_handle_irq at ffffffff81022d87
#7 [ffff8824a2ac7e90] perf_event_nmi_handler at ffffffff8152bd69
#8 [ffff8824a2ac7ea0] notifier_call_chain at ffffffff8152d825
#9 [ffff8824a2ac7ee0] atomic_notifier_call_chain at ffffffff8152d88a
#10 [ffff8824a2ac7ef0] notify_die at ffffffff810a153e
#11 [ffff8824a2ac7f20] do_nmi at ffffffff8152b4eb
#12 [ffff8824a2ac7f50] nmi at ffffffff8152adb0
[exception RIP: _spin_lock_irqsave+45]
RIP: ffffffff8152a50d RSP: ffff8824a2ac3b98 RFLAGS: 00000097
RAX: 00000000000044f6 RBX: ffff88401342d060 RCX: 00000000000044f5
RDX: 0000000000000246 RSI: 000000000cd7d9c0 RDI: ffff88401555dbf0
RBP: ffff8824a2ac3b98 R8: 00007f118ec27560 R9: 0000000000000001
R10: ffff88401403fb40 R11: 0000000000000000 R12: 0000000007800250
R13: 0000000000000078 R14: 0000000000000000 R15: ffff88401555dbf0
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
--- <NMI exception stack> ---
#13 [ffff8824a2ac3b98] _spin_lock_irqsave at ffffffff8152a50d
#14 [ffff8824a2ac3ba0] PowerPlatformTopIodone at ffffffffa02e66df [emcp]
#15 [ffff8824a2ac3c00] PowerTopIodone at ffffffffa02ee199 [emcp]
#16 [ffff8824a2ac3c30] PowerProcessTopIodonePirps at ffffffffa02ee337 [emcp]
#17 [ffff8824a2ac3c70] PowerBottomIodoneNew at ffffffffa02ee6f0 [emcp]
#18 [ffff8824a2ac3cc0] PowerPlatformBottomIodone at ffffffffa02eebe7 [emcp]
#19 [ffff8824a2ac3d10] bio_endio at ffffffff811c22bd
#20 [ffff8824a2ac3d20] req_bio_endio at ffffffff81264ebb
#21 [ffff8824a2ac3d50] blk_update_request at ffffffff81266437
#22 [ffff8824a2ac3db0] blk_update_bidi_request at ffffffff812667d7
#23 [ffff8824a2ac3de0] blk_end_bidi_request at ffffffff812688cf
#24 [ffff8824a2ac3e10] blk_end_request at ffffffff81268970
#25 [ffff8824a2ac3e20] scsi_io_completion at ffffffff81389acf
#26 [ffff8824a2ac3ea0] scsi_finish_command at ffffffff8137ff52
#27 [ffff8824a2ac3ee0] scsi_softirq_done at ffffffff8138a245
#28 [ffff8824a2ac3f10] blk_done_softirq at ffffffff8126e855
#29 [ffff8824a2ac3f40] __do_softirq at ffffffff8107a8e1
#30 [ffff8824a2ac3fb0] call_softirq at ffffffff8100c30c
--- <IRQ stack> ---
#31 [ffff88239bced990] do_softirq at ffffffff8100fa75
#32 [ffff88239bced9b0] local_bh_enable at ffffffff8107b5da
#33 [ffff88239bced9f0] ip_route_output_flow at ffffffff814912a6
#34 [ffff88239bceda40] udp_sendmsg at ffffffff814bd80a
#35 [ffff88239bcedb70] inet_sendmsg at ffffffff814c5eba
#36 [ffff88239bcedbb0] sock_sendmsg at ffffffff81448003
#37 [ffff88239bcedd60] __sys_sendmsg at ffffffff814497f6
#38 [ffff88239bcedf10] sys_sendmsg at ffffffff81449a19
#39 [ffff88239bcedf80] system_call_fastpath at ffffffff8100b072
RIP: 00000034b5a0ed30 RSP: 00007fff1f3d38c0 RFLAGS: 00000202
RAX: 000000000000002e RBX: ffffffff8100b072 RCX: 00007f9e6b5dd888
RDX: 0000000000000000 RSI: 00007fff1f3d4cf0 RDI: 0000000000000007
RBP: 00007fff1f3d4d80 R8: 00007f9e6a52fda0 R9: 0000000000000003
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f9e6a52f620
R13: 00007f9e6b5dc4f8 R14: 00007f9e6a52f620 R15: 00007f9e6b5dc4f8
ORIG_RAX: 000000000000002e CS: 0033 SS: 002b
Details of EMC Unsigned (U) module: emcp
crash> mod -t | grep -e NAME -e emcp
NAME TAINTS
emcp P(U)
emcpmpx P(U)
emcpgpx P(U)
emcpdm P(U)
emcpxcrypt P(U)
emcpvlumd P(U)
crash> mod |grep emcp
ffffffffa03056a0 emcp 1487583 (not loaded) [CONFIG_KALLSYMS]
ffffffffa048f020 emcpmpx 218529 (not loaded) [CONFIG_KALLSYMS]
ffffffffa04a6140 emcpgpx 16676 (not loaded) [CONFIG_KALLSYMS]
ffffffffa04b5f80 emcpdm 39431 (not loaded) [CONFIG_KALLSYMS]
ffffffffa04d8fa0 emcpxcrypt 130828 (not loaded) [CONFIG_KALLSYMS]
ffffffffa04ebf00 emcpvlumd 34775 (not loaded) [CONFIG_KALLSYMS]
crash> module ffffffffa03056a0| grep -e name -e version
version = 0x0 <per_cpu__irq_stack_union>,
srcversion = 0xffff882405403500 "876E5CA9FC19AC904CD8DC0",
This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.
Comments