[PATCH] usbnet: fix kernel crash after disconnect

[PATCH] usbnet: fix kernel crash after disconnect

[Kloetzke Jan]

When disconnecting cdc_ncm the kernel sporadically crashes shortly
after the disconnect:

  [   57.868812] Unable to handle kernel NULL pointer dereference at virtual address 00000000
  ...
  [   58.006653] PC is at 0x0
  [   58.009202] LR is at call_timer_fn+0xec/0x1b4
  [   58.013567] pc : [<0000000000000000>] lr : [<ffffff80080f5130>] pstate: 00000145
  [   58.020976] sp : ffffff8008003da0
  [   58.024295] x29: ffffff8008003da0 x28: 0000000000000001
  [   58.029618] x27: 000000000000000a x26: 0000000000000100
  [   58.034941] x25: 0000000000000000 x24: ffffff8008003e68
  [   58.040263] x23: 0000000000000000 x22: 0000000000000000
  [   58.045587] x21: 0000000000000000 x20: ffffffc68fac1808
  [   58.050910] x19: 0000000000000100 x18: 0000000000000000
  [   58.056232] x17: 0000007f885aff8c x16: 0000007f883a9f10
  [   58.061556] x15: 0000000000000001 x14: 000000000000006e
  [   58.066878] x13: 0000000000000000 x12: 00000000000000ba
  [   58.072201] x11: ffffffc69ff1db30 x10: 0000000000000020
  [   58.077524] x9 : 8000100008001000 x8 : 0000000000000001
  [   58.082847] x7 : 0000000000000800 x6 : ffffff8008003e70
  [   58.088169] x5 : ffffffc69ff17a28 x4 : 00000000ffff138b
  [   58.093492] x3 : 0000000000000000 x2 : 0000000000000000
  [   58.098814] x1 : 0000000000000000 x0 : 0000000000000000
  ...
  [   58.205800] [<          (null)>]           (null)
  [   58.210521] [<ffffff80080f5298>] expire_timers+0xa0/0x14c
  [   58.215937] [<ffffff80080f542c>] run_timer_softirq+0xe8/0x128
  [   58.221702] [<ffffff8008081120>] __do_softirq+0x298/0x348
  [   58.227118] [<ffffff80080a6304>] irq_exit+0x74/0xbc
  [   58.232009] [<ffffff80080e17dc>] __handle_domain_irq+0x78/0xac
  [   58.237857] [<ffffff8008080cf4>] gic_handle_irq+0x80/0xac
  ...

The crash happens roughly 125..130ms after the disconnect. This
correlates with the 'delay' timer that is started on certain USB tx/rx
errors in the URB completion handler.

The suspected problem is a race of usbnet_stop() with
usbnet_start_xmit(). In usbnet_stop() we call usbnet_terminate_urbs()
to cancel all URBs in flight. This only makes sense if no new URBs are
submitted concurrently, though. But the usbnet_start_xmit() can run at
the same time on another CPU which almost unconditionally submits an
URB. The error callback of the new URB will then schedule the timer
after it was already stopped.

The fix adds a check if the tx queue is stopped after the tx list lock
has been taken. This should reliably prevent the submission of new URBs
while usbnet_terminate_urbs() does its job. The same thing is done on
the rx side even though it might be safe due to other flags that are
checked there.

Signed-off-by: Jan Klötzke <Jan.Kloetzke@preh.de>
---
 drivers/net/usb/usbnet.c | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/drivers/net/usb/usbnet.c b/drivers/net/usb/usbnet.c
