[syzbot] INFO: task hung in __input_unregister_device (4)

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: a175eca0f3d7 Merge tag 'drm-fixes-2022-07-01' of git://ano..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=17141c97f00000
kernel config: https://syzkaller.appspot.com/x/.config?x=3a010dbf6a7af480
dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, 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: syzbot+deb6ab...@syzkaller.appspotmail.com

INFO: task kworker/0:7:3758 blocked for more than 145 seconds.
Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/0:7 state:D stack:22944 pid: 3758 ppid: 2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa00/0x4b50 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747
input_disconnect_device drivers/input/input.c:784 [inline]
__input_unregister_device+0x24/0x470 drivers/input/input.c:2234
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2429
iforce_usb_disconnect+0x5e/0xf0 drivers/input/joystick/iforce/iforce-usb.c:261
usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:545 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:537
__device_release_driver drivers/base/dd.c:1222 [inline]
device_release_driver_internal+0x4a1/0x700 drivers/base/dd.c:1248
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529
device_del+0x4f3/0xc80 drivers/base/core.c:3604
usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228
hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]
port_event drivers/usb/core/hub.c:5663 [inline]
hub_event+0x1e83/0x4690 drivers/usb/core/hub.c:5745
process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/28:
#0: ffffffff8bd83b60 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
2 locks held by acpid/2961:
#0: ffff8880739bc158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_close_device drivers/input/joydev.c:220 [inline]
#0: ffff8880739bc158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_release+0x187/0x290 drivers/input/joydev.c:252
#1: ffff88807c9c02c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_close_device+0x42/0x1f0 drivers/input/input.c:726
2 locks held by getty/3294:
#0: ffff88814ab20098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90001c282e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
3 locks held by kworker/0:3/3682:
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc90003897da8 (fqdir_free_work){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffffffff8bd8dd28 (rcu_state.barrier_mutex){+.+.}-{3:3}, at: rcu_barrier+0x44/0x630 kernel/rcu/tree.c:4105
3 locks held by kworker/1:9/3733:
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc90003f2fda8 ((work_completion)(&map->work)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffffffff8bd8de60 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:322 [inline]
#2: ffffffff8bd8de60 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x2d3/0x610 kernel/rcu/tree_exp.h:927
6 locks held by kworker/0:7/3758:
#0: ffff8881457afd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff8881457afd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff8881457afd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff8881457afd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff8881457afd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff8881457afd38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc90003fd7da8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffff888021e32190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff888021e32190 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4690 drivers/usb/core/hub.c:5691
#3: ffff888042b67190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#3: ffff888042b67190 (&dev->mutex){....}-{3:3}, at: usb_disconnect.cold+0x43/0x6ec drivers/usb/core/hub.c:2219
#4: ffff888072997118 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#4: ffff888072997118 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1054 [inline]
#4: ffff888072997118 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa0/0x700 drivers/base/dd.c:1245
#5: ffff88807c9c02c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_disconnect_device drivers/input/input.c:784 [inline]
#5: ffff88807c9c02c0 (&dev->mutex#2){+.+.}-{3:3}, at: __input_unregister_device+0x24/0x470 drivers/input/input.c:2234
3 locks held by kworker/u4:11/4030:
#0: ffff8881400a3138 ((wq_completion)netns){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff8881400a3138 ((wq_completion)netns){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff8881400a3138 ((wq_completion)netns){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff8881400a3138 ((wq_completion)netns){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff8881400a3138 ((wq_completion)netns){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff8881400a3138 ((wq_completion)netns){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc90004517da8 (net_cleanup_work){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffffffff8d572f10 (pernet_ops_rwsem){++++}-{3:3}, at: cleanup_net+0x9b/0xb00 net/core/net_namespace.c:556
2 locks held by udevd/6583:
#0: ffff888022137110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open_device drivers/input/evdev.c:393 [inline]
#0: ffff888022137110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open+0x2f3/0x6a0 drivers/input/evdev.c:487
#1: ffff88807c9c02c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_open_device+0x4a/0x320 drivers/input/input.c:656
3 locks held by kworker/1:11/6796:
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff888011867d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc9000407fda8 ((work_completion)(&map->work)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffffffff8bd8dd28 (rcu_state.barrier_mutex){+.+.}-{3:3}, at: rcu_barrier+0x44/0x630 kernel/rcu/tree.c:4105
1 lock held by syz-executor.5/10484:
#0: ffffffff8bd8dd28 (rcu_state.barrier_mutex){+.+.}-{3:3}, at: rcu_barrier+0x44/0x630 kernel/rcu/tree.c:4105
1 lock held by syz-executor.4/10494:
#0: ffffffff8bdc8b50 (cgroup_threadgroup_rwsem){++++}-{0:0}, at: do_exit+0x50d/0x2a00 kernel/exit.c:751
1 lock held by syz-executor.4/10498:
#0: ffffffff8bdc8b50 (cgroup_threadgroup_rwsem){++++}-{0:0}, at: do_exit+0x50d/0x2a00 kernel/exit.c:751
1 lock held by syz-executor.4/10503:
#0: ffffffff8bdc8b50 (cgroup_threadgroup_rwsem){++++}-{0:0}, at: copy_process+0x43c1/0x7020 kernel/fork.c:2344
1 lock held by syz-executor.4/10506:
#0: ffffffff8bdc8b50 (cgroup_threadgroup_rwsem){++++}-{0:0}, at: do_exit+0x50d/0x2a00 kernel/exit.c:751
1 lock held by syz-executor.2/10495:
#0: ffffffff8bd8dd28 (rcu_state.barrier_mutex){+.+.}-{3:3}, at: rcu_barrier+0x44/0x630 kernel/rcu/tree.c:4105
1 lock held by syz-executor.3/10500:
#0: ffffffff8bd8dd28 (rcu_state.barrier_mutex){+.+.}-{3:3}, at: rcu_barrier+0x44/0x630 kernel/rcu/tree.c:4105
1 lock held by syz-executor.1/10508:
#0: ffffffff8bdc8b50 (cgroup_threadgroup_rwsem){++++}-{0:0}, at: copy_process+0x43c1/0x7020 kernel/fork.c:2344
4 locks held by kvm-nx-lpage-re/10511:
#0: ffffffff8bdc8d88 (cgroup_mutex){+.+.}-{3:3}, at: cgroup_attach_task_all+0x21/0x140 kernel/cgroup/cgroup-v1.c:61
#1: ffffffff8bdc8b50 (cgroup_threadgroup_rwsem){++++}-{0:0}, at: cgroup_attach_task_all+0x2d/0x140 kernel/cgroup/cgroup-v1.c:62
#2: ffffffff8bdd7050 (&cpuset_rwsem){++++}-{0:0}, at: cpuset_can_attach+0xe8/0x440 kernel/cgroup/cpuset.c:2233
#3: ffffffff8bd8de60 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:290 [inline]
#3: ffffffff8bd8de60 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x4f8/0x610 kernel/rcu/tree_exp.h:927

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

NMI backtrace for cpu 1
CPU: 1 PID: 28 Comm: khungtaskd Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/18/2022
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+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 6986 Comm: kworker/u4:21 Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/18/2022
Workqueue: bat_events batadv_nc_worker
RIP: 0010:lock_release+0x28/0x780 kernel/locking/lockdep.c:5673
Code: 00 00 48 b8 00 00 00 00 00 fc ff df 41 57 41 56 41 55 41 54 49 89 fc 55 53 48 81 ec 90 00 00 00 48 8d 6c 24 10 48 89 74 24 08 <48> c7 44 24 10 b3 8a b5 41 48 c1 ed 03 48 c7 44 24 18 48 f6 5f 8b
RSP: 0018:ffffc9000430fbc0 EFLAGS: 00000286
RAX: dffffc0000000000 RBX: 0000000000000001 RCX: 0000000000000000
RDX: ffff8880497d01c0 RSI: ffffffff8910b8d9 RDI: ffffffff8bd83b60
RBP: ffffc9000430fbd0 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000001 R11: 0000000000000001 R12: ffffffff8bd83b60
R13: 0000000000000000 R14: dffffc0000000000 R15: 000000000000019f
FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f29883691b8 CR3: 000000000ba8e000 CR4: 00000000003526f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>
rcu_lock_release include/linux/rcupdate.h:274 [inline]
rcu_read_unlock include/linux/rcupdate.h:728 [inline]
batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:412 [inline]
batadv_nc_worker+0x86b/0xfa0 net/batman-adv/network-coding.c:719
process_one_work+0x996/0x1610 kernel/workqueue.c:2289
worker_thread+0x665/0x1080 kernel/workqueue.c:2436
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
----------------
Code disassembly (best guess):
0: 00 00 add %al,(%rax)
2: 48 b8 00 00 00 00 00 movabs $0xdffffc0000000000,%rax
9: fc ff df
c: 41 57 push %r15
e: 41 56 push %r14
10: 41 55 push %r13
12: 41 54 push %r12
14: 49 89 fc mov %rdi,%r12
17: 55 push %rbp
18: 53 push %rbx
19: 48 81 ec 90 00 00 00 sub $0x90,%rsp
20: 48 8d 6c 24 10 lea 0x10(%rsp),%rbp
25: 48 89 74 24 08 mov %rsi,0x8(%rsp)
* 2a: 48 c7 44 24 10 b3 8a movq $0x41b58ab3,0x10(%rsp) <-- trapping instruction
31: b5 41
33: 48 c1 ed 03 shr $0x3,%rbp
37: 48 c7 44 24 18 48 f6 movq $0xffffffff8b5ff648,0x18(%rsp)
3e: 5f 8b


---
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 syzk...@googlegroups.com.

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

[syzbot]

syzbot has found a reproducer for the following issue on:

HEAD commit: 90557fa89d3e dt-bindings: usb: atmel: Add Microchip LAN966..
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb.git usb-testing
console output: https://syzkaller.appspot.com/x/log.txt?x=16892484080000
kernel config: https://syzkaller.appspot.com/x/.config?x=33f1eaa5b20a699

dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=155cc25c080000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=11f64834080000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+deb6ab...@syzkaller.appspotmail.com

INFO: task kworker/0:2:71 blocked for more than 143 seconds.
Not tainted 5.19.0-rc4-syzkaller-00099-g90557fa89d3e #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/0:2 state:D stack:23752 pid: 71 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0x93f/0x2630 kernel/sched/core.c:6458

schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747
input_disconnect_device drivers/input/input.c:784 [inline]
__input_unregister_device+0x24/0x470 drivers/input/input.c:2234
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2429
iforce_usb_disconnect+0x5e/0xf0 drivers/input/joystick/iforce/iforce-usb.c:261
usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:545 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:537
__device_release_driver drivers/base/dd.c:1222 [inline]
device_release_driver_internal+0x4a1/0x700 drivers/base/dd.c:1248
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529
device_del+0x4f3/0xc80 drivers/base/core.c:3604
usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228

hub_port_connect drivers/usb/core/hub.c:5190 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5490 [inline]
port_event drivers/usb/core/hub.c:5646 [inline]
hub_event+0x1e83/0x4690 drivers/usb/core/hub.c:5728

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438

kthread+0x2ef/0x3a0 kernel/kthread.c:376

ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>

Showing all locks held in the system:

1 lock held by khungtaskd/26:
#0: ffffffff87a94700 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
6 locks held by kworker/0:2/71:
#0: ffff888109b13538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888109b13538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888109b13538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff888109b13538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff888109b13538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff888109b13538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc90001057da8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffff88810f267190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff88810f267190 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4690 drivers/usb/core/hub.c:5674
#3: ffff88811d2ca190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#3: ffff88811d2ca190 (&dev->mutex){....}-{3:3}, at: usb_disconnect.cold+0x43/0x6ec drivers/usb/core/hub.c:2219
#4: ffff88811d2cb118 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#4: ffff88811d2cb118 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1054 [inline]
#4: ffff88811d2cb118 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa0/0x700 drivers/base/dd.c:1245
#5: ffff88811d2cc2c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_disconnect_device drivers/input/input.c:784 [inline]
#5: ffff88811d2cc2c0 (&dev->mutex#2){+.+.}-{3:3}, at: __input_unregister_device+0x24/0x470 drivers/input/input.c:2234
2 locks held by acpid/1166:
#0: ffff88811d2cf110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_close_device drivers/input/evdev.c:411 [inline]
#0: ffff88811d2cf110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_release+0x299/0x410 drivers/input/evdev.c:456
#1: ffff88811d2cc2c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_close_device+0x42/0x1f0 drivers/input/input.c:726
2 locks held by getty/1240:
#0: ffff8881109fc098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc900000432e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
3 locks held by udevd/1293:
#0: ffff8881106e6488 (&of->mutex){+.+.}-{3:3}, at: kernfs_file_read_iter fs/kernfs/file.c:197 [inline]
#0: ffff8881106e6488 (&of->mutex){+.+.}-{3:3}, at: kernfs_fop_read_iter+0x189/0x6e0 fs/kernfs/file.c:236
#1: ffff888108bf0a00 (kn->active#40){++++}-{0:0}, at: kernfs_file_read_iter fs/kernfs/file.c:198 [inline]
#1: ffff888108bf0a00 (kn->active#40){++++}-{0:0}, at: kernfs_fop_read_iter+0x1ac/0x6e0 fs/kernfs/file.c:236
#2: ffff88811d2ca190 (&dev->mutex){....}-{3:3}, at: device_lock_interruptible include/linux/device.h:840 [inline]
#2: ffff88811d2ca190 (&dev->mutex){....}-{3:3}, at: read_descriptors+0x3c/0x2c0 drivers/usb/core/sysfs.c:873

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

NMI backtrace for cpu 0
CPU: 0 PID: 26 Comm: khungtaskd Not tainted 5.19.0-rc4-syzkaller-00099-g90557fa89d3e #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022

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+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369

kthread+0x2ef/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at native_safe_halt arch/x86/include/asm/irqflags.h:51 [inline]
NMI backtrace for cpu 1 skipped: idling at arch_safe_halt arch/x86/include/asm/irqflags.h:89 [inline]
NMI backtrace for cpu 1 skipped: idling at acpi_safe_halt drivers/acpi/processor_idle.c:111 [inline]
NMI backtrace for cpu 1 skipped: idling at acpi_idle_do_entry+0x1c9/0x240 drivers/acpi/processor_idle.c:554

[syzbot]

syzbot has bisected this issue to:

commit 744d0090a5f6dfa4c81b53402ccdf08313100429
Author: Johan Hovold <jo...@kernel.org>
Date: Wed Nov 10 06:58:01 2021 +0000

Input: iforce - fix control-message timeout

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=1603376c080000
start commit: 089866061428 Merge tag 'libnvdimm-fixes-5.19-rc5' of git:/..
git tree: upstream
final oops: https://syzkaller.appspot.com/x/report.txt?x=1503376c080000
console output: https://syzkaller.appspot.com/x/log.txt?x=1103376c080000
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9
dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=158619f0080000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=1072b5f4080000

Reported-by: syzbot+deb6ab...@syzkaller.appspotmail.com
Fixes: 744d0090a5f6 ("Input: iforce - fix control-message timeout")

For information about bisection process see: https://goo.gl/tpsmEJ#bisection

[Hillf Danton]

On Sat, 02 Jul 2022 08:32:22 -0700

See if batman is a rcu hog.

#syz test http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git a175eca0f3d7

--- y/net/batman-adv/network-coding.c
+++ n/net/batman-adv/network-coding.c
@@ -396,11 +396,13 @@ static void batadv_nc_purge_orig_hash(st
struct batadv_hashtable *hash = bat_priv->orig_hash;
struct hlist_head *head;
struct batadv_orig_node *orig_node;
+ unsigned long j;
u32 i;

if (!hash)
return;

+ j = jiffies;
/* For each orig_node */
for (i = 0; i < hash->size; i++) {
head = &hash->table[i];
@@ -410,6 +412,11 @@ static void batadv_nc_purge_orig_hash(st
batadv_nc_purge_orig(bat_priv, orig_node,
batadv_nc_to_purge_nc_node);
rcu_read_unlock();
+
+ if (j + 2 < jiffies) {
+ schedule_timeout_idle(1);
+ j = jiffies;
+ }
}
}

--

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
INFO: task hung in __input_unregister_device

INFO: task kworker/1:1:26 blocked for more than 143 seconds.
Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/1:1 state:D stack:23328 pid: 26 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458

schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747
input_disconnect_device drivers/input/input.c:784 [inline]
__input_unregister_device+0x24/0x470 drivers/input/input.c:2234
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2429
iforce_usb_disconnect+0x5e/0xf0 drivers/input/joystick/iforce/iforce-usb.c:261
usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:545 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:537
__device_release_driver drivers/base/dd.c:1222 [inline]
device_release_driver_internal+0x4a1/0x700 drivers/base/dd.c:1248
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529
device_del+0x4f3/0xc80 drivers/base/core.c:3604
usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228

hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]
port_event drivers/usb/core/hub.c:5663 [inline]
hub_event+0x1e83/0x4690 drivers/usb/core/hub.c:5745

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438

kthread+0x2e9/0x3a0 kernel/kthread.c:376

ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>

Showing all locks held in the system:

6 locks held by kworker/1:1/26:
#0: ffff888011ad3138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888011ad3138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888011ad3138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff888011ad3138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff888011ad3138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff888011ad3138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc90000a1fda8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffff888147a97190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff888147a97190 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4690 drivers/usb/core/hub.c:5691
#3: ffff88807b9db190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#3: ffff88807b9db190 (&dev->mutex){....}-{3:3}, at: usb_disconnect.cold+0x43/0x6ec drivers/usb/core/hub.c:2219
#4: ffff88807b9de118 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#4: ffff88807b9de118 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1054 [inline]
#4: ffff88807b9de118 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa0/0x700 drivers/base/dd.c:1245
#5: ffff88807ed272c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_disconnect_device drivers/input/input.c:784 [inline]
#5: ffff88807ed272c0 (&dev->mutex#2){+.+.}-{3:3}, at: __input_unregister_device+0x24/0x470 drivers/input/input.c:2234

1 lock held by khungtaskd/28:

#0: ffffffff8bd86660 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491

2 locks held by acpid/2961:

#0: ffff88807c658158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_close_device drivers/input/joydev.c:220 [inline]
#0: ffff88807c658158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_release+0x187/0x290 drivers/input/joydev.c:252
#1: ffff88807ed272c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_close_device+0x42/0x1f0 drivers/input/input.c:726
2 locks held by getty/3285:
#0: ffff8881477a2098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002d162e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
3 locks held by udevd/4064:
#0: ffff888147515c88 (&of->mutex){+.+.}-{3:3}, at: kernfs_file_read_iter fs/kernfs/file.c:197 [inline]
#0: ffff888147515c88 (&of->mutex){+.+.}-{3:3}, at: kernfs_fop_read_iter+0x189/0x6e0 fs/kernfs/file.c:236
#1: ffff88802410dda0 (kn->active#86){++++}-{0:0}, at: kernfs_file_read_iter fs/kernfs/file.c:198 [inline]
#1: ffff88802410dda0 (kn->active#86){++++}-{0:0}, at: kernfs_fop_read_iter+0x1ac/0x6e0 fs/kernfs/file.c:236
#2: ffff88807b9db190 (&dev->mutex){....}-{3:3}, at: device_lock_interruptible include/linux/device.h:840 [inline]
#2: ffff88807b9db190 (&dev->mutex){....}-{3:3}, at: read_descriptors+0x3c/0x2c0 drivers/usb/core/sysfs.c:873
2 locks held by udevd/4067:
#0: ffff88807a669110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open_device drivers/input/evdev.c:393 [inline]
#0: ffff88807a669110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open+0x2f3/0x6a0 drivers/input/evdev.c:487
#1: ffff88807ed272c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_open_device+0x4a/0x320 drivers/input/input.c:656

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

NMI backtrace for cpu 1

CPU: 1 PID: 28 Comm: khungtaskd Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
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+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369

kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 1 to CPUs 0:

NMI backtrace for cpu 0

CPU: 0 PID: 4068 Comm: syz-executor.0 Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022

RIP: 0010:native_apic_mem_write+0x8/0x10 arch/x86/include/asm/apic.h:110
Code: 00 00 be 01 00 00 00 e9 06 74 2e 00 66 0f 1f 44 00 00 b8 01 00 00 00 c3 cc cc cc cc cc cc cc cc cc cc 89 ff 89 b7 00 c0 5f ff <c3> 0f 1f 80 00 00 00 00 48 b8 00 00 00 00 00 fc ff df 53 89 fb 48
RSP: 0018:ffffc9000305fb38 EFLAGS: 00000046
RAX: dffffc0000000000 RBX: ffffffff8b7fbae0 RCX: 0000000000000020
RDX: 1ffffffff16ff75e RSI: 000000000000ffa2 RDI: 0000000000000380
RBP: ffff8880b9a27200 R08: 0000000000000005 R09: 000000000000003f
R10: 0000000000000020 R11: 0000000000000001 R12: 000000000000ffa2
R13: 0000000000000020 R14: ffff8880b9a2a500 R15: 0000000000000000
FS: 0000555556d10400(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000

CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033

CR2: 00007f3cead8f110 CR3: 000000007226e000 CR4: 00000000003506f0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>

apic_write arch/x86/include/asm/apic.h:396 [inline]
lapic_next_event+0x4d/0x80 arch/x86/kernel/apic/apic.c:478
clockevents_program_event+0x254/0x370 kernel/time/clockevents.c:334
tick_program_event+0xac/0x140 kernel/time/tick-oneshot.c:44
__hrtimer_reprogram kernel/time/hrtimer.c:681 [inline]
hrtimer_reprogram+0x38c/0x440 kernel/time/hrtimer.c:866
hrtimer_start_range_ns+0x7af/0xa80 kernel/time/hrtimer.c:1299
hrtimer_start_expires include/linux/hrtimer.h:432 [inline]
hrtimer_sleeper_start_expires kernel/time/hrtimer.c:1965 [inline]
do_nanosleep+0x1e8/0x690 kernel/time/hrtimer.c:2041
hrtimer_nanosleep+0x1f9/0x4a0 kernel/time/hrtimer.c:2097
common_nsleep+0xa2/0xc0 kernel/time/posix-timers.c:1227
__do_sys_clock_nanosleep kernel/time/posix-timers.c:1267 [inline]
__se_sys_clock_nanosleep kernel/time/posix-timers.c:1245 [inline]
__x64_sys_clock_nanosleep+0x2f4/0x430 kernel/time/posix-timers.c:1245
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+0x46/0xb0
RIP: 0033:0x7f3ce9cade31
Code: 24 0c 89 3c 24 48 89 4c 24 18 e8 aa e7 ff ff 4c 8b 54 24 18 48 8b 54 24 10 41 89 c0 8b 74 24 0c 8b 3c 24 b8 e6 00 00 00 0f 05 <44> 89 c7 48 89 04 24 e8 e3 e7 ff ff 48 8b 04 24 eb 97 66 2e 0f 1f
RSP: 002b:00007ffddf9f8200 EFLAGS: 00000293 ORIG_RAX: 00000000000000e6
RAX: ffffffffffffffda RBX: 000000000000006d RCX: 00007f3ce9cade31
RDX: 00007ffddf9f8240 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00007ffddf9f82cc R08: 0000000000000000 R09: 00007ffddf9fa080
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000032
R13: 000000000003898b R14: 0000000000000000 R15: 00007ffddf9f8330

</TASK>
----------------
Code disassembly (best guess):
0: 00 00 add %al,(%rax)

2: be 01 00 00 00 mov $0x1,%esi
7: e9 06 74 2e 00 jmpq 0x2e7412
c: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
12: b8 01 00 00 00 mov $0x1,%eax
17: c3 retq
18: cc int3
19: cc int3
1a: cc int3
1b: cc int3
1c: cc int3
1d: cc int3
1e: cc int3
1f: cc int3
20: cc int3
21: cc int3
22: 89 ff mov %edi,%edi
24: 89 b7 00 c0 5f ff mov %esi,-0xa04000(%rdi)
* 2a: c3 retq <-- trapping instruction
2b: 0f 1f 80 00 00 00 00 nopl 0x0(%rax)
32: 48 b8 00 00 00 00 00 movabs $0xdffffc0000000000,%rax
39: fc ff df
3c: 53 push %rbx
3d: 89 fb mov %edi,%ebx
3f: 48 rex.W


Tested on:

commit: a175eca0 Merge tag 'drm-fixes-2022-07-01' of git://ano..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=16a9e6f0080000
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9

dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=1491b034080000

[Hillf Danton]

On Sat, 02 Jul 2022 08:32:22 -0700

v1, See if batman is a rcu hog.
v2, synchronize rcu without dev->mutex held.

#syz test http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git a175eca0f3d7

--- y/drivers/input/input.c
+++ n/drivers/input/input.c
@@ -677,12 +677,13 @@ int input_open_device(struct input_handl
if (retval) {
dev->users--;
handle->open--;
+ mutex_unlock(&dev->mutex);
/*
* Make sure we are not delivering any more events
* through this handle
*/
synchronize_rcu();
- goto out;
+ return retval;
}
}

--

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
INFO: task hung in __input_unregister_device

INFO: task kworker/0:2:142 blocked for more than 143 seconds.
Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/0:2 state:D stack:24456 pid: 142 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458

schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747

input_disconnect_device drivers/input/input.c:785 [inline]
__input_unregister_device+0x24/0x470 drivers/input/input.c:2235
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2430

iforce_usb_disconnect+0x5e/0xf0 drivers/input/joystick/iforce/iforce-usb.c:261
usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:545 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:537
__device_release_driver drivers/base/dd.c:1222 [inline]
device_release_driver_internal+0x4a1/0x700 drivers/base/dd.c:1248
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529
device_del+0x4f3/0xc80 drivers/base/core.c:3604
usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228

hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]
port_event drivers/usb/core/hub.c:5663 [inline]
hub_event+0x1e83/0x4690 drivers/usb/core/hub.c:5745

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438

kthread+0x2e9/0x3a0 kernel/kthread.c:376

ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>

Showing all locks held in the system:

1 lock held by khungtaskd/28:
#0: ffffffff8bd86660 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
6 locks held by kworker/0:2/142:
#0: ffff88801741b938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff88801741b938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff88801741b938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff88801741b938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff88801741b938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff88801741b938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc900029bfda8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffff888147aaf190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff888147aaf190 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4690 drivers/usb/core/hub.c:5691
#3: ffff88814713f190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#3: ffff88814713f190 (&dev->mutex){....}-{3:3}, at: usb_disconnect.cold+0x43/0x6ec drivers/usb/core/hub.c:2219
#4: ffff888147139118 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#4: ffff888147139118 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1054 [inline]
#4: ffff888147139118 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa0/0x700 drivers/base/dd.c:1245
#5: ffff8881471382c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_disconnect_device drivers/input/input.c:785 [inline]
#5: ffff8881471382c0 (&dev->mutex#2){+.+.}-{3:3}, at: __input_unregister_device+0x24/0x470 drivers/input/input.c:2235
2 locks held by syslogd/2958:
#0: ffff8880b9b39ed8 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:544
#1: ffffffff8bd86660 (rcu_read_lock){....}-{1:2}, at: inode_lock include/linux/fs.h:741 [inline]
#1: ffffffff8bd86660 (rcu_read_lock){....}-{1:2}, at: generic_file_write_iter+0x8a/0x220 mm/filemap.c:3936

2 locks held by acpid/2961:

#0: ffff888076e50158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_close_device drivers/input/joydev.c:220 [inline]
#0: ffff888076e50158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_release+0x187/0x290 drivers/input/joydev.c:252
#1: ffff8881471382c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_close_device+0x42/0x1f0 drivers/input/input.c:727
2 locks held by getty/3289:
#0: ffff88807ee70098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002d162e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
2 locks held by udevd/4091:
#0: ffff88814ae63110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open_device drivers/input/evdev.c:393 [inline]
#0: ffff88814ae63110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open+0x2f3/0x6a0 drivers/input/evdev.c:487
#1: ffff8881471382c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_open_device+0x4a/0x320 drivers/input/input.c:656

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

NMI backtrace for cpu 1

CPU: 1 PID: 28 Comm: khungtaskd Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
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+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369

kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 1 to CPUs 0:

NMI backtrace for cpu 0

CPU: 0 PID: 8 Comm: kworker/u4:0 Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022

Workqueue: bat_events batadv_purge_orig
RIP: 0010:native_save_fl arch/x86/include/asm/irqflags.h:29 [inline]
RIP: 0010:arch_local_save_flags arch/x86/include/asm/irqflags.h:70 [inline]
RIP: 0010:arch_irqs_disabled arch/x86/include/asm/irqflags.h:130 [inline]
RIP: 0010:__local_bh_enable_ip+0x5d/0x120 kernel/softirq.c:378
Code: 03 83 c0 03 0f b6 14 11 38 d0 7c 08 84 d2 0f 85 c5 00 00 00 8b 05 ff 76 73 0c 85 c0 74 0b 65 8b 05 f0 2a ba 7e 85 c0 74 53 9c <58> fa f6 c4 02 75 5a 65 8b 05 15 21 ba 7e 25 00 ff 00 00 3d 00 02
RSP: 0018:ffffc900000d7bd0 EFLAGS: 00000202
RAX: 0000000000000001 RBX: 0000000000000201 RCX: 1ffffffff1b778a1
RDX: 0000000000000000 RSI: 0000000000000201 RDI: ffffffff891218b7
RBP: ffffffff891218b7 R08: 0000000000000000 R09: ffff8880703e0783
R10: ffffed100e07c0f0 R11: 0000000000000000 R12: dffffc0000000000
R13: ffffc900000d7da8 R14: ffff8880119b7900 R15: 000000000000001e
FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000

CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033

CR2: 00007fc54d501110 CR3: 000000000ba8e000 CR4: 00000000003506f0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>

spin_unlock_bh include/linux/spinlock.h:394 [inline]
batadv_purge_orig_ref+0xeb7/0x1550 net/batman-adv/originator.c:1259
batadv_purge_orig+0x17/0x60 net/batman-adv/originator.c:1272

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
worker_thread+0x665/0x1080 kernel/workqueue.c:2436

kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>

----------------
Code disassembly (best guess):

0: 03 83 c0 03 0f b6 add -0x49f0fc40(%rbx),%eax
6: 14 11 adc $0x11,%al
8: 38 d0 cmp %dl,%al
a: 7c 08 jl 0x14
c: 84 d2 test %dl,%dl
e: 0f 85 c5 00 00 00 jne 0xd9
14: 8b 05 ff 76 73 0c mov 0xc7376ff(%rip),%eax # 0xc737719
1a: 85 c0 test %eax,%eax
1c: 74 0b je 0x29
1e: 65 8b 05 f0 2a ba 7e mov %gs:0x7eba2af0(%rip),%eax # 0x7eba2b15
25: 85 c0 test %eax,%eax
27: 74 53 je 0x7c
29: 9c pushfq
* 2a: 58 pop %rax <-- trapping instruction
2b: fa cli
2c: f6 c4 02 test $0x2,%ah
2f: 75 5a jne 0x8b
31: 65 8b 05 15 21 ba 7e mov %gs:0x7eba2115(%rip),%eax # 0x7eba214d
38: 25 00 ff 00 00 and $0xff00,%eax
3d: 3d .byte 0x3d
3e: 00 02 add %al,(%rdx)

Tested on:

commit: a175eca0 Merge tag 'drm-fixes-2022-07-01' of git://ano..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git

console output: https://syzkaller.appspot.com/x/log.txt?x=14c88434080000
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9

dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=17ed9168080000

[Hillf Danton]

On Sat, 02 Jul 2022 08:32:22 -0700

v1, See if batman is a rcu hog.

v2, synchronize rcu without dev->mutex held in the open path.
v3, synchronize rcu without dev->mutex held in the close path.

#syz test http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git a175eca0f3d7

--- y/drivers/input/input.c
+++ n/drivers/input/input.c
@@ -677,12 +677,13 @@ int input_open_device(struct input_handl
if (retval) {
dev->users--;
handle->open--;
+ mutex_unlock(&dev->mutex);
/*
* Make sure we are not delivering any more events
* through this handle
*/
synchronize_rcu();
- goto out;
+ return retval;
}
}

@@ -722,6 +723,7 @@ EXPORT_SYMBOL(input_flush_device);
void input_close_device(struct input_handle *handle)
{
struct input_dev *dev = handle->dev;
+ int sync = 0;

mutex_lock(&dev->mutex);

@@ -740,10 +742,12 @@ void input_close_device(struct input_han
* completed and that no more input events are delivered

* through this handle
*/

- synchronize_rcu();
+ sync = 1;
}

mutex_unlock(&dev->mutex);
+ if (sync)
+ synchronize_rcu();
}
EXPORT_SYMBOL(input_close_device);

--

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
INFO: task hung in __input_unregister_device

INFO: task kworker/1:4:3628 blocked for more than 143 seconds.
Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/1:4 state:D stack:22768 pid: 3628 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458

schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747

input_disconnect_device drivers/input/input.c:788 [inline]
__input_unregister_device+0x24/0x470 drivers/input/input.c:2238
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2433

iforce_usb_disconnect+0x5e/0xf0 drivers/input/joystick/iforce/iforce-usb.c:261
usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:545 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:537
__device_release_driver drivers/base/dd.c:1222 [inline]
device_release_driver_internal+0x4a1/0x700 drivers/base/dd.c:1248
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529
device_del+0x4f3/0xc80 drivers/base/core.c:3604
usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228

hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]
port_event drivers/usb/core/hub.c:5663 [inline]
hub_event+0x1e83/0x4690 drivers/usb/core/hub.c:5745

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438

kthread+0x2e9/0x3a0 kernel/kthread.c:376

ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>

Showing all locks held in the system:

1 lock held by khungtaskd/28:
#0: ffffffff8bd86660 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
5 locks held by kworker/u4:3/51:
2 locks held by kworker/u4:5/1185:
#0: ffff8880b9a39ed8 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:544
#1: ffff8880b9a277c8 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x3e7/0x4e0 kernel/sched/psi.c:889
2 locks held by acpid/2962:
#0: ffff88807d7e0158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_close_device drivers/input/joydev.c:220 [inline]
#0: ffff88807d7e0158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_release+0x187/0x290 drivers/input/joydev.c:252
#1: ffff88802127a2c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_close_device+0x42/0x200 drivers/input/input.c:728
2 locks held by getty/3287:
#0: ffff88814aa77098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002d162e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
6 locks held by kworker/1:4/3628:
#0: ffff88801723f538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff88801723f538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff88801723f538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff88801723f538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff88801723f538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff88801723f538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc9000308fda8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffff888147a84190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff888147a84190 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4690 drivers/usb/core/hub.c:5691
#3: ffff888021278190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#3: ffff888021278190 (&dev->mutex){....}-{3:3}, at: usb_disconnect.cold+0x43/0x6ec drivers/usb/core/hub.c:2219
#4: ffff888021279118 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#4: ffff888021279118 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1054 [inline]
#4: ffff888021279118 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa0/0x700 drivers/base/dd.c:1245
#5: ffff88802127a2c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_disconnect_device drivers/input/input.c:788 [inline]
#5: ffff88802127a2c0 (&dev->mutex#2){+.+.}-{3:3}, at: __input_unregister_device+0x24/0x470 drivers/input/input.c:2238
2 locks held by udevd/4068:
#0: ffff88802127d110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open_device drivers/input/evdev.c:393 [inline]
#0: ffff88802127d110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open+0x2f3/0x6a0 drivers/input/evdev.c:487
#1: ffff88802127a2c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_open_device+0x4a/0x320 drivers/input/input.c:656

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

NMI backtrace for cpu 1

CPU: 1 PID: 28 Comm: khungtaskd Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
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+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369

kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 1 to CPUs 0:

NMI backtrace for cpu 0

CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022

RIP: 0010:__mod_timer+0x386/0xe30 kernel/time/timer.c:1072
Code: c0 74 09 3c 03 7f 05 e8 58 f7 5c 00 8b 5d 20 44 89 ff c1 eb 16 89 de e8 b8 2e 10 00 41 39 df 0f 85 fd 00 00 00 e9 1f 08 00 00 <e8> e5 32 10 00 48 89 ef 48 8d 74 24 60 e8 58 78 ff ff 48 c7 c2 00
RSP: 0018:ffffc90000007b98 EFLAGS: 00000002
RAX: 0000000000000000 RBX: 0000000000000004 RCX: ffffffff816a30fa
RDX: ffffffff8babc940 RSI: 0000000000000100 RDI: 0000000000000005
RBP: ffffffff91283ce0 R08: 0000000000000005 R09: 0000000000000000
R10: 0000000000000004 R11: 0000000000000001 R12: 00000000ffffffff
R13: 1ffff92000000fa8 R14: 00000000002000f1 R15: 0000000000000000

FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033

CR2: 00007f3644ba0000 CR3: 0000000025674000 CR4: 00000000003506f0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:

<IRQ>
dsp_cmx_send+0xbf3/0x1580 drivers/isdn/mISDN/dsp_cmx.c:1850
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1474
expire_timers kernel/time/timer.c:1519 [inline]
__run_timers.part.0+0x679/0xa80 kernel/time/timer.c:1790
__run_timers kernel/time/timer.c:1768 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1803
__do_softirq+0x29b/0x9c2 kernel/softirq.c:571
invoke_softirq kernel/softirq.c:445 [inline]
__irq_exit_rcu+0x123/0x180 kernel/softirq.c:650
irq_exit_rcu+0x5/0x20 kernel/softirq.c:662
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1106
</IRQ>
<TASK>
asm_sysvec_apic_timer_interrupt+0x1b/0x20 arch/x86/include/asm/idtentry.h:649

RIP: 0010:native_save_fl arch/x86/include/asm/irqflags.h:29 [inline]
RIP: 0010:arch_local_save_flags arch/x86/include/asm/irqflags.h:70 [inline]
RIP: 0010:arch_irqs_disabled arch/x86/include/asm/irqflags.h:130 [inline]

RIP: 0010:acpi_safe_halt drivers/acpi/processor_idle.c:112 [inline]
RIP: 0010:acpi_idle_do_entry+0x1c9/0x240 drivers/acpi/processor_idle.c:554
Code: 89 de e8 8a 08 00 f8 84 db 75 98 e8 81 0c 00 f8 e8 ac 5a 06 f8 66 90 e8 75 0c 00 f8 0f 00 2d be b8 b9 00 e8 69 0c 00 f8 fb f4 <9c> 5b 81 e3 00 02 00 00 fa 31 ff 48 89 de e8 b4 08 00 f8 48 85 db
RSP: 0018:ffffffff8ba07d38 EFLAGS: 00000293
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: ffffffff8babc940 RSI: ffffffff897a5a47 RDI: 0000000000000000
RBP: ffff888017258864 R08: 0000000000000001 R09: 0000000000000001
R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000001
R13: ffff888017258800 R14: ffff888017258864 R15: ffff888145c9c804
acpi_idle_enter+0x369/0x510 drivers/acpi/processor_idle.c:691
cpuidle_enter_state+0x1b1/0xc80 drivers/cpuidle/cpuidle.c:237
cpuidle_enter+0x4a/0xa0 drivers/cpuidle/cpuidle.c:351
call_cpuidle kernel/sched/idle.c:155 [inline]
cpuidle_idle_call kernel/sched/idle.c:236 [inline]
do_idle+0x3e8/0x590 kernel/sched/idle.c:303
cpu_startup_entry+0x14/0x20 kernel/sched/idle.c:400
rest_init+0x169/0x270 init/main.c:726
arch_call_rest_init+0xf/0x14 init/main.c:882
start_kernel+0x46e/0x48f init/main.c:1137
secondary_startup_64_no_verify+0xce/0xdb

</TASK>
----------------
Code disassembly (best guess):

0: c0 74 09 3c 03 shlb $0x3,0x3c(%rcx,%rcx,1)
5: 7f 05 jg 0xc
7: e8 58 f7 5c 00 callq 0x5cf764
c: 8b 5d 20 mov 0x20(%rbp),%ebx
f: 44 89 ff mov %r15d,%edi
12: c1 eb 16 shr $0x16,%ebx
15: 89 de mov %ebx,%esi
17: e8 b8 2e 10 00 callq 0x102ed4
1c: 41 39 df cmp %ebx,%r15d
1f: 0f 85 fd 00 00 00 jne 0x122
25: e9 1f 08 00 00 jmpq 0x849
* 2a: e8 e5 32 10 00 callq 0x103314 <-- trapping instruction
2f: 48 89 ef mov %rbp,%rdi
32: 48 8d 74 24 60 lea 0x60(%rsp),%rsi
37: e8 58 78 ff ff callq 0xffff7894
3c: 48 rex.W
3d: c7 .byte 0xc7
3e: c2 .byte 0xc2

Tested on:

commit: a175eca0 Merge tag 'drm-fixes-2022-07-01' of git://ano..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git

console output: https://syzkaller.appspot.com/x/log.txt?x=135ba7fff00000
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9

dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=1272e084080000

[Hillf Danton]

On Sat, 02 Jul 2022 08:32:22 -0700

v1, See if batman is a rcu hog.
v2, synchronize rcu without dev->mutex held in the open path.
v3, synchronize rcu without dev->mutex held in the close path.

v4, synchronize rcu without dev->mutex held in the release path.

#syz test http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git a175eca0f3d7

--- y/drivers/input/input.c
+++ n/drivers/input/input.c

@@ -604,22 +604,24 @@ int input_grab_device(struct input_handl
}
EXPORT_SYMBOL(input_grab_device);

-static void __input_release_device(struct input_handle *handle)
+static int __input_release_device(struct input_handle *handle)

{
struct input_dev *dev = handle->dev;

struct input_handle *grabber;

+ int sync = 0;

grabber = rcu_dereference_protected(dev->grab,
lockdep_is_held(&dev->mutex));
if (grabber == handle) {
rcu_assign_pointer(dev->grab, NULL);
/* Make sure input_pass_event() notices that grab is gone */

- synchronize_rcu();
+ sync = 1;

list_for_each_entry(handle, &dev->h_list, d_node)
if (handle->open && handle->handler->start)
handle->handler->start(handle);
}
+ return sync;
}

/**
@@ -634,10 +636,13 @@ static void __input_release_device(struc
void input_release_device(struct input_handle *handle)

{
struct input_dev *dev = handle->dev;

+ int sync;

mutex_lock(&dev->mutex);
- __input_release_device(handle);
+ sync = __input_release_device(handle);

mutex_unlock(&dev->mutex);
+ if (sync)
+ synchronize_rcu();
}

EXPORT_SYMBOL(input_release_device);

@@ -677,12 +682,13 @@ int input_open_device(struct input_handl

if (retval) {
dev->users--;
handle->open--;
+ mutex_unlock(&dev->mutex);
/*
* Make sure we are not delivering any more events
* through this handle
*/
synchronize_rcu();
- goto out;
+ return retval;
}
}

