WARNING in usb_submit_urb (4)

WARNING in usb_submit_urb (4)

[Alan Stern]

On Mon, 15 Apr 2019, Andrey Konovalov wrote:

> On Mon, Apr 15, 2019 at 5:16 PM Andrey Konovalov <andreyknvl@google.com> wrote:
> >
> > On Mon, Apr 15, 2019 at 2:34 PM syzbot
> > <syzbot+7634edaea4d0b341c625@syzkaller.appspotmail.com> wrote:
> > >
> > > Hello,
> > >
> > > syzbot has tested the proposed patch and the reproducer did not trigger
> > > crash:
> > >
> > > Reported-and-tested-by:
> > > syzbot+7634edaea4d0b341c625@syzkaller.appspotmail.com
> >
> > Hm, I think this is some kind of race and the patch affects the
> > timings, so this can't be reproduced that easily. I'll try to do it
> > manually.
> 
> Hm, now I'm having troubles to reproduce it manually. Let's try your
> debug patch once more on the exact commit this was reported. If it
> doesn't trigger, I think the best thing would be to close this report
> as invalid, and wait for syzbot to (hopefully) generate a fresh
> reproducer.
> 
> #syz test: git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
> e12e00e388de

Okay, let's try a simpler and less intrusive debugging patch.

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,8 @@ static void hub_activate(struct usb_hub
 	bool need_debounce_delay = false;
 	unsigned delay;
 
+	dev_info(hub->intfdev, "%s type %d\n", __func__, type);
+
 	/* Continue a partial initialization */
 	if (type == HUB_INIT2 || type == HUB_INIT3) {
 		device_lock(&hdev->dev);
@@ -1254,6 +1256,7 @@ static void hub_activate(struct usb_hub
  init3:
 	hub->quiescing = 0;
 
+	dev_info(hub->intfdev, "Submitting status URB\n");
 	status = usb_submit_urb(hub->urb, GFP_NOIO);
 	if (status < 0)
 		dev_err(hub->intfdev, "activate --> %d\n", status);
@@ -3711,7 +3714,7 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%s\n", __func__);
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3759,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, "%s\n", __func__);
 	hub_activate(hub, HUB_RESUME);
 
 	/*

Re: WARNING in usb_submit_urb (4)

[Alan Stern]

On Mon, 15 Apr 2019, Andrey Konovalov wrote:

> On Mon, Apr 15, 2019 at 5:16 PM Andrey Konovalov <andreyknvl@google.com> wrote:
> >
> > On Mon, Apr 15, 2019 at 2:34 PM syzbot
> > <syzbot+7634edaea4d0b341c625@syzkaller.appspotmail.com> wrote:
> > >
> > > Hello,
> > >
> > > syzbot has tested the proposed patch and the reproducer did not trigger
> > > crash:
> > >
> > > Reported-and-tested-by:
> > > syzbot+7634edaea4d0b341c625@syzkaller.appspotmail.com
> >
> > Hm, I think this is some kind of race and the patch affects the
> > timings, so this can't be reproduced that easily. I'll try to do it
> > manually.
> 
> Hm, now I'm having troubles to reproduce it manually. Let's try your
> debug patch once more on the exact commit this was reported. If it
> doesn't trigger, I think the best thing would be to close this report
> as invalid, and wait for syzbot to (hopefully) generate a fresh
> reproducer.
> 
> #syz test: git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
> e12e00e388de

Okay, let's try a simpler and less intrusive debugging patch.

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,8 @@ static void hub_activate(struct usb_hub
 	bool need_debounce_delay = false;
 	unsigned delay;
 
+	dev_info(hub->intfdev, "%s type %d\n", __func__, type);
+
 	/* Continue a partial initialization */
 	if (type == HUB_INIT2 || type == HUB_INIT3) {
 		device_lock(&hdev->dev);
@@ -1254,6 +1256,7 @@ static void hub_activate(struct usb_hub
  init3:
 	hub->quiescing = 0;
 
+	dev_info(hub->intfdev, "Submitting status URB\n");
 	status = usb_submit_urb(hub->urb, GFP_NOIO);
 	if (status < 0)
 		dev_err(hub->intfdev, "activate --> %d\n", status);
@@ -3711,7 +3714,7 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%s\n", __func__);
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3759,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, "%s\n", __func__);
 	hub_activate(hub, HUB_RESUME);
 
 	/*

WARNING in usb_submit_urb (4)

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
WARNING in usb_submit_urb

hub 3-0:1.0: hub_activate type 4
hub 3-0:1.0: Submitting status URB
hub 3-0:1.0: Submitting status URB
------------[ cut here ]------------
URB 00000000a8d7a6c6 submitted while active
WARNING: CPU: 0 PID: 3405 at drivers/usb/core/urb.c:363  
usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Kernel panic - not syncing: panic_on_warn set ...
CPU: 0 PID: 3405 Comm: kworker/0:2 Not tainted 4.20.0-rc1+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: events_power_efficient hub_init_func2
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x253/0x3bb lib/dump_stack.c:113
  panic+0x2cb/0x586 kernel/panic.c:188
  __warn.cold+0x20/0x4e kernel/panic.c:540
  report_bug+0x263/0x2b0 lib/bug.c:186
  fixup_bug arch/x86/kernel/traps.c:178 [inline]
  fixup_bug arch/x86/kernel/traps.c:173 [inline]
  do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:271
  do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:290
  invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:969
RIP: 0010:usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Code: 89 de e8 93 22 7d fc 84 db 0f 85 fe f5 ff ff e8 46 21 7d fc 4c 89 fe  
48 c7 c7 80 48 93 88 c6 05 13 1c 10 05 01 e8 20 96 46 fc <0f> 0b e9 dc f5  
ff ff c7 45 c8 01 00 00 00 e9 94 f6 ff ff 41 be ed
RSP: 0018:ffff8881c64ef828 EFLAGS: 00010282
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff81656e66 RDI: 0000000000000005
RBP: ffff8881c64ef888 R08: ffff8881c6532340 R09: ffffed103b5c5021
R10: ffffed103b5c5020 R11: ffff8881dae28107 R12: ffff8881c64ef9a0
R13: ffff8881c3c26050 R14: 00000000fffffff0 R15: ffff8881c0b0ca00
  hub_activate+0xce0/0x1980 drivers/usb/core/hub.c:1218
  hub_init_func2+0x1e/0x30 drivers/usb/core/hub.c:1243
  process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
  worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Kernel Offset: disabled
Rebooting in 86400 seconds..


Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=15d0b5bf200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=1244a26b200000

Re: WARNING in usb_submit_urb (4)

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
WARNING in usb_submit_urb

hub 3-0:1.0: hub_activate type 4
hub 3-0:1.0: Submitting status URB
hub 3-0:1.0: Submitting status URB
------------[ cut here ]------------
URB 00000000a8d7a6c6 submitted while active
WARNING: CPU: 0 PID: 3405 at drivers/usb/core/urb.c:363  
usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Kernel panic - not syncing: panic_on_warn set ...
CPU: 0 PID: 3405 Comm: kworker/0:2 Not tainted 4.20.0-rc1+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: events_power_efficient hub_init_func2
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x253/0x3bb lib/dump_stack.c:113
  panic+0x2cb/0x586 kernel/panic.c:188
  __warn.cold+0x20/0x4e kernel/panic.c:540
  report_bug+0x263/0x2b0 lib/bug.c:186
  fixup_bug arch/x86/kernel/traps.c:178 [inline]
  fixup_bug arch/x86/kernel/traps.c:173 [inline]
  do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:271
  do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:290
  invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:969
RIP: 0010:usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Code: 89 de e8 93 22 7d fc 84 db 0f 85 fe f5 ff ff e8 46 21 7d fc 4c 89 fe  
48 c7 c7 80 48 93 88 c6 05 13 1c 10 05 01 e8 20 96 46 fc <0f> 0b e9 dc f5  
ff ff c7 45 c8 01 00 00 00 e9 94 f6 ff ff 41 be ed
RSP: 0018:ffff8881c64ef828 EFLAGS: 00010282
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff81656e66 RDI: 0000000000000005
RBP: ffff8881c64ef888 R08: ffff8881c6532340 R09: ffffed103b5c5021
R10: ffffed103b5c5020 R11: ffff8881dae28107 R12: ffff8881c64ef9a0
R13: ffff8881c3c26050 R14: 00000000fffffff0 R15: ffff8881c0b0ca00
  hub_activate+0xce0/0x1980 drivers/usb/core/hub.c:1218
  hub_init_func2+0x1e/0x30 drivers/usb/core/hub.c:1243
  process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
  worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Kernel Offset: disabled
Rebooting in 86400 seconds..


Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=15d0b5bf200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=1244a26b200000

WARNING in usb_submit_urb (4)

[Alan Stern]

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: hub_activate type 4
> hub 3-0:1.0: Submitting status URB
> hub 3-0:1.0: Submitting status URB
> ------------[ cut here ]------------
> URB 00000000a8d7a6c6 submitted while active

The console output shows pretty clearly that there is a race.  But I 
can't quite see how it is caused.  Let's try a little bit more 
debugging.

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,7 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%p %s\n", hub, __func__);
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3762,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);
 
 	/*

Re: WARNING in usb_submit_urb (4)

[Alan Stern]

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: hub_activate type 4
> hub 3-0:1.0: Submitting status URB
> hub 3-0:1.0: Submitting status URB
> ------------[ cut here ]------------
> URB 00000000a8d7a6c6 submitted while active

The console output shows pretty clearly that there is a race.  But I 
can't quite see how it is caused.  Let's try a little bit more 
debugging.

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,7 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%p %s\n", hub, __func__);
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3762,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);
 
 	/*

WARNING in usb_submit_urb (4)

[syzbot]

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  
usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Kernel panic - not syncing: panic_on_warn set ...
CPU: 0 PID: 6476 Comm: kworker/0:3 Not tainted 4.20.0-rc1+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: events_power_efficient hub_init_func2
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x253/0x3bb lib/dump_stack.c:113
  panic+0x2cb/0x586 kernel/panic.c:188
  __warn.cold+0x20/0x4e kernel/panic.c:540
  report_bug+0x263/0x2b0 lib/bug.c:186
  fixup_bug arch/x86/kernel/traps.c:178 [inline]
  fixup_bug arch/x86/kernel/traps.c:173 [inline]
  do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:271
  do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:290
  invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:969
RIP: 0010:usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Code: 89 de e8 d3 21 7d fc 84 db 0f 85 fe f5 ff ff e8 86 20 7d fc 4c 89 fe  
48 c7 c7 00 49 93 88 c6 05 d3 1b 10 05 01 e8 60 95 46 fc <0f> 0b e9 dc f5  
ff ff c7 45 c8 01 00 00 00 e9 94 f6 ff ff 41 be ed
RSP: 0018:ffff8881c397f820 EFLAGS: 00010286
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff81656e66 RDI: 0000000000000005
RBP: ffff8881c397f880 R08: ffff8881b82185c0 R09: ffff8881b8218e88
R10: ffff8881b82185c0 R11: 0000000000000000 R12: ffff8881c397f9a0
R13: ffff8881cdf73b10 R14: 00000000fffffff0 R15: ffff8881d507d700
  hub_activate+0xcef/0x19f0 drivers/usb/core/hub.c:1219
  hub_init_func2+0x1e/0x30 drivers/usb/core/hub.c:1244
  process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
  worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Kernel Offset: disabled
Rebooting in 86400 seconds..


Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=166b19b7200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=144ac55b200000

Re: WARNING in usb_submit_urb (4)

[syzbot]

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  
usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Kernel panic - not syncing: panic_on_warn set ...
CPU: 0 PID: 6476 Comm: kworker/0:3 Not tainted 4.20.0-rc1+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: events_power_efficient hub_init_func2
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x253/0x3bb lib/dump_stack.c:113
  panic+0x2cb/0x586 kernel/panic.c:188
  __warn.cold+0x20/0x4e kernel/panic.c:540
  report_bug+0x263/0x2b0 lib/bug.c:186
  fixup_bug arch/x86/kernel/traps.c:178 [inline]
  fixup_bug arch/x86/kernel/traps.c:173 [inline]
  do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:271
  do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:290
  invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:969
RIP: 0010:usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Code: 89 de e8 d3 21 7d fc 84 db 0f 85 fe f5 ff ff e8 86 20 7d fc 4c 89 fe  
48 c7 c7 00 49 93 88 c6 05 d3 1b 10 05 01 e8 60 95 46 fc <0f> 0b e9 dc f5  
ff ff c7 45 c8 01 00 00 00 e9 94 f6 ff ff 41 be ed
RSP: 0018:ffff8881c397f820 EFLAGS: 00010286
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff81656e66 RDI: 0000000000000005
RBP: ffff8881c397f880 R08: ffff8881b82185c0 R09: ffff8881b8218e88
R10: ffff8881b82185c0 R11: 0000000000000000 R12: ffff8881c397f9a0
R13: ffff8881cdf73b10 R14: 00000000fffffff0 R15: ffff8881d507d700
  hub_activate+0xcef/0x19f0 drivers/usb/core/hub.c:1219
  hub_init_func2+0x1e/0x30 drivers/usb/core/hub.c:1244
  process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
  worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Kernel Offset: disabled
Rebooting in 86400 seconds..


Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=166b19b7200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=144ac55b200000

WARNING in usb_submit_urb (4)

[Alan Stern]

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);
 
 	/*

Re: WARNING in usb_submit_urb (4)

[Alan Stern]

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);
 
 	/*

WARNING in usb_submit_urb (4)

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
WARNING in usb_submit_urb

hub 3-0:1.0: 0000000090da6a2e hub_activate type 4 discon 0
hub 3-0:1.0: 0000000090da6a2e Submitting status URB
hub 3-0:1.0: 0000000090da6a2e Submitting status URB
------------[ cut here ]------------
URB 000000000612b84f submitted while active
WARNING: CPU: 1 PID: 3403 at drivers/usb/core/urb.c:363  
usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Kernel panic - not syncing: panic_on_warn set ...
CPU: 1 PID: 3403 Comm: kworker/1:2 Not tainted 4.20.0-rc1+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: events_power_efficient hub_init_func2
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x253/0x3bb lib/dump_stack.c:113
  panic+0x2cb/0x586 kernel/panic.c:188
  __warn.cold+0x20/0x4e kernel/panic.c:540
  report_bug+0x263/0x2b0 lib/bug.c:186
  fixup_bug arch/x86/kernel/traps.c:178 [inline]
  fixup_bug arch/x86/kernel/traps.c:173 [inline]
  do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:271
  do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:290
  invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:969
RIP: 0010:usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Code: 89 de e8 73 20 7d fc 84 db 0f 85 fe f5 ff ff e8 26 1f 7d fc 4c 89 fe  
48 c7 c7 60 49 93 88 c6 05 b3 1a 10 05 01 e8 00 94 46 fc <0f> 0b e9 dc f5  
ff ff c7 45 c8 01 00 00 00 e9 94 f6 ff ff 41 be ed
RSP: 0018:ffff8881c64d7820 EFLAGS: 00010286
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff81656e66 RDI: 0000000000000005
RBP: ffff8881c64d7880 R08: ffff8881c64fe2c0 R09: ffff8881c64feb88
R10: ffff8881c64fe2c0 R11: 0000000000000000 R12: ffff8881c64d79a0
R13: ffff8881ba64f690 R14: 00000000fffffff0 R15: ffff8881cc9bd200
  hub_activate+0xcef/0x19f0 drivers/usb/core/hub.c:1219
  hub_init_func2+0x1e/0x30 drivers/usb/core/hub.c:1244
  process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
  worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Kernel Offset: disabled
Rebooting in 86400 seconds..


Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=154bbb87200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=1721f267200000

Re: WARNING in usb_submit_urb (4)

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
WARNING in usb_submit_urb

hub 3-0:1.0: 0000000090da6a2e hub_activate type 4 discon 0
hub 3-0:1.0: 0000000090da6a2e Submitting status URB
hub 3-0:1.0: 0000000090da6a2e Submitting status URB
------------[ cut here ]------------
URB 000000000612b84f submitted while active
WARNING: CPU: 1 PID: 3403 at drivers/usb/core/urb.c:363  
usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Kernel panic - not syncing: panic_on_warn set ...
CPU: 1 PID: 3403 Comm: kworker/1:2 Not tainted 4.20.0-rc1+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: events_power_efficient hub_init_func2
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x253/0x3bb lib/dump_stack.c:113
  panic+0x2cb/0x586 kernel/panic.c:188
  __warn.cold+0x20/0x4e kernel/panic.c:540
  report_bug+0x263/0x2b0 lib/bug.c:186
  fixup_bug arch/x86/kernel/traps.c:178 [inline]
  fixup_bug arch/x86/kernel/traps.c:173 [inline]
  do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:271
  do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:290
  invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:969
RIP: 0010:usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Code: 89 de e8 73 20 7d fc 84 db 0f 85 fe f5 ff ff e8 26 1f 7d fc 4c 89 fe  
48 c7 c7 60 49 93 88 c6 05 b3 1a 10 05 01 e8 00 94 46 fc <0f> 0b e9 dc f5  
ff ff c7 45 c8 01 00 00 00 e9 94 f6 ff ff 41 be ed
RSP: 0018:ffff8881c64d7820 EFLAGS: 00010286
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff81656e66 RDI: 0000000000000005
RBP: ffff8881c64d7880 R08: ffff8881c64fe2c0 R09: ffff8881c64feb88
R10: ffff8881c64fe2c0 R11: 0000000000000000 R12: ffff8881c64d79a0
R13: ffff8881ba64f690 R14: 00000000fffffff0 R15: ffff8881cc9bd200
  hub_activate+0xcef/0x19f0 drivers/usb/core/hub.c:1219
  hub_init_func2+0x1e/0x30 drivers/usb/core/hub.c:1244
  process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
  worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Kernel Offset: disabled
Rebooting in 86400 seconds..


Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=154bbb87200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=1721f267200000

WARNING in usb_submit_urb (4)

[Alan Stern]

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: 0000000090da6a2e hub_activate type 4 discon 0
> hub 3-0:1.0: 0000000090da6a2e Submitting status URB
> hub 3-0:1.0: 0000000090da6a2e Submitting status URB
> ------------[ cut here ]------------
> URB 000000000612b84f submitted while active
> WARNING: CPU: 1 PID: 3403 at drivers/usb/core/urb.c:363  
> usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363

I'm still having trouble understanding this.  Here's some more 
debugging.

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);
@@ -1299,6 +1302,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 +3716,9 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%p %s usage %d\n",
+			hub, __func__,
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3763,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);
 
 	/*
Index: usb-devel/drivers/usb/core/driver.c
===================================================================
--- usb-devel.orig/drivers/usb/core/driver.c
+++ usb-devel/drivers/usb/core/driver.c
@@ -358,7 +358,11 @@ static int usb_probe_interface(struct de
 		intf->needs_altsetting0 = 0;
 	}
 
+	dev_info(dev, "pre-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	error = driver->probe(intf, id);
+	dev_info(dev, "post-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	if (error)
 		goto err;
 
@@ -420,7 +424,11 @@ static int usb_unbind_interface(struct d
 	if (!driver->soft_unbind || udev->state == USB_STATE_NOTATTACHED)
 		usb_disable_interface(udev, intf, false);
 
+	dev_info(dev, "pre-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	driver->disconnect(intf);
+	dev_info(dev, "post-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* Free streams */
 	for (i = 0, j = 0; i < intf->cur_altsetting->desc.bNumEndpoints; i++) {

Re: WARNING in usb_submit_urb (4)

[Alan Stern]

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: 0000000090da6a2e hub_activate type 4 discon 0
> hub 3-0:1.0: 0000000090da6a2e Submitting status URB
> hub 3-0:1.0: 0000000090da6a2e Submitting status URB
> ------------[ cut here ]------------
> URB 000000000612b84f submitted while active
> WARNING: CPU: 1 PID: 3403 at drivers/usb/core/urb.c:363  
> usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363

I'm still having trouble understanding this.  Here's some more 
debugging.

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);
@@ -1299,6 +1302,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 +3716,9 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%p %s usage %d\n",
+			hub, __func__,
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3763,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);
 
 	/*
Index: usb-devel/drivers/usb/core/driver.c
===================================================================
--- usb-devel.orig/drivers/usb/core/driver.c
+++ usb-devel/drivers/usb/core/driver.c
@@ -358,7 +358,11 @@ static int usb_probe_interface(struct de
 		intf->needs_altsetting0 = 0;
 	}
 
+	dev_info(dev, "pre-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	error = driver->probe(intf, id);
+	dev_info(dev, "post-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	if (error)
 		goto err;
 
@@ -420,7 +424,11 @@ static int usb_unbind_interface(struct d
 	if (!driver->soft_unbind || udev->state == USB_STATE_NOTATTACHED)
 		usb_disable_interface(udev, intf, false);
 
+	dev_info(dev, "pre-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	driver->disconnect(intf);
+	dev_info(dev, "post-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* Free streams */
 	for (i = 0, j = 0; i < intf->cur_altsetting->desc.bNumEndpoints; i++) {

WARNING in usb_submit_urb (4)

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
WARNING in usb_submit_urb

hub 3-0:1.0: 00000000e9b0f156 hub_resume
hub 3-0:1.0: 00000000e9b0f156 hub_activate type 4 discon 0
hub 3-0:1.0: 00000000e9b0f156 hub_activate type 1 discon 0
------------[ cut here ]------------
URB 0000000098fd290c submitted while active
WARNING: CPU: 0 PID: 12 at drivers/usb/core/urb.c:363  
usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Kernel panic - not syncing: panic_on_warn set ...
CPU: 0 PID: 12 Comm: kworker/0:1 Not tainted 4.20.0-rc1+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: events_power_efficient hub_init_func2
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x253/0x3bb lib/dump_stack.c:113
  panic+0x2cb/0x586 kernel/panic.c:188
  __warn.cold+0x20/0x4e kernel/panic.c:540
  report_bug+0x263/0x2b0 lib/bug.c:186
  fixup_bug arch/x86/kernel/traps.c:178 [inline]
  fixup_bug arch/x86/kernel/traps.c:173 [inline]
  do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:271
  do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:290
  invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:969
RIP: 0010:usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Code: 89 de e8 43 21 7d fc 84 db 0f 85 fe f5 ff ff e8 f6 1f 7d fc 4c 89 fe  
48 c7 c7 00 49 93 88 c6 05 43 1b 10 05 01 e8 d0 94 46 fc <0f> 0b e9 dc f5  
ff ff c7 45 c8 01 00 00 00 e9 94 f6 ff ff 41 be ed
RSP: 0018:ffff8881d9b1f820 EFLAGS: 00010286
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff81656e66 RDI: 0000000000000005
RBP: ffff8881d9b1f880 R08: ffff8881d9b12300 R09: ffffed103b5c3ef9
R10: ffffed103b5c3ef8 R11: ffff8881dae1f7c7 R12: ffff8881d9b1f9a0
R13: ffff8881c49b9210 R14: 00000000fffffff0 R15: ffff8881c990dd00
  hub_activate+0xcc2/0x19c0 drivers/usb/core/hub.c:1218
  hub_init_func2+0x1e/0x30 drivers/usb/core/hub.c:1243
  process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
  worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Kernel Offset: disabled
Rebooting in 86400 seconds..


Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=16cacd2d200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=17b94d8f200000

Re: WARNING in usb_submit_urb (4)

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
WARNING in usb_submit_urb

hub 3-0:1.0: 00000000e9b0f156 hub_resume
hub 3-0:1.0: 00000000e9b0f156 hub_activate type 4 discon 0
hub 3-0:1.0: 00000000e9b0f156 hub_activate type 1 discon 0
------------[ cut here ]------------
URB 0000000098fd290c submitted while active
WARNING: CPU: 0 PID: 12 at drivers/usb/core/urb.c:363  
usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Kernel panic - not syncing: panic_on_warn set ...
CPU: 0 PID: 12 Comm: kworker/0:1 Not tainted 4.20.0-rc1+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: events_power_efficient hub_init_func2
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x253/0x3bb lib/dump_stack.c:113
  panic+0x2cb/0x586 kernel/panic.c:188
  __warn.cold+0x20/0x4e kernel/panic.c:540
  report_bug+0x263/0x2b0 lib/bug.c:186
  fixup_bug arch/x86/kernel/traps.c:178 [inline]
  fixup_bug arch/x86/kernel/traps.c:173 [inline]
  do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:271
  do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:290
  invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:969
RIP: 0010:usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Code: 89 de e8 43 21 7d fc 84 db 0f 85 fe f5 ff ff e8 f6 1f 7d fc 4c 89 fe  
48 c7 c7 00 49 93 88 c6 05 43 1b 10 05 01 e8 d0 94 46 fc <0f> 0b e9 dc f5  
ff ff c7 45 c8 01 00 00 00 e9 94 f6 ff ff 41 be ed
RSP: 0018:ffff8881d9b1f820 EFLAGS: 00010286
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff81656e66 RDI: 0000000000000005
RBP: ffff8881d9b1f880 R08: ffff8881d9b12300 R09: ffffed103b5c3ef9
R10: ffffed103b5c3ef8 R11: ffff8881dae1f7c7 R12: ffff8881d9b1f9a0
R13: ffff8881c49b9210 R14: 00000000fffffff0 R15: ffff8881c990dd00
  hub_activate+0xcc2/0x19c0 drivers/usb/core/hub.c:1218
  hub_init_func2+0x1e/0x30 drivers/usb/core/hub.c:1243
  process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
  worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Kernel Offset: disabled
Rebooting in 86400 seconds..


Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=16cacd2d200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=17b94d8f200000

WARNING in usb_submit_urb (4)

[Alan Stern]

On Wed, 17 Apr 2019, Alan Stern wrote:

> I'm still having trouble understanding this.  Here's some more 
> debugging.

Let's try this again.  The patch format was wrong.

Alan Stern

--- 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);
@@ -1299,6 +1302,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 +3716,9 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%p %s usage %d\n",
+			hub, __func__,
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3763,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);
 
 	/*
--- a/drivers/usb/core/driver.c
+++ b/drivers/usb/core/driver.c
@@ -358,7 +358,11 @@ static int usb_probe_interface(struct de
 		intf->needs_altsetting0 = 0;
 	}
 
+	dev_info(dev, "pre-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	error = driver->probe(intf, id);
+	dev_info(dev, "post-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	if (error)
 		goto err;
 
@@ -420,7 +424,11 @@ static int usb_unbind_interface(struct d
 	if (!driver->soft_unbind || udev->state == USB_STATE_NOTATTACHED)
 		usb_disable_interface(udev, intf, false);
 
+	dev_info(dev, "pre-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	driver->disconnect(intf);
+	dev_info(dev, "post-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* Free streams */
 	for (i = 0, j = 0; i < intf->cur_altsetting->desc.bNumEndpoints; i++) {

Re: WARNING in usb_submit_urb (4)

[Alan Stern]

On Wed, 17 Apr 2019, Alan Stern wrote:

> I'm still having trouble understanding this.  Here's some more 
> debugging.

Let's try this again.  The patch format was wrong.

Alan Stern

--- 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);
@@ -1299,6 +1302,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 +3716,9 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%p %s usage %d\n",
+			hub, __func__,
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3763,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);
 
 	/*
--- a/drivers/usb/core/driver.c
+++ b/drivers/usb/core/driver.c
@@ -358,7 +358,11 @@ static int usb_probe_interface(struct de
 		intf->needs_altsetting0 = 0;
 	}
 
+	dev_info(dev, "pre-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	error = driver->probe(intf, id);
+	dev_info(dev, "post-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	if (error)
 		goto err;
 
@@ -420,7 +424,11 @@ static int usb_unbind_interface(struct d
 	if (!driver->soft_unbind || udev->state == USB_STATE_NOTATTACHED)
 		usb_disable_interface(udev, intf, false);
 
+	dev_info(dev, "pre-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	driver->disconnect(intf);
+	dev_info(dev, "post-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* Free streams */
 	for (i = 0, j = 0; i < intf->cur_altsetting->desc.bNumEndpoints; i++) {

WARNING in usb_submit_urb (4)

[Alan Stern]

On Thu, 18 Apr 2019, Alan Stern wrote:

> On Wed, 17 Apr 2019, Alan Stern wrote:
> 
> > I'm still having trouble understanding this.  Here's some more 
> > debugging.
> 
> Let's try this again.  The patch format was wrong.

One more try, this time with the syz command line.

Incidentally, the console log from the last test had a very troubling
entry showing the runtime PM usage counter for the hub interface was
set to -4!  Whatever caused the counter to go negative is probably also
the reason for this bug.

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);
@@ -1299,6 +1302,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 +3716,9 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%p %s usage %d\n",
+			hub, __func__,
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3763,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);
 
 	/*
--- a/drivers/usb/core/driver.c
+++ b/drivers/usb/core/driver.c
@@ -358,7 +358,11 @@ static int usb_probe_interface(struct de
 		intf->needs_altsetting0 = 0;
 	}
 
+	dev_info(dev, "pre-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	error = driver->probe(intf, id);
+	dev_info(dev, "post-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	if (error)
 		goto err;
 
@@ -420,7 +424,11 @@ static int usb_unbind_interface(struct d
 	if (!driver->soft_unbind || udev->state == USB_STATE_NOTATTACHED)
 		usb_disable_interface(udev, intf, false);
 
+	dev_info(dev, "pre-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	driver->disconnect(intf);
+	dev_info(dev, "post-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* Free streams */
 	for (i = 0, j = 0; i < intf->cur_altsetting->desc.bNumEndpoints; i++) {

Re: WARNING in usb_submit_urb (4)

[Alan Stern]

On Thu, 18 Apr 2019, Alan Stern wrote:

> On Wed, 17 Apr 2019, Alan Stern wrote:
> 
> > I'm still having trouble understanding this.  Here's some more 
> > debugging.
> 
> Let's try this again.  The patch format was wrong.

One more try, this time with the syz command line.

Incidentally, the console log from the last test had a very troubling
entry showing the runtime PM usage counter for the hub interface was
set to -4!  Whatever caused the counter to go negative is probably also
the reason for this bug.

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);
@@ -1299,6 +1302,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 +3716,9 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%p %s usage %d\n",
+			hub, __func__,
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3763,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);
 
 	/*
--- a/drivers/usb/core/driver.c
+++ b/drivers/usb/core/driver.c
@@ -358,7 +358,11 @@ static int usb_probe_interface(struct de
 		intf->needs_altsetting0 = 0;
 	}
 
+	dev_info(dev, "pre-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	error = driver->probe(intf, id);
+	dev_info(dev, "post-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	if (error)
 		goto err;
 
@@ -420,7 +424,11 @@ static int usb_unbind_interface(struct d
 	if (!driver->soft_unbind || udev->state == USB_STATE_NOTATTACHED)
 		usb_disable_interface(udev, intf, false);
 
+	dev_info(dev, "pre-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	driver->disconnect(intf);
+	dev_info(dev, "post-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* Free streams */
 	for (i = 0, j = 0; i < intf->cur_altsetting->desc.bNumEndpoints; i++) {

WARNING in usb_submit_urb (4)

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
WARNING in usb_submit_urb

hub 3-0:1.0: 00000000b89ba4aa hub_resume
hub 3-0:1.0: 00000000b89ba4aa hub_activate type 1 discon 0
hub 3-0:1.0: 00000000b89ba4aa hub_activate type 4 discon 0
------------[ cut here ]------------
URB 0000000031fb463e submitted while active
WARNING: CPU: 0 PID: 2917 at drivers/usb/core/urb.c:363  
usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Kernel panic - not syncing: panic_on_warn set ...
CPU: 0 PID: 2917 Comm: kworker/0:2 Not tainted 4.20.0-rc1+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: events_power_efficient hub_init_func2
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x253/0x3bb lib/dump_stack.c:113
  panic+0x2cb/0x586 kernel/panic.c:188
  __warn.cold+0x20/0x4e kernel/panic.c:540
  report_bug+0x263/0x2b0 lib/bug.c:186
  fixup_bug arch/x86/kernel/traps.c:178 [inline]
  fixup_bug arch/x86/kernel/traps.c:173 [inline]
  do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:271
  do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:290
  invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:969
RIP: 0010:usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Code: 89 de e8 43 21 7d fc 84 db 0f 85 fe f5 ff ff e8 f6 1f 7d fc 4c 89 fe  
48 c7 c7 00 49 93 88 c6 05 43 1c 10 05 01 e8 d0 94 46 fc <0f> 0b e9 dc f5  
ff ff c7 45 c8 01 00 00 00 e9 94 f6 ff ff 41 be ed
RSP: 0018:ffff8881cb9cf820 EFLAGS: 00010286
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff81656e66 RDI: 0000000000000005
RBP: ffff8881cb9cf880 R08: ffff8881cb9c2480 R09: ffffed103b5c5021
R10: ffffed103b5c5020 R11: ffff8881dae28107 R12: ffff8881cb9cf9a0
R13: ffff8881c43d9250 R14: 00000000fffffff0 R15: ffff8881d7718300
  hub_activate+0xcc2/0x19c0 drivers/usb/core/hub.c:1218
  hub_init_func2+0x1e/0x30 drivers/usb/core/hub.c:1243
  process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
  worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Kernel Offset: disabled
Rebooting in 86400 seconds..


Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=16a7f38f200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=112bbbbf200000

Re: WARNING in usb_submit_urb (4)

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered  
crash:
WARNING in usb_submit_urb

hub 3-0:1.0: 00000000b89ba4aa hub_resume
hub 3-0:1.0: 00000000b89ba4aa hub_activate type 1 discon 0
hub 3-0:1.0: 00000000b89ba4aa hub_activate type 4 discon 0
------------[ cut here ]------------
URB 0000000031fb463e submitted while active
WARNING: CPU: 0 PID: 2917 at drivers/usb/core/urb.c:363  
usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Kernel panic - not syncing: panic_on_warn set ...
CPU: 0 PID: 2917 Comm: kworker/0:2 Not tainted 4.20.0-rc1+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Workqueue: events_power_efficient hub_init_func2
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x253/0x3bb lib/dump_stack.c:113
  panic+0x2cb/0x586 kernel/panic.c:188
  __warn.cold+0x20/0x4e kernel/panic.c:540
  report_bug+0x263/0x2b0 lib/bug.c:186
  fixup_bug arch/x86/kernel/traps.c:178 [inline]
  fixup_bug arch/x86/kernel/traps.c:173 [inline]
  do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:271
  do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:290
  invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:969
RIP: 0010:usb_submit_urb+0x1110/0x1400 drivers/usb/core/urb.c:363
Code: 89 de e8 43 21 7d fc 84 db 0f 85 fe f5 ff ff e8 f6 1f 7d fc 4c 89 fe  
48 c7 c7 00 49 93 88 c6 05 43 1c 10 05 01 e8 d0 94 46 fc <0f> 0b e9 dc f5  
ff ff c7 45 c8 01 00 00 00 e9 94 f6 ff ff 41 be ed
RSP: 0018:ffff8881cb9cf820 EFLAGS: 00010286
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff81656e66 RDI: 0000000000000005
RBP: ffff8881cb9cf880 R08: ffff8881cb9c2480 R09: ffffed103b5c5021
R10: ffffed103b5c5020 R11: ffff8881dae28107 R12: ffff8881cb9cf9a0
R13: ffff8881c43d9250 R14: 00000000fffffff0 R15: ffff8881d7718300
  hub_activate+0xcc2/0x19c0 drivers/usb/core/hub.c:1218
  hub_init_func2+0x1e/0x30 drivers/usb/core/hub.c:1243
  process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
  worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Kernel Offset: disabled
Rebooting in 86400 seconds..


Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=16a7f38f200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=112bbbbf200000

WARNING in usb_submit_urb (4)

[Alan Stern]

On Thu, 18 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: 00000000b89ba4aa hub_resume
> hub 3-0:1.0: 00000000b89ba4aa hub_activate type 1 discon 0
> hub 3-0:1.0: 00000000b89ba4aa hub_activate type 4 discon 0

Oh, now I see the problem.  And it was my fault to begin with...
Let's see if this fixes it.

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);
@@ -1299,6 +1302,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 +3716,9 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%p %s usage %d\n",
+			hub, __func__,
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3763,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);
 
 	/*
--- a/drivers/usb/core/driver.c
+++ b/drivers/usb/core/driver.c
@@ -358,7 +358,11 @@ static int usb_probe_interface(struct de
 		intf->needs_altsetting0 = 0;
 	}
 
+	dev_info(dev, "pre-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	error = driver->probe(intf, id);
+	dev_info(dev, "post-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	if (error)
 		goto err;
 
@@ -420,7 +424,11 @@ static int usb_unbind_interface(struct d
 	if (!driver->soft_unbind || udev->state == USB_STATE_NOTATTACHED)
 		usb_disable_interface(udev, intf, false);
 
+	dev_info(dev, "pre-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	driver->disconnect(intf);
+	dev_info(dev, "post-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* Free streams */
 	for (i = 0, j = 0; i < intf->cur_altsetting->desc.bNumEndpoints; i++) {
@@ -473,11 +481,6 @@ static int usb_unbind_interface(struct d
 		pm_runtime_disable(dev);
 	pm_runtime_set_suspended(dev);
 
-	/* Undo any residual pm_autopm_get_interface_* calls */
-	for (r = atomic_read(&intf->pm_usage_cnt); r > 0; --r)
-		usb_autopm_put_interface_no_suspend(intf);
-	atomic_set(&intf->pm_usage_cnt, 0);
-
 	if (!error)
 		usb_autosuspend_device(udev);
 

Re: WARNING in usb_submit_urb (4)

[Alan Stern]

On Thu, 18 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: 00000000b89ba4aa hub_resume
> hub 3-0:1.0: 00000000b89ba4aa hub_activate type 1 discon 0
> hub 3-0:1.0: 00000000b89ba4aa hub_activate type 4 discon 0

Oh, now I see the problem.  And it was my fault to begin with...
Let's see if this fixes it.

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);
@@ -1299,6 +1302,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 +3716,9 @@ static int hub_suspend(struct usb_interf
 		}
 	}
 
