syzbot


INFO: task hung in btrfs_sync_file

Status: closed as invalid on 2023/02/08 16:28
Subsystems: btrfs
[Documentation on labels]
First crash: 538d, last: 523d
Cause bisection: failed (error log, bisect log)
  
Similar bugs (2)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in btrfs_sync_file (2) btrfs C error 5 412d 408d 23/27 fixed on 2023/09/28 17:51
upstream INFO: task hung in btrfs_sync_file (3) btrfs 1 180d 180d 0/27 auto-obsoleted due to no activity on 2024/04/15 09:26

Sample crash report:
INFO: task syz-executor356:5650 blocked for more than 143 seconds.
      Not tainted 6.2.0-rc7-syzkaller-00002-gd2d11f342b17 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor356 state:D stack:23784 pid:5650  ppid:5130   flags:0x00004004
Call Trace:
 <TASK>
 __schedule+0x13ca/0x43c0
 schedule+0xc3/0x190
 rwsem_down_write_slowpath+0xfb5/0x1490
 btrfs_inode_lock+0xc5/0xd0
 btrfs_sync_file+0x487/0x1220
 btrfs_do_write_iter+0xccc/0x1270
 vfs_write+0x7dd/0xc50
 ksys_write+0x17c/0x2a0
 do_syscall_64+0x41/0xc0
 entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fd86db499f9
RSP: 002b:00007fd86daf52f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007fd86dbd37a0 RCX: 00007fd86db499f9
RDX: 0000000000000090 RSI: 0000000020000000 RDI: 0000000000000006
RBP: 00007fd86dba01d0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 61635f65646f6e69
R13: 65646f7475616f6e R14: 7261637369646f6e R15: 00007fd86dbd37a8
 </TASK>
INFO: task syz-executor356:5695 blocked for more than 143 seconds.
      Not tainted 6.2.0-rc7-syzkaller-00002-gd2d11f342b17 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor356 state:D stack:24584 pid:5695  ppid:5130   flags:0x00004004
Call Trace:
 <TASK>
 __schedule+0x13ca/0x43c0
 schedule+0xc3/0x190
 wait_extent_bit+0x50c/0x6a0
 lock_extent+0x1bb/0x270
 btrfs_page_mkwrite+0x536/0xc90
 do_page_mkwrite+0x1a1/0x600
 do_wp_page+0x506/0x3270
 handle_mm_fault+0x2388/0x51c0
 exc_page_fault+0x66a/0x880
 asm_exc_page_fault+0x26/0x30
RIP: 0010:copy_user_short_string+0xd/0x40
Code: 74 0a 89 d1 f3 a4 89 c8 0f 01 ca c3 89 d0 0f 01 ca c3 01 ca eb e7 0f 1f 80 00 00 00 00 89 d1 83 e2 07 c1 e9 03 74 12 4c 8b 06 <4c> 89 07 48 8d 76 08 48 8d 7f 08 ff c9 75 ee 21 d2 74 10 89 d1 8a
RSP: 0000:ffffc900046ef330 EFLAGS: 00050202
RAX: ffffffff8435f301 RBX: 00007fffffffefc8 RCX: 0000000000000007
RDX: 0000000000000000 RSI: ffffc900046ef3e0 RDI: 0000000020000120
RBP: ffffc900046ef488 R08: 0000000000000000 R09: fffff520008dde83
R10: 0000000000000000 R11: dffffc0000000001 R12: 0000000000000038
R13: ffffc900046ef3e0 R14: 0000000020000120 R15: ffffc900046ef3e0
 _copy_to_user+0xed/0x130
 fiemap_fill_next_extent+0x235/0x410
 emit_fiemap_extent+0x242/0x3f0
 fiemap_process_hole+0xa71/0xb40
 extent_fiemap+0xe42/0x2100
 btrfs_fiemap+0x178/0x1e0
 do_vfs_ioctl+0x194f/0x2a40
 __se_sys_ioctl+0x81/0x160
 do_syscall_64+0x41/0xc0
 entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fd86db499f9
RSP: 002b:00007fd8666d42f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fd86dbd37b0 RCX: 00007fd86db499f9
RDX: 0000000020000100 RSI: 00000000c020660b RDI: 0000000000000005
RBP: 00007fd86dba01d0 R08: 00007fd8666d4700 R09: 0000000000000000
R10: 00007fd8666d4700 R11: 0000000000000246 R12: 61635f65646f6e69
R13: 65646f7475616f6e R14: 7261637369646f6e R15: 00007fd86dbd37b8
 </TASK>
INFO: task kworker/u4:5:5669 blocked for more than 144 seconds.
      Not tainted 6.2.0-rc7-syzkaller-00002-gd2d11f342b17 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/u4:5    state:D stack:24448 pid:5669  ppid:2      flags:0x00004000
Workqueue: btrfs-endio-write btrfs_work_helper
Call Trace:
 <TASK>
 __schedule+0x13ca/0x43c0
 schedule+0xc3/0x190
 wait_extent_bit+0x50c/0x6a0
 lock_extent+0x1bb/0x270
 btrfs_finish_ordered_io+0x5de/0x1c50
 btrfs_work_helper+0x43a/0xe90
 process_one_work+0x96c/0x13e0
 worker_thread+0xa63/0x1210
 kthread+0x270/0x300
 ret_from_fork+0x1f/0x30
 </TASK>

Showing all locks held in the system:
1 lock held by rcu_tasks_kthre/12:
 #0: ffffffff8cf26e10 (rcu_tasks.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x26/0xce0
1 lock held by rcu_tasks_trace/13:
 #0: ffffffff8cf27610 (rcu_tasks_trace.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x26/0xce0
