INFO: task hung in vfat_lookup

2 views
Skip to first unread message

syzbot

unread,
Aug 16, 2018, 10:30:03 AM8/16/18
to syzkaller-upst...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: 4e8b38549b50 Add linux-next specific files for 20180814
git tree: linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=16efeaaa400000
kernel config: https://syzkaller.appspot.com/x/.config?x=c7a15c9ae0895a59
dashboard link: https://syzkaller.appspot.com/bug?extid=9398b39d2dc6e465a470
compiler: gcc (GCC) 8.0.1 20180413 (experimental)
CC: [hiro...@mail.parknet.co.jp linux-...@vger.kernel.org]

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+9398b3...@syzkaller.appspotmail.com

syz-executor0(8760): getblk(): executed=9 bh_count=0 bh_state=0
syz-executor0(8760): getblk(): executed=9 bh_count=0 bh_state=0
syz-executor0(8760): getblk(): executed=9 bh_count=0 bh_state=0
syz-executor0(8760): getblk(): executed=9 bh_count=0 bh_state=0
syz-executor0(8760): getblk(): executed=9 bh_count=0 bh_state=0
INFO: task syz-executor0:7920 blocked for more than 140 seconds.
Not tainted 4.18.0-next-20180814+ #39
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor0 D22112 7920 1 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2825 [inline]
__schedule+0x87c/0x1df0 kernel/sched/core.c:3473
schedule+0xfb/0x450 kernel/sched/core.c:3517
schedule_preempt_disabled+0x10/0x20 kernel/sched/core.c:3575
__mutex_lock_common kernel/locking/mutex.c:1003 [inline]
__mutex_lock+0xbf9/0x1700 kernel/locking/mutex.c:1073
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1088
vfat_lookup+0xf1/0x640 fs/fat/namei_vfat.c:709
__lookup_slow+0x2b5/0x540 fs/namei.c:1671
lookup_slow+0x57/0x80 fs/namei.c:1688
walk_component+0x94a/0x2630 fs/namei.c:1810
link_path_walk.part.42+0xa6e/0x1540 fs/namei.c:2141
link_path_walk fs/namei.c:2072 [inline]
path_openat+0x268/0x5300 fs/namei.c:3533
do_filp_open+0x255/0x380 fs/namei.c:3564
do_sys_open+0x584/0x720 fs/open.c:1063
__do_sys_open fs/open.c:1081 [inline]
__se_sys_open fs/open.c:1076 [inline]
__x64_sys_open+0x7e/0xc0 fs/open.c:1076
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x455190
Code: 24 98 00 00 00 48 89 14 24 e8 dc ef ff ff 48 8b 44 24 10 48 8b 4c 24
08 48 8b 54 24 70 48 39 d0 0f 85 69 01 00 00 48 8b 9c 24 <10> 01 00 00 48
89 1c 24 48 89 54 24 08 48 89 4c 24 10 48 89 44 24
RSP: 002b:00007ffe40ba1510 EFLAGS: 00000202 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000455190
RDX: 0000000000000000 RSI: 0000000000090800 RDI: 00000000004c1d23
RBP: 0000000000000125 R08: 0000000000000001 R09: 0000000001a98940
R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000005
R13: 000000000004003a R14: 000000000000000d R15: badc0ffeebadface
INFO: task syz-executor0:8767 blocked for more than 140 seconds.
Not tainted 4.18.0-next-20180814+ #39
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor0 D23984 8767 7920 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2825 [inline]
__schedule+0x87c/0x1df0 kernel/sched/core.c:3473
schedule+0xfb/0x450 kernel/sched/core.c:3517
d_wait_lookup fs/dcache.c:2428 [inline]
d_alloc_parallel+0x1456/0x1eb0 fs/dcache.c:2510
__lookup_slow+0x1e6/0x540 fs/namei.c:1654
lookup_slow+0x57/0x80 fs/namei.c:1688
walk_component+0x94a/0x2630 fs/namei.c:1810
link_path_walk.part.42+0xa6e/0x1540 fs/namei.c:2141
link_path_walk fs/namei.c:2072 [inline]
path_openat+0x268/0x5300 fs/namei.c:3533
do_filp_open+0x255/0x380 fs/namei.c:3564
do_sys_open+0x584/0x720 fs/open.c:1063
__do_sys_open fs/open.c:1081 [inline]
__se_sys_open fs/open.c:1076 [inline]
__x64_sys_open+0x7e/0xc0 fs/open.c:1076
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x410dc1
Code: c7 84 24 80 00 00 00 00 00 00 00 48 c7 84 24 88 00 00 00 00 00 00 00
48 c7 84 24 90 00 00 00 00 00 00 00 48 8d 05 0f 5e 04 00 <48> 89 44 24 78
48 8d 44 24 50 48 89 84 24 80 00 00 00 48 8d 84 24
RSP: 002b:00007fedba4a3bb0 EFLAGS: 00000293 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 00007fedba4a46d4 RCX: 0000000000410dc1
RDX: 00007fedba4a3be8 RSI: 0000000000000002 RDI: 00007fedba4a3bd0
RBP: 0000000000930140 R08: 0000000000000000 R09: 0000000000000018
R10: 000000000000000d R11: 0000000000000293 R12: 00000000ffffffff
R13: 00000000004d6aa0 R14: 00000000004ca01f R15: 0000000000000001
INFO: task syz-executor0:8773 blocked for more than 140 seconds.
Not tainted 4.18.0-next-20180814+ #39
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor0 D23984 8773 7920 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2825 [inline]
__schedule+0x87c/0x1df0 kernel/sched/core.c:3473
syz-executor0(8760): getblk(): executed=9 bh_count=0 bh_state=0
schedule+0xfb/0x450 kernel/sched/core.c:3517
d_wait_lookup fs/dcache.c:2428 [inline]
d_alloc_parallel+0x1456/0x1eb0 fs/dcache.c:2510
__lookup_slow+0x1e6/0x540 fs/namei.c:1654
lookup_slow+0x57/0x80 fs/namei.c:1688
walk_component+0x94a/0x2630 fs/namei.c:1810
link_path_walk.part.42+0xa6e/0x1540 fs/namei.c:2141
link_path_walk fs/namei.c:2072 [inline]
path_openat+0x268/0x5300 fs/namei.c:3533
do_filp_open+0x255/0x380 fs/namei.c:3564
do_sys_open+0x584/0x720 fs/open.c:1063
__do_sys_open fs/open.c:1081 [inline]
__se_sys_open fs/open.c:1076 [inline]
__x64_sys_open+0x7e/0xc0 fs/open.c:1076
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x410dc1
Code: c7 84 24 80 00 00 00 00 00 00 00 48 c7 84 24 88 00 00 00 00 00 00 00
48 c7 84 24 90 00 00 00 00 00 00 00 48 8d 05 0f 5e 04 00 <48> 89 44 24 78
48 8d 44 24 50 48 89 84 24 80 00 00 00 48 8d 84 24
RSP: 002b:00007fedba482bb0 EFLAGS: 00000293 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 00007fedba4836d4 RCX: 0000000000410dc1
RDX: 00007fedba482be7 RSI: 0000000000000002 RDI: 00007fedba482bd0
RBP: 00000000009301e0 R08: 0000000000000000 R09: 0000000000000017
R10: 000000000000000c R11: 0000000000000293 R12: 00000000ffffffff
R13: 00000000004d6aa0 R14: 00000000004ca01f R15: 0000000000000002

