INFO: task hung in fuse_lookup

10 views
Skip to first unread message

syzbot

unread,
Aug 14, 2019, 1:24:05 AM8/14/19
to syzkaller...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: 893af1c7 Linux 4.19.66
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=11a729ba600000
kernel config: https://syzkaller.appspot.com/x/.config?x=d5fac5a8617b8643
dashboard link: https://syzkaller.appspot.com/bug?extid=f8b3822507e83905193d
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=113192a6600000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=14f4031c600000

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

audit: type=1400 audit(1565756259.473:37): avc: denied { map } for
pid=7814 comm="syz-executor292" path="/root/syz-executor292550793"
dev="sda1" ino=1426 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1
INFO: task cron:7712 blocked for more than 140 seconds.
Not tainted 4.19.66 #40
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
cron D25112 7712 1 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x866/0x1dc0 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3576
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x726/0x1300 kernel/locking/mutex.c:1072
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
fuse_lock_inode+0xba/0xf0 fs/fuse/inode.c:365
fuse_lookup+0x8e/0x3e0 fs/fuse/dir.c:360
__lookup_slow+0x279/0x500 fs/namei.c:1671
lookup_slow+0x58/0x80 fs/namei.c:1688
walk_component+0x747/0x2000 fs/namei.c:1810
link_path_walk.part.0+0x980/0x1330 fs/namei.c:2141
link_path_walk fs/namei.c:2269 [inline]
path_lookupat.isra.0+0xe3/0x8d0 fs/namei.c:2317
filename_lookup+0x1b0/0x410 fs/namei.c:2348
user_path_at_empty+0x43/0x50 fs/namei.c:2608
user_path_at include/linux/namei.h:57 [inline]
vfs_statx+0x129/0x200 fs/stat.c:185
vfs_stat include/linux/fs.h:3128 [inline]
__do_sys_newstat+0xa4/0x130 fs/stat.c:337
__se_sys_newstat fs/stat.c:333 [inline]
__x64_sys_newstat+0x54/0x80 fs/stat.c:333
do_syscall_64+0xfd/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7f3fc84fdc65
Code: Bad RIP value.
RSP: 002b:00007ffff4f24648 EFLAGS: 00000246 ORIG_RAX: 0000000000000004
RAX: ffffffffffffffda RBX: 00007f3fc857baa4 RCX: 00007f3fc84fdc65
RDX: 00007ffff4f24690 RSI: 00007ffff4f24690 RDI: 00007f3fc857baa4
RBP: 00007ffff4f24790 R08: 0000000000661710 R09: 00000000000007e3
R10: 0000000000000008 R11: 0000000000000246 R12: 0000000000000000
R13: 0000000000000001 R14: 000000000000002f R15: 0000000000000000
INFO: task syz-executor292:7814 blocked for more than 140 seconds.
Not tainted 4.19.66 #40
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor292 D27704 7814 7812 0x00000000
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x866/0x1dc0 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3576
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x726/0x1300 kernel/locking/mutex.c:1072
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
fuse_lock_inode+0xba/0xf0 fs/fuse/inode.c:365
fuse_lookup+0x8e/0x3e0 fs/fuse/dir.c:360
__lookup_slow+0x279/0x500 fs/namei.c:1671
lookup_slow+0x58/0x80 fs/namei.c:1688
walk_component+0x747/0x2000 fs/namei.c:1810
link_path_walk.part.0+0x980/0x1330 fs/namei.c:2141
link_path_walk fs/namei.c:2072 [inline]
path_openat+0x1f9/0x45e0 fs/namei.c:3533
do_filp_open+0x1a1/0x280 fs/namei.c:3564
do_sys_open+0x3fe/0x550 fs/open.c:1088
__do_sys_open fs/open.c:1106 [inline]
__se_sys_open fs/open.c:1101 [inline]
__x64_sys_open+0x7e/0xc0 fs/open.c:1101
do_syscall_64+0xfd/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x444ca0
Code: 31 c0 e9 45 ff ff ff 0f 1f 00 80 3f 00 0f 84 f7 00 00 00 55 53 b9 02
00 00 00 be 00 08 09 00 89 c8 48 81 ec 98 00 00 00 0f 05 <48> 3d 00 f0 ff
ff 48 89 c3 0f 87 e9 00 00 00 85 db 0f 88 2f 01 00
RSP: 002b:00007ffc6065eb20 EFLAGS: 00000202 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000444ca0
RDX: 0000000000000000 RSI: 0000000000090800 RDI: 00000000004ae91e
RBP: 0000000000001e8b R08: 0000000000001e86 R09: 0000000001f43880
R10: 0000000000000000 R11: 0000000000000202 R12: 00007ffc6065ed50
R13: 00000000004075d0 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor292:7819 blocked for more than 140 seconds.
Not tainted 4.19.66 #40
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor292 D28184 7819 7814 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x866/0x1dc0 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3576
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x726/0x1300 kernel/locking/mutex.c:1072
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
fuse_lock_inode+0xba/0xf0 fs/fuse/inode.c:365
fuse_lookup+0x8e/0x3e0 fs/fuse/dir.c:360
__lookup_slow+0x279/0x500 fs/namei.c:1671
lookup_slow+0x58/0x80 fs/namei.c:1688
walk_component+0x747/0x2000 fs/namei.c:1810
link_path_walk.part.0+0x980/0x1330 fs/namei.c:2141
link_path_walk fs/namei.c:2072 [inline]
path_openat+0x1f9/0x45e0 fs/namei.c:3533
do_filp_open+0x1a1/0x280 fs/namei.c:3564
do_sys_open+0x3fe/0x550 fs/open.c:1088
__do_sys_open fs/open.c:1106 [inline]
__se_sys_open fs/open.c:1101 [inline]
__x64_sys_open+0x7e/0xc0 fs/open.c:1101
do_syscall_64+0xfd/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x405810
Code: 01 f0 ff ff 0f 83 d0 18 00 00 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f
44 00 00 83 3d 1d c3 2d 00 00 75 14 b8 02 00 00 00 0f 05 <48> 3d 01 f0 ff
ff 0f 83 a4 18 00 00 c3 48 83 ec 08 e8 0a fc ff ff
RSP: 002b:00007ffc6065e828 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 00007ffc6065e854 RCX: 0000000000405810
RDX: 00007ffc6065e85a RSI: 0000000000080001 RDI: 00000000004ae93c
RBP: 00007ffc6065e850 R08: 0000000000000000 R09: 0000000000000004
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000407540
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000

