INFO: task hung in fuse_lookup (2)

12 views
Skip to first unread message

syzbot

unread,
Sep 10, 2018, 3:41:07 AM9/10/18
to syzkaller-upst...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: d7b686ebf704 Merge branch 'i2c/for-current' of git://git.k..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=173b7056400000
kernel config: https://syzkaller.appspot.com/x/.config?x=8f59875069d721b6
dashboard link: https://syzkaller.appspot.com/bug?extid=1f2de7c1f418ee2aafd2
compiler: gcc (GCC) 8.0.1 20180413 (experimental)
CC: [linux-...@vger.kernel.org linux-...@vger.kernel.org
mik...@szeredi.hu]

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+1f2de7...@syzkaller.appspotmail.com

ALSA: seq fatal error: cannot create timer (-19)
ALSA: seq fatal error: cannot create timer (-19)
INFO: task syz-executor7:5574 blocked for more than 140 seconds.
Not tainted 4.19.0-rc2+ #7
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor7 D18936 5574 1 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2825 [inline]
__schedule+0x86c/0x1ed0 kernel/sched/core.c:3473
schedule+0xfe/0x460 kernel/sched/core.c:3517
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3575
__mutex_lock_common kernel/locking/mutex.c:1003 [inline]
__mutex_lock+0xbfb/0x1710 kernel/locking/mutex.c:1073
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1088
fuse_lock_inode+0xba/0xf0 fs/fuse/inode.c:365
fuse_lookup+0x8f/0x4c0 fs/fuse/dir.c:360
__lookup_slow+0x2b5/0x540 fs/namei.c:1671
lookup_slow+0x57/0x80 fs/namei.c:1688
walk_component+0x92b/0x25c0 fs/namei.c:1810
link_path_walk.part.40+0xa61/0x1530 fs/namei.c:2141
link_path_walk fs/namei.c:2072 [inline]
path_openat+0x270/0x5160 fs/namei.c:3533
do_filp_open+0x255/0x380 fs/namei.c:3564
do_sys_open+0x568/0x700 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:0x4551a0
Code: 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 18 e8 74 6d 00 00 0f b6 44 24 20 84 c0 0f 84 3c
RSP: 002b:00007fffa1249ba0 EFLAGS: 00000206 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00000000004551a0
RDX: 0000000000000000 RSI: 0000000000090800 RDI: 00000000004c2058
RBP: 0000000000001186 R08: 0000000000000001 R09: 0000000002881940
R10: 0000000000000000 R11: 0000000000000206 R12: 000000000000000b
R13: 0000000000116b91 R14: 00000000000004e1 R15: badc0ffeebadface
INFO: task syz-executor7:8618 blocked for more than 140 seconds.
Not tainted 4.19.0-rc2+ #7
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor7 D22856 8618 5574 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2825 [inline]
__schedule+0x86c/0x1ed0 kernel/sched/core.c:3473
schedule+0xfe/0x460 kernel/sched/core.c:3517
request_wait_answer+0x4a6/0x900 fs/fuse/dev.c:474
__fuse_request_send+0x12a/0x1d0 fs/fuse/dev.c:494
fuse_request_send+0x62/0xa0 fs/fuse/dev.c:507
fuse_simple_request+0x33d/0x730 fs/fuse/dev.c:565
fuse_lookup_name+0x3ee/0x830 fs/fuse/dir.c:323
fuse_lookup+0xff/0x4c0 fs/fuse/dir.c:361
__lookup_slow+0x2b5/0x540 fs/namei.c:1671
lookup_slow+0x57/0x80 fs/namei.c:1688
walk_component+0x92b/0x25c0 fs/namei.c:1810
link_path_walk.part.40+0xa61/0x1530 fs/namei.c:2141
link_path_walk fs/namei.c:2072 [inline]
path_openat+0x270/0x5160 fs/namei.c:3533
do_filp_open+0x255/0x380 fs/namei.c:3564
do_sys_open+0x568/0x700 fs/open.c:1063
__do_sys_openat fs/open.c:1090 [inline]
__se_sys_openat fs/open.c:1084 [inline]
__x64_sys_openat+0x9d/0x100 fs/open.c:1084
do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x457099
Code: 48 8b 54 24 38 48 8b 7c 24 48 eb 8d 48 8b 6c 24 50 48 83 c4 58 c3 48
89 04 24 48 89 5c 24 08 e8 fd a8 fb ff 48 8b 44 24 40 48 <8b> 4c 24 48 48
8b 54 24 38 4c 8b 54 24 18 e9 ee fe ff ff 48 89 74
RSP: 002b:00007f40998b0c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007f40998b16d4 RCX: 0000000000457099
RDX: 0000000000000800 RSI: 0000000020000080 RDI: ffffffffffffff9c
RBP: 0000000000930140 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 00000000004d3798 R14: 00000000004c8497 R15: 0000000000000001

