2021-11-16 02:49:49

by syzbot

[permalink] [raw]
Subject: [syzbot] INFO: task hung in hub_port_init (2)

Hello,

syzbot found the following issue on:

HEAD commit: 8ab774587903 Merge tag 'trace-v5.16-5' of git://git.kernel..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=12a6b6d1b00000
kernel config: https://syzkaller.appspot.com/x/.config?x=6c3ab72998e7f1a4
dashboard link: https://syzkaller.appspot.com/bug?extid=76629376e06e2c2ad626
compiler: Debian clang version 11.0.1-2, GNU ld (GNU Binutils for Debian) 2.35.2

Unfortunately, I don't have any reproducer for this issue yet.

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: [email protected]

INFO: task kworker/1:4:7960 blocked for more than 143 seconds.
Not tainted 5.16.0-rc1-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:4 state:D stack:23576 pid: 7960 ppid: 2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4972 [inline]
__schedule+0xb72/0x1460 kernel/sched/core.c:6253
schedule+0x12b/0x1f0 kernel/sched/core.c:6326
usb_kill_urb+0x1d5/0x310 drivers/usb/core/urb.c:720
usb_start_wait_urb+0x265/0x530 drivers/usb/core/message.c:64
usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
usb_control_msg+0x2a5/0x4b0 drivers/usb/core/message.c:153
hub_port_init+0x9f1/0x2df0 drivers/usb/core/hub.c:4829
hub_port_connect+0xcf8/0x27d0 drivers/usb/core/hub.c:5280
hub_port_connect_change+0x5f9/0xc20 drivers/usb/core/hub.c:5488
port_event+0xb67/0x1220 drivers/usb/core/hub.c:5634
hub_event+0x4ed/0xe40 drivers/usb/core/hub.c:5716
process_one_work+0x853/0x1140 kernel/workqueue.c:2298
worker_thread+0xac1/0x1320 kernel/workqueue.c:2445
kthread+0x468/0x490 kernel/kthread.c:327
ret_from_fork+0x1f/0x30
</TASK>

Showing all locks held in the system:
3 locks held by kworker/u4:0/8:
1 lock held by khungtaskd/27:
#0: ffffffff8cd1da80 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
1 lock held by in:imklog/6200:
#0: ffff8880715914f0 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x24e/0x2f0 fs/file.c:990
2 locks held by agetty/6229:
#0: ffff888024550098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x21/0x70 drivers/tty/tty_ldisc.c:252
#1: ffffc900028dc2e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6c5/0x1c60 drivers/tty/n_tty.c:2113
5 locks held by kworker/1:4/7960:
#0: ffff888016717538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x7ca/0x1140
#1: ffffc9000c1bfd20 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x808/0x1140 kernel/workqueue.c:2273
#2: ffff888147758220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#2: ffff888147758220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1b2/0xe40 drivers/usb/core/hub.c:5662
#3: ffff88814775c5c0 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3086 [inline]
#3: ffff88814775c5c0 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect+0xce1/0x27d0 drivers/usb/core/hub.c:5279
#4: ffff888147701168 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_init+0x1ef/0x2df0 drivers/usb/core/hub.c:4703
1 lock held by syz-executor.0/16819:
2 locks held by syz-executor.4/16820:
1 lock held by syz-executor.1/16824:

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

NMI backtrace for cpu 1
CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.16.0-rc1-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x1dc/0x2d8 lib/dump_stack.c:106
nmi_cpu_backtrace+0x45f/0x490 lib/nmi_backtrace.c:105
nmi_trigger_cpumask_backtrace+0x16a/0x280 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+0xc82/0xcd0 kernel/hung_task.c:295
kthread+0x468/0x490 kernel/kthread.c:327
ret_from_fork+0x1f/0x30
</TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 16715 Comm: kworker/u4:4 Not tainted 5.16.0-rc1-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: phy8 ieee80211_iface_work
RIP: 0010:unwind_done arch/x86/include/asm/unwind.h:50 [inline]
RIP: 0010:__unwind_start+0x61a/0x750 arch/x86/kernel/unwind_orc.c:709
Code: e8 5b 79 95 00 48 8b 44 24 10 48 39 03 0f 83 d4 fa ff ff 4c 89 f7 e8 35 da ff ff 48 b8 00 00 00 00 00 fc ff df 0f b6 44 05 00 <84> c0 75 2d 41 83 3e 00 0f 85 38 ff ff ff e9 aa fa ff ff 44 89 f1
RSP: 0018:ffffc90001b3f3b8 EFLAGS: 00000292
RAX: 0000000000000000 RBX: ffffc90001b3f458 RCX: 0000000080000000
RDX: ffffc90001b3f3b8 RSI: 0000000000000001 RDI: 0000000000000001
RBP: 1ffff92000367e84 R08: dffffc0000000000 R09: ffffc90001b3f470
R10: fffff52000367e90 R11: 0000000000000000 R12: 1ffff92000367e86
R13: ffffc90001b38000 R14: ffffc90001b3f420 R15: ffffc90001b3f428
FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fd4386b03a4 CR3: 000000003a2bd000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000600
Call Trace:
<TASK>
unwind_start arch/x86/include/asm/unwind.h:64 [inline]
arch_stack_walk+0xdc/0x140 arch/x86/kernel/stacktrace.c:24
stack_trace_save+0x11b/0x1e0 kernel/stacktrace.c:122
kasan_save_stack mm/kasan/common.c:38 [inline]
kasan_set_track mm/kasan/common.c:46 [inline]
set_alloc_info mm/kasan/common.c:434 [inline]
____kasan_kmalloc+0xdc/0x110 mm/kasan/common.c:513
kasan_kmalloc include/linux/kasan.h:269 [inline]
kmem_cache_alloc_trace+0x9d/0x330 mm/slub.c:3261
kmalloc include/linux/slab.h:590 [inline]
kzalloc include/linux/slab.h:724 [inline]
ieee802_11_parse_elems_crc+0xc7/0x1040 net/mac80211/util.c:1471
ieee802_11_parse_elems net/mac80211/ieee80211_i.h:2208 [inline]
ieee80211_rx_mgmt_probe_beacon net/mac80211/ibss.c:1605 [inline]
ieee80211_ibss_rx_queued_mgmt+0x389/0x2b30 net/mac80211/ibss.c:1639
ieee80211_iface_process_skb net/mac80211/iface.c:1466 [inline]
ieee80211_iface_work+0x709/0xc90 net/mac80211/iface.c:1520
process_one_work+0x853/0x1140 kernel/workqueue.c:2298
worker_thread+0xac1/0x1320 kernel/workqueue.c:2445
kthread+0x468/0x490 kernel/kthread.c:327
ret_from_fork+0x1f/0x30
</TASK>
----------------
Code disassembly (best guess):
0: e8 5b 79 95 00 callq 0x957960
5: 48 8b 44 24 10 mov 0x10(%rsp),%rax
a: 48 39 03 cmp %rax,(%rbx)
d: 0f 83 d4 fa ff ff jae 0xfffffae7
13: 4c 89 f7 mov %r14,%rdi
16: e8 35 da ff ff callq 0xffffda50
1b: 48 b8 00 00 00 00 00 movabs $0xdffffc0000000000,%rax
22: fc ff df
25: 0f b6 44 05 00 movzbl 0x0(%rbp,%rax,1),%eax
* 2a: 84 c0 test %al,%al <-- trapping instruction
2c: 75 2d jne 0x5b
2e: 41 83 3e 00 cmpl $0x0,(%r14)
32: 0f 85 38 ff ff ff jne 0xffffff70
38: e9 aa fa ff ff jmpq 0xfffffae7
3d: 44 89 f1 mov %r14d,%ecx


---
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 [email protected].

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.


2022-01-21 20:03:00

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] INFO: task hung in hub_port_init (2)

syzbot has found a reproducer for the following issue on:

HEAD commit: 6f59bc242877 Add linux-next specific files for 20220118
git tree: linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=173526ffb00000
kernel config: https://syzkaller.appspot.com/x/.config?x=94e8da4df9ab6319
dashboard link: https://syzkaller.appspot.com/bug?extid=76629376e06e2c2ad626
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=13070f40700000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: [email protected]

INFO: task kworker/1:6:3709 blocked for more than 143 seconds.
Not tainted 5.16.0-next-20220118-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:6 state:D stack:26416 pid: 3709 ppid: 2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
usb_kill_urb.part.0+0x19a/0x220 drivers/usb/core/urb.c:720
usb_kill_urb+0x7f/0xa0 drivers/usb/core/urb.c:715
usb_start_wait_urb+0x24a/0x4c0 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+0x7bd/0x2e80 drivers/usb/core/hub.c:4832
hub_port_connect drivers/usb/core/hub.c:5287 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5502 [inline]
port_event drivers/usb/core/hub.c:5660 [inline]
hub_event+0x238a/0x44d0 drivers/usb/core/hub.c:5742
process_one_work+0x996/0x1610 kernel/workqueue.c:2289
worker_thread+0x665/0x1080 kernel/workqueue.c:2436
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
INFO: task syz-executor.0:3767 can't die for more than 143 seconds.
task:syz-executor.0 state:D stack:28000 pid: 3767 ppid: 3655 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_release+0x83/0x4b0 drivers/usb/core/devio.c:1075
__fput+0x286/0x9f0 fs/file_table.c:311
task_work_run+0xdd/0x1a0 kernel/task_work.c:164
tracehook_notify_resume include/linux/tracehook.h:188 [inline]
exit_to_user_mode_loop kernel/entry/common.c:175 [inline]
exit_to_user_mode_prepare+0x27e/0x290 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7ff21c603c2b
RSP: 002b:00007ffe6d368d40 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000004 RCX: 00007ff21c603c2b
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000003
RBP: 00007ff21c765960 R08: 0000000000000000 R09: 00007ff21c7680d0
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000079a2e
R13: 00007ffe6d368e40 R14: 00007ffe6d368e60 R15: 0000000000000032
</TASK>
INFO: task syz-executor.0:3767 blocked for more than 143 seconds.
Not tainted 5.16.0-next-20220118-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.0 state:D stack:28000 pid: 3767 ppid: 3655 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_release+0x83/0x4b0 drivers/usb/core/devio.c:1075
__fput+0x286/0x9f0 fs/file_table.c:311
task_work_run+0xdd/0x1a0 kernel/task_work.c:164
tracehook_notify_resume include/linux/tracehook.h:188 [inline]
exit_to_user_mode_loop kernel/entry/common.c:175 [inline]
exit_to_user_mode_prepare+0x27e/0x290 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7ff21c603c2b
RSP: 002b:00007ffe6d368d40 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000004 RCX: 00007ff21c603c2b
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000003
RBP: 00007ff21c765960 R08: 0000000000000000 R09: 00007ff21c7680d0
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000079a2e
R13: 00007ffe6d368e40 R14: 00007ffe6d368e60 R15: 0000000000000032
</TASK>
INFO: task syz-executor.2:3773 can't die for more than 144 seconds.
task:syz-executor.2 state:D stack:28504 pid: 3773 ppid: 3657 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x1240 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c9e/0x2940 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
do_sys_open fs/open.c:1230 [inline]
__do_sys_openat fs/open.c:1246 [inline]
__se_sys_openat fs/open.c:1241 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f3be7549f04
RSP: 002b:00007f3be6d0bca0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007f3be7549f04
RDX: 0000000000028101 RSI: 00007f3be6d0bd40 RDI: 00000000ffffff9c
RBP: 00007f3be6d0bd40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000028101
R13: 00007ffcf9aa18df R14: 00007f3be6d0c300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.2:3773 blocked for more than 144 seconds.
Not tainted 5.16.0-next-20220118-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.2 state:D stack:28504 pid: 3773 ppid: 3657 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x1240 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c9e/0x2940 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
do_sys_open fs/open.c:1230 [inline]
__do_sys_openat fs/open.c:1246 [inline]
__se_sys_openat fs/open.c:1241 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f3be7549f04
RSP: 002b:00007f3be6d0bca0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007f3be7549f04
RDX: 0000000000028101 RSI: 00007f3be6d0bd40 RDI: 00000000ffffff9c
RBP: 00007f3be6d0bd40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000028101
R13: 00007ffcf9aa18df R14: 00007f3be6d0c300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.3:3778 can't die for more than 144 seconds.
task:syz-executor.3 state:D stack:28504 pid: 3778 ppid: 3654 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x1240 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c9e/0x2940 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
do_sys_open fs/open.c:1230 [inline]
__do_sys_openat fs/open.c:1246 [inline]
__se_sys_openat fs/open.c:1241 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f1ccb53ef04
RSP: 002b:00007f1ccad00ca0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007f1ccb53ef04
RDX: 0000000000028101 RSI: 00007f1ccad00d40 RDI: 00000000ffffff9c
RBP: 00007f1ccad00d40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000028101
R13: 00007ffee90aa8cf R14: 00007f1ccad01300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.3:3778 blocked for more than 145 seconds.
Not tainted 5.16.0-next-20220118-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.3 state:D stack:28504 pid: 3778 ppid: 3654 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x1240 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c9e/0x2940 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
do_sys_open fs/open.c:1230 [inline]
__do_sys_openat fs/open.c:1246 [inline]
__se_sys_openat fs/open.c:1241 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f1ccb53ef04
RSP: 002b:00007f1ccad00ca0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007f1ccb53ef04
RDX: 0000000000028101 RSI: 00007f1ccad00d40 RDI: 00000000ffffff9c
RBP: 00007f1ccad00d40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000028101
R13: 00007ffee90aa8cf R14: 00007f1ccad01300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:3783 can't die for more than 145 seconds.
task:syz-executor.5 state:D stack:28152 pid: 3783 ppid: 3656 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x1240 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c9e/0x2940 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
do_sys_open fs/open.c:1230 [inline]
__do_sys_openat fs/open.c:1246 [inline]
__se_sys_openat fs/open.c:1241 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7ffbef1d2f04
RSP: 002b:00007ffbee994ca0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007ffbef1d2f04
RDX: 0000000000028101 RSI: 00007ffbee994d40 RDI: 00000000ffffff9c
RBP: 00007ffbee994d40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000028101
R13: 00007ffedefc73bf R14: 00007ffbee995300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:3783 blocked for more than 145 seconds.
Not tainted 5.16.0-next-20220118-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.5 state:D stack:28152 pid: 3783 ppid: 3656 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x1240 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c9e/0x2940 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
do_sys_open fs/open.c:1230 [inline]
__do_sys_openat fs/open.c:1246 [inline]
__se_sys_openat fs/open.c:1241 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7ffbef1d2f04
RSP: 002b:00007ffbee994ca0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007ffbef1d2f04
RDX: 0000000000028101 RSI: 00007ffbee994d40 RDI: 00000000ffffff9c
RBP: 00007ffbee994d40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000028101
R13: 00007ffedefc73bf R14: 00007ffbee995300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.1:3790 can't die for more than 145 seconds.
task:syz-executor.1 state:D stack:28504 pid: 3790 ppid: 3659 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x1240 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c9e/0x2940 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
do_sys_open fs/open.c:1230 [inline]
__do_sys_openat fs/open.c:1246 [inline]
__se_sys_openat fs/open.c:1241 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7fb7dbbeaf04
RSP: 002b:00007fb7db3acca0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007fb7dbbeaf04
RDX: 0000000000028101 RSI: 00007fb7db3acd40 RDI: 00000000ffffff9c
RBP: 00007fb7db3acd40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000028101
R13: 00007ffdd38c69ef R14: 00007fb7db3ad300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.1:3790 blocked for more than 146 seconds.
Not tainted 5.16.0-next-20220118-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1 state:D stack:28504 pid: 3790 ppid: 3659 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x1240 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c9e/0x2940 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
do_sys_open fs/open.c:1230 [inline]
__do_sys_openat fs/open.c:1246 [inline]
__se_sys_openat fs/open.c:1241 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7fb7dbbeaf04
RSP: 002b:00007fb7db3acca0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007fb7dbbeaf04
RDX: 0000000000028101 RSI: 00007fb7db3acd40 RDI: 00000000ffffff9c
RBP: 00007fb7db3acd40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000028101
R13: 00007ffdd38c69ef R14: 00007fb7db3ad300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.4:3792 can't die for more than 146 seconds.
task:syz-executor.4 state:D stack:28504 pid: 3792 ppid: 3658 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x1240 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c9e/0x2940 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
do_sys_open fs/open.c:1230 [inline]
__do_sys_openat fs/open.c:1246 [inline]
__se_sys_openat fs/open.c:1241 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f2ad26daf04
RSP: 002b:00007f2ad1e9cca0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007f2ad26daf04
RDX: 0000000000028101 RSI: 00007f2ad1e9cd40 RDI: 00000000ffffff9c
RBP: 00007f2ad1e9cd40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000028101
R13: 00007ffd4db79f0f R14: 00007f2ad1e9d300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.4:3792 blocked for more than 146 seconds.
Not tainted 5.16.0-next-20220118-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.4 state:D stack:28504 pid: 3792 ppid: 3658 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4e90 kernel/sched/core.c:6296
schedule+0xd2/0x260 kernel/sched/core.c:6369
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
device_lock include/linux/device.h:767 [inline]
usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x1240 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c9e/0x2940 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
do_sys_open fs/open.c:1230 [inline]
__do_sys_openat fs/open.c:1246 [inline]
__se_sys_openat fs/open.c:1241 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f2ad26daf04
RSP: 002b:00007f2ad1e9cca0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007f2ad26daf04
RDX: 0000000000028101 RSI: 00007f2ad1e9cd40 RDI: 00000000ffffff9c
RBP: 00007f2ad1e9cd40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000028101
R13: 00007ffd4db79f0f R14: 00007f2ad1e9d300 R15: 0000000000022000
</TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
#0: ffffffff8bb83520 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6460
2 locks held by getty/3291:
#0: ffff88814aeb3098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002b632e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xcf0/0x1230 drivers/tty/n_tty.c:2077
5 locks held by kworker/1:6/3709:
#0: ffff888013392938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888013392938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888013392938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff888013392938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff888013392938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff888013392938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc90002c7fda8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#2: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c5/0x44d0 drivers/usb/core/hub.c:5688
#3: ffff88801dc55580 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3091 [inline]
#3: ffff88801dc55580 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect drivers/usb/core/hub.c:5254 [inline]
#3: ffff88801dc55580 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect_change drivers/usb/core/hub.c:5502 [inline]
#3: ffff88801dc55580 (&port_dev->status_lock){+.+.}-{3:3}, at: port_event drivers/usb/core/hub.c:5660 [inline]
#3: ffff88801dc55580 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_event+0x1fba/0x44d0 drivers/usb/core/hub.c:5742
#4: ffff88801d301868 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_connect drivers/usb/core/hub.c:5255 [inline]
#4: ffff88801d301868 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_connect_change drivers/usb/core/hub.c:5502 [inline]
#4: ffff88801d301868 (hcd->address0_mutex){+.+.}-{3:3}, at: port_event drivers/usb/core/hub.c:5660 [inline]
#4: ffff88801d301868 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_event+0x1fe3/0x44d0 drivers/usb/core/hub.c:5742
1 lock held by syz-executor.0/3767:
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: usbdev_release+0x83/0x4b0 drivers/usb/core/devio.c:1075
1 lock held by syz-executor.2/3773:
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
1 lock held by syz-executor.3/3778:
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
1 lock held by syz-executor.5/3783:
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
1 lock held by syz-executor.1/3790:
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030
1 lock held by syz-executor.4/3792:
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#0: ffff88801dc51220 (&dev->mutex){....}-{3:3}, at: usbdev_open+0x19d/0x920 drivers/usb/core/devio.c:1030

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

