INFO: task hung in __blkdev_get

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: b7634809
git tree: android-4.9
console output: https://syzkaller.appspot.com/x/log.txt?x=162e443e800000
kernel config: https://syzkaller.appspot.com/x/.config?x=a53a99daca608767
dashboard link: https://syzkaller.appspot.com/bug?extid=ea035c20286692c41efe
compiler: gcc (GCC) 7.1.1 20170620
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1574f6fe800000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=117117be800000

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

random: crng init done
INFO: task blkid:3373 blocked for more than 120 seconds.
Not tainted 4.9.66-gb763480 #103
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
blkid D28208 3373 1866 0x00000004
ffff8801cefb8000 0000000000000000 ffff8801cd990540 ffff8801da29b000
ffff8801db321418 ffff8801ca087708 ffffffff838981cb 0000000000000000
0000000000000007 00ff8801cefb8000 ffff8801db321ce8 ffff8801db321d10
Call Trace:
[<ffffffff8389976f>] schedule+0x7f/0x1b0 kernel/sched/core.c:3550
[<ffffffff8389a0f3>] schedule_preempt_disabled+0x13/0x20
kernel/sched/core.c:3583
[<ffffffff8389f702>] __mutex_lock_common kernel/locking/mutex.c:582
[inline]
[<ffffffff8389f702>] mutex_lock_nested+0x312/0x870
kernel/locking/mutex.c:621
[<ffffffff8162a23c>] __blkdev_get+0x10c/0xd50 fs/block_dev.c:1268
[<ffffffff8162c10b>] blkdev_get+0x33b/0x960 fs/block_dev.c:1416
[<ffffffff8162c935>] blkdev_open+0x1a5/0x250 fs/block_dev.c:1571
[<ffffffff81563227>] do_dentry_open+0x607/0xc60 fs/open.c:766
[<ffffffff81566cd5>] vfs_open+0x105/0x220 fs/open.c:879
[<ffffffff8159d44c>] do_last fs/namei.c:3408 [inline]
[<ffffffff8159d44c>] path_openat+0x5ac/0x2910 fs/namei.c:3531
[<ffffffff815a2fa7>] do_filp_open+0x197/0x290 fs/namei.c:3566
[<ffffffff815677b2>] do_sys_open+0x352/0x4c0 fs/open.c:1072
[<ffffffff8156794d>] SYSC_open fs/open.c:1090 [inline]
[<ffffffff8156794d>] SyS_open+0x2d/0x40 fs/open.c:1085
[<ffffffff838a9985>] entry_SYSCALL_64_fastpath+0x23/0xc6

Showing all locks held in the system:
2 locks held by khungtaskd/514:
#0: (rcu_read_lock){......}, at: [<ffffffff8136fe05>]
check_hung_uninterruptible_tasks kernel/hung_task.c:168 [inline]
#0: (rcu_read_lock){......}, at: [<ffffffff8136fe05>]
watchdog+0x125/0xa70 kernel/hung_task.c:239
#1: (tasklist_lock){.+.+..}, at: [<ffffffff812355d0>]
debug_show_all_locks+0x70/0x280 kernel/locking/lockdep.c:4336
1 lock held by rsyslogd/3150:
#0: (&f->f_pos_lock){+.+.+.}, at: [<ffffffff815cf91f>]
__fdget_pos+0x9f/0xc0 fs/file.c:781
2 locks held by getty/3238:
#0: (&tty->ldisc_sem){++++++}, at: [<ffffffff838a7b92>]
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:367
#1: (&ldata->atomic_read_lock){+.+...}, at: [<ffffffff82001d84>]
n_tty_read+0x1f4/0x16c0 drivers/tty/n_tty.c:2133
1 lock held by syzkaller946102/3370:
#0: (&bdev->bd_mutex){+.+.+.}, at: [<ffffffff81629a0c>]
__blkdev_put+0xbc/0x7e0 fs/block_dev.c:1579
1 lock held by blkid/3373:
#0: (&bdev->bd_mutex){+.+.+.}, at: [<ffffffff8162a23c>]
__blkdev_get+0x10c/0xd50 fs/block_dev.c:1268

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

