[syzbot] INFO: task hung in port100_probe

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: fd0aa1a4 Merge tag 'for-linus' of git://git.kernel.org/pub..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=13e1500c300000
kernel config: https://syzkaller.appspot.com/x/.config?x=7ca96a2d153c74b0
dashboard link: https://syzkaller.appspot.com/bug?extid=abd2e0dafb481b621869
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1792e284300000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=13ad9d48300000

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

INFO: task kworker/0:1:7 blocked for more than 143 seconds.
Not tainted 5.13.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/0:1 state:D stack:25584 pid: 7 ppid: 2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
context_switch kernel/sched/core.c:4339 [inline]
__schedule+0x916/0x23e0 kernel/sched/core.c:5147
schedule+0xcf/0x270 kernel/sched/core.c:5226
schedule_timeout+0x1db/0x250 kernel/time/timer.c:1868
do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common kernel/sched/completion.c:106 [inline]
wait_for_common kernel/sched/completion.c:117 [inline]
wait_for_completion+0x168/0x270 kernel/sched/completion.c:138
port100_send_cmd_sync drivers/nfc/port100.c:923 [inline]
port100_get_command_type_mask drivers/nfc/port100.c:1008 [inline]
port100_probe+0x9e4/0x1340 drivers/nfc/port100.c:1554
usb_probe_interface+0x315/0x7f0 drivers/usb/core/driver.c:396
really_probe+0x291/0xf60 drivers/base/dd.c:576
driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324
usb_set_configuration+0x113f/0x1910 drivers/usb/core/message.c:2164
usb_generic_driver_probe+0xba/0x100 drivers/usb/core/generic.c:238
usb_probe_device+0xd9/0x2c0 drivers/usb/core/driver.c:293
really_probe+0x291/0xf60 drivers/base/dd.c:576
driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324
usb_new_device.cold+0x721/0x1058 drivers/usb/core/hub.c:2556
hub_port_connect drivers/usb/core/hub.c:5276 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5416 [inline]
port_event drivers/usb/core/hub.c:5562 [inline]
hub_event+0x2357/0x4330 drivers/usb/core/hub.c:5644
process_one_work+0x98d/0x1600 kernel/workqueue.c:2276
process_scheduled_works kernel/workqueue.c:2338 [inline]
worker_thread+0x82b/0x1120 kernel/workqueue.c:2424
kthread+0x3b1/0x4a0 kernel/kthread.c:313
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
INFO: task kworker/1:2:3367 blocked for more than 143 seconds.
Not tainted 5.13.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:2 state:D stack:25552 pid: 3367 ppid: 2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
context_switch kernel/sched/core.c:4339 [inline]
__schedule+0x916/0x23e0 kernel/sched/core.c:5147
schedule+0xcf/0x270 kernel/sched/core.c:5226
schedule_timeout+0x1db/0x250 kernel/time/timer.c:1868
do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common kernel/sched/completion.c:106 [inline]
wait_for_common kernel/sched/completion.c:117 [inline]
wait_for_completion+0x168/0x270 kernel/sched/completion.c:138
port100_send_cmd_sync drivers/nfc/port100.c:923 [inline]
port100_get_command_type_mask drivers/nfc/port100.c:1008 [inline]
port100_probe+0x9e4/0x1340 drivers/nfc/port100.c:1554
usb_probe_interface+0x315/0x7f0 drivers/usb/core/driver.c:396
really_probe+0x291/0xf60 drivers/base/dd.c:576
driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324
usb_set_configuration+0x113f/0x1910 drivers/usb/core/message.c:2164
usb_generic_driver_probe+0xba/0x100 drivers/usb/core/generic.c:238
usb_probe_device+0xd9/0x2c0 drivers/usb/core/driver.c:293
really_probe+0x291/0xf60 drivers/base/dd.c:576
driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324
usb_new_device.cold+0x721/0x1058 drivers/usb/core/hub.c:2556
hub_port_connect drivers/usb/core/hub.c:5276 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5416 [inline]
port_event drivers/usb/core/hub.c:5562 [inline]
hub_event+0x2357/0x4330 drivers/usb/core/hub.c:5644
process_one_work+0x98d/0x1600 kernel/workqueue.c:2276
process_scheduled_works kernel/workqueue.c:2338 [inline]
worker_thread+0x82b/0x1120 kernel/workqueue.c:2424
kthread+0x3b1/0x4a0 kernel/kthread.c:313
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
INFO: task kworker/1:3:4871 blocked for more than 144 seconds.
Not tainted 5.13.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:3 state:D stack:25584 pid: 4871 ppid: 2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
context_switch kernel/sched/core.c:4339 [inline]
__schedule+0x916/0x23e0 kernel/sched/core.c:5147
schedule+0xcf/0x270 kernel/sched/core.c:5226
schedule_timeout+0x1db/0x250 kernel/time/timer.c:1868
do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common kernel/sched/completion.c:106 [inline]
wait_for_common kernel/sched/completion.c:117 [inline]
wait_for_completion+0x168/0x270 kernel/sched/completion.c:138
port100_send_cmd_sync drivers/nfc/port100.c:923 [inline]
port100_get_command_type_mask drivers/nfc/port100.c:1008 [inline]
port100_probe+0x9e4/0x1340 drivers/nfc/port100.c:1554
usb_probe_interface+0x315/0x7f0 drivers/usb/core/driver.c:396
really_probe+0x291/0xf60 drivers/base/dd.c:576
driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324
usb_set_configuration+0x113f/0x1910 drivers/usb/core/message.c:2164
usb_generic_driver_probe+0xba/0x100 drivers/usb/core/generic.c:238
usb_probe_device+0xd9/0x2c0 drivers/usb/core/driver.c:293
really_probe+0x291/0xf60 drivers/base/dd.c:576
driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324
usb_new_device.cold+0x721/0x1058 drivers/usb/core/hub.c:2556
hub_port_connect drivers/usb/core/hub.c:5276 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5416 [inline]
port_event drivers/usb/core/hub.c:5562 [inline]
hub_event+0x2357/0x4330 drivers/usb/core/hub.c:5644
process_one_work+0x98d/0x1600 kernel/workqueue.c:2276
process_scheduled_works kernel/workqueue.c:2338 [inline]
worker_thread+0x82b/0x1120 kernel/workqueue.c:2424
kthread+0x3b1/0x4a0 kernel/kthread.c:313
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
INFO: task kworker/1:0:8456 blocked for more than 144 seconds.
Not tainted 5.13.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:0 state:D stack:25936 pid: 8456 ppid: 2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
context_switch kernel/sched/core.c:4339 [inline]
__schedule+0x916/0x23e0 kernel/sched/core.c:5147
schedule+0xcf/0x270 kernel/sched/core.c:5226
schedule_timeout+0x1db/0x250 kernel/time/timer.c:1868
do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common kernel/sched/completion.c:106 [inline]
wait_for_common kernel/sched/completion.c:117 [inline]
wait_for_completion+0x168/0x270 kernel/sched/completion.c:138
port100_send_cmd_sync drivers/nfc/port100.c:923 [inline]
port100_get_command_type_mask drivers/nfc/port100.c:1008 [inline]
port100_probe+0x9e4/0x1340 drivers/nfc/port100.c:1554
usb_probe_interface+0x315/0x7f0 drivers/usb/core/driver.c:396
really_probe+0x291/0xf60 drivers/base/dd.c:576
driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324
usb_set_configuration+0x113f/0x1910 drivers/usb/core/message.c:2164
usb_generic_driver_probe+0xba/0x100 drivers/usb/core/generic.c:238
usb_probe_device+0xd9/0x2c0 drivers/usb/core/driver.c:293
really_probe+0x291/0xf60 drivers/base/dd.c:576
driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324
usb_new_device.cold+0x721/0x1058 drivers/usb/core/hub.c:2556
hub_port_connect drivers/usb/core/hub.c:5276 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5416 [inline]
port_event drivers/usb/core/hub.c:5562 [inline]
hub_event+0x2357/0x4330 drivers/usb/core/hub.c:5644
process_one_work+0x98d/0x1600 kernel/workqueue.c:2276
process_scheduled_works kernel/workqueue.c:2338 [inline]
worker_thread+0x82b/0x1120 kernel/workqueue.c:2424
kthread+0x3b1/0x4a0 kernel/kthread.c:313
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
INFO: task kworker/1:1:8462 blocked for more than 145 seconds.
Not tainted 5.13.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:1 state:D stack:25960 pid: 8462 ppid: 2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
context_switch kernel/sched/core.c:4339 [inline]
__schedule+0x916/0x23e0 kernel/sched/core.c:5147
schedule+0xcf/0x270 kernel/sched/core.c:5226
schedule_timeout+0x1db/0x250 kernel/time/timer.c:1868
do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common kernel/sched/completion.c:106 [inline]
wait_for_common kernel/sched/completion.c:117 [inline]
wait_for_completion+0x168/0x270 kernel/sched/completion.c:138
port100_send_cmd_sync drivers/nfc/port100.c:923 [inline]
port100_get_command_type_mask drivers/nfc/port100.c:1008 [inline]
port100_probe+0x9e4/0x1340 drivers/nfc/port100.c:1554
usb_probe_interface+0x315/0x7f0 drivers/usb/core/driver.c:396
really_probe+0x291/0xf60 drivers/base/dd.c:576
driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324
usb_set_configuration+0x113f/0x1910 drivers/usb/core/message.c:2164
usb_generic_driver_probe+0xba/0x100 drivers/usb/core/generic.c:238
usb_probe_device+0xd9/0x2c0 drivers/usb/core/driver.c:293
really_probe+0x291/0xf60 drivers/base/dd.c:576
driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324
usb_new_device.cold+0x721/0x1058 drivers/usb/core/hub.c:2556
hub_port_connect drivers/usb/core/hub.c:5276 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5416 [inline]
port_event drivers/usb/core/hub.c:5562 [inline]
hub_event+0x2357/0x4330 drivers/usb/core/hub.c:5644
process_one_work+0x98d/0x1600 kernel/workqueue.c:2276
process_scheduled_works kernel/workqueue.c:2338 [inline]
worker_thread+0x82b/0x1120 kernel/workqueue.c:2424
kthread+0x3b1/0x4a0 kernel/kthread.c:313
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
INFO: task syz-executor195:8751 blocked for more than 145 seconds.
Not tainted 5.13.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor195 state:D stack:28016 pid: 8751 ppid: 8448 flags:0x00000004
Call Trace:
context_switch kernel/sched/core.c:4339 [inline]
__schedule+0x916/0x23e0 kernel/sched/core.c:5147
schedule+0xcf/0x270 kernel/sched/core.c:5226
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5285
__mutex_lock_common kernel/locking/mutex.c:1036 [inline]
__mutex_lock+0x7d4/0x10c0 kernel/locking/mutex.c:1104
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x11b0 fs/open.c:826
do_open fs/namei.c:3361 [inline]
path_openat+0x1c0e/0x27e0 fs/namei.c:3494
do_filp_open+0x190/0x3d0 fs/namei.c:3521
do_sys_openat2+0x16d/0x420 fs/open.c:1187
do_sys_open fs/open.c:1203 [inline]
__do_sys_openat fs/open.c:1219 [inline]
__se_sys_openat fs/open.c:1214 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1214
do_syscall_64+0x3a/0xb0 arch/x86/entry/common.c:47
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x402af7
RSP: 002b:00007ffc0cb8ab80 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00000000200000c0 RCX: 0000000000402af7
RDX: 0000000000000002 RSI: 000000000048803b RDI: 00000000ffffff9c
RBP: 000000000048803b R08: 00007ffc0cb8ac68 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
R13: 00007ffc0cb8ccdc R14: 0000000000000036 R15: 00007ffc0cb8cce0
INFO: task syz-executor195:8758 blocked for more than 145 seconds.
Not tainted 5.13.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor195 state:D stack:28144 pid: 8758 ppid: 8447 flags:0x00000004
Call Trace:
context_switch kernel/sched/core.c:4339 [inline]
__schedule+0x916/0x23e0 kernel/sched/core.c:5147
schedule+0xcf/0x270 kernel/sched/core.c:5226
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5285
__mutex_lock_common kernel/locking/mutex.c:1036 [inline]
__mutex_lock+0x7d4/0x10c0 kernel/locking/mutex.c:1104
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x11b0 fs/open.c:826
do_open fs/namei.c:3361 [inline]
path_openat+0x1c0e/0x27e0 fs/namei.c:3494
do_filp_open+0x190/0x3d0 fs/namei.c:3521
do_sys_openat2+0x16d/0x420 fs/open.c:1187
do_sys_open fs/open.c:1203 [inline]
__do_sys_openat fs/open.c:1219 [inline]
__se_sys_openat fs/open.c:1214 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1214
do_syscall_64+0x3a/0xb0 arch/x86/entry/common.c:47
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x402af7
RSP: 002b:00007ffc0cb8ab80 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00000000200000c0 RCX: 0000000000402af7
RDX: 0000000000000002 RSI: 000000000048803b RDI: 00000000ffffff9c
RBP: 000000000048803b R08: 00007ffc0cb8ac68 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
R13: 00007ffc0cb8ccdc R14: 0000000000000036 R15: 00007ffc0cb8cce0
INFO: task syz-executor195:8778 blocked for more than 146 seconds.
Not tainted 5.13.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor195 state:D stack:28144 pid: 8778 ppid: 8445 flags:0x00000004
Call Trace:
context_switch kernel/sched/core.c:4339 [inline]
__schedule+0x916/0x23e0 kernel/sched/core.c:5147
schedule+0xcf/0x270 kernel/sched/core.c:5226
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5285
__mutex_lock_common kernel/locking/mutex.c:1036 [inline]
__mutex_lock+0x7d4/0x10c0 kernel/locking/mutex.c:1104
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x11b0 fs/open.c:826
do_open fs/namei.c:3361 [inline]
path_openat+0x1c0e/0x27e0 fs/namei.c:3494
do_filp_open+0x190/0x3d0 fs/namei.c:3521
do_sys_openat2+0x16d/0x420 fs/open.c:1187
do_sys_open fs/open.c:1203 [inline]
__do_sys_openat fs/open.c:1219 [inline]
__se_sys_openat fs/open.c:1214 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1214
do_syscall_64+0x3a/0xb0 arch/x86/entry/common.c:47
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x402af7
RSP: 002b:00007ffc0cb8ab80 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00000000200000c0 RCX: 0000000000402af7
RDX: 0000000000000002 RSI: 000000000048803b RDI: 00000000ffffff9c
RBP: 000000000048803b R08: 00007ffc0cb8ac68 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
R13: 00007ffc0cb8ccdc R14: 0000000000000036 R15: 00007ffc0cb8cce0
INFO: task syz-executor195:8784 blocked for more than 146 seconds.
Not tainted 5.13.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor195 state:D stack:28144 pid: 8784 ppid: 8446 flags:0x00000004
Call Trace:
context_switch kernel/sched/core.c:4339 [inline]
__schedule+0x916/0x23e0 kernel/sched/core.c:5147
schedule+0xcf/0x270 kernel/sched/core.c:5226
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5285
__mutex_lock_common kernel/locking/mutex.c:1036 [inline]
__mutex_lock+0x7d4/0x10c0 kernel/locking/mutex.c:1104
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x11b0 fs/open.c:826
do_open fs/namei.c:3361 [inline]
path_openat+0x1c0e/0x27e0 fs/namei.c:3494
do_filp_open+0x190/0x3d0 fs/namei.c:3521
do_sys_openat2+0x16d/0x420 fs/open.c:1187
do_sys_open fs/open.c:1203 [inline]
__do_sys_openat fs/open.c:1219 [inline]
__se_sys_openat fs/open.c:1214 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1214
do_syscall_64+0x3a/0xb0 arch/x86/entry/common.c:47
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x402af7
RSP: 002b:00007ffc0cb8ab80 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00000000200000c0 RCX: 0000000000402af7
RDX: 0000000000000002 RSI: 000000000048803b RDI: 00000000ffffff9c
RBP: 000000000048803b R08: 00007ffc0cb8ac68 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
R13: 00007ffc0cb8ccdc R14: 0000000000000036 R15: 00007ffc0cb8cce0
INFO: task syz-executor195:8792 blocked for more than 146 seconds.
Not tainted 5.13.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor195 state:D stack:28144 pid: 8792 ppid: 8442 flags:0x00004004
Call Trace:
context_switch kernel/sched/core.c:4339 [inline]
__schedule+0x916/0x23e0 kernel/sched/core.c:5147
schedule+0xcf/0x270 kernel/sched/core.c:5226
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5285
__mutex_lock_common kernel/locking/mutex.c:1036 [inline]
__mutex_lock+0x7d4/0x10c0 kernel/locking/mutex.c:1104
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4b9/0x11b0 fs/open.c:826
do_open fs/namei.c:3361 [inline]
path_openat+0x1c0e/0x27e0 fs/namei.c:3494
do_filp_open+0x190/0x3d0 fs/namei.c:3521
do_sys_openat2+0x16d/0x420 fs/open.c:1187
do_sys_open fs/open.c:1203 [inline]
__do_sys_openat fs/open.c:1219 [inline]
__se_sys_openat fs/open.c:1214 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1214
do_syscall_64+0x3a/0xb0 arch/x86/entry/common.c:47
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x402af7
RSP: 002b:00007ffc0cb8ab80 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00000000200000c0 RCX: 0000000000402af7
RDX: 0000000000000002 RSI: 000000000048803b RDI: 00000000ffffff9c
RBP: 000000000048803b R08: 00007ffc0cb8ac68 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
R13: 00007ffc0cb8ccdc R14: 0000000000000036 R15: 00007ffc0cb8cce0