NMI backtrace for cpu 1
CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.16.0-next-20220118-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
nmi_trigger_cpumask_backtrace+0x1b3/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:256 [inline]
watchdog+0xcb7/0xed0 kernel/hung_task.c:413
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 3269 Comm: kworker/0:3 Not tainted 5.16.0-next-20220118-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events nsim_dev_trap_report_work
RIP: 0010:mark_lock+0x30/0x17b0 kernel/locking/lockdep.c:4566
Code: 41 54 41 89 d4 48 ba 00 00 00 00 00 fc ff df 55 53 48 81 ec 18 01 00 00 48 8d 5c 24 38 48 89 3c 24 48 c7 44 24 38 b3 8a b5 41 <48> c1 eb 03 48 c7 44 24 40 28 3c 3a 8b 48 8d 04 13 48 c7 44 24 48
RSP: 0018:ffffc90002c9f938 EFLAGS: 00000092
RAX: 0000000000000004 RBX: ffffc90002c9f970 RCX: 1ffffffff1ffb5ee
RDX: dffffc0000000000 RSI: ffff8880206c8a90 RDI: ffff8880206c8000
RBP: 0000000000000006 R08: 0000000000000000 R09: ffffffff8ffd2957
R10: 0000000000000001 R11: 0000000000088078 R12: 0000000000000006
R13: dffffc0000000000 R14: ffff8880206c8a68 R15: ffff888077ad2000
FS: 0000000000000000(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fac04558600 CR3: 000000000b88e000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>
mark_held_locks+0x9f/0xe0 kernel/locking/lockdep.c:4206
__trace_hardirqs_on_caller kernel/locking/lockdep.c:4232 [inline]
lockdep_hardirqs_on_prepare kernel/locking/lockdep.c:4292 [inline]
lockdep_hardirqs_on_prepare+0x28b/0x400 kernel/locking/lockdep.c:4244
trace_hardirqs_on+0x5b/0x1c0 kernel/trace/trace_preemptirq.c:49
kasan_quarantine_put+0xf5/0x210 mm/kasan/quarantine.c:231
kasan_slab_free include/linux/kasan.h:236 [inline]
slab_free_hook mm/slub.c:1728 [inline]
slab_free_freelist_hook+0x8b/0x1c0 mm/slub.c:1754
slab_free mm/slub.c:3509 [inline]
kfree+0xce/0x380 mm/slub.c:4562
skb_free_head net/core/skbuff.c:655 [inline]
skb_release_data+0x718/0x870 net/core/skbuff.c:677
skb_release_all net/core/skbuff.c:742 [inline]
__kfree_skb net/core/skbuff.c:756 [inline]
consume_skb net/core/skbuff.c:914 [inline]
consume_skb+0xc2/0x160 net/core/skbuff.c:908
nsim_dev_trap_report drivers/net/netdevsim/dev.c:818 [inline]
nsim_dev_trap_report_work+0x85d/0xbc0 drivers/net/netdevsim/dev.c:843
process_one_work+0x996/0x1610 kernel/workqueue.c:2289
worker_thread+0x665/0x1080 kernel/workqueue.c:2436
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
----------------
Code disassembly (best guess):
0: 41 54 push %r12
2: 41 89 d4 mov %edx,%r12d
5: 48 ba 00 00 00 00 00 movabs $0xdffffc0000000000,%rdx
c: fc ff df
f: 55 push %rbp
10: 53 push %rbx
11: 48 81 ec 18 01 00 00 sub $0x118,%rsp
18: 48 8d 5c 24 38 lea 0x38(%rsp),%rbx
1d: 48 89 3c 24 mov %rdi,(%rsp)
21: 48 c7 44 24 38 b3 8a movq $0x41b58ab3,0x38(%rsp)
28: b5 41
* 2a: 48 c1 eb 03 shr $0x3,%rbx <-- trapping instruction
2e: 48 c7 44 24 40 28 3c movq $0xffffffff8b3a3c28,0x40(%rsp)
35: 3a 8b
37: 48 8d 04 13 lea (%rbx,%rdx,1),%rax
3b: 48 rex.W
3c: c7 .byte 0xc7
3d: 44 24 48 rex.R and $0x48,%al

2022-01-21 21:10:42

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] INFO: task hung in hub_port_init (2)

