On Mon, Jun 10, 2024 at 10:58:02AM -0700, syzbot wrote:
> Hello,
>
> syzbot has tested the proposed patch but the reproducer is still triggering an issue:
> BUG: soft lockup in raw_ioctl
>
> dummy_hcd dummy_hcd.0: urbp 000000006bf6c1dd 40409880 next_frame 0000000000000000
> cdc_wdm 1-1:1.0: nonzero urb status received: -71
> cdc_wdm 1-1:1.0: wdm_int_callback - 0 bytes
> dummy_hcd dummy_hcd.0: urbp 000000003f481f40 40409880 next_frame 000000003f481f40
> watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [syz-executor415:10796]
The full console log shows that the cdc-wm and dummy-hcd loop uses less
than 60 microseconds out of every 2400 or so. That's not enough to
cause this. Something else must be going on.
> Call trace:
> __daif_local_irq_restore arch/arm64/include/asm/irqflags.h:175 [inline]
> arch_local_irq_restore arch/arm64/include/asm/irqflags.h:195 [inline]
> console_emit_next_record kernel/printk/printk.c:2935 [inline]
> console_flush_all+0x67c/0xb74 kernel/printk/printk.c:2994
> console_unlock+0xec/0x3d4 kernel/printk/printk.c:3063
> vprintk_emit+0x1ec/0x350 kernel/printk/printk.c:2345
> vprintk_default+0xa0/0xe4 kernel/printk/printk.c:2360
> vprintk+0x200/0x2d4 kernel/printk/printk_safe.c:45
> _printk+0xdc/0x128 kernel/printk/printk.c:2370
> usb_gadget_register_driver_owner+0x1f0/0x224 drivers/usb/gadget/udc/core.c:1711
Is this a coincidence? If CPU #0 is getting stuck, why here? Line 1711
is a mutex_unlock() call; it shouldn't take long. This doesn't seem to
make sense.
Let's try to find out what the CPU is really doing when this happens.
Alan Stern
#syz test: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git 8867bbd4a056
Index: usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
===================================================================
--- usb-devel.orig/drivers/usb/gadget/udc/dummy_hcd.c
+++ usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
@@ -1826,6 +1826,7 @@ static void dummy_timer(struct timer_lis
break;
dum->ep[i].already_seen = 0;
}
+ dev_info(dummy_dev(dum_hcd), "Timer handler\n");
restart:
list_for_each_entry_safe(urbp, tmp, &dum_hcd->urbp_list, urbp_list) {
@@ -1835,6 +1836,9 @@ restart:
struct dummy_ep *ep = NULL;
int status = -EINPROGRESS;
+ dev_info(dummy_dev(dum_hcd), "urbp %p %x next_frame %p\n",
+ urbp, urbp->urb->pipe, dum_hcd->next_frame_urbp);
+
/* stop when we reach URBs queued after the timer interrupt */
if (urbp == dum_hcd->next_frame_urbp)
break;
Index: usb-devel/drivers/usb/class/cdc-wdm.c
===================================================================
--- usb-devel.orig/drivers/usb/class/cdc-wdm.c
+++ usb-devel/drivers/usb/class/cdc-wdm.c
@@ -112,6 +112,7 @@ struct wdm_device {
enum wwan_port_type wwanp_type;
struct wwan_port *wwanp;
+ int alancount;
};
static struct usb_driver wdm_driver;
@@ -255,6 +256,14 @@ static void wdm_int_callback(struct urb
desc = urb->context;
dr = (struct usb_cdc_notification *)desc->sbuf;
+ if (status == -EPROTO) {
+ if (desc->alancount >= 1)
+ return;
+ ++desc->alancount;
+ dev_info(&desc->intf->dev, "Alan test\n");
+ dump_stack();
+ }
+
if (status) {
switch (status) {
case -ESHUTDOWN:
