INFO: task hung in hub_port_init

INFO: task hung in hub_port_init

[Hao Sun]

Hello,

When using Healer to fuzz the Linux kernel, the following crash was triggered.

HEAD commit: ac08b1c68d1b Merge tag 'pci-v5.15-changes'
git tree: upstream
console output:
https://drive.google.com/file/d/1ZeDIMe-DoY3fB32j2p5ifgpq-Lc5N74I/view?usp=sharing
kernel config: https://drive.google.com/file/d/1qrJUXD8ZIeAkg-xojzDpp04v9MtQ8RR6/view?usp=sharing
Syzlang reproducer:
https://drive.google.com/file/d/1tZe8VmXfxoPqlNpzpGOd-e5WCSWgbkxB/view?usp=sharing
Similar report:
https://groups.google.com/g/syzkaller-bugs/c/zX55CUzjBOY/m/uf91r0XqAgAJ

Sorry, I don't have a C reproducer for this crash but have a Syzlang
reproducer. Also, hope the symbolized report can help.
Here are the instructions on how to execute Syzlang prog:
https://github.com/google/syzkaller/blob/master/docs/executing_syzkaller_programs.md

If you fix this issue, please add the following tag to the commit:
Reported-by: Hao Sun <sunhao.th@gmail.com>

INFO: task kworker/2:10:12595 blocked for more than 143 seconds.
      Not tainted 5.14.0+ #15
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/2:10    state:D stack:12600 pid:12595 ppid:     2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
 context_switch kernel/sched/core.c:4940 [inline]
 __schedule+0x323/0xae0 kernel/sched/core.c:6287
 schedule+0x36/0xe0 kernel/sched/core.c:6366
 usb_kill_urb+0xcf/0x110 drivers/usb/core/urb.c:720
 usb_start_wait_urb+0x103/0x1a0 drivers/usb/core/message.c:64
 usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
 usb_control_msg+0xee/0x170 drivers/usb/core/message.c:153
 hub_port_init+0x5a8/0x1060 drivers/usb/core/hub.c:4829
 hub_port_connect drivers/usb/core/hub.c:5280 [inline]
 hub_port_connect_change drivers/usb/core/hub.c:5488 [inline]
 port_event drivers/usb/core/hub.c:5634 [inline]
 hub_event+0x1083/0x1ec0 drivers/usb/core/hub.c:5716
 process_one_work+0x359/0x850 kernel/workqueue.c:2297
 worker_thread+0x41/0x4d0 kernel/workqueue.c:2444
 kthread+0x178/0x1b0 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295

Showing all locks held in the system:
1 lock held by khungtaskd/1673:
 #0: ffffffff85a1d520 (rcu_read_lock){....}-{1:2}, at:
debug_show_all_locks+0xe/0x1a0 kernel/locking/lockdep.c:6446
1 lock held by in:imklog/8139:
 #0: ffff88810537cef0 (&f->f_pos_lock){+.+.}-{3:3}, at:
__fdget_pos+0x55/0x60 fs/file.c:990
3 locks held by kworker/u8:2/9082:
 #0: ffff8881000bad38 ((wq_completion)netns){+.+.}-{0:0}, at:
set_work_data kernel/workqueue.c:633 [inline]
 #0: ffff8881000bad38 ((wq_completion)netns){+.+.}-{0:0}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
 #0: ffff8881000bad38 ((wq_completion)netns){+.+.}-{0:0}, at:
process_one_work+0x2a0/0x850 kernel/workqueue.c:2268
 #1: ffffc900034d7e70 (net_cleanup_work){+.+.}-{0:0}, at:
set_work_data kernel/workqueue.c:633 [inline]
 #1: ffffc900034d7e70 (net_cleanup_work){+.+.}-{0:0}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
 #1: ffffc900034d7e70 (net_cleanup_work){+.+.}-{0:0}, at:
process_one_work+0x2a0/0x850 kernel/workqueue.c:2268
 #2: ffffffff85e926d0 (pernet_ops_rwsem){++++}-{3:3}, at:
cleanup_net+0x4f/0x4e0 net/core/net_namespace.c:553
5 locks held by kworker/2:10/12595:
 #0: ffff88800a3b0938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at:
set_work_data kernel/workqueue.c:633 [inline]
 #0: ffff88800a3b0938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
 #0: ffff88800a3b0938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at:
process_one_work+0x2a0/0x850 kernel/workqueue.c:2268
 #1: ffffc90003a3fe70 ((work_completion)(&hub->events)){+.+.}-{0:0},
at: set_work_data kernel/workqueue.c:633 [inline]
 #1: ffffc90003a3fe70 ((work_completion)(&hub->events)){+.+.}-{0:0},
at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
 #1: ffffc90003a3fe70 ((work_completion)(&hub->events)){+.+.}-{0:0},
at: process_one_work+0x2a0/0x850 kernel/workqueue.c:2268
 #2: ffff88800e159220 (&dev->mutex){....}-{3:3}, at: device_lock
include/linux/device.h:760 [inline]
 #2: ffff88800e159220 (&dev->mutex){....}-{3:3}, at:
hub_event+0xad/0x1ec0 drivers/usb/core/hub.c:5662
 #3: ffff88800e15adc0 (&port_dev->status_lock){+.+.}-{3:3}, at:
usb_lock_port drivers/usb/core/hub.c:3086 [inline]
 #3: ffff88800e15adc0 (&port_dev->status_lock){+.+.}-{3:3}, at:
hub_port_connect drivers/usb/core/hub.c:5279 [inline]
 #3: ffff88800e15adc0 (&port_dev->status_lock){+.+.}-{3:3}, at:
hub_port_connect_change drivers/usb/core/hub.c:5488 [inline]
 #3: ffff88800e15adc0 (&port_dev->status_lock){+.+.}-{3:3}, at:
port_event drivers/usb/core/hub.c:5634 [inline]
 #3: ffff88800e15adc0 (&port_dev->status_lock){+.+.}-{3:3}, at:
hub_event+0x106c/0x1ec0 drivers/usb/core/hub.c:5716
 #4: ffff88800e0fbba8 (hcd->address0_mutex){+.+.}-{3:3}, at:
hub_port_init+0x83/0x1060 drivers/usb/core/hub.c:4703

=============================================

NMI backtrace for cpu 2
CPU: 2 PID: 1673 Comm: khungtaskd Not tainted 5.14.0+ #15
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014
Call Trace:
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x8d/0xcf lib/dump_stack.c:105
 nmi_cpu_backtrace+0x1e9/0x210 lib/nmi_backtrace.c:105
 nmi_trigger_cpumask_backtrace+0x120/0x180 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline]
 watchdog+0x4e1/0x980 kernel/hung_task.c:295
 kthread+0x178/0x1b0 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
Sending NMI from CPU 2 to CPUs 0-1,3:
NMI backtrace for cpu 3 skipped: idling at native_safe_halt
arch/x86/include/asm/irqflags.h:51 [inline]
NMI backtrace for cpu 3 skipped: idling at arch_safe_halt
arch/x86/include/asm/irqflags.h:89 [inline]
NMI backtrace for cpu 3 skipped: idling at default_idle+0xb/0x10
arch/x86/kernel/process.c:716
NMI backtrace for cpu 0
CPU: 0 PID: 4919 Comm: systemd-journal Not tainted 5.14.0+ #15
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014
RIP: 0033:0x7f64cb4fd944
Code: ff 0f 1f 44 00 00 41 54 55 53 48 83 ec 40 64 48 8b 04 25 28 00
00 00 48 89 44 24 38 31 c0 48 85 ff 48 c7 44 24 10 00 00 00 00 <48> c7
44 24 18 00 00 00 00 48 c7 44 24 20 00 00 00 00 48 c7 44 24
RSP: 002b:00007ffefbc47ab0 EFLAGS: 00000202
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 000056107dab12a0 RDI: 000056107dab11e0
RBP: 000056107dab11e0 R08: 00007ffefbd3f080 R09: 00007ffefbd3f080
R10: 00000000000288c8 R11: 0000000000000202 R12: 00007f64cb56e548
R13: 00007f64cb55b147 R14: 00007f64cb5b8800 R15: 0005cb8a5495d061
FS:  00007f64cb8588c0 GS:  0000000000000000
NMI backtrace for cpu 1
CPU: 1 PID: 8140 Comm: rs:main Q:Reg Not tainted 5.14.0+ #15
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014
RIP: 0010:lockdep_enabled kernel/locking/lockdep.c:91 [inline]
RIP: 0010:lock_is_held_type+0x4c/0x140 kernel/locking/lockdep.c:5661
Code: f3 dc 7b 85 c0 74 12 48 83 c4 08 44 89 e8 5b 5d 41 5c 41 5d 41
5e 41 5f c3 65 4c 8b 24 25 40 70 01 00 41 8b 94 24 f4 09 00 00 <85> d2
75 d9 41 89 f6 48 89 fd 9c 8f 04 24 fa 48 c7 c7 d0 46 5d 85
RSP: 0018:ffffc90006a07e20 EFLAGS: 00000046
RAX: 0000000000000000 RBX: 0000000000000001 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffffffff85a1d4a0
RBP: 0000000000000000 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff88810ba48000
R13: 00000000ffffffff R14: 0000000000000000 R15: 0000000000000000
FS:  00007f672594b700(0000) GS:ffff88813dc00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f64c670c000 CR3: 00000001052a5000 CR4: 0000000000750ee0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
 lock_is_held include/linux/lockdep.h:283 [inline]
 rcu_read_lock_sched_held+0x4d/0x80 kernel/rcu/update.c:125
 trace_lock_acquire include/trace/events/lock.h:13 [inline]
 lock_acquire+0x2b7/0x340 kernel/locking/lockdep.c:5596
 do_write_seqcount_begin_nested include/linux/seqlock.h:520 [inline]
 do_write_seqcount_begin include/linux/seqlock.h:545 [inline]
 vtime_user_exit+0x50/0xe0 kernel/sched/cputime.c:719
 __context_tracking_exit+0x88/0x1f0 kernel/context_tracking.c:160
 user_exit_irqoff include/linux/context_tracking.h:47 [inline]
 __enter_from_user_mode kernel/entry/common.c:22 [inline]
 syscall_enter_from_user_mode+0x4a/0x70 kernel/entry/common.c:104
 do_syscall_64+0x15/0xb0 arch/x86/entry/common.c:76
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f672838f1cd
Code: c2 20 00 00 75 10 b8 01 00 00 00 0f 05 48 3d 01 f0 ff ff 73 31
c3 48 83 ec 08 e8 ae fc ff ff 48 89 04 24 b8 01 00 00 00 0f 05 <48> 8b
3c 24 48 89 c2 e8 f7 fc ff ff 48 89 d0 48 83 c4 08 48 3d 01
RSP: 002b:00007f672594a590 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f671c025620 RCX: 00007f672838f1cd
RDX: 00000000000005fc RSI: 00007f671c025620 RDI: 0000000000000008
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 00007f671c0253a0
R13: 00007f672594a5b0 R14: 000055ff62a4b440 R15: 00000000000005fc
----------------
Code disassembly (best guess), 3 bytes skipped:
   0: 85 c0                test   %eax,%eax
   2: 74 12                je     0x16
   4: 48 83 c4 08          add    $0x8,%rsp
   8: 44 89 e8              mov    %r13d,%eax
   b: 5b                    pop    %rbx
   c: 5d                    pop    %rbp
   d: 41 5c                pop    %r12
   f: 41 5d                pop    %r13
  11: 41 5e                pop    %r14
  13: 41 5f                pop    %r15
  15: c3                    retq
  16: 65 4c 8b 24 25 40 70 mov    %gs:0x17040,%r12
  1d: 01 00
  1f: 41 8b 94 24 f4 09 00 mov    0x9f4(%r12),%edx
  26: 00
* 27: 85 d2                test   %edx,%edx <-- trapping instruction
  29: 75 d9                jne    0x4
  2b: 41 89 f6              mov    %esi,%r14d
  2e: 48 89 fd              mov    %rdi,%rbp
  31: 9c                    pushfq
  32: 8f 04 24              popq   (%rsp)
  35: fa                    cli
  36: 48 c7 c7 d0 46 5d 85 mov    $0xffffffff855d46d0,%rdi

