ftgmac driver has locking issues

[jk-ozlabs]

I've booted a kernel with CONFIG_LOCKDEP, but it crashes on DHCP:

root@palmetto:/sys/class/gpio# udhcpc
udhcpc (v1.23.2) started

=================================
[ INFO: inconsistent lock state ]
4.2.0-00056-gd4643a2 #54 Not tainted
---------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
kworker/0:0/810 [HC0[0]:SC1[1]:HE1:SE0] takes:
 (&(&ndp->ndp_req_lock)->rlock){+.?...}, at: [<c03a087c>] ncsi_rcv_rsp+0x3c/0xfc
{SOFTIRQ-ON-W} state was registered at:
  [<c03b0048>] _raw_spin_lock+0x28/0x38
  [<c03a1af4>] ncsi_alloc_req+0x14/0x108
  [<c039f238>] ncsi_xmit_cmd+0x78/0x208
  [<c03a0f54>] ncsi_dev_start+0x84/0x3c0
  [<c03a1a00>] ncsi_dev_work+0x1b8/0x1fc
  [<c002b7c8>] process_one_work+0x22c/0x3d0
  [<c002beb8>] worker_thread+0x2a4/0x3dc
  [<c00301bc>] kthread+0xc4/0xd8
  [<c000a3b0>] ret_from_fork+0x14/0x24
irq event stamp: 112342
hardirqs last  enabled at (112342): [<c00568e8>] ktime_get_with_offset+0x9c/0x178
hardirqs last disabled at (112341): [<c005689c>] ktime_get_with_offset+0x50/0x178
softirqs last  enabled at (112300): [<c0300bec>] __dev_queue_xmit+0x63c/0x6cc
softirqs last disabled at (112301): [<c001981c>] do_softirq+0x48/0x70

other info that might help us debug this:
 Possible unsafe locking scenario:

       CPU0
       ----
  lock(&(&ndp->ndp_req_lock)->rlock);
  <Interrupt>
    lock(&(&ndp->ndp_req_lock)->rlock);

 *** DEADLOCK ***

3 locks held by kworker/0:0/810:
 #0:  ("events"){.+.+.+}, at: [<c002b754>] process_one_work+0x1b8/0x3d0
 #1:  ((&ndp->ndp_work)){+.+...}, at: [<c002b754>] process_one_work+0x1b8/0x3d0
 #2:  (rcu_read_lock){......}, at: [<c02fdba8>] netif_receive_skb_internal+0x48/0x138

stack backtrace:
CPU: 0 PID: 810 Comm: kworker/0:0 Not tainted 4.2.0-00056-gd4643a2 #54
Hardware name: ASpeed SoC
Workqueue: events ncsi_dev_work
[<c000f2a0>] (unwind_backtrace) from [<c000cf48>] (show_stack+0x10/0x14)
[<c000cf48>] (show_stack) from [<c03a9130>] (print_usage_bug.part.31+0x228/0x294)
[<c03a9130>] (print_usage_bug.part.31) from [<c003ebc8>] (mark_lock+0x410/0x64c)
[<c003ebc8>] (mark_lock) from [<c003fa60>] (__lock_acquire+0x7b8/0x1adc)
[<c003fa60>] (__lock_acquire) from [<c0041500>] (lock_acquire+0x70/0x90)
[<c0041500>] (lock_acquire) from [<c03b0048>] (_raw_spin_lock+0x28/0x38)
[<c03b0048>] (_raw_spin_lock) from [<c03a087c>] (ncsi_rcv_rsp+0x3c/0xfc)
[<c03a087c>] (ncsi_rcv_rsp) from [<c02fced0>] (__netif_receive_skb_core+0x6c0/0x7fc)
[<c02fced0>] (__netif_receive_skb_core) from [<c02fdc14>] (netif_receive_skb_internal+0xb4/0x138)
[<c02fdc14>] (netif_receive_skb_internal) from [<c02fe8a4>] (napi_gro_receive+0x48/0x9c)
[<c02fe8a4>] (napi_gro_receive) from [<c0264588>] (ftgmac100_poll+0x38c/0x5b8)
[<c0264588>] (ftgmac100_poll) from [<c02fe0b4>] (net_rx_action+0xe8/0x2a0)
[<c02fe0b4>] (net_rx_action) from [<c0019618>] (__do_softirq+0x108/0x26c)
[<c0019618>] (__do_softirq) from [<c001981c>] (do_softirq+0x48/0x70)
[<c001981c>] (do_softirq) from [<c001990c>] (__local_bh_enable_ip+0xc8/0x104)
[<c001990c>] (__local_bh_enable_ip) from [<c0300c08>] (__dev_queue_xmit+0x658/0x6cc)
[<c0300c08>] (__dev_queue_xmit) from [<c039f36c>] (ncsi_xmit_cmd+0x1ac/0x208)
[<c039f36c>] (ncsi_xmit_cmd) from [<c03a0f54>] (ncsi_dev_start+0x84/0x3c0)
[<c03a0f54>] (ncsi_dev_start) from [<c03a1a00>] (ncsi_dev_work+0x1b8/0x1fc)
[<c03a1a00>] (ncsi_dev_work) from [<c002b7c8>] (process_one_work+0x22c/0x3d0)
[<c002b7c8>] (process_one_work) from [<c002beb8>] (worker_thread+0x2a4/0x3dc)
[<c002beb8>] (worker_thread) from [<c00301bc>] (kthread+0xc4/0xd8)
[<c00301bc>] (kthread) from [<c000a3b0>] (ret_from_fork+0x14/0x24)
Sending discover...
BUG: spinlock lockup suspected on CPU#0, kworker/0:0/810
 lock: 0xcfa00050, .magic: dead4ead, .owner: kworker/0:0/810, .owner_cpu: 0