Showing all locks held in the system:
3 locks held by kworker/0:0/5:
5 locks held by kworker/0:1/7:
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic64_set include/asm-generic/atomic-instrumented.h:856 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/asm-generic/atomic-long.h:41 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:617 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x871/0x1600 kernel/workqueue.c:2247
#1: ffffc90000cc7da8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8a5/0x1600 kernel/workqueue.c:2251
#2: ffff8880215bc220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#2: ffff8880215bc220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5590
#3: ffff8880143f6220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#3: ffff8880143f6220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4b0 drivers/base/dd.c:913
#4: ffff88802d51b1a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#4: ffff88802d51b1a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4b0 drivers/base/dd.c:913
1 lock held by khungtaskd/1643:
#0: ffffffff8bf79620 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6333
5 locks held by kworker/1:2/3367:
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic64_set include/asm-generic/atomic-instrumented.h:856 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/asm-generic/atomic-long.h:41 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:617 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x871/0x1600 kernel/workqueue.c:2247
#1: ffffc90003027da8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8a5/0x1600 kernel/workqueue.c:2251
#2: ffff8880214df220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#2: ffff8880214df220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5590
#3: ffff888019014220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#3: ffff888019014220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4b0 drivers/base/dd.c:913
#4: ffff8880190171a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#4: ffff8880190171a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4b0 drivers/base/dd.c:913
5 locks held by kworker/1:3/4871:
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic64_set include/asm-generic/atomic-instrumented.h:856 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/asm-generic/atomic-long.h:41 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:617 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x871/0x1600 kernel/workqueue.c:2247
#1: ffffc9000b01fda8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8a5/0x1600 kernel/workqueue.c:2251
#2: ffff88802168b220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#2: ffff88802168b220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5590
#3: ffff88802d05d220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#3: ffff88802d05d220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4b0 drivers/base/dd.c:913
#4: ffff8880190131a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#4: ffff8880190131a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4b0 drivers/base/dd.c:913
1 lock held by in:imklog/8343:
#0: ffff8880147e6870 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:974
5 locks held by kworker/1:0/8456:
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic64_set include/asm-generic/atomic-instrumented.h:856 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/asm-generic/atomic-long.h:41 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:617 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x871/0x1600 kernel/workqueue.c:2247
#1: ffffc900016cfda8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8a5/0x1600 kernel/workqueue.c:2251
#2: ffff8880216c3220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#2: ffff8880216c3220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5590
#3: ffff88802d059220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#3: ffff88802d059220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4b0 drivers/base/dd.c:913
#4: ffff888030fe51a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#4: ffff888030fe51a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4b0 drivers/base/dd.c:913
5 locks held by kworker/1:1/8462:
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic64_set include/asm-generic/atomic-instrumented.h:856 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/asm-generic/atomic-long.h:41 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:617 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: ffff8880198c2d38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x871/0x1600 kernel/workqueue.c:2247
#1: ffffc900016dfda8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8a5/0x1600 kernel/workqueue.c:2251
#2: ffff88823bc62a20 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#2: ffff88823bc62a20 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5590
#3: ffff888030fe7220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#3: ffff888030fe7220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4b0 drivers/base/dd.c:913
#4: ffff8880190151a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:742 [inline]
#4: ffff8880190151a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4b0 drivers/base/dd.c:913
1 lock held by syz-executor195/8751:
#0: ffffffff8c99e6e8 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor195/8758:
#0: ffffffff8c99e6e8 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor195/8778:
#0: ffffffff8c99e6e8 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor195/8784:
#0: ffffffff8c99e6e8 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor195/8792:
#0: ffffffff8c99e6e8 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
2 locks held by syz-executor195/8814:
#0: ffffffff8c99e6e8 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
#1: ffffffff8be49fe8 (system_transition_mutex){+.+.}-{3:3}, at: snapshot_open+0x3b/0x2a0 kernel/power/user.c:54

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

NMI backtrace for cpu 1
CPU: 1 PID: 1643 Comm: khungtaskd Not tainted 5.13.0-rc6-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:79 [inline]
dump_stack+0x141/0x1d7 lib/dump_stack.c:120
nmi_cpu_backtrace.cold+0x44/0xd7 lib/nmi_backtrace.c:105
nmi_trigger_cpumask_backtrace+0x1b3/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:209 [inline]
watchdog+0xd48/0xfb0 kernel/hung_task.c:294
kthread+0x3b1/0x4a0 kernel/kthread.c:313
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 4850 Comm: systemd-journal Not tainted 5.13.0-rc6-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0033:0x7fbb9961e46c
Code: d1 49 89 e1 31 d2 41 b8 10 00 00 00 41 89 f6 49 89 e7 e8 57 fc ff ff 85 c0 41 89 c4 0f 88 5f ff ff ff 48 8b 04 24 4c 8b 40 08 <4d> 85 c0 0f 84 bb 00 00 00 49 83 f8 0f 0f 87 e1 00 00 00 e8 6c 7b
RSP: 002b:00007ffc2e6bdca0 EFLAGS: 00000202
RAX: 00007fbb96c1b798 RBX: 000000000016c798 RCX: 000000000016c798
RDX: 0000000000000000 RSI: 0000000000000010 RDI: 00005570395fa120
RBP: 00005570395f9e80 R08: 0000000000001608 R09: 00005570395fa120
R10: 00007ffc2e6cf090 R11: 00007fbb96da6658 R12: 0000000000000001
R13: 00007ffc2e6bdd18 R14: 0000000000000006 R15: 00007ffc2e6bdca0
FS: 00007fbb999308c0 GS: 0000000000000000