NMI backtrace for cpu 0
CPU: 0 PID: 514 Comm: khungtaskd Not tainted 4.9.66-gb763480 #103
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
ffff8801d99dfd00 ffffffff81d90749 0000000000000000 0000000000000000
0000000000000000 0000000000000001 ffffffff810ba170 ffff8801d99dfd38
ffffffff81d9b86d 0000000000000000 0000000000000000 ffff8801cefb8418
Call Trace:
[<ffffffff81d90749>] __dump_stack lib/dump_stack.c:15 [inline]
[<ffffffff81d90749>] dump_stack+0xc1/0x128 lib/dump_stack.c:51
[<ffffffff81d9b86d>] nmi_cpu_backtrace+0xfd/0x120 lib/nmi_backtrace.c:99
[<ffffffff81d9b9a7>] nmi_trigger_cpumask_backtrace+0x117/0x190
lib/nmi_backtrace.c:60
[<ffffffff810ba264>] arch_trigger_cpumask_backtrace+0x14/0x20
arch/x86/kernel/apic/hw_nmi.c:37
[<ffffffff813703d0>] trigger_all_cpu_backtrace include/linux/nmi.h:58
[inline]
[<ffffffff813703d0>] check_hung_task kernel/hung_task.c:125 [inline]
[<ffffffff813703d0>] check_hung_uninterruptible_tasks
kernel/hung_task.c:182 [inline]
[<ffffffff813703d0>] watchdog+0x6f0/0xa70 kernel/hung_task.c:239
[<ffffffff811985ad>] kthread+0x26d/0x300 kernel/kthread.c:211
[<ffffffff838a9c2a>] ret_from_fork+0x2a/0x40 arch/x86/entry/entry_64.S:437
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at pc 0xffffffff838a8606


---
This bug 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 bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: 47350a9f ANDROID: x86_64_cuttlefish_defconfig: Enable lz4 ..
git tree: android-4.14
console output: https://syzkaller.appspot.com/x/log.txt?x=1467bb0e400000
kernel config: https://syzkaller.appspot.com/x/.config?x=10d236078f3378a3
dashboard link: https://syzkaller.appspot.com/bug?extid=29067ccee0d84204a7e9
compiler: gcc (GCC) 8.0.1 20180413 (experimental)

Unfortunately, I don't have any reproducer for this crash yet.

IMPORTANT: if you fix the bug, please add the following tag to the commit:

Reported-by: syzbot+29067c...@syzkaller.appspotmail.com

INFO: task syz-executor1:2009 blocked for more than 140 seconds.
Not tainted 4.14.67+ #1

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

syz-executor1 D26448 2009 2001 0x00000000
Call Trace:
schedule+0x7f/0x1b0 kernel/sched/core.c:3490
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3548
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x521/0x1480 kernel/locking/mutex.c:893
__blkdev_get+0xf3/0xe50 fs/block_dev.c:1452
blkdev_get+0x97/0x8c0 fs/block_dev.c:1604
blkdev_open+0x1bd/0x240 fs/block_dev.c:1762
do_dentry_open+0x426/0xda0 fs/open.c:764
vfs_open+0x11c/0x210 fs/open.c:878
do_last fs/namei.c:3408 [inline]
path_openat+0x4eb/0x23a0 fs/namei.c:3550
do_filp_open+0x197/0x270 fs/namei.c:3584
do_sys_open+0x2ef/0x580 fs/open.c:1071
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x410da0
RSP: 002b:00007ffcd31bd908 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000410da0
RDX: 00007ffcd31bd94a RSI: 0000000000000002 RDI: 00007ffcd31bd940
RBP: 0000000000000cb0 R08: 0000000000000000 R09: 000000000000000a
R10: 0000000000000075 R11: 0000000000000246 R12: 0000000000000006
R13: 0000000000099bc0 R14: 00000000000005b5 R15: badc0ffeebadface
INFO: task syz-executor7:2014 blocked for more than 140 seconds.
Not tainted 4.14.67+ #1

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

syz-executor7 D27144 2014 2005 0x00000000
Call Trace:
schedule+0x7f/0x1b0 kernel/sched/core.c:3490
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3548
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x521/0x1480 kernel/locking/mutex.c:893
lo_open+0x17/0xa0 drivers/block/loop.c:1592
__blkdev_get+0x267/0xe50 fs/block_dev.c:1467
blkdev_get+0x97/0x8c0 fs/block_dev.c:1604
blkdev_open+0x1bd/0x240 fs/block_dev.c:1762
do_dentry_open+0x426/0xda0 fs/open.c:764
vfs_open+0x11c/0x210 fs/open.c:878
do_last fs/namei.c:3408 [inline]
path_openat+0x4eb/0x23a0 fs/namei.c:3550
do_filp_open+0x197/0x270 fs/namei.c:3584
do_sys_open+0x2ef/0x580 fs/open.c:1071
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x410da0
RSP: 002b:00007fff06825358 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000410da0
RDX: 00007fff0682539a RSI: 0000000000000002 RDI: 00007fff06825390
RBP: 0000000000000c07 R08: 0000000000000000 R09: 000000000000000a
R10: 0000000000000075 R11: 0000000000000246 R12: 000000000000000a
R13: 0000000000099b2b R14: 0000000000000573 R15: badc0ffeebadface
INFO: task syz-executor0:11655 blocked for more than 140 seconds.
Not tainted 4.14.67+ #1

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

