5.12-rc4: rm directory hangs for > 1m on an idle system

5.12-rc4: rm directory hangs for > 1m on an idle system

[Chris Murphy]

5.12.0-0.rc4.175.fc35.x86_64+debug

/dev/sdb1 on /srv/extra type btrfs
(rw,relatime,seclabel,compress=zstd:1,space_cache=v2,subvolid=5,subvol=/)

The directories being deleted are on a separate drive (HDD) from /
(SSD). It's an unpacked Firefox source tarball, ~2.7G. I had two
separate copies, so the rm command was merely:

rm -rf firefox1 firefox2

And that command did not return to a prompt for over a minute, with no
disk activity all, on an otherwise idle laptop. sysrq+w shows nothing,
sysrq+t shows some things.


[ 9638.375968] kernel: task:rm              state:R  running task
stack:13176 pid: 2275 ppid:  1892 flags:0x00000000
[ 9638.375986] kernel: Call Trace:
[ 9638.375998] kernel:  ? __lock_acquire+0x3ac/0x1e10
[ 9638.376014] kernel:  ? __lock_acquire+0x3ac/0x1e10
[ 9638.376036] kernel:  ? lock_acquire+0xc2/0x3a0
[ 9638.376051] kernel:  ? lock_acquire+0xc2/0x3a0
[ 9638.376069] kernel:  ? lock_acquire+0xc2/0x3a0
[ 9638.376081] kernel:  ? lock_is_held_type+0xa7/0x120
[ 9638.376090] kernel:  ? rcu_read_lock_sched_held+0x3f/0x80
[ 9638.376099] kernel:  ? __btrfs_tree_lock+0x27/0x120
[ 9638.376111] kernel:  ? __clear_extent_bit+0x274/0x560
[ 9638.376120] kernel:  ? _raw_spin_lock_irqsave+0x67/0x90
[ 9638.376139] kernel:  ? __lock_acquire+0x3ac/0x1e10
[ 9638.376153] kernel:  ? lock_acquire+0xc2/0x3a0
[ 9638.376161] kernel:  ? __lock_acquire+0x3ac/0x1e10
[ 9638.376189] kernel:  ? lock_is_held_type+0xa7/0x120
[ 9638.376208] kernel:  ? release_extent_buffer+0xa3/0xe0
[ 9638.376224] kernel:  ? btrfs_update_root_times+0x2a/0x60
[ 9638.376237] kernel:  ? btrfs_insert_orphan_item+0x62/0x80
[ 9638.376246] kernel:  ? _atomic_dec_and_lock+0x31/0x50
[ 9638.376264] kernel:  ? btrfs_evict_inode+0x16b/0x4e0
[ 9638.376273] kernel:  ? btrfs_evict_inode+0x370/0x4e0
[ 9638.376293] kernel:  ? evict+0xcf/0x1d0
[ 9638.376305] kernel:  ? do_unlinkat+0x1b2/0x2c0
[ 9638.376329] kernel:  ? do_syscall_64+0x33/0x40
[ 9638.376338] kernel:  ? entry_SYSCALL_64_after_hwframe+0x44/0xae

The entire dmesg is here:
https://drive.google.com/file/d/1gyyp59Ju1aRIz3FCZU-kmu05-W1NN89A/view?usp=sharing

It isn't nearly as bad deleting one directory at once ~15s.

-- 
Chris Murphy

Re: 5.12-rc4: rm directory hangs for > 1m on an idle system

[Chris Murphy]

Fresh boot, this time no compression, everything else the same. Time
to delete both directories takes as long as it takes to copy one of
them ~1m17s. This time I took an early and late sysrq t pair, and
maybe caught some extra stuff.

[ 1190.094618] kernel: Workqueue: events_unbound
btrfs_preempt_reclaim_metadata_space
[ 1190.094633] kernel: Call Trace:
[ 1190.094641] kernel:  ? find_extent_buffer+0x5/0x200
[ 1190.094656] kernel:  ? find_held_lock+0x32/0x90
[ 1190.094683] kernel:  ? __lock_acquire+0x172/0x1e10
[ 1190.094694] kernel:  ? lock_is_held_type+0xa7/0x120
[ 1190.094714] kernel:  ? btrfs_search_slot+0x6d2/0x9f0
[ 1190.094729] kernel:  ? btrfs_get_64+0x5e/0x100
[ 1190.094751] kernel:  ? lock_acquire+0xc2/0x3a0
[ 1190.094768] kernel:  ? _raw_spin_unlock+0x1f/0x30
[ 1190.094779] kernel:  ? rcu_read_lock_sched_held+0x3f/0x80
[ 1190.094798] kernel:  ? __lock_acquire+0x172/0x1e10
[ 1190.094811] kernel:  ? lookup_extent_backref+0x43/0xd0
[ 1190.094829] kernel:  ? release_extent_buffer+0xa3/0xe0
[ 1190.094846] kernel:  ? __btrfs_free_extent+0x49c/0x8f0
[ 1190.094878] kernel:  ? __btrfs_run_delayed_refs+0x29a/0x1270
[ 1190.094912] kernel:  ? _raw_spin_unlock+0x1f/0x30
[ 1190.094934] kernel:  ? btrfs_run_delayed_refs+0x86/0x210
[ 1190.094954] kernel:  ? flush_space+0x570/0x6d0
[ 1190.094966] kernel:  ? lock_release+0x280/0x410
[ 1190.094987] kernel:  ? btrfs_preempt_reclaim_metadata_space+0x170/0x2f0
[ 1190.095007] kernel:  ? process_one_work+0x2b0/0x5e0
[ 1190.095035] kernel:  ? worker_thread+0x55/0x3c0
[ 1190.095045] kernel:  ? process_one_work+0x5e0/0x5e0
[ 1190.095060] kernel:  ? kthread+0x13a/0x150
[ 1190.095070] kernel:  ? __kthread_bind_mask+0x60/0x60
[ 1190.095085] kernel:  ? ret_from_fork+0x1f/0x30

dmesg
https://drive.google.com/file/d/1VQNAVynVTJo6VqsRX9K5-Z0dMsLmb-vH/view?usp=sharing