1 lock held by khungtaskd/28:
 #0: ffffffff8cf26c40 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
2 locks held by getty/4755:
 #0: ffff888027f3c098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x25/0x70
 #1: ffffc900015a02f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x53b/0x1630
4 locks held by syz-executor356/5650:
 #0: ffff88802945c868 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x254/0x2f0
 #1: ffff888077258460 (sb_writers#9){.+.+}-{0:0}, at: vfs_write+0x27f/0xc50
 #2: ffff888072cf3600 (&sb->s_type->i_mutex_key#15){++++}-{3:3}, at: btrfs_inode_lock+0x4d/0xd0
 #3: ffff888072cf3488 (&ei->i_mmap_lock){++++}-{3:3}, at: btrfs_inode_lock+0xc5/0xd0
3 locks held by syz-executor356/5695:
 #0: ffff8880295b8a18 (&mm->mmap_lock){++++}-{3:3}, at: exc_page_fault+0x18d/0x880
 #1: ffff888077258558 (sb_pagefaults){.+.+}-{0:0}, at: do_page_mkwrite+0x1a1/0x600
 #2: ffff888072cf3488 (&ei->i_mmap_lock){++++}-{3:3}, at: btrfs_page_mkwrite+0x416/0xc90
3 locks held by kworker/u4:5/5669:
 #0: ffff88807eb1d938 ((wq_completion)btrfs-endio-write){+.+.}-{0:0}, at: process_one_work+0x7eb/0x13e0
 #1: ffffc90004c7fd20 ((work_completion)(&work->normal_work)){+.+.}-{0:0}, at: process_one_work+0x835/0x13e0
 #2: ffff88801d1ee430 (btrfs_ordered_extent){++++}-{0:0}, at: btrfs_finish_ordered_io+0x33b/0x1c50
2 locks held by syz-executor356/7919:
1 lock held by syz-executor356/7920:
3 locks held by syz-executor356/7924:
2 locks held by syz-executor356/7926:

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

NMI backtrace for cpu 0
CPU: 0 PID: 28 Comm: khungtaskd Not tainted 6.2.0-rc7-syzkaller-00002-gd2d11f342b17 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/12/2023
Call Trace:
 <TASK>
 dump_stack_lvl+0x1b5/0x2a0
 nmi_cpu_backtrace+0x47b/0x500
 nmi_trigger_cpumask_backtrace+0x1d3/0x430
 watchdog+0xf70/0xfb0
 kthread+0x270/0x300
 ret_from_fork+0x1f/0x30
 </TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 7920 Comm: syz-executor356 Not tainted 6.2.0-rc7-syzkaller-00002-gd2d11f342b17 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/12/2023
RIP: 0010:debug_lockdep_rcu_enabled+0x0/0x30
Code: fd 18 c1 03 00 75 e7 48 c7 c7 c0 85 ea 8a 48 c7 c6 e0 a9 ea 8a e8 b0 29 bc f6 0f 0b eb d0 66 2e 0f 1f 84 00 00 00 00 00 66 90 <f3> 0f 1e fa 31 c0 83 3d 43 e5 c0 03 00 74 1d 83 3d be 18 c1 03 00
RSP: 0018:ffffc9000b67f4f8 EFLAGS: 00000a06
RAX: f3f3f300f1f1f1f1 RBX: 1ffff920016cfea0 RCX: ffffffff81d242d9
RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffffffff8e56d8a8
RBP: ffffc9000b67f588 R08: dffffc0000000000 R09: fffffbfff1cadb16
R10: 0000000000000000 R11: dffffc0000000001 R12: ffffea0001c60a48
R13: ffffea0001c60a40 R14: dffffc0000000000 R15: dffffc0000000000
FS:  00007fd86daf5700(0000) GS:ffff8880b9900000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fd86daf6000 CR3: 000000001d923000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <TASK>
 rcu_read_lock_sched_held+0x61/0x110
 free_unref_page_prepare+0xe4/0x1040
 free_unref_page_list+0x6b1/0x950
 release_pages+0x2196/0x2470
 __pagevec_release+0x84/0x100
 shmem_undo_range+0x698/0x1db0
 shmem_evict_inode+0x263/0x9d0
 evict+0x2a4/0x620
 __dentry_kill+0x436/0x650
 dentry_kill+0xbb/0x290
 dput+0x1d8/0x3f0
 __fput+0x5e4/0x890
 task_work_run+0x24a/0x300
 exit_to_user_mode_loop+0xd1/0xf0
 exit_to_user_mode_prepare+0xb1/0x140
 syscall_exit_to_user_mode+0x54/0x2d0
 do_syscall_64+0x4d/0xc0
 entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fd86db498b7
Code: 3c 1c 48 f7 d8 49 39 c4 72 b8 e8 b4 5d 02 00 85 c0 78 bd 48 83 c4 08 4c 89 e0 5b 41 5c c3 0f 1f 44 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fd86daf5168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: 0000000000000000 RBX: 0000000000000011 RCX: 00007fd86db498b7
RDX: 0000000000000000 RSI: 0000000000004c01 RDI: 0000000000000004
RBP: 0000000000000004 R08: 00007fd86daf51c0 R09: 00000000000050e9
R10: 0000000000000000 R11: 0000000000000246 R12: 00007fd86daf56b8
R13: 00007fd86daf5180 R14: 00007fd86daf51c0 R15: 0000000000000000
 </TASK>
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.095 msecs

Crashes (2):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2023/02/06 20:55 upstream d2d11f342b17 0a9c11b6 .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-upstream-fs INFO: task hung in btrfs_sync_file
2023/01/22 19:29 upstream 2241ab53cbb5 cc0f9968 .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in btrfs_sync_file
* Struck through repros no longer work on HEAD.