Skip to contentSkip to conversation

inconsistent lock state with usbnet/asix usb ethernet and xhci

PATCH In review Marek Szyprowski 4 participants 13 messages Feb 27, 2018 – Mar 7, 2018 1 message not in the archive

Subsystems (6)
Networking Network drivers USB Arm Samsung Exynos +2 more subsystems
lore
Share & tools
lore

A message that is not in the archive (sent off-list or not yet received): CGME20180227072602eucas1p28dcdba711b3153820bd409d838cc63bd@eucas1p2.samsung.com

Marek Szyprowski

author
#1 lore raw

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-00007-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): [<d58261d0>] __netdev_alloc_skb+0x94/0x140 [   17.904903] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   17.906116] softirqs last  enabled at (161904): [<387102ff>] irq_enter+0x78/0x80
[   17.906123] softirqs last disabled at (161905): [<cf4c628e>] 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]   <Interrupt>
[   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-00007-g876c53a7493c #453 [   17.980312] Hardware name: SAMSUNG EXYNOS (Flattened Device Tree)
[   17.986380] [<c0111548>] (unwind_backtrace) from [<c010dbd8>] (show_stack+0x10/0x14)
[   17.994128] [<c010dbd8>] (show_stack) from [<c09bd418>] (dump_stack+0x90/0xc8)
[   18.001339] [<c09bd418>] (dump_stack) from [<c017fdf8>] (print_usage_bug+0x25c/0x2cc) [   18.009161] [<c017fdf8>] (print_usage_bug) from [<c017c14c>] (mark_lock+0x290/0x698)
[   18.014952] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   18.016899] [<c017c14c>] (mark_lock) from [<c017c9a8>] (__lock_acquire+0x454/0x1850)
[   18.029449] [<c017c9a8>] (__lock_acquire) from [<c017e6e0>] (lock_acquire+0xc8/0x2b8) [   18.037272] [<c017e6e0>] (lock_acquire) from [<c05be98c>] (usbnet_skb_return+0x7c/0x1a0) [   18.045356] [<c05be98c>] (usbnet_skb_return) from [<c05b185c>] (asix_rx_fixup_internal+0x188/0x288) [   18.054420] [<c05b185c>] (asix_rx_fixup_internal) from [<c05bfe40>] (usbnet_bh+0xf8/0x2e4) [   18.062694] [<c05bfe40>] (usbnet_bh) from [<c012d6b4>] (tasklet_action+0x8c/0x13c)
[   18.070259] [<c012d6b4>] (tasklet_action) from [<c0102214>] (__do_softirq+0xd4/0x6d4) [   18.078089] [<c0102214>] (__do_softirq) from [<c012cf34>] (irq_exit+0x134/0x158)
[   18.085480] [<c012cf34>] (irq_exit) from [<c018c444>] (__handle_domain_irq+0x70/0xe4) [   18.093314] [<c018c444>] (__handle_domain_irq) from [<c046400c>] (gic_handle_irq+0x54/0xa0) [   18.101670] [<c046400c>] (gic_handle_irq) from [<c01019f0>] (__irq_svc+0x70/0xb0)
[   18.109163] Exception stack(0xc0f01eb8 to 0xc0f01f00)
[   18.114202] 1ea0: 00000001 00000001
[   18.122397] 1ec0: 00000000 c0f0ba80 eef3a540 eef3a540 ee8d2700 c0f088b4 00000402 c09d23e0 [   18.124980] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   18.130611] 1ee0: c0f0ba80 c0f01f4c 00000000 c0f01f08 c017ea54 c09d92d4 20000013 ffffffff [   18.135504] cpu cpu0: _set_opp_voltage: failed to set voltage (1250000 1250000 1250000 mV): -110 [   18.143690] [<c01019f0>] (__irq_svc) from [<c09d92d4>] (_raw_spin_unlock_irq+0x28/0x5c) [   18.152671] cpufreq: __target_index: Failed to change cpu frequency: -110
[   18.160683] [<c09d92d4>] (_raw_spin_unlock_irq) from [<c0152684>] (finish_task_switch+0xb4/0x254) [   18.160696] [<c0152684>] (finish_task_switch) from [<c09d23e0>] (__schedule+0x290/0xb10) [   18.160704] [<c09d23e0>] (__schedule) from [<c09d3134>] (schedule_idle+0x2c/0x78)
[   18.160711] [<c09d3134>] (schedule_idle) from [<c01703a0>] (cpu_startup_entry+0x18/0x1c) [   18.200726] [<c01703a0>] (cpu_startup_entry) from [<c0e00c74>] (start_kernel+0x394/0x400)

