Wind River Support Network

HomeDefectsLIN6-11980
Fixed

LIN6-11980 : In preempt-rt kernel, nobody cared irq will cause BUG of sleeping function called from invalid context.

Created: Nov 21, 2016    Updated: Dec 9, 2019
Resolved Date: Dec 5, 2016
Found In Version: 6.0.0.31
Fix Version: 6.0.0.32
Severity: Severe
Applicable for: Wind River Linux 6
Component/s: Kernel

Description

This issue is separated from OVP6-47. Focus on below warning message:

Disabling IRQ #16
BUG: sleeping function called from invalid context at /b/rbu-builder/daily/vmhost/19/build-project/bitbake_build/tmp/work/intel_x86_64-wrs-linux/linux-windriver/3.10-r0/linux/kernel/rtmutex.c:796
in_atomic(): 1, irqs_disabled(): 1, pid: 3, name: ksoftirqd/0
Preemption disabled at:[<ffffffff8196bbae>] do_IRQ+0x2e/0xc0 

============================
below is the description of OVP6-47:

...

Customer use OVP6 RCPL20. They found an issue when passthrough USB host controller to the VM, the OVP6 host kernel will reported the following error.
If they don't passthrough the USB host controller to VM, this issue don't 
happen.

Below is the log from customer:
----------------------------------------------------
Disabling IRQ #16 
BUG: sleeping function called from invalid context at /b/rbu-builder/daily/vmhost/19/build-project/bitbake_build/tmp/work/intel_x86_64-wrs-linux/linux-windriver/3.10-r0/linux/kernel/rtmutex.c:796 
in_atomic(): 1, irqs_disabled(): 1, pid: 3, name: ksoftirqd/0 
Preemption disabled at:[<ffffffff8196bbae>] do_IRQ+0x2e/0xc0 

Crash details: 