index 504282af27e5..921cc0571bd0 100644
--- a/drivers/net/usb/usbnet.c
+++ b/drivers/net/usb/usbnet.c
@@ -506,6 +506,7 @@ static int rx_submit (struct usbnet *dev, struct urb *urb, gfp_t flags)
 
 	if (netif_running (dev->net) &&
 	    netif_device_present (dev->net) &&
+	    test_bit(EVENT_DEV_OPEN, &dev->flags) &&
 	    !test_bit (EVENT_RX_HALT, &dev->flags) &&
 	    !test_bit (EVENT_DEV_ASLEEP, &dev->flags)) {
 		switch (retval = usb_submit_urb (urb, GFP_ATOMIC)) {
@@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
 		spin_unlock_irqrestore(&dev->txq.lock, flags);
 		goto drop;
 	}
+	if (netif_queue_stopped(net)) {
+		usb_autopm_put_interface_async(dev->intf);
+		spin_unlock_irqrestore(&dev->txq.lock, flags);
+		goto drop;
+	}
 
 #ifdef CONFIG_PM
 	/* if this triggers the device is still a sleep */
-- 
2.11.0

usbnet: fix kernel crash after disconnect

[Kloetzke Jan]

When disconnecting cdc_ncm the kernel sporadically crashes shortly
after the disconnect:

  [   57.868812] Unable to handle kernel NULL pointer dereference at virtual address 00000000
  ...
  [   58.006653] PC is at 0x0
  [   58.009202] LR is at call_timer_fn+0xec/0x1b4
  [   58.013567] pc : [<0000000000000000>] lr : [<ffffff80080f5130>] pstate: 00000145
  [   58.020976] sp : ffffff8008003da0
  [   58.024295] x29: ffffff8008003da0 x28: 0000000000000001
  [   58.029618] x27: 000000000000000a x26: 0000000000000100
  [   58.034941] x25: 0000000000000000 x24: ffffff8008003e68
  [   58.040263] x23: 0000000000000000 x22: 0000000000000000
  [   58.045587] x21: 0000000000000000 x20: ffffffc68fac1808
  [   58.050910] x19: 0000000000000100 x18: 0000000000000000
  [   58.056232] x17: 0000007f885aff8c x16: 0000007f883a9f10
  [   58.061556] x15: 0000000000000001 x14: 000000000000006e
  [   58.066878] x13: 0000000000000000 x12: 00000000000000ba
  [   58.072201] x11: ffffffc69ff1db30 x10: 0000000000000020
  [   58.077524] x9 : 8000100008001000 x8 : 0000000000000001
  [   58.082847] x7 : 0000000000000800 x6 : ffffff8008003e70
  [   58.088169] x5 : ffffffc69ff17a28 x4 : 00000000ffff138b
  [   58.093492] x3 : 0000000000000000 x2 : 0000000000000000
  [   58.098814] x1 : 0000000000000000 x0 : 0000000000000000
  ...
  [   58.205800] [<          (null)>]           (null)
  [   58.210521] [<ffffff80080f5298>] expire_timers+0xa0/0x14c
  [   58.215937] [<ffffff80080f542c>] run_timer_softirq+0xe8/0x128
  [   58.221702] [<ffffff8008081120>] __do_softirq+0x298/0x348
  [   58.227118] [<ffffff80080a6304>] irq_exit+0x74/0xbc
  [   58.232009] [<ffffff80080e17dc>] __handle_domain_irq+0x78/0xac
  [   58.237857] [<ffffff8008080cf4>] gic_handle_irq+0x80/0xac
  ...

The crash happens roughly 125..130ms after the disconnect. This
correlates with the 'delay' timer that is started on certain USB tx/rx
errors in the URB completion handler.

The suspected problem is a race of usbnet_stop() with
usbnet_start_xmit(). In usbnet_stop() we call usbnet_terminate_urbs()
to cancel all URBs in flight. This only makes sense if no new URBs are
submitted concurrently, though. But the usbnet_start_xmit() can run at
the same time on another CPU which almost unconditionally submits an
URB. The error callback of the new URB will then schedule the timer
after it was already stopped.

The fix adds a check if the tx queue is stopped after the tx list lock
has been taken. This should reliably prevent the submission of new URBs
while usbnet_terminate_urbs() does its job. The same thing is done on
the rx side even though it might be safe due to other flags that are
checked there.

Signed-off-by: Jan Klötzke <Jan.Kloetzke@preh.de>
---
 drivers/net/usb/usbnet.c | 6 ++++++
 1 file changed, 6 insertions(+)

-- 
2.11.0

diff --git a/drivers/net/usb/usbnet.c b/drivers/net/usb/usbnet.c
index 504282af27e5..921cc0571bd0 100644
--- a/drivers/net/usb/usbnet.c
+++ b/drivers/net/usb/usbnet.c
@@ -506,6 +506,7 @@ static int rx_submit (struct usbnet *dev, struct urb *urb, gfp_t flags)
 
 	if (netif_running (dev->net) &&
 	    netif_device_present (dev->net) &&
+	    test_bit(EVENT_DEV_OPEN, &dev->flags) &&
 	    !test_bit (EVENT_RX_HALT, &dev->flags) &&
 	    !test_bit (EVENT_DEV_ASLEEP, &dev->flags)) {
 		switch (retval = usb_submit_urb (urb, GFP_ATOMIC)) {
@@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
 		spin_unlock_irqrestore(&dev->txq.lock, flags);
 		goto drop;
 	}
+	if (netif_queue_stopped(net)) {
+		usb_autopm_put_interface_async(dev->intf);
+		spin_unlock_irqrestore(&dev->txq.lock, flags);
+		goto drop;
+	}
 
 #ifdef CONFIG_PM
 	/* if this triggers the device is still a sleep */

Re: [PATCH] usbnet: fix kernel crash after disconnect

[Oliver Neukum]

On Mi, 2019-04-17 at 09:19 +0000, Kloetzke Jan wrote:
> When disconnecting cdc_ncm the kernel sporadically crashes shortly
> after the disconnect:
> 
>   [   57.868812] Unable to handle kernel NULL pointer dereference at virtual address 00000000
>   ...
>   [   58.006653] PC is at 0x0
>   [   58.009202] LR is at call_timer_fn+0xec/0x1b4
>   [   58.013567] pc : [<0000000000000000>] lr : [<ffffff80080f5130>] pstate: 00000145
>   [   58.020976] sp : ffffff8008003da0
>   [   58.024295] x29: ffffff8008003da0 x28: 0000000000000001
>   [   58.029618] x27: 000000000000000a x26: 0000000000000100
>   [   58.034941] x25: 0000000000000000 x24: ffffff8008003e68
>   [   58.040263] x23: 0000000000000000 x22: 0000000000000000
>   [   58.045587] x21: 0000000000000000 x20: ffffffc68fac1808
>   [   58.050910] x19: 0000000000000100 x18: 0000000000000000
>   [   58.056232] x17: 0000007f885aff8c x16: 0000007f883a9f10
>   [   58.061556] x15: 0000000000000001 x14: 000000000000006e
>   [   58.066878] x13: 0000000000000000 x12: 00000000000000ba
>   [   58.072201] x11: ffffffc69ff1db30 x10: 0000000000000020
>   [   58.077524] x9 : 8000100008001000 x8 : 0000000000000001
>   [   58.082847] x7 : 0000000000000800 x6 : ffffff8008003e70
>   [   58.088169] x5 : ffffffc69ff17a28 x4 : 00000000ffff138b
>   [   58.093492] x3 : 0000000000000000 x2 : 0000000000000000
>   [   58.098814] x1 : 0000000000000000 x0 : 0000000000000000
>   ...
>   [   58.205800] [<          (null)>]           (null)
>   [   58.210521] [<ffffff80080f5298>] expire_timers+0xa0/0x14c
>   [   58.215937] [<ffffff80080f542c>] run_timer_softirq+0xe8/0x128
>   [   58.221702] [<ffffff8008081120>] __do_softirq+0x298/0x348
>   [   58.227118] [<ffffff80080a6304>] irq_exit+0x74/0xbc
>   [   58.232009] [<ffffff80080e17dc>] __handle_domain_irq+0x78/0xac
>   [   58.237857] [<ffffff8008080cf4>] gic_handle_irq+0x80/0xac
>   ...
> 
> The crash happens roughly 125..130ms after the disconnect. This
> correlates with the 'delay' timer that is started on certain USB tx/rx
> errors in the URB completion handler.
> 
> The suspected problem is a race of usbnet_stop() with
> usbnet_start_xmit(). In usbnet_stop() we call usbnet_terminate_urbs()
> to cancel all URBs in flight. This only makes sense if no new URBs are
> submitted concurrently, though. But the usbnet_start_xmit() can run at
> the same time on another CPU which almost unconditionally submits an
> URB. The error callback of the new URB will then schedule the timer
> after it was already stopped.

Hi,

interesting. How sure are you of the details of your analysis?
I am asking because usbnet_stop() does a del_timer_sync().
It is indeed written under the assumption that the upper layer
will have ceased transmission when it stops an interface.

So I am wondering whether the correct fix would not be to make
sure the timer is started.

	Regards
		Oliver

usbnet: fix kernel crash after disconnect

[Oliver Neukum]

On Mi, 2019-04-17 at 09:19 +0000, Kloetzke Jan wrote:
> When disconnecting cdc_ncm the kernel sporadically crashes shortly
> after the disconnect:
> 
>   [   57.868812] Unable to handle kernel NULL pointer dereference at virtual address 00000000
>   ...
>   [   58.006653] PC is at 0x0
>   [   58.009202] LR is at call_timer_fn+0xec/0x1b4
>   [   58.013567] pc : [<0000000000000000>] lr : [<ffffff80080f5130>] pstate: 00000145
>   [   58.020976] sp : ffffff8008003da0
>   [   58.024295] x29: ffffff8008003da0 x28: 0000000000000001
>   [   58.029618] x27: 000000000000000a x26: 0000000000000100
>   [   58.034941] x25: 0000000000000000 x24: ffffff8008003e68
>   [   58.040263] x23: 0000000000000000 x22: 0000000000000000
>   [   58.045587] x21: 0000000000000000 x20: ffffffc68fac1808
>   [   58.050910] x19: 0000000000000100 x18: 0000000000000000
>   [   58.056232] x17: 0000007f885aff8c x16: 0000007f883a9f10
>   [   58.061556] x15: 0000000000000001 x14: 000000000000006e
>   [   58.066878] x13: 0000000000000000 x12: 00000000000000ba
>   [   58.072201] x11: ffffffc69ff1db30 x10: 0000000000000020
>   [   58.077524] x9 : 8000100008001000 x8 : 0000000000000001
>   [   58.082847] x7 : 0000000000000800 x6 : ffffff8008003e70
>   [   58.088169] x5 : ffffffc69ff17a28 x4 : 00000000ffff138b
>   [   58.093492] x3 : 0000000000000000 x2 : 0000000000000000
>   [   58.098814] x1 : 0000000000000000 x0 : 0000000000000000
>   ...
>   [   58.205800] [<          (null)>]           (null)
>   [   58.210521] [<ffffff80080f5298>] expire_timers+0xa0/0x14c
>   [   58.215937] [<ffffff80080f542c>] run_timer_softirq+0xe8/0x128
>   [   58.221702] [<ffffff8008081120>] __do_softirq+0x298/0x348
>   [   58.227118] [<ffffff80080a6304>] irq_exit+0x74/0xbc
>   [   58.232009] [<ffffff80080e17dc>] __handle_domain_irq+0x78/0xac
>   [   58.237857] [<ffffff8008080cf4>] gic_handle_irq+0x80/0xac
>   ...
> 
> The crash happens roughly 125..130ms after the disconnect. This
> correlates with the 'delay' timer that is started on certain USB tx/rx
> errors in the URB completion handler.
> 
> The suspected problem is a race of usbnet_stop() with
> usbnet_start_xmit(). In usbnet_stop() we call usbnet_terminate_urbs()
> to cancel all URBs in flight. This only makes sense if no new URBs are
> submitted concurrently, though. But the usbnet_start_xmit() can run at
> the same time on another CPU which almost unconditionally submits an
> URB. The error callback of the new URB will then schedule the timer
> after it was already stopped.

Hi,

interesting. How sure are you of the details of your analysis?
I am asking because usbnet_stop() does a del_timer_sync().
It is indeed written under the assumption that the upper layer
will have ceased transmission when it stops an interface.

So I am wondering whether the correct fix would not be to make
sure the timer is started.

	Regards
		Oliver

Re: [PATCH] usbnet: fix kernel crash after disconnect

[Kloetzke Jan]

Hi,

Am Donnerstag, den 18.04.2019, 08:37 +0200 schrieb Oliver Neukum:
> On Mi, 2019-04-17 at 09:19 +0000, Kloetzke Jan wrote:
> > When disconnecting cdc_ncm the kernel sporadically crashes shortly
> > after the disconnect:
> > 
> >   [   57.868812] Unable to handle kernel NULL pointer dereference
> > at virtual address 00000000
> >   ...
> >   [   58.006653] PC is at 0x0
> >   [   58.009202] LR is at call_timer_fn+0xec/0x1b4
> >   [   58.013567] pc : [<0000000000000000>] lr :
> > [<ffffff80080f5130>] pstate: 00000145
> >   [   58.020976] sp : ffffff8008003da0
> >   [   58.024295] x29: ffffff8008003da0 x28: 0000000000000001
> >   [   58.029618] x27: 000000000000000a x26: 0000000000000100
> >   [   58.034941] x25: 0000000000000000 x24: ffffff8008003e68
> >   [   58.040263] x23: 0000000000000000 x22: 0000000000000000
> >   [   58.045587] x21: 0000000000000000 x20: ffffffc68fac1808
> >   [   58.050910] x19: 0000000000000100 x18: 0000000000000000
> >   [   58.056232] x17: 0000007f885aff8c x16: 0000007f883a9f10
> >   [   58.061556] x15: 0000000000000001 x14: 000000000000006e
> >   [   58.066878] x13: 0000000000000000 x12: 00000000000000ba
> >   [   58.072201] x11: ffffffc69ff1db30 x10: 0000000000000020
> >   [   58.077524] x9 : 8000100008001000 x8 : 0000000000000001
> >   [   58.082847] x7 : 0000000000000800 x6 : ffffff8008003e70
> >   [   58.088169] x5 : ffffffc69ff17a28 x4 : 00000000ffff138b
> >   [   58.093492] x3 : 0000000000000000 x2 : 0000000000000000
> >   [   58.098814] x1 : 0000000000000000 x0 : 0000000000000000
> >   ...
> >   [   58.205800] [<          (null)>]           (null)
> >   [   58.210521] [<ffffff80080f5298>] expire_timers+0xa0/0x14c
> >   [   58.215937] [<ffffff80080f542c>] run_timer_softirq+0xe8/0x128
> >   [   58.221702] [<ffffff8008081120>] __do_softirq+0x298/0x348
> >   [   58.227118] [<ffffff80080a6304>] irq_exit+0x74/0xbc
> >   [   58.232009] [<ffffff80080e17dc>] __handle_domain_irq+0x78/0xac
> >   [   58.237857] [<ffffff8008080cf4>] gic_handle_irq+0x80/0xac
> >   ...
> > 
> > The crash happens roughly 125..130ms after the disconnect. This
> > correlates with the 'delay' timer that is started on certain USB
> > tx/rx
> > errors in the URB completion handler.
> > 
> > The suspected problem is a race of usbnet_stop() with
> > usbnet_start_xmit(). In usbnet_stop() we call
> > usbnet_terminate_urbs()
> > to cancel all URBs in flight. This only makes sense if no new URBs
> > are
> > submitted concurrently, though. But the usbnet_start_xmit() can run
> > at
> > the same time on another CPU which almost unconditionally submits
> > an
> > URB. The error callback of the new URB will then schedule the timer
> > after it was already stopped.
> 
> Hi,
> 
> interesting. How sure are you of the details of your analysis?

We have seen the issue sporadically, maybe once a month, on our IVI
system with dozens of units being tested all day long. We have the fix
in the field since three months and got no further reports so far. So
I'm relatively optimistic that the patch solves the problem.

> I am asking because usbnet_stop() does a del_timer_sync().
> It is indeed written under the assumption that the upper layer
> will have ceased transmission when it stops an interface.

I think this assumption is not correct. As far as I understand the
networking code it is still possible that the ndo_start_xmit callback
is called while ndo_stop is running and even after ndo_stop has
returned. You can only be sure after unregister_netdev() has returned.
Maybe some networking folks can comment on that.

> So I am wondering whether the correct fix would not be to make
> sure the timer is started.

I think the real problem is that new URBs are submitted concurrently.
The timer is just a secondary problem that blows up later. But if my
above assumption wrt. ndo_stop/ndo_start_xmit is not correct then the
patch would be indeed wrong.

Regards,
Jan

usbnet: fix kernel crash after disconnect

[Kloetzke Jan]

Hi,

Am Donnerstag, den 18.04.2019, 08:37 +0200 schrieb Oliver Neukum:
> On Mi, 2019-04-17 at 09:19 +0000, Kloetzke Jan wrote:
> > When disconnecting cdc_ncm the kernel sporadically crashes shortly
> > after the disconnect:
> > 
> >   [   57.868812] Unable to handle kernel NULL pointer dereference
> > at virtual address 00000000
> >   ...
> >   [   58.006653] PC is at 0x0
> >   [   58.009202] LR is at call_timer_fn+0xec/0x1b4
> >   [   58.013567] pc : [<0000000000000000>] lr :
> > [<ffffff80080f5130>] pstate: 00000145
> >   [   58.020976] sp : ffffff8008003da0
> >   [   58.024295] x29: ffffff8008003da0 x28: 0000000000000001
> >   [   58.029618] x27: 000000000000000a x26: 0000000000000100
> >   [   58.034941] x25: 0000000000000000 x24: ffffff8008003e68
> >   [   58.040263] x23: 0000000000000000 x22: 0000000000000000
> >   [   58.045587] x21: 0000000000000000 x20: ffffffc68fac1808
> >   [   58.050910] x19: 0000000000000100 x18: 0000000000000000
> >   [   58.056232] x17: 0000007f885aff8c x16: 0000007f883a9f10
> >   [   58.061556] x15: 0000000000000001 x14: 000000000000006e
> >   [   58.066878] x13: 0000000000000000 x12: 00000000000000ba
> >   [   58.072201] x11: ffffffc69ff1db30 x10: 0000000000000020
> >   [   58.077524] x9 : 8000100008001000 x8 : 0000000000000001
> >   [   58.082847] x7 : 0000000000000800 x6 : ffffff8008003e70
> >   [   58.088169] x5 : ffffffc69ff17a28 x4 : 00000000ffff138b
> >   [   58.093492] x3 : 0000000000000000 x2 : 0000000000000000
> >   [   58.098814] x1 : 0000000000000000 x0 : 0000000000000000
> >   ...
> >   [   58.205800] [<          (null)>]           (null)
> >   [   58.210521] [<ffffff80080f5298>] expire_timers+0xa0/0x14c
> >   [   58.215937] [<ffffff80080f542c>] run_timer_softirq+0xe8/0x128
> >   [   58.221702] [<ffffff8008081120>] __do_softirq+0x298/0x348
> >   [   58.227118] [<ffffff80080a6304>] irq_exit+0x74/0xbc
> >   [   58.232009] [<ffffff80080e17dc>] __handle_domain_irq+0x78/0xac
> >   [   58.237857] [<ffffff8008080cf4>] gic_handle_irq+0x80/0xac
> >   ...
> > 
> > The crash happens roughly 125..130ms after the disconnect. This
> > correlates with the 'delay' timer that is started on certain USB
> > tx/rx
> > errors in the URB completion handler.
> > 
> > The suspected problem is a race of usbnet_stop() with
> > usbnet_start_xmit(). In usbnet_stop() we call
> > usbnet_terminate_urbs()
> > to cancel all URBs in flight. This only makes sense if no new URBs
> > are
> > submitted concurrently, though. But the usbnet_start_xmit() can run
> > at
> > the same time on another CPU which almost unconditionally submits
> > an
> > URB. The error callback of the new URB will then schedule the timer
> > after it was already stopped.
> 
> Hi,
> 
> interesting. How sure are you of the details of your analysis?

We have seen the issue sporadically, maybe once a month, on our IVI
system with dozens of units being tested all day long. We have the fix
in the field since three months and got no further reports so far. So
I'm relatively optimistic that the patch solves the problem.

> I am asking because usbnet_stop() does a del_timer_sync().
> It is indeed written under the assumption that the upper layer
> will have ceased transmission when it stops an interface.

I think this assumption is not correct. As far as I understand the
networking code it is still possible that the ndo_start_xmit callback
is called while ndo_stop is running and even after ndo_stop has
returned. You can only be sure after unregister_netdev() has returned.
Maybe some networking folks can comment on that.

> So I am wondering whether the correct fix would not be to make
> sure the timer is started.

I think the real problem is that new URBs are submitted concurrently.
The timer is just a secondary problem that blows up later. But if my
above assumption wrt. ndo_stop/ndo_start_xmit is not correct then the
patch would be indeed wrong.

Regards,
Jan

Re: [PATCH] usbnet: fix kernel crash after disconnect

[David Miller]

From: Kloetzke Jan <Jan.Kloetzke@preh.de>
Date: Thu, 18 Apr 2019 08:02:59 +0000

> I think this assumption is not correct. As far as I understand the
> networking code it is still possible that the ndo_start_xmit callback
> is called while ndo_stop is running and even after ndo_stop has
> returned. You can only be sure after unregister_netdev() has returned.
> Maybe some networking folks can comment on that.

The kernel loops over the devices being unregistered, and first it clears
the __LINK_STATE_START on all of them, then it invokes ->ndo_stop() on
all of them.

__LINK_STATE_START controls what netif_running() returns.

All calls to ->ndo_start_xmit() are guarded by netif_running() checks.

So when ndo_stop is invoked you should get no more ndo_start_xmit
invocations on that device.  Otherwise how could you shut down DMA
resources and turn off the TX engine properly?

usbnet: fix kernel crash after disconnect

[David Miller]

From: Kloetzke Jan <Jan.Kloetzke@preh.de>
Date: Thu, 18 Apr 2019 08:02:59 +0000

> I think this assumption is not correct. As far as I understand the
> networking code it is still possible that the ndo_start_xmit callback
> is called while ndo_stop is running and even after ndo_stop has
> returned. You can only be sure after unregister_netdev() has returned.
> Maybe some networking folks can comment on that.

The kernel loops over the devices being unregistered, and first it clears
the __LINK_STATE_START on all of them, then it invokes ->ndo_stop() on
all of them.

__LINK_STATE_START controls what netif_running() returns.

All calls to ->ndo_start_xmit() are guarded by netif_running() checks.

So when ndo_stop is invoked you should get no more ndo_start_xmit
invocations on that device.  Otherwise how could you shut down DMA
resources and turn off the TX engine properly?

Re: [PATCH] usbnet: fix kernel crash after disconnect

[Jan Klötzke]

Hi David,

On Thu, Apr 18, 2019 at 04:35:44PM -0700, David Miller wrote:
> From: Kloetzke Jan <Jan.Kloetzke@preh.de>
> Date: Thu, 18 Apr 2019 08:02:59 +0000
> 
> > I think this assumption is not correct. As far as I understand the
> > networking code it is still possible that the ndo_start_xmit callback
> > is called while ndo_stop is running and even after ndo_stop has
> > returned. You can only be sure after unregister_netdev() has returned.
> > Maybe some networking folks can comment on that.
> 
> The kernel loops over the devices being unregistered, and first it clears
> the __LINK_STATE_START on all of them, then it invokes ->ndo_stop() on
> all of them.
> 
> __LINK_STATE_START controls what netif_running() returns.
> 
> All calls to ->ndo_start_xmit() are guarded by netif_running() checks.
> 
> So when ndo_stop is invoked you should get no more ndo_start_xmit
> invocations on that device.  Otherwise how could you shut down DMA
> resources and turn off the TX engine properly?

But you could still race with another CPU that is past the
netif_running() check, can you? So the driver has to make sure that it
gracefully handles concurrent ->ndo_start_xmit() and ->ndo_stop() calls.

Or are there any locks/barriers involved that make sure all
->ndo_start_xmit() calls have returned before invoking ->ndo_stop()?

Regards,
Jan

usbnet: fix kernel crash after disconnect

[Jan Klötzke]

Hi David,

On Thu, Apr 18, 2019 at 04:35:44PM -0700, David Miller wrote:
> From: Kloetzke Jan <Jan.Kloetzke@preh.de>
> Date: Thu, 18 Apr 2019 08:02:59 +0000
> 
> > I think this assumption is not correct. As far as I understand the
> > networking code it is still possible that the ndo_start_xmit callback
> > is called while ndo_stop is running and even after ndo_stop has
> > returned. You can only be sure after unregister_netdev() has returned.
> > Maybe some networking folks can comment on that.
> 
> The kernel loops over the devices being unregistered, and first it clears
> the __LINK_STATE_START on all of them, then it invokes ->ndo_stop() on
> all of them.
> 
> __LINK_STATE_START controls what netif_running() returns.
> 
> All calls to ->ndo_start_xmit() are guarded by netif_running() checks.
> 
> So when ndo_stop is invoked you should get no more ndo_start_xmit
> invocations on that device.  Otherwise how could you shut down DMA
> resources and turn off the TX engine properly?

But you could still race with another CPU that is past the
netif_running() check, can you? So the driver has to make sure that it
gracefully handles concurrent ->ndo_start_xmit() and ->ndo_stop() calls.

Or are there any locks/barriers involved that make sure all
->ndo_start_xmit() calls have returned before invoking ->ndo_stop()?

Regards,
Jan

Re: [PATCH] usbnet: fix kernel crash after disconnect

[Oliver Neukum]

On Fr, 2019-04-19 at 09:17 +0200, Jan Klötzke  wrote:
> Hi David,
> 
> On Thu, Apr 18, 2019 at 04:35:44PM -0700, David Miller wrote:
> > From: Kloetzke Jan <Jan.Kloetzke@preh.de>
> > Date: Thu, 18 Apr 2019 08:02:59 +0000
> > 
> > > I think this assumption is not correct. As far as I understand the
> > > networking code it is still possible that the ndo_start_xmit callback
> > > is called while ndo_stop is running and even after ndo_stop has
> > > returned. You can only be sure after unregister_netdev() has returned.
> > > Maybe some networking folks can comment on that.
> > 
> > The kernel loops over the devices being unregistered, and first it clears
> > the __LINK_STATE_START on all of them, then it invokes ->ndo_stop() on
> > all of them.
> > 
> > __LINK_STATE_START controls what netif_running() returns.
> > 
> > All calls to ->ndo_start_xmit() are guarded by netif_running() checks.
> > 
> > So when ndo_stop is invoked you should get no more ndo_start_xmit
> > invocations on that device.  Otherwise how could you shut down DMA
> > resources and turn off the TX engine properly?
> 
> But you could still race with another CPU that is past the
> netif_running() check, can you? So the driver has to make sure that it
> gracefully handles concurrent ->ndo_start_xmit() and ->ndo_stop() calls.

Looking at dev_direct_xmit(struct sk_buff *skb, u16 queue_id)
this indeed seems possible. But the documentation says that it is not.

Dave?

> Or are there any locks/barriers involved that make sure all
> ->ndo_start_xmit() calls have returned before invoking ->ndo_stop()?

Jan,

could you make versio of your patch that gives a WARNing if this race
triggers?

	Regards
		Oliver

usbnet: fix kernel crash after disconnect

[Oliver Neukum]

On Fr, 2019-04-19 at 09:17 +0200, Jan Klötzke  wrote:
> Hi David,
> 
> On Thu, Apr 18, 2019 at 04:35:44PM -0700, David Miller wrote:
> > From: Kloetzke Jan <Jan.Kloetzke@preh.de>
> > Date: Thu, 18 Apr 2019 08:02:59 +0000
> > 
> > > I think this assumption is not correct. As far as I understand the
> > > networking code it is still possible that the ndo_start_xmit callback
> > > is called while ndo_stop is running and even after ndo_stop has
> > > returned. You can only be sure after unregister_netdev() has returned.
> > > Maybe some networking folks can comment on that.
> > 
> > The kernel loops over the devices being unregistered, and first it clears
> > the __LINK_STATE_START on all of them, then it invokes ->ndo_stop() on
> > all of them.
> > 
> > __LINK_STATE_START controls what netif_running() returns.
> > 
> > All calls to ->ndo_start_xmit() are guarded by netif_running() checks.
> > 
> > So when ndo_stop is invoked you should get no more ndo_start_xmit
> > invocations on that device.  Otherwise how could you shut down DMA
> > resources and turn off the TX engine properly?
> 
> But you could still race with another CPU that is past the
> netif_running() check, can you? So the driver has to make sure that it
> gracefully handles concurrent ->ndo_start_xmit() and ->ndo_stop() calls.

Looking at dev_direct_xmit(struct sk_buff *skb, u16 queue_id)
this indeed seems possible. But the documentation says that it is not.

Dave?

> Or are there any locks/barriers involved that make sure all
> ->ndo_start_xmit() calls have returned before invoking ->ndo_stop()?

Jan,

could you make versio of your patch that gives a WARNing if this race
triggers?

	Regards
		Oliver

Re: [PATCH] usbnet: fix kernel crash after disconnect

[Kloetzke Jan]

Am Montag, den 29.04.2019, 20:48 +0200 schrieb Oliver Neukum:
> On Fr, 2019-04-19 at 09:17 +0200, Jan Klötzke  wrote:
> > Hi David,
> > 
> > On Thu, Apr 18, 2019 at 04:35:44PM -0700, David Miller wrote:
> > > From: Kloetzke Jan <Jan.Kloetzke@preh.de>
> > > Date: Thu, 18 Apr 2019 08:02:59 +0000
> > > 
> > > > I think this assumption is not correct. As far as I understand the
> > > > networking code it is still possible that the ndo_start_xmit callback
> > > > is called while ndo_stop is running and even after ndo_stop has
> > > > returned. You can only be sure after unregister_netdev() has returned.
> > > > Maybe some networking folks can comment on that.
> > > 
> > > The kernel loops over the devices being unregistered, and first it clears
> > > the __LINK_STATE_START on all of them, then it invokes ->ndo_stop() on
> > > all of them.
> > > 
> > > __LINK_STATE_START controls what netif_running() returns.
> > > 
> > > All calls to ->ndo_start_xmit() are guarded by netif_running() checks.
> > > 
> > > So when ndo_stop is invoked you should get no more ndo_start_xmit
> > > invocations on that device.  Otherwise how could you shut down DMA
> > > resources and turn off the TX engine properly?
> > 
> > But you could still race with another CPU that is past the
> > netif_running() check, can you? So the driver has to make sure that it
> > gracefully handles concurrent ->ndo_start_xmit() and ->ndo_stop() calls.
> 
> Looking at dev_direct_xmit(struct sk_buff *skb, u16 queue_id)
> this indeed seems possible. But the documentation says that it is not.
> 
> Dave?
> 
> > Or are there any locks/barriers involved that make sure all
> > ->ndo_start_xmit() calls have returned before invoking ->ndo_stop()?
> 
> Jan,
> 
> could you make versio of your patch that gives a WARNing if this race
> triggers?

Sure. I'll send v2 shortly.

Regards,
Jan

usbnet: fix kernel crash after disconnect

[Kloetzke Jan]

Am Montag, den 29.04.2019, 20:48 +0200 schrieb Oliver Neukum:
> On Fr, 2019-04-19 at 09:17 +0200, Jan Klötzke  wrote:
> > Hi David,
> > 
> > On Thu, Apr 18, 2019 at 04:35:44PM -0700, David Miller wrote:
> > > From: Kloetzke Jan <Jan.Kloetzke@preh.de>
> > > Date: Thu, 18 Apr 2019 08:02:59 +0000
> > > 
> > > > I think this assumption is not correct. As far as I understand the
> > > > networking code it is still possible that the ndo_start_xmit callback
> > > > is called while ndo_stop is running and even after ndo_stop has
> > > > returned. You can only be sure after unregister_netdev() has returned.
> > > > Maybe some networking folks can comment on that.
> > > 
> > > The kernel loops over the devices being unregistered, and first it clears
> > > the __LINK_STATE_START on all of them, then it invokes ->ndo_stop() on
> > > all of them.
> > > 
> > > __LINK_STATE_START controls what netif_running() returns.
> > > 
> > > All calls to ->ndo_start_xmit() are guarded by netif_running() checks.
> > > 
> > > So when ndo_stop is invoked you should get no more ndo_start_xmit
> > > invocations on that device.  Otherwise how could you shut down DMA
> > > resources and turn off the TX engine properly?
> > 
> > But you could still race with another CPU that is past the
> > netif_running() check, can you? So the driver has to make sure that it
> > gracefully handles concurrent ->ndo_start_xmit() and ->ndo_stop() calls.
> 
> Looking at dev_direct_xmit(struct sk_buff *skb, u16 queue_id)
> this indeed seems possible. But the documentation says that it is not.
> 
> Dave?
> 
> > Or are there any locks/barriers involved that make sure all
> > ->ndo_start_xmit() calls have returned before invoking ->ndo_stop()?
> 
> Jan,
> 
> could you make versio of your patch that gives a WARNing if this race
> triggers?

Sure. I'll send v2 shortly.

Regards,
Jan

[PATCH v2] usbnet: fix kernel crash after disconnect

[Kloetzke Jan]

When disconnecting cdc_ncm the kernel sporadically crashes shortly
after the disconnect:

  [   57.868812] Unable to handle kernel NULL pointer dereference at virtual address 00000000
  ...
  [   58.006653] PC is at 0x0
  [   58.009202] LR is at call_timer_fn+0xec/0x1b4
  [   58.013567] pc : [<0000000000000000>] lr : [<ffffff80080f5130>] pstate: 00000145
  [   58.020976] sp : ffffff8008003da0
  [   58.024295] x29: ffffff8008003da0 x28: 0000000000000001
  [   58.029618] x27: 000000000000000a x26: 0000000000000100
  [   58.034941] x25: 0000000000000000 x24: ffffff8008003e68
  [   58.040263] x23: 0000000000000000 x22: 0000000000000000
  [   58.045587] x21: 0000000000000000 x20: ffffffc68fac1808
  [   58.050910] x19: 0000000000000100 x18: 0000000000000000
  [   58.056232] x17: 0000007f885aff8c x16: 0000007f883a9f10
  [   58.061556] x15: 0000000000000001 x14: 000000000000006e
  [   58.066878] x13: 0000000000000000 x12: 00000000000000ba
  [   58.072201] x11: ffffffc69ff1db30 x10: 0000000000000020
  [   58.077524] x9 : 8000100008001000 x8 : 0000000000000001
  [   58.082847] x7 : 0000000000000800 x6 : ffffff8008003e70
  [   58.088169] x5 : ffffffc69ff17a28 x4 : 00000000ffff138b
  [   58.093492] x3 : 0000000000000000 x2 : 0000000000000000
  [   58.098814] x1 : 0000000000000000 x0 : 0000000000000000
  ...
  [   58.205800] [<          (null)>]           (null)
  [   58.210521] [<ffffff80080f5298>] expire_timers+0xa0/0x14c
  [   58.215937] [<ffffff80080f542c>] run_timer_softirq+0xe8/0x128
  [   58.221702] [<ffffff8008081120>] __do_softirq+0x298/0x348
  [   58.227118] [<ffffff80080a6304>] irq_exit+0x74/0xbc
  [   58.232009] [<ffffff80080e17dc>] __handle_domain_irq+0x78/0xac
  [   58.237857] [<ffffff8008080cf4>] gic_handle_irq+0x80/0xac
  ...

The crash happens roughly 125..130ms after the disconnect. This
correlates with the 'delay' timer that is started on certain USB tx/rx
errors in the URB completion handler.

The suspected problem is a race of usbnet_stop() with
usbnet_start_xmit(). In usbnet_stop() we call usbnet_terminate_urbs()
to cancel all URBs in flight. This only makes sense if no new URBs are
submitted concurrently, though. But the usbnet_start_xmit() can run at
the same time on another CPU which almost unconditionally submits an
URB. The error callback of the new URB will then schedule the timer
after it was already stopped.

The fix adds a check if the tx queue is stopped after the tx list lock
has been taken. This should reliably prevent the submission of new URBs
while usbnet_terminate_urbs() does its job. The same thing is done on
the rx side even though it might be safe due to other flags that are
checked there.

Signed-off-by: Jan Klötzke <Jan.Kloetzke@preh.de>
---
 drivers/net/usb/usbnet.c | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/drivers/net/usb/usbnet.c b/drivers/net/usb/usbnet.c
index 504282af27e5..36bb0a4fc320 100644
--- a/drivers/net/usb/usbnet.c
+++ b/drivers/net/usb/usbnet.c
@@ -506,6 +506,7 @@ static int rx_submit (struct usbnet *dev, struct urb *urb, gfp_t flags)
 
 	if (netif_running (dev->net) &&
 	    netif_device_present (dev->net) &&
+	    test_bit(EVENT_DEV_OPEN, &dev->flags) &&
 	    !test_bit (EVENT_RX_HALT, &dev->flags) &&
 	    !test_bit (EVENT_DEV_ASLEEP, &dev->flags)) {
 		switch (retval = usb_submit_urb (urb, GFP_ATOMIC)) {
@@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
 		spin_unlock_irqrestore(&dev->txq.lock, flags);
 		goto drop;
 	}
+	if (WARN_ON(netif_queue_stopped(net))) {
+		usb_autopm_put_interface_async(dev->intf);
+		spin_unlock_irqrestore(&dev->txq.lock, flags);
+		goto drop;
+	}
 
 #ifdef CONFIG_PM
 	/* if this triggers the device is still a sleep */
-- 
2.11.0

[v2] usbnet: fix kernel crash after disconnect

[Kloetzke Jan]

When disconnecting cdc_ncm the kernel sporadically crashes shortly
after the disconnect:

  [   57.868812] Unable to handle kernel NULL pointer dereference at virtual address 00000000
  ...
  [   58.006653] PC is at 0x0
  [   58.009202] LR is at call_timer_fn+0xec/0x1b4
  [   58.013567] pc : [<0000000000000000>] lr : [<ffffff80080f5130>] pstate: 00000145
  [   58.020976] sp : ffffff8008003da0
  [   58.024295] x29: ffffff8008003da0 x28: 0000000000000001
  [   58.029618] x27: 000000000000000a x26: 0000000000000100
  [   58.034941] x25: 0000000000000000 x24: ffffff8008003e68
  [   58.040263] x23: 0000000000000000 x22: 0000000000000000
  [   58.045587] x21: 0000000000000000 x20: ffffffc68fac1808
  [   58.050910] x19: 0000000000000100 x18: 0000000000000000
  [   58.056232] x17: 0000007f885aff8c x16: 0000007f883a9f10
  [   58.061556] x15: 0000000000000001 x14: 000000000000006e
  [   58.066878] x13: 0000000000000000 x12: 00000000000000ba
  [   58.072201] x11: ffffffc69ff1db30 x10: 0000000000000020
  [   58.077524] x9 : 8000100008001000 x8 : 0000000000000001
  [   58.082847] x7 : 0000000000000800 x6 : ffffff8008003e70
  [   58.088169] x5 : ffffffc69ff17a28 x4 : 00000000ffff138b
  [   58.093492] x3 : 0000000000000000 x2 : 0000000000000000
  [   58.098814] x1 : 0000000000000000 x0 : 0000000000000000
  ...
  [   58.205800] [<          (null)>]           (null)
  [   58.210521] [<ffffff80080f5298>] expire_timers+0xa0/0x14c
  [   58.215937] [<ffffff80080f542c>] run_timer_softirq+0xe8/0x128
  [   58.221702] [<ffffff8008081120>] __do_softirq+0x298/0x348
  [   58.227118] [<ffffff80080a6304>] irq_exit+0x74/0xbc
  [   58.232009] [<ffffff80080e17dc>] __handle_domain_irq+0x78/0xac
  [   58.237857] [<ffffff8008080cf4>] gic_handle_irq+0x80/0xac
  ...

The crash happens roughly 125..130ms after the disconnect. This
correlates with the 'delay' timer that is started on certain USB tx/rx
errors in the URB completion handler.

The suspected problem is a race of usbnet_stop() with
usbnet_start_xmit(). In usbnet_stop() we call usbnet_terminate_urbs()
to cancel all URBs in flight. This only makes sense if no new URBs are
submitted concurrently, though. But the usbnet_start_xmit() can run at
the same time on another CPU which almost unconditionally submits an
URB. The error callback of the new URB will then schedule the timer
after it was already stopped.

The fix adds a check if the tx queue is stopped after the tx list lock
has been taken. This should reliably prevent the submission of new URBs
while usbnet_terminate_urbs() does its job. The same thing is done on
the rx side even though it might be safe due to other flags that are
checked there.

Signed-off-by: Jan Klötzke <Jan.Kloetzke@preh.de>
---
 drivers/net/usb/usbnet.c | 6 ++++++
 1 file changed, 6 insertions(+)

-- 
2.11.0

diff --git a/drivers/net/usb/usbnet.c b/drivers/net/usb/usbnet.c
index 504282af27e5..36bb0a4fc320 100644
--- a/drivers/net/usb/usbnet.c
+++ b/drivers/net/usb/usbnet.c
@@ -506,6 +506,7 @@ static int rx_submit (struct usbnet *dev, struct urb *urb, gfp_t flags)
 
 	if (netif_running (dev->net) &&
 	    netif_device_present (dev->net) &&
+	    test_bit(EVENT_DEV_OPEN, &dev->flags) &&
 	    !test_bit (EVENT_RX_HALT, &dev->flags) &&
 	    !test_bit (EVENT_DEV_ASLEEP, &dev->flags)) {
 		switch (retval = usb_submit_urb (urb, GFP_ATOMIC)) {
@@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
 		spin_unlock_irqrestore(&dev->txq.lock, flags);
 		goto drop;
 	}
+	if (WARN_ON(netif_queue_stopped(net))) {
+		usb_autopm_put_interface_async(dev->intf);
+		spin_unlock_irqrestore(&dev->txq.lock, flags);
+		goto drop;
+	}
 
 #ifdef CONFIG_PM
 	/* if this triggers the device is still a sleep */

Re: [PATCH v2] usbnet: fix kernel crash after disconnect

[David Miller]

From: Kloetzke Jan <Jan.Kloetzke@preh.de>
Date: Tue, 30 Apr 2019 14:15:07 +0000

> @@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
>  		spin_unlock_irqrestore(&dev->txq.lock, flags);
>  		goto drop;
>  	}
> +	if (WARN_ON(netif_queue_stopped(net))) {
> +		usb_autopm_put_interface_async(dev->intf);
> +		spin_unlock_irqrestore(&dev->txq.lock, flags);
> +		goto drop;
> +	}

If this is known to happen and is expected, then we should not warn.

[v2] usbnet: fix kernel crash after disconnect

[David Miller]

From: Kloetzke Jan <Jan.Kloetzke@preh.de>
Date: Tue, 30 Apr 2019 14:15:07 +0000

> @@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
>  		spin_unlock_irqrestore(&dev->txq.lock, flags);
>  		goto drop;
>  	}
> +	if (WARN_ON(netif_queue_stopped(net))) {
> +		usb_autopm_put_interface_async(dev->intf);
> +		spin_unlock_irqrestore(&dev->txq.lock, flags);
> +		goto drop;
> +	}

If this is known to happen and is expected, then we should not warn.

Re: [PATCH v2] usbnet: fix kernel crash after disconnect

[Oliver Neukum]

On So, 2019-05-05 at 00:45 -0700, David Miller wrote:
> From: Kloetzke Jan <Jan.Kloetzke@preh.de>
> Date: Tue, 30 Apr 2019 14:15:07 +0000
> 
> > @@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
> >               spin_unlock_irqrestore(&dev->txq.lock, flags);
> >               goto drop;
> >       }
> > +     if (WARN_ON(netif_queue_stopped(net))) {
> > +             usb_autopm_put_interface_async(dev->intf);
> > +             spin_unlock_irqrestore(&dev->txq.lock, flags);
> > +             goto drop;
> > +     }
> 
> If this is known to happen and is expected, then we should not warn.
> 

Hi,

yes this is the point. Can ndo_start_xmit() and ndo_stop() race?
If not, why does the patch fix the observed issue and what
prevents the race? Something is not clear here.

	Regards
		Oliver

Re: [PATCH v2] usbnet: fix kernel crash after disconnect

[Kloetzke Jan]

Am Montag, den 06.05.2019, 10:17 +0200 schrieb Oliver Neukum:
> On So, 2019-05-05 at 00:45 -0700, David Miller wrote:
> > From: Kloetzke Jan <Jan.Kloetzke@preh.de>
> > Date: Tue, 30 Apr 2019 14:15:07 +0000
> > 
> > > @@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
> > >               spin_unlock_irqrestore(&dev->txq.lock, flags);
> > >               goto drop;
> > >       }
> > > +     if (WARN_ON(netif_queue_stopped(net))) {
> > > +             usb_autopm_put_interface_async(dev->intf);
> > > +             spin_unlock_irqrestore(&dev->txq.lock, flags);
> > > +             goto drop;
> > > +     }
> > 
> > If this is known to happen and is expected, then we should not warn.
> > 
> 
> Hi,
> 
> yes this is the point. Can ndo_start_xmit() and ndo_stop() race?
> If not, why does the patch fix the observed issue and what
> prevents the race? Something is not clear here.