syz-executor0 D25608 11655 2004 0x00000004
Call Trace:
schedule+0x7f/0x1b0 kernel/sched/core.c:3490
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3548
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x521/0x1480 kernel/locking/mutex.c:893
blkdev_reread_part+0x18/0x30 block/ioctl.c:192
loop_reread_partitions+0x72/0x80 drivers/block/loop.c:614
loop_set_status+0xa84/0xf40 drivers/block/loop.c:1169
loop_set_status64+0x8d/0xe0 drivers/block/loop.c:1287
lo_ioctl+0x3cd/0x17d0 drivers/block/loop.c:1400
__blkdev_driver_ioctl block/ioctl.c:297 [inline]
blkdev_ioctl+0x57d/0x18c0 block/ioctl.c:594
block_ioctl+0xd9/0x120 fs/block_dev.c:1873
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x1a0/0x1030 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7e/0xb0 fs/ioctl.c:692
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x456ef7
RSP: 002b:00007fbf0dd47a18 EFLAGS: 00000202 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fbf0dd486d4 RCX: 0000000000456ef7
RDX: 00007fbf0dd47ab0 RSI: 0000000000004c04 RDI: 0000000000000005
RBP: 0000000000000001 R08: 0000000000000000 R09: 000000000000000a
R10: 0000000000000075 R11: 0000000000000202 R12: 00007fbf0dd486d4
R13: 0000000000000004 R14: 0000000000000005 R15: 0000000000000001
INFO: task syz-executor4:11666 blocked for more than 140 seconds.
Not tainted 4.14.67+ #1

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

syz-executor4 D28216 11666 2015 0x00000004
Call Trace:
schedule+0x7f/0x1b0 kernel/sched/core.c:3490
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3548
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x521/0x1480 kernel/locking/mutex.c:893
loop_control_ioctl+0x180/0x310 drivers/block/loop.c:1965
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x1a0/0x1030 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7e/0xb0 fs/ioctl.c:692
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x457089
RSP: 002b:00007f6cfe018c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f6cfe0196d4 RCX: 0000000000457089
RDX: 0000000000000000 RSI: 0000000000004c81 RDI: 0000000000000005
RBP: 00000000009300a0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 00000000004cf728 R14: 00000000004c5ae9 R15: 0000000000000000
INFO: task syz-executor4:11673 blocked for more than 140 seconds.
Not tainted 4.14.67+ #1

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

syz-executor4 D29704 11673 2015 0x00000004
Call Trace:
schedule+0x7f/0x1b0 kernel/sched/core.c:3490
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3548
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x521/0x1480 kernel/locking/mutex.c:893
loop_control_ioctl+0x71/0x310 drivers/block/loop.c:1951
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x1a0/0x1030 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7e/0xb0 fs/ioctl.c:692
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x457089
RSP: 002b:00007f6cfdff7c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f6cfdff86d4 RCX: 0000000000457089
RDX: 0000000000000000 RSI: 0000000000004c82 RDI: 0000000000000005
RBP: 0000000000930140 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 00000000004cf710 R14: 00000000004c5ad1 R15: 0000000000000001
INFO: task syz-executor4:11674 blocked for more than 140 seconds.
Not tainted 4.14.67+ #1

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

syz-executor4 D29160 11674 2015 0x00000004
Call Trace:
schedule+0x7f/0x1b0 kernel/sched/core.c:3490
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3548
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x521/0x1480 kernel/locking/mutex.c:893
loop_control_ioctl+0x71/0x310 drivers/block/loop.c:1951
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x1a0/0x1030 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7e/0xb0 fs/ioctl.c:692
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x457089
RSP: 002b:00007f6cfdfd6c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f6cfdfd76d4 RCX: 0000000000457089
RDX: 00000000200001c0 RSI: 000000000000540f RDI: 0000000000000005
RBP: 00000000009301e0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 00000000004d09b8 R14: 00000000004c6485 R15: 0000000000000002
INFO: task blkid:11663 blocked for more than 140 seconds.
Not tainted 4.14.67+ #1

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