Hello,

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

Reported-and-tested-by: [email protected]

Tested on:

commit: 6f59bc24 Add linux-next specific files for 20220118
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git
kernel config: https://syzkaller.appspot.com/x/.config?x=94e8da4df9ab6319
dashboard link: https://syzkaller.appspot.com/bug?extid=76629376e06e2c2ad626
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=101ba7efb00000

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

2022-01-21 22:28:34

by Alan Stern

[permalink] [raw]
Subject: Re: [syzbot] INFO: task hung in hub_port_init (2)

On Thu, Jan 20, 2022 at 12:11:10AM -0800, syzbot wrote:
> Hello,
>
> syzbot has tested the proposed patch and the reproducer did not trigger any issue:
>
> Reported-and-tested-by: [email protected]
>
> Tested on:
>
> commit: 6f59bc24 Add linux-next specific files for 20220118
> git tree: git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git
> kernel config: https://syzkaller.appspot.com/x/.config?x=94e8da4df9ab6319
> dashboard link: https://syzkaller.appspot.com/bug?extid=76629376e06e2c2ad626
> compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
> patch: https://syzkaller.appspot.com/x/patch.diff?x=101ba7efb00000
>
> Note: testing is done by a robot and is best-effort only.

Attempted fix.

Alan Stern

#syz test: https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/ 6f59bc24