Dave, could you shed some light on Olivers question? If the race can
happen then we can stick to v1 because the WARN_ON is indeed pointless.
Otherwise it's not clear why it made the problem go away for us and v2
may be the better option...

Regards,
Jan

Re: [PATCH v2] usbnet: fix kernel crash after disconnect

[David Miller]

From: Kloetzke Jan <Jan.Kloetzke@preh.de>
Date: Thu, 16 May 2019 07:10:30 +0000

> Am Montag, den 06.05.2019, 10:17 +0200 schrieb Oliver Neukum:
>> On So, 2019-05-05 at 00:45 -0700, David Miller wrote:
>> > From: Kloetzke Jan <Jan.Kloetzke@preh.de>
>> > Date: Tue, 30 Apr 2019 14:15:07 +0000
>> > 
>> > > @@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
>> > >               spin_unlock_irqrestore(&dev->txq.lock, flags);
>> > >               goto drop;
>> > >       }
>> > > +     if (WARN_ON(netif_queue_stopped(net))) {
>> > > +             usb_autopm_put_interface_async(dev->intf);
>> > > +             spin_unlock_irqrestore(&dev->txq.lock, flags);
>> > > +             goto drop;
>> > > +     }
>> > 
>> > If this is known to happen and is expected, then we should not warn.
>> > 
>> 
>> yes this is the point. Can ndo_start_xmit() and ndo_stop() race?
>> If not, why does the patch fix the observed issue and what
>> prevents the race? Something is not clear here.
> 
> Dave, could you shed some light on Olivers question? If the race can
> happen then we can stick to v1 because the WARN_ON is indeed pointless.
> Otherwise it's not clear why it made the problem go away for us and v2
> may be the better option...