Showing all locks held in the system:
1 lock held by khungtaskd/773:
#0: 000000003cad8bc4 (rcu_read_lock){....}, at:
debug_show_all_locks+0xd0/0x428 kernel/locking/lockdep.c:4436
1 lock held by rsyslogd/4252:
#0: 00000000b587cc9c (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x1bb/0x200
fs/file.c:766
2 locks held by getty/4342:
#0: 00000000558a8418 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000f1d7a2d7 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/4343:
#0: 00000000d17ccdaf (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000b3f7b3c1 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/4344:
#0: 0000000032e16e3d (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:353
#1: 0000000017054029 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/4345:
#0: 000000006e9e746d (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000f84cc53e (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/4346:
#0: 000000006e4e2eec (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000e21cd0df (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/4347:
#0: 00000000df353f35 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:353
#1: 0000000032f91962 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/4348:
#0: 000000001cce5cc2 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:353
#1: 0000000033723a2e (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by syz-executor0/7920:
#0: 00000000c7306e0b (&sb->s_type->i_mutex_key#20){++++}, at:
inode_lock_shared include/linux/fs.h:780 [inline]
#0: 00000000c7306e0b (&sb->s_type->i_mutex_key#20){++++}, at:
lookup_slow+0x49/0x80 fs/namei.c:1687
#1: 00000000a4a3e4cb (&sbi->s_lock){+.+.}, at: vfat_lookup+0xf1/0x640
fs/fat/namei_vfat.c:709
2 locks held by syz-executor0/8760:
1 lock held by syz-executor0/8767:
#0: 00000000c7306e0b (&sb->s_type->i_mutex_key#20){++++}, at:
inode_lock_shared include/linux/fs.h:780 [inline]
#0: 00000000c7306e0b (&sb->s_type->i_mutex_key#20){++++}, at:
lookup_slow+0x49/0x80 fs/namei.c:1687
1 lock held by syz-executor0/8773:
#0: 00000000c7306e0b (&sb->s_type->i_mutex_key#20){++++}, at:
inode_lock_shared include/linux/fs.h:780 [inline]
#0: 00000000c7306e0b (&sb->s_type->i_mutex_key#20){++++}, at:
lookup_slow+0x49/0x80 fs/namei.c:1687

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