Best regards

Signature · 2 lines
Marek Szyprowski, PhD
Samsung R&D Institute Poland
maintainer
#2 lore raw

Am Dienstag, den 27.02.2018, 08:26 +0100 schrieb Marek Szyprowski:

Hi,

Quoted 2 lines

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?

Quoted 3 lines

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.

Quoted 2 lines

to fix it. The same adapter connected to EHCI ports on other boards based on the same SoC works fine without any warnings.

Odd.

Quoted 10 lines

And the log with mentioned warning:

[   17.768040] ================================
[   17.772239] WARNING: inconsistent lock state
[   17.776511] 4.16.0-rc3-next-20180227-00007-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

author
#3 lore raw

Hi Oliver,

Quoted 5 lines · Oliver Neukum

Am Dienstag, den 27.02.2018, 08:26 +0100 schrieb Marek Szyprowski:

Quoted 2 lines

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).

Quoted 21 lines
Quoted 3 lines

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.

Quoted 2 lines

to fix it. The same adapter connected to EHCI ports on other boards based on the same SoC works fine without any warnings.

Odd.

Quoted 10 lines

And the log with mentioned warning:

[   17.768040] ================================
[   17.772239] WARNING: inconsistent lock state
[   17.776511] 4.16.0-rc3-next-20180227-00007-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):

Quoted 7 lines

        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

Signature · 2 lines
Marek Szyprowski, PhD
Samsung R&D Institute Poland
#4 lore raw
In reply to Marek Szyprowski
Quoted 145 lines · 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 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-00007-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): [<d58261d0>] __netdev_alloc_skb+0x94/0x140
[   17.904903] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   17.906116] softirqs last  enabled at (161904): [<387102ff>] irq_enter+0x78/0x80
[   17.906123] softirqs last disabled at (161905): [<cf4c628e>] 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]   <Interrupt>
[   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-00007-g876c53a7493c #453
[   17.980312] Hardware name: SAMSUNG EXYNOS (Flattened Device Tree) [   17.986380] [<c0111548>] (unwind_backtrace) from [<c010dbd8>] (show_stack+0x10/0x14)
[   17.994128] [<c010dbd8>] (show_stack) from [<c09bd418>] (dump_stack+0x90/0xc8)
[   18.001339] [<c09bd418>] (dump_stack) from [<c017fdf8>] (print_usage_bug+0x25c/0x2cc)
[   18.009161] [<c017fdf8>] (print_usage_bug) from [<c017c14c>] (mark_lock+0x290/0x698)
[   18.014952] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   18.016899] [<c017c14c>] (mark_lock) from [<c017c9a8>] (__lock_acquire+0x454/0x1850)
[   18.029449] [<c017c9a8>] (__lock_acquire) from [<c017e6e0>] (lock_acquire+0xc8/0x2b8)
[   18.037272] [<c017e6e0>] (lock_acquire) from [<c05be98c>] (usbnet_skb_return+0x7c/0x1a0)
[   18.045356] [<c05be98c>] (usbnet_skb_return) from [<c05b185c>] (asix_rx_fixup_internal+0x188/0x288)
[   18.054420] [<c05b185c>] (asix_rx_fixup_internal) from [<c05bfe40>] (usbnet_bh+0xf8/0x2e4)
[   18.062694] [<c05bfe40>] (usbnet_bh) from [<c012d6b4>] (tasklet_action+0x8c/0x13c)
[   18.070259] [<c012d6b4>] (tasklet_action) from [<c0102214>] (__do_softirq+0xd4/0x6d4)
[   18.078089] [<c0102214>] (__do_softirq) from [<c012cf34>] (irq_exit+0x134/0x158)
[   18.085480] [<c012cf34>] (irq_exit) from [<c018c444>] (__handle_domain_irq+0x70/0xe4)
[   18.093314] [<c018c444>] (__handle_domain_irq) from [<c046400c>] (gic_handle_irq+0x54/0xa0)
[   18.101670] [<c046400c>] (gic_handle_irq) from [<c01019f0>] (__irq_svc+0x70/0xb0)
[   18.109163] Exception stack(0xc0f01eb8 to 0xc0f01f00)
[   18.114202] 1ea0: 00000001 00000001
[   18.122397] 1ec0: 00000000 c0f0ba80 eef3a540 eef3a540 ee8d2700 c0f088b4 00000402 c09d23e0
[   18.124980] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   18.130611] 1ee0: c0f0ba80 c0f01f4c 00000000 c0f01f08 c017ea54 c09d92d4 20000013 ffffffff
[   18.135504] cpu cpu0: _set_opp_voltage: failed to set voltage (1250000 1250000 1250000 mV): -110
[   18.143690] [<c01019f0>] (__irq_svc) from [<c09d92d4>] (_raw_spin_unlock_irq+0x28/0x5c)
[   18.152671] cpufreq: __target_index: Failed to change cpu frequency: -110 [   18.160683] [<c09d92d4>] (_raw_spin_unlock_irq) from [<c0152684>] (finish_task_switch+0xb4/0x254)
[   18.160696] [<c0152684>] (finish_task_switch) from [<c09d23e0>] (__schedule+0x290/0xb10)
[   18.160704] [<c09d23e0>] (__schedule) from [<c09d3134>] (schedule_idle+0x2c/0x78)
[   18.160711] [<c09d3134>] (schedule_idle) from [<c01703a0>] (cpu_startup_entry+0x18/0x1c)
[   18.200726] [<c01703a0>] (cpu_startup_entry) from [<c0e00c74>] (start_kernel+0x394/0x400)