Yes I think they can race.   ->ndo_stop() executes and stops the queue,
then we get an RCU grace period so that all parallel executions of
->ndo_start_xmit() complete.

But I wonder, this can probably cause problems because some drivers have
"stop queue and re-check" logic, f.e. in drivers/net/tg3.c we have:

	if (unlikely(tg3_tx_avail(tnapi) <= (MAX_SKB_FRAGS + 1))) {
		netif_tx_stop_queue(txq);

		/* netif_tx_stop_queue() must be done before checking
		 * checking tx index in tg3_tx_avail() below, because in
		 * tg3_tx(), we update tx index before checking for
		 * netif_tx_queue_stopped().
		 */
		smp_mb();
		if (tg3_tx_avail(tnapi) > TG3_TX_WAKEUP_THRESH(tnapi))
			netif_tx_wake_queue(txq);
	}

which in the racey scenerio would undo ->ndo_stop()'s work which is
completely unexpected.

Hmmm...

Re: [PATCH v2] usbnet: fix kernel crash after disconnect

[Oliver Neukum]

On Do, 2019-05-16 at 07:10 +0000, Kloetzke Jan wrote:
> Am Montag, den 06.05.2019, 10:17 +0200 schrieb Oliver Neukum:
> > On So, 2019-05-05 at 00:45 -0700, David Miller wrote:
> > > From: Kloetzke Jan <Jan.Kloetzke@preh.de>
> > > Date: Tue, 30 Apr 2019 14:15:07 +0000
> > > 
> > > > @@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
> > > >               spin_unlock_irqrestore(&dev->txq.lock, flags);
> > > >               goto drop;
> > > >       }
> > > > +     if (WARN_ON(netif_queue_stopped(net))) {
> > > > +             usb_autopm_put_interface_async(dev->intf);
> > > > +             spin_unlock_irqrestore(&dev->txq.lock, flags);
> > > > +             goto drop;
> > > > +     }
> > > 
> > > If this is known to happen and is expected, then we should not warn.
> > > 
> > 
> > Hi,
> > 
> > yes this is the point. Can ndo_start_xmit() and ndo_stop() race?
> > If not, why does the patch fix the observed issue and what
> > prevents the race? Something is not clear here.
> 
> Dave, could you shed some light on Olivers question? If the race can
> happen then we can stick to v1 because the WARN_ON is indeed pointless.
> Otherwise it's not clear why it made the problem go away for us and v2
> may be the better option...