Showing all locks held in the system:
2 locks held by init/1:
#0: 000000001b3d7020 (&type->i_mutex_dir_key#6){++++}, at:
inode_lock_shared include/linux/fs.h:757 [inline]
#0: 000000001b3d7020 (&type->i_mutex_dir_key#6){++++}, at:
lookup_slow+0x4a/0x80 fs/namei.c:1687
#1: 00000000ccfabe77 (&fi->mutex){+.+.}, at: fuse_lock_inode+0xba/0xf0
fs/fuse/inode.c:365
1 lock held by khungtaskd/1037:
#0: 00000000b22edb8e (rcu_read_lock){....}, at:
debug_show_all_locks+0x5f/0x27e kernel/locking/lockdep.c:4435
1 lock held by rsyslogd/7664:
2 locks held by cron/7712:
#0: 000000001b3d7020 (&type->i_mutex_dir_key#6){++++}, at:
inode_lock_shared include/linux/fs.h:757 [inline]
#0: 000000001b3d7020 (&type->i_mutex_dir_key#6){++++}, at:
lookup_slow+0x4a/0x80 fs/namei.c:1687
#1: 00000000ccfabe77 (&fi->mutex){+.+.}, at: fuse_lock_inode+0xba/0xf0
fs/fuse/inode.c:365
2 locks held by getty/7786:
#0: 00000000a2f2e947 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 000000006d811bbe (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7787:
#0: 0000000064c399c2 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000fb4e40d5 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7788:
#0: 00000000afa2650e (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 000000002978798e (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7789:
#0: 00000000651cb44a (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 0000000080c7054e (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7790:
#0: 000000008b211ebe (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000c220a5c8 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7791:
#0: 0000000024cfc970 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 000000007fdc011b (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7792:
#0: 0000000051798e85 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 0000000021a17fcb (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by syz-executor292/7814:
#0: 000000001b3d7020 (&type->i_mutex_dir_key#6){++++}, at:
inode_lock_shared include/linux/fs.h:757 [inline]
#0: 000000001b3d7020 (&type->i_mutex_dir_key#6){++++}, at:
lookup_slow+0x4a/0x80 fs/namei.c:1687
#1: 00000000ccfabe77 (&fi->mutex){+.+.}, at: fuse_lock_inode+0xba/0xf0
fs/fuse/inode.c:365
2 locks held by syz-executor292/7819:
#0: 000000001b3d7020 (&type->i_mutex_dir_key#6){++++}, at:
inode_lock_shared include/linux/fs.h:757 [inline]
#0: 000000001b3d7020 (&type->i_mutex_dir_key#6){++++}, at:
lookup_slow+0x4a/0x80 fs/namei.c:1687
#1: 00000000ccfabe77 (&fi->mutex){+.+.}, at: fuse_lock_inode+0xba/0xf0
fs/fuse/inode.c:365

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

NMI backtrace for cpu 1
CPU: 1 PID: 1037 Comm: khungtaskd Not tainted 4.19.66 #40
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+0x172/0x1f0 lib/dump_stack.c:113
nmi_cpu_backtrace.cold+0x63/0xa4 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1b0/0x1f8 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:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
watchdog+0x9df/0xee0 kernel/hung_task.c:287
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0 skipped: idling at native_safe_halt+0xe/0x10
arch/x86/include/asm/irqflags.h:60


---
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
Reply all
Reply to author
Forward
0 new messages