Index: usb-devel/drivers/usb/core/hcd.c
===================================================================
--- usb-devel.orig/drivers/usb/core/hcd.c
+++ usb-devel/drivers/usb/core/hcd.c
@@ -1563,6 +1563,12 @@ int usb_hcd_submit_urb (struct urb *urb,
urb->hcpriv = NULL;
INIT_LIST_HEAD(&urb->urb_list);
atomic_dec(&urb->use_count);
+ /*
+ * Order the write of urb->use_count above against the read of
+ * urb->reject below. Pairs with the memory barriers in
+ * usb_kill_urb() and usb_poison_urb().
+ */
+ smp_mb__after_atomic();
atomic_dec(&urb->dev->urbnum);
if (atomic_read(&urb->reject))
wake_up(&usb_kill_urb_queue);
@@ -1665,6 +1671,13 @@ static void __usb_hcd_giveback_urb(struc

usb_anchor_resume_wakeups(anchor);
atomic_dec(&urb->use_count);
+ /*
+ * Order the write of urb->use_count above against the read of
+ * urb->reject below. Pairs with the memory barriers in
+ * usb_kill_urb() and usb_poison_urb().
+ */
+ smp_mb__after_atomic();
+
if (unlikely(atomic_read(&urb->reject)))
wake_up(&usb_kill_urb_queue);
usb_put_urb(urb);
Index: usb-devel/drivers/usb/core/urb.c
===================================================================
--- usb-devel.orig/drivers/usb/core/urb.c
+++ usb-devel/drivers/usb/core/urb.c
@@ -715,6 +715,12 @@ void usb_kill_urb(struct urb *urb)
if (!(urb && urb->dev && urb->ep))
return;
atomic_inc(&urb->reject);
+ /*
+ * Order the write of urb->reject above against the read of
+ * urb->use_count below. Pairs with the barriers in
+ * __usb_hcd_giveback_urb() and usb_hcd_submit_urb().
+ */
+ smp_mb__after_atomic();

usb_hcd_unlink_urb(urb, -ENOENT);
wait_event(usb_kill_urb_queue, atomic_read(&urb->use_count) == 0);
@@ -756,6 +762,12 @@ void usb_poison_urb(struct urb *urb)
if (!urb)
return;
atomic_inc(&urb->reject);
+ /*
+ * Order the write of urb->reject above against the read of
+ * urb->use_count below. Pairs with the barriers in
+ * __usb_hcd_giveback_urb() and usb_hcd_submit_urb().
+ */
+ smp_mb__after_atomic();

if (!urb->dev || !urb->ep)
return;

2022-01-21 22:29:58

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] INFO: task hung in hub_port_init (2)

Hello,

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

Reported-and-tested-by: [email protected]

Tested on:

commit: 6f59bc24 Add linux-next specific files for 20220118
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/
kernel config: https://syzkaller.appspot.com/x/.config?x=94e8da4df9ab6319
dashboard link: https://syzkaller.appspot.com/bug?extid=76629376e06e2c2ad626
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=1596bbdfb00000

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

2022-09-19 02:29:39

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] INFO: task hung in hub_port_init (2)

syzbot has found a reproducer for the following issue on:

HEAD commit: a6b443748715 Merge branch 'for-next/core', remote-tracking..
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci
console output: https://syzkaller.appspot.com/x/log.txt?x=16b7e0f8880000
kernel config: https://syzkaller.appspot.com/x/.config?x=14bf9ec0df433b27
dashboard link: https://syzkaller.appspot.com/bug?extid=76629376e06e2c2ad626
compiler: Debian clang version 13.0.1-++20220126092033+75e33f71c2da-1~exp1~20220126212112.63, GNU ld (GNU Binutils for Debian) 2.35.2
userspace arch: arm64
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=111ff2d5080000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=11667887080000

Downloadable assets:
disk image: https://storage.googleapis.com/81b491dd5861/disk-a6b44374.raw.xz
vmlinux: https://storage.googleapis.com/69c979cdc99a/vmlinux-a6b44374.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: [email protected]