Quoted 1 line

Best regards

Please try the attached patch, thanks.

 drivers/net/usb/usbnet.c       |    5 +++-- include/linux/u64_stats_sync.h |   22 ++++++++++++++++++++++

 2 files changed, 25 insertions(+), 2 deletions(-)
drivers/net/usb/usbnet.c +3 -2
index 8a22ff67b0268a588428c61c6a6211e3c6c2a02a..7f5bda0ec9e8520e6db327b713152afdb250255f 100644
@@ -315,6 +315,7 @@ static void __usbnet_status_stop_force(struct usbnet *dev)
 void usbnet_skb_return (struct usbnet *dev, struct sk_buff *skb)
 {
 	struct pcpu_sw_netstats *stats64 = this_cpu_ptr(dev->stats64);
+	unsigned long flags;
 	int	status;
 
 	if (test_bit(EVENT_RX_PAUSED, &dev->flags)) {

@@ -326,10 +327,10 @@ void usbnet_skb_return (struct usbnet *dev, struct sk_buff *skb)
 	if (skb->protocol == 0)
 		skb->protocol = eth_type_trans (skb, dev->net);
 
-	u64_stats_update_begin(&stats64->syncp);
+	flags = u64_stats_update_begin_irqsave(&stats64->syncp);
 	stats64->rx_packets++;
 	stats64->rx_bytes += skb->len;
-	u64_stats_update_end(&stats64->syncp);
+	u64_stats_update_end_irqrestore(&stats64->syncp, flags);
 
 	netif_dbg(dev, rx_status, dev->net, "< rx, len %zu, type 0x%x\n",
 		  skb->len + sizeof (struct ethhdr), skb->protocol);
include/linux/u64_stats_sync.h +22 -0
index 5bdbd9f49395f883ca2dc5aa0d7bbde11f379063..07ee0f84a46caa9e2b1c446f96009f63b3b99f50 100644
@@ -90,6 +90,28 @@ static inline void u64_stats_update_end(struct u64_stats_sync *syncp)
 #endif
 }
 
+static inline unsigned long
+u64_stats_update_begin_irqsave(struct u64_stats_sync *syncp)
+{
+	unsigned long flags = 0;
+
+#if BITS_PER_LONG==32 && defined(CONFIG_SMP)
+	local_irq_save(flags);
+	write_seqcount_begin(&syncp->seq);
+#endif
+	return flags;
+}
+
+static inline void
+u64_stats_update_end_irqrestore(struct u64_stats_sync *syncp,
+				unsigned long flags)
+{
+#if BITS_PER_LONG==32 && defined(CONFIG_SMP)
+	write_seqcount_end(&syncp->seq);
+	local_irq_restore(flags);
+#endif
+}
+
 static inline void u64_stats_update_begin_raw(struct u64_stats_sync *syncp)
 {
 #if BITS_PER_LONG==32 && defined(CONFIG_SMP)
author
#5 lore raw

Hi Eric,

Quoted 144 lines · Eric Dumazet
Quoted 143 lines · Marek Szyprowski

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-00007-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): [<d58261d0>] __netdev_alloc_skb+0x94/0x140
[   17.904903] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   17.906116] softirqs last  enabled at (161904): [<387102ff>] irq_enter+0x78/0x80
[   17.906123] softirqs last disabled at (161905): [<cf4c628e>] 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]   <Interrupt>
[   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-00007-g876c53a7493c #453
[   17.980312] Hardware name: SAMSUNG EXYNOS (Flattened Device Tree) [   17.986380] [<c0111548>] (unwind_backtrace) from [<c010dbd8>] (show_stack+0x10/0x14)
[   17.994128] [<c010dbd8>] (show_stack) from [<c09bd418>] (dump_stack+0x90/0xc8)
[   18.001339] [<c09bd418>] (dump_stack) from [<c017fdf8>] (print_usage_bug+0x25c/0x2cc)
[   18.009161] [<c017fdf8>] (print_usage_bug) from [<c017c14c>] (mark_lock+0x290/0x698)
[   18.014952] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   18.016899] [<c017c14c>] (mark_lock) from [<c017c9a8>] (__lock_acquire+0x454/0x1850)
[   18.029449] [<c017c9a8>] (__lock_acquire) from [<c017e6e0>] (lock_acquire+0xc8/0x2b8)
[   18.037272] [<c017e6e0>] (lock_acquire) from [<c05be98c>] (usbnet_skb_return+0x7c/0x1a0)
[   18.045356] [<c05be98c>] (usbnet_skb_return) from [<c05b185c>] (asix_rx_fixup_internal+0x188/0x288)
[   18.054420] [<c05b185c>] (asix_rx_fixup_internal) from [<c05bfe40>] (usbnet_bh+0xf8/0x2e4)
[   18.062694] [<c05bfe40>] (usbnet_bh) from [<c012d6b4>] (tasklet_action+0x8c/0x13c)
[   18.070259] [<c012d6b4>] (tasklet_action) from [<c0102214>] (__do_softirq+0xd4/0x6d4)
[   18.078089] [<c0102214>] (__do_softirq) from [<c012cf34>] (irq_exit+0x134/0x158)
[   18.085480] [<c012cf34>] (irq_exit) from [<c018c444>] (__handle_domain_irq+0x70/0xe4)
[   18.093314] [<c018c444>] (__handle_domain_irq) from [<c046400c>] (gic_handle_irq+0x54/0xa0)
[   18.101670] [<c046400c>] (gic_handle_irq) from [<c01019f0>] (__irq_svc+0x70/0xb0)
[   18.109163] Exception stack(0xc0f01eb8 to 0xc0f01f00)
[   18.114202] 1ea0: 00000001 00000001
[   18.122397] 1ec0: 00000000 c0f0ba80 eef3a540 eef3a540 ee8d2700 c0f088b4 00000402 c09d23e0
[   18.124980] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   18.130611] 1ee0: c0f0ba80 c0f01f4c 00000000 c0f01f08 c017ea54 c09d92d4 20000013 ffffffff
[   18.135504] cpu cpu0: _set_opp_voltage: failed to set voltage (1250000 1250000 1250000 mV): -110
[   18.143690] [<c01019f0>] (__irq_svc) from [<c09d92d4>] (_raw_spin_unlock_irq+0x28/0x5c)
[   18.152671] cpufreq: __target_index: Failed to change cpu frequency: -110 [   18.160683] [<c09d92d4>] (_raw_spin_unlock_irq) from [<c0152684>] (finish_task_switch+0xb4/0x254)
[   18.160696] [<c0152684>] (finish_task_switch) from [<c09d23e0>] (__schedule+0x290/0xb10)
[   18.160704] [<c09d23e0>] (__schedule) from [<c09d3134>] (schedule_idle+0x2c/0x78)
[   18.160711] [<c09d3134>] (schedule_idle) from [<c01703a0>] (cpu_startup_entry+0x18/0x1c)
[   18.200726] [<c01703a0>] (cpu_startup_entry) from [<c0e00c74>] (start_kernel+0x394/0x400)

