Re: Suspicious RCU usage in bridge with Linux v4.0-9362-g1fc149933fd4
On Thu, Apr 23, 2015 at 10:07 AM, Josh Boyer wrote:
> [ 29.382235] br0: port 1(tap0) entered forwarding state
>
> [ 29.382286] ===
> [ 29.382315] [ INFO: suspicious RCU usage. ]
> [ 29.382344] 4.1.0-0.rc0.git11.1.fc23.x86_64 #1 Not tainted
> [ 29.382380] ---
> [ 29.382409] net/bridge/br_private.h:626 suspicious
> rcu_dereference_check() usage!
> [ 29.382455]
>other info that might help us debug this:
>
> [ 29.382507]
>rcu_scheduler_active = 1, debug_locks = 0
> [ 29.382549] 2 locks held by swapper/0/0:
> [ 29.382576] #0: (((&p->forward_delay_timer))){+.-...}, at:
> [] call_timer_fn+0x5/0x4f0
> [ 29.382660] #1: (&(&br->lock)->rlock){+.-...}, at:
> [] br_forward_delay_timer_expired+0x31/0x140
> [bridge]
> [ 29.382754]
>stack backtrace:
> [ 29.382787] CPU: 0 PID: 0 Comm: swapper/0 Not tainted
> 4.1.0-0.rc0.git11.1.fc23.x86_64 #1
> [ 29.382838] Hardware name: LENOVO 422916G/LENOVO, BIOS A1KT53AUS 04/07/2015
> [ 29.382882] 3ebfc20364115825 88003c48
> 81892d4b
> [ 29.382943] 81e124e0 88003c78
> 8110bcd7
> [ 29.383004] 8800785c9d00 88065485ac58 880c62002800
> 880c5fc88ac0
> [ 29.383065] Call Trace:
> [ 29.383084][] dump_stack+0x4c/0x65
> [ 29.383130] [] lockdep_rcu_suspicious+0xe7/0x120
> [ 29.383178] [] br_fill_ifinfo+0x4a9/0x6a0 [bridge]
> [ 29.383225] [] br_ifinfo_notify+0x11b/0x4b0 [bridge]
> [ 29.383271] [] ? br_hold_timer_expired+0x70/0x70
> [bridge]
> [ 29.383320] []
> br_forward_delay_timer_expired+0x58/0x140 [bridge]
> [ 29.383371] [] ? br_hold_timer_expired+0x70/0x70
> [bridge]
> [ 29.383416] [] call_timer_fn+0xc3/0x4f0
> [ 29.383454] [] ? call_timer_fn+0x5/0x4f0
> [ 29.383493] [] ? lock_release_holdtime.part.29+0xf/0x200
> [ 29.383541] [] ? br_hold_timer_expired+0x70/0x70
> [bridge]
> [ 29.383587] [] run_timer_softirq+0x244/0x490
> [ 29.383629] [] __do_softirq+0xec/0x670
> [ 29.383666] [] irq_exit+0x145/0x150
> [ 29.383703] [] smp_apic_timer_interrupt+0x46/0x60
> [ 29.383744] [] apic_timer_interrupt+0x73/0x80
> [ 29.383782][] ? cpuidle_enter_state+0x5f/0x2f0
> [ 29.383832] [] ? cpuidle_enter_state+0x5b/0x2f0
> [ 29.383873] [] cpuidle_enter+0x17/0x20
> [ 29.383908] [] cpu_startup_entry+0x36f/0x5f0
> [ 29.383949] [] rest_init+0x13d/0x150
> [ 29.383986] [] start_kernel+0x4d2/0x4f3
> [ 29.384023] [] ? early_idt_handlers+0x120/0x120
> [ 29.384064] [] x86_64_start_reservations+0x2a/0x2c
> [ 29.384105] [] x86_64_start_kernel+0x14a/0x16d
We are dereferencing a RCU pointer with rtnl assert, but in the timer context
we only have br->lock. It looks like we need to take RCU read lock on that path
rather than asserting rtnl lock.
Thanks for the report.
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: Suspicious RCU usage in bridge with Linux v4.0-9362-g1fc149933fd4
On Thu, Apr 23, 2015 at 6:07 PM, Josh Boyer wrote: > Hi All, > > We've had a user report the following backtrace from the bridge module > with a recent Linus' tree. Has anything like this been reported yet? > If you have any questions on setup, the user is CC'd. > I too observed similar backtrace once(not able to reproduce it again) while I was trying to check inconsistent lock state[1] with lockdep enabled. Regards, Sudeep [1] https://lkml.org/lkml/2015/4/23/329 --->8 === [ INFO: suspicious RCU usage. ] 4.0.0 #269 Not tainted --- include/trace/events/ipi.h:68 suspicious rcu_dereference_check() usage! other info that might help us debug this: RCU used illegally from idle CPU! rcu_scheduler_active = 1, debug_locks = 1 RCU used illegally from extended quiescent state! no locks held by swapper/0/0. stack backtrace: CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.0.0 #269 Hardware name: ARM-Versatile Express [] (unwind_backtrace) from [] (show_stack+0x11/0x14) [] (show_stack) from [] (dump_stack+0x73/0x8c) [] (dump_stack) from [] (handle_IPI+0x257/0x410) [] (handle_IPI) from [] (gic_handle_irq+0x4f/0x50) [] (gic_handle_irq) from [] (__irq_svc+0x3f/0x64) Exception stack(0xc083bf30 to 0xc083bf78) bf20: 0001 0001 c0841938 bf40: c083a000 c083d5fc c08ba5c8 c083d598 c08b938f c056afc8 bf60: 0008 c083bf78 c005d157 c000f288 4133 [] (__irq_svc) from [] (arch_cpu_idle+0x30/0x34) [] (arch_cpu_idle) from [] (cpu_startup_entry+0x339/0x404) [] (cpu_startup_entry) from [] (start_kernel+0x32f/0x338) [] (start_kernel) from [<8000807f>] (0x8000807f) === [ INFO: suspicious RCU usage. ] 4.0.0 #269 Not tainted --- include/trace/events/ipi.h:84 suspicious rcu_dereference_check() usage! other info that might help us debug this: RCU used illegally from idle CPU! rcu_scheduler_active = 1, debug_locks = 1 RCU used illegally from extended quiescent state! no locks held by swapper/0/0. stack backtrace: CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.0.0 #269 Hardware name: ARM-Versatile Express [] (unwind_backtrace) from [] (show_stack+0x11/0x14) [] (show_stack) from [] (dump_stack+0x73/0x8c) [] (dump_stack) from [] (handle_IPI+0x379/0x410) [] (handle_IPI) from [] (gic_handle_irq+0x4f/0x50) [] (gic_handle_irq) from [] (__irq_svc+0x3f/0x64) Exception stack(0xc083bf30 to 0xc083bf78) bf20: 0001 0001 c0841938 bf40: c083a000 c083d5fc c08ba5c8 c083d598 c08b938f c056afc8 bf60: 0008 c083bf78 c005d157 c000f288 4133 [] (__irq_svc) from [] (arch_cpu_idle+0x30/0x34) [] (arch_cpu_idle) from [] (cpu_startup_entry+0x339/0x404) [] (cpu_startup_entry) from [] (start_kernel+0x32f/0x338) [] (start_kernel) from [<8000807f>] (0x8000807f) -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Suspicious RCU usage in bridge with Linux v4.0-9362-g1fc149933fd4
Hi All,
We've had a user report the following backtrace from the bridge module
with a recent Linus' tree. Has anything like this been reported yet?
If you have any questions on setup, the user is CC'd.
josh
[ 29.382235] br0: port 1(tap0) entered forwarding state
[ 29.382286] ===
[ 29.382315] [ INFO: suspicious RCU usage. ]
[ 29.382344] 4.1.0-0.rc0.git11.1.fc23.x86_64 #1 Not tainted
[ 29.382380] ---
[ 29.382409] net/bridge/br_private.h:626 suspicious
rcu_dereference_check() usage!
[ 29.382455]
other info that might help us debug this:
[ 29.382507]
rcu_scheduler_active = 1, debug_locks = 0
[ 29.382549] 2 locks held by swapper/0/0:
[ 29.382576] #0: (((&p->forward_delay_timer))){+.-...}, at:
[] call_timer_fn+0x5/0x4f0
[ 29.382660] #1: (&(&br->lock)->rlock){+.-...}, at:
[] br_forward_delay_timer_expired+0x31/0x140
[bridge]
[ 29.382754]
stack backtrace:
[ 29.382787] CPU: 0 PID: 0 Comm: swapper/0 Not tainted
4.1.0-0.rc0.git11.1.fc23.x86_64 #1
[ 29.382838] Hardware name: LENOVO 422916G/LENOVO, BIOS A1KT53AUS 04/07/2015
[ 29.382882] 3ebfc20364115825 88003c48
81892d4b
[ 29.382943] 81e124e0 88003c78
8110bcd7
[ 29.383004] 8800785c9d00 88065485ac58 880c62002800
880c5fc88ac0
[ 29.383065] Call Trace:
[ 29.383084][] dump_stack+0x4c/0x65
[ 29.383130] [] lockdep_rcu_suspicious+0xe7/0x120
[ 29.383178] [] br_fill_ifinfo+0x4a9/0x6a0 [bridge]
[ 29.383225] [] br_ifinfo_notify+0x11b/0x4b0 [bridge]
[ 29.383271] [] ? br_hold_timer_expired+0x70/0x70 [bridge]
[ 29.383320] []
br_forward_delay_timer_expired+0x58/0x140 [bridge]
[ 29.383371] [] ? br_hold_timer_expired+0x70/0x70 [bridge]
[ 29.383416] [] call_timer_fn+0xc3/0x4f0
[ 29.383454] [] ? call_timer_fn+0x5/0x4f0
[ 29.383493] [] ? lock_release_holdtime.part.29+0xf/0x200
[ 29.383541] [] ? br_hold_timer_expired+0x70/0x70 [bridge]
[ 29.383587] [] run_timer_softirq+0x244/0x490
[ 29.383629] [] __do_softirq+0xec/0x670
[ 29.383666] [] irq_exit+0x145/0x150
[ 29.383703] [] smp_apic_timer_interrupt+0x46/0x60
[ 29.383744] [] apic_timer_interrupt+0x73/0x80
[ 29.383782][] ? cpuidle_enter_state+0x5f/0x2f0
[ 29.383832] [] ? cpuidle_enter_state+0x5b/0x2f0
[ 29.383873] [] cpuidle_enter+0x17/0x20
[ 29.383908] [] cpu_startup_entry+0x36f/0x5f0
[ 29.383949] [] rest_init+0x13d/0x150
[ 29.383986] [] start_kernel+0x4d2/0x4f3
[ 29.384023] [] ? early_idt_handlers+0x120/0x120
[ 29.384064] [] x86_64_start_reservations+0x2a/0x2c
[ 29.384105] [] x86_64_start_kernel+0x14a/0x16d
[ 36.100347] IN=br0 OUT=
MAC=33:33:00:00:00:02:52:54:00:12:01:00:86:dd
SRC=fe80::::5054:00ff:fe12:0100
DST=ff02:::::::0002 LEN=56 TC=0 HOPLIMIT=255
FLOWLBL=0 PROTO=ICMPv6 TYPE=133 CODE=0
[ 40.113744] IN=br0 OUT=
MAC=33:33:00:00:00:02:52:54:00:12:01:00:86:dd
SRC=fe80::::5054:00ff:fe12:0100
DST=ff02:::::::0002 LEN=56 TC=0 HOPLIMIT=255
FLOWLBL=0 PROTO=ICMPv6 TYPE=133 CODE=0
[ 44.119727] IN=br0 OUT=
MAC=33:33:00:00:00:02:52:54:00:12:01:00:86:dd
SRC=fe80::::5054:00ff:fe12:0100
DST=ff02:::::::0002 LEN=56 TC=0 HOPLIMIT=255
FLOWLBL=0 PROTO=ICMPv6 TYPE=133 CODE=0
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
