Hi,
We would like to report the following bug which has been found by our
modified version of syzkaller.
======================================================
description: INFO: task hung in __floppy_read_block_0
affected file: drivers/block/floppy.c
kernel version: 5.19-rc6
kernel commit: 32346491ddf24599decca06190ebca03ff9de7f8
git tree: upstream
kernel config: https://syzkaller.appspot.com/text?tag=KernelConfig&x=cd73026ceaed1402
crash reproducer: attached
======================================================
Crash log:
======================================================
INFO: task syz-executor.1:9482 blocked for more than 143 seconds.
Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1 state:D stack:27528 pid: 9482 ppid: 5005 flags:0x00004004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa76/0x5140 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_timeout+0x5e5/0x890 kernel/time/timer.c:1911
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+0x182/0x360 kernel/sched/completion.c:138
__floppy_read_block_0+0x1dd/0x290 drivers/block/floppy.c:4162
floppy_revalidate+0x74f/0xa90 drivers/block/floppy.c:4206
invalidate_drive+0xeb/0x120 drivers/block/floppy.c:3219
fd_locked_ioctl+0xac1/0x1720 drivers/block/floppy.c:3467
fd_ioctl+0x35/0x50 drivers/block/floppy.c:3574
blkdev_ioctl+0x36e/0x800 block/ioctl.c:614
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:870 [inline]
__se_sys_ioctl fs/ioctl.c:856 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:856
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7fa70548d4ed
RSP: 002b:00007fa706530be8 EFLAGS: 00000246
ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fa7055abf60 RCX: 00007fa70548d4ed
RDX: 0000000000000000 RSI: 0000000000000241 RDI: 0000000000000003
RBP: 00007fa7054f92e1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fff9363b3ef R14: 00007fa7055abf60 R15: 00007fa706530d80
</TASK>
INFO: task syz-executor.1:9490 blocked for more than 143 seconds.
Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1 state:D stack:28120 pid: 9490 ppid: 5005 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa76/0x5140 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
blkdev_get_by_dev block/bdev.c:814 [inline]
blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
blkdev_open+0x13c/0x2c0 block/fops.c:481
do_dentry_open+0x4a1/0x11f0 fs/open.c:848
do_open fs/namei.c:3520 [inline]
path_openat+0x1c51/0x2890 fs/namei.c:3653
do_filp_open+0x1c1/0x290 fs/namei.c:3680
do_sys_openat2+0x61b/0x990 fs/open.c:1278
do_sys_open+0xc3/0x140 fs/open.c:1294
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7fa70543caf4
RSP: 002b:00007fa70650f710 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007fa70543caf4
RDX: 0000000000000003 RSI: 00007fa70650f7b0 RDI: 00000000ffffff9c
RBP: 00007fa70650f7b0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000003
R13: 00007fff9363b3ef R14: 00007fa7055ac040 R15: 00007fa70650fd80
</TASK>
INFO: task syz-executor.1:9498 blocked for more than 143 seconds.
Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1 state:D stack:29272 pid: 9498 ppid: 5005 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa76/0x5140 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
blkdev_ioctl+0x36e/0x800 block/ioctl.c:614
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:870 [inline]
__se_sys_ioctl fs/ioctl.c:856 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:856
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7fa70548d4ed
RSP: 002b:00007fa703a8bbe8 EFLAGS: 00000246
ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fa7055ac120 RCX: 00007fa70548d4ed
RDX: 0000000000000000 RSI: 0000000000000246 RDI: 0000000000000003
RBP: 00007fa7054f92e1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fff9363b3ef R14: 00007fa7055ac120 R15: 00007fa703a8bd80
</TASK>
INFO: task syz-executor.1:9506 blocked for more than 143 seconds.
Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1 state:D
stack:29272 pid: 9506 ppid: 5005 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa76/0x5140 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
blkdev_ioctl+0x36e/0x800 block/ioctl.c:614
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:870 [inline]
__se_sys_ioctl fs/ioctl.c:856 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:856
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7fa70548d4ed
RSP: 002b:00007fa70386abe8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fa7055ac200 RCX: 00007fa70548d4ed
RDX: 0000000000000000 RSI: 0000000000000247 RDI: 0000000000000003
RBP: 00007fa7054f92e1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fff9363b3ef R14: 00007fa7055ac200 R15: 00007fa70386ad80
</TASK>
INFO: task syz-executor.1:9523 blocked for more than 143 seconds.
Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1 state:D
stack:28120 pid: 9523 ppid: 5005 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa76/0x5140 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
blkdev_get_by_dev block/bdev.c:814 [inline]
blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
blkdev_open+0x13c/0x2c0 block/fops.c:481
do_dentry_open+0x4a1/0x11f0 fs/open.c:848
do_open fs/namei.c:3520 [inline]
path_openat+0x1c51/0x2890 fs/namei.c:3653
do_filp_open+0x1c1/0x290 fs/namei.c:3680
do_sys_openat2+0x61b/0x990 fs/open.c:1278
do_sys_open+0xc3/0x140 fs/open.c:1294
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7fa70543caf4
RSP: 002b:00007fa703649710 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007fa70543caf4
RDX: 0000000000000003 RSI: 00007fa7036497b0 RDI: 00000000ffffff9c
RBP: 00007fa7036497b0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000003
R13: 00007fff9363b3ef R14: 00007fa7055ac2e0 R15: 00007fa703649d80
</TASK>
INFO: task syz-executor.1:9526 blocked for more than 143 seconds.
Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1 state:D stack:28120 pid: 9526 ppid: 5005 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa76/0x5140 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
blkdev_get_by_dev block/bdev.c:814 [inline]
blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
blkdev_open+0x13c/0x2c0 block/fops.c:481
do_dentry_open+0x4a1/0x11f0 fs/open.c:848
do_open fs/namei.c:3520 [inline]
path_openat+0x1c51/0x2890 fs/namei.c:3653
do_filp_open+0x1c1/0x290 fs/namei.c:3680
do_sys_openat2+0x61b/0x990 fs/open.c:1278
do_sys_open+0xc3/0x140 fs/open.c:1294
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7fa70543caf4
RSP: 002b:00007fa703428710 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007fa70543caf4
RDX: 0000000000000003 RSI: 00007fa7034287b0 RDI: 00000000ffffff9c
RBP: 00007fa7034287b0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000003
R13: 00007fff9363b3ef R14: 00007fa7055ac3c0 R15: 00007fa703428d80
</TASK>
INFO: task syz-executor.1:9537 blocked for more than 143 seconds.
Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1 state:D
stack:28584 pid: 9537 ppid: 5005 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa76/0x5140 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
blkdev_ioctl+0x36e/0x800 block/ioctl.c:614
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:870 [inline]
__se_sys_ioctl fs/ioctl.c:856 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:856
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7fa70548d4ed
RSP: 002b:00007fa703207be8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fa7055ac4a0 RCX: 00007fa70548d4ed
RDX: 0000000020000200 RSI: 0000000040200242 RDI: 0000000000000003
RBP: 00007fa7054f92e1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fff9363b3ef R14: 00007fa7055ac4a0 R15: 00007fa703207d80
</TASK>
INFO: task syz-executor.6:9486 blocked for more than 143 seconds.
Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.6 state:D stack:28120 pid: 9486 ppid: 6033 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa76/0x5140 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
floppy_open+0x7f/0xdb0 drivers/block/floppy.c:3994
blkdev_get_whole+0x99/0x260 block/bdev.c:673
blkdev_get_by_dev block/bdev.c:823 [inline]
blkdev_get_by_dev+0x4a8/0xae0 block/bdev.c:787
blkdev_open+0x13c/0x2c0 block/fops.c:481
do_dentry_open+0x4a1/0x11f0 fs/open.c:848
do_open fs/namei.c:3520 [inline]
path_openat+0x1c51/0x2890 fs/namei.c:3653
do_filp_open+0x1c1/0x290 fs/namei.c:3680
do_sys_openat2+0x61b/0x990 fs/open.c:1278
do_sys_open+0xc3/0x140 fs/open.c:1294
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f9e8623caf4
RSP: 002b:00007f9e8731f710 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007f9e8623caf4
RDX: 0000000000000003 RSI: 00007f9e8731f7b0 RDI: 00000000ffffff9c
RBP: 00007f9e8731f7b0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000003
R13: 00007ffe6d243b2f R14: 00007f9e863abf60 R15: 00007f9e8731fd80
</TASK>
INFO: task syz-executor.5:9503 blocked for more than 143 seconds.
Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.5 state:D stack:28120 pid: 9503 ppid: 6502 flags:0x00004004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa76/0x5140 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
blkdev_get_by_dev block/bdev.c:814 [inline]
blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
blkdev_open+0x13c/0x2c0 block/fops.c:481
do_dentry_open+0x4a1/0x11f0 fs/open.c:848
do_open fs/namei.c:3520 [inline]
path_openat+0x1c51/0x2890 fs/namei.c:3653
do_filp_open+0x1c1/0x290 fs/namei.c:3680
do_sys_openat2+0x61b/0x990 fs/open.c:1278
do_sys_open+0xc3/0x140 fs/open.c:1294
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7fc9a783caf4
RSP: 002b:00007fc9a5f27710 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007fc9a783caf4
RDX: 0000000000000000 RSI: 00007fc9a5f277b0 RDI: 00000000ffffff9c
RBP: 00007fc9a5f277b0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
R13: 00007ffda907f81f R14: 00007fc9a79abf60 R15: 00007fc9a5f27d80
</TASK>
Showing all locks held in the system:
2 locks held by kworker/u4:1/12:
1 lock held by khungtaskd/30:
#0: ffffffff8bd83aa0 (rcu_read_lock){....}-{1:2}, at:
debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
1 lock held by in:imklog/6573:
#0: ffff88810db62368 (&f->f_pos_lock){+.+.}-{3:3}, at:
__fdget_pos+0xe3/0x100 fs/file.c:1036
5 locks held by kworker/u4:4/8242:
#0: ffff888063c39ed8 (&rq->__lock){-.-.}-{2:2}, at:
raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:544
#1: ffff888063c277c8 (&per_cpu_ptr(group->pcpu,
cpu)->seq){-.-.}-{0:0}, at: process_one_work+0x8e4/0x1650
kernel/workqueue.c:2264
#2: ffffffff8bdbc198 (dma_spin_lock){-.-.}-{2:2}, at: claim_dma_lock
arch/x86/include/asm/dma.h:156 [inline]
#2: ffffffff8bdbc198 (dma_spin_lock){-.-.}-{2:2}, at: floppy_ready
drivers/block/floppy.c:1946 [inline]
#2: ffffffff8bdbc198 (dma_spin_lock){-.-.}-{2:2}, at:
floppy_ready+0xb27/0x19b0 drivers/block/floppy.c:1926
#3: ffff888063c28398 (&base->lock){-.-.}-{2:2}
, at: lock_timer_base+0x5a/0x1f0 kernel/time/timer.c:999
#4:
ffffffff911ba350
(&obj_hash[i].lock
){-.-.}-{2:2}, at: console_lock_spinning_disable_and_check
kernel/printk/printk.c:1830 [inline]
){-.-.}-{2:2}, at: console_emit_next_record.constprop.0+0x40a/0x840
kernel/printk/printk.c:2737
1 lock held by syz-executor.1/9482:
#0: ffffffff8c8f20e8 (floppy_mutex){+.+.}-{3:3}, at:
fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
1 lock held by syz-executor.1/9490:
#0: ffff8880174eb118 (
&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev block/bdev.c:814 [inline]
&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev+0x241/0xae0
block/bdev.c:787
1 lock held by syz-executor.1/9498:
#0: ffffffff8c8f20e8 (floppy_mutex){+.+.}-{3:3}, at:
fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
1 lock held by syz-executor.1/9506:
#0: ffffffff8c8f20e8 (floppy_mutex){+.+.}-{3:3}, at:
fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
1 lock held by syz-executor.1/9523:
#0:
ffff8880174eb118
(&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev
block/bdev.c:814 [inline]
(&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev+0x241/0xae0
block/bdev.c:787
1 lock held by syz-executor.1/9526:
#0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
blkdev_get_by_dev block/bdev.c:814 [inline]
#0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
1 lock held by syz-executor.1/9537:
#0: ffffffff8c8f20e8 (floppy_mutex){+.+.}-{3:3}, at:
fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
2 locks held by syz-executor.6/9486:
#0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
blkdev_get_by_dev block/bdev.c:814 [inline]
#0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
#1: ffffffff8c8f20e8 (floppy_mutex){+.+.}-{3:3}, at:
floppy_open+0x7f/0xdb0 drivers/block/floppy.c:3994
1 lock held by syz-executor.5/9503:
#0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
blkdev_get_by_dev block/bdev.c:814 [inline]
#0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
=============================================
NMI backtrace for cpu 1
CPU: 1 PID: 30 Comm: khungtaskd Tainted: G OE
5.19.0-rc6-g2eae0556bb9d #2
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.13.0-1ubuntu1.1 04/01/2014
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
nmi_trigger_cpumask_backtrace+0x1a1/0x1e0 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xcc8/0x1010 kernel/hung_task.c:369
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 6574 Comm: rs:main Q:Reg Tainted: G OE
5.19.0-rc6-g2eae0556bb9d #2
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.13.0-1ubuntu1.1 04/01/2014
RIP: 0010:__rq_lockp kernel/sched/sched.h:1179 [inline]
RIP: 0010:rq_pin_lock kernel/sched/sched.h:1525 [inline]
RIP: 0010:rq_lock_irqsave kernel/sched/sched.h:1587 [inline]
RIP: 0010:sched_ttwu_pending+0x114/0x570 kernel/sched/core.c:3741
Code: 00 00 00 00 00 00 00 9c 5d fa f7 c5 00 02 00 00 0f 85 12 03 00
00 31 f6 4c 89 ff e8 e6 ad fe ff 49 8d 87 58 0d 00 00 48 89 c2 <48> 89
44 24 08 48 b8 00 00 00 00 00 fc ff df 48 c1 ea 03 48 89 6c
RSP: 0018:ffffc90000007d90 EFLAGS: 00000093
RAX: ffff888063c3ac18 RBX: ffff88812cffd8b8 RCX: 0000000000000000
RDX: ffff888063c3ac18 RSI: 0000000000000003 RDI: 0000000000000001
RBP: 0000000000000046 R08: fffff52000000f9c R09: fffff52000000f9d
R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
R13: 1ffff92000000fb9 R14: ffff88812cffd8c0 R15: ffff888063c39ec0
FS: 00007f6eca9fd700(0000) GS:ffff888063c00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f6ec0000000 CR3: 000000001700a000 CR4: 0000000000150ef0
Call Trace:
<IRQ>
__flush_smp_call_function_queue+0x451/0x9a0 kernel/smp.c:681
__sysvec_call_function_single+0x95/0x3e0 arch/x86/kernel/smp.c:248
sysvec_call_function_single+0x40/0xc0 arch/x86/kernel/smp.c:243
asm_sysvec_call_function_single+0x1b/0x20 arch/x86/include/asm/idtentry.h:657
RIP: 0010:__do_softirq+0x193/0x908 kernel/softirq.c:557
Code: 89 5c 24 08 48 89 44 24 18 48 c7 c7 60 1a cb 89 e8 d2 2d da ff
65 66 c7 05 f8 92 63 76 00 00 e8 b3 07 e1 f7 fb b8 ff ff ff ff <48> c7
c3 c0 a0 a0 8b 41 0f bc c5 41 89 c7 41 83 c7 01 0f 85 ad 00
RSP: 0018:ffffc90000007f80 EFLAGS: 00000206
RAX: 00000000ffffffff RBX: ffff88810a591d80 RCX: 1ffffffff20d7bd6
RDX: 0000000000000000 RSI: 0000000000000101 RDI: 0000000000000000
RBP: ffffc9000386f648 R08: 0000000000000001 R09: fffffbfff20d0135
R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
R13: 0000000000000080 R14: 0000000000000000 R15: 0000000000000000
invoke_softirq kernel/softirq.c:445 [inline]
__irq_exit_rcu kernel/softirq.c:650 [inline]
irq_exit_rcu+0xf2/0x130 kernel/softirq.c:662
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1106
</IRQ>
<TASK>
asm_sysvec_apic_timer_interrupt+0x1b/0x20 arch/x86/include/asm/idtentry.h:649
RIP: 0010:lock_is_held_type+0xff/0x140 kernel/locking/lockdep.c:5713
Code: 00 00 b8 ff ff ff ff 65 0f c1 05 14 57 88 76 83 f8 01 75 29 9c
58 f6 c4 02 75 3d 48 f7 04 24 00 02 00 00 74 01 fb 48 83 c4 08 <44> 89
e8 5b 5d 41 5c 41 5d 41 5e 41 5f c3 45 31 ed eb b9 0f 0b 48
RSP: 0018:ffffc9000386f6f0 EFLAGS: 00000296
RAX: 0000000000000046 RBX: 0000000000000004 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000000
RBP: ffffffff8bd839e0 R08: fffffbfff1b7619a R09: fffffbfff1b7619b
R10: 0000000000000001 R11: 000000000008a07a R12: ffff88810a591d80
R13: 0000000000000000 R14: 00000000ffffffff R15: ffff88810a592858
lock_is_held include/linux/lockdep.h:279 [inline]
rcu_read_lock_sched_held+0x9c/0xd0 kernel/rcu/update.c:125
trace_lock_release include/trace/events/lock.h:69 [inline]
lock_release+0x524/0x6d0 kernel/locking/lockdep.c:5676
rcu_lock_release include/linux/rcupdate.h:274 [inline]
rcu_read_unlock include/linux/rcupdate.h:728 [inline]
mapping_get_entry mm/filemap.c:1902 [inline]
__filemap_get_folio+0x345/0x1210 mm/filemap.c:1946
pagecache_get_page+0x2e/0x290 mm/folio-compat.c:126
ext4_da_write_begin+0x3f9/0xaf0 fs/ext4/inode.c:2977
generic_perform_write+0x240/0x570 mm/filemap.c:3779
ext4_buffered_write_iter+0x11d/0x2e0 fs/ext4/file.c:270
ext4_file_write_iter+0x448/0x14e0 fs/ext4/file.c:679
call_write_iter include/linux/fs.h:2058 [inline]
new_sync_write+0x393/0x570 fs/read_write.c:504
vfs_write+0x7c4/0xab0 fs/read_write.c:591
ksys_write+0x127/0x250 fs/read_write.c:644
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f6ecf2101cd
Code: c2 20 00 00 75 10 b8 01 00 00 00 0f 05 48 3d 01 f0 ff ff 73 31
c3 48 83 ec 08 e8 ae fc ff ff 48 89 04 24 b8 01 00 00 00 0f 05 <48> 8b
3c 24 48 89 c2 e8 f7 fc ff ff 48 89 d0 48 83 c4 08 48 3d 01
RSP: 002b:00007f6eca9fc590 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f6ec00243f0 RCX: 00007f6ecf2101cd
RDX: 0000000000000310 RSI: 00007f6ec00243f0 RDI: 0000000000000009
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 00007f6ec0024170
R13: 00007f6eca9fc5b0 R14: 000055b91e051440 R15: 0000000000000310
</TASK>
----------------
Code disassembly (best guess), 1 bytes skipped:
0: 00 00 add %al,(%rax)
2: 00 00 add %al,(%rax)
4: 00 00 add %al,(%rax)
6: 9c pushfq
7: 5d pop %rbp
8: fa cli
9: f7 c5 00 02 00 00 test $0x200,%ebp
f: 0f 85 12 03 00 00 jne 0x327
15: 31 f6 xor %esi,%esi
17: 4c 89 ff mov %r15,%rdi
1a: e8 e6 ad fe ff callq 0xfffeae05
1f: 49 8d 87 58 0d 00 00 lea 0xd58(%r15),%rax
26: 48 89 c2 mov %rax,%rdx
* 29: 48 89 44 24 08 mov %rax,0x8(%rsp) <-- trapping instruction
2e: 48 b8 00 00 00 00 00 movabs $0xdffffc0000000000,%rax
35: fc ff df
38: 48 c1 ea 03 shr $0x3,%rdx
3c: 48 rex.W
3d: 89 .byte 0x89
3e: 6c insb (%dx),%es:(%rdi)
--
Thanks and Regards,
Dipanjan
On Thu, Jul 28, 2022 at 12:01 AM Dipanjan Das
<[email protected]> wrote:
>
> Hi,
>
> We would like to report the following bug which has been found by our
> modified version of syzkaller.
>
> ======================================================
> description: INFO: task hung in __floppy_read_block_0
> affected file: drivers/block/floppy.c
> kernel version: 5.19-rc6
> kernel commit: 32346491ddf24599decca06190ebca03ff9de7f8
> git tree: upstream
> kernel config: https://syzkaller.appspot.com/text?tag=KernelConfig&x=cd73026ceaed1402
> crash reproducer: attached
Dipanjan, are you really sure that you want to report a "INFO: task
hung" bug identified with your syzkaller instance? Especially for a
floppy driver, probably in your case even just an emulated one
(right?). Reading data from floppies was always very slow as far as I
remember those times...
Consider the severity of the issue and judge if you would like to
point out such a 'bug'.
It might happen that:
Due to bad judgement on your side, kernel developers and maintainers
will consider the value/severity of the provided bug reports overall
and then eventually simply ignore all reports that you send.
Dmitry and his team around syzkaller and syzbot can give you more
insights on learning a good judgement of what to report, how and when.
IMHO, this is the trickiest (the most challenging) task when setting
up a syzkaller/syzbot instance and trying to use that to influence
releasing "better kernel versions". By the way, kudos to Dmitry and
his team for working on that challenging task and doing a good job on
that.
I hope this helps,
Lukas
> ======================================================
> Crash log:
> ======================================================
> INFO: task syz-executor.1:9482 blocked for more than 143 seconds.
> Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor.1 state:D stack:27528 pid: 9482 ppid: 5005 flags:0x00004004
> Call Trace:
> <TASK>
> context_switch kernel/sched/core.c:5146 [inline]
> __schedule+0xa76/0x5140 kernel/sched/core.c:6458
> schedule+0xd2/0x1f0 kernel/sched/core.c:6530
> schedule_timeout+0x5e5/0x890 kernel/time/timer.c:1911
> 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+0x182/0x360 kernel/sched/completion.c:138
> __floppy_read_block_0+0x1dd/0x290 drivers/block/floppy.c:4162
> floppy_revalidate+0x74f/0xa90 drivers/block/floppy.c:4206
> invalidate_drive+0xeb/0x120 drivers/block/floppy.c:3219
> fd_locked_ioctl+0xac1/0x1720 drivers/block/floppy.c:3467
> fd_ioctl+0x35/0x50 drivers/block/floppy.c:3574
> blkdev_ioctl+0x36e/0x800 block/ioctl.c:614
> vfs_ioctl fs/ioctl.c:51 [inline]
> __do_sys_ioctl fs/ioctl.c:870 [inline]
> __se_sys_ioctl fs/ioctl.c:856 [inline]
> __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:856
> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> entry_SYSCALL_64_after_hwframe+0x46/0xb0
> RIP: 0033:0x7fa70548d4ed
> RSP: 002b:00007fa706530be8 EFLAGS: 00000246
> ORIG_RAX: 0000000000000010
> RAX: ffffffffffffffda RBX: 00007fa7055abf60 RCX: 00007fa70548d4ed
> RDX: 0000000000000000 RSI: 0000000000000241 RDI: 0000000000000003
> RBP: 00007fa7054f92e1 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
> R13: 00007fff9363b3ef R14: 00007fa7055abf60 R15: 00007fa706530d80
> </TASK>
> INFO: task syz-executor.1:9490 blocked for more than 143 seconds.
> Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor.1 state:D stack:28120 pid: 9490 ppid: 5005 flags:0x00000004
> Call Trace:
> <TASK>
> context_switch kernel/sched/core.c:5146 [inline]
> __schedule+0xa76/0x5140 kernel/sched/core.c:6458
> schedule+0xd2/0x1f0 kernel/sched/core.c:6530
> schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
> __mutex_lock_common kernel/locking/mutex.c:679 [inline]
> __mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
> blkdev_get_by_dev block/bdev.c:814 [inline]
> blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
> blkdev_open+0x13c/0x2c0 block/fops.c:481
> do_dentry_open+0x4a1/0x11f0 fs/open.c:848
> do_open fs/namei.c:3520 [inline]
> path_openat+0x1c51/0x2890 fs/namei.c:3653
> do_filp_open+0x1c1/0x290 fs/namei.c:3680
> do_sys_openat2+0x61b/0x990 fs/open.c:1278
> do_sys_open+0xc3/0x140 fs/open.c:1294
> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> entry_SYSCALL_64_after_hwframe+0x46/0xb0
> RIP: 0033:0x7fa70543caf4
> RSP: 002b:00007fa70650f710 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
> RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007fa70543caf4
> RDX: 0000000000000003 RSI: 00007fa70650f7b0 RDI: 00000000ffffff9c
> RBP: 00007fa70650f7b0 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000003
> R13: 00007fff9363b3ef R14: 00007fa7055ac040 R15: 00007fa70650fd80
> </TASK>
> INFO: task syz-executor.1:9498 blocked for more than 143 seconds.
> Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor.1 state:D stack:29272 pid: 9498 ppid: 5005 flags:0x00000004
> Call Trace:
> <TASK>
> context_switch kernel/sched/core.c:5146 [inline]
> __schedule+0xa76/0x5140 kernel/sched/core.c:6458
> schedule+0xd2/0x1f0 kernel/sched/core.c:6530
> schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
> __mutex_lock_common kernel/locking/mutex.c:679 [inline]
> __mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
> fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
> blkdev_ioctl+0x36e/0x800 block/ioctl.c:614
> vfs_ioctl fs/ioctl.c:51 [inline]
> __do_sys_ioctl fs/ioctl.c:870 [inline]
> __se_sys_ioctl fs/ioctl.c:856 [inline]
> __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:856
> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> entry_SYSCALL_64_after_hwframe+0x46/0xb0
> RIP: 0033:0x7fa70548d4ed
> RSP: 002b:00007fa703a8bbe8 EFLAGS: 00000246
> ORIG_RAX: 0000000000000010
> RAX: ffffffffffffffda RBX: 00007fa7055ac120 RCX: 00007fa70548d4ed
> RDX: 0000000000000000 RSI: 0000000000000246 RDI: 0000000000000003
> RBP: 00007fa7054f92e1 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
> R13: 00007fff9363b3ef R14: 00007fa7055ac120 R15: 00007fa703a8bd80
> </TASK>
> INFO: task syz-executor.1:9506 blocked for more than 143 seconds.
> Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor.1 state:D
> stack:29272 pid: 9506 ppid: 5005 flags:0x00000004
> Call Trace:
> <TASK>
> context_switch kernel/sched/core.c:5146 [inline]
> __schedule+0xa76/0x5140 kernel/sched/core.c:6458
> schedule+0xd2/0x1f0 kernel/sched/core.c:6530
> schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
> __mutex_lock_common kernel/locking/mutex.c:679 [inline]
> __mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
> fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
> blkdev_ioctl+0x36e/0x800 block/ioctl.c:614
> vfs_ioctl fs/ioctl.c:51 [inline]
> __do_sys_ioctl fs/ioctl.c:870 [inline]
> __se_sys_ioctl fs/ioctl.c:856 [inline]
> __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:856
> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> entry_SYSCALL_64_after_hwframe+0x46/0xb0
> RIP: 0033:0x7fa70548d4ed
> RSP: 002b:00007fa70386abe8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
> RAX: ffffffffffffffda RBX: 00007fa7055ac200 RCX: 00007fa70548d4ed
> RDX: 0000000000000000 RSI: 0000000000000247 RDI: 0000000000000003
> RBP: 00007fa7054f92e1 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
> R13: 00007fff9363b3ef R14: 00007fa7055ac200 R15: 00007fa70386ad80
> </TASK>
> INFO: task syz-executor.1:9523 blocked for more than 143 seconds.
> Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor.1 state:D
> stack:28120 pid: 9523 ppid: 5005 flags:0x00000004
> Call Trace:
> <TASK>
> context_switch kernel/sched/core.c:5146 [inline]
> __schedule+0xa76/0x5140 kernel/sched/core.c:6458
> schedule+0xd2/0x1f0 kernel/sched/core.c:6530
> schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
> __mutex_lock_common kernel/locking/mutex.c:679 [inline]
> __mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
> blkdev_get_by_dev block/bdev.c:814 [inline]
> blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
> blkdev_open+0x13c/0x2c0 block/fops.c:481
> do_dentry_open+0x4a1/0x11f0 fs/open.c:848
> do_open fs/namei.c:3520 [inline]
> path_openat+0x1c51/0x2890 fs/namei.c:3653
> do_filp_open+0x1c1/0x290 fs/namei.c:3680
> do_sys_openat2+0x61b/0x990 fs/open.c:1278
> do_sys_open+0xc3/0x140 fs/open.c:1294
> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> entry_SYSCALL_64_after_hwframe+0x46/0xb0
> RIP: 0033:0x7fa70543caf4
> RSP: 002b:00007fa703649710 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
> RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007fa70543caf4
> RDX: 0000000000000003 RSI: 00007fa7036497b0 RDI: 00000000ffffff9c
> RBP: 00007fa7036497b0 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000003
> R13: 00007fff9363b3ef R14: 00007fa7055ac2e0 R15: 00007fa703649d80
> </TASK>
> INFO: task syz-executor.1:9526 blocked for more than 143 seconds.
> Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor.1 state:D stack:28120 pid: 9526 ppid: 5005 flags:0x00000004
> Call Trace:
> <TASK>
> context_switch kernel/sched/core.c:5146 [inline]
> __schedule+0xa76/0x5140 kernel/sched/core.c:6458
> schedule+0xd2/0x1f0 kernel/sched/core.c:6530
> schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
> __mutex_lock_common kernel/locking/mutex.c:679 [inline]
> __mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
> blkdev_get_by_dev block/bdev.c:814 [inline]
> blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
> blkdev_open+0x13c/0x2c0 block/fops.c:481
> do_dentry_open+0x4a1/0x11f0 fs/open.c:848
> do_open fs/namei.c:3520 [inline]
> path_openat+0x1c51/0x2890 fs/namei.c:3653
> do_filp_open+0x1c1/0x290 fs/namei.c:3680
> do_sys_openat2+0x61b/0x990 fs/open.c:1278
> do_sys_open+0xc3/0x140 fs/open.c:1294
> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> entry_SYSCALL_64_after_hwframe+0x46/0xb0
> RIP: 0033:0x7fa70543caf4
> RSP: 002b:00007fa703428710 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
> RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007fa70543caf4
> RDX: 0000000000000003 RSI: 00007fa7034287b0 RDI: 00000000ffffff9c
> RBP: 00007fa7034287b0 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000003
> R13: 00007fff9363b3ef R14: 00007fa7055ac3c0 R15: 00007fa703428d80
> </TASK>
> INFO: task syz-executor.1:9537 blocked for more than 143 seconds.
> Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor.1 state:D
> stack:28584 pid: 9537 ppid: 5005 flags:0x00000004
> Call Trace:
> <TASK>
> context_switch kernel/sched/core.c:5146 [inline]
> __schedule+0xa76/0x5140 kernel/sched/core.c:6458
> schedule+0xd2/0x1f0 kernel/sched/core.c:6530
> schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
> __mutex_lock_common kernel/locking/mutex.c:679 [inline]
> __mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
> fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
> blkdev_ioctl+0x36e/0x800 block/ioctl.c:614
> vfs_ioctl fs/ioctl.c:51 [inline]
> __do_sys_ioctl fs/ioctl.c:870 [inline]
> __se_sys_ioctl fs/ioctl.c:856 [inline]
> __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:856
> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> entry_SYSCALL_64_after_hwframe+0x46/0xb0
> RIP: 0033:0x7fa70548d4ed
> RSP: 002b:00007fa703207be8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
> RAX: ffffffffffffffda RBX: 00007fa7055ac4a0 RCX: 00007fa70548d4ed
> RDX: 0000000020000200 RSI: 0000000040200242 RDI: 0000000000000003
> RBP: 00007fa7054f92e1 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
> R13: 00007fff9363b3ef R14: 00007fa7055ac4a0 R15: 00007fa703207d80
> </TASK>
> INFO: task syz-executor.6:9486 blocked for more than 143 seconds.
> Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor.6 state:D stack:28120 pid: 9486 ppid: 6033 flags:0x00000004
> Call Trace:
> <TASK>
> context_switch kernel/sched/core.c:5146 [inline]
> __schedule+0xa76/0x5140 kernel/sched/core.c:6458
> schedule+0xd2/0x1f0 kernel/sched/core.c:6530
> schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
> __mutex_lock_common kernel/locking/mutex.c:679 [inline]
> __mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
> floppy_open+0x7f/0xdb0 drivers/block/floppy.c:3994
> blkdev_get_whole+0x99/0x260 block/bdev.c:673
> blkdev_get_by_dev block/bdev.c:823 [inline]
> blkdev_get_by_dev+0x4a8/0xae0 block/bdev.c:787
> blkdev_open+0x13c/0x2c0 block/fops.c:481
> do_dentry_open+0x4a1/0x11f0 fs/open.c:848
> do_open fs/namei.c:3520 [inline]
> path_openat+0x1c51/0x2890 fs/namei.c:3653
> do_filp_open+0x1c1/0x290 fs/namei.c:3680
> do_sys_openat2+0x61b/0x990 fs/open.c:1278
> do_sys_open+0xc3/0x140 fs/open.c:1294
> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> entry_SYSCALL_64_after_hwframe+0x46/0xb0
> RIP: 0033:0x7f9e8623caf4
> RSP: 002b:00007f9e8731f710 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
> RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007f9e8623caf4
> RDX: 0000000000000003 RSI: 00007f9e8731f7b0 RDI: 00000000ffffff9c
> RBP: 00007f9e8731f7b0 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000003
> R13: 00007ffe6d243b2f R14: 00007f9e863abf60 R15: 00007f9e8731fd80
> </TASK>
> INFO: task syz-executor.5:9503 blocked for more than 143 seconds.
> Tainted: G OE 5.19.0-rc6-g2eae0556bb9d #2
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor.5 state:D stack:28120 pid: 9503 ppid: 6502 flags:0x00004004
> Call Trace:
> <TASK>
> context_switch kernel/sched/core.c:5146 [inline]
> __schedule+0xa76/0x5140 kernel/sched/core.c:6458
> schedule+0xd2/0x1f0 kernel/sched/core.c:6530
> schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
> __mutex_lock_common kernel/locking/mutex.c:679 [inline]
> __mutex_lock+0xfa9/0x1f50 kernel/locking/mutex.c:747
> blkdev_get_by_dev block/bdev.c:814 [inline]
> blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
> blkdev_open+0x13c/0x2c0 block/fops.c:481
> do_dentry_open+0x4a1/0x11f0 fs/open.c:848
> do_open fs/namei.c:3520 [inline]
> path_openat+0x1c51/0x2890 fs/namei.c:3653
> do_filp_open+0x1c1/0x290 fs/namei.c:3680
> do_sys_openat2+0x61b/0x990 fs/open.c:1278
> do_sys_open+0xc3/0x140 fs/open.c:1294
> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> entry_SYSCALL_64_after_hwframe+0x46/0xb0
> RIP: 0033:0x7fc9a783caf4
> RSP: 002b:00007fc9a5f27710 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
> RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007fc9a783caf4
> RDX: 0000000000000000 RSI: 00007fc9a5f277b0 RDI: 00000000ffffff9c
> RBP: 00007fc9a5f277b0 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
> R13: 00007ffda907f81f R14: 00007fc9a79abf60 R15: 00007fc9a5f27d80
> </TASK>
>
> Showing all locks held in the system:
> 2 locks held by kworker/u4:1/12:
> 1 lock held by khungtaskd/30:
> #0: ffffffff8bd83aa0 (rcu_read_lock){....}-{1:2}, at:
> debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
> 1 lock held by in:imklog/6573:
> #0: ffff88810db62368 (&f->f_pos_lock){+.+.}-{3:3}, at:
> __fdget_pos+0xe3/0x100 fs/file.c:1036
> 5 locks held by kworker/u4:4/8242:
> #0: ffff888063c39ed8 (&rq->__lock){-.-.}-{2:2}, at:
> raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:544
> #1: ffff888063c277c8 (&per_cpu_ptr(group->pcpu,
> cpu)->seq){-.-.}-{0:0}, at: process_one_work+0x8e4/0x1650
> kernel/workqueue.c:2264
> #2: ffffffff8bdbc198 (dma_spin_lock){-.-.}-{2:2}, at: claim_dma_lock
> arch/x86/include/asm/dma.h:156 [inline]
> #2: ffffffff8bdbc198 (dma_spin_lock){-.-.}-{2:2}, at: floppy_ready
> drivers/block/floppy.c:1946 [inline]
> #2: ffffffff8bdbc198 (dma_spin_lock){-.-.}-{2:2}, at:
> floppy_ready+0xb27/0x19b0 drivers/block/floppy.c:1926
> #3: ffff888063c28398 (&base->lock){-.-.}-{2:2}
> , at: lock_timer_base+0x5a/0x1f0 kernel/time/timer.c:999
> #4:
> ffffffff911ba350
> (&obj_hash[i].lock
> ){-.-.}-{2:2}, at: console_lock_spinning_disable_and_check
> kernel/printk/printk.c:1830 [inline]
> ){-.-.}-{2:2}, at: console_emit_next_record.constprop.0+0x40a/0x840
> kernel/printk/printk.c:2737
> 1 lock held by syz-executor.1/9482:
> #0: ffffffff8c8f20e8 (floppy_mutex){+.+.}-{3:3}, at:
> fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
> 1 lock held by syz-executor.1/9490:
> #0: ffff8880174eb118 (
> &disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev block/bdev.c:814 [inline]
> &disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev+0x241/0xae0
> block/bdev.c:787
> 1 lock held by syz-executor.1/9498:
> #0: ffffffff8c8f20e8 (floppy_mutex){+.+.}-{3:3}, at:
> fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
> 1 lock held by syz-executor.1/9506:
> #0: ffffffff8c8f20e8 (floppy_mutex){+.+.}-{3:3}, at:
> fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
> 1 lock held by syz-executor.1/9523:
> #0:
> ffff8880174eb118
> (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev
> block/bdev.c:814 [inline]
> (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev+0x241/0xae0
> block/bdev.c:787
> 1 lock held by syz-executor.1/9526:
> #0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
> blkdev_get_by_dev block/bdev.c:814 [inline]
> #0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
> blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
> 1 lock held by syz-executor.1/9537:
> #0: ffffffff8c8f20e8 (floppy_mutex){+.+.}-{3:3}, at:
> fd_ioctl+0x25/0x50 drivers/block/floppy.c:3573
> 2 locks held by syz-executor.6/9486:
> #0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
> blkdev_get_by_dev block/bdev.c:814 [inline]
> #0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
> blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
> #1: ffffffff8c8f20e8 (floppy_mutex){+.+.}-{3:3}, at:
> floppy_open+0x7f/0xdb0 drivers/block/floppy.c:3994
> 1 lock held by syz-executor.5/9503:
> #0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
> blkdev_get_by_dev block/bdev.c:814 [inline]
> #0: ffff8880174eb118 (&disk->open_mutex){+.+.}-{3:3}, at:
> blkdev_get_by_dev+0x241/0xae0 block/bdev.c:787
>
> =============================================
>
> NMI backtrace for cpu 1
> CPU: 1 PID: 30 Comm: khungtaskd Tainted: G OE
> 5.19.0-rc6-g2eae0556bb9d #2
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> 1.13.0-1ubuntu1.1 04/01/2014
> Call Trace:
> <TASK>
> __dump_stack lib/dump_stack.c:88 [inline]
> dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
> nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
> nmi_trigger_cpumask_backtrace+0x1a1/0x1e0 lib/nmi_backtrace.c:62
> trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
> check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
> watchdog+0xcc8/0x1010 kernel/hung_task.c:369
> kthread+0x2e9/0x3a0 kernel/kthread.c:376
> ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
> </TASK>
> Sending NMI from CPU 1 to CPUs 0:
> NMI backtrace for cpu 0
> CPU: 0 PID: 6574 Comm: rs:main Q:Reg Tainted: G OE
> 5.19.0-rc6-g2eae0556bb9d #2
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> 1.13.0-1ubuntu1.1 04/01/2014
> RIP: 0010:__rq_lockp kernel/sched/sched.h:1179 [inline]
> RIP: 0010:rq_pin_lock kernel/sched/sched.h:1525 [inline]
> RIP: 0010:rq_lock_irqsave kernel/sched/sched.h:1587 [inline]
> RIP: 0010:sched_ttwu_pending+0x114/0x570 kernel/sched/core.c:3741
> Code: 00 00 00 00 00 00 00 9c 5d fa f7 c5 00 02 00 00 0f 85 12 03 00
> 00 31 f6 4c 89 ff e8 e6 ad fe ff 49 8d 87 58 0d 00 00 48 89 c2 <48> 89
> 44 24 08 48 b8 00 00 00 00 00 fc ff df 48 c1 ea 03 48 89 6c
> RSP: 0018:ffffc90000007d90 EFLAGS: 00000093
> RAX: ffff888063c3ac18 RBX: ffff88812cffd8b8 RCX: 0000000000000000
> RDX: ffff888063c3ac18 RSI: 0000000000000003 RDI: 0000000000000001
> RBP: 0000000000000046 R08: fffff52000000f9c R09: fffff52000000f9d
> R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
> R13: 1ffff92000000fb9 R14: ffff88812cffd8c0 R15: ffff888063c39ec0
> FS: 00007f6eca9fd700(0000) GS:ffff888063c00000(0000) knlGS:0000000000000000
> CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> CR2: 00007f6ec0000000 CR3: 000000001700a000 CR4: 0000000000150ef0
> Call Trace:
> <IRQ>
> __flush_smp_call_function_queue+0x451/0x9a0 kernel/smp.c:681
> __sysvec_call_function_single+0x95/0x3e0 arch/x86/kernel/smp.c:248
> sysvec_call_function_single+0x40/0xc0 arch/x86/kernel/smp.c:243
> asm_sysvec_call_function_single+0x1b/0x20 arch/x86/include/asm/idtentry.h:657
> RIP: 0010:__do_softirq+0x193/0x908 kernel/softirq.c:557
> Code: 89 5c 24 08 48 89 44 24 18 48 c7 c7 60 1a cb 89 e8 d2 2d da ff
> 65 66 c7 05 f8 92 63 76 00 00 e8 b3 07 e1 f7 fb b8 ff ff ff ff <48> c7
> c3 c0 a0 a0 8b 41 0f bc c5 41 89 c7 41 83 c7 01 0f 85 ad 00
> RSP: 0018:ffffc90000007f80 EFLAGS: 00000206
> RAX: 00000000ffffffff RBX: ffff88810a591d80 RCX: 1ffffffff20d7bd6
> RDX: 0000000000000000 RSI: 0000000000000101 RDI: 0000000000000000
> RBP: ffffc9000386f648 R08: 0000000000000001 R09: fffffbfff20d0135
> R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
> R13: 0000000000000080 R14: 0000000000000000 R15: 0000000000000000
> invoke_softirq kernel/softirq.c:445 [inline]
> __irq_exit_rcu kernel/softirq.c:650 [inline]
> irq_exit_rcu+0xf2/0x130 kernel/softirq.c:662
> sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1106
> </IRQ>
> <TASK>
> asm_sysvec_apic_timer_interrupt+0x1b/0x20 arch/x86/include/asm/idtentry.h:649
> RIP: 0010:lock_is_held_type+0xff/0x140 kernel/locking/lockdep.c:5713
> Code: 00 00 b8 ff ff ff ff 65 0f c1 05 14 57 88 76 83 f8 01 75 29 9c
> 58 f6 c4 02 75 3d 48 f7 04 24 00 02 00 00 74 01 fb 48 83 c4 08 <44> 89
> e8 5b 5d 41 5c 41 5d 41 5e 41 5f c3 45 31 ed eb b9 0f 0b 48
> RSP: 0018:ffffc9000386f6f0 EFLAGS: 00000296
> RAX: 0000000000000046 RBX: 0000000000000004 RCX: 0000000000000001
> RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000000
> RBP: ffffffff8bd839e0 R08: fffffbfff1b7619a R09: fffffbfff1b7619b
> R10: 0000000000000001 R11: 000000000008a07a R12: ffff88810a591d80
> R13: 0000000000000000 R14: 00000000ffffffff R15: ffff88810a592858
> lock_is_held include/linux/lockdep.h:279 [inline]
> rcu_read_lock_sched_held+0x9c/0xd0 kernel/rcu/update.c:125
> trace_lock_release include/trace/events/lock.h:69 [inline]
> lock_release+0x524/0x6d0 kernel/locking/lockdep.c:5676
> rcu_lock_release include/linux/rcupdate.h:274 [inline]
> rcu_read_unlock include/linux/rcupdate.h:728 [inline]
> mapping_get_entry mm/filemap.c:1902 [inline]
> __filemap_get_folio+0x345/0x1210 mm/filemap.c:1946
> pagecache_get_page+0x2e/0x290 mm/folio-compat.c:126
> ext4_da_write_begin+0x3f9/0xaf0 fs/ext4/inode.c:2977
> generic_perform_write+0x240/0x570 mm/filemap.c:3779
> ext4_buffered_write_iter+0x11d/0x2e0 fs/ext4/file.c:270
> ext4_file_write_iter+0x448/0x14e0 fs/ext4/file.c:679
> call_write_iter include/linux/fs.h:2058 [inline]
> new_sync_write+0x393/0x570 fs/read_write.c:504
> vfs_write+0x7c4/0xab0 fs/read_write.c:591
> ksys_write+0x127/0x250 fs/read_write.c:644
> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> entry_SYSCALL_64_after_hwframe+0x46/0xb0
> RIP: 0033:0x7f6ecf2101cd
> Code: c2 20 00 00 75 10 b8 01 00 00 00 0f 05 48 3d 01 f0 ff ff 73 31
> c3 48 83 ec 08 e8 ae fc ff ff 48 89 04 24 b8 01 00 00 00 0f 05 <48> 8b
> 3c 24 48 89 c2 e8 f7 fc ff ff 48 89 d0 48 83 c4 08 48 3d 01
> RSP: 002b:00007f6eca9fc590 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
> RAX: ffffffffffffffda RBX: 00007f6ec00243f0 RCX: 00007f6ecf2101cd
> RDX: 0000000000000310 RSI: 00007f6ec00243f0 RDI: 0000000000000009
> RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000293 R12: 00007f6ec0024170
> R13: 00007f6eca9fc5b0 R14: 000055b91e051440 R15: 0000000000000310
> </TASK>
> ----------------
> Code disassembly (best guess), 1 bytes skipped:
> 0: 00 00 add %al,(%rax)
> 2: 00 00 add %al,(%rax)
> 4: 00 00 add %al,(%rax)
> 6: 9c pushfq
> 7: 5d pop %rbp
> 8: fa cli
> 9: f7 c5 00 02 00 00 test $0x200,%ebp
> f: 0f 85 12 03 00 00 jne 0x327
> 15: 31 f6 xor %esi,%esi
> 17: 4c 89 ff mov %r15,%rdi
> 1a: e8 e6 ad fe ff callq 0xfffeae05
> 1f: 49 8d 87 58 0d 00 00 lea 0xd58(%r15),%rax
> 26: 48 89 c2 mov %rax,%rdx
> * 29: 48 89 44 24 08 mov %rax,0x8(%rsp) <-- trapping instruction
> 2e: 48 b8 00 00 00 00 00 movabs $0xdffffc0000000000,%rax
> 35: fc ff df
> 38: 48 c1 ea 03 shr $0x3,%rdx
> 3c: 48 rex.W
> 3d: 89 .byte 0x89
> 3e: 6c insb (%dx),%es:(%rdi)
>
> --
> Thanks and Regards,
>
> Dipanjan
>
> --
> You received this message because you are subscribed to the Google Groups "syzkaller" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to [email protected].
> To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller/CANX2M5ZSuHONz-TPVdGcW3q_n6Z2DKLM6M8RfG%2BmORA9CCQRsQ%40mail.gmail.com.
On Thu, Jul 28, 2022 at 7:23 AM Lukas Bulwahn <[email protected]> wrote:
>
> Dipanjan, are you really sure that you want to report a "INFO: task
> hung" bug identified with your syzkaller instance? Especially for a
> floppy driver, probably in your case even just an emulated one
> (right?). Reading data from floppies was always very slow as far as I
> remember those times...
From the bugs reported by syzkaller in the past, we observed that
several of these “INFO: task hung in… “ reports were considered and
acted on, for example, this:
https://groups.google.com/g/syzkaller-bugs/c/L0SBaHZ5bYc. For the
reported issue, we noticed the read task stays blocked for 143
seconds, which seemed to be one the higher, especially given that it
is an emulated floppy drive (yes, you are right). If it deems normal,
then we do apologize for our misassesment.
> Consider the severity of the issue and judge if you would like to
> point out such a 'bug'.
>
> It might happen that:
>
> Due to bad judgement on your side, kernel developers and maintainers
> will consider the value/severity of the provided bug reports overall
> and then eventually simply ignore all reports that you send.
That would be very unfortunate. Please allow me to explain how we, as
a *small* academic team, are operating. If you closely follow our
reportings we did in the last few days, the first “quality control” we
are doing (to minimize the noise and frustration) is to make sure not
to report any bug without a reproducer. Now, the unfortunate reality
is that none of us is a pro kernel hacker with years of expertise in
tinkering with Linux internals, which essentially means, no matter how
hard we try, we cannot simply match up the combined level of expertise
and competency of the people in these mailing groups. We are using our
best judgement before reporting these bugs. Admittedly, we may be
wrong, and we apologize in advance for such mishaps. The developers
can confirm, or refute the reports (if they can spend a line or two
why they think something we reported is not a problem, we would be
grateful). In our defense, what we can say is that, in the last few
days we responded to the developers who asked us to provide details of
a bug, or test a patch. In fact, we are still in the process of
responding to some of them, because being a small team, our turnaround
time is higher than ideal. To answer you, simply ignoring all the
reports we send might be too harsh (unfair?) to an academic group
operating in good faith. Providing us pointers like you did above
(thanks to Greg for helping us in some other thread), and letting us
know what we did wrong will help us to align ourselves better with the
reporting and patching workflow.
> Dmitry and his team around syzkaller and syzbot can give you more
> insights on learning a good judgement of what to report, how and when.
We would very much appreciate any help (even positive criticism) from
the community in this regard.
--
Thanks and Regards,
Dipanjan
On Thu, Jul 28, 2022 at 10:20 PM Dipanjan Das
<[email protected]> wrote:
>
> On Thu, Jul 28, 2022 at 7:23 AM Lukas Bulwahn <[email protected]> wrote:
> >
> > Dipanjan, are you really sure that you want to report a "INFO: task
> > hung" bug identified with your syzkaller instance? Especially for a
> > floppy driver, probably in your case even just an emulated one
> > (right?). Reading data from floppies was always very slow as far as I
> > remember those times...
>
> From the bugs reported by syzkaller in the past, we observed that
> several of these “INFO: task hung in… “ reports were considered and
> acted on, for example, this:
> https://groups.google.com/g/syzkaller-bugs/c/L0SBaHZ5bYc. For the
> reported issue, we noticed the read task stays blocked for 143
> seconds, which seemed to be one the higher, especially given that it
> is an emulated floppy drive (yes, you are right). If it deems normal,
> then we do apologize for our misassesment.
>
Maybe, some of the "INFO: task hung" reports are considered once in a
while, but from the testing with fuzzing, they are often really
difficult to judge. Was the system first put into a strange state and
then the system was made slow/hanging by that setup?
Often, human users would never do that or if they do, they basically
would need to expect that the system slows down. So, these reports are
generally more difficult to consider valid. I cannot tell you if that
happens in this case, too. Certainly the floppy driver is special by
now, and I would not expect much bug investigation and fixing for
that.
If Dmitry and his team have not answered some of the questions below
and you are coming from an academic background, you might really want
to look into, which may help you in your interest in working on
syzkaller improvements and considering reporting to kernel developers:
We already have https://syzkaller.appspot.com/upstream to track and
report various issues identified by syzkaller.
At this syzbot instance, as of writing, we currently have 976 issues
open, 3904 fixed, 8461 considered invalid.
The bugs are of different types, e.g., BUG: ..., general protection
fault, INFO: ..., KASAN: ..., KMSAN: ..., memory leak: ..., possible
deadlock: ..., UBSAN: ...
So, from the current data, how many bugs of each type were actively
fixed (so, a dedicated commit to repair the code), not just a report
that was closed because it eventually disappeared? How many bugs of
each type are still open? How long does it take from first reporting
to the commit being accepted? Again, e.g., aggregated by type?
That can tell which type of bugs really are addressed more than
others. And that may help you to decide if to report a bug from your
syzkaller instance.
> > Consider the severity of the issue and judge if you would like to
> > point out such a 'bug'.
> >
> > It might happen that:
> >
> > Due to bad judgement on your side, kernel developers and maintainers
> > will consider the value/severity of the provided bug reports overall
> > and then eventually simply ignore all reports that you send.
>
> That would be very unfortunate. Please allow me to explain how we, as
> a *small* academic team, are operating. If you closely follow our
> reportings we did in the last few days, the first “quality control” we
> are doing (to minimize the noise and frustration) is to make sure not
> to report any bug without a reproducer. Now, the unfortunate reality
> is that none of us is a pro kernel hacker with years of expertise in
> tinkering with Linux internals, which essentially means, no matter how
> hard we try, we cannot simply match up the combined level of expertise
> and competency of the people in these mailing groups. We are using our
> best judgement before reporting these bugs. Admittedly, we may be
> wrong, and we apologize in advance for such mishaps. The developers
> can confirm, or refute the reports (if they can spend a line or two
> why they think something we reported is not a problem, we would be
> grateful). In our defense, what we can say is that, in the last few
> days we responded to the developers who asked us to provide details of
> a bug, or test a patch. In fact, we are still in the process of
> responding to some of them, because being a small team, our turnaround
> time is higher than ideal. To answer you, simply ignoring all the
> reports we send might be too harsh (unfair?) to an academic group
> operating in good faith. Providing us pointers like you did above
> (thanks to Greg for helping us in some other thread), and letting us
> know what we did wrong will help us to align ourselves better with the
> reporting and patching workflow.
>
All good, but probably you need to follow some simple guidelines.
If you find an issue in older LTS kernel releases and not on the
current one, you can bisect the issue with the reproducer, and
identify the commit in which the issue is fixed. Then the usual stable
patch acceptance process works.
If you find an issue on the current kernel release, you can bisect the
issue with the reproducer to the commit that introduced the issue.
That is helpful for pinpointing the issue and creating a fix.
Do not report more issues than you can handle when testing suggestions
or writing responses. No one expects you to report everything you
find. (We know there are 900 bugs open, reported by syzkaller; so we
are not short of bug reports.). However, if you report, you should
really have time to follow up with responses and work in reasonable
time (probably within a few days). If you cannot handle that full
time, one important bug report each week might be okay and help a bit,
rather than automated sending 1000 bug reports and never being
available for questions on those reports.
> > Dmitry and his team around syzkaller and syzbot can give you more
> > insights on learning a good judgement of what to report, how and when.
>
> We would very much appreciate any help (even positive criticism) from
> the community in this regard.
>
I think there is not much documentation available specific to
reporting bugs from syzkaller, but there are a few best practices that
we already know and we really might want to write up here because "I
run some syzkaller instance and just report whatever I find to the
developers" simply does not work (we have seen that in the past
already). This keeps developers busy and does not necessarily get more
bugs or the important bugs fixed.
Lukas
Hi,
On Thu, Jul 28, 2022 at 01:20:33PM -0700, Dipanjan Das wrote:
> On Thu, Jul 28, 2022 at 7:23 AM Lukas Bulwahn <[email protected]> wrote:
> >
> > Dipanjan, are you really sure that you want to report a "INFO: task
> > hung" bug identified with your syzkaller instance? Especially for a
> > floppy driver, probably in your case even just an emulated one
> > (right?). Reading data from floppies was always very slow as far as I
> > remember those times...
>
> >From the bugs reported by syzkaller in the past, we observed that
> several of these "INFO: task hung in... " reports were considered and
> acted on, for example, this:
> https://groups.google.com/g/syzkaller-bugs/c/L0SBaHZ5bYc. For the
> reported issue, we noticed the read task stays blocked for 143
> seconds, which seemed to be one the higher, especially given that it
> is an emulated floppy drive (yes, you are right). If it deems normal,
> then we do apologize for our misassesment.
FWIW I've been running the repro here on machine running 5.19-rc8 and
equipped with a real floppy drive. The code is still running as I type,
it sounds like it's destroying the floppy disk in it but after 12 minutes
of torture, nothing happens.
Thus I'm a bit confused about what to look for. It's very likely that
there are still bugs left in this driver, but trying to identify them
and to validate a fix will be difficult if they cannot be reproduced.
Maybe they only happen under emulation due to timing issues.
As such, any hint about the exact setup and how long to wait to get
the error would be much appreciated.
Thanks,
Willy
Hi,
On 7/31/22 13:53, Willy Tarreau wrote:
> Hi,
>
> On Thu, Jul 28, 2022 at 01:20:33PM -0700, Dipanjan Das wrote:
>> On Thu, Jul 28, 2022 at 7:23 AM Lukas Bulwahn <[email protected]> wrote:
>>>
>>> Dipanjan, are you really sure that you want to report a "INFO: task
>>> hung" bug identified with your syzkaller instance? Especially for a
>>> floppy driver, probably in your case even just an emulated one
>>> (right?). Reading data from floppies was always very slow as far as I
>>> remember those times...
>>
>> >From the bugs reported by syzkaller in the past, we observed that
>> several of these "INFO: task hung in... " reports were considered and
>> acted on, for example, this:
>> https://groups.google.com/g/syzkaller-bugs/c/L0SBaHZ5bYc. For the
>> reported issue, we noticed the read task stays blocked for 143
>> seconds, which seemed to be one the higher, especially given that it
>> is an emulated floppy drive (yes, you are right). If it deems normal,
>> then we do apologize for our misassesment.
>
> FWIW I've been running the repro here on machine running 5.19-rc8 and
> equipped with a real floppy drive. The code is still running as I type,
> it sounds like it's destroying the floppy disk in it but after 12 minutes
> of torture, nothing happens.
>
> Thus I'm a bit confused about what to look for. It's very likely that
> there are still bugs left in this driver, but trying to identify them
> and to validate a fix will be difficult if they cannot be reproduced.
> Maybe they only happen under emulation due to timing issues.
>
> As such, any hint about the exact setup and how long to wait to get
> the error would be much appreciated.
It's relatively easy to get "INFO: task hung ..." with the floppy driver.
The simplest way is to do "while (true) { close(open("/dev/fd0", ...)); }"
in multiple threads. Maybe with O_NBLOCK flag, I don't remember the exact
details. The timeout value to report task hung matters here (i.e.
CONFIG_DEFAULT_HUNG_TASK_TIMEOUT). If you stop executing the cycle the
requests will be processed eventually. Floppy driver contains a number
of timeouts for hardware requests because hardware is slow. I would not
treat it as a thing to fix because: 1) a user faces it only if he tries
to fuzz the driver 2) it's easy to break something in the driver
(testing is hard and it doesn't cover all hardware/use-cases, real users
will notice if something broken only ~6 six months after distros will release
kernels with LTS patches) 3) floppy is not a security problem in modern
distros (/dev/fd0 access requires disk group or floppy group at least).
Null-ptr-deref reported recently is a different bug and I will look at it.
Last week I was out of my hardware with only limited access to the email
and I wasn't able to do it. Sorry for delays.
Thanks,
Denis
On Sun, Jul 31, 2022 at 2:53 AM Willy Tarreau <[email protected]> wrote:
>
> Thus I'm a bit confused about what to look for. It's very likely that
> there are still bugs left in this driver, but trying to identify them
> and to validate a fix will be difficult if they cannot be reproduced.
> Maybe they only happen under emulation due to timing issues.
>
> As such, any hint about the exact setup and how long to wait to get
> the error would be much appreciated.
We can confirm that we were able to trigger the issue on the latest
5.19 (commit: 3d7cb6b04c3f3115719235cc6866b10326de34cd) with the
C-repro within a VM. We use this:
https://syzkaller.appspot.com/text?tag=KernelConfig&x=cd73026ceaed1402
config to build the kernel. The issue triggers after around 143
seconds. For all the five times we tried, we were able to reproduce
the issue deterministically every time. Please let us know if you need
any other information.
--
Thanks and Regards,
Dipanjan
Hi,
On Mon, Aug 01, 2022 at 10:04:46PM -0700, Dipanjan Das wrote:
> On Sun, Jul 31, 2022 at 2:53 AM Willy Tarreau <[email protected]> wrote:
> >
> > Thus I'm a bit confused about what to look for. It's very likely that
> > there are still bugs left in this driver, but trying to identify them
> > and to validate a fix will be difficult if they cannot be reproduced.
> > Maybe they only happen under emulation due to timing issues.
> >
> > As such, any hint about the exact setup and how long to wait to get
> > the error would be much appreciated.
>
> We can confirm that we were able to trigger the issue on the latest
> 5.19 (commit: 3d7cb6b04c3f3115719235cc6866b10326de34cd) with the
> C-repro within a VM. We use this:
> https://syzkaller.appspot.com/text?tag=KernelConfig&x=cd73026ceaed1402
> config to build the kernel. The issue triggers after around 143
> seconds. For all the five times we tried, we were able to reproduce
> the issue deterministically every time. Please let us know if you need
> any other information.
Yep, I could reproduce it under qemu as well. I've added traces, and
ugly things are happening with the lock (but I haven't understood what
yet). What I saw was that process_fd_request() is first called under
lock, then we drop the lock, then __floppy_read_block_0() is called
under lock, which calls process_fd_request(), then the lock is dropped,
wait_for_completion() is called, then process_fd_request() is called
again without lock this time, and from there we're looping in
fd_wait_for_completion. I need to dig into more details but it doesn't
seem right to me that process_fd_request() is sometimes called under a
lock and sometimes out, and that __floppy_read_block_0() is called with
a lock held and it's relesed under it. I could have missed certain things
due to the concurrent accesses but in any case I should probably not be
observing this.
I'll try to dig deeper. I really don't know that area and I must confess
it's not the most exciting to rediscover each time :-)
Thanks,
Willy