Hi,

as Dave confirmed that the race exists, could you resubmit without
the WARN ?

	Regards
		Oliver

Re: [PATCH v2] usbnet: fix kernel crash after disconnect

[Kloetzke Jan]

Hi,

Am Dienstag, den 21.05.2019, 11:48 +0200 schrieb Oliver Neukum:
> On Do, 2019-05-16 at 07:10 +0000, Kloetzke Jan wrote:
> > Am Montag, den 06.05.2019, 10:17 +0200 schrieb Oliver Neukum:
> > > On So, 2019-05-05 at 00:45 -0700, David Miller wrote:
> > > > From: Kloetzke Jan <Jan.Kloetzke@preh.de>
> > > > Date: Tue, 30 Apr 2019 14:15:07 +0000
> > > > 
> > > > > @@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
> > > > >               spin_unlock_irqrestore(&dev->txq.lock, flags);
> > > > >               goto drop;
> > > > >       }
> > > > > +     if (WARN_ON(netif_queue_stopped(net))) {
> > > > > +             usb_autopm_put_interface_async(dev->intf);
> > > > > +             spin_unlock_irqrestore(&dev->txq.lock, flags);
> > > > > +             goto drop;
> > > > > +     }
> > > > 
> > > > If this is known to happen and is expected, then we should not warn.
> > > > 
> > > 
> > > Hi,
> > > 
> > > yes this is the point. Can ndo_start_xmit() and ndo_stop() race?
> > > If not, why does the patch fix the observed issue and what
> > > prevents the race? Something is not clear here.
> > 
> > Dave, could you shed some light on Olivers question? If the race can
> > happen then we can stick to v1 because the WARN_ON is indeed pointless.
> > Otherwise it's not clear why it made the problem go away for us and v2
> > may be the better option...
> 
> Hi,
> 
> as Dave confirmed that the race exists, could you resubmit without
> the WARN ?