INFO: task kworker/0:0:6 blocked for more than 143 seconds.
Not tainted 6.0.0-rc4-syzkaller-17255-ga6b443748715 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/0:0 state:D stack: 0 pid: 6 ppid: 2 flags:0x00000008
Workqueue: usb_hub_wq hub_event
Call trace:
__switch_to+0x180/0x28c arch/arm64/kernel/process.c:557
context_switch kernel/sched/core.c:5182 [inline]
__schedule+0x414/0x5a0 kernel/sched/core.c:6494
schedule+0x64/0xa4 kernel/sched/core.c:6570
usb_kill_urb+0xe0/0x1c8 drivers/usb/core/urb.c:726
usb_start_wait_urb+0xf8/0x1ec drivers/usb/core/message.c:64
usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
usb_control_msg+0xd8/0x17c drivers/usb/core/message.c:153
hub_port_init+0x534/0x1064 drivers/usb/core/hub.c:4825
hub_port_connect+0x528/0xe30 drivers/usb/core/hub.c:5282
hub_port_connect_change+0x3d8/0x70c drivers/usb/core/hub.c:5497
port_event+0x780/0x930 drivers/usb/core/hub.c:5653
hub_event+0x2f0/0x658 drivers/usb/core/hub.c:5735
process_one_work+0x2d8/0x504 kernel/workqueue.c:2289
worker_thread+0x340/0x610 kernel/workqueue.c:2436
kthread+0x12c/0x158 kernel/kthread.c:376
ret_from_fork+0x10/0x20
INFO: task kworker/1:0:20 blocked for more than 143 seconds.
Not tainted 6.0.0-rc4-syzkaller-17255-ga6b443748715 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:0 state:D stack: 0 pid: 20 ppid: 2 flags:0x00000008
Workqueue: usb_hub_wq hub_event
Call trace:
__switch_to+0x180/0x28c arch/arm64/kernel/process.c:557
context_switch kernel/sched/core.c:5182 [inline]
__schedule+0x414/0x5a0 kernel/sched/core.c:6494
schedule+0x64/0xa4 kernel/sched/core.c:6570
usb_kill_urb+0xe0/0x1c8 drivers/usb/core/urb.c:726
usb_start_wait_urb+0xf8/0x1ec drivers/usb/core/message.c:64
usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
usb_control_msg+0xd8/0x17c drivers/usb/core/message.c:153
hub_port_init+0x534/0x1064 drivers/usb/core/hub.c:4825
hub_port_connect+0x528/0xe30 drivers/usb/core/hub.c:5282
hub_port_connect_change+0x3d8/0x70c drivers/usb/core/hub.c:5497
port_event+0x780/0x930 drivers/usb/core/hub.c:5653
hub_event+0x2f0/0x658 drivers/usb/core/hub.c:5735
process_one_work+0x2d8/0x504 kernel/workqueue.c:2289
worker_thread+0x340/0x610 kernel/workqueue.c:2436
kthread+0x12c/0x158 kernel/kthread.c:376
ret_from_fork+0x10/0x20
INFO: task kworker/1:2:109 blocked for more than 143 seconds.
Not tainted 6.0.0-rc4-syzkaller-17255-ga6b443748715 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:2 state:D stack: 0 pid: 109 ppid: 2 flags:0x00000008
Workqueue: usb_hub_wq hub_event
Call trace:
__switch_to+0x180/0x28c arch/arm64/kernel/process.c:557
context_switch kernel/sched/core.c:5182 [inline]
__schedule+0x414/0x5a0 kernel/sched/core.c:6494
schedule+0x64/0xa4 kernel/sched/core.c:6570
usb_kill_urb+0xe0/0x1c8 drivers/usb/core/urb.c:726
usb_start_wait_urb+0xf8/0x1ec drivers/usb/core/message.c:64
usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
usb_control_msg+0xd8/0x17c drivers/usb/core/message.c:153
hub_port_init+0x534/0x1064 drivers/usb/core/hub.c:4825
hub_port_connect+0x528/0xe30 drivers/usb/core/hub.c:5282
hub_port_connect_change+0x3d8/0x70c drivers/usb/core/hub.c:5497
port_event+0x780/0x930 drivers/usb/core/hub.c:5653
hub_event+0x2f0/0x658 drivers/usb/core/hub.c:5735
process_one_work+0x2d8/0x504 kernel/workqueue.c:2289
worker_thread+0x340/0x610 kernel/workqueue.c:2436
kthread+0x12c/0x158 kernel/kthread.c:376
ret_from_fork+0x10/0x20
INFO: task syz-executor535:3088 blocked for more than 143 seconds.
Not tainted 6.0.0-rc4-syzkaller-17255-ga6b443748715 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor535 state:D stack: 0 pid: 3088 ppid: 3083 flags:0x00000001
Call trace:
__switch_to+0x180/0x28c arch/arm64/kernel/process.c:557
context_switch kernel/sched/core.c:5182 [inline]
__schedule+0x414/0x5a0 kernel/sched/core.c:6494
schedule+0x64/0xa4 kernel/sched/core.c:6570
schedule_preempt_disabled+0x18/0x2c kernel/sched/core.c:6629
__mutex_lock_common+0x788/0xca8 kernel/locking/mutex.c:679
__mutex_lock kernel/locking/mutex.c:747 [inline]
mutex_lock_nested+0x38/0x44 kernel/locking/mutex.c:799
device_lock include/linux/device.h:835 [inline]
usbdev_release+0x40/0x3b8 drivers/usb/core/devio.c:1087
__fput+0x198/0x3dc fs/file_table.c:320
____fput+0x20/0x30 fs/file_table.c:353
task_work_run+0xc4/0x14c kernel/task_work.c:177
resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
do_notify_resume+0x174/0x1f0 arch/arm64/kernel/signal.c:1127
prepare_exit_to_user_mode arch/arm64/kernel/entry-common.c:137 [inline]
exit_to_user_mode arch/arm64/kernel/entry-common.c:142 [inline]
el0_svc+0x9c/0x150 arch/arm64/kernel/entry-common.c:625
el0t_64_sync_handler+0x84/0xf0 arch/arm64/kernel/entry-common.c:642
el0t_64_sync+0x18c/0x190
INFO: task kworker/0:1:3090 blocked for more than 143 seconds.
Not tainted 6.0.0-rc4-syzkaller-17255-ga6b443748715 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/0:1 state:D stack: 0 pid: 3090 ppid: 2 flags:0x00000008
Workqueue: usb_hub_wq hub_event
Call trace:
__switch_to+0x180/0x28c arch/arm64/kernel/process.c:557
context_switch kernel/sched/core.c:5182 [inline]
__schedule+0x414/0x5a0 kernel/sched/core.c:6494
schedule+0x64/0xa4 kernel/sched/core.c:6570
usb_kill_urb+0xe0/0x1c8 drivers/usb/core/urb.c:726
usb_start_wait_urb+0xf8/0x1ec drivers/usb/core/message.c:64
usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
usb_control_msg+0xd8/0x17c drivers/usb/core/message.c:153
hub_port_init+0x534/0x1064 drivers/usb/core/hub.c:4825
hub_port_connect+0x528/0xe30 drivers/usb/core/hub.c:5282
hub_port_connect_change+0x3d8/0x70c drivers/usb/core/hub.c:5497
port_event+0x780/0x930 drivers/usb/core/hub.c:5653
hub_event+0x2f0/0x658 drivers/usb/core/hub.c:5735
process_one_work+0x2d8/0x504 kernel/workqueue.c:2289
worker_thread+0x340/0x610 kernel/workqueue.c:2436
kthread+0x12c/0x158 kernel/kthread.c:376
ret_from_fork+0x10/0x20
INFO: task syz-executor535:3091 blocked for more than 143 seconds.
Not tainted 6.0.0-rc4-syzkaller-17255-ga6b443748715 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor535 state:D stack: 0 pid: 3091 ppid: 3080 flags:0x00000001
Call trace:
__switch_to+0x180/0x28c arch/arm64/kernel/process.c:557
context_switch kernel/sched/core.c:5182 [inline]
__schedule+0x414/0x5a0 kernel/sched/core.c:6494
schedule+0x64/0xa4 kernel/sched/core.c:6570
schedule_preempt_disabled+0x18/0x2c kernel/sched/core.c:6629
__mutex_lock_common+0x788/0xca8 kernel/locking/mutex.c:679
__mutex_lock kernel/locking/mutex.c:747 [inline]
mutex_lock_nested+0x38/0x44 kernel/locking/mutex.c:799
device_lock include/linux/device.h:835 [inline]
usbdev_release+0x40/0x3b8 drivers/usb/core/devio.c:1087
__fput+0x198/0x3dc fs/file_table.c:320
____fput+0x20/0x30 fs/file_table.c:353
task_work_run+0xc4/0x14c kernel/task_work.c:177
resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
do_notify_resume+0x174/0x1f0 arch/arm64/kernel/signal.c:1127
prepare_exit_to_user_mode arch/arm64/kernel/entry-common.c:137 [inline]
exit_to_user_mode arch/arm64/kernel/entry-common.c:142 [inline]
el0_svc+0x9c/0x150 arch/arm64/kernel/entry-common.c:625
el0t_64_sync_handler+0x84/0xf0 arch/arm64/kernel/entry-common.c:642
el0t_64_sync+0x18c/0x190
INFO: task syz-executor535:3092 blocked for more than 143 seconds.
Not tainted 6.0.0-rc4-syzkaller-17255-ga6b443748715 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor535 state:D stack: 0 pid: 3092 ppid: 3082 flags:0x00000001
Call trace:
__switch_to+0x180/0x28c arch/arm64/kernel/process.c:557
context_switch kernel/sched/core.c:5182 [inline]
__schedule+0x414/0x5a0 kernel/sched/core.c:6494
schedule+0x64/0xa4 kernel/sched/core.c:6570
schedule_preempt_disabled+0x18/0x2c kernel/sched/core.c:6629
__mutex_lock_common+0x788/0xca8 kernel/locking/mutex.c:679
__mutex_lock kernel/locking/mutex.c:747 [inline]
mutex_lock_nested+0x38/0x44 kernel/locking/mutex.c:799
device_lock include/linux/device.h:835 [inline]
usbdev_release+0x40/0x3b8 drivers/usb/core/devio.c:1087
__fput+0x198/0x3dc fs/file_table.c:320
____fput+0x20/0x30 fs/file_table.c:353
task_work_run+0xc4/0x14c kernel/task_work.c:177
resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
do_notify_resume+0x174/0x1f0 arch/arm64/kernel/signal.c:1127
prepare_exit_to_user_mode arch/arm64/kernel/entry-common.c:137 [inline]
exit_to_user_mode arch/arm64/kernel/entry-common.c:142 [inline]
el0_svc+0x9c/0x150 arch/arm64/kernel/entry-common.c:625
el0t_64_sync_handler+0x84/0xf0 arch/arm64/kernel/entry-common.c:642
el0t_64_sync+0x18c/0x190
INFO: task syz-executor535:3096 blocked for more than 143 seconds.
Not tainted 6.0.0-rc4-syzkaller-17255-ga6b443748715 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor535 state:D stack: 0 pid: 3096 ppid: 3084 flags:0x00000001
Call trace:
__switch_to+0x180/0x28c arch/arm64/kernel/process.c:557
context_switch kernel/sched/core.c:5182 [inline]
__schedule+0x414/0x5a0 kernel/sched/core.c:6494
schedule+0x64/0xa4 kernel/sched/core.c:6570
schedule_preempt_disabled+0x18/0x2c kernel/sched/core.c:6629
__mutex_lock_common+0x788/0xca8 kernel/locking/mutex.c:679
__mutex_lock kernel/locking/mutex.c:747 [inline]
mutex_lock_nested+0x38/0x44 kernel/locking/mutex.c:799
device_lock include/linux/device.h:835 [inline]
usbdev_release+0x40/0x3b8 drivers/usb/core/devio.c:1087
__fput+0x198/0x3dc fs/file_table.c:320
____fput+0x20/0x30 fs/file_table.c:353
task_work_run+0xc4/0x14c kernel/task_work.c:177
resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
do_notify_resume+0x174/0x1f0 arch/arm64/kernel/signal.c:1127
prepare_exit_to_user_mode arch/arm64/kernel/entry-common.c:137 [inline]
exit_to_user_mode arch/arm64/kernel/entry-common.c:142 [inline]
el0_svc+0x9c/0x150 arch/arm64/kernel/entry-common.c:625
el0t_64_sync_handler+0x84/0xf0 arch/arm64/kernel/entry-common.c:642
el0t_64_sync+0x18c/0x190
INFO: task syz-executor535:3099 blocked for more than 143 seconds.
Not tainted 6.0.0-rc4-syzkaller-17255-ga6b443748715 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor535 state:D stack: 0 pid: 3099 ppid: 3076 flags:0x00000001
Call trace:
__switch_to+0x180/0x28c arch/arm64/kernel/process.c:557
context_switch kernel/sched/core.c:5182 [inline]
__schedule+0x414/0x5a0 kernel/sched/core.c:6494
schedule+0x64/0xa4 kernel/sched/core.c:6570
schedule_preempt_disabled+0x18/0x2c kernel/sched/core.c:6629
__mutex_lock_common+0x788/0xca8 kernel/locking/mutex.c:679
__mutex_lock kernel/locking/mutex.c:747 [inline]
mutex_lock_nested+0x38/0x44 kernel/locking/mutex.c:799
device_lock include/linux/device.h:835 [inline]
usbdev_release+0x40/0x3b8 drivers/usb/core/devio.c:1087
__fput+0x198/0x3dc fs/file_table.c:320
____fput+0x20/0x30 fs/file_table.c:353
task_work_run+0xc4/0x14c kernel/task_work.c:177
resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
do_notify_resume+0x174/0x1f0 arch/arm64/kernel/signal.c:1127
prepare_exit_to_user_mode arch/arm64/kernel/entry-common.c:137 [inline]
exit_to_user_mode arch/arm64/kernel/entry-common.c:142 [inline]
el0_svc+0x9c/0x150 arch/arm64/kernel/entry-common.c:625
el0t_64_sync_handler+0x84/0xf0 arch/arm64/kernel/entry-common.c:642
el0t_64_sync+0x18c/0x190
INFO: task kworker/1:1:3101 blocked for more than 143 seconds.
Not tainted 6.0.0-rc4-syzkaller-17255-ga6b443748715 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:1 state:D stack: 0 pid: 3101 ppid: 2 flags:0x00000008
Workqueue: usb_hub_wq hub_event
Call trace:
__switch_to+0x180/0x28c arch/arm64/kernel/process.c:557
context_switch kernel/sched/core.c:5182 [inline]
__schedule+0x414/0x5a0 kernel/sched/core.c:6494
schedule+0x64/0xa4 kernel/sched/core.c:6570
usb_kill_urb+0xe0/0x1c8 drivers/usb/core/urb.c:726
usb_start_wait_urb+0xf8/0x1ec drivers/usb/core/message.c:64
usb_internal_control_msg drivers/usb/core/message.c:102 [inline]
usb_control_msg+0xd8/0x17c drivers/usb/core/message.c:153
hub_port_init+0x534/0x1064 drivers/usb/core/hub.c:4825
hub_port_connect+0x528/0xe30 drivers/usb/core/hub.c:5282
hub_port_connect_change+0x3d8/0x70c drivers/usb/core/hub.c:5497
port_event+0x780/0x930 drivers/usb/core/hub.c:5653
hub_event+0x2f0/0x658 drivers/usb/core/hub.c:5735
process_one_work+0x2d8/0x504 kernel/workqueue.c:2289
worker_thread+0x340/0x610 kernel/workqueue.c:2436
kthread+0x12c/0x158 kernel/kthread.c:376
ret_from_fork+0x10/0x20