blkid D28424 11663 27632 0x00000004
Call Trace:
schedule+0x7f/0x1b0 kernel/sched/core.c:3490
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3548
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x521/0x1480 kernel/locking/mutex.c:893
lo_release+0x1a/0x190 drivers/block/loop.c:1635
__blkdev_put+0x526/0x6e0 fs/block_dev.c:1783
blkdev_close+0x86/0xb0 fs/block_dev.c:1855
__fput+0x25e/0x6f0 fs/file_table.c:210
task_work_run+0x116/0x190 kernel/task_work.c:113
tracehook_notify_resume include/linux/tracehook.h:191 [inline]
exit_to_usermode_loop+0x12e/0x150 arch/x86/entry/common.c:163
prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
syscall_return_slowpath arch/x86/entry/common.c:267 [inline]
do_syscall_64+0x35d/0x4b0 arch/x86/entry/common.c:294
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x7f0b782662b0
RSP: 002b:00007ffcd0a04978 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007f0b782662b0
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000003
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000001
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000001c35030
R13: 0000000000000000 R14: 0000000000000003 R15: 0000000000000005
INFO: task blkid:11664 blocked for more than 140 seconds.
Not tainted 4.14.67+ #1

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

blkid D28696 11664 28176 0x00000004
Call Trace:
schedule+0x7f/0x1b0 kernel/sched/core.c:3490
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3548
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x521/0x1480 kernel/locking/mutex.c:893
lo_open+0x17/0xa0 drivers/block/loop.c:1592
__blkdev_get+0x8e2/0xe50 fs/block_dev.c:1529
blkdev_get+0x97/0x8c0 fs/block_dev.c:1604
blkdev_open+0x1bd/0x240 fs/block_dev.c:1762
do_dentry_open+0x426/0xda0 fs/open.c:764
vfs_open+0x11c/0x210 fs/open.c:878
do_last fs/namei.c:3408 [inline]
path_openat+0x4eb/0x23a0 fs/namei.c:3550
do_filp_open+0x197/0x270 fs/namei.c:3584
do_sys_open+0x2ef/0x580 fs/open.c:1071
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x7fb8dd3af120
RSP: 002b:00007ffe14bcb168 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fb8dd3af120
RDX: 00007ffe14bcbf40 RSI: 0000000000000000 RDI: 00007ffe14bcbf40
RBP: 0000000000000000 R08: 0000000000000078 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000001f07030
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000005
INFO: task blkid:11665 blocked for more than 140 seconds.
Not tainted 4.14.67+ #1

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

blkid D29000 11665 28179 0x00000004
Call Trace:
schedule+0x7f/0x1b0 kernel/sched/core.c:3490
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3548
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x521/0x1480 kernel/locking/mutex.c:893
lo_open+0x17/0xa0 drivers/block/loop.c:1592
__blkdev_get+0x267/0xe50 fs/block_dev.c:1467
blkdev_get+0x97/0x8c0 fs/block_dev.c:1604
blkdev_open+0x1bd/0x240 fs/block_dev.c:1762
do_dentry_open+0x426/0xda0 fs/open.c:764
vfs_open+0x11c/0x210 fs/open.c:878
do_last fs/namei.c:3408 [inline]
path_openat+0x4eb/0x23a0 fs/namei.c:3550
do_filp_open+0x197/0x270 fs/namei.c:3584
do_sys_open+0x2ef/0x580 fs/open.c:1071
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x7efee16cf120
RSP: 002b:00007ffdc6cd9448 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007efee16cf120
RDX: 00007ffdc6cd9f33 RSI: 0000000000000000 RDI: 00007ffdc6cd9f33
RBP: 0000000000000000 R08: 0000000000000078 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000068e030
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000005
INFO: task blkid:11667 blocked for more than 140 seconds.
Not tainted 4.14.67+ #1

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