Quoted 2 lines
Quoted 1 line

Best regards

Please try the attached patch, thanks.

Thanks for the patch. It fixes the deplock warning. However IMHO the same fix should be also applied to complete_tx function for modifying stats64 there:

drivers/net/usb/usbnet.c +0 -0
index 7f5bda0ec9e8..d9eea8cfe6cb 100644
@@ -1249,11 +1249,12 @@ static void tx_complete (struct urb *urb)

        if (urb->status == 0) {
                struct pcpu_sw_netstats *stats64 = this_cpu_ptr(dev->stats64); +               unsigned long flags;

-               u64_stats_update_begin(&stats64->syncp);
+               flags = u64_stats_update_begin_irqsave(&stats64->syncp); stats64->tx_packets += entry->packets; stats64->tx_bytes += entry->length;
-               u64_stats_update_end(&stats64->syncp);
+ u64_stats_update_end_irqrestore(&stats64->syncp, flags);
        } else {
                dev->net->stats.tx_errors++;

I've did that and it also works fine without deplock warning.

Quoted 56 lines
  drivers/net/usb/usbnet.c       |    5 +++--
  include/linux/u64_stats_sync.h |   22 ++++++++++++++++++++++
  2 files changed, 25 insertions(+), 2 deletions(-)
drivers/net/usb/usbnet.c +3 -2
index 8a22ff67b0268a588428c61c6a6211e3c6c2a02a..7f5bda0ec9e8520e6db327b713152afdb250255f 100644
@@ -315,6 +315,7 @@ static void __usbnet_status_stop_force(struct usbnet *dev)
  void usbnet_skb_return (struct usbnet *dev, struct sk_buff *skb)
  {
  	struct pcpu_sw_netstats *stats64 = this_cpu_ptr(dev->stats64);
+	unsigned long flags;
  	int	status;
 
  	if (test_bit(EVENT_RX_PAUSED, &dev->flags)) {

@@ -326,10 +327,10 @@ void usbnet_skb_return (struct usbnet *dev, struct sk_buff *skb)
  	if (skb->protocol == 0)
  		skb->protocol = eth_type_trans (skb, dev->net);
 
-	u64_stats_update_begin(&stats64->syncp);
+	flags = u64_stats_update_begin_irqsave(&stats64->syncp);
  	stats64->rx_packets++;
  	stats64->rx_bytes += skb->len;
-	u64_stats_update_end(&stats64->syncp);
+	u64_stats_update_end_irqrestore(&stats64->syncp, flags);
 
  	netif_dbg(dev, rx_status, dev->net, "< rx, len %zu, type 0x%x\n",
  		  skb->len + sizeof (struct ethhdr), skb->protocol);
include/linux/u64_stats_sync.h +15 -0
index 5bdbd9f49395f883ca2dc5aa0d7bbde11f379063..07ee0f84a46caa9e2b1c446f96009f63b3b99f50 100644
@@ -90,6 +90,28 @@ static inline void u64_stats_update_end(struct u64_stats_sync *syncp)
  #endif
  }
 
+static inline unsigned long
+u64_stats_update_begin_irqsave(struct u64_stats_sync *syncp)
+{
+	unsigned long flags = 0;
+
+#if BITS_PER_LONG==32 && defined(CONFIG_SMP)
+	local_irq_save(flags);
+	write_seqcount_begin(&syncp->seq);
+#endif
+	return flags;
+}
+
+static inline void
+u64_stats_update_end_irqrestore(struct u64_stats_sync *syncp,
+				unsigned long flags)

include/linux/u64_stats_sync.h static inline void u64_stats_update_end(struct u64_stats_sync *syncp) · line 117

Quoted 10 lines
include/linux/u64_stats_sync.h +7 -0
+{
+#if BITS_PER_LONG==32 && defined(CONFIG_SMP)
+	write_seqcount_end(&syncp->seq);
+	local_irq_restore(flags);
+#endif
+}
+
  static inline void u64_stats_update_begin_raw(struct u64_stats_sync *syncp)
  {
  #if BITS_PER_LONG==32 && defined(CONFIG_SMP)

Best regards

Signature · 2 lines
Marek Szyprowski, PhD
Samsung R&D Institute Poland
#6 lore raw
Quoted 176 lines · Marek Szyprowski

Hi Eric,

Quoted 144 lines · Eric Dumazet
Quoted 143 lines · Marek Szyprowski

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-00007-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): [<d58261d0>] __netdev_alloc_skb+0x94/0x140
[   17.904903] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   17.906116] softirqs last  enabled at (161904): [<387102ff>] irq_enter+0x78/0x80
[   17.906123] softirqs last disabled at (161905): [<cf4c628e>] 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]   <Interrupt>
[   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-00007-g876c53a7493c #453
[   17.980312] Hardware name: SAMSUNG EXYNOS (Flattened Device Tree) [   17.986380] [<c0111548>] (unwind_backtrace) from [<c010dbd8>] (show_stack+0x10/0x14)
[   17.994128] [<c010dbd8>] (show_stack) from [<c09bd418>] (dump_stack+0x90/0xc8)
[   18.001339] [<c09bd418>] (dump_stack) from [<c017fdf8>] (print_usage_bug+0x25c/0x2cc)
[   18.009161] [<c017fdf8>] (print_usage_bug) from [<c017c14c>] (mark_lock+0x290/0x698)
[   18.014952] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   18.016899] [<c017c14c>] (mark_lock) from [<c017c9a8>] (__lock_acquire+0x454/0x1850)
[   18.029449] [<c017c9a8>] (__lock_acquire) from [<c017e6e0>] (lock_acquire+0xc8/0x2b8)
[   18.037272] [<c017e6e0>] (lock_acquire) from [<c05be98c>] (usbnet_skb_return+0x7c/0x1a0)
[   18.045356] [<c05be98c>] (usbnet_skb_return) from [<c05b185c>] (asix_rx_fixup_internal+0x188/0x288)
[   18.054420] [<c05b185c>] (asix_rx_fixup_internal) from [<c05bfe40>] (usbnet_bh+0xf8/0x2e4)
[   18.062694] [<c05bfe40>] (usbnet_bh) from [<c012d6b4>] (tasklet_action+0x8c/0x13c)
[   18.070259] [<c012d6b4>] (tasklet_action) from [<c0102214>] (__do_softirq+0xd4/0x6d4)
[   18.078089] [<c0102214>] (__do_softirq) from [<c012cf34>] (irq_exit+0x134/0x158)
[   18.085480] [<c012cf34>] (irq_exit) from [<c018c444>] (__handle_domain_irq+0x70/0xe4)
[   18.093314] [<c018c444>] (__handle_domain_irq) from [<c046400c>] (gic_handle_irq+0x54/0xa0)
[   18.101670] [<c046400c>] (gic_handle_irq) from [<c01019f0>] (__irq_svc+0x70/0xb0)
[   18.109163] Exception stack(0xc0f01eb8 to 0xc0f01f00)
[   18.114202] 1ea0: 00000001 00000001
[   18.122397] 1ec0: 00000000 c0f0ba80 eef3a540 eef3a540 ee8d2700 c0f088b4 00000402 c09d23e0
[   18.124980] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   18.130611] 1ee0: c0f0ba80 c0f01f4c 00000000 c0f01f08 c017ea54 c09d92d4 20000013 ffffffff
[   18.135504] cpu cpu0: _set_opp_voltage: failed to set voltage (1250000 1250000 1250000 mV): -110
[   18.143690] [<c01019f0>] (__irq_svc) from [<c09d92d4>] (_raw_spin_unlock_irq+0x28/0x5c)
[   18.152671] cpufreq: __target_index: Failed to change cpu frequency: -110 [   18.160683] [<c09d92d4>] (_raw_spin_unlock_irq) from [<c0152684>] (finish_task_switch+0xb4/0x254)
[   18.160696] [<c0152684>] (finish_task_switch) from [<c09d23e0>] (__schedule+0x290/0xb10)
[   18.160704] [<c09d23e0>] (__schedule) from [<c09d3134>] (schedule_idle+0x2c/0x78)
[   18.160711] [<c09d3134>] (schedule_idle) from [<c01703a0>] (cpu_startup_entry+0x18/0x1c)
[   18.200726] [<c01703a0>] (cpu_startup_entry) from [<c0e00c74>] (start_kernel+0x394/0x400)

