Re: usb/gadget: stalls in dummy_timer

[Andrey Konovalov]

On Tue, Sep 19, 2017 at 7:17 PM, Alan Stern  wrote:
> On Tue, 19 Sep 2017, Andrey Konovalov wrote:
>
>> On Fri, Sep 15, 2017 at 8:57 PM, Alan Stern  
>> wrote:
>> > On Thu, 14 Sep 2017, Andrey Konovalov wrote:
>> >
>> >> On Thu, Sep 14, 2017 at 7:49 PM, Alan Stern  
>> >> wrote:
>> >> > On Thu, 14 Sep 2017, Andrey Konovalov wrote:
>> >> >
>> >> >> Looked at this a little more.
>> >> >>
>> >> >> dummy_timer() stucks in an infinite loop. It calls
>> >> >> usb_hcd_giveback_urb(), which in turn calls usbtouch_irq(), which
>> >> >> calls usb_submit_urb(), which calls dummy_urb_enqueue() and puts urb
>> >> >> back into dummy urb queue. dummy_timer() then does goto restart, finds
>> >> >> the urb and calls usb_hcd_giveback_urb() again. And this process goes
>> >> >> on again and again. It seems that something should either process the
>> >> >> urb and set urb->status or it should just expire.
>> >> >
>> >> > There is some throttling code, but it applies only to bulk transfers.
>> >> > Probably because the bandwidth limits for other types are slightly
>> >> > different.  However, I don't think we need to worry about this level of
>> >> > detail, since the driver makes a number of other approximations anyway.
>> >> >
>> >> > Try the patch below; it should fix the problem.
>> >>
>> >> Hi Alan,
>> >>
>> >> Just tried your patch, my reproducer still hangs the kernel until all
>> >> memory is exhausted.
>> >>
>> >> Thanks!
>> >
>> > Hmmm.  Your reproducer doesn't run on my system.  The mmap system call
>> > fails, perhaps because this laptop has a 32-bit kernel.  So I can't
>> > tell what's going on.
>> >
>> > Can you collect a usbmon trace that shows what happens while the
>> > reproducer runs?  If it turns out to be extremely large, just post an
>> > initial portion of it.
>>
>> I've attached the usbmon trace. It's actually quite short, probably
>> due to the fact that the kernel enters infinite loop.
>>
>> I've also attached a reproducer that should compile on a 32 bit
>> system, however I haven't tested whether it reproduces the issue.
>
> Got it, thanks.  Can you test the patch below in place of (or in
> addition to) the earlier patch?

With this patch (just this one, without the other one) the reproducer
no longer hangs the kernel :)

Tested-by: Andrey Konovalov 

Thanks!

