INFO: task hung in fuse

INFO: task hung in fuse_lookup (3)
Status: upstream: reported C repro on 2019/08/14 09:48
Reported-by: syzbot+b64df836ad08c8e31a47@syzkaller.appspotmail.com
First crash: 735d, last: 51d

Cause bisection: the issue happens on the oldest tested release (bisect log)
Crash: INFO: task hung in lookup_slow (log)
Repro: C syz .config

Fix bisection: failed (bisect log)

similar bugs (6):
Kernel	Title	Repro	Fix bisect	Count	Last	Reported	Patched	Status
linux-4.14	INFO: task hung in fuse_lookup			4	522d	675d	0/1	auto-closed as invalid on 2020/01/29 21:30
linux-4.19	INFO: task hung in fuse_lookup	C	error	4	355d	570d	0/1	upstream: reported C repro on 2019/08/14 05:24
linux-4.14	INFO: task hung in fuse_lookup (2)			1	356d	356d	0/1	auto-closed as invalid on 2020/07/13 23:30
upstream	INFO: task hung in fuse_lookup			16	915d	966d	0/21	closed as invalid on 2018/09/05 12:51
android-49	INFO: task hung in fuse_lookup	C		112	484d	695d	0/3	public: reported C repro on 2019/04/11 08:44
upstream	INFO: task hung in fuse_lookup (2)	C		13	748d	908d	0/21	closed as dup on 2018/09/10 08:43

Sample crash report:

INFO: task cron:9900 blocked for more than 143 seconds.
      Not tainted 5.3.0-rc4+ #108
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
cron            D25064  9900      1 0x00000000
Call Trace:
 context_switch kernel/sched/core.c:3254 [inline]
 __schedule+0x755/0x1580 kernel/sched/core.c:3880
 schedule+0xa8/0x270 kernel/sched/core.c:3944
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:4003
 __mutex_lock_common kernel/locking/mutex.c:1007 [inline]
 __mutex_lock+0x7b0/0x13c0 kernel/locking/mutex.c:1077
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1092
 fuse_lock_inode+0xba/0xf0 fs/fuse/inode.c:362
 fuse_lookup+0x8e/0x360 fs/fuse/dir.c:335
 __lookup_slow+0x279/0x500 fs/namei.c:1669
 lookup_slow+0x58/0x80 fs/namei.c:1686
 walk_component+0x747/0x2000 fs/namei.c:1808
 link_path_walk.part.0+0x9a4/0x1340 fs/namei.c:2139
 link_path_walk fs/namei.c:2267 [inline]
 path_lookupat.isra.0+0xe3/0x8d0 fs/namei.c:2315
 filename_lookup+0x1b0/0x410 fs/namei.c:2346
 user_path_at_empty+0x43/0x50 fs/namei.c:2606
 user_path_at include/linux/namei.h:60 [inline]
 vfs_statx+0x129/0x200 fs/stat.c:187
 vfs_stat include/linux/fs.h:3188 [inline]
 __do_sys_newstat+0xa4/0x130 fs/stat.c:341
 __se_sys_newstat fs/stat.c:337 [inline]
 __x64_sys_newstat+0x54/0x80 fs/stat.c:337
 do_syscall_64+0xfd/0x6a0 arch/x86/entry/common.c:296
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7f5beb7e8c65
Code: Bad RIP value.
RSP: 002b:00007fffecf5a5c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000004
RAX: ffffffffffffffda RBX: 00007f5beb866aa4 RCX: 00007f5beb7e8c65
RDX: 00007fffecf5a610 RSI: 00007fffecf5a610 RDI: 00007f5beb866aa4
RBP: 00007fffecf5a710 R08: 0000000001013240 R09: 0000000000000000
R10: 0000000000000008 R11: 0000000000000246 R12: 0000000000000000
R13: 0000000000000001 R14: 000000000000002f R15: 0000000000000000
INFO: task syz-executor385:9979 blocked for more than 143 seconds.
      Not tainted 5.3.0-rc4+ #108
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor385 D28336  9979   9977 0x00000000
Call Trace:
 context_switch kernel/sched/core.c:3254 [inline]
 __schedule+0x755/0x1580 kernel/sched/core.c:3880
 schedule+0xa8/0x270 kernel/sched/core.c:3944
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:4003
 __mutex_lock_common kernel/locking/mutex.c:1007 [inline]
 __mutex_lock+0x7b0/0x13c0 kernel/locking/mutex.c:1077
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1092
 fuse_lock_inode+0xba/0xf0 fs/fuse/inode.c:362
 fuse_lookup+0x8e/0x360 fs/fuse/dir.c:335
 __lookup_slow+0x279/0x500 fs/namei.c:1669
 lookup_slow+0x58/0x80 fs/namei.c:1686
 walk_component+0x747/0x2000 fs/namei.c:1808
 link_path_walk.part.0+0x9a4/0x1340 fs/namei.c:2139
 link_path_walk fs/namei.c:2070 [inline]
 path_openat+0x202/0x4630 fs/namei.c:3532
 do_filp_open+0x1a1/0x280 fs/namei.c:3563
 do_sys_open+0x3fe/0x5d0 fs/open.c:1089
 __do_sys_open fs/open.c:1107 [inline]
 __se_sys_open fs/open.c:1102 [inline]
 __x64_sys_open+0x7e/0xc0 fs/open.c:1102
 do_syscall_64+0xfd/0x6a0 arch/x86/entry/common.c:296
 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:00007ffd34cf7ce0 EFLAGS: 00000202 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000444ca0
