On 28.03.22 13:28, Thorsten Leemhuis wrote: > Hi Btrfs developers, this is your Linux kernel regression tracker. > Top-posting for once, to make this easily accessible to everyone. > > Are there any known regressions in 5.15 that cause more inode evictions? > There is a user reporting such problems, see the msg quoted below, which > is the last from this thread: > > https://lore.kernel.org/all/MN2PR20MB2512314446801B92562E26B5D2169@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/ > > @Bruno: sorry, you report is very hard to follow at least for me. Maybe > the btrfs developers have a idea what's wrong here, but if not you > likely need to make this easier for all us: > > Write a really simple testcase and run it on those vanilla kernels that > matter, which are in this case: The latest 5.17.y and 5.15.y releases to > check if it was already solved -- and if not, on 5.14 and 5.15. Maybe > you need to bisect the issue to bring us closer the the root of the > problem. But with a bit of luck the btrfs developers might have an idea > already. > > Ciao, Thosten Hi Thorsten, Thanks for the feedback. I tried my best to make it simple this time. I hope it is, at least, better than before. Grazie, Bruno *** Test case about high inode eviction on the 5.15 kernel *** This regression was first observed during rpm operations with specific packages that became A LOT slower to update ranging from 4 to 30 minutes [1]. The symptoms are: high cpu usage, high inode eviction and much slower I/O performance. Analyzing the rpm's strace report and making some experiments I could replace the rpm with a script that do 3 thing: - rename a file, unlink the renamed file and create a new file. This test case is designed to trigger the following regression on the 5.15 kernel: * repeated renameat2, unlink and openat system calls reach files with btrfs compression property enable. * the combination of these system calls and the btrfs compression property triggers the high inode eviction. * the high inode eviction causes to much work for the btrfs directory logging. * the overloaded btrfs directory logging causes the slower I/O performance. A simplified script is supplied. For a more capable script, more information and more test results please refer to my github account [2]. [1] https://bugzilla.opensuse.org/show_bug.cgi?id=1193549 [2] https://github.com/bdamascen0/s3e Index: 1. Vanilla kernels 2. k5.14.21 x k5.15.32 2.1. Detailed test report for compressed files 2.2. Comparison results for compressed files 2.3. Detailed test report for uncompressed files 2.4. Comparison results for uncompressed files 2.5. Cpu usage 3. k5.17.1 and k5.16.15 3.1. Basic test report 4. Simplified test script 1. Vanilla kernels This test case mainly covers the following vanilla kernels [3]: 5.15.32 and 5.14.21. The 5.15.32 vanilla kernel produced abnormal results: * high cpu usage, high inode eviction and much slower I/O performance for compressed files. * double inode eviction and slightly worse I/O performance for uncompressed files. The 5.14.21 vanilla kernel produced normal results and is used as a reference. The 5.17.1 and 5.16.15 vanilla kernels [4] produced normal results which can be found at the end. [3] https://wiki.ubuntu.com/Kernel/MainlineBuilds [4] https://software.opensuse.org/package/kernel-vanilla 2. k5.14.21 x k5.15.32 2.1 Detailed test report for compressed files ubuntu jammy jellyfish -- kernel 5.14.21 --- vanilla --- (kvm) ..updating 50 files on /mnt/inode-ev/zstd: Job took 226 ms @inode_evictions: 51 ..updating 50 files on /mnt/inode-ev/lzo: Job took 222 ms @inode_evictions: 51 ..updating 100 files on /mnt/inode-ev/zstd: Job took 384 ms @inode_evictions: 101 ..updating 100 files on /mnt/inode-ev/lzo: Job took 462 ms @inode_evictions: 101 ..updating 150 files on /mnt/inode-ev/zstd: Job took 493 ms @inode_evictions: 151 ..updating 150 files on /mnt/inode-ev/lzo: Job took 554 ms @inode_evictions: 151 ..updating 200 files on /mnt/inode-ev/zstd: Job took 804 ms @inode_evictions: 201 ..updating 200 files on /mnt/inode-ev/lzo: Job took 725 ms @inode_evictions: 201 ..updating 250 files on /mnt/inode-ev/zstd: Job took 745 ms @inode_evictions: 251 ..updating 250 files on /mnt/inode-ev/lzo: Job took 758 ms @inode_evictions: 251 ..updating 1000 files on /mnt/inode-ev/zstd: Job took 3452 ms @inode_evictions: 1001 ..updating 1000 files on /mnt/inode-ev/lzo: Job took 2979 ms @inode_evictions: 1001 ubuntu jammy jellyfish -- kernel 5.15.32 --- vanilla --- (kvm) ..updating 50 files on /mnt/inode-ev/zstd: Job took 420 ms @inode_evictions: 1275 ..updating 50 files on /mnt/inode-ev/lzo: Job took 488 ms @inode_evictions: 1275 ..updating 100 files on /mnt/inode-ev/zstd: Job took 1649 ms @inode_evictions: 5050 ..updating 100 files on /mnt/inode-ev/lzo: Job took 1566 ms @inode_evictions: 5050 ..updating 150 files on /mnt/inode-ev/zstd: Job took 4448 ms @inode_evictions: 11325 ..updating 150 files on /mnt/inode-ev/lzo: Job took 4136 ms @inode_evictions: 11325 ..updating 200 files on /mnt/inode-ev/zstd: Job took 9177 ms @inode_evictions: 20100 ..updating 200 files on /mnt/inode-ev/lzo: Job took 9070 ms @inode_evictions: 20100 ..updating 250 files on /mnt/inode-ev/zstd: Job took 16191 ms @inode_evictions: 31375 ..updating 250 files on /mnt/inode-ev/lzo: Job took 16062 ms @inode_evictions: 31375 ..updating 1000 files on /mnt/inode-ev/zstd: Job took 132865 ms @inode_evictions: 104195 ..updating 1000 files on /mnt/inode-ev/lzo: Job took 131979 ms @inode_evictions: 106639 2.2. Comparison results for compressed files k5.15.32 vanilla (compared to: k5.14.21 vanilla) 50 files gives aprox. 1.8 x more time and aprox. 25 x more inode evictions 100 files gives aprox. 3.3 x more time and aprox. 50 x more inode evictions 150 files gives aprox. 7.4 x more time and aprox. 75 x more inode evictions 200 files gives aprox. 11.4 x more time and aprox. 100 x more inode evictions 250 files gives aprox. 21.1 x more time and aprox. 125 x more inode evictions 1000 files gives aprox. 38.4 x more time and aprox. 100 x more inode evictions 2.3 Detailed test report for uncompressed files ubuntu jammy jellyfish -- kernel 5.14.21 --- vanilla --- (kvm) ..updating 50 files on /mnt/inode-ev/uncompressed: Job took 214 ms @inode_evictions: 51 ..updating 100 files on /mnt/inode-ev/uncompressed: Job took 402 ms @inode_evictions: 101 ..updating 150 files on /mnt/inode-ev/uncompressed: Job took 543 ms @inode_evictions: 151 ..updating 200 files on /mnt/inode-ev/uncompressed: Job took 694 ms @inode_evictions: 201 ..updating 250 files on /mnt/inode-ev/uncompressed: Job took 835 ms @inode_evictions: 251 ..updating 1000 files on /mnt/inode-ev/uncompressed: Job took 3162 ms @inode_evictions: 1001 ubuntu jammy jellyfish -- kernel 5.15.32 --- vanilla --- (kvm) ..updating 50 files on /mnt/inode-ev/uncompressed: Job took 269 ms @inode_evictions: 99 ..updating 100 files on /mnt/inode-ev/uncompressed: Job took 359 ms @inode_evictions: 199 ..updating 150 files on /mnt/inode-ev/uncompressed: Job took 675 ms @inode_evictions: 299 ..updating 200 files on /mnt/inode-ev/uncompressed: Job took 752 ms @inode_evictions: 399 ..updating 250 files on /mnt/inode-ev/uncompressed: Job took 1149 ms @inode_evictions: 499 ..updating 1000 files on /mnt/inode-ev/uncompressed: Job took 7333 ms @inode_evictions: 1999 2.4. Comparison results for uncompressed files k5.15.32 vanilla (compared to: k5.14.21 vanilla) 50 files gives aprox. 1.2 x more time and aprox. 2 x more inode evictions 100 files gives aprox. 0.8 x more time and aprox. 2 x more inode evictions 150 files gives aprox. 1.2 x more time and aprox. 2 x more inode evictions 200 files gives aprox. 1.0 x more time and aprox. 2 x more inode evictions 250 files gives aprox. 1.3 x more time and aprox. 2 x more inode evictions 1000 files gives aprox. 2.3 x more time and aprox. 2 x more inode evictions 2.5. Cpu usage ubuntu jammy jellyfish -- kernel 5.15.32 --- vanilla --- (kvm) ..updating 1000 files on /mnt/inode-ev/zstd: Job took 132691 ms - real 2m12,731s sys 2m 7,134s ..updating 1000 files on /mnt/inode-ev/lzo: Job took 134130 ms - real 2m14,149s sys 2m 8,447s ..updating 1000 files on /mnt/inode-ev/uncompressed: Job took 7241 ms - real 0m 7,256s sys 0m 4,732s 3 k5.17.1 and k5.16.15 Just for the record, the 5.16 kernel never reproduced the regression. The real life workload to trigger the regression, the rpm package updates, were verified to work fine since 5.16~rc6 [1]. It was expected that the synthetic workload from the script also produced normal results on the 5.16 and 5.17 kernels. [1] https://bugzilla.opensuse.org/show_bug.cgi?id=1193549 3.1 Basic test report opensuse tumbleweed ----- kernel 5.16.15 --- vanilla --- (kvm) ..updating 250 files on /mnt/inode-ev/zstd: Job took 910 ms @inode_evictions: 250 ..updating 250 files on /mnt/inode-ev/lzo: Job took 740 ms @inode_evictions: 250 ..updating 250 files on /mnt/inode-ev/uncompressed: Job took 717 ms @inode_evictions: 250 opensuse tumbleweed ----- kernel 5.17.1 ---- vanilla --- (kvm) ..updating 250 files on /mnt/inode-ev/zstd: Job took 701 ms @inode_evictions: 250 ..updating 250 files on /mnt/inode-ev/lzo: Job took 695 ms @inode_evictions: 250 ..updating 250 files on /mnt/inode-ev/uncompressed: Job took 954 ms @inode_evictions: 250 4. Simplified test script This simplified script tries to setup, format and mount a ramdisk block device. It creates 3 testing folders (zstd, lzo, uncompressed) and set its btrfs compression property. For each time the script is executed, 3 tests are done and the bpftrace is started right before each test. #!/bin/bash # s3e_t3.sh (based on s3e.sh version 4.7) # Simple Syscall Signature Emulator (test3) # test3: populate + test. test renameat2/openat + unlink syscalls w/ empty files (3x) # Copyright (c) 2022 Bruno Damasceno <bdamasceno@xxxxxxxxxxxxxx> # Warning: no safety checks dir1=zstd dir2=lzo dir3=uncompressed DIR=zzz NUM_FILES=250 DEV=/dev/ram0 MNT=/mnt/inode-ev DIR_1="$MNT/$dir1" DIR_2="$MNT/$dir2" DIR_3="$MNT/$dir3" populate() { DIR=$1 echo "...populating 1st generation of files on $DIR:" for ((i = 1; i <= $NUM_FILES; i++)); do echo -n > $DIR/file_$i done } run_test() { DIR=$1 sync xfs_io -c "fsync" $DIR echo -e "\n...updating $NUM_FILES files on $DIR:" #dumb pause so bpftrace has time to atach its probe sleep 3s start=$(date +%s%N) for ((i = 1; i <= $NUM_FILES; i++)); do mv $DIR/file_$i $DIR/file_$i-RPMDELETE unlink $DIR/file_$i-RPMDELETE echo -n > $DIR/file_$i echo -n "_$i" [ $i != $NUM_FILES ] && echo -ne "\r" done end=$(date +%s%N) dur=$(( (end - start) / 1000000 )) echo -ne "\r" echo "Job took $dur milliseconds" } modprobe brd rd_size=128000 max_part=1 rd_nr=1 mkfs.btrfs --label inode-ev --force $DEV > /dev/null mkdir $MNT mount $DEV $MNT mkdir $MNT/{$dir1,$dir2,$dir3} btrfs property set $DIR_1 compression zstd:1 btrfs property set $DIR_2 compression lzo btrfs property set $DIR_3 compression none for dir in "$DIR_1" "$DIR_2" "$DIR_3" do populate "$dir" bpftrace -e 'kprobe:btrfs_evict_inode { @inode_evictions = count(); }' & run_test "$dir" pkill bpftrace #dumb pause to wait the bpftrace report sleep 2s done umount $MNT rm --dir $MNT rmmod brd
