Re: inconsistent lock state with usbnet/asix usb ethernet and xhci
On Mon, 2018-03-05 at 12:46 +0100, Oliver Neukum wrote: > On Mon, 2018-03-05 at 08:45 +0100, Marek Szyprowski wrote: > > Hi Oliver, > > > > On 2018-02-27 17:07, Oliver Neukum wrote: > > > Am Dienstag, den 27.02.2018, 07:13 -0800 schrieb Eric Dumazet: > > > > On Tue, 2018-02-27 at 07:09 -0800, Eric Dumazet wrote: > > > > > > > > > > Note that for this one, it seems we also could perform stats > > > > > updates in > > > > > BH context, since skb is queued via defer_bh() > > > > > > > > > > But simplicity wins I guess. > > > > > > > > Thinking more about this, I am not sure we have any guarantee > > > > that TX > > > > and RX can not run on multiple cpus. > > > > > > > > Using an unique syncp is not going to be safe, even if we make > > > > lockdep > > > > happy enough with the local_irq save/restore. > > > > > > Unfortunately you are right. It is not guaranteed for some > > > hardware. > > > > Does it mean that the fix proposed by Eric is not the proper > > solution? > > For asix it should work, but asix is unlikely to be the only driver > with that issue. 32 bit recieves less testing nowadays. Yes, although the lockdep part could be enforced in 64bit if we really care. I will send a patch using two different sync (one for RX, one for TX)
Re: inconsistent lock state with usbnet/asix usb ethernet and xhci
On Mon, 2018-03-05 at 08:45 +0100, Marek Szyprowski wrote: > Hi Oliver, > > On 2018-02-27 17:07, Oliver Neukum wrote: > > Am Dienstag, den 27.02.2018, 07:13 -0800 schrieb Eric Dumazet: > >> On Tue, 2018-02-27 at 07:09 -0800, Eric Dumazet wrote: > >>> > >>> Note that for this one, it seems we also could perform stats updates in > >>> BH context, since skb is queued via defer_bh() > >>> > >>> But simplicity wins I guess. > >> Thinking more about this, I am not sure we have any guarantee that TX > >> and RX can not run on multiple cpus. > >> > >> Using an unique syncp is not going to be safe, even if we make lockdep > >> happy enough with the local_irq save/restore. > > Unfortunately you are right. It is not guaranteed for some hardware. > > Does it mean that the fix proposed by Eric is not the proper solution? For asix it should work, but asix is unlikely to be the only driver with that issue. 32 bit recieves less testing nowadays. Regards Oliver
Re: inconsistent lock state with usbnet/asix usb ethernet and xhci
Hi Oliver, On 2018-02-27 17:07, Oliver Neukum wrote: Am Dienstag, den 27.02.2018, 07:13 -0800 schrieb Eric Dumazet: On Tue, 2018-02-27 at 07:09 -0800, Eric Dumazet wrote: Note that for this one, it seems we also could perform stats updates in BH context, since skb is queued via defer_bh() But simplicity wins I guess. Thinking more about this, I am not sure we have any guarantee that TX and RX can not run on multiple cpus. Using an unique syncp is not going to be safe, even if we make lockdep happy enough with the local_irq save/restore. Unfortunately you are right. It is not guaranteed for some hardware. Does it mean that the fix proposed by Eric is not the proper solution? Best regards -- Marek Szyprowski, PhD Samsung R&D Institute Poland
Re: inconsistent lock state with usbnet/asix usb ethernet and xhci
Am Dienstag, den 27.02.2018, 07:13 -0800 schrieb Eric Dumazet: > On Tue, 2018-02-27 at 07:09 -0800, Eric Dumazet wrote: > > > > > > Note that for this one, it seems we also could perform stats updates in > > BH context, since skb is queued via defer_bh() > > > > But simplicity wins I guess. > > Thinking more about this, I am not sure we have any guarantee that TX > and RX can not run on multiple cpus. > > Using an unique syncp is not going to be safe, even if we make lockdep > happy enough with the local_irq save/restore. Unfortunately you are right. It is not guaranteed for some hardware. Regards Oliver
Re: inconsistent lock state with usbnet/asix usb ethernet and xhci
On Tue, 2018-02-27 at 07:09 -0800, Eric Dumazet wrote: > > Note that for this one, it seems we also could perform stats updates in > BH context, since skb is queued via defer_bh() > > But simplicity wins I guess. Thinking more about this, I am not sure we have any guarantee that TX and RX can not run on multiple cpus. Using an unique syncp is not going to be safe, even if we make lockdep happy enough with the local_irq save/restore.
Re: inconsistent lock state with usbnet/asix usb ethernet and xhci
On Tue, 2018-02-27 at 15:42 +0100, Marek Szyprowski wrote: > Hi Eric, > > On 2018-02-27 15:07, Eric Dumazet wrote: > > On Tue, 2018-02-27 at 08:26 +0100, Marek Szyprowski wrote: > > > I've noticed that USBnet/ASIX AX88772B USB driver produces deplock kernel > > > warning ("inconsistent lock state") on Chromebook2 Peach-PIT board. No > > > special activity is needed to reproduce this issue, it happens almost > > > on every boot. ASIX USB ethernet is connected to XHCI USB host controller > > > on that board. Is it a known issue? Frankly I have no idea where to look > > > to fix it. The same adapter connected to EHCI ports on other boards based > > > on the same SoC works fine without any warnings. > > > > > > Here are some more information from that board: > > > # lsusb > > > Bus 006 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub > > > Bus 005 Device 002: ID 0b95:772b ASIX Electronics Corp. AX88772B > > > Bus 005 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub > > > Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub > > > Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub > > > Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub > > > Bus 001 Device 002: ID 2232:1056 Silicon Motion > > > Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub > > > > > > # lsusb -t > > > /: Bus 06.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M > > > /: Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 480M > > > |__ Port 1: Dev 2, If 0, Class=Vendor Specific Class, Driver=asix, > > > 480M > > > /: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M > > > /: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 480M > > > /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=exynos-ohci/3p, 12M > > > /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=exynos-ehci/3p, 480M > > > |__ Port 1: Dev 2, If 0, Class=Video, Driver=, 480M > > > |__ Port 1: Dev 2, If 1, Class=Video, Driver=, 480M > > > > > > > > > And the log with mentioned warning: > > > > > > [ 17.768040] > > > [ 17.772239] WARNING: inconsistent lock state > > > [ 17.776511] 4.16.0-rc3-next-20180227-7-g876c53a7493c #453 Not > > > tainted > > > [ 17.783329] > > > [ 17.787580] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. > > > [ 17.793607] swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes: > > > [ 17.798751] (&syncp->seq#5){?.-.}, at: [<9b22e5f0>] > > > asix_rx_fixup_internal+0x188/0x288 > > > [ 17.806790] {IN-HARDIRQ-W} state was registered at: > > > [ 17.811677] tx_complete+0x100/0x208 > > > [ 17.815319] __usb_hcd_giveback_urb+0x60/0xf0 > > > [ 17.819770] xhci_giveback_urb_in_irq+0xa8/0x240 > > > [ 17.824469] xhci_td_cleanup+0xf4/0x16c > > > [ 17.828367] xhci_irq+0xe74/0x2240 > > > [ 17.831827] usb_hcd_irq+0x24/0x38 > > > [ 17.835343] __handle_irq_event_percpu+0x98/0x510 > > > [ 17.840111] handle_irq_event_percpu+0x1c/0x58 > > > [ 17.844623] handle_irq_event+0x38/0x5c > > > [ 17.848519] handle_fasteoi_irq+0xa4/0x138 > > > [ 17.852681] generic_handle_irq+0x18/0x28 > > > [ 17.856760] __handle_domain_irq+0x6c/0xe4 > > > [ 17.860941] gic_handle_irq+0x54/0xa0 > > > [ 17.864666] __irq_svc+0x70/0xb0 > > > [ 17.867964] arch_cpu_idle+0x20/0x3c > > > [ 17.871578] arch_cpu_idle+0x20/0x3c > > > [ 17.875190] do_idle+0x144/0x218 > > > [ 17.878468] cpu_startup_entry+0x18/0x1c > > > [ 17.882454] start_kernel+0x394/0x400 > > > [ 17.886177] irq event stamp: 161912 > > > [ 17.889616] hardirqs last enabled at (161912): [<7bedfacf>] > > > __netdev_alloc_skb+0xcc/0x140 > > > [ 17.897893] hardirqs last disabled at (161911): [] > > > __netdev_alloc_skb+0x94/0x140 > > > [ 17.904903] exynos5-hsi2c 12ca.i2c: tx timeout > > > [ 17.906116] softirqs last enabled at (161904): [<387102ff>] > > > irq_enter+0x78/0x80 > > > [ 17.906123] softirqs last disabled at (161905): [] > > > irq_exit+0x134/0x158 > > > [ 17.925722]. > > > [ 17.925722] other info that might help us debug this: > > > [ 17.933435] Possible unsafe locking scenario: > > > [ 17.933435]. > > > [ 17.940331] CPU0 > > > [ 17.942488] > > > [ 17.944894] lock(&syncp->seq#5); > > > [ 17.948274] > > > [ 17.950847] lock(&syncp->seq#5); > > > [ 17.954386]. > > > [ 17.954386] *** DEADLOCK *** > > > [ 17.954386]. > > > [ 17.962422] no locks held by swapper/0/0. > > > [ 17.966011]. > > > [ 17.966011] stack backtrace: > > > [ 17.971333] CPU: 0 PID: 0 Comm: swapper/0 Not tainted > > > 4.16.0-rc3-next-20180227-7-g876c53a7493c #453 > > > [ 17.980312] Hardware name: SAMSUNG EXYNOS (Flattened Device Tree) > > > [ 17.986380] [] (unwind_backtrace) from [] > > > (show_stack+0x10/0x14) > > > [ 17.994128] [] (show_stack) from [] > > > (dump_stack+0x90/0xc8) > > > [ 18.001339] [] (dump_stack) from []
Re: inconsistent lock state with usbnet/asix usb ethernet and xhci
Hi Eric, On 2018-02-27 15:07, Eric Dumazet wrote: On Tue, 2018-02-27 at 08:26 +0100, Marek Szyprowski wrote: I've noticed that USBnet/ASIX AX88772B USB driver produces deplock kernel warning ("inconsistent lock state") on Chromebook2 Peach-PIT board. No special activity is needed to reproduce this issue, it happens almost on every boot. ASIX USB ethernet is connected to XHCI USB host controller on that board. Is it a known issue? Frankly I have no idea where to look to fix it. The same adapter connected to EHCI ports on other boards based on the same SoC works fine without any warnings. Here are some more information from that board: # lsusb Bus 006 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub Bus 005 Device 002: ID 0b95:772b ASIX Electronics Corp. AX88772B Bus 005 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub Bus 001 Device 002: ID 2232:1056 Silicon Motion Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub # lsusb -t /: Bus 06.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M /: Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 480M |__ Port 1: Dev 2, If 0, Class=Vendor Specific Class, Driver=asix, 480M /: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M /: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 480M /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=exynos-ohci/3p, 12M /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=exynos-ehci/3p, 480M |__ Port 1: Dev 2, If 0, Class=Video, Driver=, 480M |__ Port 1: Dev 2, If 1, Class=Video, Driver=, 480M And the log with mentioned warning: [ 17.768040] [ 17.772239] WARNING: inconsistent lock state [ 17.776511] 4.16.0-rc3-next-20180227-7-g876c53a7493c #453 Not tainted [ 17.783329] [ 17.787580] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. [ 17.793607] swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes: [ 17.798751] (&syncp->seq#5){?.-.}, at: [<9b22e5f0>] asix_rx_fixup_internal+0x188/0x288 [ 17.806790] {IN-HARDIRQ-W} state was registered at: [ 17.811677] tx_complete+0x100/0x208 [ 17.815319] __usb_hcd_giveback_urb+0x60/0xf0 [ 17.819770] xhci_giveback_urb_in_irq+0xa8/0x240 [ 17.824469] xhci_td_cleanup+0xf4/0x16c [ 17.828367] xhci_irq+0xe74/0x2240 [ 17.831827] usb_hcd_irq+0x24/0x38 [ 17.835343] __handle_irq_event_percpu+0x98/0x510 [ 17.840111] handle_irq_event_percpu+0x1c/0x58 [ 17.844623] handle_irq_event+0x38/0x5c [ 17.848519] handle_fasteoi_irq+0xa4/0x138 [ 17.852681] generic_handle_irq+0x18/0x28 [ 17.856760] __handle_domain_irq+0x6c/0xe4 [ 17.860941] gic_handle_irq+0x54/0xa0 [ 17.864666] __irq_svc+0x70/0xb0 [ 17.867964] arch_cpu_idle+0x20/0x3c [ 17.871578] arch_cpu_idle+0x20/0x3c [ 17.875190] do_idle+0x144/0x218 [ 17.878468] cpu_startup_entry+0x18/0x1c [ 17.882454] start_kernel+0x394/0x400 [ 17.886177] irq event stamp: 161912 [ 17.889616] hardirqs last enabled at (161912): [<7bedfacf>] __netdev_alloc_skb+0xcc/0x140 [ 17.897893] hardirqs last disabled at (161911): [] __netdev_alloc_skb+0x94/0x140 [ 17.904903] exynos5-hsi2c 12ca.i2c: tx timeout [ 17.906116] softirqs last enabled at (161904): [<387102ff>] irq_enter+0x78/0x80 [ 17.906123] softirqs last disabled at (161905): [] irq_exit+0x134/0x158 [ 17.925722]. [ 17.925722] other info that might help us debug this: [ 17.933435] Possible unsafe locking scenario: [ 17.933435]. [ 17.940331] CPU0 [ 17.942488] [ 17.944894] lock(&syncp->seq#5); [ 17.948274] [ 17.950847] lock(&syncp->seq#5); [ 17.954386]. [ 17.954386] *** DEADLOCK *** [ 17.954386]. [ 17.962422] no locks held by swapper/0/0. [ 17.966011]. [ 17.966011] stack backtrace: [ 17.971333] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.16.0-rc3-next-20180227-7-g876c53a7493c #453 [ 17.980312] Hardware name: SAMSUNG EXYNOS (Flattened Device Tree) [ 17.986380] [] (unwind_backtrace) from [] (show_stack+0x10/0x14) [ 17.994128] [] (show_stack) from [] (dump_stack+0x90/0xc8) [ 18.001339] [] (dump_stack) from [] (print_usage_bug+0x25c/0x2cc) [ 18.009161] [] (print_usage_bug) from [] (mark_lock+0x290/0x698) [ 18.014952] exynos5-hsi2c 12ca.i2c: tx timeout [ 18.016899] [] (mark_lock) from [] (__lock_acquire+0x454/0x1850) [ 18.029449] [] (__lock_acquire) from [] (lock_acquire+0xc8/0x2b8) [ 18.037272] [] (lock_acquire) from [] (usbnet_skb_return+0x7c/0x1a0) [ 18.045356] [] (usbnet_skb_return) from [] (asix_rx_fixup_internal+0x188/0x288) [ 18.054420] [] (asix_rx_fixup_internal) from [] (usbnet_bh+0xf8/0x2e4) [ 18.062694] [] (usbnet_bh) from [] (tasklet_action+0x8c/0x13c) [ 18.070259] [] (tasklet_action) from [] (__do_softirq+0xd
Re: inconsistent lock state with usbnet/asix usb ethernet and xhci
On Tue, 2018-02-27 at 08:26 +0100, Marek Szyprowski wrote: > Hi > > I've noticed that USBnet/ASIX AX88772B USB driver produces deplock kernel > warning ("inconsistent lock state") on Chromebook2 Peach-PIT board. No > special activity is needed to reproduce this issue, it happens almost > on every boot. ASIX USB ethernet is connected to XHCI USB host controller > on that board. Is it a known issue? Frankly I have no idea where to look > to fix it. The same adapter connected to EHCI ports on other boards based > on the same SoC works fine without any warnings. > > Here are some more information from that board: > # lsusb > Bus 006 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub > Bus 005 Device 002: ID 0b95:772b ASIX Electronics Corp. AX88772B > Bus 005 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub > Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub > Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub > Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub > Bus 001 Device 002: ID 2232:1056 Silicon Motion > Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub > > # lsusb -t > /: Bus 06.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M > /: Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 480M > |__ Port 1: Dev 2, If 0, Class=Vendor Specific Class, Driver=asix, 480M > /: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M > /: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 480M > /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=exynos-ohci/3p, 12M > /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=exynos-ehci/3p, 480M > |__ Port 1: Dev 2, If 0, Class=Video, Driver=, 480M > |__ Port 1: Dev 2, If 1, Class=Video, Driver=, 480M > > > And the log with mentioned warning: > > [ 17.768040] > [ 17.772239] WARNING: inconsistent lock state > [ 17.776511] 4.16.0-rc3-next-20180227-7-g876c53a7493c #453 Not tainted > [ 17.783329] > [ 17.787580] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. > [ 17.793607] swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes: > [ 17.798751] (&syncp->seq#5){?.-.}, at: [<9b22e5f0>] > asix_rx_fixup_internal+0x188/0x288 > [ 17.806790] {IN-HARDIRQ-W} state was registered at: > [ 17.811677] tx_complete+0x100/0x208 > [ 17.815319] __usb_hcd_giveback_urb+0x60/0xf0 > [ 17.819770] xhci_giveback_urb_in_irq+0xa8/0x240 > [ 17.824469] xhci_td_cleanup+0xf4/0x16c > [ 17.828367] xhci_irq+0xe74/0x2240 > [ 17.831827] usb_hcd_irq+0x24/0x38 > [ 17.835343] __handle_irq_event_percpu+0x98/0x510 > [ 17.840111] handle_irq_event_percpu+0x1c/0x58 > [ 17.844623] handle_irq_event+0x38/0x5c > [ 17.848519] handle_fasteoi_irq+0xa4/0x138 > [ 17.852681] generic_handle_irq+0x18/0x28 > [ 17.856760] __handle_domain_irq+0x6c/0xe4 > [ 17.860941] gic_handle_irq+0x54/0xa0 > [ 17.864666] __irq_svc+0x70/0xb0 > [ 17.867964] arch_cpu_idle+0x20/0x3c > [ 17.871578] arch_cpu_idle+0x20/0x3c > [ 17.875190] do_idle+0x144/0x218 > [ 17.878468] cpu_startup_entry+0x18/0x1c > [ 17.882454] start_kernel+0x394/0x400 > [ 17.886177] irq event stamp: 161912 > [ 17.889616] hardirqs last enabled at (161912): [<7bedfacf>] > __netdev_alloc_skb+0xcc/0x140 > [ 17.897893] hardirqs last disabled at (161911): [] > __netdev_alloc_skb+0x94/0x140 > [ 17.904903] exynos5-hsi2c 12ca.i2c: tx timeout > [ 17.906116] softirqs last enabled at (161904): [<387102ff>] > irq_enter+0x78/0x80 > [ 17.906123] softirqs last disabled at (161905): [] > irq_exit+0x134/0x158 > [ 17.925722]. > [ 17.925722] other info that might help us debug this: > [ 17.933435] Possible unsafe locking scenario: > [ 17.933435]. > [ 17.940331] CPU0 > [ 17.942488] > [ 17.944894] lock(&syncp->seq#5); > [ 17.948274] > [ 17.950847] lock(&syncp->seq#5); > [ 17.954386]. > [ 17.954386] *** DEADLOCK *** > [ 17.954386]. > [ 17.962422] no locks held by swapper/0/0. > [ 17.966011]. > [ 17.966011] stack backtrace: > [ 17.971333] CPU: 0 PID: 0 Comm: swapper/0 Not tainted > 4.16.0-rc3-next-20180227-7-g876c53a7493c #453 > [ 17.980312] Hardware name: SAMSUNG EXYNOS (Flattened Device Tree) > [ 17.986380] [] (unwind_backtrace) from [] > (show_stack+0x10/0x14) > [ 17.994128] [] (show_stack) from [] > (dump_stack+0x90/0xc8) > [ 18.001339] [] (dump_stack) from [] > (print_usage_bug+0x25c/0x2cc) > [ 18.009161] [] (print_usage_bug) from [] > (mark_lock+0x290/0x698) > [ 18.014952] exynos5-hsi2c 12ca.i2c: tx timeout > [ 18.016899] [] (mark_lock) from [] > (__lock_acquire+0x454/0x1850) > [ 18.029449] [] (__lock_acquire) from [] > (lock_acquire+0xc8/0x2b8) > [ 18.037272] [] (lock_acquire) from [] > (usbnet_skb_return+0x7c/0x1a0) > [ 18.045356] [] (usbnet_skb_return) from [] > (asix_rx_fixup_internal+0x188/0x288) > [ 18.054420] [] (as
Re: inconsistent lock state with usbnet/asix usb ethernet and xhci
Hi Oliver, On 2018-02-27 11:37, Oliver Neukum wrote: Am Dienstag, den 27.02.2018, 08:26 +0100 schrieb Marek Szyprowski: I've noticed that USBnet/ASIX AX88772B USB driver produces deplock kernel warning ("inconsistent lock state") on Chromebook2 Peach-PIT board. No Is that 32 bit? Yes. ARM 32bit. Exynos5420 SoC (4 x CortexA15 + 4 x CortexA7 big.LITTLE CPUs). special activity is needed to reproduce this issue, it happens almost on every boot. ASIX USB ethernet is connected to XHCI USB host controller on that board. Is it a known issue? Frankly I have no idea where to look No, it is not known. to fix it. The same adapter connected to EHCI ports on other boards based on the same SoC works fine without any warnings. Odd. And the log with mentioned warning: [ 17.768040] [ 17.772239] WARNING: inconsistent lock state [ 17.776511] 4.16.0-rc3-next-20180227-7-g876c53a7493c #453 Not tainted [ 17.783329] [ 17.787580] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. [ 17.793607] swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes: [ 17.798751] (&syncp->seq#5){?.-.}, at: [<9b22e5f0>] asix_rx_fixup_internal+0x188/0x288 Looks like this triggers (in usbnet): u64_stats_update_begin(&stats64->syncp); stats64->rx_packets++; stats64->rx_bytes += skb->len; u64_stats_update_end(&stats64->syncp); That I considered to be called under lock. Could you comment this out for testing? Yes, commenting this out indeed hides the deplock warning. Best regards -- Marek Szyprowski, PhD Samsung R&D Institute Poland
Re: inconsistent lock state with usbnet/asix usb ethernet and xhci
Am Dienstag, den 27.02.2018, 08:26 +0100 schrieb Marek Szyprowski: Hi, > I've noticed that USBnet/ASIX AX88772B USB driver produces deplock kernel > warning ("inconsistent lock state") on Chromebook2 Peach-PIT board. No Is that 32 bit? > special activity is needed to reproduce this issue, it happens almost > on every boot. ASIX USB ethernet is connected to XHCI USB host controller > on that board. Is it a known issue? Frankly I have no idea where to look No, it is not known. > to fix it. The same adapter connected to EHCI ports on other boards based > on the same SoC works fine without any warnings. Odd. > And the log with mentioned warning: > > [ 17.768040] > [ 17.772239] WARNING: inconsistent lock state > [ 17.776511] 4.16.0-rc3-next-20180227-7-g876c53a7493c #453 Not tainted > [ 17.783329] > [ 17.787580] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. > [ 17.793607] swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes: > [ 17.798751] (&syncp->seq#5){?.-.}, at: [<9b22e5f0>] > asix_rx_fixup_internal+0x188/0x288 Looks like this triggers (in usbnet): u64_stats_update_begin(&stats64->syncp); stats64->rx_packets++; stats64->rx_bytes += skb->len; u64_stats_update_end(&stats64->syncp); That I considered to be called under lock. Could you comment this out for testing? Regards Oliver
inconsistent lock state with usbnet/asix usb ethernet and xhci
Hi I've noticed that USBnet/ASIX AX88772B USB driver produces deplock kernel warning ("inconsistent lock state") on Chromebook2 Peach-PIT board. No special activity is needed to reproduce this issue, it happens almost on every boot. ASIX USB ethernet is connected to XHCI USB host controller on that board. Is it a known issue? Frankly I have no idea where to look to fix it. The same adapter connected to EHCI ports on other boards based on the same SoC works fine without any warnings. Here are some more information from that board: # lsusb Bus 006 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub Bus 005 Device 002: ID 0b95:772b ASIX Electronics Corp. AX88772B Bus 005 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub Bus 001 Device 002: ID 2232:1056 Silicon Motion Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub # lsusb -t /: Bus 06.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M /: Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 480M |__ Port 1: Dev 2, If 0, Class=Vendor Specific Class, Driver=asix, 480M /: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M /: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 480M /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=exynos-ohci/3p, 12M /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=exynos-ehci/3p, 480M |__ Port 1: Dev 2, If 0, Class=Video, Driver=, 480M |__ Port 1: Dev 2, If 1, Class=Video, Driver=, 480M And the log with mentioned warning: [ 17.768040] [ 17.772239] WARNING: inconsistent lock state [ 17.776511] 4.16.0-rc3-next-20180227-7-g876c53a7493c #453 Not tainted [ 17.783329] [ 17.787580] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. [ 17.793607] swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes: [ 17.798751] (&syncp->seq#5){?.-.}, at: [<9b22e5f0>] asix_rx_fixup_internal+0x188/0x288 [ 17.806790] {IN-HARDIRQ-W} state was registered at: [ 17.811677] tx_complete+0x100/0x208 [ 17.815319] __usb_hcd_giveback_urb+0x60/0xf0 [ 17.819770] xhci_giveback_urb_in_irq+0xa8/0x240 [ 17.824469] xhci_td_cleanup+0xf4/0x16c [ 17.828367] xhci_irq+0xe74/0x2240 [ 17.831827] usb_hcd_irq+0x24/0x38 [ 17.835343] __handle_irq_event_percpu+0x98/0x510 [ 17.840111] handle_irq_event_percpu+0x1c/0x58 [ 17.844623] handle_irq_event+0x38/0x5c [ 17.848519] handle_fasteoi_irq+0xa4/0x138 [ 17.852681] generic_handle_irq+0x18/0x28 [ 17.856760] __handle_domain_irq+0x6c/0xe4 [ 17.860941] gic_handle_irq+0x54/0xa0 [ 17.864666] __irq_svc+0x70/0xb0 [ 17.867964] arch_cpu_idle+0x20/0x3c [ 17.871578] arch_cpu_idle+0x20/0x3c [ 17.875190] do_idle+0x144/0x218 [ 17.878468] cpu_startup_entry+0x18/0x1c [ 17.882454] start_kernel+0x394/0x400 [ 17.886177] irq event stamp: 161912 [ 17.889616] hardirqs last enabled at (161912): [<7bedfacf>] __netdev_alloc_skb+0xcc/0x140 [ 17.897893] hardirqs last disabled at (161911): [] __netdev_alloc_skb+0x94/0x140 [ 17.904903] exynos5-hsi2c 12ca.i2c: tx timeout [ 17.906116] softirqs last enabled at (161904): [<387102ff>] irq_enter+0x78/0x80 [ 17.906123] softirqs last disabled at (161905): [] irq_exit+0x134/0x158 [ 17.925722]. [ 17.925722] other info that might help us debug this: [ 17.933435] Possible unsafe locking scenario: [ 17.933435]. [ 17.940331] CPU0 [ 17.942488] [ 17.944894] lock(&syncp->seq#5); [ 17.948274] [ 17.950847] lock(&syncp->seq#5); [ 17.954386]. [ 17.954386] *** DEADLOCK *** [ 17.954386]. [ 17.962422] no locks held by swapper/0/0. [ 17.966011]. [ 17.966011] stack backtrace: [ 17.971333] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.16.0-rc3-next-20180227-7-g876c53a7493c #453 [ 17.980312] Hardware name: SAMSUNG EXYNOS (Flattened Device Tree) [ 17.986380] [] (unwind_backtrace) from [] (show_stack+0x10/0x14) [ 17.994128] [] (show_stack) from [] (dump_stack+0x90/0xc8) [ 18.001339] [] (dump_stack) from [] (print_usage_bug+0x25c/0x2cc) [ 18.009161] [] (print_usage_bug) from [] (mark_lock+0x290/0x698) [ 18.014952] exynos5-hsi2c 12ca.i2c: tx timeout [ 18.016899] [] (mark_lock) from [] (__lock_acquire+0x454/0x1850) [ 18.029449] [] (__lock_acquire) from [] (lock_acquire+0xc8/0x2b8) [ 18.037272] [] (lock_acquire) from [] (usbnet_skb_return+0x7c/0x1a0) [ 18.045356] [] (usbnet_skb_return) from [] (asix_rx_fixup_internal+0x188/0x288) [ 18.054420] [] (asix_rx_fixup_internal) from [] (usbnet_bh+0xf8/0x2e4) [ 18.062694] [] (usbnet_bh) from [] (tasklet_action+0x8c/0x13c) [ 18.070259] [] (tasklet_action) from [] (__do_softirq+0xd4/0x6d4) [ 18.078089] [] (__do_softirq) from [] (irq_exit+0x134/0x158) [ 18.085480] []