blkid D29000 11667 29238 0x00000004
Call Trace:
schedule+0x7f/0x1b0 kernel/sched/core.c:3490
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3548
__mutex_lock_common kernel/locking/mutex.c:833 [inline]
__mutex_lock+0x521/0x1480 kernel/locking/mutex.c:893
lo_open+0x17/0xa0 drivers/block/loop.c:1592
__blkdev_get+0x267/0xe50 fs/block_dev.c:1467
blkdev_get+0x97/0x8c0 fs/block_dev.c:1604
blkdev_open+0x1bd/0x240 fs/block_dev.c:1762
do_dentry_open+0x426/0xda0 fs/open.c:764
vfs_open+0x11c/0x210 fs/open.c:878
do_last fs/namei.c:3408 [inline]
path_openat+0x4eb/0x23a0 fs/namei.c:3550
do_filp_open+0x197/0x270 fs/namei.c:3584
do_sys_open+0x2ef/0x580 fs/open.c:1071
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x7fe9eb59b120
RSP: 002b:00007ffccab64238 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fe9eb59b120
RDX: 00007ffccab64f33 RSI: 0000000000000000 RDI: 00007ffccab64f33
RBP: 0000000000000000 R08: 0000000000000078 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000002330030
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000005

Showing all locks held in the system:

1 lock held by khungtaskd/23:
#0: (tasklist_lock){.+.+}, at: [<ffffffffb2401847>]
debug_show_all_locks+0x74/0x20f kernel/locking/lockdep.c:4541
2 locks held by rs:main Q:Reg/1852:
#0: (&f->f_pos_lock){+.+.}, at: [<ffffffffb27bcab2>]
__fdget_pos+0xa2/0xc0 fs/file.c:768
#1: (sb_writers#3){.+.+}, at: [<ffffffffb275b3d7>] file_start_write
include/linux/fs.h:2722 [inline]
#1: (sb_writers#3){.+.+}, at: [<ffffffffb275b3d7>] vfs_write+0x3d7/0x4d0
fs/read_write.c:545
2 locks held by getty/1950:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffffb2f1c500>]
tty_ldisc_ref_wait+0x20/0x80 drivers/tty/tty_ldisc.c:275
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffffb2f17a7f>]
n_tty_read+0x1ff/0x15e0 drivers/tty/n_tty.c:2142
1 lock held by syz-executor1/2009:
#0: (&bdev->bd_mutex){+.+.}, at: [<ffffffffb28188c3>]
__blkdev_get+0xf3/0xe50 fs/block_dev.c:1452
2 locks held by syz-executor7/2014:
#0: (&bdev->bd_mutex){+.+.}, at: [<ffffffffb28188c3>]
__blkdev_get+0xf3/0xe50 fs/block_dev.c:1452
#1: (loop_index_mutex){+.+.}, at: [<ffffffffb2fc7107>] lo_open+0x17/0xa0
drivers/block/loop.c:1592
2 locks held by syz-executor0/11655:
#0: (&lo->lo_ctl_mutex/1){+.+.}, at: [<ffffffffb2fcb8d5>]
lo_ioctl+0x85/0x17d0 drivers/block/loop.c:1373
#1: (&bdev->bd_mutex){+.+.}, at: [<ffffffffb2cfd838>]
blkdev_reread_part+0x18/0x30 block/ioctl.c:192
2 locks held by syz-executor4/11666:
#0: (loop_index_mutex){+.+.}, at: [<ffffffffb2fce641>]
loop_control_ioctl+0x71/0x310 drivers/block/loop.c:1951
#1: (&lo->lo_ctl_mutex#2){+.+.}, at: [<ffffffffb2fce750>]
loop_control_ioctl+0x180/0x310 drivers/block/loop.c:1965
1 lock held by syz-executor4/11673:
#0: (loop_index_mutex){+.+.}, at: [<ffffffffb2fce641>]
loop_control_ioctl+0x71/0x310 drivers/block/loop.c:1951
1 lock held by syz-executor4/11674:
#0: (loop_index_mutex){+.+.}, at: [<ffffffffb2fce641>]
loop_control_ioctl+0x71/0x310 drivers/block/loop.c:1951
2 locks held by blkid/11663:
#0: (&bdev->bd_mutex){+.+.}, at: [<ffffffffb28181a1>]
__blkdev_put+0xb1/0x6e0 fs/block_dev.c:1770
#1: (loop_index_mutex){+.+.}, at: [<ffffffffb2fcd16a>]
lo_release+0x1a/0x190 drivers/block/loop.c:1635
2 locks held by blkid/11664:
#0: (&bdev->bd_mutex){+.+.}, at: [<ffffffffb28188c3>]
__blkdev_get+0xf3/0xe50 fs/block_dev.c:1452
#1: (loop_index_mutex){+.+.}, at: [<ffffffffb2fc7107>] lo_open+0x17/0xa0
drivers/block/loop.c:1592
2 locks held by blkid/11665:
#0: (&bdev->bd_mutex){+.+.}, at: [<ffffffffb28188c3>]
__blkdev_get+0xf3/0xe50 fs/block_dev.c:1452
#1: (loop_index_mutex){+.+.}, at: [<ffffffffb2fc7107>] lo_open+0x17/0xa0
drivers/block/loop.c:1592
2 locks held by blkid/11667:
#0: (&bdev->bd_mutex){+.+.}, at: [<ffffffffb28188c3>]
__blkdev_get+0xf3/0xe50 fs/block_dev.c:1452
#1: (loop_index_mutex){+.+.}, at: [<ffffffffb2fc7107>] lo_open+0x17/0xa0
drivers/block/loop.c:1592
1 lock held by init/11700:
#0: (tty_mutex){+.+.}, at: [<ffffffffb2f0bef8>] tty_open_by_driver
drivers/tty/tty_io.c:1922 [inline]
#0: (tty_mutex){+.+.}, at: [<ffffffffb2f0bef8>] tty_open+0x3a8/0x980
drivers/tty/tty_io.c:2006

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

