I've just tripped over this lockdep splat on v5.12-rc1 (Linus' tree not
misc-next),
while investigating a different bug report.
[ 1250.721882] BUG: MAX_LOCKDEP_CHAIN_HLOCKS too low!
[ 1250.722641] turning off the locking correctness validator.
[ 1250.723486] CPU: 0 PID: 468 Comm: fsstress Not tainted 5.12.0-rc1 #950
[ 1250.724483] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.14.0-0-g155821a-rebuilt.opensuse.org 04/01/2014
[ 1250.726180] Call Trace:
[ 1250.726551] dump_stack+0x6d/0x89
[ 1250.727052] __lock_acquire.cold+0x2dd/0x2e2
[ 1250.727676] lock_acquire+0xab/0x350
[ 1250.728204] ? btrfs_add_delayed_tree_ref+0x1ae/0x4a0 [btrfs]
[ 1250.729215] ? debug_mutex_init+0x33/0x40
[ 1250.729822] _raw_spin_lock+0x2c/0x40
[ 1250.730340] ? btrfs_add_delayed_tree_ref+0x1ae/0x4a0 [btrfs]
[ 1250.731208] btrfs_add_delayed_tree_ref+0x1ae/0x4a0 [btrfs]
[ 1250.732047] ? kmem_cache_alloc+0x17a/0x300
[ 1250.732635] btrfs_alloc_tree_block+0x292/0x320 [btrfs]
[ 1250.733417] alloc_tree_block_no_bg_flush+0x4f/0x60 [btrfs]
[ 1250.734253] __btrfs_cow_block+0x13b/0x5e0 [btrfs]
[ 1250.734964] btrfs_cow_block+0x117/0x240 [btrfs]
[ 1250.735662] btrfs_search_slot+0x688/0xc60 [btrfs]
[ 1250.736378] ? mark_held_locks+0x49/0x70
[ 1250.736927] btrfs_insert_empty_items+0x58/0xa0 [btrfs]
[ 1250.737706] btrfs_insert_file_extent+0x8d/0x1c0 [btrfs]
[ 1250.738494] btrfs_cont_expand+0x359/0x4c0 [btrfs]
[ 1250.739226] btrfs_setattr+0x380/0x660 [btrfs]
[ 1250.739900] ? ktime_get_coarse_real_ts64+0xcb/0xe0
[ 1250.740578] ? current_time+0x1b/0xd0
[ 1250.741088] notify_change+0x27b/0x490
[ 1250.741613] ? do_truncate+0x6d/0xb0
[ 1250.742122] do_truncate+0x6d/0xb0
[ 1250.742604] vfs_truncate+0x108/0x140
[ 1250.743122] do_sys_truncate.part.0+0x6a/0x80
[ 1250.743738] do_syscall_64+0x33/0x40
[ 1250.744250] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 1250.744946] RIP: 0033:0x7f38d7819b8b
[ 1250.745453] Code: 48 8b 4c 24 28 64 48 2b 0c 25 28 00 00 00 75 05 48 83 c4
38 c3 e8 c5 69 01 00 0f 1f 44 00 00 f3 0f 1e fa b8 4c 00 00 00 0f 05 <48> 3d 00
f0 ff ff 77 05 c3 0f 1f 40 00 48 8b 15 b1 92 0c 00 f7 d8
[ 1250.748044] RSP: 002b:00007ffdf2983ed8 EFLAGS: 00000202 ORIG_RAX:
000000000000004c
[ 1250.749096] RAX: ffffffffffffffda RBX: 00007ffdf2984030 RCX: 00007f38d7819b8b
[ 1250.750081] RDX: 00000000001b92a2 RSI: 00000000001b92a2 RDI: 0000000000bdb380
[ 1250.751061] RBP: 00000000001b92a2 R08: 0000000000000029 R09: 00007ffdf298402c
[ 1250.752052] R10: 0000000000000002 R11: 0000000000000202 R12: 0000000000000010
[ 1250.753040] R13: 00000000001b92a2 R14: 0000000000000000 R15: 0000000000000001
[ 1260.719289] BTRFS info (device md0): scrub: started on devid 1
[ 1262.030768] BTRFS info (device md0): scrub: finished on devid 1 with status: 0
To trigger the bug I did several (4-5 I think) runs of this script:
rapido1:/home/johannes/src/xfstests-dev# cat test.sh
#!/bin/sh
SCRATCH_DIR=/mnt/scratch
echo "running fsstress"
./ltp/fsstress -w -f unlink=1 -f rmdir=1 -f symlink=1 -f sync=1 -f link=1 \
-f rename=1 -f fdatasync=1 -f removefattr=1 -f fsync=1 -f setfattr=1 \
-f setxattr=1 -f unresvsp=1 -f mkdir=1 -f mknod=1 -f chown=1 -f
fiemap=1 \
-f freesp=1 -f snapshot=1 -f rnoreplace=1 -f rexchange=1 -f rwhiteout=1
\
-f allocsp=1 -f subvol_create=1 -f subvol_delete=1 -f awrite=1 \
-f writev=1 -f write=1 -f splice=1 -f mread=1 -f deduperange=1 \
-f mwrite=1 -f dwrite=1 -f clonerange=1 -f copyrange=1 -f truncate=1 \
-f fallocate=1 -f punch=1 -f zero=1 -f collapse=1 -f insert=1 -p 30 \
-n 1000 -S t -d $SCRATCH_DIR
echo "scrubbing"
btrfs scrub start -Bd $SCRATCH_DIR || exit 1
echo "cleaning up"
rm -rf $SCRATCH_DIR/*
$SCRATCH_DIR is mounted on top of a md-raid1 array:
rapido1:/home/johannes/src/xfstests-dev# mdadm --detail /dev/md0
/dev/md0:
Version : 1.2
Creation Time : Tue Mar 2 09:38:17 2021
Raid Level : raid1
Array Size : 3142656 (3.00 GiB 3.22 GB)
Used Dev Size : 3142656 (3.00 GiB 3.22 GB)
Raid Devices : 4
Total Devices : 4
Persistence : Superblock is persistent
Update Time : Tue Mar 2 09:58:57 2021
State : clean
Active Devices : 4
Working Devices : 4
Failed Devices : 0
Spare Devices : 0
Consistency Policy : resync
Name : rapido1:0 (local to host rapido1)
UUID : 10a4866b:6da1ccdc:e069e6da:79196fb1
Events : 19
Number Major Minor RaidDevice State
0 251 1 0 active sync /dev/zram1
1 251 4 1 active sync /dev/zram4
2 251 2 2 active sync /dev/zram2
3 251 3 3 active sync /dev/zram3
johannes@redsun60:linux(master)$ ./scripts/faddr2line fs/btrfs/btrfs.ko
btrfs_add_delayed_tree_ref+0x1ae
btrfs_add_delayed_tree_ref+0x1ae/0x4a0:
btrfs_add_delayed_tree_ref at
/home/johannes/src/linux/fs/btrfs/delayed-ref.c:999
johannes@redsun60:linux(master)$ cat -n fs/btrfs/delayed-ref.c | grep -C 10 999
989 is_system);
990 head_ref->extent_op = extent_op;
991
992 delayed_refs = &trans->transaction->delayed_refs;
993 spin_lock(&delayed_refs->lock);
994
995 /*
996 * insert both the head node and the new ref without dropping
997 * the spin lock
998 */
999 head_ref = add_delayed_ref_head(trans, head_ref, record,
1000 action, &qrecord_inserted);
1001
1002 ret = insert_delayed_ref(trans, delayed_refs, head_ref,
&ref->node);
1003 spin_unlock(&delayed_refs->lock);
1004
1005 /*
1006 * Need to update the delayed_refs_rsv with any changes we may
have
1007 * made.
1008 */
1009 btrfs_update_delayed_refs_rsv(trans);
Has anyone seen this before?