@@ -722,10 +728,11 @@ EXPORT_SYMBOL(input_flush_device);

void input_close_device(struct input_handle *handle)
{
struct input_dev *dev = handle->dev;
+ int sync = 0;

mutex_lock(&dev->mutex);

- __input_release_device(handle);
+ sync = __input_release_device(handle);

if (!dev->inhibited && !--dev->users) {
if (dev->poller)
@@ -740,10 +747,12 @@ void input_close_device(struct input_han

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
INFO: task hung in __input_unregister_device

INFO: task kworker/0:1:14 blocked for more than 143 seconds.
Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/0:1 state:D stack:24296 pid: 14 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458

schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747

input_disconnect_device drivers/input/input.c:793 [inline]
__input_unregister_device+0x24/0x470 drivers/input/input.c:2243
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2438

iforce_usb_disconnect+0x5e/0xf0 drivers/input/joystick/iforce/iforce-usb.c:261
usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:545 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:537
__device_release_driver drivers/base/dd.c:1222 [inline]
device_release_driver_internal+0x4a1/0x700 drivers/base/dd.c:1248
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529
device_del+0x4f3/0xc80 drivers/base/core.c:3604
usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228

hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]
port_event drivers/usb/core/hub.c:5663 [inline]
hub_event+0x1e83/0x4690 drivers/usb/core/hub.c:5745

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438

kthread+0x2e9/0x3a0 kernel/kthread.c:376

ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>

Showing all locks held in the system:

6 locks held by kworker/0:1/14:
#0: ffff8881458a0538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff8881458a0538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff8881458a0538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff8881458a0538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff8881458a0538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff8881458a0538 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc90000137da8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffff888020a04190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff888020a04190 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4690 drivers/usb/core/hub.c:5691
#3: ffff888146de5190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#3: ffff888146de5190 (&dev->mutex){....}-{3:3}, at: usb_disconnect.cold+0x43/0x6ec drivers/usb/core/hub.c:2219
#4: ffff888146de3118 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#4: ffff888146de3118 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1054 [inline]
#4: ffff888146de3118 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa0/0x700 drivers/base/dd.c:1245
#5: ffff88807df402c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_disconnect_device drivers/input/input.c:793 [inline]
#5: ffff88807df402c0 (&dev->mutex#2){+.+.}-{3:3}, at: __input_unregister_device+0x24/0x470 drivers/input/input.c:2243
1 lock held by khungtaskd/27:
#0: ffffffff8bd86660 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
2 locks held by acpid/2960:
#0: ffff88807dcec158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_close_device drivers/input/joydev.c:220 [inline]
#0: ffff88807dcec158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_release+0x187/0x290 drivers/input/joydev.c:252
#1: ffff88807df402c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_close_device+0x44/0x220 drivers/input/input.c:733

2 locks held by getty/3285:

#0: ffff88814b110098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002d162e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
3 locks held by udevd/4093:
#0: ffff88807e905488 (&of->mutex){+.+.}-{3:3}, at: kernfs_file_read_iter fs/kernfs/file.c:197 [inline]
#0: ffff88807e905488 (&of->mutex){+.+.}-{3:3}, at: kernfs_fop_read_iter+0x189/0x6e0 fs/kernfs/file.c:236
#1: ffff88806f5b50f0 (kn->active#86){++++}-{0:0}, at: kernfs_file_read_iter fs/kernfs/file.c:198 [inline]
#1: ffff88806f5b50f0 (kn->active#86){++++}-{0:0}, at: kernfs_fop_read_iter+0x1ac/0x6e0 fs/kernfs/file.c:236
#2: ffff888146de5190 (&dev->mutex){....}-{3:3}, at: device_lock_interruptible include/linux/device.h:840 [inline]
#2: ffff888146de5190 (&dev->mutex){....}-{3:3}, at: read_descriptors+0x3c/0x2c0 drivers/usb/core/sysfs.c:873

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

NMI backtrace for cpu 0

CPU: 0 PID: 27 Comm: khungtaskd Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
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+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369

kthread+0x2e9/0x3a0 kernel/kthread.c:376

ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1

CPU: 1 PID: 4070 Comm: syz-executor.0 Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022

RIP: 0010:__pvclock_read_cycles arch/x86/include/asm/pvclock.h:86 [inline]
RIP: 0010:pvclock_clocksource_read+0x91/0x530 arch/x86/kernel/pvclock.c:76
Code: 43 08 8b 0b 48 bd 00 00 00 00 00 fc ff df 48 8d 7b 1c 48 89 44 24 10 48 c1 e8 03 48 8d 53 1b 49 89 c5 48 89 f8 48 89 7c 24 18 <4c> 8d 4b 0f 48 c1 e8 03 48 89 14 24 49 01 ed 4c 8d 43 18 48 01 e8
RSP: 0018:ffffc90002fafe20 EFLAGS: 00000806
RAX: ffffffff8f2ad05c RBX: ffffffff8f2ad040 RCX: 0000000000000004
RDX: ffffffff8f2ad05b RSI: 0000000000000000 RDI: ffffffff8f2ad05c
RBP: dffffc0000000000 R08: 0000000000000000 R09: ffffffff90680917
R10: fffffbfff20d0122 R11: 0000000000000001 R12: ffffffff8f2ad043
R13: 1ffffffff1e55a09 R14: 0000000000000000 R15: ffff88801d2824a8
FS: 0000555555f7a400(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000

CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033

CR2: 0000555555f7a708 CR3: 000000007435c000 CR4: 00000000003506e0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:

<TASK>
kvm_clock_read arch/x86/kernel/kvmclock.c:79 [inline]
kvm_sched_clock_read+0x14/0x40 arch/x86/kernel/kvmclock.c:91
vtime_delta kernel/sched/cputime.c:637 [inline]
get_vtime_delta kernel/sched/cputime.c:646 [inline]
vtime_user_exit+0xbc/0x6c0 kernel/sched/cputime.c:720
__context_tracking_exit+0xb8/0xe0 kernel/context_tracking.c:160
user_exit_irqoff include/linux/context_tracking.h:47 [inline]
__enter_from_user_mode kernel/entry/common.c:24 [inline]
syscall_enter_from_user_mode+0x4c/0x70 kernel/entry/common.c:106
do_syscall_64+0x16/0xb0 arch/x86/entry/common.c:76
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7fbe204ade31

Code: 24 0c 89 3c 24 48 89 4c 24 18 e8 aa e7 ff ff 4c 8b 54 24 18 48 8b 54 24 10 41 89 c0 8b 74 24 0c 8b 3c 24 b8 e6 00 00 00 0f 05 <44> 89 c7 48 89 04 24 e8 e3 e7 ff ff 48 8b 04 24 eb 97 66 2e 0f 1f

RSP: 002b:00007fff04d571e0 EFLAGS: 00000293 ORIG_RAX: 00000000000000e6
RAX: ffffffffffffffda RBX: 0000000000000085 RCX: 00007fbe204ade31
RDX: 00007fff04d57220 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00007fff04d572ac R08: 0000000000000000 R09: 00007fff04dbc080

R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000032

R13: 000000000003dbc7 R14: 0000000000000000 R15: 00007fff04d57310
</TASK>
----------------
Code disassembly (best guess), 2 bytes skipped:
0: 8b 0b mov (%rbx),%ecx
2: 48 bd 00 00 00 00 00 movabs $0xdffffc0000000000,%rbp
9: fc ff df
c: 48 8d 7b 1c lea 0x1c(%rbx),%rdi
10: 48 89 44 24 10 mov %rax,0x10(%rsp)
15: 48 c1 e8 03 shr $0x3,%rax
19: 48 8d 53 1b lea 0x1b(%rbx),%rdx
1d: 49 89 c5 mov %rax,%r13
20: 48 89 f8 mov %rdi,%rax
23: 48 89 7c 24 18 mov %rdi,0x18(%rsp)
* 28: 4c 8d 4b 0f lea 0xf(%rbx),%r9 <-- trapping instruction
2c: 48 c1 e8 03 shr $0x3,%rax
30: 48 89 14 24 mov %rdx,(%rsp)
34: 49 01 ed add %rbp,%r13
37: 4c 8d 43 18 lea 0x18(%rbx),%r8
3b: 48 01 e8 add %rbp,%rax

Tested on:

commit: a175eca0 Merge tag 'drm-fixes-2022-07-01' of git://ano..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git

console output: https://syzkaller.appspot.com/x/log.txt?x=15812020080000
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9

dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=16a4c000080000

[Hillf Danton]

On Sat, 02 Jul 2022 08:32:22 -0700

v1, See if batman is a rcu hog.
v2, synchronize rcu without dev->mutex held in the open path.
v3, synchronize rcu without dev->mutex held in the close path.
v4, synchronize rcu without dev->mutex held in the release path.

v5, replace mutex with rcu and see what will happen

#syz test http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git a175eca0f3d7

--- y/drivers/input/input.c
+++ n/drivers/input/input.c

@@ -781,9 +781,8 @@ static void input_disconnect_device(stru
* not to protect access to dev->going_away but rather to ensure
* that there are no threads in the middle of input_open_device()
*/
- mutex_lock(&dev->mutex);
dev->going_away = true;
- mutex_unlock(&dev->mutex);
+ synchronize_rcu();

spin_lock_irq(&dev->event_lock);

--

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:

INFO: task hung in joydev_cleanup

INFO: task kworker/0:0:6 blocked for more than 143 seconds.
Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/0:0 state:D stack:24472 pid: 6 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458

schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747

joydev_mark_dead drivers/input/joydev.c:731 [inline]
joydev_cleanup+0x21/0x190 drivers/input/joydev.c:740
joydev_disconnect+0x45/0xb0 drivers/input/joydev.c:1022
__input_unregister_device+0x1f1/0x460 drivers/input/input.c:2238
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2428

iforce_usb_disconnect+0x5e/0xf0 drivers/input/joystick/iforce/iforce-usb.c:261
usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:545 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:537
__device_release_driver drivers/base/dd.c:1222 [inline]
device_release_driver_internal+0x4a1/0x700 drivers/base/dd.c:1248
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529
device_del+0x4f3/0xc80 drivers/base/core.c:3604
usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228

hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]
port_event drivers/usb/core/hub.c:5663 [inline]
hub_event+0x1e83/0x4690 drivers/usb/core/hub.c:5745

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438

kthread+0x2e9/0x3a0 kernel/kthread.c:376

ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>

Showing all locks held in the system:

7 locks held by kworker/0:0/6:
#0: ffff8881459c3938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff8881459c3938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff8881459c3938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff8881459c3938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff8881459c3938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff8881459c3938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc900000b7da8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffff888147879190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff888147879190 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4690 drivers/usb/core/hub.c:5691
#3: ffff8880173a9190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#3: ffff8880173a9190 (&dev->mutex){....}-{3:3}, at: usb_disconnect.cold+0x43/0x6ec drivers/usb/core/hub.c:2219
#4: ffff8880173ae118 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#4: ffff8880173ae118 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1054 [inline]
#4: ffff8880173ae118 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa0/0x700 drivers/base/dd.c:1245
#5: ffffffff8ceafca8 (input_mutex){+.+.}-{3:3}, at: __input_unregister_device+0x158/0x460 drivers/input/input.c:2235
#6: ffff88807bab4158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_mark_dead drivers/input/joydev.c:731 [inline]
#6: ffff88807bab4158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_cleanup+0x21/0x190 drivers/input/joydev.c:740

1 lock held by khungtaskd/28:

#0: ffffffff8bd86660 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
2 locks held by acpid/2960:

#0: ffff88807bab4158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_close_device drivers/input/joydev.c:220 [inline]
#0: ffff88807bab4158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_release+0x187/0x290 drivers/input/joydev.c:252
#1: ffff8880173af2c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_close_device+0x42/0x1f0 drivers/input/input.c:726
2 locks held by getty/3287:
#0: ffff88802616e098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002d162e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
2 locks held by udevd/4084:
#0: ffff8881458fa110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open_device drivers/input/evdev.c:393 [inline]
#0: ffff8881458fa110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open+0x2f3/0x6a0 drivers/input/evdev.c:487
#1: ffff8880173af2c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_open_device+0x4a/0x320 drivers/input/input.c:656

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

NMI backtrace for cpu 1

CPU: 1 PID: 28 Comm: khungtaskd Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
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+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369

kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 1 to CPUs 0:

NMI backtrace for cpu 0

CPU: 0 PID: 41 Comm: kworker/u4:2 Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022

Workqueue: phy5 ieee80211_iface_work
RIP: 0010:next_tid mm/slub.c:2311 [inline]
RIP: 0010:___slab_alloc+0x74b/0xe20 mm/slub.c:2985
Code: 8b 34 24 48 89 43 10 8b 05 5e 20 f5 0b 85 c0 0f 85 80 03 00 00 48 8b 43 10 80 78 2b 00 0f 89 25 04 00 00 8b 45 28 49 8b 04 06 <48> 83 43 08 08 48 89 03 48 8b 5d 00 e8 c4 bf b0 07 89 c5 48 83 c3
RSP: 0018:ffffc90000b27700 EFLAGS: 00000082
RAX: ffff888020bfa000 RBX: ffff8880b9a3db80 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000000
RBP: ffff888011841dc0 R08: 0000000000000000 R09: 0000000080100010
R10: ffffffff81c69e72 R11: 0000000000000000 R12: 000000000003dba0
R13: 0000000000000246 R14: ffff888020bfb000 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000

CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033

CR2: 00007f4fd6a83110 CR3: 000000000ba8e000 CR4: 00000000003506f0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>

__slab_alloc.constprop.0+0x4d/0xa0 mm/slub.c:3118
slab_alloc_node mm/slub.c:3209 [inline]
slab_alloc mm/slub.c:3251 [inline]
kmem_cache_alloc_trace+0x310/0x3f0 mm/slub.c:3282
kmalloc include/linux/slab.h:600 [inline]
kzalloc include/linux/slab.h:733 [inline]
ieee802_11_parse_elems_crc+0xd5/0x1050 net/mac80211/util.c:1502
ieee802_11_parse_elems net/mac80211/ieee80211_i.h:2257 [inline]
ieee80211_bss_info_update+0x42c/0xb00 net/mac80211/scan.c:212
ieee80211_rx_bss_info net/mac80211/ibss.c:1119 [inline]
ieee80211_rx_mgmt_probe_beacon net/mac80211/ibss.c:1610 [inline]
ieee80211_ibss_rx_queued_mgmt+0x1ab8/0x33f0 net/mac80211/ibss.c:1639
ieee80211_iface_process_skb net/mac80211/iface.c:1527 [inline]
ieee80211_iface_work+0xa78/0xd10 net/mac80211/iface.c:1581

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
worker_thread+0x665/0x1080 kernel/workqueue.c:2436

kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>

----------------
Code disassembly (best guess):

0: 8b 34 24 mov (%rsp),%esi
3: 48 89 43 10 mov %rax,0x10(%rbx)
7: 8b 05 5e 20 f5 0b mov 0xbf5205e(%rip),%eax # 0xbf5206b
d: 85 c0 test %eax,%eax
f: 0f 85 80 03 00 00 jne 0x395
15: 48 8b 43 10 mov 0x10(%rbx),%rax
19: 80 78 2b 00 cmpb $0x0,0x2b(%rax)
1d: 0f 89 25 04 00 00 jns 0x448
23: 8b 45 28 mov 0x28(%rbp),%eax
26: 49 8b 04 06 mov (%r14,%rax,1),%rax
* 2a: 48 83 43 08 08 addq $0x8,0x8(%rbx) <-- trapping instruction
2f: 48 89 03 mov %rax,(%rbx)
32: 48 8b 5d 00 mov 0x0(%rbp),%rbx
36: e8 c4 bf b0 07 callq 0x7b0bfff
3b: 89 c5 mov %eax,%ebp
3d: 48 rex.W
3e: 83 .byte 0x83
3f: c3 retq

Tested on:

commit: a175eca0 Merge tag 'drm-fixes-2022-07-01' of git://ano..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git

console output: https://syzkaller.appspot.com/x/log.txt?x=1626aa58080000
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9

dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=15b3b658080000

[Hillf Danton]

On Sat, 02 Jul 2022 08:32:22 -0700

v1, See if batman is a rcu hog.
v2, synchronize rcu without dev->mutex held in the open path.
v3, synchronize rcu without dev->mutex held in the close path.
v4, synchronize rcu without dev->mutex held in the release path.

v5, replace mutex with rcu in input_disconnect_device() and see what will happen
v6, replace mutex with rcu in joydev_mark_dead()

#syz test http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git a175eca0f3d7

--- y/drivers/input/input.c
+++ n/drivers/input/input.c
@@ -781,9 +781,8 @@ static void input_disconnect_device(stru
* not to protect access to dev->going_away but rather to ensure
* that there are no threads in the middle of input_open_device()
*/
- mutex_lock(&dev->mutex);
dev->going_away = true;
- mutex_unlock(&dev->mutex);
+ synchronize_rcu();

spin_lock_irq(&dev->event_lock);

--- a/drivers/input/joydev.c
+++ b/drivers/input/joydev.c
@@ -728,9 +728,8 @@ static const struct file_operations joyd
*/
static void joydev_mark_dead(struct joydev *joydev)
{
- mutex_lock(&joydev->mutex);
joydev->exist = false;
- mutex_unlock(&joydev->mutex);
+ synchronize_rcu();
}

static void joydev_cleanup(struct joydev *joydev)
--

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:

INFO: task hung in input_unregister_handle

INFO: task kworker/1:2:143 blocked for more than 143 seconds.
Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/1:2 state:D stack:23672 pid: 143 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458

schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747

input_unregister_handle+0x128/0x290 drivers/input/input.c:2592
joydev_disconnect+0xfb/0x150 drivers/input/joydev.c:1023

__input_unregister_device+0x1f1/0x460 drivers/input/input.c:2238
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2428

iforce_usb_disconnect+0x5e/0xf0 drivers/input/joystick/iforce/iforce-usb.c:261
usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:545 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:537
__device_release_driver drivers/base/dd.c:1222 [inline]
device_release_driver_internal+0x4a1/0x700 drivers/base/dd.c:1248
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529
device_del+0x4f3/0xc80 drivers/base/core.c:3604
usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228

hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]
port_event drivers/usb/core/hub.c:5663 [inline]
hub_event+0x1e83/0x4690 drivers/usb/core/hub.c:5745

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438

kthread+0x2e9/0x3a0 kernel/kthread.c:376

ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>

Showing all locks held in the system:

1 lock held by khungtaskd/28:
#0: ffffffff8bd86660 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
3 locks held by kworker/u4:2/41:
7 locks held by kworker/1:2/143:
#0: ffff888011a65938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888011a65938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888011a65938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff888011a65938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff888011a65938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff888011a65938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc90002b9fda8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffff88802011d190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#2: ffff88802011d190 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4690 drivers/usb/core/hub.c:5691
#3: ffff88807b888190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#3: ffff88807b888190 (&dev->mutex){....}-{3:3}, at: usb_disconnect.cold+0x43/0x6ec drivers/usb/core/hub.c:2219
#4: ffff88807a420118 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:835 [inline]
#4: ffff88807a420118 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1054 [inline]
#4: ffff88807a420118 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa0/0x700 drivers/base/dd.c:1245
#5: ffffffff8ceafca8 (input_mutex){+.+.}-{3:3}, at: __input_unregister_device+0x158/0x460 drivers/input/input.c:2235
#6: ffff88807a4212c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_unregister_handle+0x128/0x290 drivers/input/input.c:2592

2 locks held by acpid/2962:

#0: ffff88807a120158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_close_device drivers/input/joydev.c:220 [inline]
#0: ffff88807a120158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_release+0x187/0x290 drivers/input/joydev.c:252
#1: ffff88807a4212c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_close_device+0x42/0x1f0 drivers/input/input.c:726
2 locks held by getty/3288:
#0: ffff88814b342098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002d162e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
2 locks held by udevd/4098:
#0: ffff88807a424110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open_device drivers/input/evdev.c:393 [inline]
#0: ffff88807a424110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open+0x2f3/0x6a0 drivers/input/evdev.c:487
#1: ffff88807a4212c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_open_device+0x4a/0x320 drivers/input/input.c:656

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

NMI backtrace for cpu 1

CPU: 1 PID: 28 Comm: khungtaskd Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
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+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369

kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 1 to CPUs 0:

NMI backtrace for cpu 0

CPU: 0 PID: 41 Comm: kworker/u4:2 Not tainted 5.19.0-rc4-syzkaller-00125-ga175eca0f3d7-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022

Workqueue: events_unbound toggle_allocation_gate
RIP: 0010:mark_held_locks+0xc1/0xe0 kernel/locking/lockdep.c:4239
Code: 4c 89 e7 e8 51 e6 ff ff 85 c0 74 12 83 c3 01 41 39 9c 24 58 0a 00 00 7f a9 b8 01 00 00 00 48 83 c4 08 5b 5d 41 5c 41 5d 41 5e <c3> e8 c9 3f 69 00 e9 6d ff ff ff 48 89 34 24 e8 9b 3f 69 00 48 8b
RSP: 0018:ffffc90000b27998 EFLAGS: 00000092
RAX: 0000000000000001 RBX: ffff888011b19d80 RCX: 1ffffffff20d0d76
RDX: dffffc0000000000 RSI: 0000000000000004 RDI: ffffffff90686bb0
RBP: ffff888011b19d80 R08: 0000000000000000 R09: ffffffff9067f917
R10: 0000000000000001 R11: 0000000000000001 R12: ffffffff812c131f
R13: 0000000000000004 R14: 0000000000000aa8 R15: ffffffff8bec6480

FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033

CR2: 00007f7f22bcc110 CR3: 000000000ba8e000 CR4: 00000000003506f0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>

__trace_hardirqs_on_caller kernel/locking/lockdep.c:4252 [inline]
lockdep_hardirqs_on_prepare kernel/locking/lockdep.c:4319 [inline]
lockdep_hardirqs_on_prepare+0x135/0x400 kernel/locking/lockdep.c:4271
trace_hardirqs_on+0x2d/0x120 kernel/trace/trace_preemptirq.c:49
__text_poke+0x6df/0x8e0 arch/x86/kernel/alternative.c:1112
text_poke arch/x86/kernel/alternative.c:1137 [inline]
text_poke_bp_batch+0x382/0x6c0 arch/x86/kernel/alternative.c:1432
text_poke_flush arch/x86/kernel/alternative.c:1589 [inline]
text_poke_flush arch/x86/kernel/alternative.c:1586 [inline]
text_poke_finish+0x16/0x30 arch/x86/kernel/alternative.c:1596
arch_jump_label_transform_apply+0x13/0x20 arch/x86/kernel/jump_label.c:146
jump_label_update+0x32f/0x410 kernel/jump_label.c:830
static_key_disable_cpuslocked+0x152/0x1b0 kernel/jump_label.c:207
static_key_disable+0x16/0x20 kernel/jump_label.c:215
toggle_allocation_gate mm/kfence/core.c:825 [inline]
toggle_allocation_gate+0x183/0x390 mm/kfence/core.c:803

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
worker_thread+0x665/0x1080 kernel/workqueue.c:2436

kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>

----------------
Code disassembly (best guess):

0: 4c 89 e7 mov %r12,%rdi
3: e8 51 e6 ff ff callq 0xffffe659
8: 85 c0 test %eax,%eax
a: 74 12 je 0x1e
c: 83 c3 01 add $0x1,%ebx
f: 41 39 9c 24 58 0a 00 cmp %ebx,0xa58(%r12)
16: 00
17: 7f a9 jg 0xffffffc2
19: b8 01 00 00 00 mov $0x1,%eax
1e: 48 83 c4 08 add $0x8,%rsp
22: 5b pop %rbx
23: 5d pop %rbp
24: 41 5c pop %r12
26: 41 5d pop %r13
28: 41 5e pop %r14

* 2a: c3 retq <-- trapping instruction

2b: e8 c9 3f 69 00 callq 0x693ff9
30: e9 6d ff ff ff jmpq 0xffffffa2
35: 48 89 34 24 mov %rsi,(%rsp)
39: e8 9b 3f 69 00 callq 0x693fd9
3e: 48 rex.W
3f: 8b .byte 0x8b

Tested on:

commit: a175eca0 Merge tag 'drm-fixes-2022-07-01' of git://ano..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git

console output: https://syzkaller.appspot.com/x/log.txt?x=1422b968080000
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9

dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=130ec148080000

[Tetsuo Handa]

Hello.

syzbot is reporting that iforce_close() from input_close_device() from
joydev_close_device() from joydev_release() forever sleeps at

wait_event_interruptible(iforce->wait,
!test_bit(IFORCE_XMIT_RUNNING, iforce->xmit_flags));

with dev->mutex held, which in turn prevents input_disconnect_device() from
__input_unregister_device() from input_unregister_device() from
iforce_usb_disconnect() from setting dev->going_away = true.

We somehow need to wake up this wait_event_interruptible() in iforce_close()
if iforce_usb_disconnect() is in progress. But iforce_usb_disconnect() does
not manipulate flags for waking up this wait_event_interruptible(). How can
we wake up this wait_event_interruptible()?



INFO: task kworker/0:0:6 blocked for more than 143 seconds.
Not tainted 5.18.0-syzkaller-dirty #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/0:0 state:D stack:24464 pid: 6 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>

context_switch kernel/sched/core.c:5073 [inline]
__schedule+0xa9a/0x4cc0 kernel/sched/core.c:6388
schedule+0xd2/0x1f0 kernel/sched/core.c:6460
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6519
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
input_disconnect_device drivers/input/input.c:784 [inline]
__input_unregister_device+0x24/0x470 drivers/input/input.c:2236
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2431

iforce_usb_disconnect+0x5e/0xf0 drivers/input/joystick/iforce/iforce-usb.c:261
usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458

device_remove drivers/base/dd.c:532 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:524
__device_release_driver drivers/base/dd.c:1200 [inline]
device_release_driver_internal+0x4a3/0x680 drivers/base/dd.c:1223
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529
device_del+0x4f3/0xc80 drivers/base/core.c:3592

usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228
hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]

port_event drivers/usb/core/hub.c:5665 [inline]
hub_event+0x1e74/0x4680 drivers/usb/core/hub.c:5747

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438
kthread+0x2e9/0x3a0 kernel/kthread.c:376

ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
</TASK>
6 locks held by kworker/0:0/6:
#0: ffff8881457f4138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff8881457f4138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff8881457f4138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff8881457f4138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff8881457f4138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff8881457f4138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc900000b7da8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffff88801f817220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#2: ffff88801f817220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4680 drivers/usb/core/hub.c:5693
#3: ffff88814bc3b220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#3: ffff88814bc3b220 (&dev->mutex){....}-{3:3}, at: usb_disconnect.cold+0x43/0x6ec drivers/usb/core/hub.c:2219
#4: ffff88814bc3a1a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#4: ffff88814bc3a1a8 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1033 [inline]
#4: ffff88814bc3a1a8 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa0/0x680 drivers/base/dd.c:1220
#5: ffff88807b7202c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_disconnect_device drivers/input/input.c:784 [inline]
#5: ffff88807b7202c0 (&dev->mutex#2){+.+.}-{3:3}, at: __input_unregister_device+0x24/0x470 drivers/input/input.c:2236

task:acpid state:S stack:23384 pid: 2951 ppid: 1 flags:0x00004000
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5073 [inline]
__schedule+0xa9a/0x4cc0 kernel/sched/core.c:6388
schedule+0xd2/0x1f0 kernel/sched/core.c:6460
iforce_close+0x396/0x4b0 drivers/input/joystick/iforce/iforce-main.c:203
input_close_device+0x156/0x1f0 drivers/input/input.c:734
joydev_close_device drivers/input/joydev.c:223 [inline]
joydev_release+0x222/0x290 drivers/input/joydev.c:252
__fput+0x277/0x9d0 fs/file_table.c:317
task_work_run+0xdd/0x1a0 kernel/task_work.c:164
resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
exit_to_user_mode_loop kernel/entry/common.c:169 [inline]
exit_to_user_mode_prepare+0x23c/0x250 kernel/entry/common.c:201
__syscall_exit_to_user_mode_work kernel/entry/common.c:283 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:294
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f135bd3ffc3
RSP: 002b:00007ffe571c93d8 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 00007ffe571c9648 RCX: 00007f135bd3ffc3
RDX: 00007ffe571c8808 RSI: 000000000000001e RDI: 000000000000000a
RBP: 000000000000000a R08: 00007ffe571c965c R09: 00007ffe571c9548
R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffe571c9548
R13: 00007ffe571c9648 R14: 0000000000000020 R15: 0000000000000000
</TASK>
2 locks held by acpid/2951:
#0: ffff88807bd28158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_close_device drivers/input/joydev.c:220 [inline]
#0: ffff88807bd28158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_release+0x187/0x290 drivers/input/joydev.c:252
#1: ffff88807b7202c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_close_device+0x42/0x1f0 drivers/input/input.c:726

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:

INFO: task hung in __input_unregister_device

INFO: task kworker/1:4:3610 blocked for more than 143 seconds.

Not tainted 5.18.0-syzkaller-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/1:4 state:D stack:23504 pid: 3610 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5073 [inline]
__schedule+0xa9a/0x4cc0 kernel/sched/core.c:6388
schedule+0xd2/0x1f0 kernel/sched/core.c:6460
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6519
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
input_disconnect_device drivers/input/input.c:784 [inline]
__input_unregister_device+0x24/0x470 drivers/input/input.c:2236
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2431

iforce_usb_disconnect+0xbe/0x160 drivers/input/joystick/iforce/iforce-usb.c:264

usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:532 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:524
__device_release_driver drivers/base/dd.c:1200 [inline]
device_release_driver_internal+0x4a3/0x680 drivers/base/dd.c:1223
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529
device_del+0x4f3/0xc80 drivers/base/core.c:3592
usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228
hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]
port_event drivers/usb/core/hub.c:5665 [inline]
hub_event+0x1e74/0x4680 drivers/usb/core/hub.c:5747
process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
</TASK>

Showing all threads with locks held in the system:

task:acpid state:S stack:23384 pid: 2951 ppid: 1 flags:0x00004000
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5073 [inline]
__schedule+0xa9a/0x4cc0 kernel/sched/core.c:6388
schedule+0xd2/0x1f0 kernel/sched/core.c:6460
iforce_close+0x396/0x4b0 drivers/input/joystick/iforce/iforce-main.c:203
input_close_device+0x156/0x1f0 drivers/input/input.c:734
joydev_close_device drivers/input/joydev.c:223 [inline]
joydev_release+0x222/0x290 drivers/input/joydev.c:252
__fput+0x277/0x9d0 fs/file_table.c:317
task_work_run+0xdd/0x1a0 kernel/task_work.c:164
resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
exit_to_user_mode_loop kernel/entry/common.c:169 [inline]
exit_to_user_mode_prepare+0x23c/0x250 kernel/entry/common.c:201
__syscall_exit_to_user_mode_work kernel/entry/common.c:283 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:294
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae

RIP: 0033:0x7fd621054fc3
RSP: 002b:00007fff26190c98 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 00007fff26190f08 RCX: 00007fd621054fc3
RDX: 00007fff261900c8 RSI: 000000000000001e RDI: 000000000000000a
RBP: 000000000000000a R08: 00007fff26190f1c R09: 00007fff26190e08
R10: 0000000000000000 R11: 0000000000000246 R12: 00007fff26190e08
R13: 00007fff26190f08 R14: 0000000000000020 R15: 0000000000000000

</TASK>
2 locks held by acpid/2951:

#0: ffff88807639c158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_close_device drivers/input/joydev.c:220 [inline]
#0: ffff88807639c158 (&joydev->mutex){+.+.}-{3:3}, at: joydev_release+0x187/0x290 drivers/input/joydev.c:252
#1: ffff88801fa302c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_close_device+0x42/0x1f0 drivers/input/input.c:726
task:getty state:S stack:23384 pid: 3276 ppid: 1 flags:0x00000000

Call Trace:
<TASK>
context_switch kernel/sched/core.c:5073 [inline]
__schedule+0xa9a/0x4cc0 kernel/sched/core.c:6388
schedule+0xd2/0x1f0 kernel/sched/core.c:6460

schedule_timeout+0x1db/0x2a0 kernel/time/timer.c:1860
wait_woken+0x18b/0x1f0 kernel/sched/wait.c:459
n_tty_read+0xee6/0x1230 drivers/tty/n_tty.c:2141
iterate_tty_read drivers/tty/tty_io.c:858 [inline]
tty_read+0x33a/0x5d0 drivers/tty/tty_io.c:933
call_read_iter include/linux/fs.h:2044 [inline]
new_sync_read+0x384/0x5f0 fs/read_write.c:401
vfs_read+0x492/0x5d0 fs/read_write.c:482
ksys_read+0x127/0x250 fs/read_write.c:620

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:0x7f0b27cdd8fe
RSP: 002b:00007ffcb6bc5b68 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 00005566d2775910 RCX: 00007f0b27cdd8fe
RDX: 0000000000000001 RSI: 00007ffcb6bc5b80 RDI: 0000000000000000
RBP: 00005566d2775970 R08: 0000000000000007 R09: 00005566d2776cd0
R10: 0000000000000063 R11: 0000000000000246 R12: 00005566d27759ac
R13: 00007ffcb6bc5b80 R14: 0000000000000000 R15: 00005566d27759ac
</TASK>
2 locks held by getty/3276:
#0: ffff8881482fa098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002ce62e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xcea/0x1230 drivers/tty/n_tty.c:2075
task:kworker/1:4 state:D stack:23504 pid: 3610 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5073 [inline]
__schedule+0xa9a/0x4cc0 kernel/sched/core.c:6388
schedule+0xd2/0x1f0 kernel/sched/core.c:6460
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6519
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
input_disconnect_device drivers/input/input.c:784 [inline]
__input_unregister_device+0x24/0x470 drivers/input/input.c:2236
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2431

iforce_usb_disconnect+0xbe/0x160 drivers/input/joystick/iforce/iforce-usb.c:264

usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:532 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:524
__device_release_driver drivers/base/dd.c:1200 [inline]
device_release_driver_internal+0x4a3/0x680 drivers/base/dd.c:1223
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529
device_del+0x4f3/0xc80 drivers/base/core.c:3592
usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228
hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]
port_event drivers/usb/core/hub.c:5665 [inline]
hub_event+0x1e74/0x4680 drivers/usb/core/hub.c:5747
process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
</TASK>