CPU: 0 PID: 810 Comm: kworker/0:0 Not tainted 4.2.0-00056-gd4643a2 #54
Hardware name: ASpeed SoC
Workqueue: events ncsi_dev_work
[<c000f2a0>] (unwind_backtrace) from [<c000cf48>] (show_stack+0x10/0x14)
[<c000cf48>] (show_stack) from [<c004394c>] (do_raw_spin_lock+0xd4/0x118)
[<c004394c>] (do_raw_spin_lock) from [<c03a1c24>] (ncsi_free_req+0x3c/0xe0)
[<c03a1c24>] (ncsi_free_req) from [<c03a092c>] (ncsi_rcv_rsp+0xec/0xfc)
[<c03a092c>] (ncsi_rcv_rsp) from [<c02fced0>] (__netif_receive_skb_core+0x6c0/0x7fc)
[<c02fced0>] (__netif_receive_skb_core) from [<c02fdc14>] (netif_receive_skb_internal+0xb4/0x138)
[<c02fdc14>] (netif_receive_skb_internal) from [<c02fe8a4>] (napi_gro_receive+0x48/0x9c)
[<c02fe8a4>] (napi_gro_receive) from [<c0264588>] (ftgmac100_poll+0x38c/0x5b8)
[<c0264588>] (ftgmac100_poll) from [<c02fe0b4>] (net_rx_action+0xe8/0x2a0)
[<c02fe0b4>] (net_rx_action) from [<c0019618>] (__do_softirq+0x108/0x26c)
[<c0019618>] (__do_softirq) from [<c0019a40>] (irq_exit+0x80/0xc0)
[<c0019a40>] (irq_exit) from [<c0049320>] (__handle_domain_irq+0x84/0xa0)
[<c0049320>] (__handle_domain_irq) from [<c0009438>] (avic_handle_irq+0x5c/0x64)
[<c0009438>] (avic_handle_irq) from [<c000d9c4>] (__irq_svc+0x44/0x54)
Exception stack(0xc895fdc8 to 0xc895fe10)
fdc0:                   cfa13e60 0000000e cc3cf500 cc3cf502 0000000e 00000000
fde0: 00000010 c895fe3c c1e6a3b4 cc1d2800 00000000 00000001 00000000 c895fe10
fe00: c039f314 c02efbf8 20000013 ffffffff
[<c000d9c4>] (__irq_svc) from [<c02efbf8>] (skb_push+0x38/0x44)
[<c02efbf8>] (skb_push) from [<c039f314>] (ncsi_xmit_cmd+0x154/0x208)
[<c039f314>] (ncsi_xmit_cmd) from [<c03a0fa0>] (ncsi_dev_start+0xd0/0x3c0)
[<c03a0fa0>] (ncsi_dev_start) from [<c03a1a00>] (ncsi_dev_work+0x1b8/0x1fc)
[<c03a1a00>] (ncsi_dev_work) from [<c002b7c8>] (process_one_work+0x22c/0x3d0)
[<c002b7c8>] (process_one_work) from [<c002beb8>] (worker_thread+0x2a4/0x3dc)
[<c002beb8>] (worker_thread) from [<c00301bc>] (kthread+0xc4/0xd8)
[<c00301bc>] (kthread) from [<c000a3b0>] (ret_from_fork+0x14/0x24)

[gwshan]

There is a spinlock protecting all NCSI request, which contains a command and possibly a response. In Tx path, the spinlock is taken before grabbing a available NCSI request from 256-elements table. In Rx path (NAPI & softIRQ), the lock is taken and then ingress skb is associated with the NCSI request. In the timer handler, the lock is taken as well before checking the state NCSI request.

According to the above backtrace dumped by LOCKDEP, we need disable external interrupt while taking the lock to avoid the possible dead-lock.

[jk-ozlabs]

@gwshan so this is a matter of replacing a spin_lock() with a spin_lock_irqsave() ?

[gwshan]

Yes I think so, jk

[shenki]

We made this change, and I cannot reproduce with our 4.4 based tree.