Why not just take v1 of the patch?

  https://lore.kernel.org/netdev/20190417091849.7475-1-Jan.Kloetzke@preh.de/

The original version was exactly the same, just without the WARN_ON().
Or is it required to send a v3 in this case?

Regards,
Jan

Re: [PATCH v2] usbnet: fix kernel crash after disconnect

[Oliver Neukum]

On Di, 2019-05-21 at 10:12 +0000, Kloetzke Jan wrote:
> 
> Why not just take v1 of the patch?
> 
>   https://lore.kernel.org/netdev/20190417091849.7475-1-Jan.Kloetzke@preh.de/
> 
> The original version was exactly the same, just without the WARN_ON().
> Or is it required to send a v3 in this case?

It will make things easier for Dave to pick up.

	Regards
		Oliver

[PATCH v3] usbnet: fix kernel crash after disconnect

[Kloetzke Jan]

When disconnecting cdc_ncm the kernel sporadically crashes shortly
after the disconnect:

  [   57.868812] Unable to handle kernel NULL pointer dereference at virtual address 00000000
  ...
  [   58.006653] PC is at 0x0
  [   58.009202] LR is at call_timer_fn+0xec/0x1b4
  [   58.013567] pc : [<0000000000000000>] lr : [<ffffff80080f5130>] pstate: 00000145
  [   58.020976] sp : ffffff8008003da0
  [   58.024295] x29: ffffff8008003da0 x28: 0000000000000001
  [   58.029618] x27: 000000000000000a x26: 0000000000000100
  [   58.034941] x25: 0000000000000000 x24: ffffff8008003e68
  [   58.040263] x23: 0000000000000000 x22: 0000000000000000
  [   58.045587] x21: 0000000000000000 x20: ffffffc68fac1808
  [   58.050910] x19: 0000000000000100 x18: 0000000000000000
  [   58.056232] x17: 0000007f885aff8c x16: 0000007f883a9f10
  [   58.061556] x15: 0000000000000001 x14: 000000000000006e
  [   58.066878] x13: 0000000000000000 x12: 00000000000000ba
  [   58.072201] x11: ffffffc69ff1db30 x10: 0000000000000020
  [   58.077524] x9 : 8000100008001000 x8 : 0000000000000001
  [   58.082847] x7 : 0000000000000800 x6 : ffffff8008003e70
  [   58.088169] x5 : ffffffc69ff17a28 x4 : 00000000ffff138b
  [   58.093492] x3 : 0000000000000000 x2 : 0000000000000000
  [   58.098814] x1 : 0000000000000000 x0 : 0000000000000000
  ...
  [   58.205800] [<          (null)>]           (null)
  [   58.210521] [<ffffff80080f5298>] expire_timers+0xa0/0x14c
  [   58.215937] [<ffffff80080f542c>] run_timer_softirq+0xe8/0x128
  [   58.221702] [<ffffff8008081120>] __do_softirq+0x298/0x348
  [   58.227118] [<ffffff80080a6304>] irq_exit+0x74/0xbc
  [   58.232009] [<ffffff80080e17dc>] __handle_domain_irq+0x78/0xac
  [   58.237857] [<ffffff8008080cf4>] gic_handle_irq+0x80/0xac
  ...