6 locks held by kworker/1:4/3610:
#0: ffff88814559e138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff88814559e138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff88814559e138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff88814559e138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
#0: ffff88814559e138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
#0: ffff88814559e138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x87a/0x1610 kernel/workqueue.c:2260
#1: ffffc900030dfda8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ae/0x1610 kernel/workqueue.c:2264
#2: ffff88814843b220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#2: ffff88814843b220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4680 drivers/usb/core/hub.c:5693
#3: ffff888147773220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#3: ffff888147773220 (&dev->mutex){....}-{3:3}, at: usb_disconnect.cold+0x43/0x6ec drivers/usb/core/hub.c:2219
#4: ffff8881477721a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:767 [inline]
#4: ffff8881477721a8 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1033 [inline]
#4: ffff8881477721a8 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa0/0x680 drivers/base/dd.c:1220
#5: ffff88801fa302c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_disconnect_device drivers/input/input.c:784 [inline]
#5: ffff88801fa302c0 (&dev->mutex#2){+.+.}-{3:3}, at: __input_unregister_device+0x24/0x470 drivers/input/input.c:2236
task:udevd state:S stack:27480 pid: 4048 ppid: 2966 flags:0x00000000

Call Trace:
<TASK>
context_switch kernel/sched/core.c:5073 [inline]
__schedule+0xa9a/0x4cc0 kernel/sched/core.c:6388
schedule+0xd2/0x1f0 kernel/sched/core.c:6460
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6519
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733