>
> Alan Stern
>
>
>
> Index: usb-4.x/drivers/usb/gadget/udc/dummy_hcd.c
> ===
> --- usb-4.x.orig/drivers/usb/gadget/udc/dummy_hcd.c
> +++ usb-4.x/drivers/usb/gadget/udc/dummy_hcd.c
> @@ -237,6 +237,8 @@ struct dummy_hcd {
>
> struct usb_device   *udev;
> struct list_headurbp_list;
> +   struct urbp *next_frame_urbp;
> +
> u32 stream_en_ep;
> u8  num_stream[30 / 2];
>
> @@ -1252,6 +1254,8 @@ static int dummy_urb_enqueue(
>
> list_add_tail(>urbp_list, _hcd->urbp_list);
> urb->hcpriv = urbp;
> +   if (!dum_hcd->next_frame_urbp)
> +   dum_hcd->next_frame_urbp = urbp;
> if (usb_pipetype(urb->pipe) == PIPE_CONTROL)
> urb->error_count = 1;   /* mark as a new urb */
>
> @@ -1768,6 +1772,7 @@ static void dummy_timer(unsigned long _d
> spin_unlock_irqrestore(>lock, flags);
> return;
> }
> +   dum_hcd->next_frame_urbp = NULL;
>
> for (i = 0; i < DUMMY_ENDPOINTS; i++) {
> if (!ep_info[i].name)
> @@ -1784,6 +1789,10 @@ restart:
> int type;
> int status = -EINPROGRESS;
>
> +   /* stop when we reach URBs queued after the timer interrupt */
> +   if (urbp == dum_hcd->next_frame_urbp)
> +   break;
> +
> urb = urbp->urb;
> if (urb->unlinked)
> goto return_urb;
>
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: usb/gadget: stalls in dummy_timer

[Alan Stern]

On Tue, 19 Sep 2017, Andrey Konovalov wrote:

> On Fri, Sep 15, 2017 at 8:57 PM, Alan Stern  wrote:
> > On Thu, 14 Sep 2017, Andrey Konovalov wrote:
> >
> >> On Thu, Sep 14, 2017 at 7:49 PM, Alan Stern  
> >> wrote:
> >> > On Thu, 14 Sep 2017, Andrey Konovalov wrote:
> >> >
> >> >> Looked at this a little more.
> >> >>
> >> >> dummy_timer() stucks in an infinite loop. It calls
> >> >> usb_hcd_giveback_urb(), which in turn calls usbtouch_irq(), which
> >> >> calls usb_submit_urb(), which calls dummy_urb_enqueue() and puts urb
> >> >> back into dummy urb queue. dummy_timer() then does goto restart, finds
> >> >> the urb and calls usb_hcd_giveback_urb() again. And this process goes
> >> >> on again and again. It seems that something should either process the
> >> >> urb and set urb->status or it should just expire.
> >> >
> >> > There is some throttling code, but it applies only to bulk transfers.
> >> > Probably because the bandwidth limits for other types are slightly
> >> > different.  However, I don't think we need to worry about this level of
> >> > detail, since the driver makes a number of other approximations anyway.
> >> >
> >> > Try the patch below; it should fix the problem.
> >>
> >> Hi Alan,
> >>
> >> Just tried your patch, my reproducer still hangs the kernel until all
> >> memory is exhausted.
> >>
> >> Thanks!
> >
> > Hmmm.  Your reproducer doesn't run on my system.  The mmap system call
> > fails, perhaps because this laptop has a 32-bit kernel.  So I can't
> > tell what's going on.
> >
> > Can you collect a usbmon trace that shows what happens while the
> > reproducer runs?  If it turns out to be extremely large, just post an
> > initial portion of it.
> 
> I've attached the usbmon trace. It's actually quite short, probably
> due to the fact that the kernel enters infinite loop.
> 
> I've also attached a reproducer that should compile on a 32 bit
> system, however I haven't tested whether it reproduces the issue.

Got it, thanks.  Can you test the patch below in place of (or in 
addition to) the earlier patch?

Alan Stern



Index: usb-4.x/drivers/usb/gadget/udc/dummy_hcd.c
===
--- usb-4.x.orig/drivers/usb/gadget/udc/dummy_hcd.c
+++ usb-4.x/drivers/usb/gadget/udc/dummy_hcd.c
@@ -237,6 +237,8 @@ struct dummy_hcd {
 
struct usb_device   *udev;
struct list_headurbp_list;
+   struct urbp *next_frame_urbp;
+
u32 stream_en_ep;
u8  num_stream[30 / 2];
 
@@ -1252,6 +1254,8 @@ static int dummy_urb_enqueue(
 
list_add_tail(>urbp_list, _hcd->urbp_list);
urb->hcpriv = urbp;
+   if (!dum_hcd->next_frame_urbp)
+   dum_hcd->next_frame_urbp = urbp;
if (usb_pipetype(urb->pipe) == PIPE_CONTROL)
urb->error_count = 1;   /* mark as a new urb */
 
@@ -1768,6 +1772,7 @@ static void dummy_timer(unsigned long _d
spin_unlock_irqrestore(>lock, flags);
return;
}
+   dum_hcd->next_frame_urbp = NULL;
 
for (i = 0; i < DUMMY_ENDPOINTS; i++) {
if (!ep_info[i].name)
@@ -1784,6 +1789,10 @@ restart:
int type;
int status = -EINPROGRESS;
 
+   /* stop when we reach URBs queued after the timer interrupt */
+   if (urbp == dum_hcd->next_frame_urbp)
+   break;
+
urb = urbp->urb;
if (urb->unlinked)
goto return_urb;

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: usb/gadget: stalls in dummy_timer

[Andrey Konovalov]

On Fri, Sep 15, 2017 at 8:57 PM, Alan Stern  wrote:
> On Thu, 14 Sep 2017, Andrey Konovalov wrote:
>
>> On Thu, Sep 14, 2017 at 7:49 PM, Alan Stern  
>> wrote:
>> > On Thu, 14 Sep 2017, Andrey Konovalov wrote:
>> >
>> >> Looked at this a little more.
>> >>
>> >> dummy_timer() stucks in an infinite loop. It calls
>> >> usb_hcd_giveback_urb(), which in turn calls usbtouch_irq(), which
>> >> calls usb_submit_urb(), which calls dummy_urb_enqueue() and puts urb
>> >> back into dummy urb queue. dummy_timer() then does goto restart, finds
>> >> the urb and calls usb_hcd_giveback_urb() again. And this process goes
>> >> on again and again. It seems that something should either process the
>> >> urb and set urb->status or it should just expire.
>> >
>> > There is some throttling code, but it applies only to bulk transfers.
>> > Probably because the bandwidth limits for other types are slightly
>> > different.  However, I don't think we need to worry about this level of
>> > detail, since the driver makes a number of other approximations anyway.
>> >
>> > Try the patch below; it should fix the problem.
>>
>> Hi Alan,
>>
>> Just tried your patch, my reproducer still hangs the kernel until all
>> memory is exhausted.
>>
>> Thanks!
>
> Hmmm.  Your reproducer doesn't run on my system.  The mmap system call
> fails, perhaps because this laptop has a 32-bit kernel.  So I can't
> tell what's going on.
>
> Can you collect a usbmon trace that shows what happens while the
> reproducer runs?  If it turns out to be extremely large, just post an
> initial portion of it.

I've attached the usbmon trace. It's actually quite short, probably
due to the fact that the kernel enters infinite loop.

I've also attached a reproducer that should compile on a 32 bit
system, however I haven't tested whether it reproduces the issue.

>
> Alan Stern
>


dummy_timer-stall-usbmon
Description: Binary data
// autogenerated by syzkaller (http://github.com/google/syzkaller)

#define _GNU_SOURCE

#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 

void gadgetfs_mkdir()
{
mkdir("/dev/gadget", 0755) != 0;
}

void gadgetfs_mount()
{
while (mount("none", "/dev/gadget", "gadgetfs", 0, NULL) != 0) {
usleep(10 * 1000);
umount2("/dev/gadget", MNT_FORCE | MNT_DETACH);
}
}

static int
gfs_handle_event_setup_get_descriptor(int fd,
  struct usb_ctrlrequest* setup)
{
char buffer[128];
int rv;
switch (setup->wValue >> 8) {
case USB_DT_STRING:
buffer[0] = 4;
buffer[1] = USB_DT_STRING;
if ((setup->wValue & 0x0ff) == 0) {
buffer[2] = 0x09;
buffer[3] = 0x04;
} else {
buffer[2] = 0x61;
buffer[3] = 0x00;
}
rv = write(fd, [0], 4);
if (rv != 4) {
return -1;
}
break;
default:
break;
}
return 0;
}

static int
gfs_handle_event_setup_set_configuration(int fd,
 struct usb_ctrlrequest* setup)
{
int rv = read(fd, , 0);
if (rv != 0) {
return -1;
}
return 0;
}

static int gfs_handle_event_setup(int fd, struct usb_ctrlrequest* setup)
{
switch (setup->bRequest) {
case USB_REQ_GET_DESCRIPTOR:
gfs_handle_event_setup_get_descriptor(fd, setup);
break;
case USB_REQ_SET_CONFIGURATION:
gfs_handle_event_setup_set_configuration(fd, setup);
break;
case USB_REQ_GET_INTERFACE:
break;
case USB_REQ_SET_INTERFACE:
break;
default:
break;
}
return 0;
}

static int gfs_handle_event(int fd, struct usb_gadgetfs_event* event)
{
switch (event->type) {
case GADGETFS_NOP:
break;
case GADGETFS_CONNECT:
break;
case GADGETFS_SETUP:
gfs_handle_event_setup(fd, >u.setup);
break;
case GADGETFS_DISCONNECT:
break;
case GADGETFS_SUSPEND:
break;
default:
break;
}
return 0;
}

#define GFS_MAX_EVENTS 1

static int gfs_handle_ep0(int fd)
{
struct pollfd pfd;
struct usb_gadgetfs_event events[GFS_MAX_EVENTS];

pfd.fd = fd;
pfd.events = POLLIN | POLLOUT | POLLHUP;

int i;
for (i = 0; i < 15; i++) {
int rv = poll(, 1, 100);
if (rv < 0) {

Re: usb/gadget: stalls in dummy_timer

[Alan Stern]

On Thu, 14 Sep 2017, Andrey Konovalov wrote:

> On Thu, Sep 14, 2017 at 7:49 PM, Alan Stern  wrote:
> > On Thu, 14 Sep 2017, Andrey Konovalov wrote:
> >
> >> Looked at this a little more.
> >>
> >> dummy_timer() stucks in an infinite loop. It calls
> >> usb_hcd_giveback_urb(), which in turn calls usbtouch_irq(), which
> >> calls usb_submit_urb(), which calls dummy_urb_enqueue() and puts urb
> >> back into dummy urb queue. dummy_timer() then does goto restart, finds
> >> the urb and calls usb_hcd_giveback_urb() again. And this process goes
> >> on again and again. It seems that something should either process the
> >> urb and set urb->status or it should just expire.
> >
> > There is some throttling code, but it applies only to bulk transfers.
> > Probably because the bandwidth limits for other types are slightly
> > different.  However, I don't think we need to worry about this level of
> > detail, since the driver makes a number of other approximations anyway.
> >
> > Try the patch below; it should fix the problem.
> 
> Hi Alan,
> 
> Just tried your patch, my reproducer still hangs the kernel until all
> memory is exhausted.
> 
> Thanks!

Hmmm.  Your reproducer doesn't run on my system.  The mmap system call
fails, perhaps because this laptop has a 32-bit kernel.  So I can't
tell what's going on.

Can you collect a usbmon trace that shows what happens while the 
reproducer runs?  If it turns out to be extremely large, just post an 
initial portion of it.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: usb/gadget: stalls in dummy_timer

[Andrey Konovalov]

On Thu, Sep 14, 2017 at 7:49 PM, Alan Stern  wrote:
> On Thu, 14 Sep 2017, Andrey Konovalov wrote:
>
>> Looked at this a little more.
>>
>> dummy_timer() stucks in an infinite loop. It calls
>> usb_hcd_giveback_urb(), which in turn calls usbtouch_irq(), which
>> calls usb_submit_urb(), which calls dummy_urb_enqueue() and puts urb
>> back into dummy urb queue. dummy_timer() then does goto restart, finds
>> the urb and calls usb_hcd_giveback_urb() again. And this process goes
>> on again and again. It seems that something should either process the
>> urb and set urb->status or it should just expire.
>
> There is some throttling code, but it applies only to bulk transfers.
> Probably because the bandwidth limits for other types are slightly
> different.  However, I don't think we need to worry about this level of
> detail, since the driver makes a number of other approximations anyway.
>
> Try the patch below; it should fix the problem.

Hi Alan,

Just tried your patch, my reproducer still hangs the kernel until all
memory is exhausted.

Thanks!

>
> Alan Stern
>
>
>
> Index: usb-4.x/drivers/usb/gadget/udc/dummy_hcd.c
> ===
> --- usb-4.x.orig/drivers/usb/gadget/udc/dummy_hcd.c
> +++ usb-4.x/drivers/usb/gadget/udc/dummy_hcd.c
> @@ -1781,7 +1781,6 @@ restart:
> struct dummy_request*req;
> u8  address;
> struct dummy_ep *ep = NULL;
> -   int type;
> int status = -EINPROGRESS;
>
> urb = urbp->urb;
> @@ -1789,14 +1788,10 @@ restart:
> goto return_urb;
> else if (dum_hcd->rh_state != DUMMY_RH_RUNNING)
> continue;
> -   type = usb_pipetype(urb->pipe);
>
> -   /* used up this frame's non-periodic bandwidth?
> -* FIXME there's infinite bandwidth for control and
> -* periodic transfers ... unrealistic.
> -*/
> -   if (total <= 0 && type == PIPE_BULK)
> -   continue;
> +   /* Used up this frame's bandwidth? */
> +   if (total <= 0)
> +   break;
>
> /* find the gadget's ep for this request (if configured) */
> address = usb_pipeendpoint (urb->pipe);
>
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: usb/gadget: stalls in dummy_timer

[Alan Stern]

On Thu, 14 Sep 2017, Andrey Konovalov wrote:

> Looked at this a little more.
> 
> dummy_timer() stucks in an infinite loop. It calls
> usb_hcd_giveback_urb(), which in turn calls usbtouch_irq(), which
> calls usb_submit_urb(), which calls dummy_urb_enqueue() and puts urb
> back into dummy urb queue. dummy_timer() then does goto restart, finds
> the urb and calls usb_hcd_giveback_urb() again. And this process goes
> on again and again. It seems that something should either process the
> urb and set urb->status or it should just expire.

There is some throttling code, but it applies only to bulk transfers.  
Probably because the bandwidth limits for other types are slightly 
different.  However, I don't think we need to worry about this level of 
detail, since the driver makes a number of other approximations anyway.

Try the patch below; it should fix the problem.

Alan Stern



Index: usb-4.x/drivers/usb/gadget/udc/dummy_hcd.c
===
--- usb-4.x.orig/drivers/usb/gadget/udc/dummy_hcd.c
+++ usb-4.x/drivers/usb/gadget/udc/dummy_hcd.c
@@ -1781,7 +1781,6 @@ restart:
struct dummy_request*req;
u8  address;
struct dummy_ep *ep = NULL;
-   int type;
int status = -EINPROGRESS;
 
urb = urbp->urb;
@@ -1789,14 +1788,10 @@ restart:
goto return_urb;
else if (dum_hcd->rh_state != DUMMY_RH_RUNNING)
continue;
-   type = usb_pipetype(urb->pipe);
 
-   /* used up this frame's non-periodic bandwidth?
-* FIXME there's infinite bandwidth for control and
-* periodic transfers ... unrealistic.
-*/
-   if (total <= 0 && type == PIPE_BULK)
-   continue;
+   /* Used up this frame's bandwidth? */
+   if (total <= 0)
+   break;
 
/* find the gadget's ep for this request (if configured) */
address = usb_pipeendpoint (urb->pipe);

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: usb/gadget: stalls in dummy_timer

[Andrey Konovalov]

On Tue, Sep 12, 2017 at 7:44 PM, Andrey Konovalov  wrote:
> On Tue, Sep 12, 2017 at 7:06 PM, Dmitry Torokhov
>  wrote:
>> On Tue, Sep 12, 2017 at 05:48:51PM +0200, Andrey Konovalov wrote:
>>> On Mon, Sep 11, 2017 at 8:54 PM, Dmitry Torokhov
>>>  wrote:
>>> > On Mon, Sep 11, 2017 at 8:15 AM, Andrey Konovalov  
>>> > wrote:
>>> >> On Mon, Sep 11, 2017 at 3:25 PM, Alan Stern  
>>> >> wrote:
>>> >>> On Mon, 11 Sep 2017, Andrey Konovalov wrote:
>>> >>>
>>>  Hi!
>>> 
>>>  I've been getting stall reports like this one while fuzzing the USB
>>>  stack with gadgetfs. I'm wondering whether this is a bug in gadgetfs
>>>  or is this report induced by the changes I've made to the USB core
>>>  code. I didn't touch gadgetfs code though (except for adding a few
>>>  printk's).
>>> 
>>>  I'm on commit 81a84ad3cb5711cec79f4dd53a4ce026b092c432
>>> >>>
>>> >>> It's possible that this was caused by commit f16443a034c7 ("USB:
>>> >>> gadgetfs, dummy-hcd, net2280: fix locking for callbacks").  I've been
>>> >>> meaning to repair the commit but haven't done it yet.
>>> >>>
>>> >>> Can you test with that commit reverted?  You may end up seeing other
>>> >>> problems instead -- the ones that commit was intended to solve -- but
>>> >>> perhaps the stalls won't occur.
>>> >>
>>> >> So I've reverted both: the changes I made to USB core and the commit
>>> >> you mentioned, still saw the stalls.
>>> >>
>>> >> I've manged to find a way to reproduce this and now I'm not sure the
>>> >> problem is actually in gadgetfs, it might be the usbtouchscreen
>>> >> driver.
>>> >>
>>> >> The crash log is below.
>>> >>
>>> >> Thanks!
>>> >>
>>> >> gadgetfs: bound to dummy_udc driver
>>> >> usb 1-1: new full-speed USB device number 2 using dummy_hcd
>>> >> gadgetfs: connected
>>> >> gadgetfs: disconnected
>>> >> gadgetfs: connected
>>> >> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x8F has an
>>> >> invalid bInterval 0, changing to 10
>>> >> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x8F has invalid
>>> >> maxpacket 839, setting to 64
>>> >> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x7 has invalid
>>> >> maxpacket 1839, setting to 64
>>> >> usb 1-1: config 8 interface 0 has no altsetting 0
>>> >> usb 1-1: New USB device found, idVendor=0403, idProduct=f9e9
>>> >> usb 1-1: New USB device strings: Mfr=4, Product=8, SerialNumber=255
>>> >> usb 1-1: Product: a
>>> >> usb 1-1: Manufacturer: a
>>> >> usb 1-1: SerialNumber: a
>>> >> gadgetfs: configuration #8
>>> >> input: a a as /devices/platform/dummy_hcd.0/usb1/1-1/1-1:8.0/input/input8
>>> >> evbug: Connected device: input8 (a a at usb-dummy_hcd.0-1/input0)
>>> >> kworker/0:0: page allocation failure: order:0,
>>> >> mode:0x1280020(GFP_ATOMIC|__GFP_NOTRACK), nodemask=(null)
>>> >> kworker/0:0 cpuset=/ mems_allowed=0
>>> >
>>> > It seems you are running out of memory.
>>> >
>>> >> Swap cache stats: add 0, delete 0, find 0/0
>>> >> Free swap  = 0kB
>>> >> Total swap = 0kB
>>> >
>>> > And no swap. I think you need to give the box a bit more memory (or
>>> > there might be a leak somewhere).
>>>
>>> Increasing the amount of memory doesn't help. It looks like
>>> usbtouch_irq() gets called in an infinite loop, and calls
>>> usb_submit_urb on each iteration, until the kernel runs out of memory.
>>
>> Yes, that is exactly how USB interrupt-driven devices work. Their URB
>> completion routine handles the data and immediately resubmits URB to get
>> more data. The device/HCD will signal interrupt once more data is
>> available and the process starts over again. The only time we stop
>> resubmitting URBs if we get one of the following errors:
>>
>> case -ETIME:
>> /* this urb is timing out */
>> dev_dbg(dev,
>> "%s - urb timed out - was the device unplugged?\n",
>> __func__);
>> return;
>> case -ECONNRESET:
>> case -ENOENT:
>> case -ESHUTDOWN:
>> case -EPIPE:
>> /* this urb is terminated, clean up */
>> dev_dbg(dev, "%s - urb shutting down with status: %d\n",
>> __func__, urb->status);
>> return;
>>
>> So I'd start looking into dummy_hcd and see why it does not discard
>> processed URBs fast enough in your setup.
>
> I now have a C reproducer (attached), which causes this behavior on
> upstream kernel built with attached .config on commit
> 81a84ad3cb5711cec79f4dd53a4ce026b092c432, so I'm not sure if the issue
> is with my particular setup.

Looked at this a little more.

dummy_timer() stucks in an infinite loop. It calls
usb_hcd_giveback_urb(), which in turn calls usbtouch_irq(), which
calls usb_submit_urb(), which calls dummy_urb_enqueue() and puts urb
back into dummy urb queue. dummy_timer() then does goto restart, 

Re: usb/gadget: stalls in dummy_timer

[Dmitry Torokhov]

On Tue, Sep 12, 2017 at 05:48:51PM +0200, Andrey Konovalov wrote:
> On Mon, Sep 11, 2017 at 8:54 PM, Dmitry Torokhov
>  wrote:
> > On Mon, Sep 11, 2017 at 8:15 AM, Andrey Konovalov  
> > wrote:
> >> On Mon, Sep 11, 2017 at 3:25 PM, Alan Stern  
> >> wrote:
> >>> On Mon, 11 Sep 2017, Andrey Konovalov wrote:
> >>>
>  Hi!
> 
>  I've been getting stall reports like this one while fuzzing the USB
>  stack with gadgetfs. I'm wondering whether this is a bug in gadgetfs
>  or is this report induced by the changes I've made to the USB core
>  code. I didn't touch gadgetfs code though (except for adding a few
>  printk's).
> 
>  I'm on commit 81a84ad3cb5711cec79f4dd53a4ce026b092c432
> >>>
> >>> It's possible that this was caused by commit f16443a034c7 ("USB:
> >>> gadgetfs, dummy-hcd, net2280: fix locking for callbacks").  I've been
> >>> meaning to repair the commit but haven't done it yet.
> >>>
> >>> Can you test with that commit reverted?  You may end up seeing other
> >>> problems instead -- the ones that commit was intended to solve -- but
> >>> perhaps the stalls won't occur.
> >>
> >> So I've reverted both: the changes I made to USB core and the commit
> >> you mentioned, still saw the stalls.
> >>
> >> I've manged to find a way to reproduce this and now I'm not sure the
> >> problem is actually in gadgetfs, it might be the usbtouchscreen
> >> driver.
> >>
> >> The crash log is below.
> >>
> >> Thanks!
> >>
> >> gadgetfs: bound to dummy_udc driver
> >> usb 1-1: new full-speed USB device number 2 using dummy_hcd
> >> gadgetfs: connected
> >> gadgetfs: disconnected
> >> gadgetfs: connected
> >> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x8F has an
> >> invalid bInterval 0, changing to 10
> >> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x8F has invalid
> >> maxpacket 839, setting to 64
> >> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x7 has invalid
> >> maxpacket 1839, setting to 64
> >> usb 1-1: config 8 interface 0 has no altsetting 0
> >> usb 1-1: New USB device found, idVendor=0403, idProduct=f9e9
> >> usb 1-1: New USB device strings: Mfr=4, Product=8, SerialNumber=255
> >> usb 1-1: Product: a
> >> usb 1-1: Manufacturer: a
> >> usb 1-1: SerialNumber: a
> >> gadgetfs: configuration #8
> >> input: a a as /devices/platform/dummy_hcd.0/usb1/1-1/1-1:8.0/input/input8
> >> evbug: Connected device: input8 (a a at usb-dummy_hcd.0-1/input0)
> >> kworker/0:0: page allocation failure: order:0,
> >> mode:0x1280020(GFP_ATOMIC|__GFP_NOTRACK), nodemask=(null)
> >> kworker/0:0 cpuset=/ mems_allowed=0
> >
> > It seems you are running out of memory.
> >
> >> Swap cache stats: add 0, delete 0, find 0/0
> >> Free swap  = 0kB
> >> Total swap = 0kB
> >
> > And no swap. I think you need to give the box a bit more memory (or
> > there might be a leak somewhere).
> 
> Increasing the amount of memory doesn't help. It looks like
> usbtouch_irq() gets called in an infinite loop, and calls
> usb_submit_urb on each iteration, until the kernel runs out of memory.

Yes, that is exactly how USB interrupt-driven devices work. Their URB
completion routine handles the data and immediately resubmits URB to get
more data. The device/HCD will signal interrupt once more data is
available and the process starts over again. The only time we stop
resubmitting URBs if we get one of the following errors:

case -ETIME:
/* this urb is timing out */
dev_dbg(dev,
"%s - urb timed out - was the device unplugged?\n",
__func__);
return;
case -ECONNRESET:
case -ENOENT:
case -ESHUTDOWN:
case -EPIPE:
/* this urb is terminated, clean up */
dev_dbg(dev, "%s - urb shutting down with status: %d\n",
__func__, urb->status);
return;

So I'd start looking into dummy_hcd and see why it does not discard
processed URBs fast enough in your setup.

Thanks.

-- 
Dmitry
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: usb/gadget: stalls in dummy_timer

[Andrey Konovalov]

On Mon, Sep 11, 2017 at 8:54 PM, Dmitry Torokhov
 wrote:
> On Mon, Sep 11, 2017 at 8:15 AM, Andrey Konovalov  
> wrote:
>> On Mon, Sep 11, 2017 at 3:25 PM, Alan Stern  
>> wrote:
>>> On Mon, 11 Sep 2017, Andrey Konovalov wrote:
>>>
 Hi!

 I've been getting stall reports like this one while fuzzing the USB
 stack with gadgetfs. I'm wondering whether this is a bug in gadgetfs
 or is this report induced by the changes I've made to the USB core
 code. I didn't touch gadgetfs code though (except for adding a few
 printk's).

 I'm on commit 81a84ad3cb5711cec79f4dd53a4ce026b092c432
>>>
>>> It's possible that this was caused by commit f16443a034c7 ("USB:
>>> gadgetfs, dummy-hcd, net2280: fix locking for callbacks").  I've been
>>> meaning to repair the commit but haven't done it yet.
>>>
>>> Can you test with that commit reverted?  You may end up seeing other
>>> problems instead -- the ones that commit was intended to solve -- but
>>> perhaps the stalls won't occur.
>>
>> So I've reverted both: the changes I made to USB core and the commit
>> you mentioned, still saw the stalls.
>>
>> I've manged to find a way to reproduce this and now I'm not sure the
>> problem is actually in gadgetfs, it might be the usbtouchscreen
>> driver.
>>
>> The crash log is below.
>>
>> Thanks!
>>
>> gadgetfs: bound to dummy_udc driver
>> usb 1-1: new full-speed USB device number 2 using dummy_hcd
>> gadgetfs: connected
>> gadgetfs: disconnected
>> gadgetfs: connected
>> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x8F has an
>> invalid bInterval 0, changing to 10
>> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x8F has invalid
>> maxpacket 839, setting to 64
>> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x7 has invalid
>> maxpacket 1839, setting to 64
>> usb 1-1: config 8 interface 0 has no altsetting 0
>> usb 1-1: New USB device found, idVendor=0403, idProduct=f9e9
>> usb 1-1: New USB device strings: Mfr=4, Product=8, SerialNumber=255
>> usb 1-1: Product: a
>> usb 1-1: Manufacturer: a
>> usb 1-1: SerialNumber: a
>> gadgetfs: configuration #8
>> input: a a as /devices/platform/dummy_hcd.0/usb1/1-1/1-1:8.0/input/input8
>> evbug: Connected device: input8 (a a at usb-dummy_hcd.0-1/input0)
>> kworker/0:0: page allocation failure: order:0,
>> mode:0x1280020(GFP_ATOMIC|__GFP_NOTRACK), nodemask=(null)
>> kworker/0:0 cpuset=/ mems_allowed=0
>
> It seems you are running out of memory.
>
>> Swap cache stats: add 0, delete 0, find 0/0
>> Free swap  = 0kB
>> Total swap = 0kB
>
> And no swap. I think you need to give the box a bit more memory (or
> there might be a leak somewhere).

Increasing the amount of memory doesn't help. It looks like
usbtouch_irq() gets called in an infinite loop, and calls
usb_submit_urb on each iteration, until the kernel runs out of memory.

(gdb) bt
#0  unwind_next_frame (state=0x8801f6806120) at
arch/x86/kernel/unwind_frame.c:277
#1  0x81109e33 in unwind_next_frame (state=0x8801f515bd98)
at arch/x86/kernel/unwind_frame.c:269
#2  0x8108fa13 in __save_stack_trace
(trace=0x8801f68061b8, task=0x8801f515b400, regs=0x0
, nosched=false) at arch/x86/kernel/stacktrace.c:44
#3  0x8108fa8b in save_stack_trace (trace=) at
arch/x86/kernel/stacktrace.c:59
#4  0x81723873 in save_stack (flags=17301536) at mm/kasan/kasan.c:447
#5  0x81723b3d in set_track (flags=,
track=) at mm/kasan/kasan.c:459
#6  kasan_kmalloc (cache=0x8801f515bd98, object=,
size=, flags=17301536) at mm/kasan/kasan.c:551
#7  0x81724102 in kasan_slab_alloc (cache=,
object=, flags=) at mm/kasan/kasan.c:489
#8  0x8171f836 in slab_post_alloc_hook (p=,
size=, flags=, s=) at
mm/slab.h:440
#9  slab_alloc_node (addr=, node=,
gfpflags=, s=) at mm/slub.c:2712
#10 slab_alloc (addr=, gfpflags=,
s=) at mm/slub.c:2720
#11 kmem_cache_alloc_trace (s=0x8801f6401640, gfpflags=17301536,
size=) at mm/slub.c:2737
#12 0x83dc4ce3 in kmalloc (flags=,
size=) at ./include/linux/slab.h:493
#13 dummy_urb_enqueue (hcd=0x8801f0e5d200, urb=0x8801eac10d00,
mem_flags=17301536) at drivers/usb/gadget/udc/dummy_hcd.c:1220
#14 0x839bf3d3 in usb_hcd_submit_urb (urb=0x8801eac10d00,
mem_flags=17301536) at drivers/usb/core/hcd.c:1664
#15 0x839c4327 in usb_submit_urb (urb=0x8801eac10d00,
mem_flags=) at drivers/usb/core/urb.c:542
#16 0x840bda26 in usbtouch_irq (urb=0x8801eac10d00) at
drivers/input/touchscreen/usbtouchscreen.c:1441
#17 0x839b90c1 in __usb_hcd_giveback_urb
(urb=0x8801eac10d00) at drivers/usb/core/hcd.c:1779
#18 0x839b971f in usb_hcd_giveback_urb
(hcd=0x8801f0e5d200, urb=0x8801eac10d00, status=) at drivers/usb/core/hcd.c:1845
#19 0x83dc755a in dummy_timer (_dum_hcd=) at
drivers/usb/gadget/udc/dummy_hcd.c:1924
#20 0x813245ba in call_timer_fn (timer=,
fn=, data=) at 