NMI backtrace for cpu 1
CPU: 1 PID: 23 Comm: khungtaskd Not tainted 4.14.67+ #1
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0xb9/0x11b lib/dump_stack.c:53
nmi_cpu_backtrace.cold.0+0x18/0x8e lib/nmi_backtrace.c:103
nmi_trigger_cpumask_backtrace+0x121/0x146 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:138 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:196 [inline]
watchdog+0x574/0xa70 kernel/hung_task.c:252
kthread+0x348/0x420 kernel/kthread.c:232
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:402
Sending NMI from CPU 1 to CPUs 0:

NMI backtrace for cpu 0

CPU: 0 PID: 1854 Comm: rsyslogd Not tainted 4.14.67+ #1
task: ffff8801c0bec680 task.stack: ffff8801c01d8000
RIP: 0010:memcpy_erms+0x8/0x10 arch/x86/lib/memcpy_64.S:54
RSP: 0018:ffff8801c01df958 EFLAGS: 00000046
RAX: ffff8801bc285f82 RBX: ffff8801bc285f82 RCX: 0000000000000000
RDX: 0000000000000001 RSI: ffffffffb405abe4 RDI: ffff8801bc285f83
RBP: ffffffffb405abe3 R08: ffffed0037850bf1 R09: ffffed0037850bf0
R10: ffffed0037850bf0 R11: ffff8801bc285f82 R12: dffffc0000000000
R13: ffffffffb405abe4 R14: ffff8801c01dfa58 R15: 0000000000000001
FS: 00007f439d240700(0000) GS:ffff8801dba00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f5385a6da30 CR3: 00000001cd328006 CR4: 00000000001606b0
DR0: 0000000020000000 DR1: 0000000020000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
Call Trace:
memcpy include/linux/string.h:344 [inline]
vsnprintf+0x3ef/0x13a0 lib/vsprintf.c:2143
sprintf+0xb0/0xe0 lib/vsprintf.c:2383
print_prefix+0xb1/0x3a0 kernel/printk/printk.c:1230
msg_print_text+0xae/0x1a0 kernel/printk/printk.c:1269
syslog_print kernel/printk/printk.c:1314 [inline]
do_syslog+0x700/0x980 kernel/printk/printk.c:1455
kmsg_read+0x6f/0x90 fs/proc/kmsg.c:40
proc_reg_read+0xef/0x170 fs/proc/inode.c:217
__vfs_read+0xf4/0x5b0 fs/read_write.c:411
vfs_read+0x11e/0x330 fs/read_write.c:447
SYSC_read fs/read_write.c:577 [inline]
SyS_read+0xc2/0x1a0 fs/read_write.c:570
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x7f439fca01fd
RSP: 002b:00007f439d23fe30 EFLAGS: 00000293 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 0000000002618650 RCX: 00007f439fca01fd
RDX: 0000000000000fff RSI: 00007f439ea745a0 RDI: 0000000000000004
RBP: 0000000000000000 R08: 0000000002603260 R09: 0000000000000000
R10: 705f706f6f6c203f R11: 0000000000000293 R12: 000000000065e420
R13: 00007f439d2409c0 R14: 00007f43a02e5040 R15: 0000000000000003
Code: 90 90 90 eb 1e 0f 1f 00 48 89 f8 48 89 d1 48 c1 e9 03 83 e2 07 f3 48
a5 89 d1 f3 a4 c3 66 0f 1f 44 00 00 48 89 f8 48 89 d1 f3 a4 <c3> 0f 1f 80
00 00 00 00 48 89 f8 48 83 fa 20 72 7e 40 38 fe 7c

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: 62872f95 Merge 4.4.174 into android-4.4
git tree: android-4.4
console output: https://syzkaller.appspot.com/x/log.txt?x=1058a283200000
kernel config: https://syzkaller.appspot.com/x/.config?x=47bc4dd423780c4a
dashboard link: https://syzkaller.appspot.com/bug?extid=0f5a67e59c689a865fdb
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=17d8d713200000