Showing all locks held in the system:
5 locks held by kworker/0:0/6:
#0: ffff0000c0c12138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x270/0x504 kernel/workqueue.c:2262
#1: ffff80000f21bd80 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x29c/0x504 kernel/workqueue.c:2264
#2: ffff0000c4a87990 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff0000c4a87990 (&dev->mutex){....}-{3:3}, at: hub_event+0x8c/0x658 drivers/usb/core/hub.c:5681
#3: ffff0000c6299508 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3103 [inline]
#3: ffff0000c6299508 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect+0x33c/0xe30 drivers/usb/core/hub.c:5249
#4: ffff0000c66b8468 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_connect+0x348/0xe30 drivers/usb/core/hub.c:5250
1 lock held by rcu_tasks_kthre/10:
#0: ffff80000d4634e8 (rcu_tasks.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x3c/0x450 kernel/rcu/tasks.h:507
1 lock held by rcu_tasks_trace/11:
#0: ffff80000d463b38 (rcu_tasks_trace.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x3c/0x450 kernel/rcu/tasks.h:507
5 locks held by kworker/1:0/20:
#0: ffff0000c0c12138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x270/0x504 kernel/workqueue.c:2262
#1: ffff80000f293d80 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x29c/0x504 kernel/workqueue.c:2264
#2: ffff0000c622f990 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff0000c622f990 (&dev->mutex){....}-{3:3}, at: hub_event+0x8c/0x658 drivers/usb/core/hub.c:5681
#3: ffff0000c4bf1508 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3103 [inline]
#3: ffff0000c4bf1508 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect+0x33c/0xe30 drivers/usb/core/hub.c:5249
#4: ffff0000c64c9168 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_connect+0x348/0xe30 drivers/usb/core/hub.c:5250
1 lock held by khungtaskd/26:
#0: ffff80000d4633c0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x4/0x48 include/linux/rcupdate.h:279
5 locks held by kworker/1:2/109:
#0: ffff0000c0c12138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x270/0x504 kernel/workqueue.c:2262
#1: ffff8000126ebd80 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x29c/0x504 kernel/workqueue.c:2264
#2: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: hub_event+0x8c/0x658 drivers/usb/core/hub.c:5681
#3: ffff0000c5285508 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3103 [inline]
#3: ffff0000c5285508 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect+0x33c/0xe30 drivers/usb/core/hub.c:5249
#4: ffff0000c64d2368 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_connect+0x348/0xe30 drivers/usb/core/hub.c:5250
2 locks held by getty/2728:
#0: ffff0000c6f4d898 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x28/0x58 drivers/tty/tty_ldisc.c:244
#1: ffff80000f63e2f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x19c/0x89c drivers/tty/n_tty.c:2177
1 lock held by syz-executor535/3088:
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: usbdev_release+0x40/0x3b8 drivers/usb/core/devio.c:1087
5 locks held by kworker/0:1/3090:
#0: ffff0000c0c12138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x270/0x504 kernel/workqueue.c:2262
#1: ffff8000127a3d80 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x29c/0x504 kernel/workqueue.c:2264
#2: ffff0000c6289990 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff0000c6289990 (&dev->mutex){....}-{3:3}, at: hub_event+0x8c/0x658 drivers/usb/core/hub.c:5681
#3: ffff0000c628b508 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3103 [inline]
#3: ffff0000c628b508 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect+0x33c/0xe30 drivers/usb/core/hub.c:5249
#4: ffff0000c66b8f68 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_connect+0x348/0xe30 drivers/usb/core/hub.c:5250
1 lock held by syz-executor535/3091:
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: usbdev_release+0x40/0x3b8 drivers/usb/core/devio.c:1087
1 lock held by syz-executor535/3092:
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: usbdev_release+0x40/0x3b8 drivers/usb/core/devio.c:1087
1 lock held by syz-executor535/3096:
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: usbdev_release+0x40/0x3b8 drivers/usb/core/devio.c:1087
1 lock held by syz-executor535/3099:
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: usbdev_release+0x40/0x3b8 drivers/usb/core/devio.c:1087
5 locks held by kworker/1:1/3101:
#0: ffff0000c0c12138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x270/0x504 kernel/workqueue.c:2262
#1: ffff800012863d80 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x29c/0x504 kernel/workqueue.c:2264
#2: ffff0000c62c9190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff0000c62c9190 (&dev->mutex){....}-{3:3}, at: hub_event+0x8c/0x658 drivers/usb/core/hub.c:5681
#3: ffff0000c62cb508 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3103 [inline]
#3: ffff0000c62cb508 (&port_dev->status_lock){+.+.}-{3:3}, at: hub_port_connect+0x33c/0xe30 drivers/usb/core/hub.c:5249
#4: ffff0000c64d2d68 (hcd->address0_mutex){+.+.}-{3:3}, at: hub_port_connect+0x348/0xe30 drivers/usb/core/hub.c:5250
1 lock held by syz-executor535/3102:
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#0: ffff0000c5283990 (&dev->mutex){....}-{3:3}, at: usbdev_open+0xb0/0x370 drivers/usb/core/devio.c:1042

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


2022-09-19 12:28:35

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] INFO: task hung in hub_port_init (2)

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
INFO: rcu detected stall in corrupted

rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { P3497 } 2645 jiffies s: 2025 root: 0x0/T
rcu: blocking rcu_node structures (internal RCU debug):


Tested on:

commit: a6b44374 Merge branch 'for-next/core', remote-tracking..
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=120d7937080000
kernel config: https://syzkaller.appspot.com/x/.config?x=14bf9ec0df433b27
dashboard link: https://syzkaller.appspot.com/bug?extid=76629376e06e2c2ad626
compiler: Debian clang version 13.0.1-++20220126092033+75e33f71c2da-1~exp1~20220126212112.63, GNU ld (GNU Binutils for Debian) 2.35.2
userspace arch: arm64
patch: https://syzkaller.appspot.com/x/patch.diff?x=11a15337080000