INFO: task hung in filename_create

[syzbot]

Hello,

syzbot hit the following crash on upstream commit
87ef12027b9b1dd0e0b12cf311fbcb19f9d92539 (Wed Apr 18 19:48:17 2018 +0000)
Merge tag 'ceph-for-4.17-rc2' of git://github.com/ceph/ceph-client
syzbot dashboard link:
https://syzkaller.appspot.com/bug?extid=1ae8dbd46c20b9d1a051

Unfortunately, I don't have any reproducer for this crash yet.
Raw console output:
https://syzkaller.appspot.com/x/log.txt?id=6528738372091904
Kernel config:
https://syzkaller.appspot.com/x/.config?id=-5914490758943236750
compiler: gcc (GCC) 8.0.1 20180413 (experimental)
CC: [linux-...@vger.kernel.org linux-...@vger.kernel.org
vi...@zeniv.linux.org.uk]

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+1ae8db...@syzkaller.appspotmail.com
It will help syzbot understand when the bug is fixed. See footer for
details.
If you forward the report, please keep this part and the footer.

device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
INFO: task syz-executor0:7707 blocked for more than 120 seconds.
Not tainted 4.17.0-rc1+ #7
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor0 D25896 7707 4579 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2848 [inline]
__schedule+0x801/0x1e30 kernel/sched/core.c:3490
b_state=0x00000029, b_size=512
schedule+0xef/0x430 kernel/sched/core.c:3549
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
__rwsem_down_write_failed_common+0x919/0x15d0
kernel/locking/rwsem-xadd.c:566
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
rwsem_down_write_failed+0xe/0x10 kernel/locking/rwsem-xadd.c:595
b_state=0x00000029, b_size=512
call_rwsem_down_write_failed+0x17/0x30 arch/x86/lib/rwsem.S:117
__down_write arch/x86/include/asm/rwsem.h:142 [inline]
down_write_nested+0xa6/0x120 kernel/locking/rwsem.c:193
device loop0 blocksize: 4096
inode_lock_nested include/linux/fs.h:748 [inline]
filename_create+0x1aa/0x5a0 fs/namei.c:3606
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
user_path_create fs/namei.c:3664 [inline]
do_mkdirat+0xd2/0x2f0 fs/namei.c:3802
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__do_sys_mkdir fs/namei.c:3826 [inline]
__se_sys_mkdir fs/namei.c:3824 [inline]
__x64_sys_mkdir+0x5c/0x80 fs/namei.c:3824
__find_get_block_slow() failed. block=1, b_blocknr=8
do_syscall_64+0x1b1/0x800 arch/x86/entry/common.c:287
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x455329
__find_get_block_slow() failed. block=1, b_blocknr=8
RSP: 002b:00007fa047b6ac68 EFLAGS: 00000246 ORIG_RAX: 0000000000000053
RAX: ffffffffffffffda RBX: 00007fa047b6b6d4 RCX: 0000000000455329
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020000080
RBP: 000000000072bf58 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
__find_get_block_slow() failed. block=1, b_blocknr=8
R13: 00000000000003eb R14: 00000000006f8ea8 R15: 0000000000000001