IMPORTANT: if you fix the bug, please add the following tag to the commit:

Reported-by: syzbot+0f5a67...@syzkaller.appspotmail.com

INFO: task syz-executor.1:2205 blocked for more than 140 seconds.
Not tainted 4.4.174+ #4

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

syz-executor.1 D ffff8800b4fb7668 25104 2205 1 0x00000004
ffff8800b4fb7668 ffff8801d258c740 2352dfd30ba1e502 ffff8801d258c740
0000000000000000 ffff8801d258d000 ffff8801db71f180 ffff8801db71f1a8
ffff8801db71e898 ffff8800b52d8000 ffff8801d258c740 ffffed00169f6001
Call Trace:
[<ffffffff82709b79>] schedule+0x99/0x1d0 kernel/sched/core.c:3355
[<ffffffff8270a333>] schedule_preempt_disabled+0x13/0x20
kernel/sched/core.c:3388
[<ffffffff8270c492>] __mutex_lock_common kernel/locking/mutex.c:582
[inline]
[<ffffffff8270c492>] mutex_lock_nested+0x3c2/0xb80
kernel/locking/mutex.c:621
[<ffffffff8154e9cc>] __blkdev_get+0x10c/0xdf0 fs/block_dev.c:1199
[<ffffffff81551938>] blkdev_get+0x2e8/0x920 fs/block_dev.c:1353
[<ffffffff8155219a>] blkdev_open+0x1aa/0x250 fs/block_dev.c:1508
[<ffffffff8149154f>] do_dentry_open+0x38f/0xbd0 fs/open.c:749
[<ffffffff81494d3b>] vfs_open+0x10b/0x210 fs/open.c:862
[<ffffffff814c5ddf>] do_last fs/namei.c:3269 [inline]
[<ffffffff814c5ddf>] path_openat+0x136f/0x4470 fs/namei.c:3406
[<ffffffff814ccab1>] do_filp_open+0x1a1/0x270 fs/namei.c:3440
[<ffffffff81495668>] do_sys_open+0x2f8/0x600 fs/open.c:1038
[<ffffffff8149599d>] SYSC_open fs/open.c:1056 [inline]
[<ffffffff8149599d>] SyS_open+0x2d/0x40 fs/open.c:1051
[<ffffffff82718ba1>] entry_SYSCALL_64_fastpath+0x1e/0x9a
1 lock held by syz-executor.1/2205:
#0: (&bdev->bd_mutex){+.+.+.}, at: [<ffffffff8154e9cc>]
__blkdev_get+0x10c/0xdf0 fs/block_dev.c:1199
Sending NMI to all CPUs:

NMI backtrace for cpu 0

CPU: 0 PID: 20 Comm: khungtaskd Not tainted 4.4.174+ #4
task: ffff8801da6f4740 task.stack: ffff8800001c0000
RIP: 0010:[<ffffffff8109b617>] [<ffffffff8109b617>] _flat_send_IPI_mask
arch/x86/kernel/apic/apic_flat_64.c:62 [inline]
RIP: 0010:[<ffffffff8109b617>] [<ffffffff8109b617>]
flat_send_IPI_mask+0xf7/0x1b0 arch/x86/kernel/apic/apic_flat_64.c:69
RSP: 0018:ffff8800001c7c88 EFLAGS: 00000046
RAX: 0000000000000000 RBX: 0000000000000c00 RCX: 0000000000000000
RDX: 0000000000000c00 RSI: 0000000000000000 RDI: ffffffffff5fc300
RBP: ffff8800001c7cb8 R08: 0000000000000018 R09: 0000000000000000
R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000246
R13: 0000000003000000 R14: ffffffff82e5f2e0 R15: 0000000000000002
FS: 0000000000000000(0000) GS:ffff8801db600000(0000) knlGS:0000000000000000

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

