Received: by 2002:a25:4158:0:0:0:0:0 with SMTP id o85csp2435285yba; Mon, 15 Apr 2019 11:33:03 -0700 (PDT) X-Google-Smtp-Source: APXvYqzq9/BHGh+ynDJLduxmIiTTjxOI3X5TOKZsu7Lod2NgL3qiqLj20y75OBNjDSb1lxeQ2JZY X-Received: by 2002:a63:61d7:: with SMTP id v206mr73047192pgb.349.1555353183405; Mon, 15 Apr 2019 11:33:03 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1555353183; cv=none; d=google.com; s=arc-20160816; b=vaBEdXmEH3AuD7ZAa66AWCj3OWoK9fZ07lhV3q1oO64vEJYblYsIL+yq5iJcXRcYaP e1JWP/ihfmEuZXcERwWuqInENgSu/IC69+pSN+kS5goDQWxBMhm2dOEkV/U+st1m13KM B2t1se928LjJhse8lfOWIlJt8D7pwHtb8Cdm+ll8xlL08JizCxWPbcLDMbR74tEn85dN zHqgG4286UUFy0bHvznRjk9vNrbOWfrbt65pynD6VHkzCgKS8Wf+VeV7EXdVYxqlfRMI mj49m0Ec/KX9EDy4EardROTeU+l/ZNZwQhICb2I6WQdMRlH1bEq78ykQk4zNYoslVpv4 V4wA== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:sender:mime-version:message-id:in-reply-to :subject:cc:to:from:date; bh=NwnIipUAl3HnYCybBflF+4o/ik+yaxuiTcTykZ41heQ=; b=YLoJ6xhZ8196xSv/5tRzs4jrTwEGShhLqmQ6Qe0s82XeodPtjCozqugWC1mvUYm0hS IECt6ix5ysFeAskRRGwJA8Xiix1SN9yESd43thjGC8rDtOqpTHyhW5W6ZS/uMC92mA7u +/IoNY6oJDnrSZw1gm+RUqhOmwdkkkub9AL5uRDWx4Pf6jUoKeArkL2hE7P6q7ML+wvu 1D8GrsHUSq8+GiES5jDS3zLxBT+IfTro4apUU7CaPZZVkr1E+Uwwpp0Bq2vkKy1hW1zH TiP03idXFtYa5pFk6QynJB/y/DVhfKd9NVcsuSANXW2ah1b6ZeTJ31QEi8Q13027C6g2 Zukw== ARC-Authentication-Results: i=1; mx.google.com; spf=pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org Return-Path: Received: from vger.kernel.org (vger.kernel.org. [209.132.180.67]) by mx.google.com with ESMTP id b6si42423478plx.325.2019.04.15.11.32.31; Mon, 15 Apr 2019 11:33:03 -0700 (PDT) Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67; Authentication-Results: mx.google.com; spf=pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1727911AbfDOSG7 (ORCPT + 99 others); Mon, 15 Apr 2019 14:06:59 -0400 Received: from iolanthe.rowland.org ([192.131.102.54]:39914 "HELO iolanthe.rowland.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with SMTP id S1725786AbfDOSG7 (ORCPT ); Mon, 15 Apr 2019 14:06:59 -0400 Received: (qmail 6419 invoked by uid 2102); 15 Apr 2019 14:06:58 -0400 Received: from localhost (sendmail-bs@127.0.0.1) by localhost with SMTP; 15 Apr 2019 14:06:58 -0400 Date: Mon, 15 Apr 2019 14:06:58 -0400 (EDT) From: Alan Stern X-X-Sender: stern@iolanthe.rowland.org To: Andrey Konovalov cc: Greg Kroah-Hartman , , Kernel development list , USB list , syzkaller-bugs Subject: Re: INFO: task hung in usb_kill_urb In-Reply-To: Message-ID: MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII Sender: linux-kernel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Mon, 15 Apr 2019, Andrey Konovalov wrote: > On Fri, Apr 12, 2019 at 9:46 PM Alan Stern wrote: > > > > Andrey: > > > > It's really hard to tell just what's going on here. > > > > On Fri, 12 Apr 2019, syzbot wrote: > > > > > Hello, > > > > > > syzbot found the following crash on: > > > > > > HEAD commit: 9a33b369 usb-fuzzer: main usb gadget fuzzer driver > > > git tree: https://github.com/google/kasan/tree/usb-fuzzer > > > console output: https://syzkaller.appspot.com/x/log.txt?x=14c4c1af200000 > > > kernel config: https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15 > > > dashboard link: https://syzkaller.appspot.com/bug?extid=d919b0f29d7b5a4994b9 > > > compiler: gcc (GCC) 9.0.0 20181231 (experimental) > > > syz repro: https://syzkaller.appspot.com/x/repro.syz?x=14410dbb200000 > > > C reproducer: https://syzkaller.appspot.com/x/repro.c?x=12f0acd3200000 > > > > > > IMPORTANT: if you fix the bug, please add the following tag to the commit: > > > Reported-by: syzbot+d919b0f29d7b5a4994b9@syzkaller.appspotmail.com > > > > > > usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22 > > > usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22 > > > usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22 > > > usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22 > > > usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22 > > > INFO: task kworker/0:2:532 blocked for more than 143 seconds. > > > Not tainted 5.1.0-rc4-319354-g9a33b36 #3 > > > "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > > > kworker/0:2 D26656 532 2 0x80000000 > > > Workqueue: usb_hub_wq hub_event > > > Call Trace: > > > schedule+0x8f/0x180 kernel/sched/core.c:3562 > > > usb_kill_urb drivers/usb/core/urb.c:695 [inline] > > > usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687 > > > usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63 > > > usb_internal_control_msg drivers/usb/core/message.c:101 [inline] > > > usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152 > > > > It looks like something is stuck waiting for usb_kill_urb() to finish. > > But what happened before that? > > This crash is somewhat special. It happens quite often during USB > fuzzing, but at the same time it's a hang, which makes it a bit harder > debug. I initially thought that is somehow related to my custom USB > fuzzing kernel patches, but then I saw that someone else hit this > issue while doing USB fuzzing in a completely different way that > doesn't require kernel modifications. So it might be an actual issue > in the kernel. > > The full console output is provided by the syzbot, but I guess it's > not very useful in this case. I've just made sure that this issue is > manually reproducible, so we can easily retest it with debug patches > (syzbot should be also able to do that via the syz test command). Or > is there a way to turn on some verbose mode to see some USB debug > messages? If I were doing this manually, I would run the following commands after loading the dummy-hcd driver but before starting the main test (requires CONFIG_USB_MON; you can skip the modprobe if CONFIG_USB_MON=y): modprobe usbmon cat /sys/kernel/debug/usb/usbmon/Nu >/tmp/mon.out & where N is the USB bus number corresponding to the dummy-hcd bus. Then after the test hangs, on another VT kill the "cat" process and examine the contents of /tmp/mon.out. Maybe you can do the equivalent with syzkaller? If necessary, you can start the "cat" before loading dummy-hcd and specify a bus number of 0. That will capture data for all the USB buses, including the dummy-hcd bus when it gets added (I think -- I haven't actually tried it). Alan > > I can't tell from the reproducer source, because it uses a bunch of > > special stuff you added in your usb-fuzzer tree. > > > > Alan Stern > > > > I understand, for now I guess the simpler way to debug this is to run > the reproducer. I'll write you and Greg a separate email regarding all > that special stuff that I added. > > Thanks!