input_open_device+0x4a/0x320 drivers/input/input.c:656
evdev_open_device drivers/input/evdev.c:400 [inline]
evdev_open+0x538/0x6a0 drivers/input/evdev.c:487
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4a1/0x11e0 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c71/0x2910 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4c0 fs/open.c:1213
do_sys_open fs/open.c:1229 [inline]
__do_sys_openat fs/open.c:1245 [inline]
__se_sys_openat fs/open.c:1240 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1240

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:0x7f9b5a725697
RSP: 002b:00007fffa48719a0 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000005a7f5a01 RCX: 00007f9b5a725697
RDX: 0000000000080000 RSI: 0000555a276e3a80 RDI: 00000000ffffff9c
RBP: 0000555a276e3a80 R08: 0000555a276ce490 R09: 00007f9b5a7f5a00
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000080000
R13: 0000000000000000 R14: 0000555a274a7150 R15: 0000000000000000
</TASK>
2 locks held by udevd/4048:
#0: ffff8881455ed110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open_device drivers/input/evdev.c:393 [inline]
#0: ffff8881455ed110 (&evdev->mutex){+.+.}-{3:3}, at: evdev_open+0x2f3/0x6a0 drivers/input/evdev.c:487
#1: ffff88801fa302c0 (&dev->mutex#2){+.+.}-{3:3}, at: input_open_device+0x4a/0x320 drivers/input/input.c:656

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