-	dev_dbg(&intf->dev, "%s\n", __func__);
+	dev_info(&intf->dev, "%p %s usage %d\n",
+			hub, __func__,
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* stop hub_wq and related activity */
 	hub_quiesce(hub, HUB_SUSPEND);
@@ -3756,7 +3763,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);
 
 	/*
--- a/drivers/usb/core/driver.c
+++ b/drivers/usb/core/driver.c
@@ -358,7 +358,11 @@ static int usb_probe_interface(struct de
 		intf->needs_altsetting0 = 0;
 	}
 
+	dev_info(dev, "pre-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	error = driver->probe(intf, id);
+	dev_info(dev, "post-probe usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	if (error)
 		goto err;
 
@@ -420,7 +424,11 @@ static int usb_unbind_interface(struct d
 	if (!driver->soft_unbind || udev->state == USB_STATE_NOTATTACHED)
 		usb_disable_interface(udev, intf, false);
 
+	dev_info(dev, "pre-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 	driver->disconnect(intf);
+	dev_info(dev, "post-discon usage %d\n",
+			atomic_read(&intf->dev.power.usage_count));
 
 	/* Free streams */
 	for (i = 0, j = 0; i < intf->cur_altsetting->desc.bNumEndpoints; i++) {
@@ -473,11 +481,6 @@ static int usb_unbind_interface(struct d
 		pm_runtime_disable(dev);
 	pm_runtime_set_suspended(dev);
 
-	/* Undo any residual pm_autopm_get_interface_* calls */
-	for (r = atomic_read(&intf->pm_usage_cnt); r > 0; --r)
-		usb_autopm_put_interface_no_suspend(intf);
-	atomic_set(&intf->pm_usage_cnt, 0);
-
 	if (!error)
 		usb_autosuspend_device(udev);
 

WARNING in usb_submit_urb (4)

[syzbot]

Hello,

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

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

Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=17a7eaa0a00000

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

Re: WARNING in usb_submit_urb (4)

[syzbot]

Hello,

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

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

Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=17a7eaa0a00000

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

WARNING in usb_submit_urb (4)

[Alan Stern]

On Thu, 18 Apr 2019, syzbot wrote:

> Hello,
> 
> syzbot has tested the proposed patch and the reproducer did not trigger  
> crash:
> 
> Reported-and-tested-by:  
> syzbot+7634edaea4d0b341c625@syzkaller.appspotmail.com
> 
> Tested on:
> 
> commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
> git tree:        
> git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
> kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
> compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> patch:          https://syzkaller.appspot.com/x/patch.diff?x=17a7eaa0a00000
> 
> Note: testing is done by a robot and is best-effort only.

Great!  Okay, let's try one more time, with the patch I will actually 
submit.

Alan Stern


#syz test: git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git e12e00e388de

--- a/include/linux/usb.h
+++ b/include/linux/usb.h
@@ -200,7 +200,6 @@ usb_find_last_int_out_endpoint(struct us
  * @dev: driver model's view of this device
  * @usb_dev: if an interface is bound to the USB major, this will point
  *	to the sysfs representation for that device.
- * @pm_usage_cnt: PM usage counter for this interface
  * @reset_ws: Used for scheduling resets from atomic context.
  * @resetting_device: USB core reset the device, so use alt setting 0 as
  *	current; needs bandwidth alloc after reset.
@@ -257,7 +256,6 @@ struct usb_interface {
 
 	struct device dev;		/* interface specific device info */
 	struct device *usb_dev;
-	atomic_t pm_usage_cnt;		/* usage counter for autosuspend */
 	struct work_struct reset_ws;	/* for resets in atomic context */
 };
 #define	to_usb_interface(d) container_of(d, struct usb_interface, dev)
--- a/drivers/usb/core/driver.c
+++ b/drivers/usb/core/driver.c
@@ -473,11 +473,6 @@ static int usb_unbind_interface(struct d
 		pm_runtime_disable(dev);
 	pm_runtime_set_suspended(dev);
 
-	/* Undo any residual pm_autopm_get_interface_* calls */
-	for (r = atomic_read(&intf->pm_usage_cnt); r > 0; --r)
-		usb_autopm_put_interface_no_suspend(intf);
-	atomic_set(&intf->pm_usage_cnt, 0);
-
 	if (!error)
 		usb_autosuspend_device(udev);
 
@@ -1633,7 +1628,6 @@ void usb_autopm_put_interface(struct usb
 	int			status;
 
 	usb_mark_last_busy(udev);
-	atomic_dec(&intf->pm_usage_cnt);
 	status = pm_runtime_put_sync(&intf->dev);
 	dev_vdbg(&intf->dev, "%s: cnt %d -> %d\n",
 			__func__, atomic_read(&intf->dev.power.usage_count),
@@ -1662,7 +1656,6 @@ void usb_autopm_put_interface_async(stru
 	int			status;
 
 	usb_mark_last_busy(udev);
-	atomic_dec(&intf->pm_usage_cnt);
 	status = pm_runtime_put(&intf->dev);
 	dev_vdbg(&intf->dev, "%s: cnt %d -> %d\n",
 			__func__, atomic_read(&intf->dev.power.usage_count),
@@ -1684,7 +1677,6 @@ void usb_autopm_put_interface_no_suspend
 	struct usb_device	*udev = interface_to_usbdev(intf);
 
 	usb_mark_last_busy(udev);
-	atomic_dec(&intf->pm_usage_cnt);
 	pm_runtime_put_noidle(&intf->dev);
 }
 EXPORT_SYMBOL_GPL(usb_autopm_put_interface_no_suspend);
@@ -1715,8 +1707,6 @@ int usb_autopm_get_interface(struct usb_
 	status = pm_runtime_get_sync(&intf->dev);
 	if (status < 0)
 		pm_runtime_put_sync(&intf->dev);
-	else
-		atomic_inc(&intf->pm_usage_cnt);
 	dev_vdbg(&intf->dev, "%s: cnt %d -> %d\n",
 			__func__, atomic_read(&intf->dev.power.usage_count),
 			status);
@@ -1750,8 +1740,6 @@ int usb_autopm_get_interface_async(struc
 	status = pm_runtime_get(&intf->dev);
 	if (status < 0 && status != -EINPROGRESS)
 		pm_runtime_put_noidle(&intf->dev);
-	else
-		atomic_inc(&intf->pm_usage_cnt);
 	dev_vdbg(&intf->dev, "%s: cnt %d -> %d\n",
 			__func__, atomic_read(&intf->dev.power.usage_count),
 			status);
@@ -1775,7 +1763,6 @@ void usb_autopm_get_interface_no_resume(
 	struct usb_device	*udev = interface_to_usbdev(intf);
 
 	usb_mark_last_busy(udev);
-	atomic_inc(&intf->pm_usage_cnt);
 	pm_runtime_get_noresume(&intf->dev);
 }
 EXPORT_SYMBOL_GPL(usb_autopm_get_interface_no_resume);
--- a/Documentation/driver-api/usb/power-management.rst
+++ b/Documentation/driver-api/usb/power-management.rst
@@ -370,11 +370,15 @@ autosuspend the interface's device.  Whe
 then the interface is considered to be idle, and the kernel may
 autosuspend the device.
 
-Drivers need not be concerned about balancing changes to the usage
-counter; the USB core will undo any remaining "get"s when a driver
-is unbound from its interface.  As a corollary, drivers must not call
-any of the ``usb_autopm_*`` functions after their ``disconnect``
-routine has returned.
+Drivers must be careful to balance their overall changes to the usage
+counter.  Unbalanced "get"s will remain in effect when a driver is
+unbound from its interface, preventing the device from going into
+runtime suspend should the interface be bound to a driver again.  On
+the other hand, drivers are allowed to achieve this balance by calling
+the ``usb_autopm_*`` functions even after their ``disconnect`` routine
+has returned -- say from within a work-queue routine -- provided they
+retain an active reference to the interface (via ``usb_get_intf`` and
+``usb_put_intf``).
 
 Drivers using the async routines are responsible for their own
 synchronization and mutual exclusion.
--- a/drivers/usb/storage/realtek_cr.c
+++ b/drivers/usb/storage/realtek_cr.c
@@ -763,18 +763,16 @@ static void rts51x_suspend_timer_fn(stru
 		break;
 	case RTS51X_STAT_IDLE:
 	case RTS51X_STAT_SS:
-		usb_stor_dbg(us, "RTS51X_STAT_SS, intf->pm_usage_cnt:%d, power.usage:%d\n",
-			     atomic_read(&us->pusb_intf->pm_usage_cnt),
+		usb_stor_dbg(us, "RTS51X_STAT_SS, power.usage:%d\n",
 			     atomic_read(&us->pusb_intf->dev.power.usage_count));
 
-		if (atomic_read(&us->pusb_intf->pm_usage_cnt) > 0) {
+		if (atomic_read(&us->pusb_intf->dev.power.usage_count) > 0) {
 			usb_stor_dbg(us, "Ready to enter SS state\n");
 			rts51x_set_stat(chip, RTS51X_STAT_SS);
 			/* ignore mass storage interface's children */
 			pm_suspend_ignore_children(&us->pusb_intf->dev, true);
 			usb_autopm_put_interface_async(us->pusb_intf);
-			usb_stor_dbg(us, "RTS51X_STAT_SS 01, intf->pm_usage_cnt:%d, power.usage:%d\n",
-				     atomic_read(&us->pusb_intf->pm_usage_cnt),
+			usb_stor_dbg(us, "RTS51X_STAT_SS 01, power.usage:%d\n",
 				     atomic_read(&us->pusb_intf->dev.power.usage_count));
 		}
 		break;
@@ -807,11 +805,10 @@ static void rts51x_invoke_transport(stru
 	int ret;
 
 	if (working_scsi(srb)) {
-		usb_stor_dbg(us, "working scsi, intf->pm_usage_cnt:%d, power.usage:%d\n",
-			     atomic_read(&us->pusb_intf->pm_usage_cnt),
+		usb_stor_dbg(us, "working scsi, power.usage:%d\n",
 			     atomic_read(&us->pusb_intf->dev.power.usage_count));
 
-		if (atomic_read(&us->pusb_intf->pm_usage_cnt) <= 0) {
+		if (atomic_read(&us->pusb_intf->dev.power.usage_count) <= 0) {
 			ret = usb_autopm_get_interface(us->pusb_intf);
 			usb_stor_dbg(us, "working scsi, ret=%d\n", ret);
 		}

Re: WARNING in usb_submit_urb (4)

[Alan Stern]

On Thu, 18 Apr 2019, syzbot wrote:

> Hello,
> 
> syzbot has tested the proposed patch and the reproducer did not trigger  
> crash:
> 
> Reported-and-tested-by:  
> syzbot+7634edaea4d0b341c625@syzkaller.appspotmail.com
> 
> Tested on:
> 
> commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
> git tree:        
> git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
> kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
> compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> patch:          https://syzkaller.appspot.com/x/patch.diff?x=17a7eaa0a00000
> 
> Note: testing is done by a robot and is best-effort only.

Great!  Okay, let's try one more time, with the patch I will actually 
submit.

Alan Stern


#syz test: git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git e12e00e388de

--- a/include/linux/usb.h
+++ b/include/linux/usb.h
@@ -200,7 +200,6 @@ usb_find_last_int_out_endpoint(struct us
  * @dev: driver model's view of this device
  * @usb_dev: if an interface is bound to the USB major, this will point
  *	to the sysfs representation for that device.
- * @pm_usage_cnt: PM usage counter for this interface
  * @reset_ws: Used for scheduling resets from atomic context.
  * @resetting_device: USB core reset the device, so use alt setting 0 as
  *	current; needs bandwidth alloc after reset.
@@ -257,7 +256,6 @@ struct usb_interface {
 
 	struct device dev;		/* interface specific device info */
 	struct device *usb_dev;
-	atomic_t pm_usage_cnt;		/* usage counter for autosuspend */
 	struct work_struct reset_ws;	/* for resets in atomic context */
 };
 #define	to_usb_interface(d) container_of(d, struct usb_interface, dev)
--- a/drivers/usb/core/driver.c
+++ b/drivers/usb/core/driver.c
@@ -473,11 +473,6 @@ static int usb_unbind_interface(struct d
 		pm_runtime_disable(dev);
 	pm_runtime_set_suspended(dev);
 
-	/* Undo any residual pm_autopm_get_interface_* calls */
-	for (r = atomic_read(&intf->pm_usage_cnt); r > 0; --r)
-		usb_autopm_put_interface_no_suspend(intf);
-	atomic_set(&intf->pm_usage_cnt, 0);
-
 	if (!error)
 		usb_autosuspend_device(udev);
 
@@ -1633,7 +1628,6 @@ void usb_autopm_put_interface(struct usb
 	int			status;
 
 	usb_mark_last_busy(udev);
-	atomic_dec(&intf->pm_usage_cnt);
 	status = pm_runtime_put_sync(&intf->dev);
 	dev_vdbg(&intf->dev, "%s: cnt %d -> %d\n",
 			__func__, atomic_read(&intf->dev.power.usage_count),
@@ -1662,7 +1656,6 @@ void usb_autopm_put_interface_async(stru
 	int			status;
 
 	usb_mark_last_busy(udev);
-	atomic_dec(&intf->pm_usage_cnt);
 	status = pm_runtime_put(&intf->dev);
 	dev_vdbg(&intf->dev, "%s: cnt %d -> %d\n",
 			__func__, atomic_read(&intf->dev.power.usage_count),
@@ -1684,7 +1677,6 @@ void usb_autopm_put_interface_no_suspend
 	struct usb_device	*udev = interface_to_usbdev(intf);
 
 	usb_mark_last_busy(udev);
-	atomic_dec(&intf->pm_usage_cnt);
 	pm_runtime_put_noidle(&intf->dev);
 }
 EXPORT_SYMBOL_GPL(usb_autopm_put_interface_no_suspend);
@@ -1715,8 +1707,6 @@ int usb_autopm_get_interface(struct usb_
 	status = pm_runtime_get_sync(&intf->dev);
 	if (status < 0)
 		pm_runtime_put_sync(&intf->dev);
-	else
-		atomic_inc(&intf->pm_usage_cnt);
 	dev_vdbg(&intf->dev, "%s: cnt %d -> %d\n",
 			__func__, atomic_read(&intf->dev.power.usage_count),
 			status);
@@ -1750,8 +1740,6 @@ int usb_autopm_get_interface_async(struc
 	status = pm_runtime_get(&intf->dev);
 	if (status < 0 && status != -EINPROGRESS)
 		pm_runtime_put_noidle(&intf->dev);
-	else
-		atomic_inc(&intf->pm_usage_cnt);
 	dev_vdbg(&intf->dev, "%s: cnt %d -> %d\n",
 			__func__, atomic_read(&intf->dev.power.usage_count),
 			status);
@@ -1775,7 +1763,6 @@ void usb_autopm_get_interface_no_resume(
 	struct usb_device	*udev = interface_to_usbdev(intf);
 
 	usb_mark_last_busy(udev);
-	atomic_inc(&intf->pm_usage_cnt);
 	pm_runtime_get_noresume(&intf->dev);
 }
 EXPORT_SYMBOL_GPL(usb_autopm_get_interface_no_resume);
--- a/Documentation/driver-api/usb/power-management.rst
+++ b/Documentation/driver-api/usb/power-management.rst
@@ -370,11 +370,15 @@ autosuspend the interface's device.  Whe
 then the interface is considered to be idle, and the kernel may
 autosuspend the device.
 
-Drivers need not be concerned about balancing changes to the usage
-counter; the USB core will undo any remaining "get"s when a driver
-is unbound from its interface.  As a corollary, drivers must not call
-any of the ``usb_autopm_*`` functions after their ``disconnect``
-routine has returned.
+Drivers must be careful to balance their overall changes to the usage
+counter.  Unbalanced "get"s will remain in effect when a driver is
+unbound from its interface, preventing the device from going into
+runtime suspend should the interface be bound to a driver again.  On
+the other hand, drivers are allowed to achieve this balance by calling
+the ``usb_autopm_*`` functions even after their ``disconnect`` routine
+has returned -- say from within a work-queue routine -- provided they
+retain an active reference to the interface (via ``usb_get_intf`` and
+``usb_put_intf``).
 
 Drivers using the async routines are responsible for their own
 synchronization and mutual exclusion.
--- a/drivers/usb/storage/realtek_cr.c
+++ b/drivers/usb/storage/realtek_cr.c
@@ -763,18 +763,16 @@ static void rts51x_suspend_timer_fn(stru
 		break;
 	case RTS51X_STAT_IDLE:
 	case RTS51X_STAT_SS:
-		usb_stor_dbg(us, "RTS51X_STAT_SS, intf->pm_usage_cnt:%d, power.usage:%d\n",
-			     atomic_read(&us->pusb_intf->pm_usage_cnt),
+		usb_stor_dbg(us, "RTS51X_STAT_SS, power.usage:%d\n",
 			     atomic_read(&us->pusb_intf->dev.power.usage_count));
 
-		if (atomic_read(&us->pusb_intf->pm_usage_cnt) > 0) {
+		if (atomic_read(&us->pusb_intf->dev.power.usage_count) > 0) {
 			usb_stor_dbg(us, "Ready to enter SS state\n");
 			rts51x_set_stat(chip, RTS51X_STAT_SS);
 			/* ignore mass storage interface's children */
 			pm_suspend_ignore_children(&us->pusb_intf->dev, true);
 			usb_autopm_put_interface_async(us->pusb_intf);
-			usb_stor_dbg(us, "RTS51X_STAT_SS 01, intf->pm_usage_cnt:%d, power.usage:%d\n",
-				     atomic_read(&us->pusb_intf->pm_usage_cnt),
+			usb_stor_dbg(us, "RTS51X_STAT_SS 01, power.usage:%d\n",
 				     atomic_read(&us->pusb_intf->dev.power.usage_count));
 		}
 		break;
@@ -807,11 +805,10 @@ static void rts51x_invoke_transport(stru
 	int ret;
 
 	if (working_scsi(srb)) {
-		usb_stor_dbg(us, "working scsi, intf->pm_usage_cnt:%d, power.usage:%d\n",
-			     atomic_read(&us->pusb_intf->pm_usage_cnt),
+		usb_stor_dbg(us, "working scsi, power.usage:%d\n",
 			     atomic_read(&us->pusb_intf->dev.power.usage_count));
 
-		if (atomic_read(&us->pusb_intf->pm_usage_cnt) <= 0) {
+		if (atomic_read(&us->pusb_intf->dev.power.usage_count) <= 0) {
 			ret = usb_autopm_get_interface(us->pusb_intf);
 			usb_stor_dbg(us, "working scsi, ret=%d\n", ret);
 		}

WARNING in usb_submit_urb (4)

[syzbot]

Hello,

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

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

Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=12231967200000

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

Re: WARNING in usb_submit_urb (4)

[syzbot]

Hello,

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

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

Tested on:

commit:         e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:        
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel config:  https://syzkaller.appspot.com/x/.config?x=69667e62a5e247a7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
patch:          https://syzkaller.appspot.com/x/patch.diff?x=12231967200000

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

Re: WARNING in usb_submit_urb (4)

[syzbot]

syzbot has bisected this bug to:

commit c470abd4fde40ea6a0846a2beab642a578c0b8cd
Author: Linus Torvalds <torvalds@linux-foundation.org>
Date:   Sun Feb 19 22:34:00 2017 +0000

     Linux 4.10

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=11b415ed200000
start commit:   e12e00e3 Merge tag 'kbuild-fixes-v4.20' of git://git.kerne..
git tree:       upstream
kernel config:  https://syzkaller.appspot.com/x/.config?x=8f215f21f041a0d7
dashboard link: https://syzkaller.appspot.com/bug?extid=7634edaea4d0b341c625
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=11ce6fbd400000

Reported-by: syzbot+7634edaea4d0b341c625@syzkaller.appspotmail.com
Fixes: c470abd4fde4 ("Linux 4.10")

For information about bisection process see: https://goo.gl/tpsmEJ#bisection