------------[ cut here ]------------ 
kernel BUG at /b/rbu-builder/daily/vmhost/19/build-project/bitbake_build/tmp/work/intel_x86_64-wrs-linux/linux-windriver/3.10-r0/linux/kernel/rtmutex.c:875! 
invalid opcode: 0000 [#1] PREEMPT SMP 
Modules linked in: vhost_net macvtap kvm_intel kvm uio_fpga(O) uio pci_stub iptable_mangle ipt_MASQUERADE iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT xt_tcpudp bridge stp llc ebtable_filter ebtables iptable_filter ip_tables x_tables nfsd aufs iTCO_wdt iTCO_vendor_support gpio_ich coretemp crct10dif_pclmul crct10dif_common aesni_intel aes_x86_64 glue_helper lrw gf128mul ablk_helper cryptd i2c_i801 lpc_ich e1000e acpi_cpufreq mperf processor i40e(O) [last unloaded: kvm] 
CPU: 0 PID: 3 Comm: ksoftirqd/0 Tainted: G O 3.10.79-ovp-rt74-WR6.0.0.20_preempt-rt #1 
task: ffff880ff5733000 ti: ffff880ff5744000 task.ti: ffff880ff5744000 
RIP: 0010:[<ffffffff81968475>] [<ffffffff81968475>] rt_spin_lock_slowlock+0x7c/0x277 
RSP: 0018:ffff88107fc03d40 EFLAGS: 00010046 
RAX: ffff880ff5733000 RBX: ffffffff8208b300 RCX: 0000000000000001 
RDX: 0000000000000000 RSI: ffff880ff5733000 RDI: ffffffff8208b300 
RBP: ffff88107fc03de8 R08: ffff880ff5733001 R09: ffffffff8208b318 
R10: ffff880ff5733001 R11: 0000000000000000 R12: ffffffff8208b300 
R13: ffffffff81e530d8 R14: ffff88107fc03e48 R15: ffff880ff5745da0 
FS: 0000000000000000(0000) GS:ffff88107fc00000(0000) knlGS:0000000000000000 
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 
CR2: 00007ffe340a9f68 CR3: 0000000fe0fbb000 CR4: 00000000001427f0 
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 
Stack: 
ffffffff81cd2efb 000000000000000c ffff880ff5733000 ffffffff810052de 
ffff88107fbfffc0 ffff88107fc03fc0 ffff88107fc03e18 ffff88107fc03db8 
0000000000000000 ffffffff8208b300 ffffffff81e530d8 ffff88107fc03e48 
Call Trace: 
<IRQ> 
[<ffffffff810052de>] ? show_stack_log_lvl+0xce/0x1c0 
[<ffffffff81006725>] ? show_stack+0x25/0x50 
[<ffffffff81968ec1>] rt_spin_lock+0x41/0x50 
[<ffffffff81051727>] lock_timer_base.isra.37+0x37/0x60 
[<ffffffff81051bd5>] mod_timer+0x75/0x290 
[<ffffffff810d912b>] note_interrupt+0x20b/0x290 
[<ffffffff810d66c6>] handle_irq_event_percpu+0x126/0x290 
[<ffffffff810515a6>] ? run_timer_softirq+0x1b6/0x300 
[<ffffffff810d6898>] handle_irq_event+0x68/0x90 
[<ffffffff810d9d89>] handle_fasteoi_irq+0xc9/0x140 
[<ffffffff81004efe>] handle_irq+0x1e/0x30 
[<ffffffff8196bbcd>] do_IRQ+0x4d/0xc0 
[<ffffffff8184db80>] ? tcp_write_timer_handler+0x1d0/0x1d0 
[<ffffffff8196972a>] common_interrupt+0x6a/0x6a 
<EOI> 
[<ffffffff810515a6>] ? run_timer_softirq+0x1b6/0x300 
[<ffffffff810515f5>] ? run_timer_softirq+0x205/0x300 
[<ffffffff810495a2>] do_current_softirqs+0x182/0x340 
[<ffffffff8104999a>] run_ksoftirqd+0x2a/0x40 
[<ffffffff8106f4cc>] smpboot_thread_fn+0x1ec/0x360 
[<ffffffff81967630>] ? schedule+0x30/0x90 
[<ffffffff8106f2e0>] ? lg_local_unlock+0x30/0x30 
[<ffffffff81067442>] kthread+0xb2/0xc0 
[<ffffffff81067390>] ? kthread_worker_fn+0x1b0/0x1b0 
[<ffffffff8196a138>] ret_from_fork+0x58/0x90 
[<ffffffff81067390>] ? kthread_worker_fn+0x1b0/0x1b0 
Code: ff ff ff 31 d2 b9 01 00 00 00 48 89 df e8 24 df 73 ff 85 c0 0f 85 b4 01 00 00 48 8b 43 18 48 83 e0 fe 48 39 85 68 ff ff ff 75 02 <0f> 0b 4c 8b b5 68 ff ff ff 4c 8d ad 70 ff ff ff 4d 8d a6 f8 06 
RIP [<ffffffff81968475>] rt_spin_lock_slowlock+0x7c/0x277 
RSP <ffff88107fc03d40> 


Logs before the above crash: 

irq 16: nobody cared (try booting with the "irqpoll" option) 
CPU: 0 PID: 3 Comm: ksoftirqd/0 Tainted: G O 3.10.79-ovp-rt74-WR6.0.0.20_preempt-rt #1 
0000000000000010 ffff88107fc03e50 ffffffff81962b69 ffff88107fc03e78 
ffffffff810d8bdb ffff880ff4976c00 0000000000000010 0000000000000000 
ffff88107fc03eb8 ffffffff810d90f0 ffff88107fc03e98 0000000000000000 
Call Trace: 
<IRQ> [<ffffffff81962b69>] dump_stack+0x19/0x1b 
[<ffffffff810d8bdb>] __report_bad_irq+0x2b/0xd0 
[<ffffffff810d90f0>] note_interrupt+0x1d0/0x290 
[<ffffffff810d66c6>] handle_irq_event_percpu+0x126/0x290 
[<ffffffff810515a6>] ? run_timer_softirq+0x1b6/0x300 
[<ffffffff810d6898>] handle_irq_event+0x68/0x90 
[<ffffffff810d9d89>] handle_fasteoi_irq+0xc9/0x140 
[<ffffffff81004efe>] handle_irq+0x1e/0x30 
[<ffffffff8196bbcd>] do_IRQ+0x4d/0xc0 
[<ffffffff8184db80>] ? tcp_write_timer_handler+0x1d0/0x1d0 
[<ffffffff8196972a>] common_interrupt+0x6a/0x6a 
<EOI> [<ffffffff810515a6>] ? run_timer_softirq+0x1b6/0x300 
[<ffffffff810515f5>] ? run_timer_softirq+0x205/0x300 
[<ffffffff810495a2>] do_current_softirqs+0x182/0x340 
[<ffffffff8104999a>] run_ksoftirqd+0x2a/0x40 
[<ffffffff8106f4cc>] smpboot_thread_fn+0x1ec/0x360 
[<ffffffff81967630>] ? schedule+0x30/0x90 
[<ffffffff8106f2e0>] ? lg_local_unlock+0x30/0x30 
[<ffffffff81067442>] kthread+0xb2/0xc0 
[<ffffffff81067390>] ? kthread_worker_fn+0x1b0/0x1b0 
[<ffffffff8196a138>] ret_from_fork+0x58/0x90 
[<ffffffff81067390>] ? kthread_worker_fn+0x1b0/0x1b0 
handlers: 
[<ffffffff810d68c0>] irq_default_primary_handler threaded [<ffffffff81677710>] usb_hcd_irq 
[<ffffffffa07c5e80>] kvm_assigned_dev_intx [kvm] threaded [<ffffffffa07c6340>] kvm_assigned_dev_thread_intx [kvm] 
Disabling IRQ #16 
BUG: sleeping function called from invalid context at /b/rbu-builder/daily/vmhost/19/build-project/bitbake_build/tmp/work/intel_x86_64-wrs-linux/linux-windriver/3.10-r0/linux/kernel/rtmutex.c:796 
in_atomic(): 1, irqs_disabled(): 1, pid: 3, name: ksoftirqd/0 
Preemption disabled at:[<ffffffff8196bbae>] do_IRQ+0x2e/0xc0 

CPU: 0 PID: 3 Comm: ksoftirqd/0 Tainted: G O 3.10.79-ovp-rt74-WR6.0.0.20_preempt-rt #1 
ffffffff8208b300 ffff88107fc03dd0 ffffffff81962b69 ffff88107fc03de8 
ffffffff8107314f ffffffff8208b300 ffff88107fc03e00 ffffffff81968ea0 
ffffffff8208b300 ffff88107fc03e30 ffffffff81051727 ffffffff81e530c0 
Call Trace: 
<IRQ> [<ffffffff81962b69>] dump_stack+0x19/0x1b 
[<ffffffff8107314f>] __might_sleep+0xef/0x160 
[<ffffffff81968ea0>] rt_spin_lock+0x20/0x50 
[<ffffffff81051727>] lock_timer_base.isra.37+0x37/0x60 
[<ffffffff81051bd5>] mod_timer+0x75/0x290 
[<ffffffff810d912b>] note_interrupt+0x20b/0x290 
[<ffffffff810d66c6>] handle_irq_event_percpu+0x126/0x290 
[<ffffffff810515a6>] ? run_timer_softirq+0x1b6/0x300 
[<ffffffff810d6898>] handle_irq_event+0x68/0x90 
[<ffffffff810d9d89>] handle_fasteoi_irq+0xc9/0x140 
[<ffffffff81004efe>] handle_irq+0x1e/0x30 
[<ffffffff8196bbcd>] do_IRQ+0x4d/0xc0 
[<ffffffff8184db80>] ? tcp_write_timer_handler+0x1d0/0x1d0 
[<ffffffff8196972a>] common_interrupt+0x6a/0x6a 
<EOI> [<ffffffff810515a6>] ? run_timer_softirq+0x1b6/0x300 
[<ffffffff810515f5>] ? run_timer_softirq+0x205/0x300 
[<ffffffff810495a2>] do_current_softirqs+0x182/0x340 
[<ffffffff8104999a>] run_ksoftirqd+0x2a/0x40 
[<ffffffff8106f4cc>] smpboot_thread_fn+0x1ec/0x360 
[<ffffffff81967630>] ? schedule+0x30/0x90 
[<ffffffff8106f2e0>] ? lg_local_unlock+0x30/0x30 
[<ffffffff81067442>] kthread+0xb2/0xc0 
[<ffffffff81067390>] ? kthread_worker_fn+0x1b0/0x1b0 
[<ffffffff8196a138>] ret_from_fork+0x58/0x90 
[<ffffffff81067390>] ? kthread_worker_fn+0x1b0/0x1b0
----------------------------------------------------

Workaround

No.

Steps to Reproduce

In Preempt-RT kernel, add a little trick to make a fake "nobody cared irq" to let kernel goes into "note_interrupt" and call "mod_timer" in it. This issue can easily be reproduced.

Other Downloads


Live chat
Online