Re: INFO: task hung in hub_port_init

[Alan Stern]

On Mon, Sep 13, 2021 at 11:13:15AM +0800, Hao Sun wrote:
> Hello,
> 
> When using Healer to fuzz the Linux kernel, the following crash was triggered.
> 
> HEAD commit: ac08b1c68d1b Merge tag 'pci-v5.15-changes'
> git tree: upstream
> console output:
> https://drive.google.com/file/d/1ZeDIMe-DoY3fB32j2p5ifgpq-Lc5N74I/view?usp=sharing
> kernel config: https://drive.google.com/file/d/1qrJUXD8ZIeAkg-xojzDpp04v9MtQ8RR6/view?usp=sharing
> Syzlang reproducer:
> https://drive.google.com/file/d/1tZe8VmXfxoPqlNpzpGOd-e5WCSWgbkxB/view?usp=sharing
> Similar report:
> https://groups.google.com/g/syzkaller-bugs/c/zX55CUzjBOY/m/uf91r0XqAgAJ
> 
> Sorry, I don't have a C reproducer for this crash but have a Syzlang
> reproducer. Also, hope the symbolized report can help.
> Here are the instructions on how to execute Syzlang prog:
> https://github.com/google/syzkaller/blob/master/docs/executing_syzkaller_programs.md
> 
> If you fix this issue, please add the following tag to the commit:
> Reported-by: Hao Sun <sunhao.th@gmail.com>

There's not much hope of finding the cause of a problem like this 
without seeing the kernel log.

Alan Stern

Re: INFO: task hung in hub_port_init

[Hao Sun]

Hi Alan,

Alan Stern <stern@rowland.harvard.edu> 于2021年9月13日周一 下午9:55写道：
>
> On Mon, Sep 13, 2021 at 11:13:15AM +0800, Hao Sun wrote:
> > Hello,
> >
> > When using Healer to fuzz the Linux kernel, the following crash was triggered.
> >
> > HEAD commit: ac08b1c68d1b Merge tag 'pci-v5.15-changes'
> > git tree: upstream
> > console output:
> > https://drive.google.com/file/d/1ZeDIMe-DoY3fB32j2p5ifgpq-Lc5N74I/view?usp=sharing
> > kernel config: https://drive.google.com/file/d/1qrJUXD8ZIeAkg-xojzDpp04v9MtQ8RR6/view?usp=sharing
> > Syzlang reproducer:
> > https://drive.google.com/file/d/1tZe8VmXfxoPqlNpzpGOd-e5WCSWgbkxB/view?usp=sharing
> > Similar report:
> > https://groups.google.com/g/syzkaller-bugs/c/zX55CUzjBOY/m/uf91r0XqAgAJ
> >
> > Sorry, I don't have a C reproducer for this crash but have a Syzlang
> > reproducer. Also, hope the symbolized report can help.
> > Here are the instructions on how to execute Syzlang prog:
> > https://github.com/google/syzkaller/blob/master/docs/executing_syzkaller_programs.md
> >
> > If you fix this issue, please add the following tag to the commit:
> > Reported-by: Hao Sun <sunhao.th@gmail.com>
>
> There's not much hope of finding the cause of a problem like this
> without seeing the kernel log.
>

Healer found another Syzlang prog to reproduce this task hang:
https://paste.ubuntu.com/p/HCNYbKJYtx/

Also here is a very simple script to execute the reproducer:
https://paste.ubuntu.com/p/ZTGmvFSP6d/

The `syz-execprog` and `syz-executor` are needed, so please build
Syzkaller first before running the script.
Hope this can help to find the root cause of the problem.

Regards
Hao

Re: INFO: task hung in hub_port_init

[Alan Stern]

On Sat, Sep 18, 2021 at 09:56:52AM +0800, Hao Sun wrote:
> Hi Alan,
> 
> Alan Stern <stern@rowland.harvard.edu> 于2021年9月13日周一 下午9:55写道：
> >
> > On Mon, Sep 13, 2021 at 11:13:15AM +0800, Hao Sun wrote:
> > > Hello,
> > >
> > > When using Healer to fuzz the Linux kernel, the following crash was triggered.
> > >
> > > HEAD commit: ac08b1c68d1b Merge tag 'pci-v5.15-changes'
> > > git tree: upstream
> > > console output:
> > > https://drive.google.com/file/d/1ZeDIMe-DoY3fB32j2p5ifgpq-Lc5N74I/view?usp=sharing
> > > kernel config: https://drive.google.com/file/d/1qrJUXD8ZIeAkg-xojzDpp04v9MtQ8RR6/view?usp=sharing
> > > Syzlang reproducer:
> > > https://drive.google.com/file/d/1tZe8VmXfxoPqlNpzpGOd-e5WCSWgbkxB/view?usp=sharing
> > > Similar report:
> > > https://groups.google.com/g/syzkaller-bugs/c/zX55CUzjBOY/m/uf91r0XqAgAJ
> > >
> > > Sorry, I don't have a C reproducer for this crash but have a Syzlang
> > > reproducer. Also, hope the symbolized report can help.
> > > Here are the instructions on how to execute Syzlang prog:
> > > https://github.com/google/syzkaller/blob/master/docs/executing_syzkaller_programs.md
> > >
> > > If you fix this issue, please add the following tag to the commit:
> > > Reported-by: Hao Sun <sunhao.th@gmail.com>
> >
> > There's not much hope of finding the cause of a problem like this
> > without seeing the kernel log.
> >
> 
> Healer found another Syzlang prog to reproduce this task hang:
> https://paste.ubuntu.com/p/HCNYbKJYtx/
> 
> Also here is a very simple script to execute the reproducer:
> https://paste.ubuntu.com/p/ZTGmvFSP6d/
> 
> The `syz-execprog` and `syz-executor` are needed, so please build
> Syzkaller first before running the script.
> Hope this can help to find the root cause of the problem.

I don't have time to install and figure out how to use Healer and 
Syzkaller.  But if you run the reproducer and post the kernel log, 
I'll take a look at it.