Re: usb/gadget: stalls in dummy_timer

[Dmitry Torokhov]

On Mon, Sep 11, 2017 at 8:15 AM, Andrey Konovalov  wrote:
> On Mon, Sep 11, 2017 at 3:25 PM, Alan Stern  wrote:
>> On Mon, 11 Sep 2017, Andrey Konovalov wrote:
>>
>>> Hi!
>>>
>>> I've been getting stall reports like this one while fuzzing the USB
>>> stack with gadgetfs. I'm wondering whether this is a bug in gadgetfs
>>> or is this report induced by the changes I've made to the USB core
>>> code. I didn't touch gadgetfs code though (except for adding a few
>>> printk's).
>>>
>>> I'm on commit 81a84ad3cb5711cec79f4dd53a4ce026b092c432
>>
>> It's possible that this was caused by commit f16443a034c7 ("USB:
>> gadgetfs, dummy-hcd, net2280: fix locking for callbacks").  I've been
>> meaning to repair the commit but haven't done it yet.
>>
>> Can you test with that commit reverted?  You may end up seeing other
>> problems instead -- the ones that commit was intended to solve -- but
>> perhaps the stalls won't occur.
>
> So I've reverted both: the changes I made to USB core and the commit
> you mentioned, still saw the stalls.
>
> I've manged to find a way to reproduce this and now I'm not sure the
> problem is actually in gadgetfs, it might be the usbtouchscreen
> driver.
>
> The crash log is below.
>
> Thanks!
>
> gadgetfs: bound to dummy_udc driver
> usb 1-1: new full-speed USB device number 2 using dummy_hcd
> gadgetfs: connected
> gadgetfs: disconnected
> gadgetfs: connected
> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x8F has an
> invalid bInterval 0, changing to 10
> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x8F has invalid
> maxpacket 839, setting to 64
> usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x7 has invalid
> maxpacket 1839, setting to 64
> usb 1-1: config 8 interface 0 has no altsetting 0
> usb 1-1: New USB device found, idVendor=0403, idProduct=f9e9
> usb 1-1: New USB device strings: Mfr=4, Product=8, SerialNumber=255
> usb 1-1: Product: a
> usb 1-1: Manufacturer: a
> usb 1-1: SerialNumber: a
> gadgetfs: configuration #8
> input: a a as /devices/platform/dummy_hcd.0/usb1/1-1/1-1:8.0/input/input8
> evbug: Connected device: input8 (a a at usb-dummy_hcd.0-1/input0)
> kworker/0:0: page allocation failure: order:0,
> mode:0x1280020(GFP_ATOMIC|__GFP_NOTRACK), nodemask=(null)
> kworker/0:0 cpuset=/ mems_allowed=0

