Skip to contentSkip to conversation

usbnet: Get rid of spammy usbnet "kevent X may have been dropped"

RFC PATCH NAK Douglas Anderson 4 participants 12 messages Sep 19, 2017 – Sep 20, 2017

Subsystems (4)
lore
Share & tools
lore
#0 lore raw

RFC PATCH 1/3 usbnet: Get rid of spammy usbnet "kevent X may have been dropped"

Every once in a while when my system is under a bit of stress I see some spammy messages show up in my logs that say:

kevent X may have been dropped

As far as I can tell these messages aren't terribly useful. The comments around the messages make me think that either workqueues used to work differently or that the original author of the code missed a sublety related to them. The error message appears to predate the git conversion of the kernel so it's somewhat hard to tell.

Specifically, workqueues should work like this:

A) If a workqueue hasn't been scheduled then schedule_work() schedules it and returns true.

B) If a workqueue has been scheduled (but hasn't started) then schedule_work() will do nothing and return false.

C) If a workqueue has been scheduled (and has started) then schedule_work() will put it on the queue to run again and return true.

Said another way: if you call schedule_work() you can guarantee that at least one full runthrough of the work will happen again. That should mean that the work will get processed and I don't see any reason to think something should be dropped.

Reading the comments in in usbnet_defer_kevent() made me think that B) and C) would be treated the same. That is: even if we've started the work and are 99% of the way through then schedule_work() would return false and the work wouldn't be queued again. If schedule_work() really did behave that way then, truly, some amount of work would be lost. ...but it doesn't.

NOTE: if somehow these warnings are useful to mean something then perhaps we should change them to make it more obvious. If it's interesting to know when the work is backlogged then we should change the spam to say "warning: usbnet is backlogged".

ALSO NOTE: If somehow some of the types of work need to be repeated if usbnet_defer_kevent() is called multiple times then that should be quite easy to accomplish without dropping any work on the floor. We can just keep an atomic count for that type of work and add a loop into usbnet_deferred_kevent().

---

 drivers/net/usb/usbnet.c | 16 +++++++---------
 1 file changed, 7 insertions(+), 9 deletions(-)
drivers/net/usb/usbnet.c +7 -9
index 6510e5cc1817..a3e8dbaadcf9 100644
@@ -450,19 +450,17 @@ static enum skb_state defer_bh(struct usbnet *dev, struct sk_buff *skb,
 }
 
 /* some work can't be done in tasklets, so we use keventd
- *
- * NOTE:  annoying asymmetry:  if it's active, schedule_work() fails,
- * but tasklet_schedule() doesn't.  hope the failure is rare.
  */
 void usbnet_defer_kevent (struct usbnet *dev, int work)
 {
 	set_bit (work, &dev->flags);
-	if (!schedule_work (&dev->kevent)) {
-		if (net_ratelimit())
-			netdev_err(dev->net, "kevent %d may have been dropped\n", work);
-	} else {
-		netdev_dbg(dev->net, "kevent %d scheduled\n", work);
-	}
+
+	/* If work is already started this will mark it to run again when it
+	 * finishes; if we already had work pending and it hadn't started
+	 * yet then that's fine too.
+	 */
+	schedule_work (&dev->kevent);
+	netdev_dbg(dev->net, "kevent %d scheduled\n", work);
 }
 EXPORT_SYMBOL_GPL(usbnet_defer_kevent);
 
Signature · 1 line
2.14.1.690.gbb1197296e-goog
#1 lore raw

RFC PATCH 2/3 usbnet: Avoid potential races in usbnet_deferred_kevent()

In general when you've got a flag communicating that "something needs to be done" you want to clear that flag _before_ doing the task. If you clear the flag _after_ doing the task you end up with the risk that this will happen:

1. Requester sets flag saying task A needs to be done.
2. Worker comes and stars doing task A.
3. Worker finishes task A but hasn't yet cleared the flag.
4. Requester wants to set flag saying task A needs to be done again.
5. Worker clears the flag without doing anything.