Quoted 3 lines
Quoted 1 line

Best regards

Please try the attached patch, thanks.

Thanks for the patch. It fixes the deplock warning. However IMHO the same fix should be also applied to complete_tx function for modifying stats64 there:

drivers/net/usb/usbnet.c +3 -2
index 7f5bda0ec9e8..d9eea8cfe6cb 100644
@@ -1249,11 +1249,12 @@ static void tx_complete (struct urb *urb)
 
         if (urb->status == 0) {
                 struct pcpu_sw_netstats *stats64 = 
 this_cpu_ptr(dev->stats64);
+               unsigned long flags;
 
-               u64_stats_update_begin(&stats64->syncp);
+               flags = u64_stats_update_begin_irqsave(&stats64->syncp);
                 stats64->tx_packets += entry->packets;
                 stats64->tx_bytes += entry->length;
-               u64_stats_update_end(&stats64->syncp);
+ u64_stats_update_end_irqrestore(&stats64->syncp, flags);
         } else {
                 dev->net->stats.tx_errors++;
Quoted 1 line

I've did that and it also works fine without deplock warning.

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.

I'll send a formal patch including your change in tx_complete(), thanks !

#7 lore raw
Quoted 5 lines · Eric Dumazet

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.

maintainer
#8 lore raw

Am Dienstag, den 27.02.2018, 07:13 -0800 schrieb Eric Dumazet:

Quoted 6 lines · Eric Dumazet
Quoted 5 lines

Note that for this one, it seems we also could perform stats updates in BH context, since skb is queued via defer_bh()

Quoted 7 lines
Quoted 1 line

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

author
#9 lore raw

Hi Oliver,

Quoted 6 lines · Oliver Neukum

Am Dienstag, den 27.02.2018, 07:13 -0800 schrieb Eric Dumazet:

Quoted 5 lines · Eric Dumazet
Quoted 4 lines

Note that for this one, it seems we also could perform stats updates in BH context, since skb is queued via defer_bh()

Quoted 7 lines
Quoted 6 lines
Quoted 1 line

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

Signature · 2 lines
Marek Szyprowski, PhD
Samsung R&D Institute Poland
maintainer
#10 lore raw
Quoted 10 lines · Marek Szyprowski

Hi Oliver,

Quoted 7 lines · Oliver Neukum

Am Dienstag, den 27.02.2018, 07:13 -0800 schrieb Eric Dumazet:

Quoted 6 lines · Eric Dumazet
Quoted 5 lines

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.

Quoted 8 lines
Quoted 6 lines
Quoted 5 lines

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

#11 lore raw
Quoted 21 lines · Oliver Neukum
Quoted 20 lines · Marek Szyprowski

Hi Oliver,

Quoted 17 lines · Oliver Neukum

Am Dienstag, den 27.02.2018, 07:13 -0800 schrieb Eric Dumazet:

Quoted 15 lines · Eric Dumazet
Quoted 6 lines

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.

Quoted 8 lines
Quoted 5 lines
Quoted 2 lines

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)

#12 lore raw

PATCH 1/1 net: usbnet: fix potential deadlock on 32bit hosts

From: Eric Dumazet <[email protected]>

Marek reported a LOCKDEP issue occurring on 32bit host, that we tracked down to the fact that usbnet could either run from soft or hard irqs.

This patch adds u64_stats_update_begin_irqsave() and u64_stats_update_end_irqrestore() helpers to solve this case.

[   17.768040] ================================
[   17.772239] WARNING: inconsistent lock state
[   17.776511] 4.16.0-rc3-next-20180227-00007-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): [<d58261d0>] 
__netdev_alloc_skb+0x94/0x140
[   17.904903] exynos5-hsi2c 12ca0000.i2c: tx timeout
[   17.906116] softirqs last  enabled at (161904): [<387102ff>] 
irq_enter+0x78/0x80
[   17.906123] softirqs last disabled at (161905): [<cf4c628e>] 
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]   <Interrupt>
[   17.950847]     lock(&syncp->seq#5);
[   17.954386].
[   17.954386]  *** DEADLOCK ***
[   17.954386].
[   17.962422] no locks held by swapper/0/0.
Fixes c8b5d129ee29 ("net: usbnet: support 64bit stats")
Signed-off-by Eric Dumazet <[email protected]>
Reported-by Marek Szyprowski <[email protected]>
Cc Greg Ungerer <[email protected]>

---
 drivers/net/usb/usbnet.c       |   10 ++++++---- include/linux/u64_stats_sync.h |   22 ++++++++++++++++++++++

 2 files changed, 28 insertions(+), 4 deletions(-)

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

drivers/net/usb/usbnet.c +6 -4
index 8a22ff67b0268a588428c61c6a6211e3c6c2a02a..d9eea8cfe6cb9a3bf8d0d4ce9198af9bccf9c757 100644
@@ -315,6 +315,7 @@ static void __usbnet_status_stop_force(struct usbnet *dev)
 void usbnet_skb_return (struct usbnet *dev, struct sk_buff *skb)
 {
 	struct pcpu_sw_netstats *stats64 = this_cpu_ptr(dev->stats64);
+	unsigned long flags;
 	int	status;
 
 	if (test_bit(EVENT_RX_PAUSED, &dev->flags)) {

@@ -326,10 +327,10 @@ void usbnet_skb_return (struct usbnet *dev, struct sk_buff *skb)
 	if (skb->protocol == 0)
 		skb->protocol = eth_type_trans (skb, dev->net);
 
-	u64_stats_update_begin(&stats64->syncp);
+	flags = u64_stats_update_begin_irqsave(&stats64->syncp);
 	stats64->rx_packets++;
 	stats64->rx_bytes += skb->len;
-	u64_stats_update_end(&stats64->syncp);
+	u64_stats_update_end_irqrestore(&stats64->syncp, flags);
 
 	netif_dbg(dev, rx_status, dev->net, "< rx, len %zu, type 0x%x\n",
 		  skb->len + sizeof (struct ethhdr), skb->protocol);

@@ -1248,11 +1249,12 @@ static void tx_complete (struct urb *urb)
 
 	if (urb->status == 0) {
 		struct pcpu_sw_netstats *stats64 = this_cpu_ptr(dev->stats64);
+		unsigned long flags;
 
-		u64_stats_update_begin(&stats64->syncp);
+		flags = u64_stats_update_begin_irqsave(&stats64->syncp);
 		stats64->tx_packets += entry->packets;
 		stats64->tx_bytes += entry->length;
-		u64_stats_update_end(&stats64->syncp);
+		u64_stats_update_end_irqrestore(&stats64->syncp, flags);
 	} else {
 		dev->net->stats.tx_errors++;
include/linux/u64_stats_sync.h +22 -0
index 5bdbd9f49395f883ca2dc5aa0d7bbde11f379063..07ee0f84a46caa9e2b1c446f96009f63b3b99f50 100644
@@ -90,6 +90,28 @@ static inline void u64_stats_update_end(struct u64_stats_sync *syncp)
 #endif
 }
 
+static inline unsigned long
+u64_stats_update_begin_irqsave(struct u64_stats_sync *syncp)
+{
+	unsigned long flags = 0;
+
+#if BITS_PER_LONG==32 && defined(CONFIG_SMP)
+	local_irq_save(flags);
+	write_seqcount_begin(&syncp->seq);
+#endif
+	return flags;
+}
+
+static inline void
+u64_stats_update_end_irqrestore(struct u64_stats_sync *syncp,
+				unsigned long flags)
+{
+#if BITS_PER_LONG==32 && defined(CONFIG_SMP)
+	write_seqcount_end(&syncp->seq);
+	local_irq_restore(flags);
+#endif
+}
+
 static inline void u64_stats_update_begin_raw(struct u64_stats_sync *syncp)
 {
 #if BITS_PER_LONG==32 && defined(CONFIG_SMP)
maintainer
#13 lore raw

Re: [PATCH net] net: usbnet: fix potential deadlock on 32bit hosts

From: Eric Dumazet <[email protected]>
Date: Mon, 05 Mar 2018 11:41:13 -0800

Quoted 8 lines

From: Eric Dumazet <[email protected]>

Marek reported a LOCKDEP issue occurring on 32bit host, that we tracked down to the fact that usbnet could either run from soft or hard irqs.

This patch adds u64_stats_update_begin_irqsave() and u64_stats_update_end_irqrestore() helpers to solve this case.

...

Quoted 4 lines
Fixes c8b5d129ee29 ("net: usbnet: support 64bit stats")
Signed-off-by Eric Dumazet <[email protected]>
Reported-by Marek Szyprowski <[email protected]>
Cc Greg Ungerer <[email protected]>

Applied and queued up for -stable, thanks Eric.
---
To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html