[syzbot] [input?] INFO: task hung in uhid_char_release

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: f7efed9f38f8 Add linux-next specific files for 20230616
git tree: linux-next
console+strace: https://syzkaller.appspot.com/x/log.txt?x=11ec12f3280000
kernel config: https://syzkaller.appspot.com/x/.config?x=60b1a32485a77c16
dashboard link: https://syzkaller.appspot.com/bug?extid=8fe2d362af0e1cba8735
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=152875ef280000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=1629f75b280000

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/95bcbee03439/disk-f7efed9f.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/6fd295caa4de/vmlinux-f7efed9f.xz
kernel image: https://storage.googleapis.com/syzbot-assets/69c038a34b5f/bzImage-f7efed9f.xz

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

INFO: task syz-executor188:5032 blocked for more than 143 seconds.
Not tainted 6.4.0-rc6-next-20230616-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor188 state:D
stack:27424 pid:5032 ppid:5028 flags:0x00004002
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5380 [inline]
__schedule+0x1d15/0x5790 kernel/sched/core.c:6709
schedule+0xde/0x1a0 kernel/sched/core.c:6785
schedule_timeout+0x276/0x2b0 kernel/time/timer.c:2143
do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common+0x1ce/0x5c0 kernel/sched/completion.c:106
__flush_work+0x595/0xb60 kernel/workqueue.c:3383
__cancel_work_timer+0x3f9/0x570 kernel/workqueue.c:3470
uhid_dev_destroy drivers/hid/uhid.c:585 [inline]
uhid_char_release+0xca/0x210 drivers/hid/uhid.c:663
__fput+0x289/0xac0 fs/file_table.c:378
task_work_run+0x16f/0x270 kernel/task_work.c:179
exit_task_work include/linux/task_work.h:38 [inline]
do_exit+0xadc/0x2a30 kernel/exit.c:874
do_group_exit+0xd4/0x2a0 kernel/exit.c:1024
__do_sys_exit_group kernel/exit.c:1035 [inline]
__se_sys_exit_group kernel/exit.c:1033 [inline]
__x64_sys_exit_group+0x3e/0x50 kernel/exit.c:1033
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x39/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fa196a81b19
RSP: 002b:00007ffc33991898 EFLAGS: 00000246
ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 00007fa196af5330 RCX: 00007fa196a81b19
RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
RBP: 0000000000000000 R08: ffffffffffffffc0 R09: 0000000000000001
R10: 00007ffc33991360 R11: 0000000000000246 R12: 00007fa196af5330
R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000001
</TASK>
INFO: task syz-executor188:5038 blocked for more than 145 seconds.
Not tainted 6.4.0-rc6-next-20230616-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor188 state:D
stack:28176 pid:5038 ppid:5036 flags:0x00004002
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5380 [inline]
__schedule+0x1d15/0x5790 kernel/sched/core.c:6709
schedule+0xde/0x1a0 kernel/sched/core.c:6785
schedule_timeout+0x276/0x2b0 kernel/time/timer.c:2143
do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common+0x1ce/0x5c0 kernel/sched/completion.c:106
__flush_work+0x595/0xb60 kernel/workqueue.c:3383
__cancel_work_timer+0x3f9/0x570 kernel/workqueue.c:3470
uhid_dev_destroy drivers/hid/uhid.c:585 [inline]
uhid_char_release+0xca/0x210 drivers/hid/uhid.c:663
__fput+0x289/0xac0 fs/file_table.c:378
task_work_run+0x16f/0x270 kernel/task_work.c:179
exit_task_work include/linux/task_work.h:38 [inline]
do_exit+0xadc/0x2a30 kernel/exit.c:874
do_group_exit+0xd4/0x2a0 kernel/exit.c:1024
__do_sys_exit_group kernel/exit.c:1035 [inline]
__se_sys_exit_group kernel/exit.c:1033 [inline]
__x64_sys_exit_group+0x3e/0x50 kernel/exit.c:1033
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x39/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fa196a81b19
RSP: 002b:00007ffc33991898 EFLAGS: 00000246
ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 00007fa196af5330 RCX: 00007fa196a81b19
RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
RBP: 0000000000000000 R08: ffffffffffffffc0 R09: 0000000000000001
R10: 00007ffc33991360 R11: 0000000000000246 R12: 00007fa196af5330
R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000001
</TASK>
INFO: task syz-executor188:5042 blocked for more than 147 seconds.
Not tainted 6.4.0-rc6-next-20230616-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor188 state:D stack:27136 pid:5042 ppid:5037 flags:0x00004002
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5380 [inline]
__schedule+0x1d15/0x5790 kernel/sched/core.c:6709
schedule+0xde/0x1a0 kernel/sched/core.c:6785
schedule_timeout+0x276/0x2b0 kernel/time/timer.c:2143
do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common+0x1ce/0x5c0 kernel/sched/completion.c:106
__flush_work+0x595/0xb60 kernel/workqueue.c:3383
__cancel_work_timer+0x3f9/0x570 kernel/workqueue.c:3470
uhid_dev_destroy drivers/hid/uhid.c:585 [inline]
uhid_char_release+0xca/0x210 drivers/hid/uhid.c:663
__fput+0x289/0xac0 fs/file_table.c:378
task_work_run+0x16f/0x270 kernel/task_work.c:179
exit_task_work include/linux/task_work.h:38 [inline]
do_exit+0xadc/0x2a30 kernel/exit.c:874
do_group_exit+0xd4/0x2a0 kernel/exit.c:1024
__do_sys_exit_group kernel/exit.c:1035 [inline]
__se_sys_exit_group kernel/exit.c:1033 [inline]
__x64_sys_exit_group+0x3e/0x50 kernel/exit.c:1033
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x39/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fa196a81b19
RSP: 002b:00007ffc33991898 EFLAGS: 00000246
ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 00007fa196af5330 RCX: 00007fa196a81b19
RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
RBP: 0000000000000000 R08: ffffffffffffffc0 R09: 0000000000000001
R10: 00007ffc33991360 R11: 0000000000000246 R12: 00007fa196af5330
R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000001
</TASK>
INFO: task syz-executor188:5046 blocked for more than 150 seconds.
Not tainted 6.4.0-rc6-next-20230616-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor188 state:D stack:28048 pid:5046 ppid:5029 flags:0x00004002
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5380 [inline]
__schedule+0x1d15/0x5790 kernel/sched/core.c:6709
schedule+0xde/0x1a0 kernel/sched/core.c:6785
schedule_timeout+0x276/0x2b0 kernel/time/timer.c:2143
do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common+0x1ce/0x5c0 kernel/sched/completion.c:106
__flush_work+0x595/0xb60 kernel/workqueue.c:3383
__cancel_work_timer+0x3f9/0x570 kernel/workqueue.c:3470
uhid_dev_destroy drivers/hid/uhid.c:585 [inline]
uhid_char_release+0xca/0x210 drivers/hid/uhid.c:663
__fput+0x289/0xac0 fs/file_table.c:378
task_work_run+0x16f/0x270 kernel/task_work.c:179
exit_task_work include/linux/task_work.h:38 [inline]
do_exit+0xadc/0x2a30 kernel/exit.c:874
do_group_exit+0xd4/0x2a0 kernel/exit.c:1024
__do_sys_exit_group kernel/exit.c:1035 [inline]
__se_sys_exit_group kernel/exit.c:1033 [inline]
__x64_sys_exit_group+0x3e/0x50 kernel/exit.c:1033
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x39/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fa196a81b19
RSP: 002b:00007ffc33991898 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 00007fa196af5330 RCX: 00007fa196a81b19
RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
RBP: 0000000000000000 R08: ffffffffffffffc0 R09: 0000000000000001
R10: 00007ffc33991360 R11: 0000000000000246 R12: 00007fa196af5330
R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000001
</TASK>