RDX: 0000000000000000 RSI: 0000000000090800 RDI: 00000000004ae91e
RBP: 0000000000002700 R08: 00000000000026fb R09: 00005555557cf880
R10: 0000000000000000 R11: 0000000000000202 R12: 00007ffd34cf7f10
R13: 00000000004075d0 R14: 0000000000000000 R15: 0000000000000000
INFO: task syz-executor385:9984 blocked for more than 144 seconds.
      Not tainted 5.3.0-rc4+ #108
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor385 D28336  9984   9979 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:3254 [inline]
 __schedule+0x755/0x1580 kernel/sched/core.c:3880
 schedule+0xa8/0x270 kernel/sched/core.c:3944
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:4003
 __mutex_lock_common kernel/locking/mutex.c:1007 [inline]
 __mutex_lock+0x7b0/0x13c0 kernel/locking/mutex.c:1077
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1092
 fuse_lock_inode+0xba/0xf0 fs/fuse/inode.c:362
 fuse_lookup+0x8e/0x360 fs/fuse/dir.c:335
 __lookup_slow+0x279/0x500 fs/namei.c:1669
 lookup_slow+0x58/0x80 fs/namei.c:1686
 walk_component+0x747/0x2000 fs/namei.c:1808
 link_path_walk.part.0+0x9a4/0x1340 fs/namei.c:2139
 link_path_walk fs/namei.c:2070 [inline]
 path_openat+0x202/0x4630 fs/namei.c:3532
 do_filp_open+0x1a1/0x280 fs/namei.c:3563
 do_sys_open+0x3fe/0x5d0 fs/open.c:1089
 __do_sys_open fs/open.c:1107 [inline]
 __se_sys_open fs/open.c:1102 [inline]
 __x64_sys_open+0x7e/0xc0 fs/open.c:1102
 do_syscall_64+0xfd/0x6a0 arch/x86/entry/common.c:296
 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:00007ffd34cf79e8 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 00007ffd34cf7a14 RCX: 0000000000405810
RDX: 00007ffd34cf7a1a RSI: 0000000000080001 RDI: 00000000004ae93c
RBP: 00007ffd34cf7a10 R08: 0000000000000000 R09: 0000000000000004
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000407540
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
INFO: lockdep is turned off.
NMI backtrace for cpu 1
CPU: 1 PID: 1057 Comm: khungtaskd Not tainted 5.3.0-rc4+ #108
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+0x70/0xb2 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x23b/0x28b 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:205 [inline]
 watchdog+0x9d0/0xef0 kernel/hung_task.c:289
 kthread+0x361/0x430 kernel/kthread.c:255
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
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

Crashes (16):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro	C repro	VM info
ci-upstream-kasan-gce-root	2019/08/14 05:38	upstream	ee1c7bd3	ef801a3e	.config	log	report	syz	C
ci-upstream-kasan-gce-smack-root	2019/08/14 04:14	upstream	ee1c7bd3	ef801a3e	.config	log	report	syz	C
ci-upstream-kasan-gce-selinux-root	2019/08/14 02:35	upstream	ee1c7bd3	ef801a3e	.config	log	report	syz	C
ci-upstream-kasan-gce-selinux-root	2021/01/14 21:40	upstream	65f0d241	65a7a854	.config	log	report			info
ci-upstream-kasan-gce-root	2021/01/14 21:29	upstream	65f0d241	65a7a854	.config	log	report			info
ci-upstream-kasan-gce	2021/01/14 21:28	upstream	65f0d241	65a7a854	.config	log	report			info
ci-upstream-kasan-gce-selinux-root	2020/02/23 06:34	upstream	54dedb5b	2c36e7a7	.config	log	report
ci-upstream-kasan-gce-selinux-root	2019/04/05 20:58	upstream	ea2cec24	40f2363e	.config	log	report
ci-upstream-kasan-gce-root	2019/03/25 12:04	upstream	8c2ffd91	2c86e0a5	.config	log	report
ci-upstream-kasan-gce-root	2019/03/22 15:25	upstream	0939221e	dce6e62f	.config	log	report
ci-upstream-kasan-gce-selinux-root	2019/03/20 03:42	upstream	b7a42146	2458c1c6	.config	log	report
ci-upstream-kasan-gce-selinux-root	2019/03/19 17:14	upstream	9e98c678	e4549234	.config	log	report
ci-upstream-kasan-gce-root	2019/03/18 18:47	upstream	9e98c678	4656beca	.config	log	report
ci-upstream-kasan-gce-selinux-root	2019/03/02 20:03	upstream	c93d9218	1c0e457a	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/12/23 21:57	linux-next	7ddd09fc	be5c2c81	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/03/17 04:58	linux-next	cf08baa2	bab43553	.config	log	report