Let's make the usbnet codebase consistently clear the flag _before_ it does the requested work. That way if there's another request to do the work while the work is already in progress it won't be lost.

NOTES:
- No known bugs are fixed by this; it's just found by code inspection.
- This changes the semantics in some of the error conditions. -> If we fail to clear the "tx halt" or "rx halt" we still clear the flag and thus won't retry the clear next time we happen to be in the work function. Had the old code really wanted to retry these events it should have re-scheduled the worker anyway. -> If we fail to allocate memory in usb_alloc_urb() we will still clear the EVENT_RX_MEMORY flag. This makes it consistent with how we would deal with other failures, including failure to allocate a memory chunk in rx_submit(). It can also be noted that usb_alloc_urb() in this case is allocating much less than 4K worth of data and probably never fails.

---

 drivers/net/usb/usbnet.c | 50 +++++++++++++++++++++---------------------------
 1 file changed, 22 insertions(+), 28 deletions(-)
drivers/net/usb/usbnet.c +22 -28
index a3e8dbaadcf9..e72547d8d0e6 100644
@@ -1103,8 +1103,6 @@ static void __handle_link_change(struct usbnet *dev)
 
 	/* hard_mtu or rx_urb_size may change during link change */
 	usbnet_update_max_qlen(dev);
-
-	clear_bit(EVENT_LINK_CHANGE, &dev->flags);
 }
 
 static void usbnet_set_rx_mode(struct net_device *net)
@@ -1118,8 +1116,6 @@ static void __handle_set_rx_mode(struct usbnet *dev)
 {
 	if (dev->driver_info->set_rx_mode)
 		(dev->driver_info->set_rx_mode)(dev);
-
-	clear_bit(EVENT_SET_RX_MODE, &dev->flags);
 }
 
 /* work that cannot be done in interrupt context uses keventd.
@@ -1135,7 +1131,7 @@ usbnet_deferred_kevent (struct work_struct *work)
 	int			status;
 
 	/* usb_clear_halt() needs a thread context */
-	if (test_bit (EVENT_TX_HALT, &dev->flags)) {
+	if (test_and_clear_bit (EVENT_TX_HALT, &dev->flags)) {
 		unlink_urbs (dev, &dev->txq);
 		status = usb_autopm_get_interface(dev->intf);
 		if (status < 0)
@@ -1150,12 +1146,11 @@ usbnet_deferred_kevent (struct work_struct *work)
 				netdev_err(dev->net, "can't clear tx halt, status %d\n",
 					   status);
 		} else {
-			clear_bit (EVENT_TX_HALT, &dev->flags);
 			if (status != -ESHUTDOWN)
 				netif_wake_queue (dev->net);
 		}
 	}
-	if (test_bit (EVENT_RX_HALT, &dev->flags)) {
+	if (test_and_clear_bit (EVENT_RX_HALT, &dev->flags)) {
 		unlink_urbs (dev, &dev->rxq);
 		status = usb_autopm_get_interface(dev->intf);
 		if (status < 0)
@@ -1170,41 +1165,39 @@ usbnet_deferred_kevent (struct work_struct *work)
 				netdev_err(dev->net, "can't clear rx halt, status %d\n",
 					   status);
 		} else {
-			clear_bit (EVENT_RX_HALT, &dev->flags);
 			tasklet_schedule (&dev->bh);
 		}
 	}
 
 	/* tasklet could resubmit itself forever if memory is tight */
