syzbot


possible deadlock in btrfs_run_dev_stats

Status: upstream: reported C repro on 2024/05/02 02:20
Bug presence: origin:upstream
[Documentation on labels]
Reported-by: syzbot+ee7f25e27b96da12819f@syzkaller.appspotmail.com
First crash: 233d, last: 1d00h
Fix bisection: failed (error log, bisect log)
  
Bug presence (1)
Date Name Commit Repro Result
2024/05/04 upstream (ToT) 7367539ad4b0 C [report] BUG: MAX_LOCKDEP_KEYS too low!
Similar bugs (1)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-4.19 possible deadlock in btrfs_run_dev_stats btrfs 4 657d 752d 0/1 upstream: reported on 2022/11/29 20:35
Last patch testing requests (9)
Created Duration User Patch Repo Result
2024/12/20 10:00 14m retest repro linux-5.15.y report log
2024/12/20 10:00 11m retest repro linux-5.15.y report log
2024/12/20 10:00 11m retest repro linux-5.15.y report log
2024/12/20 10:00 11m retest repro linux-5.15.y report log
2024/12/20 10:00 14m retest repro linux-5.15.y report log
2024/10/25 09:56 2h24m retest repro linux-5.15.y report log
2024/10/25 09:56 15m retest repro linux-5.15.y report log
2024/10/25 09:56 12m retest repro linux-5.15.y report log
2024/10/25 09:56 10m retest repro linux-5.15.y report log

Sample crash report:
======================================================
WARNING: possible circular locking dependency detected
5.15.167-syzkaller #0 Not tainted
------------------------------------------------------
btrfs-transacti/4038 is trying to acquire lock:
ffff0000d3268ce0 (&fs_devs->device_list_mutex){+.+.}-{3:3}, at: btrfs_run_dev_stats+0xe4/0xe24 fs/btrfs/volumes.c:7949

but task is already holding lock:
ffff0000d9c58720 (&fs_info->tree_log_mutex){+.+.}-{3:3}, at: btrfs_commit_transaction+0xe34/0x30f0 fs/btrfs/transaction.c:2367

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #4 (&fs_info->tree_log_mutex){+.+.}-{3:3}:
       __mutex_lock_common+0x194/0x2154 kernel/locking/mutex.c:596
       __mutex_lock kernel/locking/mutex.c:729 [inline]
       mutex_lock_nested+0xa4/0xf8 kernel/locking/mutex.c:743
       btrfs_commit_transaction+0xe34/0x30f0 fs/btrfs/transaction.c:2367
       transaction_kthread+0x284/0x3f4 fs/btrfs/disk-io.c:1904
       kthread+0x37c/0x45c kernel/kthread.c:334
       ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:870

-> #3 (&fs_info->reloc_mutex){+.+.}-{3:3}:
       __mutex_lock_common+0x194/0x2154 kernel/locking/mutex.c:596
       __mutex_lock kernel/locking/mutex.c:729 [inline]
       mutex_lock_nested+0xa4/0xf8 kernel/locking/mutex.c:743
       btrfs_record_root_in_trans fs/btrfs/transaction.c:511 [inline]
       start_transaction+0x450/0x1480 fs/btrfs/transaction.c:748
       btrfs_start_transaction+0x34/0x44 fs/btrfs/transaction.c:777
       btrfs_create+0x134/0x56c fs/btrfs/inode.c:6899
       lookup_open fs/namei.c:3462 [inline]
       open_last_lookups fs/namei.c:3532 [inline]
       path_openat+0xf18/0x26cc fs/namei.c:3739
       do_filp_open+0x1a8/0x3b4 fs/namei.c:3769
       do_sys_openat2+0x128/0x3e0 fs/open.c:1253
       do_sys_open fs/open.c:1269 [inline]
       __do_sys_openat fs/open.c:1285 [inline]
       __se_sys_openat fs/open.c:1280 [inline]
       __arm64_sys_openat+0x1f0/0x240 fs/open.c:1280
       __invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
       invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:52
       el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
       do_el0_svc+0x58/0x14c arch/arm64/kernel/syscall.c:181
       el0_svc+0x7c/0x1f0 arch/arm64/kernel/entry-common.c:608
       el0t_64_sync_handler+0x84/0xe4 arch/arm64/kernel/entry-common.c:626
       el0t_64_sync+0x1a0/0x1a4 arch/arm64/kernel/entry.S:584