CR2: 00007ffeecb4fff8 CR3: 00000000b9192000 CR4: 00000000001606b0
Stack:
0000000000000001 ffffffff82e5f2e0 ffffffff831a6ac0 fffffbfff0634c34
000000000001b6c0 0000000000000008 ffff8800001c7cd8 ffffffff81092bee
0000000000000008 ffffffff82924260 ffff8800001c7d30 ffffffff81ab8252
Call Trace:
[<ffffffff81092bee>] nmi_raise_cpu_backtrace+0x5e/0x80
arch/x86/kernel/apic/hw_nmi.c:33
[<ffffffff81ab8252>] nmi_trigger_all_cpu_backtrace.cold+0xa1/0xae
lib/nmi_backtrace.c:85
[<ffffffff81092ca4>] arch_trigger_all_cpu_backtrace+0x14/0x20
arch/x86/kernel/apic/hw_nmi.c:38
[<ffffffff813b4762>] trigger_all_cpu_backtrace include/linux/nmi.h:44
[inline]
[<ffffffff813b4762>] check_hung_task kernel/hung_task.c:125 [inline]
[<ffffffff813b4762>] check_hung_uninterruptible_tasks
kernel/hung_task.c:182 [inline]
[<ffffffff813b4762>] watchdog.cold+0xd3/0xee kernel/hung_task.c:238
[<ffffffff811342c3>] kthread+0x273/0x310 kernel/kthread.c:211
[<ffffffff82718fc5>] ret_from_fork+0x55/0x80 arch/x86/entry/entry_64.S:537
Code: 00 c3 5f ff 80 e6 10 75 e1 41 c1 e5 18 44 89 2c 25 10 c3 5f ff 44 89
fa 09 da 80 cf 04 41 83 ff 02 0f 44 d3 89 14 25 00 c3 5f ff <41> f7 c4 00
02 00 00 75 1e 4c 89 e7 57 9d 0f 1f 44 00 00 e8 f1

NMI backtrace for cpu 1

CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.4.174+ #4
task: ffff8801da6897c0 task.stack: ffff8801da698000
RIP: 0010:[<ffffffff810a1dc2>] [<ffffffff810a1dc2>]
native_safe_halt+0x2/0x10 arch/x86/include/asm/irqflags.h:53
RSP: 0018:ffff8801da69fd88 EFLAGS: 00000246
RAX: 0000000000000007 RBX: ffffffff8319bf68 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffff8801da68a084
RBP: ffff8801da69fdb8 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001
R13: ffff8801da6a0000 R14: dffffc0000000000 R15: ffff8801da698000
FS: 0000000000000000(0000) GS:ffff8801db700000(0000) knlGS:0000000000000000

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

CR2: 0000000000e1a000 CR3: 00000000b9192000 CR4: 00000000001606b0
Stack:
ffffffff81020b16 ffff8801da698000 0000000000000000 ffff8801da6a0000
dffffc0000000000 ffff8801da698000 ffff8801da69fdc8 ffffffff81022d50
ffff8801da69fde0 ffffffff811eb4c8 0000000000000000 ffff8801da69fea8
Call Trace:
[<ffffffff81022d50>] arch_cpu_idle+0x10/0x20 arch/x86/kernel/process.c:423
[<ffffffff811eb4c8>] default_idle_call+0x48/0x70 kernel/sched/idle.c:93
[<ffffffff811ebca1>] cpuidle_idle_call kernel/sched/idle.c:157 [inline]
[<ffffffff811ebca1>] cpu_idle_loop kernel/sched/idle.c:253 [inline]
[<ffffffff811ebca1>] cpu_startup_entry+0x6d1/0x810 kernel/sched/idle.c:301
[<ffffffff8108719d>] start_secondary+0x31d/0x410
arch/x86/kernel/smpboot.c:245
Code: 2e 0f 1f 84 00 00 00 00 00 fa c3 0f 1f 40 00 66 2e 0f 1f 84 00 00 00
00 00 fb c3 0f 1f 40 00 66 2e 0f 1f 84 00 00 00 00 00 fb f4 <c3> 0f 1f 00
66 2e 0f 1f 84 00 00 00 00 00 f4 c3 0f 1f 40 00 66

---
This bug 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 bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

[syzbot]

Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.