-	if (test_bit (EVENT_RX_MEMORY, &dev->flags)) {
+	if (test_and_clear_bit (EVENT_RX_MEMORY, &dev->flags)) {
 		struct urb	*urb = NULL;
 		int resched = 1;
 
-		if (netif_running (dev->net))
+		if (netif_running (dev->net)) {
 			urb = usb_alloc_urb (0, GFP_KERNEL);
-		else
-			clear_bit (EVENT_RX_MEMORY, &dev->flags);
-		if (urb != NULL) {
-			clear_bit (EVENT_RX_MEMORY, &dev->flags);
-			status = usb_autopm_get_interface(dev->intf);
-			if (status < 0) {
-				usb_free_urb(urb);
-				goto fail_lowmem;
-			}
-			if (rx_submit (dev, urb, GFP_KERNEL) == -ENOLINK)
-				resched = 0;
-			usb_autopm_put_interface(dev->intf);
+			if (urb != NULL) {
+				status = usb_autopm_get_interface(dev->intf);
+				if (status < 0) {
+					usb_free_urb(urb);
+					goto fail_lowmem;
+				}
+				if (rx_submit (dev, urb, GFP_KERNEL) ==
+				    -ENOLINK)
+					resched = 0;
+				usb_autopm_put_interface(dev->intf);
 fail_lowmem:
-			if (resched)
-				tasklet_schedule (&dev->bh);
+				if (resched)
+					tasklet_schedule (&dev->bh);
+			}
 		}
+
 	}
 
-	if (test_bit (EVENT_LINK_RESET, &dev->flags)) {
+	if (test_and_clear_bit (EVENT_LINK_RESET, &dev->flags)) {
 		struct driver_info	*info = dev->driver_info;
 		int			retval = 0;
 
-		clear_bit (EVENT_LINK_RESET, &dev->flags);
 		status = usb_autopm_get_interface(dev->intf);
 		if (status < 0)
 			goto skip_reset;
@@ -1221,13 +1214,14 @@ usbnet_deferred_kevent (struct work_struct *work)
 		}
 
 		/* handle link change from link resetting */
+		clear_bit(EVENT_LINK_CHANGE, &dev->flags);
 		__handle_link_change(dev);
 	}
 
-	if (test_bit (EVENT_LINK_CHANGE, &dev->flags))
+	if (test_and_clear_bit (EVENT_LINK_CHANGE, &dev->flags))
 		__handle_link_change(dev);
 
-	if (test_bit (EVENT_SET_RX_MODE, &dev->flags))
+	if (test_and_clear_bit (EVENT_SET_RX_MODE, &dev->flags))
 		__handle_set_rx_mode(dev);
 
 
Signature · 1 line
2.14.1.690.gbb1197296e-goog
maintainer NAK
#2 lore raw

Re: [RFC PATCH 2/3] usbnet: Avoid potential races in usbnet_deferred_kevent()

Am Dienstag, den 19.09.2017, 09:15 -0700 schrieb Douglas Anderson:

Quoted 11 lines

In general when you've got a flag communicating that "something needs to be done" you want to clear that flag _before_ doing the task. If you clear the flag _after_ doing the task you end up with the risk that this will happen:

1. Requester sets flag saying task A needs to be done.
2. Worker comes and stars doing task A.
3. Worker finishes task A but hasn't yet cleared the flag.
4. Requester wants to set flag saying task A needs to be done again.
5. Worker clears the flag without doing anything.

Quoted 6 lines

Let's make the usbnet codebase consistently clear the flag _before_ it does the requested work. That way if there's another request to do the work while the work is already in progress it won't be lost.

NOTES:
- No known bugs are fixed by this; it's just found by code inspection.

Hi,

unfortunately the patch is wrong. The flags must be cleared only in case the handler is successful. That is not guaranteed.

Regards
Oliver

NACK

#3 lore raw

Re: [RFC PATCH 2/3] usbnet: Avoid potential races in usbnet_deferred_kevent()

Quoted 16 lines · Oliver Neukum

Am Dienstag, den 19.09.2017, 09:15 -0700 schrieb Douglas Anderson:

Quoted 15 lines

In general when you've got a flag communicating that "something needs to be done" you want to clear that flag _before_ doing the task. If you clear the flag _after_ doing the task you end up with the risk that this will happen:

1. Requester sets flag saying task A needs to be done.
2. Worker comes and stars doing task A.
3. Worker finishes task A but hasn't yet cleared the flag.
4. Requester wants to set flag saying task A needs to be done again.
5. Worker clears the flag without doing anything.

Let's make the usbnet codebase consistently clear the flag _before_ it does the requested work. That way if there's another request to do the work while the work is already in progress it won't be lost.

Quoted 8 lines
Quoted 2 lines

NOTES:
- No known bugs are fixed by this; it's just found by code inspection.

Hi,

unfortunately the patch is wrong. The flags must be cleared only in case the handler is successful. That is not guaranteed.

Just out of curiosity, what is the retry mechanism ? Whenever a new, possibly unrelated, event is scheduled ?

Thanks,
Guenter

maintainer
#4 lore raw

Re: [RFC PATCH 2/3] usbnet: Avoid potential races in usbnet_deferred_kevent()

Am Dienstag, den 19.09.2017, 13:51 -0700 schrieb Guenter Roeck:

Quoted 4 lines · Oliver Neukum
Quoted 3 lines

Am Dienstag, den 19.09.2017, 09:15 -0700 schrieb Douglas Anderson:

Quoted 1 line

[..]

Quoted 11 lines
Quoted 8 lines
Quoted 2 lines

NOTES:
- No known bugs are fixed by this; it's just found by code inspection.

Hi,

unfortunately the patch is wrong. The flags must be cleared only in case the handler is successful. That is not guaranteed.

Just out of curiosity, what is the retry mechanism ? Whenever a new, possibly unrelated, event is scheduled ?

Hi,

that actually depends on the flag.
Look at the case of fail_lowmem. There we reschedule.

HTH
Oliver

#5 lore raw

Re: [RFC PATCH 2/3] usbnet: Avoid potential races in usbnet_deferred_kevent()

In reply to Oliver Neukum

Hi,

Quoted 21 lines · Oliver Neukum

Am Dienstag, den 19.09.2017, 09:15 -0700 schrieb Douglas Anderson:

Quoted 11 lines

In general when you've got a flag communicating that "something needs to be done" you want to clear that flag _before_ doing the task. If you clear the flag _after_ doing the task you end up with the risk that this will happen:

1. Requester sets flag saying task A needs to be done.
2. Worker comes and stars doing task A.
3. Worker finishes task A but hasn't yet cleared the flag.
4. Requester wants to set flag saying task A needs to be done again.
5. Worker clears the flag without doing anything.

Quoted 6 lines

Let's make the usbnet codebase consistently clear the flag _before_ it does the requested work. That way if there's another request to do the work while the work is already in progress it won't be lost.

NOTES:
- No known bugs are fixed by this; it's just found by code inspection.

Hi,

Quoted 7 lines

unfortunately the patch is wrong. The flags must be cleared only in case the handler is successful. That is not guaranteed.

Regards
Oliver

NACK

OK, thanks for reviewing! I definitely wasn't super confident about the patch (hence the RFC).

Do you think that the races I identified are possible to hit? In other words: should I try to rework the patch somehow or just drop it?
Originally I had the patch setting the flags back to true in the
failure cases, but then I convinced myself that wasn't needed. I can certainly go back and try it that way...

-Doug

maintainer
#6 lore raw

Re: [RFC PATCH 2/3] usbnet: Avoid potential races in usbnet_deferred_kevent()

Am Dienstag, den 19.09.2017, 13:53 -0700 schrieb Doug Anderson:

Quoted 32 lines

Hi,

Quoted 29 lines · Oliver Neukum

Am Dienstag, den 19.09.2017, 09:15 -0700 schrieb Douglas Anderson:

Quoted 12 lines

In general when you've got a flag communicating that "something needs to be done" you want to clear that flag _before_ doing the task. If you clear the flag _after_ doing the task you end up with the risk that this will happen:

1. Requester sets flag saying task A needs to be done.
2. Worker comes and stars doing task A.
3. Worker finishes task A but hasn't yet cleared the flag.
4. Requester wants to set flag saying task A needs to be done again.
5. Worker clears the flag without doing anything.

Quoted 6 lines

Let's make the usbnet codebase consistently clear the flag _before_ it does the requested work. That way if there's another request to do the work while the work is already in progress it won't be lost.

NOTES:
- No known bugs are fixed by this; it's just found by code inspection.

Hi,

unfortunately the patch is wrong. The flags must be cleared only in case the handler is successful. That is not guaranteed.

Regards
Oliver

Quoted 6 lines
Quoted 1 line

NACK

OK, thanks for reviewing! I definitely wasn't super confident about the patch (hence the RFC).

Do you think that the races I identified are possible to hit? In

As far as I can tell, we are safe, but you are right to say that the driver is not quite clean at that point.

Quoted 4 lines

other words: should I try to rework the patch somehow or just drop it?
Originally I had the patch setting the flags back to true in the
failure cases, but then I convinced myself that wasn't needed. I can certainly go back and try it that way...

Setting the flags again in the error case would certainly be an improvement. I'd be happy with a patch doing that.

Regards
Oliver

#7 lore raw

RFC PATCH 3/3 usbnet: Fix memory leak when rx_submit() fails

In reply to Douglas Anderson

If rx_submit() returns an error code then nobody calls usb_free_urb(). That means it's leaked.

NOTE: This problem was found solely by code inspection and not due to any failing test cases.

---

 drivers/net/usb/usbnet.c | 9 ++++++---
 1 file changed, 6 insertions(+), 3 deletions(-)
drivers/net/usb/usbnet.c +6 -3
index e72547d8d0e6..4c067aaeea5a 100644
@@ -1182,9 +1182,12 @@ usbnet_deferred_kevent (struct work_struct *work)
 					usb_free_urb(urb);
 					goto fail_lowmem;
 				}
-				if (rx_submit (dev, urb, GFP_KERNEL) ==
-				    -ENOLINK)
-					resched = 0;
+				status = rx_submit (dev, urb, GFP_KERNEL);
+				if (status) {
+					usb_free_urb(urb);
+					if (status == -ENOLINK)
+						resched = 0;
+				}
 				usb_autopm_put_interface(dev->intf);
 fail_lowmem:
 				if (resched)
Signature · 1 line
2.14.1.690.gbb1197296e-goog
#8 lore raw

Re: [RFC PATCH 3/3] usbnet: Fix memory leak when rx_submit() fails

Quoted 2 lines · Douglas Anderson

If rx_submit() returns an error code then nobody calls usb_free_urb(). That means it's leaked.

Nope. rx_submit() will call usb_free_urb() before returning an error:

static int rx_submit (struct usbnet *dev, struct urb *urb, gfp_t flags) ..

	if (!skb) {
		netif_dbg(dev, rx_err, dev->net, "no rx skb\n");
		usbnet_defer_kevent (dev, EVENT_RX_MEMORY);
		usb_free_urb (urb);
		return -ENOMEM;
	}
..
	if (retval) {
		dev_kfree_skb_any (skb);
		usb_free_urb (urb);
	}

Bjørn

Reviewed-by on v1 1/3
#9 lore raw
In reply to Douglas Anderson
Quoted 40 lines · Douglas Anderson

Every once in a while when my system is under a bit of stress I see some spammy messages show up in my logs that say:

kevent X may have been dropped

As far as I can tell these messages aren't terribly useful. The comments around the messages make me think that either workqueues used to work differently or that the original author of the code missed a sublety related to them. The error message appears to predate the git conversion of the kernel so it's somewhat hard to tell.

Specifically, workqueues should work like this:

A) If a workqueue hasn't been scheduled then schedule_work() schedules it and returns true.