It seems you are running out of memory.

> Swap cache stats: add 0, delete 0, find 0/0
> Free swap  = 0kB
> Total swap = 0kB

And no swap. I think you need to give the box a bit more memory (or
there might be a leak somewhere).

Thanks.

-- 
Dmitry
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: usb/gadget: stalls in dummy_timer

[Andrey Konovalov]

On Mon, Sep 11, 2017 at 3:25 PM, Alan Stern  wrote:
> On Mon, 11 Sep 2017, Andrey Konovalov wrote:
>
>> Hi!
>>
>> I've been getting stall reports like this one while fuzzing the USB
>> stack with gadgetfs. I'm wondering whether this is a bug in gadgetfs
>> or is this report induced by the changes I've made to the USB core
>> code. I didn't touch gadgetfs code though (except for adding a few
>> printk's).
>>
>> I'm on commit 81a84ad3cb5711cec79f4dd53a4ce026b092c432
>
> It's possible that this was caused by commit f16443a034c7 ("USB:
> gadgetfs, dummy-hcd, net2280: fix locking for callbacks").  I've been
> meaning to repair the commit but haven't done it yet.
>
> Can you test with that commit reverted?  You may end up seeing other
> problems instead -- the ones that commit was intended to solve -- but
> perhaps the stalls won't occur.

