USB: dummy-hcd: Fix failure to give back unlinked URBs

USB: dummy-hcd: Fix failure to give back unlinked URBs

[Alan Stern]

The syzkaller USB fuzzer identified a failure mode in which dummy-hcd
would never give back an unlinked URB.  This causes usb_kill_urb() to
hang, leading to WARNINGs and unkillable threads.

In dummy-hcd, all URBs are given back by the dummy_timer() routine as
it scans through the list of pending URBS.  Failure to give back URBs
can be caused by failure to start or early exit from the scanning
loop.  The code currently has two such pathways: One is triggered when
an unsupported bus transfer speed is encountered, and the other by
exhausting the simulated bandwidth for USB transfers during a frame.

This patch removes those two paths, thereby allowing all unlinked URBs
to be given back in a timely manner.  It adds a check for the bus
speed when the gadget first starts running, so that dummy_timer() will
never thereafter encounter an unsupported speed.  And it prevents the
loop from exiting as soon as the total bandwidth has been used up (the
scanning loop continues, giving back unlinked URBs as they are found,
but not transferring any more data).

Thanks to Andrey Konovalov for manually running the syzkaller fuzzer
to help track down the source of the bug.

Signed-off-by: Alan Stern <stern@rowland.harvard.edu>
Reported-and-tested-by: syzbot+d919b0f29d7b5a4994b9@syzkaller.appspotmail.com
CC: <stable@vger.kernel.org>
---


[as1889]


 drivers/usb/gadget/udc/dummy_hcd.c |   19 +++++++++++++++----
 1 file changed, 15 insertions(+), 4 deletions(-)

Index: usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
===================================================================
--- usb-devel.orig/drivers/usb/gadget/udc/dummy_hcd.c
+++ usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
@@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
 	struct dummy_hcd	*dum_hcd = gadget_to_dummy_hcd(g);
 	struct dummy		*dum = dum_hcd->dum;
 
-	if (driver->max_speed == USB_SPEED_UNKNOWN)
+	switch (g->speed) {
+	/* All the speeds we support */
+	case USB_SPEED_LOW:
+	case USB_SPEED_FULL:
+	case USB_SPEED_HIGH:
+	case USB_SPEED_SUPER:
+		break;
+	default:
+		dev_err(dummy_dev(dum_hcd), "Unsupported driver max speed %d\n",
+				driver->max_speed);
 		return -EINVAL;
+	}
 
 	/*
 	 * SLAVE side init ... the layer above hardware, which
@@ -1784,9 +1794,10 @@ static void dummy_timer(struct timer_lis
 		/* Bus speed is 500000 bytes/ms, so use a little less */
 		total = 490000;
 		break;
-	default:
+	default:	/* Can't happen */
 		dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
-		return;
+		total = 0;
+		break;
 	}
 
 	/* FIXME if HZ != 1000 this will probably misbehave ... */
@@ -1828,7 +1839,7 @@ restart:
 
 		/* Used up this frame's bandwidth? */
 		if (total <= 0)
-			break;
+			continue;
 
 		/* find the gadget's ep for this request (if configured) */
 		address = usb_pipeendpoint (urb->pipe);

[PATCH] USB: dummy-hcd: Fix failure to give back unlinked URBs

[Alan Stern]

The syzkaller USB fuzzer identified a failure mode in which dummy-hcd
would never give back an unlinked URB.  This causes usb_kill_urb() to
hang, leading to WARNINGs and unkillable threads.

In dummy-hcd, all URBs are given back by the dummy_timer() routine as
it scans through the list of pending URBS.  Failure to give back URBs
can be caused by failure to start or early exit from the scanning
loop.  The code currently has two such pathways: One is triggered when
an unsupported bus transfer speed is encountered, and the other by
exhausting the simulated bandwidth for USB transfers during a frame.

This patch removes those two paths, thereby allowing all unlinked URBs
to be given back in a timely manner.  It adds a check for the bus
speed when the gadget first starts running, so that dummy_timer() will
never thereafter encounter an unsupported speed.  And it prevents the
loop from exiting as soon as the total bandwidth has been used up (the
scanning loop continues, giving back unlinked URBs as they are found,
but not transferring any more data).

Thanks to Andrey Konovalov for manually running the syzkaller fuzzer
to help track down the source of the bug.

Signed-off-by: Alan Stern <stern@rowland.harvard.edu>
Reported-and-tested-by: syzbot+d919b0f29d7b5a4994b9@syzkaller.appspotmail.com
CC: <stable@vger.kernel.org>

---


[as1889]


 drivers/usb/gadget/udc/dummy_hcd.c |   19 +++++++++++++++----
 1 file changed, 15 insertions(+), 4 deletions(-)

Index: usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
===================================================================
--- usb-devel.orig/drivers/usb/gadget/udc/dummy_hcd.c
+++ usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
@@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
 	struct dummy_hcd	*dum_hcd = gadget_to_dummy_hcd(g);
 	struct dummy		*dum = dum_hcd->dum;
 
-	if (driver->max_speed == USB_SPEED_UNKNOWN)
+	switch (g->speed) {
+	/* All the speeds we support */
+	case USB_SPEED_LOW:
+	case USB_SPEED_FULL:
+	case USB_SPEED_HIGH:
+	case USB_SPEED_SUPER:
+		break;
+	default:
+		dev_err(dummy_dev(dum_hcd), "Unsupported driver max speed %d\n",
+				driver->max_speed);
 		return -EINVAL;
+	}
 
 	/*
 	 * SLAVE side init ... the layer above hardware, which
@@ -1784,9 +1794,10 @@ static void dummy_timer(struct timer_lis
 		/* Bus speed is 500000 bytes/ms, so use a little less */
 		total = 490000;
 		break;
-	default:
+	default:	/* Can't happen */
 		dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
-		return;
+		total = 0;
+		break;
 	}
 
 	/* FIXME if HZ != 1000 this will probably misbehave ... */
@@ -1828,7 +1839,7 @@ restart:
 
 		/* Used up this frame's bandwidth? */
 		if (total <= 0)
-			break;
+			continue;
 
 		/* find the gadget's ep for this request (if configured) */
 		address = usb_pipeendpoint (urb->pipe);

Re: INFO: task hung in usb_kill_urb

[Alan Stern]

On Mon, 15 Apr 2019, Andrey Konovalov wrote:

> On Mon, Apr 15, 2019 at 8:06 PM Alan Stern <stern@rowland.harvard.edu> wrote:

> > > > It looks like something is stuck waiting for usb_kill_urb() to finish.
> > > > But what happened before that?
> > >
> > > This crash is somewhat special. It happens quite often during USB
> > > fuzzing, but at the same time it's a hang, which makes it a bit harder
> > > debug. I initially thought that is somehow related to my custom USB
> > > fuzzing kernel patches, but then I saw that someone else hit this
> > > issue while doing USB fuzzing in a completely different way that
> > > doesn't require kernel modifications. So it might be an actual issue
> > > in the kernel.
> > >
> > > The full console output is provided by the syzbot, but I guess it's
> > > not very useful in this case. I've just made sure that this issue is
> > > manually reproducible, so we can easily retest it with debug patches
> > > (syzbot should be also able to do that via the syz test command). Or
> > > is there a way to turn on some verbose mode to see some USB debug
> > > messages?
> >
> > If I were doing this manually, I would run the following commands after
> > loading the dummy-hcd driver but before starting the main test
> > (requires CONFIG_USB_MON; you can skip the modprobe if
> > CONFIG_USB_MON=y):
> >
> >         modprobe usbmon
> >         cat /sys/kernel/debug/usb/usbmon/Nu >/tmp/mon.out &
> >
> > where N is the USB bus number corresponding to the dummy-hcd bus.
> > Then after the test hangs, on another VT kill the "cat" process and
> > examine the contents of /tmp/mon.out.
> >
> > Maybe you can do the equivalent with syzkaller?  If necessary, you can
> > start the "cat" before loading dummy-hcd and specify a bus number of 0.
> > That will capture data for all the USB buses, including the dummy-hcd
> > bus when it gets added (I think -- I haven't actually tried it).
> 
> Right now the best way to do this is to run the reproducer manually.
> I've attached the resulting mon.out and syslog.

Okay, it looks like the system is getting stuck on the very first URB.  
Let's add some more traditional debugging and see what shows up.  This 
test won't require any manual intervention.

Alan Stern


#syz test: https://github.com/google/kasan.git usb-fuzzer

--- a/drivers/usb/gadget/udc/dummy_hcd.c
+++ b/drivers/usb/gadget/udc/dummy_hcd.c
@@ -992,6 +992,7 @@ static int dummy_udc_start(struct usb_ga
 	dum->driver = driver;
 	dum->ints_enabled = 1;
 	spin_unlock_irq(&dum->lock);
+	dev_info(udc_dev(dum), "%s\n", __func__);
 
 	return 0;
 }
@@ -1001,6 +1002,7 @@ static int dummy_udc_stop(struct usb_gad
 	struct dummy_hcd	*dum_hcd = gadget_to_dummy_hcd(g);
 	struct dummy		*dum = dum_hcd->dum;
 
+	dev_info(udc_dev(dum), "%s\n", __func__);
 	spin_lock_irq(&dum->lock);
 	dum->ints_enabled = 0;
 	stop_activity(dum);
@@ -1277,6 +1279,8 @@ static int dummy_urb_enqueue(
 	} else if (unlikely(dum_hcd->udev != urb->dev))
 		dev_err(dummy_dev(dum_hcd), "usb_device address has changed!\n");
 
+	dev_info(dummy_dev(dum_hcd), "enqueue URB %p len %u\n", urb,
+			urb->transfer_buffer_length);
 	list_add_tail(&urbp->urbp_list, &dum_hcd->urbp_list);
 	urb->hcpriv = urbp;
 	if (!dum_hcd->next_frame_urbp)
@@ -1306,8 +1310,10 @@ static int dummy_urb_dequeue(struct usb_
 
 	rc = usb_hcd_check_unlink_urb(hcd, urb, status);
 	if (!rc && dum_hcd->rh_state != DUMMY_RH_RUNNING &&
-			!list_empty(&dum_hcd->urbp_list))
+			!list_empty(&dum_hcd->urbp_list)) {
+		dev_info(dummy_dev(dum_hcd), "dequeue URB %p\n", urb);
 		mod_timer(&dum_hcd->timer, jiffies);
+	}
 
 	spin_unlock_irqrestore(&dum_hcd->dum->lock, flags);
 	return rc;
@@ -1827,8 +1833,10 @@ restart:
 			continue;
 
 		/* Used up this frame's bandwidth? */
-		if (total <= 0)
+		if (total <= 0) {
+			dev_info(dummy_dev(dum_hcd), "total exceeded\n");
 			break;
+		}
 
 		/* find the gadget's ep for this request (if configured) */
 		address = usb_pipeendpoint (urb->pipe);
@@ -1965,6 +1973,7 @@ return_urb:
 
 		usb_hcd_unlink_urb_from_ep(dummy_hcd_to_hcd(dum_hcd), urb);
 		spin_unlock(&dum->lock);
+		dev_info(dummy_dev(dum_hcd), "giveback URB %p\n", urb);
 		usb_hcd_giveback_urb(dummy_hcd_to_hcd(dum_hcd), urb, status);
 		spin_lock(&dum->lock);
 
@@ -2329,7 +2338,7 @@ static int dummy_bus_suspend(struct usb_
 {
 	struct dummy_hcd *dum_hcd = hcd_to_dummy_hcd(hcd);
 
-	dev_dbg(&hcd->self.root_hub->dev, "%s\n", __func__);
+	dev_info(&hcd->self.root_hub->dev, "%s\n", __func__);
 
 	spin_lock_irq(&dum_hcd->dum->lock);
 	dum_hcd->rh_state = DUMMY_RH_SUSPENDED;
@@ -2344,7 +2353,7 @@ static int dummy_bus_resume(struct usb_h
 	struct dummy_hcd *dum_hcd = hcd_to_dummy_hcd(hcd);
 	int rc = 0;
 
-	dev_dbg(&hcd->self.root_hub->dev, "%s\n", __func__);
+	dev_info(&hcd->self.root_hub->dev, "%s\n", __func__);
 
 	spin_lock_irq(&dum_hcd->dum->lock);
 	if (!HCD_HW_ACCESSIBLE(hcd)) {
@@ -2431,6 +2440,7 @@ static DEVICE_ATTR_RO(urbs);
 
 static int dummy_start_ss(struct dummy_hcd *dum_hcd)
 {
+	dev_info(dummy_dev(dum_hcd), "%s\n", __func__);
 	timer_setup(&dum_hcd->timer, dummy_timer, 0);
 	dum_hcd->rh_state = DUMMY_RH_RUNNING;
 	dum_hcd->stream_en_ep = 0;
@@ -2459,6 +2469,7 @@ static int dummy_start(struct usb_hcd *h
 	if (!usb_hcd_is_primary_hcd(hcd))
 		return dummy_start_ss(dum_hcd);
 
+	dev_info(dummy_dev(dum_hcd), "%s\n", __func__);
 	spin_lock_init(&dum_hcd->dum->lock);
 	timer_setup(&dum_hcd->timer, dummy_timer, 0);
 	dum_hcd->rh_state = DUMMY_RH_RUNNING;

INFO: task hung in usb_kill_urb

[Alan Stern]

On Mon, 15 Apr 2019, Andrey Konovalov wrote:

> On Mon, Apr 15, 2019 at 8:06 PM Alan Stern <stern@rowland.harvard.edu> wrote:

> > > > It looks like something is stuck waiting for usb_kill_urb() to finish.
> > > > But what happened before that?
> > >
> > > This crash is somewhat special. It happens quite often during USB
> > > fuzzing, but at the same time it's a hang, which makes it a bit harder
> > > debug. I initially thought that is somehow related to my custom USB
> > > fuzzing kernel patches, but then I saw that someone else hit this
> > > issue while doing USB fuzzing in a completely different way that
> > > doesn't require kernel modifications. So it might be an actual issue
> > > in the kernel.
> > >
> > > The full console output is provided by the syzbot, but I guess it's
> > > not very useful in this case. I've just made sure that this issue is
> > > manually reproducible, so we can easily retest it with debug patches
> > > (syzbot should be also able to do that via the syz test command). Or
> > > is there a way to turn on some verbose mode to see some USB debug
> > > messages?
> >
> > If I were doing this manually, I would run the following commands after
> > loading the dummy-hcd driver but before starting the main test
> > (requires CONFIG_USB_MON; you can skip the modprobe if
> > CONFIG_USB_MON=y):
> >
> >         modprobe usbmon
> >         cat /sys/kernel/debug/usb/usbmon/Nu >/tmp/mon.out &
> >
> > where N is the USB bus number corresponding to the dummy-hcd bus.
> > Then after the test hangs, on another VT kill the "cat" process and
> > examine the contents of /tmp/mon.out.
> >
> > Maybe you can do the equivalent with syzkaller?  If necessary, you can
> > start the "cat" before loading dummy-hcd and specify a bus number of 0.
> > That will capture data for all the USB buses, including the dummy-hcd
> > bus when it gets added (I think -- I haven't actually tried it).
> 
> Right now the best way to do this is to run the reproducer manually.
> I've attached the resulting mon.out and syslog.

Okay, it looks like the system is getting stuck on the very first URB.  
Let's add some more traditional debugging and see what shows up.  This 
test won't require any manual intervention.

Alan Stern


#syz test: https://github.com/google/kasan.git usb-fuzzer

--- a/drivers/usb/gadget/udc/dummy_hcd.c
+++ b/drivers/usb/gadget/udc/dummy_hcd.c
@@ -992,6 +992,7 @@ static int dummy_udc_start(struct usb_ga
 	dum->driver = driver;
 	dum->ints_enabled = 1;
 	spin_unlock_irq(&dum->lock);
+	dev_info(udc_dev(dum), "%s\n", __func__);
 
 	return 0;
 }
@@ -1001,6 +1002,7 @@ static int dummy_udc_stop(struct usb_gad
 	struct dummy_hcd	*dum_hcd = gadget_to_dummy_hcd(g);
 	struct dummy		*dum = dum_hcd->dum;
 
+	dev_info(udc_dev(dum), "%s\n", __func__);
 	spin_lock_irq(&dum->lock);
 	dum->ints_enabled = 0;
 	stop_activity(dum);
@@ -1277,6 +1279,8 @@ static int dummy_urb_enqueue(
 	} else if (unlikely(dum_hcd->udev != urb->dev))
 		dev_err(dummy_dev(dum_hcd), "usb_device address has changed!\n");
 
+	dev_info(dummy_dev(dum_hcd), "enqueue URB %p len %u\n", urb,
+			urb->transfer_buffer_length);
 	list_add_tail(&urbp->urbp_list, &dum_hcd->urbp_list);
 	urb->hcpriv = urbp;
 	if (!dum_hcd->next_frame_urbp)
@@ -1306,8 +1310,10 @@ static int dummy_urb_dequeue(struct usb_
 
 	rc = usb_hcd_check_unlink_urb(hcd, urb, status);
 	if (!rc && dum_hcd->rh_state != DUMMY_RH_RUNNING &&
-			!list_empty(&dum_hcd->urbp_list))
+			!list_empty(&dum_hcd->urbp_list)) {
+		dev_info(dummy_dev(dum_hcd), "dequeue URB %p\n", urb);
 		mod_timer(&dum_hcd->timer, jiffies);
+	}
 
 	spin_unlock_irqrestore(&dum_hcd->dum->lock, flags);
 	return rc;
@@ -1827,8 +1833,10 @@ restart:
 			continue;
 
 		/* Used up this frame's bandwidth? */
-		if (total <= 0)
+		if (total <= 0) {
+			dev_info(dummy_dev(dum_hcd), "total exceeded\n");
 			break;
+		}
 
 		/* find the gadget's ep for this request (if configured) */
 		address = usb_pipeendpoint (urb->pipe);
@@ -1965,6 +1973,7 @@ return_urb:
 
 		usb_hcd_unlink_urb_from_ep(dummy_hcd_to_hcd(dum_hcd), urb);
 		spin_unlock(&dum->lock);
+		dev_info(dummy_dev(dum_hcd), "giveback URB %p\n", urb);
 		usb_hcd_giveback_urb(dummy_hcd_to_hcd(dum_hcd), urb, status);
 		spin_lock(&dum->lock);
 
@@ -2329,7 +2338,7 @@ static int dummy_bus_suspend(struct usb_
 {
 	struct dummy_hcd *dum_hcd = hcd_to_dummy_hcd(hcd);
 
-	dev_dbg(&hcd->self.root_hub->dev, "%s\n", __func__);
+	dev_info(&hcd->self.root_hub->dev, "%s\n", __func__);
 
 	spin_lock_irq(&dum_hcd->dum->lock);
 	dum_hcd->rh_state = DUMMY_RH_SUSPENDED;
@@ -2344,7 +2353,7 @@ static int dummy_bus_resume(struct usb_h
 	struct dummy_hcd *dum_hcd = hcd_to_dummy_hcd(hcd);
 	int rc = 0;
 
-	dev_dbg(&hcd->self.root_hub->dev, "%s\n", __func__);
+	dev_info(&hcd->self.root_hub->dev, "%s\n", __func__);
 
 	spin_lock_irq(&dum_hcd->dum->lock);
 	if (!HCD_HW_ACCESSIBLE(hcd)) {
@@ -2431,6 +2440,7 @@ static DEVICE_ATTR_RO(urbs);
 
 static int dummy_start_ss(struct dummy_hcd *dum_hcd)
 {
+	dev_info(dummy_dev(dum_hcd), "%s\n", __func__);
 	timer_setup(&dum_hcd->timer, dummy_timer, 0);
 	dum_hcd->rh_state = DUMMY_RH_RUNNING;
 	dum_hcd->stream_en_ep = 0;
@@ -2459,6 +2469,7 @@ static int dummy_start(struct usb_hcd *h
 	if (!usb_hcd_is_primary_hcd(hcd))
 		return dummy_start_ss(dum_hcd);
 
+	dev_info(dummy_dev(dum_hcd), "%s\n", __func__);
 	spin_lock_init(&dum_hcd->dum->lock);
 	timer_setup(&dum_hcd->timer, dummy_timer, 0);
 	dum_hcd->rh_state = DUMMY_RH_RUNNING;

Re: INFO: task hung in usb_kill_urb

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
INFO: task hung in usb_kill_urb

usb-fuzzer-gadget dummy_udc.4: failed to start USB fuzzer: -22
dummy_udc dummy_udc.4: dummy_udc_start
dummy_udc dummy_udc.3: dummy_udc_stop
usb-fuzzer-gadget dummy_udc.3: failed to start USB fuzzer: -22
dummy_udc dummy_udc.3: dummy_udc_start
INFO: task kworker/1:1:21 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:1     D26616    21      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:2:533 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:2     D25760   533      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
dummy_udc dummy_udc.2: dummy_udc_stop
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/0:4:6014 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:4     D27752  6014      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
usb-fuzzer-gadget dummy_udc.2: failed to start USB fuzzer: -22
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
dummy_udc dummy_udc.5: dummy_udc_stop
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
usb-fuzzer-gadget dummy_udc.5: failed to start USB fuzzer: -22
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
dummy_udc dummy_udc.1: dummy_udc_stop
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
dummy_udc dummy_udc.2: dummy_udc_start
INFO: task kworker/0:5:6019 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
usb-fuzzer-gadget dummy_udc.1: failed to start USB fuzzer: -22
kworker/0:5     D27752  6019      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
dummy_udc dummy_udc.5: dummy_udc_start
dummy_udc dummy_udc.1: dummy_udc_start
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
dummy_udc dummy_udc.0: dummy_udc_stop
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:4:6060 blocked for more than 144 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:4     D27752  6060      2 0x80000000
dummy_udc dummy_udc.0: dummy_udc_start
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352

Showing all locks held in the system:
5 locks held by kworker/1:1/21:
dummy_udc dummy_udc.4: dummy_udc_stop
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000bef12525 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000009a337b20 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000009a337b20 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000449599d5 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000449599d5 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000449599d5 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000449599d5 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000449599d5 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
usb-fuzzer-gadget dummy_udc.4: failed to start USB fuzzer: -22
  #4: 00000000bd693e6d (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
1 lock held by khungtaskd/23:
  #0: 00000000c249679f (rcu_read_lock){....}, at:  
debug_show_all_locks+0x53/0x269 kernel/locking/lockdep.c:5059
5 locks held by kworker/1:2/533:
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
dummy_udc dummy_udc.3: dummy_udc_stop
  #1: 000000000b2c3268 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000005e422e33 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000005e422e33 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
dummy_udc dummy_udc.4: dummy_udc_start
  #3: 00000000a7ffda5b (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000a7ffda5b (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000a7ffda5b (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000a7ffda5b (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000a7ffda5b (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 0000000040171de2 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
1 lock held by rsyslogd/5663:
  #0: 00000000eb497534 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xe8/0x100  
fs/file.c:801
2 locks held by getty/5753:
usb-fuzzer-gadget dummy_udc.3: failed to start USB fuzzer: -22
  #0: 0000000060cabbb9 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000c554441b (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5754:
  #0: 00000000bc2e3243 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000c105aa12 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5755:
  #0: 00000000e6d82cc9 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000007478c77a (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
dummy_udc dummy_udc.3: dummy_udc_start
2 locks held by getty/5756:
  #0: 00000000bdf7f201 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 0000000027b0060b (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5757:
  #0: 00000000ea25225e (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 0000000033c7c6b0 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5758:
  #0: 0000000026e22b8e (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000cc9d99b6 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5759:
  #0: 000000000c56f37f (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 0000000096b5ec30 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
5 locks held by kworker/0:4/6014:
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 000000008858d04f ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 0000000035fa4a95 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 0000000035fa4a95 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000b9e8bc7b (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000b9e8bc7b (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000b9e8bc7b (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000b9e8bc7b (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000b9e8bc7b (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 0000000029c7e38f (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/0:5/6019:
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000406d5ccc ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 00000000a0e74d96 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 00000000a0e74d96 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000f7d2af58 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000f7d2af58 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000f7d2af58 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000f7d2af58 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000f7d2af58 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 00000000f0b5cba1 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/0:6/6023:
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000f6fcfe1c ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 00000000c3342998 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 00000000c3342998 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 000000004d7e0c6e (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 000000004d7e0c6e (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 000000004d7e0c6e (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 000000004d7e0c6e (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 000000004d7e0c6e (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 00000000f25b0237 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/1:4/6060:
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000a61f1995 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 00000000fd9214fe (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 00000000fd9214fe (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 000000000baf27f8 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 000000000baf27f8 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 000000000baf27f8 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 000000000baf27f8 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 000000000baf27f8 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 000000006e962192 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529

=============================================

NMI backtrace for cpu 1
CPU: 1 PID: 23 Comm: khungtaskd Not tainted 5.1.0-rc4-g9a33b36-dirty #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0xe8/0x16e lib/dump_stack.c:113
  nmi_cpu_backtrace.cold+0x48/0x87 lib/nmi_backtrace.c:101
  nmi_trigger_cpumask_backtrace+0x1a6/0x1bd lib/nmi_backtrace.c:62
  trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
  check_hung_uninterruptible_tasks kernel/hung_task.c:204 [inline]
  watchdog+0x98e/0xe20 kernel/hung_task.c:288
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 5881 Comm: syz-executor.0 Not tainted 5.1.0-rc4-g9a33b36-dirty  
#1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
RIP: 0010:__read_once_size include/linux/compiler.h:193 [inline]
RIP: 0010:lookup_chain_cache kernel/locking/lockdep.c:2612 [inline]
RIP: 0010:lookup_chain_cache_add kernel/locking/lockdep.c:2631 [inline]
RIP: 0010:validate_chain kernel/locking/lockdep.c:2685 [inline]
RIP: 0010:__lock_acquire+0xfb0/0x37c0 kernel/locking/lockdep.c:3701
Code: 5d 4c 8b 64 24 20 4d 89 cd 48 bd 00 00 00 00 00 fc ff df eb 06 48 83  
eb 08 74 40 48 8d 7b 18 48 89 f8 48 c1 e8 03 80 3c 28 00 <0f> 85 f1 18 00  
00 48 8b 43 18 49 39 c4 0f 84 73 f9 ff ff 48 8d 7b
RSP: 0018:ffff88809908fa50 EFLAGS: 00000046
RAX: 1ffffffff2c188b3 RBX: ffffffff960c4580 RCX: 0000000000001872
RDX: 1ffffffff2cd93fa RSI: ffff88808be80840 RDI: ffffffff960c4598
RBP: dffffc0000000000 R08: 00000000d4b587bd R09: ffffffff966c9fd0
R10: ffff88808be80840 R11: ffff88808be80000 R12: e085ce875e243443
R13: ffffffff966c9fd0 R14: ffffffff93cb0714 R15: 0000000000000001
FS:  0000000000a57940(0000) GS:ffff8880ad000000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fbda8a77000 CR3: 0000000095e60000 CR4: 00000000001406f0
Call Trace:
  lock_acquire+0x10d/0x2f0 kernel/locking/lockdep.c:4211
  __raw_read_lock include/linux/rwlock_api_smp.h:149 [inline]
  _raw_read_lock+0x2f/0x40 kernel/locking/spinlock.c:216
  do_wait+0x38b/0x940 kernel/exit.c:1523
  kernel_wait4+0x151/0x260 kernel/exit.c:1668
  __do_sys_wait4+0x147/0x160 kernel/exit.c:1680
  do_syscall_64+0xcf/0x4f0 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x412c6a
Code: 0f 83 6a 18 00 00 c3 66 0f 1f 84 00 00 00 00 00 8b 05 2e 36 64 00 85  
c0 75 36 45 31 d2 48 63 d2 48 63 ff b8 3d 00 00 00 0f 05 <48> 3d 00 f0 ff  
ff 77 06 c3 0f 1f 44 00 00 48 c7 c2 d4 ff ff ff f7
RSP: 002b:00007fff92403508 EFLAGS: 00000246 ORIG_RAX: 000000000000003d
RAX: ffffffffffffffda RBX: 000000000003d770 RCX: 0000000000412c6a
RDX: 0000000040000001 RSI: 00007fff92403540 RDI: ffffffffffffffff
RBP: 00000000000000ad R08: 0000000000000001 R09: 0000000000a57940
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
R13: 00007fff92403540 R14: 000000000003d752 R15: 00007fff92403550


Tested on:

commit:         9a33b369 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan/tree/usb-fuzzer
console output: https://syzkaller.appspot.com/x/log.txt?x=111e62cb200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=1207901d200000

INFO: task hung in usb_kill_urb

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
INFO: task hung in usb_kill_urb

usb-fuzzer-gadget dummy_udc.4: failed to start USB fuzzer: -22
dummy_udc dummy_udc.4: dummy_udc_start
dummy_udc dummy_udc.3: dummy_udc_stop
usb-fuzzer-gadget dummy_udc.3: failed to start USB fuzzer: -22
dummy_udc dummy_udc.3: dummy_udc_start
INFO: task kworker/1:1:21 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:1     D26616    21      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:2:533 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:2     D25760   533      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
dummy_udc dummy_udc.2: dummy_udc_stop
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/0:4:6014 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:4     D27752  6014      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
usb-fuzzer-gadget dummy_udc.2: failed to start USB fuzzer: -22
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
dummy_udc dummy_udc.5: dummy_udc_stop
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
usb-fuzzer-gadget dummy_udc.5: failed to start USB fuzzer: -22
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
dummy_udc dummy_udc.1: dummy_udc_stop
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
dummy_udc dummy_udc.2: dummy_udc_start
INFO: task kworker/0:5:6019 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
usb-fuzzer-gadget dummy_udc.1: failed to start USB fuzzer: -22
kworker/0:5     D27752  6019      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
dummy_udc dummy_udc.5: dummy_udc_start
dummy_udc dummy_udc.1: dummy_udc_start
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
dummy_udc dummy_udc.0: dummy_udc_stop
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:4:6060 blocked for more than 144 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:4     D27752  6060      2 0x80000000
dummy_udc dummy_udc.0: dummy_udc_start
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352

Showing all locks held in the system:
5 locks held by kworker/1:1/21:
dummy_udc dummy_udc.4: dummy_udc_stop
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000bef12525 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000009a337b20 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000009a337b20 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000449599d5 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000449599d5 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000449599d5 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000449599d5 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000449599d5 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
usb-fuzzer-gadget dummy_udc.4: failed to start USB fuzzer: -22
  #4: 00000000bd693e6d (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
1 lock held by khungtaskd/23:
  #0: 00000000c249679f (rcu_read_lock){....}, at:  
debug_show_all_locks+0x53/0x269 kernel/locking/lockdep.c:5059
5 locks held by kworker/1:2/533:
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
dummy_udc dummy_udc.3: dummy_udc_stop
  #1: 000000000b2c3268 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000005e422e33 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000005e422e33 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
dummy_udc dummy_udc.4: dummy_udc_start
  #3: 00000000a7ffda5b (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000a7ffda5b (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000a7ffda5b (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000a7ffda5b (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000a7ffda5b (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 0000000040171de2 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
1 lock held by rsyslogd/5663:
  #0: 00000000eb497534 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xe8/0x100  
fs/file.c:801
2 locks held by getty/5753:
usb-fuzzer-gadget dummy_udc.3: failed to start USB fuzzer: -22
  #0: 0000000060cabbb9 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000c554441b (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5754:
  #0: 00000000bc2e3243 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000c105aa12 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5755:
  #0: 00000000e6d82cc9 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000007478c77a (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
dummy_udc dummy_udc.3: dummy_udc_start
2 locks held by getty/5756:
  #0: 00000000bdf7f201 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 0000000027b0060b (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5757:
  #0: 00000000ea25225e (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 0000000033c7c6b0 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5758:
  #0: 0000000026e22b8e (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000cc9d99b6 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5759:
  #0: 000000000c56f37f (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 0000000096b5ec30 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
5 locks held by kworker/0:4/6014:
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 000000008858d04f ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 0000000035fa4a95 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 0000000035fa4a95 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000b9e8bc7b (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000b9e8bc7b (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000b9e8bc7b (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000b9e8bc7b (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000b9e8bc7b (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 0000000029c7e38f (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/0:5/6019:
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000406d5ccc ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 00000000a0e74d96 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 00000000a0e74d96 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000f7d2af58 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000f7d2af58 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000f7d2af58 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000f7d2af58 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000f7d2af58 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 00000000f0b5cba1 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/0:6/6023:
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000f6fcfe1c ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 00000000c3342998 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 00000000c3342998 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 000000004d7e0c6e (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 000000004d7e0c6e (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 000000004d7e0c6e (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 000000004d7e0c6e (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 000000004d7e0c6e (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 00000000f25b0237 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/1:4/6060:
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000469d4ddc ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000a61f1995 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 00000000fd9214fe (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 00000000fd9214fe (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 000000000baf27f8 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 000000000baf27f8 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 000000000baf27f8 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 000000000baf27f8 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 000000000baf27f8 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 000000006e962192 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529

=============================================

NMI backtrace for cpu 1
CPU: 1 PID: 23 Comm: khungtaskd Not tainted 5.1.0-rc4-g9a33b36-dirty #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0xe8/0x16e lib/dump_stack.c:113
  nmi_cpu_backtrace.cold+0x48/0x87 lib/nmi_backtrace.c:101
  nmi_trigger_cpumask_backtrace+0x1a6/0x1bd lib/nmi_backtrace.c:62
  trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
  check_hung_uninterruptible_tasks kernel/hung_task.c:204 [inline]
  watchdog+0x98e/0xe20 kernel/hung_task.c:288
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 5881 Comm: syz-executor.0 Not tainted 5.1.0-rc4-g9a33b36-dirty  
#1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
RIP: 0010:__read_once_size include/linux/compiler.h:193 [inline]
RIP: 0010:lookup_chain_cache kernel/locking/lockdep.c:2612 [inline]
RIP: 0010:lookup_chain_cache_add kernel/locking/lockdep.c:2631 [inline]
RIP: 0010:validate_chain kernel/locking/lockdep.c:2685 [inline]
RIP: 0010:__lock_acquire+0xfb0/0x37c0 kernel/locking/lockdep.c:3701
Code: 5d 4c 8b 64 24 20 4d 89 cd 48 bd 00 00 00 00 00 fc ff df eb 06 48 83  
eb 08 74 40 48 8d 7b 18 48 89 f8 48 c1 e8 03 80 3c 28 00 <0f> 85 f1 18 00  
00 48 8b 43 18 49 39 c4 0f 84 73 f9 ff ff 48 8d 7b
RSP: 0018:ffff88809908fa50 EFLAGS: 00000046
RAX: 1ffffffff2c188b3 RBX: ffffffff960c4580 RCX: 0000000000001872
RDX: 1ffffffff2cd93fa RSI: ffff88808be80840 RDI: ffffffff960c4598
RBP: dffffc0000000000 R08: 00000000d4b587bd R09: ffffffff966c9fd0
R10: ffff88808be80840 R11: ffff88808be80000 R12: e085ce875e243443
R13: ffffffff966c9fd0 R14: ffffffff93cb0714 R15: 0000000000000001
FS:  0000000000a57940(0000) GS:ffff8880ad000000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fbda8a77000 CR3: 0000000095e60000 CR4: 00000000001406f0
Call Trace:
  lock_acquire+0x10d/0x2f0 kernel/locking/lockdep.c:4211
  __raw_read_lock include/linux/rwlock_api_smp.h:149 [inline]
  _raw_read_lock+0x2f/0x40 kernel/locking/spinlock.c:216
  do_wait+0x38b/0x940 kernel/exit.c:1523
  kernel_wait4+0x151/0x260 kernel/exit.c:1668
  __do_sys_wait4+0x147/0x160 kernel/exit.c:1680
  do_syscall_64+0xcf/0x4f0 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x412c6a
Code: 0f 83 6a 18 00 00 c3 66 0f 1f 84 00 00 00 00 00 8b 05 2e 36 64 00 85  
c0 75 36 45 31 d2 48 63 d2 48 63 ff b8 3d 00 00 00 0f 05 <48> 3d 00 f0 ff  
ff 77 06 c3 0f 1f 44 00 00 48 c7 c2 d4 ff ff ff f7
RSP: 002b:00007fff92403508 EFLAGS: 00000246 ORIG_RAX: 000000000000003d
RAX: ffffffffffffffda RBX: 000000000003d770 RCX: 0000000000412c6a
RDX: 0000000040000001 RSI: 00007fff92403540 RDI: ffffffffffffffff
RBP: 00000000000000ad R08: 0000000000000001 R09: 0000000000a57940
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
R13: 00007fff92403540 R14: 000000000003d752 R15: 00007fff92403550


Tested on:

commit:         9a33b369 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan/tree/usb-fuzzer
console output: https://syzkaller.appspot.com/x/log.txt?x=111e62cb200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=1207901d200000

Re: INFO: task hung in usb_kill_urb

[Alan Stern]

On Tue, 16 Apr 2019, syzbot wrote:

> Hello,
> 
> syzbot has tested the proposed patch but the reproducer still triggered  
> crash:
> INFO: task hung in usb_kill_urb

Okay, I think I found the problem.  dummy-hcd doesn't check for
unsupported speeds until it is too late.  Andrey, what values does your
usb-fuzzer gadget driver set for its max_speed field?

Anyway, if I'm right then this patch should fix the bug.

Alan Stern

#syz test: https://github.com/google/kasan.git usb-fuzzer

--- a/drivers/usb/gadget/udc/dummy_hcd.c
+++ b/drivers/usb/gadget/udc/dummy_hcd.c
@@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
 	struct dummy_hcd	*dum_hcd = gadget_to_dummy_hcd(g);
 	struct dummy		*dum = dum_hcd->dum;
 
-	if (driver->max_speed == USB_SPEED_UNKNOWN)
+	switch (driver->max_speed) {
+	/* All the speeds we support */
+	case USB_SPEED_LOW:
+	case USB_SPEED_FULL:
+	case USB_SPEED_HIGH:
+	case USB_SPEED_SUPER:
+		break;
+	default:
+		dev_err(dummy_dev(dum_hcd), "bogus driver max_speed %d\n",
+				driver->max_speed);
 		return -EINVAL;
+	}
 
 	/*
 	 * SLAVE side init ... the layer above hardware, which
@@ -1785,7 +1795,8 @@ static void dummy_timer(struct timer_lis
 		total = 490000;
 		break;
 	default:
-		dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
+		dev_err(dummy_dev(dum_hcd), "bogus device speed %d\n",
+				dum->gadget.speed);
 		return;
 	}
 

INFO: task hung in usb_kill_urb

[Alan Stern]

On Tue, 16 Apr 2019, syzbot wrote:

> Hello,
> 
> syzbot has tested the proposed patch but the reproducer still triggered  
> crash:
> INFO: task hung in usb_kill_urb

Okay, I think I found the problem.  dummy-hcd doesn't check for
unsupported speeds until it is too late.  Andrey, what values does your
usb-fuzzer gadget driver set for its max_speed field?

Anyway, if I'm right then this patch should fix the bug.

Alan Stern

#syz test: https://github.com/google/kasan.git usb-fuzzer

--- a/drivers/usb/gadget/udc/dummy_hcd.c
+++ b/drivers/usb/gadget/udc/dummy_hcd.c
@@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
 	struct dummy_hcd	*dum_hcd = gadget_to_dummy_hcd(g);
 	struct dummy		*dum = dum_hcd->dum;
 
-	if (driver->max_speed == USB_SPEED_UNKNOWN)
+	switch (driver->max_speed) {
+	/* All the speeds we support */
+	case USB_SPEED_LOW:
+	case USB_SPEED_FULL:
+	case USB_SPEED_HIGH:
+	case USB_SPEED_SUPER:
+		break;
+	default:
+		dev_err(dummy_dev(dum_hcd), "bogus driver max_speed %d\n",
+				driver->max_speed);
 		return -EINVAL;
+	}
 
 	/*
 	 * SLAVE side init ... the layer above hardware, which
@@ -1785,7 +1795,8 @@ static void dummy_timer(struct timer_lis
 		total = 490000;
 		break;
 	default:
-		dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
+		dev_err(dummy_dev(dum_hcd), "bogus device speed %d\n",
+				dum->gadget.speed);
 		return;
 	}
 

Re: INFO: task hung in usb_kill_urb

[syzbot]

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger  
crash:

Reported-and-tested-by:  
syzbot+d919b0f29d7b5a4994b9@syzkaller.appspotmail.com

Tested on:

commit:         9a33b369 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan/tree/usb-fuzzer
kernel config:  https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=1260cccb200000

Note: testing is done by a robot and is best-effort only.

INFO: task hung in usb_kill_urb

[syzbot]

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger  
crash:

Reported-and-tested-by:  
syzbot+d919b0f29d7b5a4994b9@syzkaller.appspotmail.com

Tested on:

commit:         9a33b369 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan/tree/usb-fuzzer
kernel config:  https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=1260cccb200000

Note: testing is done by a robot and is best-effort only.

Re: INFO: task hung in usb_kill_urb

[Alan Stern]

On Tue, 16 Apr 2019, syzbot wrote:

> Hello,
> 
> syzbot has tested the proposed patch and the reproducer did not trigger  
> crash:

Slight fixup to the patch.  Unsupported speeds aren't necessarily 
bogus, and what matters is the actual speed rather than the max_speed.
Also, we want to be able to give back unlinked URBs even after a 
frame's total bandwidth has been exhausted.

Alan Stern

#syz test: https://github.com/google/kasan.git usb-fuzzer

--- a/drivers/usb/gadget/udc/dummy_hcd.c
+++ b/drivers/usb/gadget/udc/dummy_hcd.c
@@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
 	struct dummy_hcd	*dum_hcd = gadget_to_dummy_hcd(g);
 	struct dummy		*dum = dum_hcd->dum;
 
-	if (driver->max_speed == USB_SPEED_UNKNOWN)
+	switch (g->speed) {
+	/* All the speeds we support */
+	case USB_SPEED_LOW:
+	case USB_SPEED_FULL:
+	case USB_SPEED_HIGH:
+	case USB_SPEED_SUPER:
+		break;
+	default:
+		dev_err(dummy_dev(dum_hcd), "Unsupported driver max speed %d\n",
+				driver->max_speed);
 		return -EINVAL;
+	}
 
 	/*
 	 * SLAVE side init ... the layer above hardware, which
@@ -1784,7 +1794,7 @@ static void dummy_timer(struct timer_lis
 		/* Bus speed is 500000 bytes/ms, so use a little less */
 		total = 490000;
 		break;
-	default:
+	default:	/* Can't happen */
 		dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
 		return;
 	}
@@ -1828,7 +1838,7 @@ restart:
 
 		/* Used up this frame's bandwidth? */
 		if (total <= 0)
-			break;
+			continue;
 
 		/* find the gadget's ep for this request (if configured) */
 		address = usb_pipeendpoint (urb->pipe);

INFO: task hung in usb_kill_urb

[Alan Stern]

On Tue, 16 Apr 2019, syzbot wrote:

> Hello,
> 
> syzbot has tested the proposed patch and the reproducer did not trigger  
> crash:

Slight fixup to the patch.  Unsupported speeds aren't necessarily 
bogus, and what matters is the actual speed rather than the max_speed.
Also, we want to be able to give back unlinked URBs even after a 
frame's total bandwidth has been exhausted.

Alan Stern

#syz test: https://github.com/google/kasan.git usb-fuzzer

--- a/drivers/usb/gadget/udc/dummy_hcd.c
+++ b/drivers/usb/gadget/udc/dummy_hcd.c
@@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
 	struct dummy_hcd	*dum_hcd = gadget_to_dummy_hcd(g);
 	struct dummy		*dum = dum_hcd->dum;
 
-	if (driver->max_speed == USB_SPEED_UNKNOWN)
+	switch (g->speed) {
+	/* All the speeds we support */
+	case USB_SPEED_LOW:
+	case USB_SPEED_FULL:
+	case USB_SPEED_HIGH:
+	case USB_SPEED_SUPER:
+		break;
+	default:
+		dev_err(dummy_dev(dum_hcd), "Unsupported driver max speed %d\n",
+				driver->max_speed);
 		return -EINVAL;
+	}
 
 	/*
 	 * SLAVE side init ... the layer above hardware, which
@@ -1784,7 +1794,7 @@ static void dummy_timer(struct timer_lis
 		/* Bus speed is 500000 bytes/ms, so use a little less */
 		total = 490000;
 		break;
-	default:
+	default:	/* Can't happen */
 		dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
 		return;
 	}
@@ -1828,7 +1838,7 @@ restart:
 
 		/* Used up this frame's bandwidth? */
 		if (total <= 0)
-			break;
+			continue;
 
 		/* find the gadget's ep for this request (if configured) */
 		address = usb_pipeendpoint (urb->pipe);

Re: INFO: task hung in usb_kill_urb

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
INFO: task hung in usb_kill_urb

usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
INFO: task kworker/1:1:21 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:1     D26512    21      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:2:533 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:2     D25760   533      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:3:5711 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:3     D26656  5711      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:4:5815 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:4     D27416  5815      2 0x80000000
Workqueue: usb_hub_wq hub_event
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:5:5854 blocked for more than 144 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:5     D27008  5854      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:6:5953 blocked for more than 144 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:6     D28144  5953      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352

Showing all locks held in the system:
5 locks held by kworker/1:1/21:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 0000000066a57f62 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000008061858c (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000008061858c (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000e9c2b745 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000e9c2b745 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000e9c2b745 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000e9c2b745 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000e9c2b745 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 0000000074a9c1da (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
1 lock held by khungtaskd/23:
  #0: 000000009a7c2fe9 (rcu_read_lock){....}, at:  
debug_show_all_locks+0x53/0x269 kernel/locking/lockdep.c:5059
5 locks held by kworker/1:2/533:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 0000000086e8eaf1 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000006469b3a5 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000006469b3a5 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 000000007f0b56f7 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 000000007f0b56f7 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 000000007f0b56f7 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 000000007f0b56f7 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 000000007f0b56f7 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 00000000f92a9577 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
1 lock held by rsyslogd/5452:
  #0: 0000000078f4a532 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xe8/0x100  
fs/file.c:801
2 locks held by getty/5542:
  #0: 0000000023afba58 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000bc10d82a (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5543:
  #0: 00000000a6ab1d25 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000d5a44554 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
2 locks held by getty/5544:
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  #0: 0000000098fc4771 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 0000000017060772 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5545:
  #0: 000000005fca8b56 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000005a5319f8 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5546:
  #0: 00000000e590919f (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000004775329f (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5547:
  #0: 00000000179d4d0b (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000002922a30b (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5548:
  #0: 000000006c2e3908 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000009cdeb0bf (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
5 locks held by kworker/1:3/5711:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 000000008f65d948 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 00000000d16a6c1c (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 00000000d16a6c1c (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000df89ca19 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000df89ca19 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000df89ca19 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000df89ca19 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000df89ca19 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 000000007284a231 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/1:4/5815:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000b6e140d2 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 0000000054730851 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 0000000054730851 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000e19c14b6 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000e19c14b6 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000e19c14b6 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000e19c14b6 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000e19c14b6 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 000000001c7bddbf (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/1:5/5854:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
  #1: 00000000357ce4fb ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000009d868e2d (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000009d868e2d (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  #3: 00000000938a6414 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000938a6414 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000938a6414 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000938a6414 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000938a6414 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 0000000050760949 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/1:6/5953:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000d3b00b82 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000008af22eae (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000008af22eae (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 000000007f7b7ee0 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 000000007f7b7ee0 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 000000007f7b7ee0 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 000000007f7b7ee0 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 000000007f7b7ee0 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 0000000090909ece (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529

=============================================

NMI backtrace for cpu 0
CPU: 0 PID: 23 Comm: khungtaskd Not tainted 5.1.0-rc4-g9a33b36-dirty #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0xe8/0x16e lib/dump_stack.c:113
  nmi_cpu_backtrace.cold+0x48/0x87 lib/nmi_backtrace.c:101
  nmi_trigger_cpumask_backtrace+0x1a6/0x1bd lib/nmi_backtrace.c:62
  trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
  check_hung_uninterruptible_tasks kernel/hung_task.c:204 [inline]
  watchdog+0x98e/0xe20 kernel/hung_task.c:288
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at native_safe_halt+0x2/0x10  
arch/x86/include/asm/irqflags.h:57


Tested on:

commit:         9a33b369 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan/tree/usb-fuzzer
console output: https://syzkaller.appspot.com/x/log.txt?x=10b5e057200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=131dca6b200000

INFO: task hung in usb_kill_urb

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
INFO: task hung in usb_kill_urb

usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
INFO: task kworker/1:1:21 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:1     D26512    21      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:2:533 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:2     D25760   533      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:3:5711 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:3     D26656  5711      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:4:5815 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:4     D27416  5815      2 0x80000000
Workqueue: usb_hub_wq hub_event
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:5:5854 blocked for more than 144 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:5     D27008  5854      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
INFO: task kworker/1:6:5953 blocked for more than 144 seconds.
       Not tainted 5.1.0-rc4-g9a33b36-dirty #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:6     D28144  5953      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352

Showing all locks held in the system:
5 locks held by kworker/1:1/21:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 0000000066a57f62 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000008061858c (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000008061858c (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000e9c2b745 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000e9c2b745 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000e9c2b745 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000e9c2b745 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000e9c2b745 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 0000000074a9c1da (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
1 lock held by khungtaskd/23:
  #0: 000000009a7c2fe9 (rcu_read_lock){....}, at:  
debug_show_all_locks+0x53/0x269 kernel/locking/lockdep.c:5059
5 locks held by kworker/1:2/533:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 0000000086e8eaf1 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000006469b3a5 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000006469b3a5 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 000000007f0b56f7 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 000000007f0b56f7 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 000000007f0b56f7 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 000000007f0b56f7 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 000000007f0b56f7 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 00000000f92a9577 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
1 lock held by rsyslogd/5452:
  #0: 0000000078f4a532 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xe8/0x100  
fs/file.c:801
2 locks held by getty/5542:
  #0: 0000000023afba58 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000bc10d82a (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5543:
  #0: 00000000a6ab1d25 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000d5a44554 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
2 locks held by getty/5544:
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  #0: 0000000098fc4771 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 0000000017060772 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5545:
  #0: 000000005fca8b56 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000005a5319f8 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5546:
  #0: 00000000e590919f (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000004775329f (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5547:
  #0: 00000000179d4d0b (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000002922a30b (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5548:
  #0: 000000006c2e3908 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000009cdeb0bf (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
5 locks held by kworker/1:3/5711:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 000000008f65d948 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 00000000d16a6c1c (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 00000000d16a6c1c (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000df89ca19 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000df89ca19 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000df89ca19 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000df89ca19 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000df89ca19 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 000000007284a231 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/1:4/5815:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000b6e140d2 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 0000000054730851 (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 0000000054730851 (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 00000000e19c14b6 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000e19c14b6 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000e19c14b6 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000e19c14b6 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000e19c14b6 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 000000001c7bddbf (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/1:5/5854:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
dummy_hcd dummy_hcd.0: Unsupported driver max speed 0
  #1: 00000000357ce4fb ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000009d868e2d (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000009d868e2d (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  #3: 00000000938a6414 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 00000000938a6414 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 00000000938a6414 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 00000000938a6414 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 00000000938a6414 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 0000000050760949 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
5 locks held by kworker/1:6/5953:
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 00000000b3ad1415 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 00000000d3b00b82 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 000000008af22eae (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 000000008af22eae (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 000000007f7b7ee0 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 000000007f7b7ee0 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 000000007f7b7ee0 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 000000007f7b7ee0 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 000000007f7b7ee0 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 0000000090909ece (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529

=============================================

NMI backtrace for cpu 0
CPU: 0 PID: 23 Comm: khungtaskd Not tainted 5.1.0-rc4-g9a33b36-dirty #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0xe8/0x16e lib/dump_stack.c:113
  nmi_cpu_backtrace.cold+0x48/0x87 lib/nmi_backtrace.c:101
  nmi_trigger_cpumask_backtrace+0x1a6/0x1bd lib/nmi_backtrace.c:62
  trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
  check_hung_uninterruptible_tasks kernel/hung_task.c:204 [inline]
  watchdog+0x98e/0xe20 kernel/hung_task.c:288
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at native_safe_halt+0x2/0x10  
arch/x86/include/asm/irqflags.h:57


Tested on:

commit:         9a33b369 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan/tree/usb-fuzzer
console output: https://syzkaller.appspot.com/x/log.txt?x=10b5e057200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=131dca6b200000

Re: INFO: task hung in usb_kill_urb

[Alan Stern]

On Tue, 16 Apr 2019, syzbot wrote:

> Hello,
> 
> syzbot has tested the proposed patch but the reproducer still triggered  
> crash:
> INFO: task hung in usb_kill_urb

That's surprising.  This patch was awfully similar to the previous one,
which did prevent the crash earlier.

> Tested on:
> 
> commit:         9a33b369 usb-fuzzer: main usb gadget fuzzer driver
> git tree:       https://github.com/google/kasan/tree/usb-fuzzer
> console output: https://syzkaller.appspot.com/x/log.txt?x=10b5e057200000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
> compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> patch:          https://syzkaller.appspot.com/x/patch.diff?x=131dca6b200000

Andrey, is there any way to increase the console output buffer size?  
The link above doesn't go all the way back to the beginning of the test
(it starts at timestamp 486.614697).

Also, here's a slightly revised patch for testing.

Alan Stern


#syz test: https://github.com/google/kasan.git usb-fuzzer

--- a/drivers/usb/gadget/udc/dummy_hcd.c
+++ b/drivers/usb/gadget/udc/dummy_hcd.c
@@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
 	struct dummy_hcd	*dum_hcd = gadget_to_dummy_hcd(g);
 	struct dummy		*dum = dum_hcd->dum;
 
-	if (driver->max_speed == USB_SPEED_UNKNOWN)
+	switch (g->speed) {
+	/* All the speeds we support */
+	case USB_SPEED_LOW:
+	case USB_SPEED_FULL:
+	case USB_SPEED_HIGH:
+	case USB_SPEED_SUPER:
+		break;
+	default:
+		dev_err(dummy_dev(dum_hcd), "Unsupported driver max speed %d\n",
+				driver->max_speed);
 		return -EINVAL;
+	}
 
 	/*
 	 * SLAVE side init ... the layer above hardware, which
@@ -1784,9 +1794,10 @@ static void dummy_timer(struct timer_lis
 		/* Bus speed is 500000 bytes/ms, so use a little less */
 		total = 490000;
 		break;
-	default:
+	default:	/* Can't happen */
 		dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
-		return;
+		total = 0;
+		break;
 	}
 
 	/* FIXME if HZ != 1000 this will probably misbehave ... */
@@ -1828,7 +1839,7 @@ restart:
 
 		/* Used up this frame's bandwidth? */
 		if (total <= 0)
-			break;
+			continue;
 
 		/* find the gadget's ep for this request (if configured) */
 		address = usb_pipeendpoint (urb->pipe);

INFO: task hung in usb_kill_urb

[Alan Stern]

On Tue, 16 Apr 2019, syzbot wrote:

> Hello,
> 
> syzbot has tested the proposed patch but the reproducer still triggered  
> crash:
> INFO: task hung in usb_kill_urb

That's surprising.  This patch was awfully similar to the previous one,
which did prevent the crash earlier.

> Tested on:
> 
> commit:         9a33b369 usb-fuzzer: main usb gadget fuzzer driver
> git tree:       https://github.com/google/kasan/tree/usb-fuzzer
> console output: https://syzkaller.appspot.com/x/log.txt?x=10b5e057200000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
> compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> patch:          https://syzkaller.appspot.com/x/patch.diff?x=131dca6b200000

Andrey, is there any way to increase the console output buffer size?  
The link above doesn't go all the way back to the beginning of the test
(it starts at timestamp 486.614697).

Also, here's a slightly revised patch for testing.

Alan Stern


#syz test: https://github.com/google/kasan.git usb-fuzzer

--- a/drivers/usb/gadget/udc/dummy_hcd.c
+++ b/drivers/usb/gadget/udc/dummy_hcd.c
@@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
 	struct dummy_hcd	*dum_hcd = gadget_to_dummy_hcd(g);
 	struct dummy		*dum = dum_hcd->dum;
 
-	if (driver->max_speed == USB_SPEED_UNKNOWN)
+	switch (g->speed) {
+	/* All the speeds we support */
+	case USB_SPEED_LOW:
+	case USB_SPEED_FULL:
+	case USB_SPEED_HIGH:
+	case USB_SPEED_SUPER:
+		break;
+	default:
+		dev_err(dummy_dev(dum_hcd), "Unsupported driver max speed %d\n",
+				driver->max_speed);
 		return -EINVAL;
+	}
 
 	/*
 	 * SLAVE side init ... the layer above hardware, which
@@ -1784,9 +1794,10 @@ static void dummy_timer(struct timer_lis
 		/* Bus speed is 500000 bytes/ms, so use a little less */
 		total = 490000;
 		break;
-	default:
+	default:	/* Can't happen */
 		dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
-		return;
+		total = 0;
+		break;
 	}
 
 	/* FIXME if HZ != 1000 this will probably misbehave ... */
@@ -1828,7 +1839,7 @@ restart:
 
 		/* Used up this frame's bandwidth? */
 		if (total <= 0)
-			break;
+			continue;
 
 		/* find the gadget's ep for this request (if configured) */
 		address = usb_pipeendpoint (urb->pipe);

Re: INFO: task hung in usb_kill_urb

[syzbot]

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger  
crash:

Reported-and-tested-by:  
syzbot+d919b0f29d7b5a4994b9@syzkaller.appspotmail.com

Tested on:

commit:         d34f9519 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan/tree/usb-fuzzer
kernel config:  https://syzkaller.appspot.com/x/.config?x=c73d1bb5aeaeae20
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=12a17dfd200000

Note: testing is done by a robot and is best-effort only.

INFO: task hung in usb_kill_urb

[syzbot]

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger  
crash:

Reported-and-tested-by:  
syzbot+d919b0f29d7b5a4994b9@syzkaller.appspotmail.com

Tested on:

commit:         d34f9519 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan/tree/usb-fuzzer
kernel config:  https://syzkaller.appspot.com/x/.config?x=c73d1bb5aeaeae20
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=12a17dfd200000

Note: testing is done by a robot and is best-effort only.

Re: INFO: task hung in usb_kill_urb

[Andrey Konovalov]

On Wed, Apr 17, 2019 at 9:09 PM Alan Stern <stern@rowland.harvard.edu> wrote:
>
> On Tue, 16 Apr 2019, syzbot wrote:
>
> > Hello,
> >
> > syzbot has tested the proposed patch but the reproducer still triggered
> > crash:
> > INFO: task hung in usb_kill_urb
>
> That's surprising.  This patch was awfully similar to the previous one,
> which did prevent the crash earlier.
>
> > Tested on:
> >
> > commit:         9a33b369 usb-fuzzer: main usb gadget fuzzer driver
> > git tree:       https://github.com/google/kasan/tree/usb-fuzzer
> > console output: https://syzkaller.appspot.com/x/log.txt?x=10b5e057200000
> > kernel config:  https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
> > compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> > patch:          https://syzkaller.appspot.com/x/patch.diff?x=131dca6b200000
>
> Andrey, is there any way to increase the console output buffer size?

Hm, I'm not sure why it got truncated here, the previous one was full.
I would try running the syz test command again in this case.

> The link above doesn't go all the way back to the beginning of the test
> (it starts at timestamp 486.614697).
>
> Also, here's a slightly revised patch for testing.
>
> Alan Stern
>
>
> #syz test: https://github.com/google/kasan.git usb-fuzzer
>
> --- a/drivers/usb/gadget/udc/dummy_hcd.c
> +++ b/drivers/usb/gadget/udc/dummy_hcd.c
> @@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
>         struct dummy_hcd        *dum_hcd = gadget_to_dummy_hcd(g);
>         struct dummy            *dum = dum_hcd->dum;
>
> -       if (driver->max_speed == USB_SPEED_UNKNOWN)
> +       switch (g->speed) {
> +       /* All the speeds we support */
> +       case USB_SPEED_LOW:
> +       case USB_SPEED_FULL:
> +       case USB_SPEED_HIGH:
> +       case USB_SPEED_SUPER:
> +               break;
> +       default:
> +               dev_err(dummy_dev(dum_hcd), "Unsupported driver max speed %d\n",
> +                               driver->max_speed);
>                 return -EINVAL;
> +       }
>
>         /*
>          * SLAVE side init ... the layer above hardware, which
> @@ -1784,9 +1794,10 @@ static void dummy_timer(struct timer_lis
>                 /* Bus speed is 500000 bytes/ms, so use a little less */
>                 total = 490000;
>                 break;
> -       default:
> +       default:        /* Can't happen */
>                 dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
> -               return;
> +               total = 0;
> +               break;
>         }
>
>         /* FIXME if HZ != 1000 this will probably misbehave ... */
> @@ -1828,7 +1839,7 @@ restart:
>
>                 /* Used up this frame's bandwidth? */
>                 if (total <= 0)
> -                       break;
> +                       continue;
>
>                 /* find the gadget's ep for this request (if configured) */
>                 address = usb_pipeendpoint (urb->pipe);
>

INFO: task hung in usb_kill_urb

[Andrey Konovalov]

On Wed, Apr 17, 2019 at 9:09 PM Alan Stern <stern@rowland.harvard.edu> wrote:
>
> On Tue, 16 Apr 2019, syzbot wrote:
>
> > Hello,
> >
> > syzbot has tested the proposed patch but the reproducer still triggered
> > crash:
> > INFO: task hung in usb_kill_urb
>
> That's surprising.  This patch was awfully similar to the previous one,
> which did prevent the crash earlier.
>
> > Tested on:
> >
> > commit:         9a33b369 usb-fuzzer: main usb gadget fuzzer driver
> > git tree:       https://github.com/google/kasan/tree/usb-fuzzer
> > console output: https://syzkaller.appspot.com/x/log.txt?x=10b5e057200000
> > kernel config:  https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
> > compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> > patch:          https://syzkaller.appspot.com/x/patch.diff?x=131dca6b200000
>
> Andrey, is there any way to increase the console output buffer size?

Hm, I'm not sure why it got truncated here, the previous one was full.
I would try running the syz test command again in this case.

> The link above doesn't go all the way back to the beginning of the test
> (it starts at timestamp 486.614697).
>
> Also, here's a slightly revised patch for testing.
>
> Alan Stern
>
>
> #syz test: https://github.com/google/kasan.git usb-fuzzer
>
> --- a/drivers/usb/gadget/udc/dummy_hcd.c
> +++ b/drivers/usb/gadget/udc/dummy_hcd.c
> @@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
>         struct dummy_hcd        *dum_hcd = gadget_to_dummy_hcd(g);
>         struct dummy            *dum = dum_hcd->dum;
>
> -       if (driver->max_speed == USB_SPEED_UNKNOWN)
> +       switch (g->speed) {
> +       /* All the speeds we support */
> +       case USB_SPEED_LOW:
> +       case USB_SPEED_FULL:
> +       case USB_SPEED_HIGH:
> +       case USB_SPEED_SUPER:
> +               break;
> +       default:
> +               dev_err(dummy_dev(dum_hcd), "Unsupported driver max speed %d\n",
> +                               driver->max_speed);
>                 return -EINVAL;
> +       }
>
>         /*
>          * SLAVE side init ... the layer above hardware, which
> @@ -1784,9 +1794,10 @@ static void dummy_timer(struct timer_lis
>                 /* Bus speed is 500000 bytes/ms, so use a little less */
>                 total = 490000;
>                 break;
> -       default:
> +       default:        /* Can't happen */
>                 dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
> -               return;
> +               total = 0;
> +               break;
>         }
>
>         /* FIXME if HZ != 1000 this will probably misbehave ... */
> @@ -1828,7 +1839,7 @@ restart:
>
>                 /* Used up this frame's bandwidth? */
>                 if (total <= 0)
> -                       break;
> +                       continue;
>
>                 /* find the gadget's ep for this request (if configured) */
>                 address = usb_pipeendpoint (urb->pipe);
>

Re: INFO: task hung in usb_kill_urb

[Andrey Konovalov]

On Tue, Apr 16, 2019 at 8:25 PM Alan Stern <stern@rowland.harvard.edu> wrote:
>
> On Tue, 16 Apr 2019, syzbot wrote:
>
> > Hello,
> >
> > syzbot has tested the proposed patch but the reproducer still triggered
> > crash:
> > INFO: task hung in usb_kill_urb
>
> Okay, I think I found the problem.  dummy-hcd doesn't check for
> unsupported speeds until it is too late.  Andrey, what values does your
> usb-fuzzer gadget driver set for its max_speed field?

It's passed from userspace without any validation :( I'll fix this!
Thanks for looking into it!

I wonder why other people saw this hang as well, they didn't use the
dummy hcd module for sure. I guess there are might be other reasons.

>
> Anyway, if I'm right then this patch should fix the bug.
>
> Alan Stern
>
> #syz test: https://github.com/google/kasan.git usb-fuzzer
>
> --- a/drivers/usb/gadget/udc/dummy_hcd.c
> +++ b/drivers/usb/gadget/udc/dummy_hcd.c
> @@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
>         struct dummy_hcd        *dum_hcd = gadget_to_dummy_hcd(g);
>         struct dummy            *dum = dum_hcd->dum;
>
> -       if (driver->max_speed == USB_SPEED_UNKNOWN)
> +       switch (driver->max_speed) {
> +       /* All the speeds we support */
> +       case USB_SPEED_LOW:
> +       case USB_SPEED_FULL:
> +       case USB_SPEED_HIGH:
> +       case USB_SPEED_SUPER:
> +               break;
> +       default:
> +               dev_err(dummy_dev(dum_hcd), "bogus driver max_speed %d\n",
> +                               driver->max_speed);
>                 return -EINVAL;
> +       }
>
>         /*
>          * SLAVE side init ... the layer above hardware, which
> @@ -1785,7 +1795,8 @@ static void dummy_timer(struct timer_lis
>                 total = 490000;
>                 break;
>         default:
> -               dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
> +               dev_err(dummy_dev(dum_hcd), "bogus device speed %d\n",
> +                               dum->gadget.speed);
>                 return;
>         }
>
>
>

INFO: task hung in usb_kill_urb

[Andrey Konovalov]

On Tue, Apr 16, 2019 at 8:25 PM Alan Stern <stern@rowland.harvard.edu> wrote:
>
> On Tue, 16 Apr 2019, syzbot wrote:
>
> > Hello,
> >
> > syzbot has tested the proposed patch but the reproducer still triggered
> > crash:
> > INFO: task hung in usb_kill_urb
>
> Okay, I think I found the problem.  dummy-hcd doesn't check for
> unsupported speeds until it is too late.  Andrey, what values does your
> usb-fuzzer gadget driver set for its max_speed field?

It's passed from userspace without any validation :( I'll fix this!
Thanks for looking into it!

I wonder why other people saw this hang as well, they didn't use the
dummy hcd module for sure. I guess there are might be other reasons.

>
> Anyway, if I'm right then this patch should fix the bug.
>
> Alan Stern
>
> #syz test: https://github.com/google/kasan.git usb-fuzzer
>
> --- a/drivers/usb/gadget/udc/dummy_hcd.c
> +++ b/drivers/usb/gadget/udc/dummy_hcd.c
> @@ -979,8 +979,18 @@ static int dummy_udc_start(struct usb_ga
>         struct dummy_hcd        *dum_hcd = gadget_to_dummy_hcd(g);
>         struct dummy            *dum = dum_hcd->dum;
>
> -       if (driver->max_speed == USB_SPEED_UNKNOWN)
> +       switch (driver->max_speed) {
> +       /* All the speeds we support */
> +       case USB_SPEED_LOW:
> +       case USB_SPEED_FULL:
> +       case USB_SPEED_HIGH:
> +       case USB_SPEED_SUPER:
> +               break;
> +       default:
> +               dev_err(dummy_dev(dum_hcd), "bogus driver max_speed %d\n",
> +                               driver->max_speed);
>                 return -EINVAL;
> +       }
>
>         /*
>          * SLAVE side init ... the layer above hardware, which
> @@ -1785,7 +1795,8 @@ static void dummy_timer(struct timer_lis
>                 total = 490000;
>                 break;
>         default:
> -               dev_err(dummy_dev(dum_hcd), "bogus device speed\n");
> +               dev_err(dummy_dev(dum_hcd), "bogus device speed %d\n",
> +                               dum->gadget.speed);
>                 return;
>         }
>
>
>

UDC hardware for fuzzing [was: Re: INFO: task hung in usb_kill_urb]

[Alan Stern]

On Wed, 17 Apr 2019, Andrey Konovalov wrote:

> On Tue, Apr 16, 2019 at 8:25 PM Alan Stern <stern@rowland.harvard.edu> wrote:
> >
> > On Tue, 16 Apr 2019, syzbot wrote:
> >
> > > Hello,
> > >
> > > syzbot has tested the proposed patch but the reproducer still triggered
> > > crash:
> > > INFO: task hung in usb_kill_urb
> >
> > Okay, I think I found the problem.  dummy-hcd doesn't check for
> > unsupported speeds until it is too late.  Andrey, what values does your
> > usb-fuzzer gadget driver set for its max_speed field?
> 
> It's passed from userspace without any validation :( I'll fix this!
> Thanks for looking into it!
> 
> I wonder why other people saw this hang as well, they didn't use the
> dummy hcd module for sure. I guess there are might be other reasons.

Unquestionably it would be for other reasons.  usb_kill_urb() is a 
host-side routine, not used by gadget drivers.  If it fails, the reason 
lies in host controller driver.  And if people aren't using dummy-hcd 
then they must be using a different host controller driver.

Is there any chance you could get hold of a USB device controller for 
more fuzzing tests?  With it, you could test other parts of the USB 
stack: the UDC driver for whatever hardware you get, and the host 
controller driver for whatever you plug the UDC into.

I don't know what types of UDC are readily available for the type of
computer syzkaller uses.  Perhaps Felipe or other people on the mailing
list will have some suggestions.

Alan Stern

INFO: task hung in usb_kill_urb

[Alan Stern]

On Wed, 17 Apr 2019, Andrey Konovalov wrote:

> On Tue, Apr 16, 2019 at 8:25 PM Alan Stern <stern@rowland.harvard.edu> wrote:
> >
> > On Tue, 16 Apr 2019, syzbot wrote:
> >
> > > Hello,
> > >
> > > syzbot has tested the proposed patch but the reproducer still triggered
> > > crash:
> > > INFO: task hung in usb_kill_urb
> >
> > Okay, I think I found the problem.  dummy-hcd doesn't check for
> > unsupported speeds until it is too late.  Andrey, what values does your
> > usb-fuzzer gadget driver set for its max_speed field?
> 
> It's passed from userspace without any validation :( I'll fix this!
> Thanks for looking into it!
> 
> I wonder why other people saw this hang as well, they didn't use the
> dummy hcd module for sure. I guess there are might be other reasons.

Unquestionably it would be for other reasons.  usb_kill_urb() is a 
host-side routine, not used by gadget drivers.  If it fails, the reason 
lies in host controller driver.  And if people aren't using dummy-hcd 
then they must be using a different host controller driver.

Is there any chance you could get hold of a USB device controller for 
more fuzzing tests?  With it, you could test other parts of the USB 
stack: the UDC driver for whatever hardware you get, and the host 
controller driver for whatever you plug the UDC into.

I don't know what types of UDC are readily available for the type of
computer syzkaller uses.  Perhaps Felipe or other people on the mailing
list will have some suggestions.

Alan Stern

Re: UDC hardware for fuzzing [was: Re: INFO: task hung in usb_kill_urb]

[Andrey Konovalov]

On Fri, Apr 19, 2019 at 8:36 PM Alan Stern <stern@rowland.harvard.edu> wrote:
>
> On Wed, 17 Apr 2019, Andrey Konovalov wrote:
>
> > On Tue, Apr 16, 2019 at 8:25 PM Alan Stern <stern@rowland.harvard.edu> wrote:
> > >
> > > On Tue, 16 Apr 2019, syzbot wrote:
> > >
> > > > Hello,
> > > >
> > > > syzbot has tested the proposed patch but the reproducer still triggered
> > > > crash:
> > > > INFO: task hung in usb_kill_urb
> > >
> > > Okay, I think I found the problem.  dummy-hcd doesn't check for
> > > unsupported speeds until it is too late.  Andrey, what values does your
> > > usb-fuzzer gadget driver set for its max_speed field?
> >
> > It's passed from userspace without any validation :( I'll fix this!
> > Thanks for looking into it!
> >
> > I wonder why other people saw this hang as well, they didn't use the
> > dummy hcd module for sure. I guess there are might be other reasons.
>
> Unquestionably it would be for other reasons.  usb_kill_urb() is a
> host-side routine, not used by gadget drivers.  If it fails, the reason
> lies in host controller driver.  And if people aren't using dummy-hcd
> then they must be using a different host controller driver.
>
> Is there any chance you could get hold of a USB device controller for
> more fuzzing tests?  With it, you could test other parts of the USB
> stack: the UDC driver for whatever hardware you get, and the host
> controller driver for whatever you plug the UDC into.
>
> I don't know what types of UDC are readily available for the type of
> computer syzkaller uses.  Perhaps Felipe or other people on the mailing
> list will have some suggestions.

You mean using a hardware UDC and plugging it into a USB host via a
physical USB cable? Yeah, I've tried that. I've used the UDC that's
available on Raspberry Pi Zero which uses the dwc2 driver for running
the reproducers syzkaller generates while having it connected to a
Linux host. It works! =) I also have a USB3380 based UDC that uses the
net2280 gadget driver. It kind of works, I was able to emulate a
SuperSpeed device with it, but the driver crashes all the time.

I haven't tried actual fuzzing of a physical host yet, that is
something on my TODO list. I was more interested in fuzzing non-Linux
hosts this way, but I can try it with Linux as well. The problem here
is that it's difficult to automate this.

INFO: task hung in usb_kill_urb

[Andrey Konovalov]

On Fri, Apr 19, 2019 at 8:36 PM Alan Stern <stern@rowland.harvard.edu> wrote:
>
> On Wed, 17 Apr 2019, Andrey Konovalov wrote:
>
> > On Tue, Apr 16, 2019 at 8:25 PM Alan Stern <stern@rowland.harvard.edu> wrote:
> > >
> > > On Tue, 16 Apr 2019, syzbot wrote:
> > >
> > > > Hello,
> > > >
> > > > syzbot has tested the proposed patch but the reproducer still triggered
> > > > crash:
> > > > INFO: task hung in usb_kill_urb
> > >
> > > Okay, I think I found the problem.  dummy-hcd doesn't check for
> > > unsupported speeds until it is too late.  Andrey, what values does your
> > > usb-fuzzer gadget driver set for its max_speed field?
> >
> > It's passed from userspace without any validation :( I'll fix this!
> > Thanks for looking into it!
> >
> > I wonder why other people saw this hang as well, they didn't use the
> > dummy hcd module for sure. I guess there are might be other reasons.
>
> Unquestionably it would be for other reasons.  usb_kill_urb() is a
> host-side routine, not used by gadget drivers.  If it fails, the reason
> lies in host controller driver.  And if people aren't using dummy-hcd
> then they must be using a different host controller driver.
>
> Is there any chance you could get hold of a USB device controller for
> more fuzzing tests?  With it, you could test other parts of the USB
> stack: the UDC driver for whatever hardware you get, and the host
> controller driver for whatever you plug the UDC into.
>
> I don't know what types of UDC are readily available for the type of
> computer syzkaller uses.  Perhaps Felipe or other people on the mailing
> list will have some suggestions.

You mean using a hardware UDC and plugging it into a USB host via a
physical USB cable? Yeah, I've tried that. I've used the UDC that's
available on Raspberry Pi Zero which uses the dwc2 driver for running
the reproducers syzkaller generates while having it connected to a
Linux host. It works! =) I also have a USB3380 based UDC that uses the
net2280 gadget driver. It kind of works, I was able to emulate a
SuperSpeed device with it, but the driver crashes all the time.

I haven't tried actual fuzzing of a physical host yet, that is
something on my TODO list. I was more interested in fuzzing non-Linux
hosts this way, but I can try it with Linux as well. The problem here
is that it's difficult to automate this.