On Wed, Dec 04, 2019 at 05:19:11PM +0000, John Garry wrote:
> Hi Corey,
>
> I'm booting an allmodconfig kernel on my arm64 system from recent Linus'
> master branch, and I see this:
I've looked at this for a bit. For the second warning, it looks like I
need to add an srcu_read_lock() around that loop.
For the first warning (line 744) I'm not sure. There is an
srcu_read_lock() right before this, so I'm not sure why this would be
happening.
I'm trying to reproduce now.
-corey
>
> [ 188.241001][ T1] IPMI message handler: version 39.2
> [ 188.247331][ T1] ipmi device interface
> [ 188.256271][ T1]
> [ 188.258541][ T1] =============================
> [ 188.263388][ T1] WARNING: suspicious RCU usage
> [ 188.268236][ T1] 5.4.0+ #1416 Not tainted
> [ 188.272645][ T1] -----------------------------
> [ 188.277496][ T1] drivers/char/ipmi/ipmi_msghandler.c:744 RCU-list
> traversed in non-reader section!!
> [ 188.286971][ T1]
> [ 188.286971][ T1] other info that might help us debug this:
> [ 188.286971][ T1]
> [ 188.297235][ T1]
> [ 188.297235][ T1] rcu_scheduler_active = 2, debug_locks = 1
> [ 188.305314][ T1] 2 locks held by swapper/0/1:
> [ 188.310072][ T1] #0: ffffffd0149687f0 (smi_watchers_mutex){+.+.}, at:
> ipmi_smi_watcher_register+0x5c/0x248
> [ 188.320295][ T1] #1: ffffffd016c9aff8 (&ipmi_interfaces_srcu){....},
> at: ipmi_smi_watcher_register+0xa8/0x248
> [ 188.330771][ T1]
> [ 188.330771][ T1] stack backtrace:
> [ 188.336671][ T1] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 5.4.0+
> #1416
> [ 188.343604][ T1] Hardware name: Huawei Taishan 2280 /D05, BIOS
> Hisilicon D05 IT21 Nemo 2.0 RC0 04/18/2018
> [ 188.353506][ T1] Call trace:
> [ 188.356688][ T1] dump_backtrace+0x0/0x3a0
> [ 188.361089][ T1] show_stack+0x28/0x38
> [ 188.365142][ T1] dump_stack+0x1ac/0x23c
> [ 188.369371][ T1] lockdep_rcu_suspicious+0x100/0x118
> [ 188.374646][ T1] ipmi_smi_watcher_register+0x134/0x248
> [ 188.380185][ T1] init_ipmi_devintf+0xec/0x140
> [ 188.384936][ T1] do_one_initcall+0x2f8/0x710
> [ 188.389600][ T1] kernel_init_freeable+0x304/0x3dc
> [ 188.394701][ T1] kernel_init+0x20/0x180
> [ 188.398928][ T1] ret_from_fork+0x10/0x18
> [ 188.403333][ T1] ipmi_si: IPMI System Interface driver
> [ 188.411646][ T1] ipmi_si hisi-lpc-ipmi.5.auto: ipmi_platform: probing
> via ACPI
> [ 188.421958][ T1] ipmi_si hisi-lpc-ipmi.5.auto: IRQ index 0 not found
> [ 188.428737][ T1] ipmi_si hisi-lpc-ipmi.5.auto: ipmi_platform: [io
> 0xffc0e3-0xffc0e7] regsize 1 spacing 1 irq 0
> [ 188.439386][ T1] ipmi_si: Adding ACPI-specified bt state machine
> [ 188.448341][ T1] kobject: 'wakeup' ((____ptrval____)):
> kobject_release, parent (____ptrval____) (delayed 1000)
> [ 188.458824][ T1] kobject: 'wakeup20' ((____ptrval____)):
> kobject_release, parent (____ptrval____) (delayed 250)
> [ 188.471778][ T1] ipmi_si hisi-lpc-ipmi.5.auto: ipmi_platform: probing
> via ACPI
> [ 188.481621][ T1] ipmi_si hisi-lpc-ipmi.5.auto: IRQ index 0 not found
> [ 188.488390][ T1] ipmi_si hisi-lpc-ipmi.5.auto: ipmi_platform: [io
> 0xffc0e3-0xffc0e7] regsize 1 spacing 1 irq 0
> [ 188.498936][ T1] ipmi_si: Adding ACPI-specified bt state machine
> [ 188.507082][ T1] ipmi_si: Trying ACPI-specified bt state machine at
> i/o address 0xffc0e3, slave address 0x0, irq 0
> [ 188.524402][ T1] ipmi_si hisi-lpc-ipmi.5.auto: bt cap response too
> short: 3
> [ 188.531809][ T1] ipmi_si hisi-lpc-ipmi.5.auto: using default values
> [ 188.538483][ T1] ipmi_si hisi-lpc-ipmi.5.auto: req2rsp=5 secs
> retries=2
> [ 188.572794][ T1]
> [ 188.575080][ T1] =============================
> [ 188.579930][ T1] WARNING: suspicious RCU usage
> [ 188.584797][ T1] 5.4.0+ #1416 Not tainted
> [ 188.589206][ T1] -----------------------------
> [ 188.594055][ T1] drivers/char/ipmi/ipmi_msghandler.c:3453 RCU-list
> traversed in non-reader section!!
> [ 188.603617][ T1]
> [ 188.603617][ T1] other info that might help us debug this:
> [ 188.603617][ T1]
> [ 188.613884][ T1]
> [ 188.613884][ T1] rcu_scheduler_active = 2, debug_locks = 1
> [ 188.621945][ T1] 2 locks held by swapper/0/1:
> [ 188.626704][ T1] #0: ffffffd01496c8f0 (smi_infos_lock){+.+.}, at:
> init_ipmi_si+0x78/0x24c
> [ 188.635436][ T1] #1: ffffffd0149689b0 (ipmi_interfaces_mutex){+.+.},
> at: ipmi_add_smi+0x5e4/0xae0
> [ 188.644864][ T1]
> [ 188.644864][ T1] stack backtrace:
> [ 188.650765][ T1] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 5.4.0+
> #1416
> [ 188.657698][ T1] Hardware name: Huawei Taishan 2280 /D05, BIOS
> Hisilicon D05 IT21 Nemo 2.0 RC0 04/18/2018
> [ 188.667598][ T1] Call trace:
> [ 188.670777][ T1] dump_backtrace+0x0/0x3a0
> [ 188.675178][ T1] show_stack+0x28/0x38
> [ 188.679230][ T1] dump_stack+0x1ac/0x23c
> [ 188.683458][ T1] lockdep_rcu_suspicious+0x100/0x118
> [ 188.688726][ T1] ipmi_add_smi+0x630/0xae0
> [ 188.688745][ T1] try_smi_init+0xdbc/0xf18
> [ 188.688759][ T1] init_ipmi_si+0x14c/0x24c
> [ 188.688773][ T1] do_one_initcall+0x2f8/0x710
> [ 188.688787][ T1] kernel_init_freeable+0x304/0x3dc
> [ 188.688802][ T1] kernel_init+0x20/0x180
> [ 188.688815][ T1] ret_from_fork+0x10/0x18
> [ 188.731333][ T1] ipmi_si hisi-lpc-ipmi.5.auto: IPMI message handler:
> Found new BMC (man_id: 0x0007db, prod_id: 0x0001, dev_id: 0x01)
> [ 188.935301][ T1] ipmi_si hisi-lpc-ipmi.5.auto: IPMI bt interface
> initialized
> [ 188.942797][ T1] ipmi_ssif: IPMI SSIF Interface driver
>
> In the code we seem to be using srcu read lock instead of rcu read lock for
> list iteration protection, but that's a quick analysis. And there is also a
> mutex locked in ipmi_smi_watcher_register() [didn't check the other case],
> so I wonder if rcu list iterator variant is required at all.
>
> Apologies if this has been reported previously. I see that Anders (cc'ed)
> has been reporting some of these sorts of issues.
>
> Thanks,
> John
_______________________________________________
Openipmi-developer mailing list
Openipmi-developer@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/openipmi-developer