---
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 can test patches for this issue, for details see:
https://goo.gl/tpsmEJ#testing-patches

[Pavel Skripkin]

On Tue, 22 Jun 2021 08:43:29 -0700
syzbot <syzbot+abd2e0...@syzkaller.appspotmail.com> wrote:

> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit: fd0aa1a4 Merge tag 'for-linus' of
> git://git.kernel.org/pub.. git tree: upstream
> console output:
> https://syzkaller.appspot.com/x/log.txt?x=13e1500c300000 kernel
> config: https://syzkaller.appspot.com/x/.config?x=7ca96a2d153c74b0
> dashboard link:
> https://syzkaller.appspot.com/bug?extid=abd2e0dafb481b621869 syz
> repro:
> https://syzkaller.appspot.com/x/repro.syz?x=1792e284300000 C
> reproducer: https://syzkaller.appspot.com/x/repro.c?x=13ad9d48300000
>
> IMPORTANT: if you fix the issue, please add the following tag to the
> commit: Reported-by:
> syzbot+abd2e0...@syzkaller.appspotmail.com
>
> INFO: task kworker/0:1:7 blocked for more than 143 seconds.
> Not tainted 5.13.0-rc6-syzkaller #0
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
> message. task:kworker/0:1 state:D stack:25584 pid: 7 ppid:
> 2 flags:0x00004000 Workqueue: usb_hub_wq hub_event

Hmmm, maybe this will work


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




With regards,
Pavel Skripkin

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
WARNING: ODEBUG bug in release_nodes

------------[ cut here ]------------
ODEBUG: free active (active state 0) object type: work_struct hint: port100_wq_cmd_complete+0x0/0x3b0 drivers/nfc/port100.c:1174
WARNING: CPU: 1 PID: 10270 at lib/debugobjects.c:505 debug_print_object+0x16e/0x250 lib/debugobjects.c:505
Modules linked in:
CPU: 1 PID: 10270 Comm: kworker/1:8 Not tainted 5.13.0-rc7-syzkaller #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011

Workqueue: usb_hub_wq hub_event
RIP: 0010:debug_print_object+0x16e/0x250 lib/debugobjects.c:505
Code: ff df 48 89 fa 48 c1 ea 03 80 3c 02 00 0f 85 af 00 00 00 48 8b 14 dd a0 f6 c2 89 4c 89 ee 48 c7 c7 a0 ea c2 89 e8 2d ee 01 05 <0f> 0b 83 05 25 2d 76 09 01 48 83 c4 18 5b 5d 41 5c 41 5d 41 5e c3
RSP: 0018:ffffc9000af76fc8 EFLAGS: 00010282
RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
RDX: ffff888017f11c40 RSI: ffffffff815ce3a5 RDI: fffff520015eedeb
RBP: 0000000000000001 R08: 0000000000000000 R09: 0000000000000000
R10: ffffffff815c820e R11: 0000000000000000 R12: ffffffff896ae040
R13: ffffffff89c2f0e0 R14: ffffffff814a7730 R15: dffffc0000000000
FS: 0000000000000000(0000) GS:ffff8880b9d00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fb6ceabf000 CR3: 000000001cbec000 CR4: 00000000001506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
__debug_check_no_obj_freed lib/debugobjects.c:987 [inline]
debug_check_no_obj_freed+0x301/0x420 lib/debugobjects.c:1018
slab_free_hook mm/slub.c:1558 [inline]
slab_free_freelist_hook+0x174/0x240 mm/slub.c:1608
slab_free mm/slub.c:3168 [inline]
kfree+0xe5/0x7f0 mm/slub.c:4212
release_nodes+0x4a3/0x8f0 drivers/base/devres.c:524
devres_release_all+0x74/0xd0 drivers/base/devres.c:545
really_probe+0x557/0xf60 drivers/base/dd.c:644

driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324
usb_set_configuration+0x113f/0x1910 drivers/usb/core/message.c:2164
usb_generic_driver_probe+0xba/0x100 drivers/usb/core/generic.c:238
usb_probe_device+0xd9/0x2c0 drivers/usb/core/driver.c:293
really_probe+0x291/0xf60 drivers/base/dd.c:576
driver_probe_device+0x298/0x410 drivers/base/dd.c:763
__device_attach_driver+0x203/0x2c0 drivers/base/dd.c:870
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:431
__device_attach+0x228/0x4b0 drivers/base/dd.c:938
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:491
device_add+0xbe0/0x2100 drivers/base/core.c:3324

usb_new_device.cold+0x721/0x1058 drivers/usb/core/hub.c:2558
hub_port_connect drivers/usb/core/hub.c:5278 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5418 [inline]
port_event drivers/usb/core/hub.c:5564 [inline]
hub_event+0x2357/0x4330 drivers/usb/core/hub.c:5646
process_one_work+0x98d/0x1600 kernel/workqueue.c:2276
worker_thread+0x64c/0x1120 kernel/workqueue.c:2422

kthread+0x3b1/0x4a0 kernel/kthread.c:313
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294

Tested on:

commit: a96bfed6 Merge tag 'for-linus' of git://git.armlinux.org.u..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=12448400300000
kernel config: https://syzkaller.appspot.com/x/.config?x=3932cedd2c2d4a69
dashboard link: https://syzkaller.appspot.com/bug?extid=abd2e0dafb481b621869
compiler:
patch: https://syzkaller.appspot.com/x/patch.diff?x=15683230300000

[Krzysztof Kozlowski]

Cc: Thierry, Alan, Andrey,

The issue is reproducible immediately on QEMU instance with
USB_DUMMY_HCD and USB_RAW_GADGET. I don't know about real port100 NFC
device.

I spent some time looking into this and have no clue, except that it
looks like an effect of a race condition.

1. When using syskaller reproducer against one USB device (In the C
reproducer change the loop in main() to use procid=0) - issue does not
happen.

2. With two threads or more talking to separate Dummy USB devices, the
issue appears. The more of them, the better...

3. The reported problem is in missing complete. The correct flow is like:
port100_probe()
port100_get_command_type_mask()
port100_send_cmd_sync()
port100_send_cmd_async()
port100_submit_urb_for_ack()
port100_send_complete()
[ 63.363863] port100 2-1:0.0: NFC: Urb failure (status -71)
port100_recv_ack()
[ 63.369942] port100 2-1:0.0: NFC: Urb failure (status -71)

and schedule_work() which completes and unblocks port100_send_cmd_sync

However in the failing case (hung task) the port100_recv_ack() is never
called. It looks like USB core / HCD / gadget does not send the Ack/URB
complete.

I don't know why. The port100 NFC driver code looks OK, except it is not
prepared for missing ack/urb so it waits indefinitely. I could try to
convert it to wait_for_completion_timeout() but it won't be trivial and
more important - I am not sure if this is the problem. Somehow the ACK
with Urb failure is not sent back to the port100 device. Therefore I am
guessing that the race condition is somwhere in USB stack, not in
port100 driver.

The lockdep and other testing tools did not find anything here.

Anyone hints where the issue could be?

Best regards,
Krzysztof

[Krzysztof Kozlowski]

Also syzbot report for pn533 NFC (and its code) looks very similar:
https://lore.kernel.org/lkml/00000000000053...@google.com/

Best regards,
Best regards,
Krzysztof

[Alan Stern]

...

Here's what I wrote earlier: "It looks like the problem stems from the fact
that port100_send_frame_async() submits two URBs, but
port100_send_cmd_sync() only waits for one of them to complete. The other
URB may then still be active when the driver tries to reuse it."

Of course, there may be more than one problem, so we may not be talking
about the same thing.

Does that help at all?

Alan Stern

[Krzysztof Kozlowski]

I see now you replied this to earlier syzbot report about "URB submitted
while active". Here is a slightly different issue - hung task on waiting
for completion coming from device ack.

However maybe these are both similar or at least come from similar root
cause in the driver.

>
> Of course, there may be more than one problem, so we may not be talking
> about the same thing.
>
> Does that help at all?

Thanks, it gives me some ideas to look into although I spent already too
much time on this old driver. I doubt it has any users so maybe better
to mark it as BROKEN...


Best regards,
Krzysztof

[Alan Stern]

Exactly what I was thinking. :-)

> > Of course, there may be more than one problem, so we may not be talking
> > about the same thing.
> >
> > Does that help at all?
>
> Thanks, it gives me some ideas to look into although I spent already too
> much time on this old driver. I doubt it has any users so maybe better
> to mark it as BROKEN...

Whatever you think is best. I know nothing about port100.

Alan Stern

[Krzysztof Kozlowski]

On 22/07/2021 16:47, Alan Stern wrote:

Hi Alan, Felipe, Greg and others,

This is an old issue reported by syzkaller for NFC port100 driver [1].
There is something similar for pn533 [2].

I was looking at it some time ago, took a break and now I am trying to
fix it again. Without success.

The issue is reproducible via USB gadget on QEMU, not on real HW. I
looked and debugged the code and I think previously mentioned
double-URB-submit is not the reason here. Or I miss how the USB works
(which is quite probable...).

1. The port100 driver calls port100_send_cmd_sync() which eventually
goes to port100_send_frame_async(). After it, it waits for "sync"
completion.

2. In port100_send_frame_async(), driver indeed first submits "out_urb"
which quite fast is being processed by dummy_hcd with "no ep configured"
and -EPROTO.

3. Then (or sometimes before -EPROTO response from (2) above) the
port100_send_frame_async() submits "in_urb" via
port100_submit_urb_for_ack() and waits for its completion. Completion of
"in_urb" (or the "ack") in port100_recv_ack() would schedule work to
complete the (1) above - the sync completion.

4. Usually, when reproducer works fine (does not trigger issue), the
dummy_timer() from gadget responds with the same "no ep configured for
urb" for this "in_urb" (3). This completes "in_urb", which eventually
completes (1) and probe finishes with error. Error is expected, because
it's random junk-gadget...

The syzkaller reproducer fails if >1 of threads are running these usb
gadgets. When this happens, no "in_urb" completion happens. No this
"ack" port100_recv_ack().

I added some debugs and simply dummy_hcd dummy_timer() is woken up on
enqueuing in_urb and then is looping crazy on a previous URB (some older
URB, coming from before port100 driver probe started). The dummy_timer()
loop never reaches the second "in_urb" to process it, I think.

The pn533 NFC driver has similar design, but I have now really doubts it
is a NFC driver issue. Instead an issue in dummy gadget HCD is somehow
triggered by the reproducer.

Reproduction - just follow [1] or [2]. Eventually I slightly tweaked the
code and put here:
https://github.com/krzk/tools/tree/master/tests-var/nfc/port100_probe
$ make
$ sudo ./port100_probe


[1] https://syzkaller.appspot.com/bug?extid=abd2e0dafb481b621869
[2] https://syzkaller.appspot.com/bug?extid=1dc8b460d6d48d7ef9ca


Best regards,
Krzysztof

[Alan Stern]

Is there any way you can track down what's happening in that crazy loop?
That is, what driver was responsible for the previous URB?