NMI backtrace for cpu 1

CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.18.0-syzkaller-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
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+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]

check_hung_uninterruptible_tasks kernel/hung_task.c:225 [inline]
watchdog+0xc53/0xf80 kernel/hung_task.c:382

kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
</TASK>

Sending NMI from CPU 1 to CPUs 0:

NMI backtrace for cpu 0 skipped: idling at native_safe_halt arch/x86/include/asm/irqflags.h:51 [inline]
NMI backtrace for cpu 0 skipped: idling at arch_safe_halt arch/x86/include/asm/irqflags.h:89 [inline]
NMI backtrace for cpu 0 skipped: idling at acpi_safe_halt drivers/acpi/processor_idle.c:110 [inline]
NMI backtrace for cpu 0 skipped: idling at acpi_idle_do_entry+0x1c6/0x250 drivers/acpi/processor_idle.c:551


Tested on:

commit: 4b0986a3 Linux 5.18
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git v5.18
console output: https://syzkaller.appspot.com/x/log.txt?x=169793dc080000
kernel config: https://syzkaller.appspot.com/x/.config?x=30033beeb37ddb23

dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=13a9eaac080000

[Fabio M. De Francesco]

On giovedì 21 luglio 2022 13:11:44 CEST Tetsuo Handa wrote:
> Hello.
>
> syzbot is reporting that iforce_close() from input_close_device() from
> joydev_close_device() from joydev_release() forever sleeps at
>
> wait_event_interruptible(iforce->wait,
> !test_bit(IFORCE_XMIT_RUNNING, iforce-
>xmit_flags));
>
> with dev->mutex held, which in turn prevents input_disconnect_device()
from
> __input_unregister_device() from input_unregister_device() from
> iforce_usb_disconnect() from setting dev->going_away = true.
>
> We somehow need to wake up this wait_event_interruptible() in
iforce_close()
> if iforce_usb_disconnect() is in progress. But iforce_usb_disconnect()
does
> not manipulate flags for waking up this wait_event_interruptible(). How
can
> we wake up this wait_event_interruptible()?
>