Showing all locks held in the system:
1 lock held by khungtaskd/984:
#0: 00000000f58f0266 (rcu_read_lock){....}, at:
debug_show_all_locks+0xd0/0x424 kernel/locking/lockdep.c:4436
1 lock held by rsyslogd/5406:
2 locks held by getty/5528:
#0: 000000002e9ff0a7 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000326d9a85 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5529:
#0: 00000000fab1da6b (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000204915df (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5530:
#0: 0000000026c61428 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000004ed6ed57 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5531:
#0: 00000000d6b5d92c (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000e6372749 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5532:
#0: 000000000c205f17 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000002c64dd81 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5533:
#0: 000000000de831e4 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000009b6d6120 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5534:
#0: 00000000271291cf (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000a53002f4 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by syz-executor7/5574:
#0: 000000001e9d1ee9 (&type->i_mutex_dir_key#4){++++}, at:
inode_lock_shared include/linux/fs.h:748 [inline]
#0: 000000001e9d1ee9 (&type->i_mutex_dir_key#4){++++}, at:
lookup_slow+0x49/0x80 fs/namei.c:1687
#1: 00000000e304b51c (&fi->mutex){+.+.}, at: fuse_lock_inode+0xba/0xf0
fs/fuse/inode.c:365
2 locks held by syz-executor5/3920:
#0: 00000000d34599c1 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000e6b752e0 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
1 lock held by syz-executor3/6342:
#0: 00000000fd02cb57 (&rp->fetch_lock){+.+.}, at: mon_bin_read+0x60/0x640
drivers/usb/mon/mon_bin.c:813
2 locks held by syz-executor7/8618:
#0: 000000001e9d1ee9 (&type->i_mutex_dir_key#4){++++}, at:
inode_lock_shared include/linux/fs.h:748 [inline]
#0: 000000001e9d1ee9 (&type->i_mutex_dir_key#4){++++}, at:
lookup_slow+0x49/0x80 fs/namei.c:1687
#1: 00000000e304b51c (&fi->mutex){+.+.}, at: fuse_lock_inode+0xba/0xf0
fs/fuse/inode.c:365

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

NMI backtrace for cpu 0
CPU: 0 PID: 984 Comm: khungtaskd Not tainted 4.19.0-rc2+ #7
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+0x1c4/0x2b4 lib/dump_stack.c:113
nmi_cpu_backtrace.cold.3+0x63/0xa2 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1b3/0x1ed 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+0xb3e/0x1050 kernel/hung_task.c:265
kthread+0x35a/0x420 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:413
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at native_safe_halt+0x6/0x10
arch/x86/include/asm/irqflags.h:57


---
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.

syzbot

unread,
Sep 10, 2018, 4:43:07 AM9/10/18
to Tetsuo Handa, penguin...@i-love.sakura.ne.jp, syzkaller-upst...@googlegroups.com
> PID=5574 was stuck at fuse_lookup() because it was waiting for
> PID=8618 to unlock fi->mutex.

> 2 locks held by syz-executor7/5574:
> #0: 000000001e9d1ee9 (&type->i_mutex_dir_key#4){++++}, at:
> lookup_slow+0x49/0x80
> #1: 00000000e304b51c (&fi->mutex){+.+.}, at: fuse_lock_inode+0xba/0xf0
> 2 locks held by syz-executor7/8618:
> #0: 000000001e9d1ee9 (&type->i_mutex_dir_key#4){++++}, at:
> lookup_slow+0x49/0x80
> #1: 00000000e304b51c (&fi->mutex){+.+.}, at: fuse_lock_inode+0xba/0xf0

> Since PID=8618 was stuck at fuse_request_send(), let's mark as

> #syz dup: INFO: task hung in __fuse_request_send

Your 'dup:' command is accepted, but please keep
syzkaller-upst...@googlegroups.com mailing list in CC next
time. It serves as a history of what happened with each bug report. Thank
you.

Reply all
Reply to author
Forward
0 new messages