Alan Stern

Re: INFO: task hung in hub_port_init

[Hao Sun]

Alan Stern <stern@rowland.harvard.edu> 于2021年9月18日周六 上午10:02写道：
>
> On Sat, Sep 18, 2021 at 09:56:52AM +0800, Hao Sun wrote:
> > Hi Alan,
> >
> > Alan Stern <stern@rowland.harvard.edu> 于2021年9月13日周一 下午9:55写道：
> > >
> > > On Mon, Sep 13, 2021 at 11:13:15AM +0800, Hao Sun wrote:
> > > > Hello,
> > > >
> > > > When using Healer to fuzz the Linux kernel, the following crash was triggered.
> > > >
> > > > HEAD commit: ac08b1c68d1b Merge tag 'pci-v5.15-changes'
> > > > git tree: upstream
> > > > console output:
> > > > https://drive.google.com/file/d/1ZeDIMe-DoY3fB32j2p5ifgpq-Lc5N74I/view?usp=sharing
> > > > kernel config: https://drive.google.com/file/d/1qrJUXD8ZIeAkg-xojzDpp04v9MtQ8RR6/view?usp=sharing
> > > > Syzlang reproducer:
> > > > https://drive.google.com/file/d/1tZe8VmXfxoPqlNpzpGOd-e5WCSWgbkxB/view?usp=sharing
> > > > Similar report:
> > > > https://groups.google.com/g/syzkaller-bugs/c/zX55CUzjBOY/m/uf91r0XqAgAJ
> > > >
> > > > Sorry, I don't have a C reproducer for this crash but have a Syzlang
> > > > reproducer. Also, hope the symbolized report can help.
> > > > Here are the instructions on how to execute Syzlang prog:
> > > > https://github.com/google/syzkaller/blob/master/docs/executing_syzkaller_programs.md
> > > >
> > > > If you fix this issue, please add the following tag to the commit:
> > > > Reported-by: Hao Sun <sunhao.th@gmail.com>
> > >
> > > There's not much hope of finding the cause of a problem like this
> > > without seeing the kernel log.
> > >
> >
> > Healer found another Syzlang prog to reproduce this task hang:
> > https://paste.ubuntu.com/p/HCNYbKJYtx/
> >
> > Also here is a very simple script to execute the reproducer:
> > https://paste.ubuntu.com/p/ZTGmvFSP6d/
> >
> > The `syz-execprog` and `syz-executor` are needed, so please build
> > Syzkaller first before running the script.
> > Hope this can help to find the root cause of the problem.
>
> I don't have time to install and figure out how to use Healer and
> Syzkaller.  But if you run the reproducer and post the kernel log,
> I'll take a look at it.
>

Just executed the reproducer, here is the full log:
https://paste.ubuntu.com/p/x43SqQy8PX/

Hao

Re: INFO: task hung in hub_port_init

[Alan Stern]

On Sat, Sep 18, 2021 at 10:17:26AM +0800, Hao Sun wrote:
> Alan Stern <stern@rowland.harvard.edu> 于2021年9月18日周六 上午10:02写道：
> >
> > On Sat, Sep 18, 2021 at 09:56:52AM +0800, Hao Sun wrote:
> > > Hi Alan,
> > >
> > > Alan Stern <stern@rowland.harvard.edu> 于2021年9月13日周一 下午9:55写道：
> > > >
> > > > On Mon, Sep 13, 2021 at 11:13:15AM +0800, Hao Sun wrote:
> > > > > Hello,
> > > > >
> > > > > When using Healer to fuzz the Linux kernel, the following crash was triggered.
> > > > >
> > > > > HEAD commit: ac08b1c68d1b Merge tag 'pci-v5.15-changes'
> > > > > git tree: upstream
> > > > > console output:
> > > > > https://drive.google.com/file/d/1ZeDIMe-DoY3fB32j2p5ifgpq-Lc5N74I/view?usp=sharing
> > > > > kernel config: https://drive.google.com/file/d/1qrJUXD8ZIeAkg-xojzDpp04v9MtQ8RR6/view?usp=sharing
> > > > > Syzlang reproducer:
> > > > > https://drive.google.com/file/d/1tZe8VmXfxoPqlNpzpGOd-e5WCSWgbkxB/view?usp=sharing
> > > > > Similar report:
> > > > > https://groups.google.com/g/syzkaller-bugs/c/zX55CUzjBOY/m/uf91r0XqAgAJ
> > > > >
> > > > > Sorry, I don't have a C reproducer for this crash but have a Syzlang
> > > > > reproducer. Also, hope the symbolized report can help.
> > > > > Here are the instructions on how to execute Syzlang prog:
> > > > > https://github.com/google/syzkaller/blob/master/docs/executing_syzkaller_programs.md
> > > > >
> > > > > If you fix this issue, please add the following tag to the commit:
> > > > > Reported-by: Hao Sun <sunhao.th@gmail.com>
> > > >
> > > > There's not much hope of finding the cause of a problem like this
> > > > without seeing the kernel log.
> > > >
> > >
> > > Healer found another Syzlang prog to reproduce this task hang:
> > > https://paste.ubuntu.com/p/HCNYbKJYtx/
> > >
> > > Also here is a very simple script to execute the reproducer:
> > > https://paste.ubuntu.com/p/ZTGmvFSP6d/
> > >
> > > The `syz-execprog` and `syz-executor` are needed, so please build
> > > Syzkaller first before running the script.
> > > Hope this can help to find the root cause of the problem.
> >
> > I don't have time to install and figure out how to use Healer and
> > Syzkaller.  But if you run the reproducer and post the kernel log,
> > I'll take a look at it.
> >
> 
> Just executed the reproducer, here is the full log:
> https://paste.ubuntu.com/p/x43SqQy8PX/

The log indicates that the problem is related to the vhci-hcd driver 
somehow.  I don't know why those "Module has invalid ELF structures" 
errors keep appearing, starting in line 1946 of the log.

Alan Stern

Re: INFO: task hung in hub_port_init

[Shuah Khan]