-> #2 (sb_internal#2){.+.+}-{0:0}:
       percpu_down_read include/linux/percpu-rwsem.h:51 [inline]
       __sb_start_write include/linux/fs.h:1811 [inline]
       sb_start_intwrite include/linux/fs.h:1928 [inline]
       start_transaction+0x644/0x1480 fs/btrfs/transaction.c:678
       btrfs_start_transaction+0x34/0x44 fs/btrfs/transaction.c:777
       btrfs_create+0x134/0x56c fs/btrfs/inode.c:6899
       lookup_open fs/namei.c:3462 [inline]
       open_last_lookups fs/namei.c:3532 [inline]
       path_openat+0xf18/0x26cc fs/namei.c:3739
       do_filp_open+0x1a8/0x3b4 fs/namei.c:3769
       do_sys_openat2+0x128/0x3e0 fs/open.c:1253
       do_sys_open fs/open.c:1269 [inline]
       __do_sys_openat fs/open.c:1285 [inline]
       __se_sys_openat fs/open.c:1280 [inline]
       __arm64_sys_openat+0x1f0/0x240 fs/open.c:1280
       __invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
       invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:52
       el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
       do_el0_svc+0x58/0x14c arch/arm64/kernel/syscall.c:181
       el0_svc+0x7c/0x1f0 arch/arm64/kernel/entry-common.c:608
       el0t_64_sync_handler+0x84/0xe4 arch/arm64/kernel/entry-common.c:626
       el0t_64_sync+0x1a0/0x1a4 arch/arm64/kernel/entry.S:584

-> #1 (&type->i_mutex_dir_key#6){++++}-{3:3}:
       down_read+0xc0/0x398 kernel/locking/rwsem.c:1498
       inode_lock_shared include/linux/fs.h:799 [inline]
       lookup_slow+0x50/0x84 fs/namei.c:1679
       walk_component+0x394/0x4cc fs/namei.c:1976
       lookup_last fs/namei.c:2431 [inline]
       path_lookupat+0x13c/0x3d0 fs/namei.c:2455
       filename_lookup+0x1c4/0x4c8 fs/namei.c:2484
       kern_path+0x4c/0x194 fs/namei.c:2582
       lookup_bdev+0xc0/0x25c block/bdev.c:979
       device_matched fs/btrfs/volumes.c:568 [inline]
       btrfs_free_stale_devices+0x658/0x9ec fs/btrfs/volumes.c:608
       btrfs_forget_devices+0x5c/0x98 fs/btrfs/volumes.c:1395
       btrfs_control_ioctl+0x12c/0x248 fs/btrfs/super.c:2451
       vfs_ioctl fs/ioctl.c:51 [inline]
       __do_sys_ioctl fs/ioctl.c:874 [inline]
       __se_sys_ioctl fs/ioctl.c:860 [inline]
       __arm64_sys_ioctl+0x14c/0x1c8 fs/ioctl.c:860
       __invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
       invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:52
       el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
       do_el0_svc+0x58/0x14c arch/arm64/kernel/syscall.c:181
       el0_svc+0x7c/0x1f0 arch/arm64/kernel/entry-common.c:608
       el0t_64_sync_handler+0x84/0xe4 arch/arm64/kernel/entry-common.c:626
       el0t_64_sync+0x1a0/0x1a4 arch/arm64/kernel/entry.S:584

-> #0 (&fs_devs->device_list_mutex){+.+.}-{3:3}:
       check_prev_add kernel/locking/lockdep.c:3053 [inline]
       check_prevs_add kernel/locking/lockdep.c:3172 [inline]
       validate_chain kernel/locking/lockdep.c:3788 [inline]
       __lock_acquire+0x32d4/0x7638 kernel/locking/lockdep.c:5012
       lock_acquire+0x240/0x77c kernel/locking/lockdep.c:5623
       __mutex_lock_common+0x194/0x2154 kernel/locking/mutex.c:596
       __mutex_lock kernel/locking/mutex.c:729 [inline]
       mutex_lock_nested+0xa4/0xf8 kernel/locking/mutex.c:743
       btrfs_run_dev_stats+0xe4/0xe24 fs/btrfs/volumes.c:7949
       commit_cowonly_roots+0x17c/0x808 fs/btrfs/transaction.c:1290
       btrfs_commit_transaction+0xef4/0x30f0 fs/btrfs/transaction.c:2392
       transaction_kthread+0x284/0x3f4 fs/btrfs/disk-io.c:1904
       kthread+0x37c/0x45c kernel/kthread.c:334
       ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:870

other info that might help us debug this:

Chain exists of:
  &fs_devs->device_list_mutex --> &fs_info->reloc_mutex --> &fs_info->tree_log_mutex

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&fs_info->tree_log_mutex);
                               lock(&fs_info->reloc_mutex);
                               lock(&fs_info->tree_log_mutex);
  lock(&fs_devs->device_list_mutex);

 *** DEADLOCK ***