We have seen this sort of thing before, where a driver submits an URB
for a gadget which has disconnected. The URB fails with -EPROTO status
but the URB's completion handler does an automatic resubmit. That can
lead to a very tight loop with dummy-hcd, and it could easily prevent
some other important processing from occurring. The simple solution is
to prevent the driver from resubmitting when the completion status is
-EPROTO.

Alan Stern

[Krzysztof Kozlowski]

On 21/10/2021 00:05, Alan Stern wrote:
>>
>> The syzkaller reproducer fails if >1 of threads are running these usb
>> gadgets. When this happens, no "in_urb" completion happens. No this
>> "ack" port100_recv_ack().
>>
>> I added some debugs and simply dummy_hcd dummy_timer() is woken up on
>> enqueuing in_urb and then is looping crazy on a previous URB (some older
>> URB, coming from before port100 driver probe started). The dummy_timer()
>> loop never reaches the second "in_urb" to process it, I think.
>
> Is there any way you can track down what's happening in that crazy loop?
> That is, what driver was responsible for the previous URB?
>
> We have seen this sort of thing before, where a driver submits an URB
> for a gadget which has disconnected. The URB fails with -EPROTO status
> but the URB's completion handler does an automatic resubmit. That can
> lead to a very tight loop with dummy-hcd, and it could easily prevent
> some other important processing from occurring. The simple solution is
> to prevent the driver from resubmitting when the completion status is
> -EPROTO.

Hi Alan,

Thanks for the reply.

The URB which causes crazy loop is the port100 driver second URB, the
one called ack or in_urb.

The flow is:
1. probe()
2. port100_get_command_type_mask()
3. port100_send_cmd_async()
4. port100_send_frame_async()
5. usb_submit_urb(dev->out_urb)
The call succeeds, the dummy_hcd picks it up and immediately ends the
timer-loop with -EPROTO

The completion here does not resubmit another/same URB. I checked this
carefully and I hope I did not miss anything.

6. port100_submit_urb_for_ack() which sends the in_urb:
usb_submit_urb(dev->in_urb)
... wait for completion
... dummy_hcd loops on this URB around line 2000:
if (status == -EINPROGRESS)
continue

Best regards,
Krzysztof

[Alan Stern]

So that URB completes immediately.

> The completion here does not resubmit another/same URB. I checked this
> carefully and I hope I did not miss anything.

Yeah, I see the same thing.

> 6. port100_submit_urb_for_ack() which sends the in_urb:
> usb_submit_urb(dev->in_urb)
> ... wait for completion
> ... dummy_hcd loops on this URB around line 2000:
> if (status == -EINPROGRESS)
> continue

Do I understand this correctly? You're saying that dummy-hcd executes
the following jump at line 1975:

/* incomplete transfer? */
if (status == -EINPROGRESS)
continue;

which goes back up to the loop head on line 1831:

list_for_each_entry_safe(urbp, tmp, &dum_hcd->urbp_list, urbp_list) {

Is that right? I don't see why this should cause any problem. It won't
loop back to the same URB; it will make its way through the list.
(Unless the list has somehow gotten corrupted...) dum_hcd->urbp_list
should be short (perhaps 32 entries at most), so the loop should reach
the end of the list fairly quickly.

Now, doing all this 1000 times per second could use up a significant
portion of the available time. Do you think that's the reason for the
problem? It seems pretty unlikely.

Alan Stern

[Krzysztof Kozlowski]

Yes, exactly. The loop continues, iterating over list finishes thus the
loops and dummy timer function exits. Then immediately it is being
rescheduled by something (I don't know by what yet).

To remind - the syzbot reproducer must run at least two threads
(spawning USB gadgets so creating separate dummy devices) at the same
time. However only one of dummy HCD devices seems to timer-loop
endlessly... but this might not be important, e.g. maybe it's how syzbot
reproducer works.

> I don't see why this should cause any problem. It won't
> loop back to the same URB; it will make its way through the list.
> (Unless the list has somehow gotten corrupted...) dum_hcd->urbp_list
> should be short (perhaps 32 entries at most), so the loop should reach
> the end of the list fairly quickly.

The list has actually only one element - only this one URB coming from
port100 device (which I was always calling second URB/ack, in_urb).

> Now, doing all this 1000 times per second could use up a significant
> portion of the available time. Do you think that's the reason for the
> problem? It seems pretty unlikely.

No, this timer-looping itself is not a problem. Problem is that this URB
never reaches some final state, e.g. -EPROTO.

In normal operation, e.g. when reproducer did not hit the issue, both
URBs from port100 (the first out_urb and second in_urb) complete with
-EPROTO. In the case leading to hang ("task kworker/0:0:5 blocked for
more than 143 seconds"), the in_urb does not complete therefore the
port100 driver waits.

Whether this intensive timer-loop is important (processing the same URB
and continuing), I don't know.

Best regards,
Krzysztof

[Alan Stern]

There's a timer (dum_hcd->timer) which fires every millisecond. If
syzbot creates a lot of dummy-hcd instances then each instance will have
its own timer, which could use up a large part of the available CPU
time. But you say this isn't the real problem...

> To remind - the syzbot reproducer must run at least two threads
> (spawning USB gadgets so creating separate dummy devices) at the same
> time. However only one of dummy HCD devices seems to timer-loop
> endlessly... but this might not be important, e.g. maybe it's how syzbot
> reproducer works.
>
> > I don't see why this should cause any problem. It won't
> > loop back to the same URB; it will make its way through the list.
> > (Unless the list has somehow gotten corrupted...) dum_hcd->urbp_list
> > should be short (perhaps 32 entries at most), so the loop should reach
> > the end of the list fairly quickly.
>
> The list has actually only one element - only this one URB coming from
> port100 device (which I was always calling second URB/ack, in_urb).

Okay, good.

> > Now, doing all this 1000 times per second could use up a significant
> > portion of the available time. Do you think that's the reason for the
> > problem? It seems pretty unlikely.
>
> No, this timer-looping itself is not a problem. Problem is that this URB
> never reaches some final state, e.g. -EPROTO.

The -EPROTO completion should happen very quickly once the gadget driver
unregisters or disconnects itself. This is because the call to
find_endpoint at line 1856 should return NULL:

ep = find_endpoint(dum, address);
if (!ep) {
/* set_configuration() disagreement */
dev_dbg(dummy_dev(dum_hcd),
"no ep configured for urb %p\n",
urb);
status = -EPROTO;
goto return_urb;
}

The NULL return should be caused by the !is_active test at the
beginning of find_endpoint:

static struct dummy_ep *find_endpoint(struct dummy *dum, u8 address)
{
int i;

if (!is_active((dum->gadget.speed == USB_SPEED_SUPER ?
dum->ss_hcd : dum->hs_hcd)))
return NULL;

is_active is defined as a macro:

#define is_active(dum_hcd) ((dum_hcd->port_status & \
(USB_PORT_STAT_CONNECTION | USB_PORT_STAT_ENABLE | \
USB_PORT_STAT_SUSPEND)) \
== (USB_PORT_STAT_CONNECTION | USB_PORT_STAT_ENABLE))

and a disconnection should turn off the USB_PORT_STAT_CONNECTION bit, as
follows:

usb_gadget_unregister_driver calls usb_gadget_remove_driver
(in drivers/usb/gadget/udc/core.c),

which calls usb_gadget_disconnect,

which calls dummy_pullup with value = 0,

which sets dum->pullup to 0 and calls set_link_state,

which calls set_link_state_by_speed,

which turns off the USB_PORT_STATE_CONNECTION bit in
dum_hcd->port_status because dum->pullup is 0.

You can try tracing through this sequence of events to see if they're
not taking place as intended.

> In normal operation, e.g. when reproducer did not hit the issue, both
> URBs from port100 (the first out_urb and second in_urb) complete with
> -EPROTO. In the case leading to hang ("task kworker/0:0:5 blocked for
> more than 143 seconds"), the in_urb does not complete therefore the
> port100 driver waits.

Those "... blocked for more than 143 seconds" errors occur when some
task or interrupt loop is using up all the CPU time, preventing normal
processes from running. In this case the culprit has got to be the
timer routine and loop in dummy_hcd. However, the loop should terminate
once the gadget driver unregisters itself, as described above.

> Whether this intensive timer-loop is important (processing the same URB
> and continuing), I don't know.

Yes, that's how dummy_hcd gets its work done.

Alan Stern

[syzbot]

Hello,

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

INFO: task hung in port100_probe

INFO: task kworker/0:4:2934 blocked for more than 143 seconds.
Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

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

task:kworker/0:4 state:D stack:25520 pid: 2934 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:

<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_timeout+0x1db/0x2a0 kernel/time/timer.c:1857

do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common kernel/sched/completion.c:106 [inline]
wait_for_common kernel/sched/completion.c:117 [inline]

wait_for_completion+0x174/0x270 kernel/sched/completion.c:138
port100_send_cmd_sync drivers/nfc/port100.c:926 [inline]
port100_get_command_type_mask drivers/nfc/port100.c:1011 [inline]
port100_probe+0x9ec/0x1320 drivers/nfc/port100.c:1557
usb_probe_interface+0x315/0x7f0 drivers/usb/core/driver.c:396
call_driver_probe drivers/base/dd.c:517 [inline]
really_probe+0x245/0xcc0 drivers/base/dd.c:596
__driver_probe_device+0x338/0x4d0 drivers/base/dd.c:751
driver_probe_device+0x4c/0x1a0 drivers/base/dd.c:781
__device_attach_driver+0x20b/0x2f0 drivers/base/dd.c:898
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:427
__device_attach+0x228/0x4a0 drivers/base/dd.c:969
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:487
device_add+0xc17/0x1ee0 drivers/base/core.c:3394
usb_set_configuration+0x101e/0x1900 drivers/usb/core/message.c:2170

usb_generic_driver_probe+0xba/0x100 drivers/usb/core/generic.c:238
usb_probe_device+0xd9/0x2c0 drivers/usb/core/driver.c:293

call_driver_probe drivers/base/dd.c:517 [inline]
really_probe+0x245/0xcc0 drivers/base/dd.c:596
__driver_probe_device+0x338/0x4d0 drivers/base/dd.c:751
driver_probe_device+0x4c/0x1a0 drivers/base/dd.c:781
__device_attach_driver+0x20b/0x2f0 drivers/base/dd.c:898
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:427
__device_attach+0x228/0x4a0 drivers/base/dd.c:969
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:487
device_add+0xc17/0x1ee0 drivers/base/core.c:3394
usb_new_device.cold+0x63f/0x108e drivers/usb/core/hub.c:2563
hub_port_connect drivers/usb/core/hub.c:5348 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5488 [inline]
port_event drivers/usb/core/hub.c:5634 [inline]
hub_event+0x2357/0x4330 drivers/usb/core/hub.c:5716
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2297
worker_thread+0x658/0x11f0 kernel/workqueue.c:2444
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
INFO: task kworker/1:3:6898 blocked for more than 143 seconds.
Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

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

task:kworker/1:3 state:D stack:25968 pid: 6898 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:

<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_timeout+0x1db/0x2a0 kernel/time/timer.c:1857

do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common kernel/sched/completion.c:106 [inline]
wait_for_common kernel/sched/completion.c:117 [inline]

wait_for_completion+0x174/0x270 kernel/sched/completion.c:138
port100_send_cmd_sync drivers/nfc/port100.c:926 [inline]
port100_get_command_type_mask drivers/nfc/port100.c:1011 [inline]
port100_probe+0x9ec/0x1320 drivers/nfc/port100.c:1557
usb_probe_interface+0x315/0x7f0 drivers/usb/core/driver.c:396
call_driver_probe drivers/base/dd.c:517 [inline]
really_probe+0x245/0xcc0 drivers/base/dd.c:596
__driver_probe_device+0x338/0x4d0 drivers/base/dd.c:751
driver_probe_device+0x4c/0x1a0 drivers/base/dd.c:781
__device_attach_driver+0x20b/0x2f0 drivers/base/dd.c:898
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:427
__device_attach+0x228/0x4a0 drivers/base/dd.c:969
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:487
device_add+0xc17/0x1ee0 drivers/base/core.c:3394
usb_set_configuration+0x101e/0x1900 drivers/usb/core/message.c:2170

usb_generic_driver_probe+0xba/0x100 drivers/usb/core/generic.c:238
usb_probe_device+0xd9/0x2c0 drivers/usb/core/driver.c:293

call_driver_probe drivers/base/dd.c:517 [inline]
really_probe+0x245/0xcc0 drivers/base/dd.c:596
__driver_probe_device+0x338/0x4d0 drivers/base/dd.c:751
driver_probe_device+0x4c/0x1a0 drivers/base/dd.c:781
__device_attach_driver+0x20b/0x2f0 drivers/base/dd.c:898
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:427
__device_attach+0x228/0x4a0 drivers/base/dd.c:969
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:487
device_add+0xc17/0x1ee0 drivers/base/core.c:3394
usb_new_device.cold+0x63f/0x108e drivers/usb/core/hub.c:2563
hub_port_connect drivers/usb/core/hub.c:5348 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5488 [inline]
port_event drivers/usb/core/hub.c:5634 [inline]
hub_event+0x2357/0x4330 drivers/usb/core/hub.c:5716
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2297
worker_thread+0x658/0x11f0 kernel/workqueue.c:2444
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
INFO: task kworker/1:5:6900 blocked for more than 144 seconds.
Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

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

task:kworker/1:5 state:D stack:26024 pid: 6900 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:

<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_timeout+0x1db/0x2a0 kernel/time/timer.c:1857

do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common kernel/sched/completion.c:106 [inline]
wait_for_common kernel/sched/completion.c:117 [inline]

wait_for_completion+0x174/0x270 kernel/sched/completion.c:138
port100_send_cmd_sync drivers/nfc/port100.c:926 [inline]
port100_get_command_type_mask drivers/nfc/port100.c:1011 [inline]
port100_probe+0x9ec/0x1320 drivers/nfc/port100.c:1557
usb_probe_interface+0x315/0x7f0 drivers/usb/core/driver.c:396
call_driver_probe drivers/base/dd.c:517 [inline]
really_probe+0x245/0xcc0 drivers/base/dd.c:596
__driver_probe_device+0x338/0x4d0 drivers/base/dd.c:751
driver_probe_device+0x4c/0x1a0 drivers/base/dd.c:781
__device_attach_driver+0x20b/0x2f0 drivers/base/dd.c:898
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:427
__device_attach+0x228/0x4a0 drivers/base/dd.c:969
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:487
device_add+0xc17/0x1ee0 drivers/base/core.c:3394
usb_set_configuration+0x101e/0x1900 drivers/usb/core/message.c:2170

usb_generic_driver_probe+0xba/0x100 drivers/usb/core/generic.c:238
usb_probe_device+0xd9/0x2c0 drivers/usb/core/driver.c:293

call_driver_probe drivers/base/dd.c:517 [inline]
really_probe+0x245/0xcc0 drivers/base/dd.c:596
__driver_probe_device+0x338/0x4d0 drivers/base/dd.c:751
driver_probe_device+0x4c/0x1a0 drivers/base/dd.c:781
__device_attach_driver+0x20b/0x2f0 drivers/base/dd.c:898
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:427
__device_attach+0x228/0x4a0 drivers/base/dd.c:969
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:487
device_add+0xc17/0x1ee0 drivers/base/core.c:3394
usb_new_device.cold+0x63f/0x108e drivers/usb/core/hub.c:2563
hub_port_connect drivers/usb/core/hub.c:5348 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5488 [inline]
port_event drivers/usb/core/hub.c:5634 [inline]
hub_event+0x2357/0x4330 drivers/usb/core/hub.c:5716
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2297
worker_thread+0x658/0x11f0 kernel/workqueue.c:2444
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
INFO: task kworker/0:5:8996 blocked for more than 144 seconds.
Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

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

task:kworker/0:5 state:D stack:26024 pid: 8996 ppid: 2 flags:0x00004000

Workqueue: usb_hub_wq hub_event
Call Trace:

<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_timeout+0x1db/0x2a0 kernel/time/timer.c:1857

do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common kernel/sched/completion.c:106 [inline]
wait_for_common kernel/sched/completion.c:117 [inline]

wait_for_completion+0x174/0x270 kernel/sched/completion.c:138
port100_send_cmd_sync drivers/nfc/port100.c:926 [inline]
port100_get_command_type_mask drivers/nfc/port100.c:1011 [inline]
port100_probe+0x9ec/0x1320 drivers/nfc/port100.c:1557
usb_probe_interface+0x315/0x7f0 drivers/usb/core/driver.c:396
call_driver_probe drivers/base/dd.c:517 [inline]
really_probe+0x245/0xcc0 drivers/base/dd.c:596
__driver_probe_device+0x338/0x4d0 drivers/base/dd.c:751
driver_probe_device+0x4c/0x1a0 drivers/base/dd.c:781
__device_attach_driver+0x20b/0x2f0 drivers/base/dd.c:898
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:427
__device_attach+0x228/0x4a0 drivers/base/dd.c:969
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:487
device_add+0xc17/0x1ee0 drivers/base/core.c:3394
usb_set_configuration+0x101e/0x1900 drivers/usb/core/message.c:2170

usb_generic_driver_probe+0xba/0x100 drivers/usb/core/generic.c:238
usb_probe_device+0xd9/0x2c0 drivers/usb/core/driver.c:293

call_driver_probe drivers/base/dd.c:517 [inline]
really_probe+0x245/0xcc0 drivers/base/dd.c:596
__driver_probe_device+0x338/0x4d0 drivers/base/dd.c:751
driver_probe_device+0x4c/0x1a0 drivers/base/dd.c:781
__device_attach_driver+0x20b/0x2f0 drivers/base/dd.c:898
bus_for_each_drv+0x15f/0x1e0 drivers/base/bus.c:427
__device_attach+0x228/0x4a0 drivers/base/dd.c:969
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:487
device_add+0xc17/0x1ee0 drivers/base/core.c:3394
usb_new_device.cold+0x63f/0x108e drivers/usb/core/hub.c:2563
hub_port_connect drivers/usb/core/hub.c:5348 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5488 [inline]
port_event drivers/usb/core/hub.c:5634 [inline]
hub_event+0x2357/0x4330 drivers/usb/core/hub.c:5716
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2297
worker_thread+0x658/0x11f0 kernel/workqueue.c:2444
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
INFO: task syz-executor.3:9098 can't die for more than 145 seconds.
task:syz-executor.3 state:D stack:27504 pid: 9098 ppid: 7066 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007fa4ca981040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>
INFO: task syz-executor.3:9098 blocked for more than 145 seconds.
Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

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

task:syz-executor.3 state:D stack:27504 pid: 9098 ppid: 7066 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007fa4ca981040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>
INFO: task syz-executor.3:9204 can't die for more than 145 seconds.
task:syz-executor.3 state:D stack:28472 pid: 9204 ppid: 7066 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007fa4ca960040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>
INFO: task syz-executor.3:9204 blocked for more than 146 seconds.
Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

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

task:syz-executor.3 state:D stack:28472 pid: 9204 ppid: 7066 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007fa4ca960040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:9110 can't die for more than 146 seconds.
task:syz-executor.5 state:D stack:27504 pid: 9110 ppid: 7068 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9
RSP: 002b:00007f2f88794188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80
R13: 00007ffd2244d6bf R14: 00007f2f88794300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:9110 blocked for more than 146 seconds.
Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

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

task:syz-executor.5 state:D stack:27504 pid: 9110 ppid: 7068 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9
RSP: 002b:00007f2f88794188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80
R13: 00007ffd2244d6bf R14: 00007f2f88794300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:9205 can't die for more than 147 seconds.
task:syz-executor.5 state:D stack:28472 pid: 9205 ppid: 7068 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007f2f88771040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:9205 blocked for more than 147 seconds.
Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

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

task:syz-executor.5 state:D stack:28472 pid: 9205 ppid: 7068 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007f2f88771040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:9206 can't die for more than 147 seconds.
task:syz-executor.5 state:D stack:28472 pid: 9206 ppid: 7068 flags:0x00004004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007f2f88750040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:9206 blocked for more than 148 seconds.
Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

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

task:syz-executor.5 state:D stack:28472 pid: 9206 ppid: 7068 flags:0x00004004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007f2f88750040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>
INFO: task syz-executor.2:9150 can't die for more than 148 seconds.
task:syz-executor.2 state:D stack:27504 pid: 9150 ppid: 7062 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007fd0d4732040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>
INFO: task syz-executor.2:9150 blocked for more than 148 seconds.
Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

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

task:syz-executor.2 state:D stack:27504 pid: 9150 ppid: 7062 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007fd0d4732040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>
INFO: task syz-executor.1:9168 can't die for more than 149 seconds.
task:syz-executor.1 state:D stack:27504 pid: 9168 ppid: 7070 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007f43ea1d1040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>
INFO: task syz-executor.4:9167 can't die for more than 149 seconds.
task:syz-executor.4 state:D stack:27504 pid: 9167 ppid: 7064 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007fe4c2ac8040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>
INFO: task syz-executor.0:9174 can't die for more than 149 seconds.
task:syz-executor.0 state:D stack:27504 pid: 9174 ppid: 7069 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732

misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414

do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4
RSP: 002b:00007efca25eb040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

Showing all locks held in the system:

1 lock held by khungtaskd/27:
#0: ffffffff8bb81ae0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6458
5 locks held by kworker/0:4/2934:
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2268
#1: ffffc9000ad57db0 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2272
#2: ffff88801cd27220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#2: ffff88801cd27220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5662
#3: ffff888018bde220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#3: ffff888018bde220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
#4: ffff8880188241a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#4: ffff8880188241a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
1 lock held by in:imklog/6245:
5 locks held by kworker/1:3/6898:
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2268
#1: ffffc90004127db0 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2272
#2: ffff88814773f220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#2: ffff88814773f220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5662
#3: ffff88823bd36220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#3: ffff88823bd36220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
#4: ffff88806ce1f1a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#4: ffff88806ce1f1a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
5 locks held by kworker/1:5/6900:
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2268
#1: ffffc900046f7db0 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2272
#2: ffff888147767220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#2: ffff888147767220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5662
#3: ffff88805efed220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#3: ffff88805efed220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
#4: ffff888018cfb1a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#4: ffff888018cfb1a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
5 locks held by kworker/0:5/8996:
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
#0: ffff888144791138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2268
#1: ffffc9000cd17db0 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2272
#2: ffff88801cc13220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#2: ffff88801cc13220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5662
#3: ffff8880779fa220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#3: ffff8880779fa220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
#4: ffff88801b7021a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#4: ffff88801b7021a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
2 locks held by syz-executor.3/9094:
#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
#1: ffffffff8ba51468 (system_transition_mutex){+.+.}-{3:3}, at: snapshot_open+0x3b/0x2a0 kernel/power/user.c:54
1 lock held by syz-executor.3/9098:
#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor.3/9204:
#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor.5/9110:
#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor.5/9205:
#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor.5/9206:
#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor.2/9150:
#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor.1/9168:
#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor.4/9167:
#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor.0/9174:
#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

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

NMI backtrace for cpu 1

CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:

<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:105
nmi_trigger_cpumask_backtrace+0x1ae/0x220 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:254 [inline]
watchdog+0xcb7/0xed0 kernel/hung_task.c:339
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>

Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0

CPU: 0 PID: 790 Comm: kworker/u4:4 Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011

Workqueue: events_unbound toggle_allocation_gate
RIP: 0010:insn_get_prefixes.part.0+0x601/0x1200 arch/x86/lib/insn.c:180
Code: 89 ea 48 c1 ea 03 0f b6 04 02 48 89 ea 83 e2 07 38 d0 7f 08 84 c0 0f 85 8b 0b 00 00 48 8b 04 24 48 8b 54 24 18 44 0f b6 70 53 <48> b8 00 00 00 00 00 fc ff df 48 c1 ea 03 80 3c 02 00 0f 85 7c 0a
RSP: 0018:ffffc90003e77928 EFLAGS: 00000246
RAX: ffffc90003e77a80 RBX: 00000000ffffffff RCX: 0000000000000000
RDX: ffffc90003e77ae8 RSI: ffffffff840d3094 RDI: 0000000000000003
RBP: ffffc90003e77ad3 R08: 000000000000000a R09: 000000000000000b
R10: ffffffff840d2d79 R11: 000000000000001f R12: 0000000000000000
R13: 000000000000000f R14: 0000000000000001 R15: 000000000000001f
FS: 0000000000000000(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000

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

CR2: 00007fdbf5e50020 CR3: 000000000b88e000 CR4: 00000000003506f0

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

<TASK>
insn_get_prefixes arch/x86/lib/insn.c:131 [inline]
insn_get_opcode arch/x86/lib/insn.c:272 [inline]
insn_get_modrm+0x646/0x7c0 arch/x86/lib/insn.c:343
insn_get_sib+0x29c/0x330 arch/x86/lib/insn.c:421
insn_get_displacement+0x346/0x6c0 arch/x86/lib/insn.c:464
insn_get_immediate arch/x86/lib/insn.c:632 [inline]
insn_get_length arch/x86/lib/insn.c:707 [inline]
insn_decode+0x473/0x4e0 arch/x86/lib/insn.c:747
text_poke_loc_init+0xa3/0x340 arch/x86/kernel/alternative.c:1204
arch_jump_label_transform_queue+0x94/0x100 arch/x86/kernel/jump_label.c:138
__jump_label_update+0x12e/0x400 kernel/jump_label.c:451
jump_label_update+0x1d5/0x430 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:745 [inline]
toggle_allocation_gate+0x183/0x390 mm/kfence/core.c:723
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2297
worker_thread+0x658/0x11f0 kernel/workqueue.c:2444
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
----------------
Code disassembly (best guess):
0: 89 ea mov %ebp,%edx
2: 48 c1 ea 03 shr $0x3,%rdx
6: 0f b6 04 02 movzbl (%rdx,%rax,1),%eax
a: 48 89 ea mov %rbp,%rdx
d: 83 e2 07 and $0x7,%edx
10: 38 d0 cmp %dl,%al
12: 7f 08 jg 0x1c
14: 84 c0 test %al,%al
16: 0f 85 8b 0b 00 00 jne 0xba7
1c: 48 8b 04 24 mov (%rsp),%rax
20: 48 8b 54 24 18 mov 0x18(%rsp),%rdx
25: 44 0f b6 70 53 movzbl 0x53(%rax),%r14d
* 2a: 48 b8 00 00 00 00 00 movabs $0xdffffc0000000000,%rax <-- trapping instruction
31: fc ff df
34: 48 c1 ea 03 shr $0x3,%rdx
38: 80 3c 02 00 cmpb $0x0,(%rdx,%rax,1)
3c: 0f .byte 0xf
3d: 85 .byte 0x85
3e: 7c 0a jl 0x4a


Tested on:

commit: 27078b06 nfc: port100: fix using -ERRNO as command typ..
git tree: https://github.com/krzk/linux.git n/nfc-port100-cmd-mask
console output: https://syzkaller.appspot.com/x/log.txt?x=16ce8172b00000
kernel config: https://syzkaller.appspot.com/x/.config?x=f125c5a9265365ae
dashboard link: https://syzkaller.appspot.com/bug?extid=abd2e0dafb481b621869
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2

[syzbot]

Hello,

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

INFO: task kworker/0:0:5 blocked for more than 143 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/0:0 state:D stack:25584 pid: 5 ppid: 2 flags:0x00004000

INFO: task kworker/0:4:6881 blocked for more than 143 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/0:4 state:D stack:24936 pid: 6881 ppid: 2 flags:0x00004000

INFO: task syz-executor.5:9148 can't die for more than 144 seconds.
task:syz-executor.5 state:D stack:27504 pid: 9148 ppid: 7048 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9

RSP: 002b:00007f4250169188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80

R13: 00007fff96f1772f R14: 00007f4250169300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:9148 blocked for more than 144 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.5 state:D stack:27504 pid: 9148 ppid: 7048 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9

RSP: 002b:00007f4250169188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80

R13: 00007fff96f1772f R14: 00007f4250169300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:9235 can't die for more than 144 seconds.
task:syz-executor.5 state:D stack:28472 pid: 9235 ppid: 7048 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f4250125040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002

R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.5:9235 blocked for more than 145 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.5 state:D stack:28472 pid: 9235 ppid: 7048 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f4250125040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002

R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.5:9236 can't die for more than 145 seconds.
task:syz-executor.5 state:D stack:28472 pid: 9236 ppid: 7048 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f4250104040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c1a8 RCX: 00000000004196d4

RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.5:9236 blocked for more than 145 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.5 state:D stack:28472 pid: 9236 ppid: 7048 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f4250104040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c1a8 RCX: 00000000004196d4

RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.1:9225 can't die for more than 146 seconds.
task:syz-executor.1 state:D stack:28472 pid: 9225 ppid: 7046 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f8ef3218040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002

R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.1:9225 blocked for more than 146 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.1 state:D stack:28472 pid: 9225 ppid: 7046 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f8ef3218040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002

R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.1:9226 can't die for more than 146 seconds.
task:syz-executor.1 state:D stack:28472 pid: 9226 ppid: 7046 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f8ef31f7040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c1a8 RCX: 00000000004196d4

RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.1:9226 blocked for more than 147 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.1 state:D stack:28472 pid: 9226 ppid: 7046 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f8ef31f7040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000000000056c1a8 RCX: 00000000004196d4

RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.3:9159 can't die for more than 147 seconds.
task:syz-executor.3 state:D stack:27504 pid: 9159 ppid: 7049 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9

RSP: 002b:00007fa580757188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80

R13: 00007ffef0f616cf R14: 00007fa580757300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.3:9159 blocked for more than 147 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.3 state:D stack:27504 pid: 9159 ppid: 7049 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9

RSP: 002b:00007fa580757188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80

R13: 00007ffef0f616cf R14: 00007fa580757300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.3:9231 can't die for more than 147 seconds.
task:syz-executor.3 state:D stack:28472 pid: 9231 ppid: 7049 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fa580734040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.3:9231 blocked for more than 148 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.3 state:D stack:28472 pid: 9231 ppid: 7049 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fa580734040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.3:9232 can't die for more than 148 seconds.
task:syz-executor.3 state:D stack:28472 pid: 9232 ppid: 7049 flags:0x00004004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fa580713040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.3:9232 blocked for more than 148 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.3 state:D stack:28472 pid: 9232 ppid: 7049 flags:0x00004004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fa580713040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.4:9168 can't die for more than 149 seconds.
task:syz-executor.4 state:D stack:27504 pid: 9168 ppid: 7050 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9

RSP: 002b:00007f2c14c6d188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80

R13: 00007ffef402811f R14: 00007f2c14c6d300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.4:9171 can't die for more than 149 seconds.
task:syz-executor.4 state:D stack:27504 pid: 9171 ppid: 7050 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f2c14c4a040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.4:9233 can't die for more than 149 seconds.
task:syz-executor.4 state:D stack:28472 pid: 9233 ppid: 7050 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f2c14c29040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.0:9178 can't die for more than 150 seconds.
task:syz-executor.0 state:D stack:28472 pid: 9178 ppid: 7047 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f9eac87b040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.2:9212 can't die for more than 150 seconds.
task:syz-executor.2 state:D stack:28472 pid: 9212 ppid: 7045 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f047ac9e040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

Showing all locks held in the system:

5 locks held by kworker/0:0/5:
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2268
#1: ffffc90000ca7db0 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2272
#2: ffff8881479d1220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#2: ffff8881479d1220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5662
#3: ffff88807bddd220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#3: ffff88807bddd220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
#4: ffff8880694bd1a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#4: ffff8880694bd1a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
2 locks held by kworker/u4:1/10:

1 lock held by khungtaskd/27:
#0: ffffffff8bb81ae0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6458

1 lock held by in:imklog/6246:
#0: ffff88801d138d70 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:990
5 locks held by kworker/0:4/6881:
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
#0: ffff888013385138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2268
#1: ffffc9000464fdb0 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2272
#2: ffff88801ced5220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#2: ffff88801ced5220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5662
#3: ffff888015d72220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#3: ffff888015d72220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
#4: ffff8880799b81a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#4: ffff8880799b81a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
1 lock held by syz-executor.5/9148:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.5/9235:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.5/9236:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

2 locks held by syz-executor.1/9158:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
#1: ffffffff8ba51468 (system_transition_mutex){+.+.}-{3:3}, at: snapshot_open+0x3b/0x2a0 kernel/power/user.c:54

1 lock held by syz-executor.1/9225:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.1/9226:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.3/9159:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.3/9231:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.3/9232:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.4/9168:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
1 lock held by syz-executor.4/9171:
#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.4/9233:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.0/9178:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.2/9212:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

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

NMI backtrace for cpu 1
CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:105
nmi_trigger_cpumask_backtrace+0x1ae/0x220 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:254 [inline]
watchdog+0xcb7/0xed0 kernel/hung_task.c:339
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0

CPU: 0 PID: 2956 Comm: systemd-journal Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011

RIP: 0010:lockdep_hardirqs_off+0x3b/0xd0 kernel/locking/lockdep.c:4384
Code: eb 95 b4 76 a9 00 00 f0 00 55 53 48 89 fb 74 49 8b 15 d9 be fb 06 85 d2 74 0e 65 8b 05 2a 9d b4 76 85 c0 75 4e 5b 5d c3 9c 58 <f6> c4 02 74 eb e8 fb d4 86 fa 85 c0 74 ed 8b 05 99 81 42 04 85 c0
RSP: 0018:ffffc9000b6af958 EFLAGS: 00000046
RAX: 0000000000000046 RBX: ffffffff81cbd09c RCX: 0000000000000001
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: ffffc9000b6afa88 R08: 0000000000000000 R09: ffff888016f284d8
R10: ffffffff81cbcb64 R11: 0000000000000000 R12: 0000000000000200
R13: ffff888016f285f0 R14: 0000000000010000 R15: ffff888016f285e0
FS: 00007f45378af8c0(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000

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

CR2: 00007f4534db3000 CR3: 000000007be1f000 CR4: 00000000003506f0

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

trace_hardirqs_off+0x13/0x1b0 kernel/trace/trace_preemptirq.c:76
seqcount_lockdep_reader_access include/linux/seqlock.h:102 [inline]
__follow_mount_rcu fs/namei.c:1455 [inline]
handle_mounts fs/namei.c:1486 [inline]
step_into+0x140c/0x1c80 fs/namei.c:1800
walk_component+0x171/0x6a0 fs/namei.c:1976
link_path_walk.part.0+0x757/0xd00 fs/namei.c:2297
link_path_walk fs/namei.c:2221 [inline]
path_lookupat+0xc8/0x860 fs/namei.c:2448
filename_lookup+0x1c6/0x590 fs/namei.c:2478
user_path_at_empty+0x42/0x60 fs/namei.c:2801
user_path_at include/linux/namei.h:57 [inline]
do_faccessat+0x127/0x850 fs/open.c:421

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:0x7f4536b6a9c7
Code: 83 c4 08 48 3d 01 f0 ff ff 73 01 c3 48 8b 0d c8 d4 2b 00 f7 d8 64 89 01 48 83 c8 ff c3 66 0f 1f 44 00 00 b8 15 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d a1 d4 2b 00 f7 d8 64 89 01 48
RSP: 002b:00007ffd652623a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000015
RAX: ffffffffffffffda RBX: 00007ffd652652c0 RCX: 00007f4536b6a9c7
RDX: 00007f45375dba00 RSI: 0000000000000000 RDI: 00005588c95379a3
RBP: 00007ffd652623e0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000069 R11: 0000000000000246 R12: 0000000000000000
R13: 0000000000000000 R14: 00007ffd652652c0 R15: 00007ffd652628d0

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

0: eb 95 jmp 0xffffff97
2: b4 76 mov $0x76,%ah
4: a9 00 00 f0 00 test $0xf00000,%eax
9: 55 push %rbp
a: 53 push %rbx
b: 48 89 fb mov %rdi,%rbx
e: 74 49 je 0x59
10: 8b 15 d9 be fb 06 mov 0x6fbbed9(%rip),%edx # 0x6fbbeef
16: 85 d2 test %edx,%edx
18: 74 0e je 0x28
1a: 65 8b 05 2a 9d b4 76 mov %gs:0x76b49d2a(%rip),%eax # 0x76b49d4b
21: 85 c0 test %eax,%eax
23: 75 4e jne 0x73
25: 5b pop %rbx
26: 5d pop %rbp
27: c3 retq
28: 9c pushfq
29: 58 pop %rax
* 2a: f6 c4 02 test $0x2,%ah <-- trapping instruction
2d: 74 eb je 0x1a
2f: e8 fb d4 86 fa callq 0xfa86d52f
34: 85 c0 test %eax,%eax
36: 74 ed je 0x25
38: 8b 05 99 81 42 04 mov 0x4428199(%rip),%eax # 0x44281d7
3e: 85 c0 test %eax,%eax

Tested on:

commit: 27078b06 nfc: port100: fix using -ERRNO as command typ..
git tree: https://github.com/krzk/linux.git

console output: https://syzkaller.appspot.com/x/log.txt?x=179457c4b00000

[syzbot]

Hello,

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

INFO: task kworker/1:3:2934 blocked for more than 143 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:kworker/1:3 state:D stack:26280 pid: 2934 ppid: 2 flags:0x00004000

INFO: task kworker/0:6:9012 blocked for more than 143 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

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

INFO: task syz-executor.5:9256 can't die for more than 144 seconds.
task:syz-executor.5 state:D stack:28392 pid: 9256 ppid: 7054 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9

RSP: 002b:00007f8547bf6188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80

R13: 00007fff4fd112ff R14: 00007f8547bf6300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:9256 blocked for more than 144 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.5 state:D stack:28392 pid: 9256 ppid: 7054 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9

RSP: 002b:00007f8547bf6188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80

R13: 00007fff4fd112ff R14: 00007f8547bf6300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.5:9357 can't die for more than 144 seconds.
task:syz-executor.5 state:D stack:28392 pid: 9357 ppid: 7054 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f8547bd3040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.5:9357 blocked for more than 145 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.5 state:D stack:28392 pid: 9357 ppid: 7054 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f8547bd3040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.5:9358 can't die for more than 145 seconds.
task:syz-executor.5 state:D stack:28472 pid: 9358 ppid: 7054 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f8547bb2040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.5:9358 blocked for more than 145 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.5 state:D stack:28472 pid: 9358 ppid: 7054 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f8547bb2040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.4:9351 can't die for more than 146 seconds.
task:syz-executor.4 state:D stack:28472 pid: 9351 ppid: 7055 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fc343c35040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.4:9351 blocked for more than 146 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.4 state:D stack:28472 pid: 9351 ppid: 7055 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fc343c35040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.4:9352 can't die for more than 146 seconds.
task:syz-executor.4 state:D stack:28472 pid: 9352 ppid: 7055 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fc343c14040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.4:9352 blocked for more than 147 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.4 state:D stack:28472 pid: 9352 ppid: 7055 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fc343c14040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c0f0 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.2:9293 can't die for more than 147 seconds.
task:syz-executor.2 state:D stack:28392 pid: 9293 ppid: 7053 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fb327009040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.2:9293 blocked for more than 147 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.2 state:D stack:28392 pid: 9293 ppid: 7053 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fb327009040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.0:9296 can't die for more than 147 seconds.
task:syz-executor.0 state:D stack:28472 pid: 9296 ppid: 7051 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fe934f62040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.0:9296 blocked for more than 148 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.0 state:D stack:28472 pid: 9296 ppid: 7051 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fe934f62040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 00000000200000c0 R15: 0000000000022000
</TASK>

INFO: task syz-executor.1:9347 can't die for more than 148 seconds.
task:syz-executor.1 state:D stack:28232 pid: 9347 ppid: 7056 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9

RSP: 002b:00007f2f1f013188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80

R13: 00007ffe60dd867f R14: 00007f2f1f013300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.1:9347 blocked for more than 148 seconds.

Not tainted 5.15.0-rc5-next-20211018-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

task:syz-executor.1 state:D stack:28232 pid: 9347 ppid: 7056 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9

RSP: 002b:00007f2f1f013188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80

R13: 00007ffe60dd867f R14: 00007f2f1f013300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.1:9350 can't die for more than 149 seconds.
task:syz-executor.1 state:D stack:28392 pid: 9350 ppid: 7056 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007f2f1eff0040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

INFO: task syz-executor.3:9349 can't die for more than 149 seconds.
task:syz-executor.3 state:D stack:28472 pid: 9349 ppid: 7052 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4665e9

RSP: 002b:00007fa3c3cfa188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665e9
RDX: 0000000000020601 RSI: 00000000200003c0 RDI: ffffffffffffff9c
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80

R13: 00007fff01b8869f R14: 00007fa3c3cfa300 R15: 0000000000022000
</TASK>
INFO: task syz-executor.3:9355 can't die for more than 149 seconds.
task:syz-executor.3 state:D stack:28392 pid: 9355 ppid: 7052 flags:0x00000004

Call Trace:
<TASK>
context_switch kernel/sched/core.c:4965 [inline]
__schedule+0x940/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6378
__mutex_lock_common kernel/locking/mutex.c:672 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:732
misc_open+0x55/0x4a0 drivers/char/misc.c:107
chrdev_open+0x266/0x770 fs/char_dev.c:414
do_dentry_open+0x4c8/0x11d0 fs/open.c:822
do_open fs/namei.c:3428 [inline]
path_openat+0x1c9a/0x2740 fs/namei.c:3561
do_filp_open+0x1aa/0x400 fs/namei.c:3588
do_sys_openat2+0x16d/0x4d0 fs/open.c:1200
do_sys_open fs/open.c:1216 [inline]
__do_sys_openat fs/open.c:1232 [inline]
__se_sys_openat fs/open.c:1227 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1227
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:0x4196d4

RSP: 002b:00007fa3c3cd7040 EFLAGS: 00000293 ORIG_RAX: 0000000000000101

RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004196d4
RDX: 0000000000000002 RSI: 00000000004beaa1 RDI: 00000000ffffff9c
RBP: 00000000004beaa1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000002
R13: 0000000000000000 R14: 0000000020000140 R15: 0000000000022000
</TASK>

Showing all locks held in the system:

1 lock held by khungtaskd/26:

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

5 locks held by kworker/1:3/2934:
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2268
#1: ffffc9000bddfdb0 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2272
#2: ffff88814792d220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#2: ffff88814792d220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5662
#3: ffff88801e918220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#3: ffff88801e918220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
#4: ffff88807e7951a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#4: ffff88807e7951a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
2 locks held by in:imklog/6247:
5 locks held by kworker/0:6/9012:
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline]
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline]
#0: ffff888012784938 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2268
#1: ffffc9000cb5fdb0 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2272
#2: ffff8881478b5220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#2: ffff8881478b5220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4330 drivers/usb/core/hub.c:5662
#3: ffff88801e7f1220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#3: ffff88801e7f1220 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
#4: ffff88807db881a8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#4: ffff88807db881a8 (&dev->mutex){....}-{3:3}, at: __device_attach+0x7a/0x4a0 drivers/base/dd.c:944
1 lock held by syz-executor.5/9256:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.5/9357:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.5/9358:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

2 locks held by syz-executor.4/9264:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107
#1: ffffffff8ba51468 (system_transition_mutex){+.+.}-{3:3}, at: snapshot_open+0x3b/0x2a0 kernel/power/user.c:54

1 lock held by syz-executor.4/9351:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.4/9352:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.2/9293:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.0/9296:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.1/9347:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.1/9350:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.3/9349:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

1 lock held by syz-executor.3/9355:

#0: ffffffff8c5d8208 (misc_mtx){+.+.}-{3:3}, at: misc_open+0x55/0x4a0 drivers/char/misc.c:107

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

NMI backtrace for cpu 0
CPU: 0 PID: 26 Comm: khungtaskd Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:105
nmi_trigger_cpumask_backtrace+0x1ae/0x220 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:254 [inline]
watchdog+0xcb7/0xed0 kernel/hung_task.c:339
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>

Sending NMI from CPU 0 to CPUs 1:

NMI backtrace for cpu 1

CPU: 1 PID: 54 Comm: kworker/u4:3 Not tainted 5.15.0-rc5-next-20211018-syzkaller #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011

Workqueue: 0x0 (phy9)
RIP: 0010:check_wait_context kernel/locking/lockdep.c:4716 [inline]
RIP: 0010:__lock_acquire+0x56e/0x54a0 kernel/locking/lockdep.c:4977
Code: 00 41 89 f6 41 83 ee 01 0f 88 67 12 00 00 49 b8 00 00 00 00 00 fc ff df 49 63 c6 41 89 d7 48 8d 04 80 49 8d ac c5 49 0a 00 00 <eb> 12 41 83 ee 01 48 83 ed 28 41 83 fe ff 0f 84 15 0b 00 00 48 8d
RSP: 0018:ffffc90001a2f9f0 EFLAGS: 00000046
RAX: 0000000000000000 RBX: ffffffff8bb81ae0 RCX: 1ffff11002f214d4
RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffff8ff4dcd9
RBP: ffff88801790a6c9 R08: dffffc0000000000 R09: ffffffff8ff4b947
R10: fffffbfff1fe9728 R11: 0000000000000001 R12: ffff88801790a6d0
R13: ffff888017909c80 R14: 0000000000000000 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff8880b9d00000(0000) knlGS:0000000000000000

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

CR2: 00007f77a77af000 CR3: 000000000b88e000 CR4: 00000000003506e0

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

lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
rcu_lock_acquire include/linux/rcupdate.h:268 [inline]
rcu_read_lock include/linux/rcupdate.h:694 [inline]
cpuacct_account_field+0x34/0x280 kernel/sched/cpuacct.c:365
cgroup_account_cputime_field include/linux/cgroup.h:807 [inline]
task_group_account_field+0x3e/0x290 kernel/sched/cputime.c:110
account_system_index_time+0xec/0x120 kernel/sched/cputime.c:173
vtime_account_system+0x63/0xb0 kernel/sched/cputime.c:668
__vtime_account_kernel kernel/sched/cputime.c:690 [inline]
vtime_task_switch_generic+0xfa/0x5a0 kernel/sched/cputime.c:772
vtime_task_switch include/linux/vtime.h:95 [inline]
finish_task_switch.isra.0+0x4b5/0xa20 kernel/sched/core.c:4827
context_switch kernel/sched/core.c:4968 [inline]
__schedule+0x948/0x26f0 kernel/sched/core.c:6246
schedule+0xd2/0x260 kernel/sched/core.c:6319
worker_thread+0x15c/0x11f0 kernel/workqueue.c:2465

kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>

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

0: 00 41 89 add %al,-0x77(%rcx)
3: f6 41 83 ee testb $0xee,-0x7d(%rcx)
7: 01 0f add %ecx,(%rdi)
9: 88 67 12 mov %ah,0x12(%rdi)
c: 00 00 add %al,(%rax)
e: 49 b8 00 00 00 00 00 movabs $0xdffffc0000000000,%r8
15: fc ff df
18: 49 63 c6 movslq %r14d,%rax
1b: 41 89 d7 mov %edx,%r15d
1e: 48 8d 04 80 lea (%rax,%rax,4),%rax
22: 49 8d ac c5 49 0a 00 lea 0xa49(%r13,%rax,8),%rbp
29: 00
* 2a: eb 12 jmp 0x3e <-- trapping instruction
2c: 41 83 ee 01 sub $0x1,%r14d
30: 48 83 ed 28 sub $0x28,%rbp
34: 41 83 fe ff cmp $0xffffffff,%r14d
38: 0f 84 15 0b 00 00 je 0xb53
3e: 48 rex.W
3f: 8d .byte 0x8d

Tested on:

commit: 27078b06 nfc: port100: fix using -ERRNO as command typ..
git tree: https://github.com/krzk/linux.git

console output: https://syzkaller.appspot.com/x/log.txt?x=132567c2b00000

[Pavel Skripkin]

On 6/22/21 18:43, syzbot wrote:
> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit: fd0aa1a4 Merge tag 'for-linus' of git://git.kernel.org/pub..
> git tree: upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=13e1500c300000
> kernel config: https://syzkaller.appspot.com/x/.config?x=7ca96a2d153c74b0
> dashboard link: https://syzkaller.appspot.com/bug?extid=abd2e0dafb481b621869
> syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1792e284300000
> C reproducer: https://syzkaller.appspot.com/x/repro.c?x=13ad9d48300000
>

Hm, I can't reproduce this issue on top of my tree. Let's test my latest
port100 patch

[syzbot]

Hello,

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

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

Tested on:

commit: 330f4c53 ARM: fix build error when BPF_SYSCALL is disa..
git tree: upstream
kernel config: https://syzkaller.appspot.com/x/.config?x=16438642a37fea1
dashboard link: https://syzkaller.appspot.com/bug?extid=abd2e0dafb481b621869
compiler: Debian clang version 11.0.1-2, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=117d9781700000

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

[Hillf Danton]

On Tue, 22 Jun 2021 08:43:29 -0700

See if it can be reproduced 8 months later.

Hillf

[syzbot]

Hello,

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

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

Tested on:

commit: 1db333d9 Merge tag 'spi-fix-v5.17-rc7' of git://git.ke..

git tree: upstream
kernel config: https://syzkaller.appspot.com/x/.config?x=16438642a37fea1
dashboard link: https://syzkaller.appspot.com/bug?extid=abd2e0dafb481b621869
compiler: Debian clang version 11.0.1-2, GNU ld (GNU Binutils for Debian) 2.35.2

Note: no patches were applied.

[Hillf Danton]

On Thu, 10 Mar 2022 06:22:10 -0800

Given the failure of reproducing it upstream, wait for syzbot to bisect the
fix commit in spare cycles.

Hillf

[Pavel Skripkin]

Hi Hillf,

upstream branch already has my patch: see commit
f80cfe2f26581f188429c12bd937eb905ad3ac7b.

let's test previous commit to see if my really fixes this issue

#syz test:
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b




With regards,
Pavel Skripkin

[syzbot]

Hello,

syzbot tried to test the proposed patch but the build/boot failed:

failed to checkout kernel repo git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b: failed to run ["git" "fetch" "--force" "f569e972c8e9057ee9c286220c83a480ebf30cc5" "3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b"]: exit status 128
fatal: couldn't find remote ref 3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b



Tested on:

commit: [unknown
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git 3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b

dashboard link: https://syzkaller.appspot.com/bug?extid=abd2e0dafb481b621869
compiler:

[Pavel Skripkin]

On 3/11/22 22:18, syzbot wrote:
> Hello,
>
> syzbot tried to test the proposed patch but the build/boot failed:
>
> failed to checkout kernel repo git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b: failed to run ["git" "fetch" "--force" "f569e972c8e9057ee9c286220c83a480ebf30cc5" "3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b"]: exit status 128
> fatal: couldn't find remote ref 3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b
>

Em, looks like wrong format

#syz test:
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b




With regards,
Pavel Skripkin

[syzbot]

Hello,

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

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

Tested on:

commit: 3bf7edc8 Merge tag 'arm64-fixes' of git://git.kernel.o..
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel config: https://syzkaller.appspot.com/x/.config?x=16438642a37fea1
dashboard link: https://syzkaller.appspot.com/bug?extid=abd2e0dafb481b621869

compiler: Debian clang version 11.0.1-2, GNU ld (GNU Binutils for Debian) 2.35.2

Note: no patches were applied.

[Hillf Danton]

Hi Pavel,

On Fri, 11 Mar 2022 22:17:16 +0300 Pavel Skripkin wrote:
>
> Hi Hillf,
>
> On 3/11/22 08:37, Hillf Danton wrote:
> > On Thu, 10 Mar 2022 06:22:10 -0800
> >> Hello,
> >>
> >> syzbot has tested the proposed patch and the reproducer did not trigger any issue:
> >>
> >> Reported-and-tested-by: syzbot+abd2e0...@syzkaller.appspotmail.com
> >>
> >> Tested on:
> >>
> >> commit: 1db333d9 Merge tag 'spi-fix-v5.17-rc7' of git://git.ke..
> >> git tree: upstream
> >> kernel config: https://syzkaller.appspot.com/x/.config?x=16438642a37fea1
> >> dashboard link: https://syzkaller.appspot.com/bug?extid=abd2e0dafb481b621869
> >> compiler: Debian clang version 11.0.1-2, GNU ld (GNU Binutils for Debian) 2.35.2
> >>
> >> Note: no patches were applied.
> >> Note: testing is done by a robot and is best-effort only.
> >
> > Given the failure of reproducing it upstream, wait for syzbot to bisect the
> > fix commit in spare cycles.
> >
>
> upstream branch already has my patch: see commit
> f80cfe2f26581f188429c12bd937eb905ad3ac7b.
>

Thanks for your fix.

> let's test previous commit to see if my really fixes this issue
>
> #syz test:
> git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
> 3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b

Given the Reported-and-tested-by tag in syzbot's echo [1], can you try and
bisect the curing commit in your spare cycles?

Hillf

[1] https://lore.kernel.org/lkml/00000000000002...@google.com/

---<---

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

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

Tested on:

commit: 3bf7edc8 Merge tag 'arm64-fixes' of git://git.kernel.o..
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git

[Pavel Skripkin]

Hi Hillf,

On 3/12/22 03:56, Hillf Danton wrote:
>> upstream branch already has my patch: see commit
>> f80cfe2f26581f188429c12bd937eb905ad3ac7b.
>>
> Thanks for your fix.
>
>> let's test previous commit to see if my really fixes this issue
>>
>> #syz test:
>> git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
>> 3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b
>
> Given the Reported-and-tested-by tag in syzbot's echo [1], can you try and
> bisect the curing commit in your spare cycles?
>
> Hillf
>
> [1] https://lore.kernel.org/lkml/00000000000002...@google.com/
>

Hm, that's odd. Last hit was 4d09h ago and I don't see related patches
went it expect for mine.

Will try to bisect...

Also there is a chance, that reproducer is just unstable.



With regards,
Pavel Skripkin

[Hillf Danton]

On Sat, 12 Mar 2022 13:36:15 +0300 Pavel Skripkin wrote:
> On 3/12/22 03:56, Hillf Danton wrote:
> >> upstream branch already has my patch: see commit
> >> f80cfe2f26581f188429c12bd937eb905ad3ac7b.
> >>
> > Thanks for your fix.
> >
> >> let's test previous commit to see if my really fixes this issue
> >>
> >> #syz test:
> >> git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
> >> 3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b
> >
> > Given the Reported-and-tested-by tag in syzbot's echo [1], can you try and
> > bisect the curing commit in your spare cycles?
> >
> > Hillf
> >
> > [1] https://lore.kernel.org/lkml/00000000000002...@google.com/
> >
>
> Hm, that's odd. Last hit was 4d09h ago and I don't see related patches

Wonder if you mean it was reproduced four days ago by "Last hit was 4d09h ago".
If it was then can you share the splat? Anything different from the
syzbot report [2] on Tue, 22 Jun 2021?

Hillf

[2] https://lore.kernel.org/lkml/000000000000c6...@google.com/

[Pavel Skripkin]

Hi Hillf,

On 3/12/22 14:58, Hillf Danton wrote:
> On Sat, 12 Mar 2022 13:36:15 +0300 Pavel Skripkin wrote:
>> On 3/12/22 03:56, Hillf Danton wrote:
>> >> upstream branch already has my patch: see commit
>> >> f80cfe2f26581f188429c12bd937eb905ad3ac7b.
>> >>
>> > Thanks for your fix.
>> >
>> >> let's test previous commit to see if my really fixes this issue
>> >>
>> >> #syz test:
>> >> git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
>> >> 3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b3bf7edc84a9eb4007dd9a0cb8878a7e1d5ec6a3b
>> >
>> > Given the Reported-and-tested-by tag in syzbot's echo [1], can you try and
>> > bisect the curing commit in your spare cycles?
>> >
>> > Hillf
>> >
>> > [1] https://lore.kernel.org/lkml/00000000000002...@google.com/
>> >
>>
>> Hm, that's odd. Last hit was 4d09h ago and I don't see related patches
>
> Wonder if you mean it was reproduced four days ago by "Last hit was 4d09h ago".

Yes, exactly.

> If it was then can you share the splat? Anything different from the
> syzbot report [2] on Tue, 22 Jun 2021?
>

IIRC syzbot tests on top of newest updates. I.e. last time syzbot
reproduced this issue on top of v5.17-rc7 at least. So fix commit should
somewhere between v5.17-rc7..HEAD




With regards,
Pavel Skripkin