syzbot


INFO: task hung in lookup_slow

Status: upstream: reported C repro on 2022/08/03 08:46
Reported-by: syzbot+d5e7a229ac2648cdeed7@syzkaller.appspotmail.com
First crash: 604d, last: 574d
Fix bisection: failed (error log, bisect log)
  
Similar bugs (6)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in lookup_slow (2) fs 2 1675d 1687d 0/26 auto-closed as invalid on 2019/11/26 02:54
upstream INFO: task hung in lookup_slow exfat 148 1896d 2189d 0/26 closed as dup on 2018/09/08 15:36
upstream INFO: task hung in lookup_slow (3) exfat C unreliable 45 8d10h 504d 0/26 upstream: reported C repro on 2022/11/11 00:21
android-49 INFO: task hung in lookup_slow syz 36 1701d 1811d 0/3 public: reported syz repro on 2019/04/14 08:51
linux-4.19 INFO: task hung in lookup_slow 1 1383d 1383d 0/1 auto-closed as invalid on 2020/10/13 00:17
linux-5.15 INFO: task hung in lookup_slow 2 347d 352d 0/3 auto-obsoleted due to no activity on 2023/08/15 05:05
Last patch testing requests (1)
Created Duration User Patch Repo Result
2023/03/07 02:32 0m retest repro linux-4.14.y error OK
Fix bisection attempts (2)
Created Duration User Patch Repo Result
2022/10/13 02:15 0m bisect fix linux-4.14.y error job log (0)
2022/09/02 08:59 26m bisect fix linux-4.14.y job log (0) log

Sample crash report:
Bluetooth: hci0 command 0x0409 tx timeout
Bluetooth: hci0 command 0x041b tx timeout
Bluetooth: hci0 command 0x040f tx timeout
Bluetooth: hci0 command 0x0419 tx timeout
Bluetooth: hci0 command 0x0406 tx timeout
INFO: task syz-executor254:7999 blocked for more than 140 seconds.
      Not tainted 4.14.290-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor254 D25736  7999   7998 0x00000000
Call Trace:
 context_switch kernel/sched/core.c:2811 [inline]
 __schedule+0x88b/0x1de0 kernel/sched/core.c:3387
 schedule+0x8d/0x1b0 kernel/sched/core.c:3431
 __rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:292 [inline]
 rwsem_down_read_failed+0x1e6/0x350 kernel/locking/rwsem-xadd.c:309
 call_rwsem_down_read_failed+0x14/0x30 arch/x86/lib/rwsem.S:94
 __down_read arch/x86/include/asm/rwsem.h:66 [inline]
 down_read+0x44/0x80 kernel/locking/rwsem.c:26
 inode_lock_shared include/linux/fs.h:729 [inline]
 lookup_slow+0x129/0x400 fs/namei.c:1674
 walk_component+0x6a1/0xbc0 fs/namei.c:1825
 link_path_walk+0x823/0x10a0 fs/namei.c:2154
 path_openat+0x15e/0x2970 fs/namei.c:3568
 do_filp_open+0x179/0x3c0 fs/namei.c:3603
 do_sys_open+0x296/0x410 fs/open.c:1081
 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x7f724210e288
RSP: 002b:00007ffd09739130 EFLAGS: 00000287 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007ffd097391a0 RCX: 00007f724210e288
RDX: 0000000000090800 RSI: 00007f7242164004 RDI: 00000000ffffff9c
RBP: 0000000000000003 R08: 0000000000090800 R09: 00007f7242164004
R10: 0000000000000000 R11: 0000000000000287 R12: 00007ffd09739320
R13: 0000000000000003 R14: 00007ffd09739390 R15: 00007ffd09739380
INFO: task syz-executor254:8036 blocked for more than 140 seconds.
      Not tainted 4.14.290-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor254 D27928  8036   7999 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2811 [inline]
 __schedule+0x88b/0x1de0 kernel/sched/core.c:3387
 schedule+0x8d/0x1b0 kernel/sched/core.c:3431
 request_wait_answer+0x30d/0x620 fs/fuse/dev.c:478
 __fuse_request_send+0x108/0x1a0 fs/fuse/dev.c:498
 fuse_request_send fs/fuse/dev.c:511 [inline]
 fuse_simple_request+0x2fa/0x790 fs/fuse/dev.c:569
 fuse_lookup_name+0x228/0x550 fs/fuse/dir.c:330
 fuse_lookup+0x102/0x3e0 fs/fuse/dir.c:371
 lookup_slow+0x20a/0x400 fs/namei.c:1696
 walk_component+0x6a1/0xbc0 fs/namei.c:1825
 link_path_walk+0x823/0x10a0 fs/namei.c:2154
 path_openat+0x15e/0x2970 fs/namei.c:3568
 do_filp_open+0x179/0x3c0 fs/namei.c:3603
 do_sys_open+0x296/0x410 fs/open.c:1081
 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x7f724210e6c9