3 locks held by btrfs-transacti/4038:
 #0: ffff0000d9c587b0 (&fs_info->transaction_kthread_mutex){+.+.}-{3:3}, at: transaction_kthread+0xd0/0x3f4 fs/btrfs/disk-io.c:1875
 #1: ffff0000d9c58c90 (&fs_info->reloc_mutex){+.+.}-{3:3}, at: btrfs_commit_transaction+0xd9c/0x30f0 fs/btrfs/transaction.c:2317
 #2: ffff0000d9c58720 (&fs_info->tree_log_mutex){+.+.}-{3:3}, at: btrfs_commit_transaction+0xe34/0x30f0 fs/btrfs/transaction.c:2367

stack backtrace:
CPU: 1 PID: 4038 Comm: btrfs-transacti Not tainted 5.15.167-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 08/06/2024
Call trace:
 dump_backtrace+0x0/0x530 arch/arm64/kernel/stacktrace.c:152
 show_stack+0x2c/0x3c arch/arm64/kernel/stacktrace.c:216
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x108/0x170 lib/dump_stack.c:106
 dump_stack+0x1c/0x58 lib/dump_stack.c:113
 print_circular_bug+0x150/0x1b8 kernel/locking/lockdep.c:2011
 check_noncircular+0x2cc/0x378 kernel/locking/lockdep.c:2133
 check_prev_add kernel/locking/lockdep.c:3053 [inline]
 check_prevs_add kernel/locking/lockdep.c:3172 [inline]
 validate_chain kernel/locking/lockdep.c:3788 [inline]
 __lock_acquire+0x32d4/0x7638 kernel/locking/lockdep.c:5012
 lock_acquire+0x240/0x77c kernel/locking/lockdep.c:5623
 __mutex_lock_common+0x194/0x2154 kernel/locking/mutex.c:596
 __mutex_lock kernel/locking/mutex.c:729 [inline]
 mutex_lock_nested+0xa4/0xf8 kernel/locking/mutex.c:743
 btrfs_run_dev_stats+0xe4/0xe24 fs/btrfs/volumes.c:7949
 commit_cowonly_roots+0x17c/0x808 fs/btrfs/transaction.c:1290
 btrfs_commit_transaction+0xef4/0x30f0 fs/btrfs/transaction.c:2392
 transaction_kthread+0x284/0x3f4 fs/btrfs/disk-io.c:1904
 kthread+0x37c/0x45c kernel/kthread.c:334
 ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:870

Crashes (12):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/09/21 06:32 linux-5.15.y 3a5928702e71 6f888b75 .config console log report syz / log C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 possible deadlock in btrfs_run_dev_stats
2024/08/24 07:07 linux-5.15.y fa93fa65db6e d7d32352 .config console log report syz / log C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 possible deadlock in btrfs_run_dev_stats
2024/07/25 07:38 linux-5.15.y 7c6d66f0266f d1a1b0ca .config console log report syz / log C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 possible deadlock in btrfs_run_dev_stats
2024/07/25 05:32 linux-5.15.y 7c6d66f0266f d1a1b0ca .config console log report syz / log C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 possible deadlock in btrfs_run_dev_stats
2024/07/25 03:31 linux-5.15.y 7c6d66f0266f d1a1b0ca .config console log report syz / log C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 possible deadlock in btrfs_run_dev_stats
2024/07/25 01:30 linux-5.15.y 7c6d66f0266f d1a1b0ca .config console log report syz / log C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 possible deadlock in btrfs_run_dev_stats
2024/07/20 06:04 linux-5.15.y 7c6d66f0266f 890ce4f3 .config console log report syz / log C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 possible deadlock in btrfs_run_dev_stats
2024/05/02 03:54 linux-5.15.y b925f60c6ee7 3ba885bc .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 possible deadlock in btrfs_run_dev_stats
2024/05/02 03:16 linux-5.15.y b925f60c6ee7 3ba885bc .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 possible deadlock in btrfs_run_dev_stats
2024/06/23 19:49 linux-5.15.y 4878aadf2d15 edc5149a .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan possible deadlock in btrfs_run_dev_stats
2024/05/02 02:22 linux-5.15.y b925f60c6ee7 3ba885bc .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 possible deadlock in btrfs_run_dev_stats
2024/05/02 02:20 linux-5.15.y b925f60c6ee7 3ba885bc .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 possible deadlock in btrfs_run_dev_stats
* Struck through repros no longer work on HEAD.