I haven't been following this thread, except reading only this message. It
may well be I'm saying something which is not suited for solving your
problem.

If it can be fixed, as you said, by a simple notification to
wait_event_interruptible(), why not changing iforce_usb_disconnect() the
following way?

static void iforce_usb_disconnect(struct usb_interface *intf)
{
struct iforce_usb *iforce_usb = usb_get_intfdata(intf);

usb_set_intfdata(intf, NULL);

__set_bit(IFORCE_XMIT_RUNNING, iforce_usb->iforce.xmit_flags);
wake_up(&iforce_usb->iforce.wait);

input_unregister_device(iforce_usb->iforce.dev);

usb_free_urb(iforce_usb->irq);
usb_free_urb(iforce_usb->out);

kfree(iforce_usb);
}

I am sorry if I'm overlooking anything, especially because I'm entering
this thread without reading the other messages and so without knowing the
whole context. Furthermore I haven't even test-compiled these changes :-(

Thanks,

Fabio

[syzbot]

Hello,

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

Reported-and-tested-by: syzbot+deb6ab...@syzkaller.appspotmail.com

Tested on:

commit: 4b0986a3 Linux 5.18
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git v5.18

console output: https://syzkaller.appspot.com/x/log.txt?x=10162b9a080000

kernel config: https://syzkaller.appspot.com/x/.config?x=30033beeb37ddb23
dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=124b9eac080000

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