B) If a workqueue has been scheduled (but hasn't started) then schedule_work() will do nothing and return false.

C) If a workqueue has been scheduled (and has started) then schedule_work() will put it on the queue to run again and return true.

Said another way: if you call schedule_work() you can guarantee that at least one full runthrough of the work will happen again. That should mean that the work will get processed and I don't see any reason to think something should be dropped.

Reading the comments in in usbnet_defer_kevent() made me think that B) and C) would be treated the same. That is: even if we've started the work and are 99% of the way through then schedule_work() would return false and the work wouldn't be queued again. If schedule_work() really did behave that way then, truly, some amount of work would be lost. ...but it doesn't.

NOTE: if somehow these warnings are useful to mean something then perhaps we should change them to make it more obvious. If it's interesting to know when the work is backlogged then we should change the spam to say "warning: usbnet is backlogged".

Quoted 7 lines

ALSO NOTE: If somehow some of the types of work need to be repeated if usbnet_defer_kevent() is called multiple times then that should be quite easy to accomplish without dropping any work on the floor. We can just keep an atomic count for that type of work and add a loop into usbnet_deferred_kevent().

Quoted 39 lines

---

 drivers/net/usb/usbnet.c | 16 +++++++---------
 1 file changed, 7 insertions(+), 9 deletions(-)