Showing all locks held in the system:
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
2 locks held by khungtaskd/889:
__find_get_block_slow() failed. block=1, b_blocknr=8
#0: 000000005a755549 (
b_state=0x00000029, b_size=512
rcu_read_lock){....}, at: check_hung_uninterruptible_tasks
kernel/hung_task.c:175 [inline]
rcu_read_lock){....}, at: watchdog+0x1ff/0xf60 kernel/hung_task.c:249
#1:
device loop0 blocksize: 4096
000000001826b538 (tasklist_lock){.+.+}
__find_get_block_slow() failed. block=1, b_blocknr=8
, at: debug_show_all_locks+0xde/0x34a kernel/locking/lockdep.c:4470
1 lock held by rsyslogd/4410:
b_state=0x00000029, b_size=512
#0: 00000000098dc5c3 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x1a9/0x1e0
fs/file.c:766
2 locks held by getty/4500:
device loop0 blocksize: 4096
#0: 000000009e1b82ce (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 000000009677209b
__find_get_block_slow() failed. block=1, b_blocknr=8
(&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x321/0x1cc0
drivers/tty/n_tty.c:2131
2 locks held by getty/4501:
b_state=0x00000029, b_size=512
#0: 0000000051d303ef (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1:
device loop0 blocksize: 4096
00000000de1d16c3 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4502:
#0: 00000000e037a2c4 (
__find_get_block_slow() failed. block=1, b_blocknr=8
&tty->ldisc_sem){++++}, at: ldsem_down_read+0x37/0x40
drivers/tty/tty_ldsem.c:365
#1:
b_state=0x00000029, b_size=512
00000000c85664e1 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4503:
device loop0 blocksize: 4096
#0: 000000004cd6d5cb (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
__find_get_block_slow() failed. block=1, b_blocknr=8
#1: 000000003dbbcec3 (&ldata->atomic_read_lock
b_state=0x00000029, b_size=512
){+.+.}, at: n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4504:
device loop0 blocksize: 4096
#0: 000000001304a854 (
__find_get_block_slow() failed. block=1, b_blocknr=8
&tty->ldisc_sem){++++}, at: ldsem_down_read+0x37/0x40
drivers/tty/tty_ldsem.c:365
#1:
b_state=0x00000029, b_size=512
0000000074a8f5c8 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4505:
device loop0 blocksize: 4096
#0: 0000000046b231bd (&tty->ldisc_sem
__find_get_block_slow() failed. block=1, b_blocknr=8
){++++}, at: ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1:
b_state=0x00000029, b_size=512
000000008ad96e3a (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4506:
device loop0 blocksize: 4096
#0: 00000000e9641bc4 (&tty->ldisc_sem
__find_get_block_slow() failed. block=1, b_blocknr=8
){++++}, at: ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1:
b_state=0x00000029, b_size=512
00000000118ea9b8 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by syz-executor0/7707:
device loop0 blocksize: 4096
#0: 00000000a54a2243 (sb_writers
__find_get_block_slow() failed. block=1, b_blocknr=8
#16){.+.+}, at: sb_start_write include/linux/fs.h:1550 [inline]
#16){.+.+}, at: mnt_want_write+0x3f/0xc0 fs/namespace.c:386
#1:
b_state=0x00000029, b_size=512
0000000031db7a55 (&sb->s_type->i_mutex_key#19/1){+.+.}, at:
inode_lock_nested include/linux/fs.h:748 [inline]
0000000031db7a55 (&sb->s_type->i_mutex_key#19/1){+.+.}, at:
filename_create+0x1aa/0x5a0 fs/namei.c:3606
device loop0 blocksize: 4096
2 locks held by syz-executor0/7710:
#0: 00000000a54a2243
__find_get_block_slow() failed. block=1, b_blocknr=8
(sb_writers#16){.+.+}, at: sb_start_write include/linux/fs.h:1550 [inline]
(sb_writers#16){.+.+}, at: mnt_want_write+0x3f/0xc0 fs/namespace.c:386
b_state=0x00000029, b_size=512
#1: 0000000031db7a55 (&sb->s_type->i_mutex_key#19){+.+.}, at: inode_lock
include/linux/fs.h:713 [inline]
#1: 0000000031db7a55 (&sb->s_type->i_mutex_key#19){+.+.}, at: do_last
fs/namei.c:3274 [inline]
#1: 0000000031db7a55 (&sb->s_type->i_mutex_key#19){+.+.}, at:
path_openat+0x123b/0x4e20 fs/namei.c:3501

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

NMI backtrace for cpu 1
device loop0 blocksize: 4096
CPU: 1 PID: 889 Comm: khungtaskd Not tainted 4.17.0-rc1+ #7
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
__find_get_block_slow() failed. block=1, b_blocknr=8
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1b9/0x294 lib/dump_stack.c:113
nmi_cpu_backtrace.cold.4+0x19/0xce lib/nmi_backtrace.c:103
b_state=0x00000029, b_size=512
nmi_trigger_cpumask_backtrace+0x151/0x192 lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_all_cpu_backtrace include/linux/nmi.h:138 [inline]
check_hung_task kernel/hung_task.c:132 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:190 [inline]
watchdog+0xc10/0xf60 kernel/hung_task.c:249
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
kthread+0x345/0x410 kernel/kthread.c:238
device loop0 blocksize: 4096
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:412
Sending NMI from CPU 1 to CPUs 0:
__find_get_block_slow() failed. block=1, b_blocknr=8
NMI backtrace for cpu 0
CPU: 0 PID: 7628 Comm: syz-executor0 Not tainted 4.17.0-rc1+ #7
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
RIP: 0010:__wrmsr arch/x86/include/asm/msr.h:105 [inline]
RIP: 0010:native_write_msr+0xa/0x30 arch/x86/include/asm/msr.h:162
RSP: 0018:ffff8801db007d48 EFLAGS: 00000046
RAX: 000000000000e3c2 RBX: 0000000000000838 RCX: 0000000000000838
RDX: 0000000000000000 RSI: 000000000000e3c2 RDI: 0000000000000838
RBP: ffff8801db007d48 R08: ffff88018b5f85c0 R09: 0000000000000000
R10: ffffed0043fff001 R11: ffff88021fff8017 R12: 000000000000e3c2
R13: 0000000000000000 R14: 0000000000000000 R15: ffff8801db025c00
FS: 00007fa047b8c700(0000) GS:ffff8801db000000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f6db4c6f000 CR3: 000000018c60d000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<IRQ>
paravirt_write_msr arch/x86/include/asm/paravirt.h:117 [inline]
native_apic_msr_write+0x5b/0x80 arch/x86/include/asm/apic.h:208
apic_write arch/x86/include/asm/apic.h:396 [inline]
lapic_next_event+0x5a/0x90 arch/x86/kernel/apic/apic.c:460
clockevents_program_event+0x251/0x370 kernel/time/clockevents.c:344
tick_program_event+0xab/0x130 kernel/time/tick-oneshot.c:48
hrtimer_interrupt+0x2db/0x650 kernel/time/hrtimer.c:1519
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1025 [inline]
smp_apic_timer_interrupt+0x15d/0x710 arch/x86/kernel/apic/apic.c:1050
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:863
</IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:783
[inline]
RIP: 0010:console_trylock_spinning kernel/printk/printk.c:1678 [inline]
RIP: 0010:vprintk_emit+0xbd0/0xdd0 kernel/printk/printk.c:1906
RSP: 0018:ffff88018b566ca8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
RAX: 0000000000040000 RBX: 0000000000000200 RCX: ffffc90001ed0000
RDX: 0000000000040000 RSI: ffffffff8160bbb7 RDI: 0000000000000246
RBP: ffff88018b566e38 R08: ffff88018b5f8df8 R09: 0000000000000006
R10: ffff88018b5f85c0 R11: 0000000000000000 R12: 1ffffffff116312d
R13: 0000000000000034 R14: ffffed00316acdb2 R15: ffffffff8a49a360
vprintk_default+0x28/0x30 kernel/printk/printk.c:1947
vprintk_func+0x7a/0xe7 kernel/printk/printk_safe.c:379
printk+0x9e/0xba kernel/printk/printk.c:1980
__find_get_block_slow fs/buffer.c:231 [inline]
__find_get_block.cold.58+0x3a/0x103 fs/buffer.c:1287
__getblk_slow fs/buffer.c:1032 [inline]
__getblk_gfp+0x2a1/0xaf0 fs/buffer.c:1313
__bread_gfp+0x2d/0x310 fs/buffer.c:1347
sb_bread include/linux/buffer_head.h:309 [inline]
fat__get_entry+0x594/0xa20 fs/fat/dir.c:101
fat_get_entry fs/fat/dir.c:129 [inline]
fat_get_short_entry+0x13c/0x2c0 fs/fat/dir.c:876
fat_scan+0x111/0x340 fs/fat/dir.c:961
msdos_find+0x10e/0x320 fs/fat/namei_msdos.c:129
msdos_lookup+0x134/0x300 fs/fat/namei_msdos.c:209
lookup_open+0x71d/0x1b40 fs/namei.c:3165
do_last fs/namei.c:3277 [inline]
path_openat+0x1268/0x4e20 fs/namei.c:3501
do_filp_open+0x249/0x350 fs/namei.c:3535
do_sys_open+0x56f/0x740 fs/open.c:1093
__do_sys_open fs/open.c:1111 [inline]
__se_sys_open fs/open.c:1106 [inline]
__x64_sys_open+0x7e/0xc0 fs/open.c:1106
do_syscall_64+0x1b1/0x800 arch/x86/entry/common.c:287
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x455329
RSP: 002b:00007fa047b8bc68 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 00007fa047b8c6d4 RCX: 0000000000455329
RDX: 0000000000000000 RSI: 0800000000002040 RDI: 0000000020000300
RBP: 000000000072bea0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000415 R14: 00000000006f9298 R15: 0000000000000000
Code: c0 5d c3 0f 21 c8 5d c3 0f 21 d0 5d c3 0f 21 d8 5d c3 0f 21 f0 5d c3
0f 0b 0f 1f 84 00 00 00 00 00 55 89 f9 89 f0 48 89 e5 0f 30 <0f> 1f 44 00
00 5d c3 48 c1 e2 20 89 f6 48 09 d6 31 d2 e8 6f d2
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.147
msecs


---
This bug is generated by a dumb bot. It may contain errors.
See https://goo.gl/tpsmEJ for details.
Direct all questions to syzk...@googlegroups.com.

syzbot will keep track of this bug report.
If you forgot to add the Reported-by tag, once the fix for this bug is
merged
into any tree, please reply to this email with:
#syz fix: exact-commit-title
To mark this as a duplicate of another syzbot report, please reply with:
#syz dup: exact-subject-of-another-report
If it's a one-off invalid bug report, please reply with:
#syz invalid
Note: if the crash happens again, it will cause creation of a new bug
report.
Note: all commands must start from beginning of the line in the email body.
To upstream this report, please reply with:
#syz upstream