[Tetsuo Handa]

On 2022/07/21 23:45, Fabio M. De Francesco wrote:
> If it can be fixed, as you said, by a simple notification to
> wait_event_interruptible(), why not changing iforce_usb_disconnect() the
> following way?
>
> static void iforce_usb_disconnect(struct usb_interface *intf)
> {
> struct iforce_usb *iforce_usb = usb_get_intfdata(intf);
>
> usb_set_intfdata(intf, NULL);
>
> __set_bit(IFORCE_XMIT_RUNNING, iforce_usb->iforce.xmit_flags);

I assume you meant clear_bit() here, for

wait_event_interruptible(iforce->wait,
!test_bit(IFORCE_XMIT_RUNNING, iforce->xmit_flags));

waits until IFORCE_XMIT_RUNNING bit is cleared.

However, clear_bit() is racy, for IFORCE_XMIT_RUNNING bit is set by
iforce_send_packet() at the previous line.

> wake_up(&iforce_usb->iforce.wait);
>
> input_unregister_device(iforce_usb->iforce.dev);
>
> usb_free_urb(iforce_usb->irq);
> usb_free_urb(iforce_usb->out);
>
> kfree(iforce_usb);
> }
>
> I am sorry if I'm overlooking anything, especially because I'm entering
> this thread without reading the other messages and so without knowing the
> whole context. Furthermore I haven't even test-compiled these changes :-(

So far, I asked syzbot to test

--- a/drivers/input/joystick/iforce/iforce-usb.c
+++ b/drivers/input/joystick/iforce/iforce-usb.c
@@ -258,6 +258,9 @@ static void iforce_usb_disconnect(struct usb_interface *intf)

usb_set_intfdata(intf, NULL);

+ usb_poison_urb(iforce_usb->irq);
+ usb_poison_urb(iforce_usb->out);
+
input_unregister_device(iforce_usb->iforce.dev);

usb_free_urb(iforce_usb->irq);

which still triggered this problem, and

--- a/drivers/input/joystick/iforce/iforce-main.c
+++ b/drivers/input/joystick/iforce/iforce-main.c
@@ -200,8 +200,10 @@ static void iforce_close(struct input_dev *dev)
/* Disable force feedback playback */
iforce_send_packet(iforce, FF_CMD_ENABLE, "\001");
/* Wait for the command to complete */
- wait_event_interruptible(iforce->wait,
- !test_bit(IFORCE_XMIT_RUNNING, iforce->xmit_flags));
+ wait_event_interruptible_timeout
+ (iforce->wait,
+ !test_bit(IFORCE_XMIT_RUNNING, iforce->xmit_flags),
+ 5 * HZ);
}

iforce->xport_ops->stop_io(iforce);

which did not trigger this problem.

Since wait_event_interruptible() was used here, I think we can expect that
it is tolerable to continue without waiting for the command to complete...

[Fabio M. De Francesco]

On giovedì 21 luglio 2022 17:06:26 CEST Tetsuo Handa wrote:
> On 2022/07/21 23:45, Fabio M. De Francesco wrote:
> > If it can be fixed, as you said, by a simple notification to
> > wait_event_interruptible(), why not changing iforce_usb_disconnect()
the
> > following way?
> >
> > static void iforce_usb_disconnect(struct usb_interface *intf)
> > {
> > struct iforce_usb *iforce_usb = usb_get_intfdata(intf);
> >
> > usb_set_intfdata(intf, NULL);
> >
> > __set_bit(IFORCE_XMIT_RUNNING, iforce_usb->iforce.xmit_flags);
>
> I assume you meant clear_bit() here, for
>
> wait_event_interruptible(iforce->wait,
> !test_bit(IFORCE_XMIT_RUNNING, iforce->xmit_flags));
>
> waits until IFORCE_XMIT_RUNNING bit is cleared.
>

Sorry, yes you are correct. I didn't note that negation of test_bit().
However, you understood what I was trying to convey :-)

> However, clear_bit() is racy, for IFORCE_XMIT_RUNNING bit is set by
> iforce_send_packet() at the previous line.

Why not protecting with a mutex, I mean both in iforce_usb_disconnect() and
soon before calling iforce_send_packet() in iforce_close()?

It did not clear this problem because of _timeout(), I guess.

If I recall correctly, this task hanged in wait_event_interruptible() and
your problem was how to clear that bit and make the task return from
wait_event_interruptible(). Correct?

Now you changed this code to return after some time, despite that flag.
Are you sure this is the better suited way to fix this bug?

>
> Since wait_event_interruptible() was used here, I think we can expect
that
> it is tolerable to continue without waiting for the command to
complete...

Ah, yes. Maybe you are right here but I wouldn't bet on what authors
thought when they called wait_event_interruptible() :-)

Thanks,

Fabio

> --
> You received this message because you are subscribed to the Google Groups
"syzkaller-bugs" group.
> To unsubscribe from this group and stop receiving emails from it, send an
email to syzkaller-bug...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/
msgid/syzkaller-bugs/2bcd5385-2423-2e8f-be01-9db93afaba43%40I-
love.SAKURA.ne.jp.
>

[Fabio M. De Francesco]

^^^^^ Sorry, "clear" -> "trigger" ^^^^^
However, I suppose it doesn't matter any longer.

Thanks,

Fabio

[Fabio M. De Francesco]

> --
> You received this message because you are subscribed to the Google Groups
"syzkaller-bugs" group.
> To unsubscribe from this group and stop receiving emails from it, send an
email to syzkaller-bug...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/

msgid/syzkaller-bugs/00000000000088a03905e2d435c2%40google.com.
>
#syz test: https://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb.git
usb-testing

[syzbot]

Hello,

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

Reported-and-tested-by: syzbot+deb6ab...@syzkaller.appspotmail.com

Tested on:

commit: 32f02a21 Revert "platform/chrome: Add Type-C mux set c..

git tree: https://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb.git usb-testing

console output: https://syzkaller.appspot.com/x/log.txt?x=120269d6080000
kernel config: https://syzkaller.appspot.com/x/.config?x=8be12c1e07a193d9
dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407

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=1141355e080000

[Tetsuo Handa]

On 2022/07/22 22:53, syzbot wrote:
> patch: https://syzkaller.appspot.com/x/patch.diff?x=1141355e080000

This patch helps only if iforce_usb_disconnect() is called while waiting at
wait_event_interruptible(iforce->wait, !test_bit(IFORCE_XMIT_RUNNING, iforce->xmit_flags)).

It is possible that iforce_usb_disconnect() is called before
iforce_send_packet(iforce, FF_CMD_ENABLE, "\001") sets IFORCE_XMIT_RUNNING bit.

On 2022/07/22 1:53, Fabio M. De Francesco wrote:
> On giovedì 21 luglio 2022 17:06:26 CEST Tetsuo Handa wrote:
>> On 2022/07/21 23:45, Fabio M. De Francesco wrote:
>>> If it can be fixed, as you said, by a simple notification to
>>> wait_event_interruptible(), why not changing iforce_usb_disconnect() the
>>> following way?
>>>
>>> static void iforce_usb_disconnect(struct usb_interface *intf)
>>> {
>>> struct iforce_usb *iforce_usb = usb_get_intfdata(intf);
>>>
>>> usb_set_intfdata(intf, NULL);
>>>
>>> __set_bit(IFORCE_XMIT_RUNNING, iforce_usb->iforce.xmit_flags);
>>
>> I assume you meant clear_bit() here, for
>>
>> wait_event_interruptible(iforce->wait,
>> !test_bit(IFORCE_XMIT_RUNNING, iforce->xmit_flags));
>>
>> waits until IFORCE_XMIT_RUNNING bit is cleared.
>>
>
> Sorry, yes you are correct. I didn't note that negation of test_bit().
> However, you understood what I was trying to convey :-)
>
>> However, clear_bit() is racy, for IFORCE_XMIT_RUNNING bit is set by
>> iforce_send_packet() at the previous line.
>
> Why not protecting with a mutex, I mean both in iforce_usb_disconnect() and
> soon before calling iforce_send_packet() in iforce_close()?

Protecting with a mutex does not help. It is possible that clear_bit(IFORCE_XMIT_RUNNING)
is called before iforce_send_packet() is called.

>
> It did not trigger this problem because of _timeout(), I guess.

Right.

>
> If I recall correctly, this task hanged in wait_event_interruptible() and
> your problem was how to clear that bit and make the task return from
> wait_event_interruptible(). Correct?

Not limited to clearing IFORCE_XMIT_RUNNING bit. We could introduce a new
bit for disconnect event and check both bits at wait_event_interruptible().

>> Since wait_event_interruptible() was used here, I think we can expect that
>> it is tolerable to continue without waiting for the command to complete...
>
> Ah, yes. Maybe you are right here but I wouldn't bet on what authors
> thought when they called wait_event_interruptible() :-)

The author who added this wait_event_interruptible() call is Dmitry Torokhov.

commit c2b27ef672992a206e5b221b8676972dd840ffa5
Author: Dmitry Torokhov <dmitry....@gmail.com>
Date: Wed Dec 30 12:18:24 2009 -0800

Input: iforce - wait for command completion when closing the device

We need to wait for the command to disable FF effects to complete before
continuing with closing the device.

Tested-by: Johannes Ebke <johann...@physik.uni-muenchen.de>
Signed-off-by: Dmitry Torokhov <dt...@mail.ru>

Dmitry, what do you think? Even without iforce_usb_disconnect() race,
a joystick device not responding for many seconds would be annoying.

[Fabio M. De Francesco]

On venerdì 22 luglio 2022 16:39:09 CEST Tetsuo Handa wrote:
> On 2022/07/22 22:53, syzbot wrote:
> > patch: https://syzkaller.appspot.com/x/patch.diff?
x=1141355e080000
>
> This patch helps only if iforce_usb_disconnect() is called while waiting
at
> wait_event_interruptible(iforce->wait, !test_bit(IFORCE_XMIT_RUNNING,
iforce->xmit_flags)).
>
> It is possible that iforce_usb_disconnect() is called before
> iforce_send_packet(iforce, FF_CMD_ENABLE, "\001") sets
IFORCE_XMIT_RUNNING bit.

I haven't spent time looking closely at this driver, I'm also reacting at
what you said about to signal the waiter that the flag changed.

First of all, I want to thank you because (1) I see how much time you use
to spend fixing tons of bugs reported by Syzbot and (2) _you_ made the
analysis which easily lead me to this "proof of concept" diff
(acknowledgment is due!).

I sent this patch for two different reasons:

1) If it passes, and it actually passes tests, I probably go deeper and see
if it is enough or other things must be considered. You mentioned another
case where it cannot work, but I have had no time to see it yet.

2) Actually I didn't like that you made a timeout wait. I wanted to "prove"
that Syzbot tests _can_ pass for a myriad reasons, but this is not a
guarantee that a patch is "good".

I'm sorry, you are right. No mutex. In fact you see no mutexes in my patch.

I had misunderstood easily what you said because I had no context. I have
not yet all the necessary context to prepare a "real" patch. As said, it
was only a "proof of concept".

> >
> > It did not trigger this problem because of _timeout(), I guess.
>
> Right.

This is not something you should do, since you have much more experience to
figure out how to fix it properly :-)

> >
> > If I recall correctly, this task hanged in wait_event_interruptible()
and
> > your problem was how to clear that bit and make the task return from
> > wait_event_interruptible(). Correct?
>
> Not limited to clearing IFORCE_XMIT_RUNNING bit. We could introduce a new
> bit for disconnect event and check both bits at
wait_event_interruptible().

It sounds reasonable.

> >> Since wait_event_interruptible() was used here, I think we can expect
that
> >> it is tolerable to continue without waiting for the command to
complete...
> >
> > Ah, yes. Maybe you are right here but I wouldn't bet on what authors
> > thought when they called wait_event_interruptible() :-)
>
> The author who added this wait_event_interruptible() call is Dmitry
Torokhov.

I didn't check. For what I saw in other cases, he knows what he does ;)

>
> commit c2b27ef672992a206e5b221b8676972dd840ffa5
> Author: Dmitry Torokhov <dmitry....@gmail.com>
> Date: Wed Dec 30 12:18:24 2009 -0800
>
> Input: iforce - wait for command completion when closing the device
>
> We need to wait for the command to disable FF effects to complete
before
> continuing with closing the device.
>
> Tested-by: Johannes Ebke <johann...@physik.uni-muenchen.de>
> Signed-off-by: Dmitry Torokhov <dt...@mail.ru>
>
> Dmitry, what do you think? Even without iforce_usb_disconnect() race,
> a joystick device not responding for many seconds would be annoying.

Thanks,

Fabio

[Fabio M. De Francesco]

On venerdì 22 luglio 2022 21:15:34 CEST Fabio M. De Francesco wrote:
> On venerdì 22 luglio 2022 16:39:09 CEST Tetsuo Handa wrote:
> > On 2022/07/22 22:53, syzbot wrote:
> > > patch: https://syzkaller.appspot.com/x/patch.diff?
> x=1141355e080000
> >
> > This patch helps only if iforce_usb_disconnect() is called while
waiting
> at
> > wait_event_interruptible(iforce->wait, !test_bit(IFORCE_XMIT_RUNNING,
> iforce->xmit_flags)).
> >
> > It is possible that iforce_usb_disconnect() is called before
> > iforce_send_packet(iforce, FF_CMD_ENABLE, "\001") sets
> IFORCE_XMIT_RUNNING bit.
>
> I haven't spent time looking closely at this driver, I'm also reacting at

