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

[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+deb6abc36aad4008f407@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 syzkaller@googlegroups.com.

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

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

[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+deb6abc36aad4008f407@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

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

[syzbot]

syzbot has bisected this issue to:

commit 744d0090a5f6dfa4c81b53402ccdf08313100429
Author: Johan Hovold <johan@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+deb6abc36aad4008f407@syzkaller.appspotmail.com
Fixes: 744d0090a5f6 ("Input: iforce - fix control-message timeout")

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

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

[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

On 2022/07/02 14:32, syzbot wrote:
> 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
> 

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

[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

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

[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...

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

[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()?

> >         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.

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-bugs+unsubscribe@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.
> 

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

[Fabio M. De Francesco]

On giovedì 21 luglio 2022 18:53:27 CEST 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()?
> 
> > >         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.
> 
> It did not clear this problem because of _timeout(), I guess.

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

Thanks,

Fabio

> 
> 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-bugs+unsubscribe@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.
> > 
> 
> 
> 
> 
> 

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

[Fabio M. De Francesco]

[-- Attachment #1: Type: text/plain, Size: 8128 bytes --]

On sabato 2 luglio 2022 17:32:22 CEST syzbot wrote:
> 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+deb6abc36aad4008f407@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
> 
> -- 
> 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-bugs+unsubscribe@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

[-- Attachment #2: diff --]
[-- Type: text/x-patch, Size: 547 bytes --]

diff --git a/drivers/input/joystick/iforce/iforce-usb.c b/drivers/input/joystick/iforce/iforce-usb.c
index ea58805c480f..2717e35c79a3 100644
--- 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);
 
+	clear_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);

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

[syzbot]

Hello,

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

Reported-and-tested-by: syzbot+deb6abc36aad4008f407@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

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

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

[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.torokhov@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 <johannes.ebke@physik.uni-muenchen.de>
      Signed-off-by: Dmitry Torokhov <dtor@mail.ru>

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

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

[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".

> 
> 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.

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.torokhov@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 <johannes.ebke@physik.uni-muenchen.de>
>       Signed-off-by: Dmitry Torokhov <dtor@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

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

[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

> what you said about to signal the waiter that the flag changed.
 

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

[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...

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

[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

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+deb6abc36aad4008f407@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
> 
> Note: testing is done by a robot and is best-effort only.

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

[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+deb6abc36aad4008f407@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
> > 
> > Note: testing is done by a robot and is best-effort only.
>