So I've reverted both: the changes I made to USB core and the commit
you mentioned, still saw the stalls.

I've manged to find a way to reproduce this and now I'm not sure the
problem is actually in gadgetfs, it might be the usbtouchscreen
driver.

The crash log is below.

Thanks!

gadgetfs: bound to dummy_udc driver
usb 1-1: new full-speed USB device number 2 using dummy_hcd
gadgetfs: connected
gadgetfs: disconnected
gadgetfs: connected
usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x8F has an
invalid bInterval 0, changing to 10
usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x8F has invalid
maxpacket 839, setting to 64
usb 1-1: config 8 interface 0 altsetting 9 endpoint 0x7 has invalid
maxpacket 1839, setting to 64
usb 1-1: config 8 interface 0 has no altsetting 0
usb 1-1: New USB device found, idVendor=0403, idProduct=f9e9
usb 1-1: New USB device strings: Mfr=4, Product=8, SerialNumber=255
usb 1-1: Product: a
usb 1-1: Manufacturer: a
usb 1-1: SerialNumber: a
gadgetfs: configuration #8
input: a a as /devices/platform/dummy_hcd.0/usb1/1-1/1-1:8.0/input/input8
evbug: Connected device: input8 (a a at usb-dummy_hcd.0-1/input0)
kworker/0:0: page allocation failure: order:0,
mode:0x1280020(GFP_ATOMIC|__GFP_NOTRACK), nodemask=(null)
kworker/0:0 cpuset=/ mems_allowed=0
CPU: 0 PID: 3 Comm: kworker/0:0 Not tainted 4.13.0+ #93
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
Workqueue: usb_hub_wq hub_event
Call Trace:
 
 __dump_stack lib/dump_stack.c:16
 dump_stack+0x192/0x22c lib/dump_stack.c:52
 warn_alloc+0x28e/0x430 mm/page_alloc.c:3242
 __alloc_pages_slowpath+0x1bbc/0x2250 mm/page_alloc.c:4043
 __alloc_pages_nodemask+0x914/0xea0 mm/page_alloc.c:4135
 alloc_pages_current+0xbb/0x1f0 mm/mempolicy.c:1974
 alloc_pages ./include/linux/gfp.h:507
 alloc_slab_page mm/slub.c:1408
 allocate_slab mm/slub.c:1559
 new_slab+0x384/0x410 mm/slub.c:1638
 new_slab_objects mm/slub.c:2423
 ___slab_alloc+0x35d/0x4c0 mm/slub.c:2575
 __slab_alloc+0x20/0x40 mm/slub.c:2615
 slab_alloc_node mm/slub.c:2678
 slab_alloc mm/slub.c:2720
 kmem_cache_alloc_trace+0x14e/0x170 mm/slub.c:2737
 kmalloc ./include/linux/slab.h:493
 dummy_urb_enqueue+0xf3/0x970 drivers/usb/gadget/udc/dummy_hcd.c:1220
 usb_hcd_submit_urb+0x2d3/0x1d50 drivers/usb/core/hcd.c:1664
 usb_submit_urb+0x937/0x11d0 drivers/usb/core/urb.c:542
 usbtouch_irq+0x216/0x2e0 drivers/input/touchscreen/usbtouchscreen.c:1441
 __usb_hcd_giveback_urb+0x2a1/0x5b0 drivers/usb/core/hcd.c:1779
 usb_hcd_giveback_urb+0x34f/0x4d0 drivers/usb/core/hcd.c:1845
 dummy_timer+0xbda/0x38c0 drivers/usb/gadget/udc/dummy_hcd.c:1924
 call_timer_fn+0xba/0x390 kernel/time/timer.c:1281
 expire_timers kernel/time/timer.c:1320
 __run_timers+0x9d0/0xda0 kernel/time/timer.c:1620
 run_timer_softirq+0x51/0xb0 kernel/time/timer.c:1646
 __do_softirq+0x258/0x7ac kernel/softirq.c:284
 invoke_softirq kernel/softirq.c:364
 irq_exit+0x14e/0x180 kernel/softirq.c:405
 exiting_irq ./arch/x86/include/asm/apic.h:638
 smp_apic_timer_interrupt+0x7b/0xa0 arch/x86/kernel/apic/apic.c:1044
 apic_timer_interrupt+0x89/0x90