Sorry, please delete that spurious "also". Perhaps I wanted to write
"only".

Thanks,

Fabio

[Tetsuo Handa]

On 2022/07/23 4:15, Fabio M. De Francesco wrote:
> I had misunderstood easily what you said because I had no context. I have
> not yet all the necessary context to prepare a "real" patch. As said, it
> was only a "proof of concept".

Although current problem is that iforce_usb_disconnect() being blocked on
dev->mutex which was held by the caller of iforce_close(), I worry that
a proper fix requires something like commit db264d4c66c0fe00 ("media:
imon: reorganize serialization") in order to defer

usb_free_urb(iforce_usb->irq);
usb_free_urb(iforce_usb->out);
kfree(iforce_usb);

part in iforce_usb_disconnect(), given that iforce_close() (which needs to
perform urb operation) might be called even after iforce_usb_disconnect()
completed.

Device file's close callback being not prepared for disconnect event
(that is, code assumes that close happens only before disconnect happens)
might be frequently observed problem in USB drivers...

[Hillf Danton]

On Sun, 03 Jul 2022 21:39:06 -0700

> syzbot has tested the proposed patch but the reproducer is still triggering an issue:
> INFO: task hung in input_unregister_handle
>
>

> Tested on:
>
> commit: a175eca0 Merge tag 'drm-fixes-2022-07-01' of git://ano..
> git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git
> console output: https://syzkaller.appspot.com/x/log.txt?x=1422b968080000
> kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9
> dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
> 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=130ec148080000

Given wait_event for IFORCE_XMIT_RUNNING in iforce_close(), do wakeup
everytime the flag is cleared.

#syz test https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git a175eca0

--- a/drivers/input/joystick/iforce/iforce-usb.c
+++ b/drivers/input/joystick/iforce/iforce-usb.c
@@ -32,6 +32,7 @@ static void __iforce_usb_xmit(struct ifo
if (iforce->xmit.head == iforce->xmit.tail) {
clear_bit(IFORCE_XMIT_RUNNING, iforce->xmit_flags);
spin_unlock_irqrestore(&iforce->xmit_lock, flags);
+ wake_up(&iforce->wait);
return;
}

@@ -59,6 +60,7 @@ static void __iforce_usb_xmit(struct ifo

if ( (n=usb_submit_urb(iforce_usb->out, GFP_ATOMIC)) ) {
clear_bit(IFORCE_XMIT_RUNNING, iforce->xmit_flags);
+ wake_up(&iforce->wait);
dev_warn(&iforce_usb->intf->dev,
"usb_submit_urb failed %d\n", n);
}
@@ -178,10 +180,8 @@ static void iforce_usb_out(struct urb *u
clear_bit(IFORCE_XMIT_RUNNING, iforce->xmit_flags);
dev_dbg(&iforce_usb->intf->dev, "urb->status %d, exiting\n",
urb->status);
- return;
- }
-
- __iforce_usb_xmit(iforce);
+ } else
+ __iforce_usb_xmit(iforce);

wake_up(&iforce->wait);
}
--

[syzbot]

Hello,

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

Reported-and-tested-by: syzbot+deb6ab...@syzkaller.appspotmail.com

Tested on:

commit: a175eca0 Merge tag 'drm-fixes-2022-07-01' of git://ano..

git tree: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=140f65aa080000

kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9
dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=13115bd6080000

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:

INFO: task hung in __input_unregister_device

INFO: task kworker/1:2:142 blocked for more than 143 seconds.
Not tainted 5.19.0-rc8-syzkaller-00214-ge0dccc3b76fb-dirty #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/1:2 state:D stack:24968 pid: 142 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458

schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747
input_disconnect_device drivers/input/input.c:784 [inline]
__input_unregister_device+0x24/0x470 drivers/input/input.c:2234
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2429

iforce_usb_disconnect+0x97/0x11d drivers/input/joystick/iforce/iforce-usb.c:262

usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:545 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:537
__device_release_driver drivers/base/dd.c:1222 [inline]
device_release_driver_internal+0x4a1/0x700 drivers/base/dd.c:1248
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529

device_del+0x4f3/0xc80 drivers/base/core.c:3615

usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228

hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]

port_event drivers/usb/core/hub.c:5663 [inline]
hub_event+0x1e83/0x4690 drivers/usb/core/hub.c:5745

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438

kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>

Showing all threads with locks held in the system:
task:kworker/0:0 state:I stack:24232 pid: 6 ppid: 2 flags:0x00004000
Workqueue: 0x0 (rcu_gp)

Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
worker_thread+0x15c/0x1080 kernel/workqueue.c:2457
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>
INFO: lockdep is turned off.
task:kworker/u4:1 state:I stack:24232 pid: 11 ppid: 2 flags:0x00004000
Workqueue: 0x0 (bat_events)

Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
worker_thread+0x15c/0x1080 kernel/workqueue.c:2457
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>
INFO: lockdep is turned off.
task:kworker/u4:4 state:I stack:23152 pid: 92 ppid: 2 flags:0x00004000
Workqueue: 0x0 (events_unbound)

Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
worker_thread+0x15c/0x1080 kernel/workqueue.c:2457
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>
INFO: lockdep is turned off.
task:kworker/1:2 state:D stack:24968 pid: 142 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458

schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747
input_disconnect_device drivers/input/input.c:784 [inline]
__input_unregister_device+0x24/0x470 drivers/input/input.c:2234
input_unregister_device+0xb4/0xf0 drivers/input/input.c:2429

iforce_usb_disconnect+0x97/0x11d drivers/input/joystick/iforce/iforce-usb.c:262

usb_unbind_interface+0x1d8/0x8e0 drivers/usb/core/driver.c:458
device_remove drivers/base/dd.c:545 [inline]
device_remove+0x11f/0x170 drivers/base/dd.c:537
__device_release_driver drivers/base/dd.c:1222 [inline]
device_release_driver_internal+0x4a1/0x700 drivers/base/dd.c:1248
bus_remove_device+0x2eb/0x5a0 drivers/base/bus.c:529

device_del+0x4f3/0xc80 drivers/base/core.c:3615

usb_disable_device+0x35b/0x7b0 drivers/usb/core/message.c:1419
usb_disconnect.cold+0x278/0x6ec drivers/usb/core/hub.c:2228

hub_port_connect drivers/usb/core/hub.c:5207 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5507 [inline]

port_event drivers/usb/core/hub.c:5663 [inline]
hub_event+0x1e83/0x4690 drivers/usb/core/hub.c:5745

process_one_work+0x996/0x1610 kernel/workqueue.c:2289
process_scheduled_works kernel/workqueue.c:2352 [inline]
worker_thread+0x854/0x1080 kernel/workqueue.c:2438

kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>
INFO: lockdep is turned off.
task:getty state:S stack:23360 pid: 3286 ppid: 1 flags:0x00000000

Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_timeout+0x1db/0x2a0 kernel/time/timer.c:1911
wait_woken+0x18b/0x1f0 kernel/sched/wait.c:459
n_tty_read+0x104c/0x13c0 drivers/tty/n_tty.c:2190

iterate_tty_read drivers/tty/tty_io.c:858 [inline]
tty_read+0x33a/0x5d0 drivers/tty/tty_io.c:933

call_read_iter include/linux/fs.h:2052 [inline]

new_sync_read+0x384/0x5f0 fs/read_write.c:401
vfs_read+0x492/0x5d0 fs/read_write.c:482
ksys_read+0x127/0x250 fs/read_write.c:620
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+0x63/0xcd
RIP: 0033:0x7f179d1dd8fe
RSP: 002b:00007ffc6cbbe648 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 000055ae847b1910 RCX: 00007f179d1dd8fe
RDX: 0000000000000001 RSI: 00007ffc6cbbe660 RDI: 0000000000000000
RBP: 000055ae847b1970 R08: 0000000000000007 R09: 000055ae847b2cd0
R10: 0000000000000063 R11: 0000000000000246 R12: 000055ae847b19ac
R13: 00007ffc6cbbe660 R14: 0000000000000000 R15: 000055ae847b19ac
</TASK>
INFO: lockdep is turned off.
task:kworker/1:5 state:I stack:24720 pid: 3621 ppid: 2 flags:0x00004000
Workqueue: 0x0 (rcu_gp)

Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]

__schedule+0xa00/0x4b50 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
worker_thread+0x15c/0x1080 kernel/workqueue.c:2457
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>
INFO: lockdep is turned off.

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

NMI backtrace for cpu 1

CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.19.0-rc8-syzkaller-00214-ge0dccc3b76fb-dirty #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
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+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]

check_hung_uninterruptible_tasks kernel/hung_task.c:225 [inline]
watchdog+0xc53/0xf80 kernel/hung_task.c:382
kthread+0x2e9/0x3a0 kernel/kthread.c:376

ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>

Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0 skipped: idling at native_safe_halt arch/x86/include/asm/irqflags.h:51 [inline]
NMI backtrace for cpu 0 skipped: idling at arch_safe_halt arch/x86/include/asm/irqflags.h:89 [inline]

NMI backtrace for cpu 0 skipped: idling at acpi_safe_halt drivers/acpi/processor_idle.c:111 [inline]
NMI backtrace for cpu 0 skipped: idling at acpi_idle_do_entry+0x1c9/0x240 drivers/acpi/processor_idle.c:554


Tested on:

commit: e0dccc3b Linux 5.19-rc8
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=12a062ce080000
kernel config: https://syzkaller.appspot.com/x/.config?x=26034e6fe0075dad

dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=139f4352080000

[syzbot]

Hello,

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

Reported-and-tested-by: syzbot+deb6ab...@syzkaller.appspotmail.com

Tested on:

commit: e0dccc3b Linux 5.19-rc8
git tree: upstream

console output: https://syzkaller.appspot.com/x/log.txt?x=15e470de080000

kernel config: https://syzkaller.appspot.com/x/.config?x=26034e6fe0075dad
dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407
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=14b307f6080000

[Tetsuo Handa]

On 2022/07/23 4:15, Fabio M. De Francesco wrote:
> I had misunderstood easily what you said because I had no context. I have
> not yet all the necessary context to prepare a "real" patch. As said, it
> was only a "proof of concept".

Well, it seems that the cause of this problem is nothing but lack of wake_up()
after clear_bit(). Debug printk() patch shown below says that iforce_usb_out()
from interrupt context hit "urb->status -71, exiting" when iforce_close()
from process context was in progress.

[ 491.314788][ T2962] iforce_close(ffff88807e6b8000) start
[ 491.316393][ T14] usb 1-1: USB disconnect, device number 117
[ 491.320453][ T2962] iforce_send_packet(ffff88807e6b8000) start
[ 491.326488][ C0] iforce 1-1:0.0: urb->status -71, exiting
[ 491.327471][ T14] iforce_usb_disconnect(ffff88807e6b8000) start
[ 491.335041][ T2962] iforce_send_packet(ffff88807e6b8000)=0
[ 491.351266][ T2962] wait_event_interruptible(ffff88807e6b8000) end
[ 491.357778][ T2962] iforce_close(ffff88807e6b8000) end
[ 491.366421][ T14] input_unregister_device(ffff88807e6b8000) end
[ 491.372939][ T14] iforce_usb_disconnect(ffff88807e6b8000) end

[Fabio M. De Francesco]

On martedì 26 luglio 2022 05:53:36 CEST Tetsuo Handa wrote:
> On 2022/07/23 4:15, Fabio M. De Francesco wrote:
> > I had misunderstood easily what you said because I had no context. I
have
> > not yet all the necessary context to prepare a "real" patch. As said,
it
> > was only a "proof of concept".
>
> Well, it seems that the cause of this problem is nothing but lack of
wake_up()
> after clear_bit(). Debug printk() patch shown below says that
iforce_usb_out()
> from interrupt context hit "urb->status -71, exiting" when
iforce_close()
> from process context was in progress.
>

Thanks to keep on working on this issue. As said, that _timeout() was not
good and the wake ups (better, wake_up_all()) were exactly what you needed.
Now you have all the necessary information to send a real patch :-)

Thanks,

Fabio

> [ 491.314788][ T2962] iforce_close(ffff88807e6b8000) start
> [ 491.316393][ T14] usb 1-1: USB disconnect, device number 117
> [ 491.320453][ T2962] iforce_send_packet(ffff88807e6b8000) start
> [ 491.326488][ C0] iforce 1-1:0.0: urb->status -71, exiting
> [ 491.327471][ T14] iforce_usb_disconnect(ffff88807e6b8000) start
> [ 491.335041][ T2962] iforce_send_packet(ffff88807e6b8000)=0
> [ 491.351266][ T2962] wait_event_interruptible(ffff88807e6b8000) end
> [ 491.357778][ T2962] iforce_close(ffff88807e6b8000) end
> [ 491.366421][ T14] input_unregister_device(ffff88807e6b8000) end
> [ 491.372939][ T14] iforce_usb_disconnect(ffff88807e6b8000) end
>
> On 2022/07/26 12:08, syzbot wrote:
> > Hello,
> >
> > syzbot has tested the proposed patch and the reproducer did not trigger
any issue:
> >
> > Reported-and-tested-by:
syzbot+deb6ab...@syzkaller.appspotmail.com
> >
> > Tested on:
> >
> > commit: e0dccc3b Linux 5.19-rc8
> > git tree: upstream
> > console output: https://syzkaller.appspot.com/x/log.txt?
x=15e470de080000
> > kernel config: https://syzkaller.appspot.com/x/.config?
x=26034e6fe0075dad

> > dashboard link: https://syzkaller.appspot.com/bug?
extid=deb6abc36aad4008f407

[syzbot]

Hello,

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

Reported-and-tested-by: syzbot+deb6ab...@syzkaller.appspotmail.com

Tested on:

commit: 5de64d44 Merge tag 's390-5.19-7' of git://git.kernel.o..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=15708822080000

kernel config: https://syzkaller.appspot.com/x/.config?x=26034e6fe0075dad
dashboard link: https://syzkaller.appspot.com/bug?extid=deb6abc36aad4008f407

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=106676ee080000