The crash happens roughly 125..130ms after the disconnect. This
correlates with the 'delay' timer that is started on certain USB tx/rx
errors in the URB completion handler.

The problem is a race of usbnet_stop() with usbnet_start_xmit(). In
usbnet_stop() we call usbnet_terminate_urbs() to cancel all URBs in
flight. This only makes sense if no new URBs are submitted
concurrently, though. But the usbnet_start_xmit() can run at the same
time on another CPU which almost unconditionally submits an URB. The
error callback of the new URB will then schedule the timer after it was
already stopped.

The fix adds a check if the tx queue is stopped after the tx list lock
has been taken. This should reliably prevent the submission of new URBs
while usbnet_terminate_urbs() does its job. The same thing is done on
the rx side even though it might be safe due to other flags that are
checked there.

Signed-off-by: Jan Klötzke <Jan.Kloetzke@preh.de>
---

v3: removed WARN_ON() because the race is expected to happen
v2: add WARN_ON() as of Olivers suggestion

 drivers/net/usb/usbnet.c | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/drivers/net/usb/usbnet.c b/drivers/net/usb/usbnet.c
index 504282af27e5..921cc0571bd0 100644
--- a/drivers/net/usb/usbnet.c
+++ b/drivers/net/usb/usbnet.c
@@ -506,6 +506,7 @@ static int rx_submit (struct usbnet *dev, struct urb *urb, gfp_t flags)
 
 	if (netif_running (dev->net) &&
 	    netif_device_present (dev->net) &&
+	    test_bit(EVENT_DEV_OPEN, &dev->flags) &&
 	    !test_bit (EVENT_RX_HALT, &dev->flags) &&
 	    !test_bit (EVENT_DEV_ASLEEP, &dev->flags)) {
 		switch (retval = usb_submit_urb (urb, GFP_ATOMIC)) {
@@ -1431,6 +1432,11 @@ netdev_tx_t usbnet_start_xmit (struct sk_buff *skb,
 		spin_unlock_irqrestore(&dev->txq.lock, flags);
 		goto drop;
 	}
+	if (netif_queue_stopped(net)) {
+		usb_autopm_put_interface_async(dev->intf);
+		spin_unlock_irqrestore(&dev->txq.lock, flags);
+		goto drop;
+	}
 
 #ifdef CONFIG_PM
 	/* if this triggers the device is still a sleep */
-- 
2.11.0

Re: [PATCH v3] usbnet: fix kernel crash after disconnect

[David Miller]

From: Kloetzke Jan <Jan.Kloetzke@preh.de>
Date: Tue, 21 May 2019 13:18:40 +0000

> When disconnecting cdc_ncm the kernel sporadically crashes shortly
> after the disconnect:
 ...
> The crash happens roughly 125..130ms after the disconnect. This
> correlates with the 'delay' timer that is started on certain USB tx/rx
> errors in the URB completion handler.
> 
> The problem is a race of usbnet_stop() with usbnet_start_xmit(). In
> usbnet_stop() we call usbnet_terminate_urbs() to cancel all URBs in
> flight. This only makes sense if no new URBs are submitted
> concurrently, though. But the usbnet_start_xmit() can run at the same
> time on another CPU which almost unconditionally submits an URB. The
> error callback of the new URB will then schedule the timer after it was
> already stopped.
> 
> The fix adds a check if the tx queue is stopped after the tx list lock
> has been taken. This should reliably prevent the submission of new URBs
> while usbnet_terminate_urbs() does its job. The same thing is done on
> the rx side even though it might be safe due to other flags that are
> checked there.
> 
> Signed-off-by: Jan Klötzke <Jan.Kloetzke@preh.de>

Applied.