On 9/18/21 7:53 AM, Alan Stern wrote:
> On Sat, Sep 18, 2021 at 10:17:26AM +0800, Hao Sun wrote:
>> Alan Stern <stern@rowland.harvard.edu> 于2021年9月18日周六 上午10:02写道：
>>>
>>> On Sat, Sep 18, 2021 at 09:56:52AM +0800, Hao Sun wrote:
>>>> Hi Alan,
>>>>
>>>> Alan Stern <stern@rowland.harvard.edu> 于2021年9月13日周一 下午9:55写道：
>>>>>
>>>>> On Mon, Sep 13, 2021 at 11:13:15AM +0800, Hao Sun wrote:
>>>>>> Hello,
>>>>>>
>>>>>> When using Healer to fuzz the Linux kernel, the following crash was triggered.
>>>>>>
>>>>>> HEAD commit: ac08b1c68d1b Merge tag 'pci-v5.15-changes'
>>>>>> git tree: upstream
>>>>>> console output:
>>>>>> https://drive.google.com/file/d/1ZeDIMe-DoY3fB32j2p5ifgpq-Lc5N74I/view?usp=sharing
>>>>>> kernel config: https://drive.google.com/file/d/1qrJUXD8ZIeAkg-xojzDpp04v9MtQ8RR6/view?usp=sharing
>>>>>> Syzlang reproducer:
>>>>>> https://drive.google.com/file/d/1tZe8VmXfxoPqlNpzpGOd-e5WCSWgbkxB/view?usp=sharing
>>>>>> Similar report:
>>>>>> https://groups.google.com/g/syzkaller-bugs/c/zX55CUzjBOY/m/uf91r0XqAgAJ
>>>>>>
>>>>>> Sorry, I don't have a C reproducer for this crash but have a Syzlang
>>>>>> reproducer. Also, hope the symbolized report can help.
>>>>>> Here are the instructions on how to execute Syzlang prog:
>>>>>> https://github.com/google/syzkaller/blob/master/docs/executing_syzkaller_programs.md
>>>>>>
>>>>>> If you fix this issue, please add the following tag to the commit:
>>>>>> Reported-by: Hao Sun <sunhao.th@gmail.com>
>>>>>
>>>>> There's not much hope of finding the cause of a problem like this
>>>>> without seeing the kernel log.
>>>>>
>>>>
>>>> Healer found another Syzlang prog to reproduce this task hang:
>>>> https://paste.ubuntu.com/p/HCNYbKJYtx/
>>>>
>>>> Also here is a very simple script to execute the reproducer:
>>>> https://paste.ubuntu.com/p/ZTGmvFSP6d/
>>>>
>>>> The `syz-execprog` and `syz-executor` are needed, so please build
>>>> Syzkaller first before running the script.
>>>> Hope this can help to find the root cause of the problem.
>>>
>>> I don't have time to install and figure out how to use Healer and
>>> Syzkaller.  But if you run the reproducer and post the kernel log,
>>> I'll take a look at it.
>>>
>>
>> Just executed the reproducer, here is the full log:
>> https://paste.ubuntu.com/p/x43SqQy8PX/
> 
> The log indicates that the problem is related to the vhci-hcd driver
> somehow.  I don't know why those "Module has invalid ELF structures"
> errors keep appearing, starting in line 1946 of the log.
> 
> Alan Stern
> 

Thank you. I will take a look.

thanks,
-- Shuah

Re: INFO: task hung in hub_port_init

[Shuah Khan]

Hi Hao Sun,

On 9/20/21 8:31 AM, Shuah Khan wrote:
> On 9/18/21 7:53 AM, Alan Stern wrote:
>> On Sat, Sep 18, 2021 at 10:17:26AM +0800, Hao Sun wrote:
>>> Alan Stern <stern@rowland.harvard.edu> 于2021年9月18日周六 上午10:02写道：
>>>>
>>>> On Sat, Sep 18, 2021 at 09:56:52AM +0800, Hao Sun wrote:
>>>>> Hi Alan,
>>>>>
>>>>> Alan Stern <stern@rowland.harvard.edu> 于2021年9月13日周一 下午9:55写道：
>>>>>>
>>>>>> On Mon, Sep 13, 2021 at 11:13:15AM +0800, Hao Sun wrote:
>>>>>>> Hello,
>>>>>>>
>>>>>>> When using Healer to fuzz the Linux kernel, the following crash was triggered.
>>>>>>>
>>>>>>> HEAD commit: ac08b1c68d1b Merge tag 'pci-v5.15-changes'
>>>>>>> git tree: upstream
>>>>>>> console output:
>>>>>>> https://drive.google.com/file/d/1ZeDIMe-DoY3fB32j2p5ifgpq-Lc5N74I/view?usp=sharing
>>>>>>> kernel config: https://drive.google.com/file/d/1qrJUXD8ZIeAkg-xojzDpp04v9MtQ8RR6/view?usp=sharing
>>>>>>> Syzlang reproducer:
>>>>>>> https://drive.google.com/file/d/1tZe8VmXfxoPqlNpzpGOd-e5WCSWgbkxB/view?usp=sharing
>>>>>>> Similar report:
>>>>>>> https://groups.google.com/g/syzkaller-bugs/c/zX55CUzjBOY/m/uf91r0XqAgAJ
>>>>>>>
>>>>>>> Sorry, I don't have a C reproducer for this crash but have a Syzlang
>>>>>>> reproducer. Also, hope the symbolized report can help.
>>>>>>> Here are the instructions on how to execute Syzlang prog:
>>>>>>> https://github.com/google/syzkaller/blob/master/docs/executing_syzkaller_programs.md
>>>>>>>
>>>>>>> If you fix this issue, please add the following tag to the commit:
>>>>>>> Reported-by: Hao Sun <sunhao.th@gmail.com>
>>>>>>
>>>>>> There's not much hope of finding the cause of a problem like this
>>>>>> without seeing the kernel log.
>>>>>>
>>>>>
>>>>> Healer found another Syzlang prog to reproduce this task hang:
>>>>> https://paste.ubuntu.com/p/HCNYbKJYtx/
>>>>>
>>>>> Also here is a very simple script to execute the reproducer:
>>>>> https://paste.ubuntu.com/p/ZTGmvFSP6d/
>>>>>
>>>>> The `syz-execprog` and `syz-executor` are needed, so please build
>>>>> Syzkaller first before running the script.
>>>>> Hope this can help to find the root cause of the problem.
>>>>
>>>> I don't have time to install and figure out how to use Healer and
>>>> Syzkaller.  But if you run the reproducer and post the kernel log,
>>>> I'll take a look at it.
>>>>
>>>
>>> Just executed the reproducer, here is the full log:
>>> https://paste.ubuntu.com/p/x43SqQy8PX/
>>
>> The log indicates that the problem is related to the vhci-hcd driver
>> somehow.  I don't know why those "Module has invalid ELF structures"
>> errors keep appearing, starting in line 1946 of the log.
>>