drivers/net/usb/usbnet.c +7 -10
index 6510e5cc1817..a3e8dbaadcf9 100644
@@ -450,19 +450,17 @@ static enum skb_state defer_bh(struct usbnet *dev, struct sk_buff *skb,
 }
 
 /* some work can't be done in tasklets, so we use keventd
- *
- * NOTE:  annoying asymmetry:  if it's active, schedule_work() fails,
- * but tasklet_schedule() doesn't.  hope the failure is rare.
  */
 void usbnet_defer_kevent (struct usbnet *dev, int work)
 {
        set_bit (work, &dev->flags);
-       if (!schedule_work (&dev->kevent)) {
-               if (net_ratelimit())
-                       netdev_err(dev->net, "kevent %d may have been dropped\n", work);
-       } else {
-               netdev_dbg(dev->net, "kevent %d scheduled\n", work);
-       }
+
+       /* If work is already started this will mark it to run again when it
+        * finishes; if we already had work pending and it hadn't started
+        * yet then that's fine too.
+        */
+       schedule_work (&dev->kevent);
+       netdev_dbg(dev->net, "kevent %d scheduled\n", work);
 }
 EXPORT_SYMBOL_GPL(usbnet_defer_kevent);
 
--

2.14.1.690.gbb1197296e-goog

