syzbot


INFO: task hung in btrfs_alloc_tree_block

Status: upstream: reported C repro on 2022/12/23 05:53
Subsystems: btrfs
[Documentation on labels]
Reported-by: syzbot+160fb6436674c067e775@syzkaller.appspotmail.com
First crash: 729d, last: 688d
Fix bisection: failed (error log, bisect log)
  

Sample crash report:
R10: 000000000000fec0 R11: 0000000000000246 R12: 0000000000000004
R13: 00007ffc993d6030 R14: 00007ffc993d6010 R15: 0000000000000001
BTRFS error (device loop0): tree block 5259264 owner 5 already locked by pid=8140, extent tree corruption detected
INFO: task syz-executor253:8102 blocked for more than 140 seconds.
      Not tainted 4.19.211-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor253 D25680  8102   8100 0x00000000
Call Trace:
 context_switch kernel/sched/core.c:2828 [inline]
 __schedule+0x887/0x2040 kernel/sched/core.c:3517
 schedule+0x8d/0x1b0 kernel/sched/core.c:3561
 btrfs_tree_lock+0x4fe/0x810 fs/btrfs/locking.c:233
 btrfs_init_new_buffer fs/btrfs/extent-tree.c:8145 [inline]
 btrfs_alloc_tree_block+0x9b1/0x15f0 fs/btrfs/extent-tree.c:8284
 alloc_tree_block_no_bg_flush+0x1b6/0x250 fs/btrfs/ctree.c:1039
 __btrfs_cow_block+0x3c7/0x10a0 fs/btrfs/ctree.c:1094
 btrfs_cow_block+0x276/0x840 fs/btrfs/ctree.c:1557
 btrfs_search_slot+0x66a/0x1ee0 fs/btrfs/ctree.c:2881
 btrfs_insert_empty_items+0xba/0x180 fs/btrfs/ctree.c:4910
 btrfs_insert_empty_item fs/btrfs/ctree.h:2923 [inline]
 alloc_reserved_tree_block fs/btrfs/extent-tree.c:8000 [inline]
 run_delayed_tree_ref fs/btrfs/extent-tree.c:2334 [inline]
 run_one_delayed_ref fs/btrfs/extent-tree.c:2364 [inline]
 __btrfs_run_delayed_refs+0x1fad/0x3de0 fs/btrfs/extent-tree.c:2638
 btrfs_run_delayed_refs.part.0+0x9a/0x310 fs/btrfs/extent-tree.c:2936
 btrfs_run_delayed_refs+0xad/0xf0 fs/btrfs/extent-tree.c:2925
 btrfs_commit_transaction+0x173/0x2480 fs/btrfs/transaction.c:1972
 btrfs_sync_fs+0x120/0x490 fs/btrfs/super.c:1279
 __sync_filesystem fs/sync.c:39 [inline]
 sync_filesystem+0x1b5/0x250 fs/sync.c:67
 generic_shutdown_super+0x70/0x370 fs/super.c:442
 kill_anon_super+0x36/0x60 fs/super.c:1032
 btrfs_kill_super+0x49/0x550 fs/btrfs/super.c:2221
 deactivate_locked_super+0x94/0x160 fs/super.c:329
 deactivate_super+0x174/0x1a0 fs/super.c:360
 cleanup_mnt+0x1a8/0x290 fs/namespace.c:1098
 task_work_run+0x148/0x1c0 kernel/task_work.c:113
 tracehook_notify_resume include/linux/tracehook.h:193 [inline]
 exit_to_usermode_loop+0x251/0x2a0 arch/x86/entry/common.c:167
 prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
 do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fd3db397df7
Code: Bad RIP value.
RSP: 002b:00007ffc993d4ed8 EFLAGS: 00000206 ORIG_RAX: 00000000000000a6
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007fd3db397df7
RDX: 00007ffc993d4f97 RSI: 000000000000000a RDI: 00007ffc993d4f90
RBP: 00007ffc993d4f90 R08: 00000000ffffffff R09: 00007ffc993d4d70
R10: 0000555555c85683 R11: 0000000000000206 R12: 00007ffc993d6010
R13: 0000555555c855f0 R14: 00007ffc993d4f00 R15: 0000000000000002

Showing all locks held in the system:
1 lock held by khungtaskd/1570:
 #0: 0000000070bdc9ca (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x265 kernel/locking/lockdep.c:4441
3 locks held by in:imklog/7797:
 #0: 00000000ec8c370c (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x26f/0x310 fs/file.c:767
 #1: 00000000fd3dbf45 (fs_reclaim){+.+.}, at: syslog_print kernel/printk/printk.c:1345 [inline]
 #1: 00000000fd3dbf45 (fs_reclaim){+.+.}, at: do_syslog.part.0+0x2d5/0x1510 kernel/printk/printk.c:1505
 #2: 0000000070bdc9ca (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
 #2: 0000000070bdc9ca (rcu_read_lock){....}, at: update_curr+0x2c3/0x870 kernel/sched/fair.c:857