NMI backtrace for cpu 1
CPU: 1 PID: 773 Comm: khungtaskd Not tainted 4.18.0-next-20180814+ #39
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1c9/0x2b4 lib/dump_stack.c:113
nmi_cpu_backtrace.cold.3+0x48/0x88 lib/nmi_backtrace.c:101
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:144 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:204 [inline]
watchdog+0xb39/0x1040 kernel/hung_task.c:265
kthread+0x35a/0x420 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 1 to CPUs 0:
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.531
msecs
NMI backtrace for cpu 0
CPU: 0 PID: 8760 Comm: syz-executor0 Not tainted 4.18.0-next-20180814+ #39
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
RIP: 0010:find_get_entry+0xafe/0x1120 mm/filemap.c:1433
Code: 29 f9 83 c1 54 c1 e9 03 f3 48 ab 4c 89 f0 48 8b 4d d0 65 48 33 0c 25
28 00 00 00 0f 85 30 05 00 00 48 8d 65 d8 5b 41 5c 41 5d <41> 5e 41 5f 5d
c3 e8 37 a5 e1 ff 49 8d 44 24 80 49 8d 7d 40 48 89
RSP: 0018:ffff8801bce765d8 EFLAGS: 00000246
RAX: 0000000000000000 RBX: ffff8801c92facd8 RCX: 0000000000000000
RDX: 1ffffffff0fe3665 RSI: 0000000000000003 RDI: ffffed00379cecb0
RBP: ffff8801bce765e8 R08: 1ffff100379cec27 R09: ffffed003b6046d6
R10: 0000000000000003 R11: 0000000000000002 R12: dffffc0000000000
R13: 0000000000000001 R14: 0000000000000000 R15: dffffc0000000000
FS: 00007fedba4c5700(0000) GS:ffff8801db000000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: ffffffffff600400 CR3: 00000001b71b6000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
pagecache_get_page+0x11e/0xe40 mm/filemap.c:1503
find_get_page_flags include/linux/pagemap.h:278 [inline]
__find_get_block_slow fs/buffer.c:206 [inline]
__find_get_block+0x5b1/0xdf0 fs/buffer.c:1326
__getblk_slow fs/buffer.c:1059 [inline]
__getblk_gfp+0x3dc/0xe00 fs/buffer.c:1352
__bread_gfp+0x2d/0x310 fs/buffer.c:1386
sb_bread include/linux/buffer_head.h:307 [inline]
fat__get_entry+0x59c/0xa30 fs/fat/dir.c:101
fat_get_entry fs/fat/dir.c:129 [inline]
fat_search_long+0x33b/0x15d0 fs/fat/dir.c:477
vfat_find+0x16d/0x1a0 fs/fat/namei_vfat.c:697
vfat_lookup+0x107/0x640 fs/fat/namei_vfat.c:711
__lookup_slow+0x2b5/0x540 fs/namei.c:1671
lookup_slow+0x57/0x80 fs/namei.c:1688
walk_component+0x94a/0x2630 fs/namei.c:1810
link_path_walk.part.42+0xa6e/0x1540 fs/namei.c:2141
link_path_walk fs/namei.c:2072 [inline]
path_openat+0x268/0x5300 fs/namei.c:3533
do_filp_open+0x255/0x380 fs/namei.c:3564
do_sys_open+0x584/0x720 fs/open.c:1063
__do_sys_open fs/open.c:1081 [inline]
__se_sys_open fs/open.c:1076 [inline]
__x64_sys_open+0x7e/0xc0 fs/open.c:1076
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x410dc1
Code: 75 14 b8 02 00 00 00 0f 05 48 3d 01 f0 ff ff 0f 83 b4 17 00 00 c3 48
83 ec 08 e8 8a fa ff ff 48 89 04 24 b8 02 00 00 00 0f 05 <48> 8b 3c 24 48
89 c2 e8 d3 fa ff ff 48 89 d0 48 83 c4 08 48 3d 01
RSP: 002b:00007fedba4c4bb0 EFLAGS: 00000293 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 00007fedba4c56d4 RCX: 0000000000410dc1
RDX: 00007fedba4c4be7 RSI: 0000000000000002 RDI: 00007fedba4c4bd0
RBP: 00000000009300a0 R08: 0000000000000000 R09: 0000000000000017
R10: 000000000000000c R11: 0000000000000293 R12: 00000000ffffffff
R13: 00000000004d6aa0 R14: 00000000004ca01f R15: 0000000000000000


---
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#bug-status-tracking for how to communicate with
syzbot.

Dmitry Vyukov

unread,
Sep 5, 2018, 7:18:42 AM9/5/18
to syzbot, 'Dmitry Vyukov' via syzkaller-upstream-moderation
#syz upstream
> --
> You received this message because you are subscribed to the Google Groups
> "syzkaller-upstream-moderation" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to syzkaller-upstream-m...@googlegroups.com.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/syzkaller-upstream-moderation/0000000000005e53b905738e472e%40google.com.
> For more options, visit https://groups.google.com/d/optout.
Reply all
Reply to author
Forward
0 new messages