Can you send me your config? This message is rather odd.

[   82.249631][ T6679] Module has invalid ELF structures

It is right below:
[   82.248529][ T6679] vhci_hcd vhci_hcd.0: Device attached

or

[   83.860819][ T6710] vhci_hcd vhci_hcd.0: port 0 already used

My guess is this isn't the vhci_hcd module that gets loaded at this
point when we see this message, but another module that gets loaded
when vhci_hcd initiates probe after device attach. Note that vhci_hcd
is loaded earlier.

It is possible, the hung task might be related to load_module()
failure. Unfortunately load_module() doesn't print elf_validity_check()
error.

Would you be able to add this patch and run the reproducer again?


--------------------------------------------------------------------
diff --git a/kernel/module.c b/kernel/module.c
index 40ec9a030eec..02f758b04f05 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -3941,7 +3941,8 @@ static int load_module(struct load_info *info, const char __user *uargs,
          */
         err = elf_validity_check(info);
         if (err) {
-               pr_err("Module has invalid ELF structures\n");
+               pr_err("Module has invalid ELF structures error (%ld)\n",
+                       err);
                 goto free_copy;
         }

--------------------------------------------------------------------

thanks,
-- Shuah

Re: INFO: task hung in hub_port_init

[Andrey Konovalov]

On Tue, Oct 6, 2020 at 10:56 AM Oliver Neukum <oneukum@suse.de> wrote:
>
> > bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=152bb760500000
> > final oops:     https://syzkaller.appspot.com/x/report.txt?x=172bb760500000
> > console output: https://syzkaller.appspot.com/x/log.txt?x=132bb760500000
> >
> > IMPORTANT: if you fix the issue, please add the following tag to the commit:
> > Reported-by: syzbot+74d6ef051d3d2eacf428@syzkaller.appspotmail.com
> > Fixes: 6dcf45e51497 ("sh_eth: use correct name for ECMR_MPDE bit")
> >
> > INFO: task kworker/0:0:5 blocked for more than 143 seconds.
> >       Not tainted 5.9.0-rc7-syzkaller #0
> > "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > task:kworker/0:0     state:D stack:27664 pid:    5 ppid:     2 flags:0x00004000
> > Workqueue: usb_hub_wq hub_event
> > Call Trace:
> >  context_switch kernel/sched/core.c:3778 [inline]
> >  __schedule+0xec9/0x2280 kernel/sched/core.c:4527
> >  schedule+0xd0/0x2a0 kernel/sched/core.c:4602
>
> By this time urb_dequeue() has been killed and has returned.
>
> >  usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:696
> >  usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:691
> >  usb_start_wait_urb+0x24a/0x2b0 drivers/usb/core/message.c:64
> >  usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
> >  usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:153
> >  hub_port_init+0x11ae/0x2d80 drivers/usb/core/hub.c:4689
> >  hub_port_connect drivers/usb/core/hub.c:5140 [inline]
> >  hub_port_connect_change drivers/usb/core/hub.c:5348 [inline]
> >  port_event drivers/usb/core/hub.c:5494 [inline]
> >
>
> This looks like it should.
>
> Which HC driver are you using for these tests?

Hi Oliver,

This is the USB/IP one, based on what I see in the reproducer.

Thanks!

> It looks like
> the HCD is not acting on urb_dequeue(), rather than a locking
> issue.

Re: INFO: task hung in hub_port_init

[Oliver Neukum]

Am Dienstag, den 06.10.2020, 01:19 -0700 schrieb syzbot:

Hi,

> HEAD commit:    d3d45f82 Merge tag 'pinctrl-v5.9-2' of git://git.kernel.or..
> git tree:       upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=14c3b3db900000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=89ab6a0c48f30b49
> dashboard link: https://syzkaller.appspot.com/bug?extid=74d6ef051d3d2eacf428
> compiler:       gcc (GCC) 10.1.0-syz 20200507
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=153bf5bd900000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=124c92af900000
> 
> The issue was bisected to:
> 
> commit 6dcf45e514974a1ff10755015b5e06746a033e5f
> Author: Niklas Söderlund <niklas.soderlund+renesas@ragnatech.se>
> Date:   Mon Jan 9 15:34:04 2017 +0000
> 
>     sh_eth: use correct name for ECMR_MPDE bit

I am afraid this has bisected a race condition into neverland.

> bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=152bb760500000
> final oops:     https://syzkaller.appspot.com/x/report.txt?x=172bb760500000
> console output: https://syzkaller.appspot.com/x/log.txt?x=132bb760500000
> 
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+74d6ef051d3d2eacf428@syzkaller.appspotmail.com
> Fixes: 6dcf45e51497 ("sh_eth: use correct name for ECMR_MPDE bit")
> 
> INFO: task kworker/0:0:5 blocked for more than 143 seconds.
>       Not tainted 5.9.0-rc7-syzkaller #0
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:kworker/0:0     state:D stack:27664 pid:    5 ppid:     2 flags:0x00004000
> Workqueue: usb_hub_wq hub_event
> Call Trace:
>  context_switch kernel/sched/core.c:3778 [inline]
>  __schedule+0xec9/0x2280 kernel/sched/core.c:4527
>  schedule+0xd0/0x2a0 kernel/sched/core.c:4602

By this time urb_dequeue() has been killed and has returned.

>  usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:696
>  usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:691
>  usb_start_wait_urb+0x24a/0x2b0 drivers/usb/core/message.c:64
>  usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
>  usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:153
>  hub_port_init+0x11ae/0x2d80 drivers/usb/core/hub.c:4689
>  hub_port_connect drivers/usb/core/hub.c:5140 [inline]
>  hub_port_connect_change drivers/usb/core/hub.c:5348 [inline]
>  port_event drivers/usb/core/hub.c:5494 [inline]
> 

This looks like it should.

Which HC driver are you using for these tests? It looks like
the HCD is not acting on urb_dequeue(), rather than a locking
issue.

	Regards
		Oliver

INFO: task hung in hub_port_init

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit:    d3d45f82 Merge tag 'pinctrl-v5.9-2' of git://git.kernel.or..
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=14c3b3db900000
kernel config:  https://syzkaller.appspot.com/x/.config?x=89ab6a0c48f30b49
dashboard link: https://syzkaller.appspot.com/bug?extid=74d6ef051d3d2eacf428
compiler:       gcc (GCC) 10.1.0-syz 20200507
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=153bf5bd900000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=124c92af900000

The issue was bisected to:

commit 6dcf45e514974a1ff10755015b5e06746a033e5f
Author: Niklas Söderlund <niklas.soderlund+renesas@ragnatech.se>
Date:   Mon Jan 9 15:34:04 2017 +0000

    sh_eth: use correct name for ECMR_MPDE bit

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=152bb760500000
final oops:     https://syzkaller.appspot.com/x/report.txt?x=172bb760500000
console output: https://syzkaller.appspot.com/x/log.txt?x=132bb760500000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+74d6ef051d3d2eacf428@syzkaller.appspotmail.com
Fixes: 6dcf45e51497 ("sh_eth: use correct name for ECMR_MPDE bit")

INFO: task kworker/0:0:5 blocked for more than 143 seconds.
      Not tainted 5.9.0-rc7-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/0:0     state:D stack:27664 pid:    5 ppid:     2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
 context_switch kernel/sched/core.c:3778 [inline]
 __schedule+0xec9/0x2280 kernel/sched/core.c:4527
 schedule+0xd0/0x2a0 kernel/sched/core.c:4602
 usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:696
 usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:691
 usb_start_wait_urb+0x24a/0x2b0 drivers/usb/core/message.c:64
 usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
 usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:153
 hub_port_init+0x11ae/0x2d80 drivers/usb/core/hub.c:4689
 hub_port_connect drivers/usb/core/hub.c:5140 [inline]
 hub_port_connect_change drivers/usb/core/hub.c:5348 [inline]
 port_event drivers/usb/core/hub.c:5494 [inline]
 hub_event+0x1e64/0x3e60 drivers/usb/core/hub.c:5576
 process_one_work+0x94c/0x1670 kernel/workqueue.c:2269
 process_scheduled_works kernel/workqueue.c:2331 [inline]
 worker_thread+0x82b/0x1120 kernel/workqueue.c:2417
 kthread+0x3b5/0x4a0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
INFO: task kworker/1:2:2641 blocked for more than 144 seconds.
      Not tainted 5.9.0-rc7-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:2     state:D stack:26992 pid: 2641 ppid:     2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
 context_switch kernel/sched/core.c:3778 [inline]
 __schedule+0xec9/0x2280 kernel/sched/core.c:4527
 schedule+0xd0/0x2a0 kernel/sched/core.c:4602
 usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:696
 usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:691
 usb_start_wait_urb+0x24a/0x2b0 drivers/usb/core/message.c:64
 usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
 usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:153
 usb_get_descriptor+0xc5/0x1b0 drivers/usb/core/message.c:655
 usb_get_device_descriptor+0x81/0xf0 drivers/usb/core/message.c:927
 hub_port_init+0x78f/0x2d80 drivers/usb/core/hub.c:4784
 hub_port_connect drivers/usb/core/hub.c:5140 [inline]
 hub_port_connect_change drivers/usb/core/hub.c:5348 [inline]
 port_event drivers/usb/core/hub.c:5494 [inline]
 hub_event+0x1e64/0x3e60 drivers/usb/core/hub.c:5576
 process_one_work+0x94c/0x1670 kernel/workqueue.c:2269
 worker_thread+0x64c/0x1120 kernel/workqueue.c:2415
 kthread+0x3b5/0x4a0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
INFO: task kworker/1:1:6862 blocked for more than 146 seconds.
      Not tainted 5.9.0-rc7-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:1     state:D stack:26864 pid: 6862 ppid:     2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
 context_switch kernel/sched/core.c:3778 [inline]
 __schedule+0xec9/0x2280 kernel/sched/core.c:4527
 schedule+0xd0/0x2a0 kernel/sched/core.c:4602
 usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:696
 usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:691
 usb_start_wait_urb+0x24a/0x2b0 drivers/usb/core/message.c:64
 usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
 usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:153
 hub_port_init+0x11ae/0x2d80 drivers/usb/core/hub.c:4689
 hub_port_connect drivers/usb/core/hub.c:5140 [inline]
 hub_port_connect_change drivers/usb/core/hub.c:5348 [inline]
 port_event drivers/usb/core/hub.c:5494 [inline]
 hub_event+0x1e64/0x3e60 drivers/usb/core/hub.c:5576
 process_one_work+0x94c/0x1670 kernel/workqueue.c:2269
 worker_thread+0x64c/0x1120 kernel/workqueue.c:2415
 kthread+0x3b5/0x4a0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
INFO: task kworker/0:1:6870 blocked for more than 148 seconds.
      Not tainted 5.9.0-rc7-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/0:1     state:D stack:27416 pid: 6870 ppid:     2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
 context_switch kernel/sched/core.c:3778 [inline]
 __schedule+0xec9/0x2280 kernel/sched/core.c:4527
 schedule+0xd0/0x2a0 kernel/sched/core.c:4602
 usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:696
 usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:691
 usb_start_wait_urb+0x24a/0x2b0 drivers/usb/core/message.c:64
 usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
 usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:153
 usb_get_descriptor+0xc5/0x1b0 drivers/usb/core/message.c:655
 usb_get_device_descriptor+0x81/0xf0 drivers/usb/core/message.c:927
 hub_port_init+0x78f/0x2d80 drivers/usb/core/hub.c:4784
 hub_port_connect drivers/usb/core/hub.c:5140 [inline]
 hub_port_connect_change drivers/usb/core/hub.c:5348 [inline]
 port_event drivers/usb/core/hub.c:5494 [inline]
 hub_event+0x1e64/0x3e60 drivers/usb/core/hub.c:5576
 process_one_work+0x94c/0x1670 kernel/workqueue.c:2269
 worker_thread+0x64c/0x1120 kernel/workqueue.c:2415
 kthread+0x3b5/0x4a0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
INFO: task kworker/1:3:6898 blocked for more than 150 seconds.
      Not tainted 5.9.0-rc7-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:3     state:D stack:27256 pid: 6898 ppid:     2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
 context_switch kernel/sched/core.c:3778 [inline]
 __schedule+0xec9/0x2280 kernel/sched/core.c:4527
 schedule+0xd0/0x2a0 kernel/sched/core.c:4602
 usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:696
 usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:691
 usb_start_wait_urb+0x24a/0x2b0 drivers/usb/core/message.c:64
 usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
 usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:153
 usb_get_descriptor+0xc5/0x1b0 drivers/usb/core/message.c:655
 usb_get_device_descriptor+0x81/0xf0 drivers/usb/core/message.c:927
 hub_port_init+0x78f/0x2d80 drivers/usb/core/hub.c:4784
 hub_port_connect drivers/usb/core/hub.c:5140 [inline]
 hub_port_connect_change drivers/usb/core/hub.c:5348 [inline]
 port_event drivers/usb/core/hub.c:5494 [inline]
 hub_event+0x1e64/0x3e60 drivers/usb/core/hub.c:5576
 process_one_work+0x94c/0x1670 kernel/workqueue.c:2269
 worker_thread+0x64c/0x1120 kernel/workqueue.c:2415
 kthread+0x3b5/0x4a0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294

Showing all locks held in the system:
5 locks held by kworker/0:0/5:
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic64_set include/asm-generic/atomic-instrumented.h:856 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/asm-generic/atomic-long.h:41 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:616 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:643 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x82b/0x1670 kernel/workqueue.c:2240
 #1: ffffc90000cbfda8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x85f/0x1670 kernel/workqueue.c:2244
 #2: ffff88809e17a218 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:785 [inline]
 #2: ffff88809e17a218 (&dev->mutex){....}-{3:3}, at: hub_event+0x1b6/0x3e60 drivers/usb/core/hub.c:5522
 #3: ffff88809e163588 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3012 [inline]
 #3: ffff88809e163588 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect drivers/usb/core/hub.c:5139 [inline]
 #3: ffff88809e163588 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect_change drivers/usb/core/hub.c:5348 [inline]
 #3: ffff88809e163588 (&port_dev->status_lock){+.+.}-{3:3}, at: port_event drivers/usb/core/hub.c:5494 [inline]
 #3: ffff88809e163588 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_event+0x1e4f/0x3e60 drivers/usb/core/hub.c:5576
 #4: ffff888217aea068 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_init+0x1b6/0x2d80 drivers/usb/core/hub.c:4563
2 locks held by kworker/u4:4/208:
1 lock held by khungtaskd/1167:
 #0: ffffffff8a067f40 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:5852
5 locks held by kworker/1:2/2641:
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic64_set include/asm-generic/atomic-instrumented.h:856 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/asm-generic/atomic-long.h:41 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:616 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:643 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x82b/0x1670 kernel/workqueue.c:2240
 #1: ffffc90008de7da8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x85f/0x1670 kernel/workqueue.c:2244
 #2: ffff88809e5de218 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:785 [inline]
 #2: ffff88809e5de218 (&dev->mutex){....}-{3:3}, at: hub_event+0x1b6/0x3e60 drivers/usb/core/hub.c:5522
 #3: ffff88809e594588 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3012 [inline]
 #3: ffff88809e594588 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect drivers/usb/core/hub.c:5139 [inline]
 #3: ffff88809e594588 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect_change drivers/usb/core/hub.c:5348 [inline]
 #3: ffff88809e594588 (&port_dev->status_lock){+.+.}-{3:3}, at: port_event drivers/usb/core/hub.c:5494 [inline]
 #3: ffff88809e594588 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_event+0x1e4f/0x3e60 drivers/usb/core/hub.c:5576
 #4: ffff888217ba0c68 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_init+0x1b6/0x2d80 drivers/usb/core/hub.c:4563
1 lock held by in:imklog/6751:
 #0: ffff8880a25dc3f0 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:930
5 locks held by kworker/1:1/6862:
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic64_set include/asm-generic/atomic-instrumented.h:856 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/asm-generic/atomic-long.h:41 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:616 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:643 [inline]
 #0: ffff8880a62d8538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x82b/0x1670 kernel/workqueue.c:2240
 #1: ffffc900056b7da8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x85f/0x1670 kernel/workqueue.c:2244
 #2: ffff88809e2f5218 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:785 [inline]
 #2: ffff88809e2f5218 (&dev->mutex){....}-{3:3}, at: hub_event+0x1b6/0x3e60 drivers/usb/core/hub.c:5522
 #3: ffff888217ac8588 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3012 [inline]
 #3: ffff888217ac8588 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect drivers/usb/core/hub.c:5139 [inline]
 #3: ffff888217ac8588 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect_change drivers/usb/core/hub.c:5348 [inline]
 #3: ffff888217ac8588 (&port_dev->status_lock){+.+.}-{3:3}, at: port_event drivers/usb/core/hub.c:5494 [inline]
 #3: ffff888217ac8588 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_event+0x1e4f/0x3e60 drivers/usb/core/hub.c:5576
 #4: ffff888217a6c268 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_init+0x1b6/0x2d80 drivers/usb/core/hub.c:4563
5 locks held by kworker/0:1/6870:


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzkaller@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
For information about bisection process see: https://goo.gl/tpsmEJ#bisection
syzbot can test patches for this issue, for details see:
https://goo.gl/tpsmEJ#testing-patches