2 locks held by syz-executor253/8102:
 #0: 0000000068c68263 (&type->s_umount_key#47){+.+.}, at: deactivate_super+0x16c/0x1a0 fs/super.c:359
 #1: 000000000b6553f1 (&head_ref->mutex){+.+.}, at: btrfs_delayed_ref_lock+0x91/0x1f0 fs/btrfs/delayed-ref.c:207
2 locks held by btrfs-transacti/8168:
 #0: 00000000c92e5705 (&fs_info->transaction_kthread_mutex){+.+.}, at: transaction_kthread+0xfa/0x490 fs/btrfs/disk-io.c:1765
 #1: 0000000036a48dbd (&head_ref->mutex){+.+.}, at: btrfs_delayed_ref_lock+0x91/0x1f0 fs/btrfs/delayed-ref.c:207

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

NMI backtrace for cpu 0
CPU: 0 PID: 1570 Comm: khungtaskd Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1fc/0x2ef lib/dump_stack.c:118
 nmi_cpu_backtrace.cold+0x63/0xa2 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x1a6/0x1f0 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
 watchdog+0x991/0xe60 kernel/hung_task.c:287
 kthread+0x33f/0x460 kernel/kthread.c:259
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 4678 Comm: systemd-journal Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
RIP: 0010:__sanitizer_cov_trace_pc+0x22/0x50 kernel/kcov.c:101
Code: 90 90 90 90 90 90 90 90 48 8b 34 24 65 48 8b 04 25 c0 df 01 00 65 8b 15 cc 59 9f 7e 81 e2 00 01 1f 00 75 2b 8b 90 60 13 00 00 <83> fa 02 75 20 48 8b 88 68 13 00 00 8b 80 64 13 00 00 48 8b 11 48
RSP: 0018:ffff8880a1a97f20 EFLAGS: 00000246
RAX: ffff8880a1a88200 RBX: 0000000000000053 RCX: 1ffff11014352ff5
RDX: 0000000000000000 RSI: ffffffff81007741 RDI: ffff8880a1a97fa8
RBP: ffff8880a1a97f58 R08: 0000000000000000 R09: fffffffffffff000
R10: 0000000000000007 R11: 0000000000000000 R12: 0000000000000100
R13: ffffffff89f18298 R14: 0000000000000000 R15: 0000000000000000
FS:  00007fe45d9a88c0(0000) GS:ffff8880ba100000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fe45ad88020 CR3: 00000000a209b000 CR4: 00000000003406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 get_current arch/x86/include/asm/current.h:15 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:252 [inline]
 do_syscall_64+0x121/0x620 arch/x86/entry/common.c:296
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fe45cc63687
Code: 00 b8 ff ff ff ff c3 0f 1f 40 00 48 8b 05 09 d8 2b 00 64 c7 00 5f 00 00 00 b8 ff ff ff ff c3 0f 1f 40 00 b8 53 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d e1 d7 2b 00 f7 d8 64 89 01 48
RSP: 002b:00007fff0ab21318 EFLAGS: 00000293 ORIG_RAX: 0000000000000053
RAX: fffffffffffffffe RBX: 00007fff0ab24230 RCX: 00007fe45cc63687
RDX: 00007fe45d6d4a00 RSI: 00000000000001ed RDI: 0000559356e208a0
RBP: 00007fff0ab21350 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000069 R11: 0000000000000293 R12: 0000000000000000
R13: 0000000000000000 R14: 00007fff0ab24230 R15: 00007fff0ab21840

Crashes (7):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2023/01/03 23:02 linux-4.19.y 3f8a27f9e27b f0036e18 .config console log report syz C [disk image] [vmlinux] [mounted in repro] ci2-linux-4-19 INFO: task hung in btrfs_alloc_tree_block
2022/12/31 16:23 linux-4.19.y 3f8a27f9e27b ab32d508 .config console log report syz C [disk image] [vmlinux] [mounted in repro] ci2-linux-4-19 INFO: task hung in btrfs_alloc_tree_block
2023/02/02 08:43 linux-4.19.y 3f8a27f9e27b 9a6f477c .config console log report info [disk image] [vmlinux] ci2-linux-4-19 INFO: task hung in btrfs_alloc_tree_block
2023/01/11 11:07 linux-4.19.y 3f8a27f9e27b 48bc529a .config console log report info [disk image] [vmlinux] ci2-linux-4-19 INFO: task hung in btrfs_alloc_tree_block
2023/01/11 10:30 linux-4.19.y 3f8a27f9e27b 48bc529a .config console log report info [disk image] [vmlinux] ci2-linux-4-19 INFO: task hung in btrfs_alloc_tree_block
2022/12/31 14:12 linux-4.19.y 3f8a27f9e27b ab32d508 .config console log report info [disk image] [vmlinux] ci2-linux-4-19 INFO: task hung in btrfs_alloc_tree_block
2022/12/23 05:53 linux-4.19.y 3f8a27f9e27b 9da18ae8 .config console log report info [disk image] [vmlinux] ci2-linux-4-19 INFO: task hung in btrfs_alloc_tree_block
* Struck through repros no longer work on HEAD.