#10 lore raw
In reply to Douglas Anderson
Quoted 6 lines · Douglas Anderson

Every once in a while when my system is under a bit of stress I see some spammy messages show up in my logs that say:

kevent X may have been dropped

As far as I can tell these messages aren't terribly useful.

I agree, FWIW. These messages just confuse users for no purpose at all.

drivers/net/usb/usbnet.c static enum skb_state defer_bh(struct usbnet *dev, struct sk_buff *skb, · line 463

Quoted 6 lines
drivers/net/usb/usbnet.c +6 -0
+	/* If work is already started this will mark it to run again when it
+	 * finishes; if we already had work pending and it hadn't started
+	 * yet then that's fine too.
+	 */
+	schedule_work (&dev->kevent);
+	netdev_dbg(dev->net, "kevent %d scheduled\n", work);

Or maybe

        if (schedule_work (&dev->kevent))
        	netdev_dbg(dev->net, "kevent %d scheduled\n", work);

? Not that I think it matters much.

Bjørn

maintainer Acked-by on v1 1/3
#11 lore raw
In reply to Douglas Anderson

Am Dienstag, den 19.09.2017, 09:15 -0700 schrieb Douglas Anderson:

Quoted 6 lines

ALSO NOTE: If somehow some of the types of work need to be repeated if usbnet_defer_kevent() is called multiple times then that should be quite easy to accomplish without dropping any work on the floor.  We can just keep an atomic count for that type of work and add a loop into usbnet_deferred_kevent().

Thanks for doing this, it is overdue.

Regards
Oliver

Quoted 1 line