Showing all locks held in the system:
3 locks held by kworker/0:0/7:
1 lock held by rcu_tasks_kthre/13:
#0:
ffffffff8c9a1ab0
(
rcu_tasks.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x31/0xe60 kernel/rcu/tasks.h:568
1 lock held by rcu_tasks_trace/14:
#0:
ffffffff8c9a1770
(
rcu_tasks_trace.tasks_gp_mutex){+.+.}-{3:3}
, at: rcu_tasks_one_gp+0x31/0xe60 kernel/rcu/tasks.h:568
3 locks held by kworker/1:0/22:
1 lock held by khungtaskd/28:
#0: ffffffff8c9a26c0 (rcu_read_lock
){....}-{1:2}
, at: debug_show_all_locks+0x51/0x390 kernel/locking/lockdep.c:6615
3 locks held by kworker/1:2/776:
3 locks held by kworker/0:2/919:
3 locks held by kworker/0:3/3948:
2 locks held by getty/4779:
#0:
ffff88814a6b7098


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

If the bug is already fixed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want syzbot to run the reproducer, reply with:
#syz test: git://repo/address.git branch-or-commit-hash
If you attach or paste a git patch, syzbot will apply it before testing.

If you want to change bug's subsystems, reply with:
#syz set subsystems: new-subsystem
(See the list of subsystem names on the web dashboard)

If the bug is a duplicate of another bug, reply with:
#syz dup: exact-subject-of-another-report

If you want to undo deduplication, reply with:
#syz undup

[syzbot]

syzbot has bisected this issue to:

commit bf48961f6f48e3b7eb80c3e179207e9f4e4cd660
Author: Tony Krowiak <akro...@linux.ibm.com>
Date: Tue May 30 22:35:37 2023 +0000

s390/vfio-ap: realize the VFIO_DEVICE_SET_IRQS ioctl

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=155eba2fa80000
start commit: bde7f150276b Merge tag 'pm-6.5-rc2' of git://git.kernel.or..
git tree: upstream
final oops: https://syzkaller.appspot.com/x/report.txt?x=175eba2fa80000
console output: https://syzkaller.appspot.com/x/log.txt?x=135eba2fa80000
kernel config: https://syzkaller.appspot.com/x/.config?x=6d0f369ef5fb88c9
dashboard link: https://syzkaller.appspot.com/bug?extid=8fe2d362af0e1cba8735
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=124711b6a80000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=178c5a92a80000

Reported-by: syzbot+8fe2d3...@syzkaller.appspotmail.com
Fixes: bf48961f6f48 ("s390/vfio-ap: realize the VFIO_DEVICE_SET_IRQS ioctl")

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

[Matthew Rosato]

On 8/29/23 1:28 PM, syzbot wrote:
> syzbot has bisected this issue to:
>
> commit bf48961f6f48e3b7eb80c3e179207e9f4e4cd660
> Author: Tony Krowiak <akro...@linux.ibm.com>
> Date: Tue May 30 22:35:37 2023 +0000
>
> s390/vfio-ap: realize the VFIO_DEVICE_SET_IRQS ioctl

Hmm, this doesn't seem like the right commit. The changes for bf48961f6f48e3b7eb80c3e179207e9f4e4cd660 are limited to the vfio_ap module, which requires CONFIG_S390 and CONFIG_VFIO_AP. Besides the config referenced below I also looked at other cases via the dashboard link and none of the config files I checked had either of these.

Thanks,
Matt