On Tue, 16 Apr 2019, syzbot wrote:
> Hello,
>
> syzbot has tested the proposed patch but the reproducer still triggered
> crash:
> WARNING in usb_submit_urb
>
> hub 3-0:1.0: 0000000015733366 hub_activate type 4 discon 0
> hub 3-0:1.0: 0000000015733366 Submitting status URB
> hub 3-0:1.0: 0000000015733366 Submitting status URB
> ------------[ cut here ]------------
> URB 000000006ea6e83c submitted while active
> WARNING: CPU: 0 PID: 6476 at drivers/usb/core/urb.c:363
Here's more of the context, showing the important part:
[ 115.102684] hub 3-0:1.0: USB hub found
[ 115.107011] hub 3-0:1.0: 8 ports detected
A new USB bus was registered and its root hub was probed.
[ 115.114470] hub 3-0:1.0: 0000000015733366 hub_activate type 0 discon 0
Type 0 is HUB_INIT, the first stage of activating a new hub. This
stage involves a long delay, so it calls
usb_autopm_get_interface_no_resume(), schedules a delayed work routine
to carry out the next stage, and returns.
[ 115.180282] hub 3-0:1.0: 0000000015733366 hub_suspend
[ 115.214681] hub 3-0:1.0: 0000000015733366 hub_quiesce type 2
Type 2 quiesce is HUB_SUSPEND. Somehow the hub was autosuspended even
though its runtime PM usage count was elevated!
[ 115.231986] hub 3-0:1.0: 0000000015733366 hub_resume
[ 115.241706] hub 3-0:1.0: 0000000015733366 hub_activate type 1 discon 0
[ 115.249931] hub 3-0:1.0: 0000000015733366 hub_activate type 4 discon 0
Then the hub was resumed again. Type 1 activation is HUB_INIT2, the
second stage of the original hub activation. Type 4 is HUB_RESUME.
Evidently both types of activation are running concurrently.
[ 115.276027] hub 3-0:1.0: 0000000015733366 Submitting status URB
[ 115.288239] hub 3-0:1.0: 0000000015733366 Submitting status URB
[ 115.295347] ------------[ cut here ]------------
[ 115.300505] URB 000000006ea6e83c submitted while active
Both activation threads submit the same status URB, leading to the
error.
So the question is: Why was the hub suspended at a time when it should
have remained active? Let's see what the runtime PM values are when
hub_suspend is called.
Alan Stern
#syz test: git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
e12e00e388de
--- a/drivers/usb/core/hub.c
+++ b/drivers/usb/core/hub.c
@@ -1016,6 +1016,9 @@ static void hub_activate(struct usb_hub
bool need_debounce_delay = false;
unsigned delay;
+ dev_info(hub->intfdev, "%p %s type %d discon %d\n",
+ hub, __func__, type, hub->disconnected);
+
/* Continue a partial initialization */
if (type == HUB_INIT2 || type == HUB_INIT3) {
device_lock(&hdev->dev);
@@ -1254,6 +1257,7 @@ static void hub_activate(struct usb_hub
init3:
hub->quiescing = 0;
+ dev_info(hub->intfdev, "%p Submitting status URB\n", hub);
status = usb_submit_urb(hub->urb, GFP_NOIO);
if (status < 0)
dev_err(hub->intfdev, "activate --> %d\n", status);
@@ -1299,6 +1303,8 @@ static void hub_quiesce(struct usb_hub *
unsigned long flags;
int i;
+ dev_info(hub->intfdev, "%p %s type %d\n", hub, __func__, type);
+
/* hub_wq and related activity won't re-trigger */
spin_lock_irqsave(&hub->irq_urb_lock, flags);
hub->quiescing = 1;
@@ -3711,7 +3717,11 @@ static int hub_suspend(struct usb_interf
}
}
- dev_dbg(&intf->dev, "%s\n", __func__);
+ dev_info(&intf->dev, "%p %s disable %d usage %d status %d\n",
+ hub, __func__,
+ intf->dev.power.disable_depth,
+ atomic_read(&intf->dev.power.usage_count),
+ intf->dev.power.runtime_status);
/* stop hub_wq and related activity */
hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3766,7 @@ static int hub_resume(struct usb_interfa
{
struct usb_hub *hub = usb_get_intfdata(intf);
- dev_dbg(&intf->dev, "%s\n", __func__);
+ dev_info(&intf->dev, "%p %s\n", hub, __func__);
hub_activate(hub, HUB_RESUME);
/*