RSP: 002b:00007f72418bd2f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007f72421994c0 RCX: 00007f724210e6c9
RDX: 0000000000000042 RSI: 0000000020002080 RDI: ffffffffffffff9c
RBP: 00007f72421662f4 R08: 0000000000000065 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000065
R13: 00007f7242166318 R14: 31f4000000000002 R15: 00007f72421994c8
INFO: task syz-executor254:8039 blocked for more than 140 seconds.
      Not tainted 4.14.290-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor254 D29312  8039   7999 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2811 [inline]
 __schedule+0x88b/0x1de0 kernel/sched/core.c:3387
 schedule+0x8d/0x1b0 kernel/sched/core.c:3431
 __rwsem_down_write_failed_common kernel/locking/rwsem-xadd.c:588 [inline]
 rwsem_down_write_failed+0x343/0x6d0 kernel/locking/rwsem-xadd.c:617
 call_rwsem_down_write_failed+0x13/0x20 arch/x86/lib/rwsem.S:105
 __down_write arch/x86/include/asm/rwsem.h:126 [inline]
 down_write_nested+0x51/0x90 kernel/locking/rwsem.c:174
 inode_lock_nested include/linux/fs.h:754 [inline]
 fuse_reverse_inval_entry+0x9e/0x5f0 fs/fuse/dir.c:990
 fuse_notify_delete fs/fuse/dev.c:1594 [inline]
 fuse_notify fs/fuse/dev.c:1828 [inline]
 fuse_dev_do_write+0x1f22/0x25c0 fs/fuse/dev.c:1903
 fuse_dev_write+0x125/0x1a0 fs/fuse/dev.c:1987
 call_write_iter include/linux/fs.h:1780 [inline]
 new_sync_write fs/read_write.c:469 [inline]
 __vfs_write+0x44c/0x630 fs/read_write.c:482
 vfs_write+0x17f/0x4d0 fs/read_write.c:544
 SYSC_write fs/read_write.c:590 [inline]
 SyS_write+0xf2/0x210 fs/read_write.c:582
 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x7f724210e6c9
RSP: 002b:00007f724189c2f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f72421994d0 RCX: 00007f724210e6c9
RDX: 000000000000002c RSI: 00000000200000c0 RDI: 0000000000000003
RBP: 00007f72421662f4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000003
R13: 00007f7242166318 R14: 31f4000000000002 R15: 00007f72421994d8

Showing all locks held in the system:
1 lock held by khungtaskd/1533:
 #0:  (tasklist_lock){.+.+}, at: [<ffffffff8701eaf9>] debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4548
1 lock held by in:imklog/7690:
 #0:  (&f->f_pos_lock){+.+.}, at: [<ffffffff818d727b>] __fdget_pos+0x1fb/0x2b0 fs/file.c:819
1 lock held by syz-executor254/7999:
 #0:  (&type->i_mutex_dir_key#7){++++}, at: [<ffffffff81891559>] inode_lock_shared include/linux/fs.h:729 [inline]
 #0:  (&type->i_mutex_dir_key#7){++++}, at: [<ffffffff81891559>] lookup_slow+0x129/0x400 fs/namei.c:1674
2 locks held by syz-executor254/8036:
 #0:  (&type->i_mutex_dir_key#7){++++}, at: [<ffffffff81891559>] inode_lock_shared include/linux/fs.h:729 [inline]
 #0:  (&type->i_mutex_dir_key#7){++++}, at: [<ffffffff81891559>] lookup_slow+0x129/0x400 fs/namei.c:1674
 #1:  (&fi->mutex){+.+.}, at: [<ffffffff823057e0>] fuse_lock_inode+0xb0/0xe0 fs/fuse/inode.c:365
2 locks held by syz-executor254/8039:
 #0:  (&fc->killsb){.+.+}, at: [<ffffffff822dbb57>] fuse_notify_delete fs/fuse/dev.c:1591 [inline]
 #0:  (&fc->killsb){.+.+}, at: [<ffffffff822dbb57>] fuse_notify fs/fuse/dev.c:1828 [inline]
 #0:  (&fc->killsb){.+.+}, at: [<ffffffff822dbb57>] fuse_dev_do_write+0x1ec7/0x25c0 fs/fuse/dev.c:1903
 #1:  (&type->i_mutex_dir_key#7/1){+.+.}, at: [<ffffffff822e70ae>] inode_lock_nested include/linux/fs.h:754 [inline]
 #1:  (&type->i_mutex_dir_key#7/1){+.+.}, at: [<ffffffff822e70ae>] fuse_reverse_inval_entry+0x9e/0x5f0 fs/fuse/dir.c:990

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

NMI backtrace for cpu 0
CPU: 0 PID: 1533 Comm: khungtaskd Not tainted 4.14.290-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 07/22/2022
Call Trace:
 __dump_stack lib/dump_stack.c:17 [inline]
 dump_stack+0x1b2/0x281 lib/dump_stack.c:58
 nmi_cpu_backtrace.cold+0x57/0x93 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x13a/0x180 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:140 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline]
 watchdog+0x5b9/0xb40 kernel/hung_task.c:274
 kthread+0x30d/0x420 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at pc 0xffffffff8723f20e

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2022/08/03 08:46 linux-4.14.y b641242202ed 1c9013ac .config console log report syz C ci2-linux-4-14 INFO: task hung in lookup_slow
* Struck through repros no longer work on HEAD.