RIP: 0010:arch_local_irq_restore ./arch/x86/include/asm/paravirt.h:814
RIP: 0010:console_unlock+0x814/0xcd0 kernel/printk/printk.c:2247
RSP: 0018:88006bdedd30 EFLAGS: 0a06 ORIG_RAX: ff10
RAX: 11000d7bdbe8 RBX:  RCX: 
RDX: 11000d7bdbe0 RSI: 87f007c0 RDI: 0a06
RBP: 88006bdee0a8 R08: fbfff0fe0102 R09: fbfff0fe0102
R10: 0009 R11: fbfff0fe0101 R12: 
R13:  R14: dc00 R15: 82d15610
 
 vprintk_emit+0x567/0x5d0 kernel/printk/printk.c:1769
 vprintk_default+0x2d/0x40 kernel/printk/printk.c:1808
 vprintk_func+0x5c/0xd0 kernel/printk/printk_safe.c:382
 printk+0xcd/0xfe kernel/printk/printk.c:1841
 evbug_connect+0x1de/0x260 drivers/input/evbug.c:69
 input_attach_handler+0x59a/0x740 drivers/input/input.c:1002
 input_register_device+0xcb8/0xf90 drivers/input/input.c:2159
 usbtouch_probe+0x1372/0x1fe0 drivers/input/touchscreen/usbtouchscreen.c:1690
 usb_probe_interface+0x351/0x8d0 

Re: usb/gadget: stalls in dummy_timer

[Alan Stern]

On Mon, 11 Sep 2017, Andrey Konovalov wrote:

> Hi!
> 
> I've been getting stall reports like this one while fuzzing the USB
> stack with gadgetfs. I'm wondering whether this is a bug in gadgetfs
> or is this report induced by the changes I've made to the USB core
> code. I didn't touch gadgetfs code though (except for adding a few
> printk's).
> 
> I'm on commit 81a84ad3cb5711cec79f4dd53a4ce026b092c432

It's possible that this was caused by commit f16443a034c7 ("USB: 
gadgetfs, dummy-hcd, net2280: fix locking for callbacks").  I've been 
meaning to repair the commit but haven't done it yet.

Can you test with that commit reverted?  You may end up seeing other 
problems instead -- the ones that commit was intended to solve -- but 
perhaps the stalls won't occur.

Alan Stern

> usbtouchscreen 2-1:8.0: usbtouch_irq - usb_submit_urb failed with result: -12
> INFO: rcu_sched self-detected stall on CPU
> INFO: rcu_sched detected stalls on CPUs/tasks:
> 2-...: (1 GPs behind) idle=ba2/142/0 softirq=100255/100259 fqs=2
> (detected by 1, t=48363 jiffies, g=20668, c=20667, q=2875)
> Sending NMI from CPU 1 to CPUs 2:
> NMI backtrace for cpu 2
> CPU: 2 PID: 9620 Comm: udevd Not tainted 4.13.0+ #87
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
> task: 88003a414e00 task.stack: 88003aaa8000
> RIP: 0010:inb arch/x86/include/asm/io.h:340 [inline]
> RIP: 0010:io_serial_in+0x70/0x90 drivers/tty/serial/8250/8250_port.c:430
> RSP: 0018:88006dc05638 EFLAGS: 0002
> RAX: dc60 RBX: 03fd RCX: 
> RDX: 03fd RSI: 0005 RDI: 88791fe8
> RBP: 88006dc05648 R08: fbfff0fe0100 R09: fbfff0fe0100
> R10: 0007 R11: fbfff0fe00ff R12: 88791fe0
> R13: 0020 R14: fbfff10f2438 R15: fbfff10f23ff
> FS:  7f88402d27a0() GS:88006dc0() knlGS:
> CS:  0010 DS:  ES:  CR0: 80050033
> CR2: 7f88402d9000 CR3: 3d4ec000 CR4: 06e0
> Call Trace:
>  
>  serial_in drivers/tty/serial/8250/8250.h:115 [inline]
>  wait_for_xmitr+0x8e/0x1d0 drivers/tty/serial/8250/8250_port.c:2015
>  serial8250_console_putchar+0x24/0x60 drivers/tty/serial/8250/8250_port.c:3149
>  uart_console_write+0x5c/0xf0 drivers/tty/serial/serial_core.c:1856
>  serial8250_console_write+0x319/0x670 drivers/tty/serial/8250/8250_port.c:3215
>  univ8250_console_write+0x6b/0x80 drivers/tty/serial/8250/8250_core.c:594
>  call_console_drivers kernel/printk/printk.c:1586 [inline]
>  console_unlock+0x8a1/0xcd0 kernel/printk/printk.c:2245
>  vprintk_emit+0x567/0x5d0 kernel/printk/printk.c:1769
>  vprintk_default+0x2d/0x40 kernel/printk/printk.c:1808
>  vprintk_func+0x5c/0xd0 kernel/printk/printk_safe.c:382
>  printk+0xcd/0xfe kernel/printk/printk.c:1841
>  print_cpu_stall_info_begin kernel/rcu/tree_plugin.h:1643 [inline]
>  print_cpu_stall+0x1a4/0x6d0 kernel/rcu/tree.c:1524
>  check_cpu_stall.isra.72+0x707/0xe90 kernel/rcu/tree.c:1604
>  __rcu_pending kernel/rcu/tree.c:3457 [inline]
>  rcu_pending kernel/rcu/tree.c:3519 [inline]
>  rcu_check_callbacks+0x241/0xa50 kernel/rcu/tree.c:2861
>  update_process_times+0x35/0x70 kernel/time/timer.c:1590
>  tick_sched_handle+0xf5/0x160 kernel/time/tick-sched.c:161
>  tick_sched_timer+0x47/0x120 kernel/time/tick-sched.c:1190
>  __run_hrtimer kernel/time/hrtimer.c:1213 [inline]
>  __hrtimer_run_queues+0x3f4/0x970 kernel/time/hrtimer.c:1277
>  hrtimer_interrupt+0x22a/0x720 kernel/time/hrtimer.c:1311
>  local_apic_timer_interrupt+0x74/0xe0 arch/x86/kernel/apic/apic.c:1019
>  smp_apic_timer_interrupt+0x76/0xa0 arch/x86/kernel/apic/apic.c:1043
>  apic_timer_interrupt+0x89/0x90 arch/x86/entry/entry_64.S:482
> RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:814 [inline]
> RIP: 0010:__raw_spin_unlock_irqrestore
> include/linux/spinlock_api_smp.h:160 [inline]
> RIP: 0010:_raw_spin_unlock_irqrestore+0xf5/0x160 kernel/locking/spinlock.c:191
> RSP: 0018:88006dc06c40 EFLAGS: 0a06 ORIG_RAX: ff10
> RAX: 11000db80d95 RBX: 11000db80d89 RCX: dc00
> RDX: dc00 RSI: 0a06 RDI: 0a06
> RBP: 88006dc06d48 R08: fbfff0fe0104 R09: fbfff0fe0104
> R10: 88006dc06420 R11: fbfff0fe0103 R12: 11000db80d9d
> R13: 11000db80d8d R14: 88006ac48000 R15: 88006c172b08
>  spin_unlock_irqrestore include/linux/spinlock.h:354 [inline]
>  dummy_timer+0x1aa8/0x38c0 drivers/usb/gadget/udc/dummy_hcd.c:1938
>  call_timer_fn+0xba/0x390 kernel/time/timer.c:1281
>  expire_timers kernel/time/timer.c:1320 [inline]
>  __run_timers+0x9d0/0xda0 kernel/time/timer.c:1620
>  run_timer_softirq+0x51/0xb0 kernel/time/timer.c:1646
>  __do_softirq+0x258/0x7ac kernel/softirq.c:284
>  invoke_softirq kernel/softirq.c:364 [inline]
>  irq_exit+0x14e/0x180 kernel/softirq.c:405
>  exiting_irq arch/x86/include/asm/apic.h:638 [inline]
>