Re: [regression] 5.15 kernel triggering 100x more inode evictions

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Thorsten Leemhuis]

Hi, this is your Linux kernel regression tracker.

CCing the regression mailing list, as it should be in the loop for all
regressions, as explained here:
https://www.kernel.org/doc/html/latest/admin-guide/reporting-issues.html

On 21.03.22 05:53, Bruno Damasceno Freire wrote:
> Hello everybody;
> 
> This regression was first found during rpm operations with specific packages that became A LOT slower to update ranging from 4 to 30 minutes.
> 
> The slowness results from:
> a_ the kernel regression: specific system calls touching files with btrfs compression property will generate higher inode eviction on 5.15 kernels.
> b_ the inode eviction generating btrfs inode logging and directory logging.
> c_ the btrfs directory logging on the 5.15 kernel not being particulary efficient in the presence of high inode eviction.
> 
> There is already an ongoing work [1] to improve "c" on newer kernels but I was told they are not elegible for the 5.15 version due to backporting policy restrictions.
> AFAIK there isn't any work for "a" yet.
> The consequence is that btrfs users running the 5.15 LTS kernel may experience severely degraded performance for specific I/O workloads on files with the compression property enabled.
> 
> ___How to reproduce:
> After some research I learned how to reproduce the regression without rpm.
>
> 1st option)
> I made a script specifically to research this regression [2].
> It has more information, more test results and several options.
> The scrip does a little too much so I'm just linking it here.
> I hope it can help.
> 
> 2nd option)
> boot a 5.15 kernel,
> setup and mount a RAM disk with btrfs,
> create a folder and set its compression property,
> populate the folder,
> make a loop that:
> -rename a file,
> -unlink the renamed file,
> -create a new file.
> 
> [1] https://bugzilla.opensuse.org/show_bug.cgi?id=1193549
> [2] https://github.com/bdamascen0/s3e
> 
> ___Test results
> These tests were done on a virtual machine (kvm) with Ubuntu Jammy Jellyfish.
> The kernel is 5.15.0.23 that relates to the 5.15.27 upstream kernel.

Please repeat this with a vanilla kernel, Ubuntu's kernel are heavily
patched and one of their patches might be causing your problem.

> Main results (x86_64):
> 250 files - zstd:         17521 ms @inode_evictions: 31375
> 250 files - lzo:          17114 ms @inode_evictions: 31375
> 250 files - uncompressed:  1138 ms @inode_evictions: 499
> 
> Load test results (x86_64):
> 1000 files - 51.6 x more inode evictions - 18.1 x more time
> 250  files - 62.9 x more inode evictions - 15.2 x more time
> 100  files - 25.4 x more inode evictions -  3.7 x more time
> 50   files - 12.8 x more inode evictions -  2.0 x more time
> 10   files -  2.8 x more inode evictions -  1.3 x more time

I'm missing something: more inode evictions when compared to what? A
5.14 vanilla kernel?

> CPU usage results (x86_64):
> 1000 files - zstd:           137841 ms
> real    2m17,881s
> user    0m1,704s
> sys     2m11,937s
> 1000 files - lzo:            135456 ms
> real    2m15,478s
> user    0m1,805s
> sys	2m9,758s
> 1000 files - uncompressed:     7496 ms
> real    0m7,517s
> user    0m1,386s
> sys     0m4,899s
> 
> I'm sending this message to the linux-fsdevel mailing list first.
> Please tell if you think this subject would be of interest of another kernel subsystem.
> PS: I'm not subscribed to this list.

We need to get Btrfs people into the boat, but please clarify first if
this really is a regression with the upstream kernel.

Ciao, Thorsten

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Bruno Damasceno Freire]

On 24.03.22 13:18, Thorsten Leemhuis wrote:
> Hi, this is your Linux kernel regression tracker.
> 
> CCing the regression mailing list, as it should be in the loop for all
> regressions, as explained here:
> https://www.kernel.org/doc/html/latest/admin-guide/reporting-issues.html

Thanks.

> On 21.03.22 05:53, Bruno Damasceno Freire wrote:
> > Hello everybody;
> > 
> > This regression was first found during rpm operations with specific packages that became A LOT slower to update ranging from 4 to 30 minutes.
> > 
> > The slowness results from:
> > a_ the kernel regression: specific system calls touching files with btrfs compression property will generate higher inode eviction on 5.15 kernels.
> > b_ the inode eviction generating btrfs inode logging and directory logging.
> > c_ the btrfs directory logging on the 5.15 kernel not being particulary efficient in the presence of high inode eviction.
> > 
> > There is already an ongoing work [1] to improve "c" on newer kernels but I was told they are not elegible for the 5.15 version due to backporting policy restrictions.
> > AFAIK there isn't any work for "a" yet.
> > The consequence is that btrfs users running the 5.15 LTS kernel may experience severely degraded performance for specific I/O workloads on files with the compression property enabled.
> > 
> > ___How to reproduce:
> > After some research I learned how to reproduce the regression without rpm.
> >
> > 1st option)
> > I made a script specifically to research this regression [2].
> > It has more information, more test results and several options.
> > The scrip does a little too much so I'm just linking it here.
> > I hope it can help.
> > 
> > 2nd option)
> > boot a 5.15 kernel,
> > setup and mount a RAM disk with btrfs,
> > create a folder and set its compression property,
> > populate the folder,
> > make a loop that:
> > -rename a file,
> > -unlink the renamed file,
> > -create a new file.
> > 
> > [1] https://bugzilla.opensuse.org/show_bug.cgi?id=1193549
> > [2] https://github.com/bdamascen0/s3e
> > 
> > ___Test results
> > These tests were done on a virtual machine (kvm) with Ubuntu Jammy Jellyfish.
> > The kernel is 5.15.0.23 that relates to the 5.15.27 upstream kernel.
> 
> Please repeat this with a vanilla kernel, Ubuntu's kernel are heavily
> patched and one of their patches might be causing your problem.

Done. Same higher inode-evictions and slow results.
Also tested on a 5.15.0-rc1 kernel and, again, same results.
Older and newer 5.14 kernels produced normal results so it really seems that the regression was introduced early in the 5.15 cycle.

> > Main results (x86_64):
> > 250 files - zstd:         17521 ms @inode_evictions: 31375
> > 250 files - lzo:          17114 ms @inode_evictions: 31375
> > 250 files - uncompressed:  1138 ms @inode_evictions: 499
> > 
> > Load test results (x86_64):
> > 1000 files - 51.6 x more inode evictions - 18.1 x more time
> > 250  files - 62.9 x more inode evictions - 15.2 x more time
> > 100  files - 25.4 x more inode evictions -  3.7 x more time
> > 50   files - 12.8 x more inode evictions -  2.0 x more time
> > 10   files -  2.8 x more inode evictions -  1.3 x more time
> 
> I'm missing something: more inode evictions when compared to what? A
> 5.14 vanilla kernel?

Not clear at all. Sorry.
Will repost with my full set of results [2] including a vanilla kernel, the 15.0-rc1, more distros and a better load test report.

> > CPU usage results (x86_64):
> > 1000 files - zstd:           137841 ms
> > real    2m17,881s
> > user    0m1,704s
> > sys     2m11,937s
> > 1000 files - lzo:            135456 ms
> > real    2m15,478s
> > user    0m1,805s
> > sys	2m9,758s
> > 1000 files - uncompressed:     7496 ms
> > real    0m7,517s
> > user    0m1,386s
> > sys     0m4,899s
> > 
> > I'm sending this message to the linux-fsdevel mailing list first.
> > Please tell if you think this subject would be of interest of another kernel subsystem.
> > PS: I'm not subscribed to this list.
> 
> We need to get Btrfs people into the boat, but please clarify first if
> this really is a regression with the upstream kernel.

Sure. The Btrfs crew belong on this boat.
The Btrfs developer Filipe Manana assisted me on the original bug report [1].
He concluded that the btrfs compression property just happens to trigger something outside the btrfs code and was guessing it could be at the vfs or mm subsystems.
The bug was also the beginning of a long term work to make the filesystem more robust but the improvements would not be elegible for the 5.15 version due to backport restrictions.

> Ciao, Thorsten

Grazie, Bruno

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Bruno Damasceno Freire]

___Updated test results

These results were obtained with the script I've made to research this regression [1].
[1] https://github.com/bdamascen0/s3e


Main results

The regression was reproduced on:
-several different 5.15 kernels versions across several different distros.
-all 5.15 kernels that I have tried on.
-the 5.15.0-rc1 kernel from the opensuse tumbleweed comunity repository.
-the 5.15.12 vanilla kernel from the official opensuse tumbleweed repository.

The regression could not be reproduced on kernels versions other than the 5.15.

The vanilla kernel test was suggested by Thorsten Leemhuis to make sure downstream custom patches aren't causing the symptoms.
The vanilla kernel test result shows the exact same pattern verified on downstream kernels and fully validates the regression.


General test results for the 5.15 kernel series (x86_64)

opensuse tumbleweed ----- kernel 5.15.12 --- vanilla --- (kvm)
... 250 files - zstd:         13327 ms @inode_evictions: 31375
... 250 files - lzo:          13361 ms @inode_evictions: 31375
... 250 files - uncompressed:  1204 ms @inode_evictions: 499
opensuse tumbleweed ----- kernel 5.15.0-rc1-1.g8787773 - (kvm)
... 250 files - zstd:         13875 ms @inode_evictions: 31375
... 250 files - lzo:          15351 ms @inode_evictions: 31375
... 250 files - uncompressed:  1231 ms @inode_evictions: 499
opensuse tumbleweed ----- kernel 5.15.12----------------------
... 250 files - zstd:         12500 ms @inode_evictions: 31375
... 250 files - lzo:          12327 ms @inode_evictions: 31375
... 250 files - uncompressed:  1482 ms @inode_evictions: 499
debian bookworm --------- kernel 5.15.0-3 - (5.15.15) -- (kvm)
... 250 files - zstd:         12343 ms @inode_evictions: 31375
... 250 files - lzo:          14028 ms @inode_evictions: 31375
... 250 files - uncompressed:  1092 ms @inode_evictions: 499
Zenwalk 15.0 Skywalker ---kernel 5.15.19 --------------- (kvm)
... 250 files - zstd:         14374 ms @inode_evictions: -
... 250 files - lzo:          14163 ms @inode_evictions: -
... 250 files - uncompressed:  2173 ms @inode_evictions: -
ubuntu jammy jellyfish -- kernel 5.15.0.23 - (5.15.27) - (kvm) 
... 250 files - zstd:         17521 ms @inode_evictions: 31375
... 250 files - lzo:          17114 ms @inode_evictions: 31375
... 250 files - uncompressed:  1138 ms @inode_evictions: 499


General test results for other kernels (x86_64)

opensuse leap 15.3 ------ kernel 5.3.18-150300.59.54----------
... 250 files - zstd:           668 ms @inode_evictions: 251
... 250 files - lzo:            693 ms @inode_evictions: 251
... 250 files - uncompressed:   661 ms @inode_evictions: 252
opensuse leap 15.4 beta - kernel 5.14.21-150400.11 ----- (kvm)
... 250 files - zstd:           811 ms @inode_evictions: 251
... 250 files - lzo:            912 ms @inode_evictions: 251
... 250 files - uncompressed:   993 ms @inode_evictions: 251
opensuse tumbleweed ----- kernel 5.14.14 --------------- (kvm)
... 250 files - zstd:           888 ms @inode_evictions: 251
... 250 files - lzo:           1063 ms @inode_evictions: 251
... 250 files - uncompressed:   778 ms @inode_evictions: 251
opensuse tumbleweed ----- kernel 5.16.14----------------------
... 250 files - zstd:          1398 ms @inode_evictions: 250
... 250 files - lzo:           1323 ms @inode_evictions: 250
... 250 files - uncompressed:  1365 ms @inode_evictions: 250


Load test results (x86_64):

opensuse leap 15.4 beta - kernel 5.14.21-150400.11 ----- (kvm)
...   50 files - zstd:            261 ms @inode_evictions: 51
...   50 files - lzo:             256 ms @inode_evictions: 51
...   50 files - uncompressed:    317 ms @inode_evictions: 51
...  100 files - zstd:            450 ms @inode_evictions: 101
...  100 files - lzo:             461 ms @inode_evictions: 101
...  100 files - uncompressed:    471 ms @inode_evictions: 101
...  150 files - zstd:            618 ms @inode_evictions: 151
...  150 files - lzo:             624 ms @inode_evictions: 151
...  150 files - uncompressed:    612 ms @inode_evictions: 151
...  200 files - zstd:            822 ms @inode_evictions: 201
...  200 files - lzo:             933 ms @inode_evictions: 201
...  200 files - uncompressed:    747 ms @inode_evictions: 201
...  250 files - zstd:           1128 ms @inode_evictions: 251
...  250 files - lzo:             974 ms @inode_evictions: 251
...  250 files - uncompressed:    936 ms @inode_evictions: 251
... 1000 files - zstd:           3517 ms @inode_evictions: 1001
... 1000 files - lzo:            4373 ms @inode_evictions: 1001
... 1000 files - uncompressed:   3797 ms @inode_evictions: 1001
ubuntu jammy jellyfish -- kernel 5.15.0.23 - (5.15.27) - (kvm) 
...   50 files - zstd:            424 ms @inode_evictions: 1275
...   50 files - lzo:             423 ms @inode_evictions: 1275
...   50 files - uncompressed:    207 ms @inode_evictions: 99
...  100 files - zstd:           1744 ms @inode_evictions: 5050
...  100 files - lzo:            1838 ms @inode_evictions: 5050
...  100 files - uncompressed:    373 ms @inode_evictions: 199
...  150 files - zstd:           4785 ms @inode_evictions: 11325
...  150 files - lzo:            4660 ms @inode_evictions: 11325
...  150 files - uncompressed:    689 ms @inode_evictions: 299
...  200 files - zstd:           9763 ms @inode_evictions: 20100
...  200 files - lzo:           10106 ms @inode_evictions: 20100
...  200 files - uncompressed:    938 ms @inode_evictions: 399
...  250 files - zstd:          17550 ms @inode_evictions: 31375
...  250 files - lzo:           17337 ms @inode_evictions: 31375
...  250 files - uncompressed:   1373 ms @inode_evictions: 499
... 1000 files - zstd:         143614 ms @inode_evictions: 101132
... 1000 files - lzo:          146724 ms @inode_evictions: 100314
... 1000 files - uncompressed:   7735 ms @inode_evictions: 1999


Load test results comparisson for compressed files (x86_64):
ubuntu jammy jellyfish - compared to - opensuse leap 15.4 beta

50   files gives aprox.  1.6 x more time and aprox.  25 x more inode evictions 
100  files gives aprox.  3.8 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. 10.8 x more time and aprox. 100 x more inode evictions 
250  files gives aprox. 15.5 x more time and aprox. 125 x more inode evictions 
1000 files gives aprox. 33.5 x more time and aprox. 100 x more inode evictions 


Load test results comparisson for uncompressed files (x86_64):
ubuntu jammy jellyfish - compared to - opensuse leap 15.4 beta

50   files gives aprox. 0.6 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.1 x more time and aprox. 2 x more inode evictions 
200  files gives aprox. 1.2 x more time and aprox. 2 x more inode evictions 
250  files gives aprox. 1.4 x more time and aprox. 2 x more inode evictions 
1000 files gives aprox. 2.0 x more time and aprox. 2 x more inode evictions 


CPU usage results:
The regression causes significant CPU usage by the kernel.

ubuntu jammy jellyfish -- kernel  5.15.0.23 (5.15.27) - (kvm) 
... 1000 files - zstd:         137841 ms
    real    2m17,881s
    user    0m 1,704s
    sys     2m11,937s
... 1000 files - lzo:          135456 ms
    real    2m15,478s
    user    0m 1,805s
    sys     2m 9,758s
... 1000 files - uncompressed:   7496 ms
    real    0m 7,517s
    user    0m 1,386s
    sys     0m 4,899s


Test system specification:
host: AMD FX-8370E 8 cores / 8GB RAM / ssd
guests (kvm): 2 cores / 2G RAM / ssd
test storage medium: RAM disk block device (host and guest)


TIA, Bruno

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Thorsten Leemhuis]

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@MN2PR20MB2512.namprd20.prod.outlook.com/

@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

On 28.03.22 05:12, Bruno Damasceno Freire wrote:
> ___Updated test results
> 
> These results were obtained with the script I've made to research this regression [1].
> [1] https://github.com/bdamascen0/s3e
> 
> 
> Main results
> 
> The regression was reproduced on:
> -several different 5.15 kernels versions across several different distros.
> -all 5.15 kernels that I have tried on.
> -the 5.15.0-rc1 kernel from the opensuse tumbleweed comunity repository.
> -the 5.15.12 vanilla kernel from the official opensuse tumbleweed repository.
> 
> The regression could not be reproduced on kernels versions other than the 5.15.
> 
> The vanilla kernel test was suggested by Thorsten Leemhuis to make sure downstream custom patches aren't causing the symptoms.
> The vanilla kernel test result shows the exact same pattern verified on downstream kernels and fully validates the regression.
> 
> 
> General test results for the 5.15 kernel series (x86_64)
> 
> opensuse tumbleweed ----- kernel 5.15.12 --- vanilla --- (kvm)
> ... 250 files - zstd:         13327 ms @inode_evictions: 31375
> ... 250 files - lzo:          13361 ms @inode_evictions: 31375
> ... 250 files - uncompressed:  1204 ms @inode_evictions: 499
> opensuse tumbleweed ----- kernel 5.15.0-rc1-1.g8787773 - (kvm)
> ... 250 files - zstd:         13875 ms @inode_evictions: 31375
> ... 250 files - lzo:          15351 ms @inode_evictions: 31375
> ... 250 files - uncompressed:  1231 ms @inode_evictions: 499
> opensuse tumbleweed ----- kernel 5.15.12----------------------
> ... 250 files - zstd:         12500 ms @inode_evictions: 31375
> ... 250 files - lzo:          12327 ms @inode_evictions: 31375
> ... 250 files - uncompressed:  1482 ms @inode_evictions: 499
> debian bookworm --------- kernel 5.15.0-3 - (5.15.15) -- (kvm)
> ... 250 files - zstd:         12343 ms @inode_evictions: 31375
> ... 250 files - lzo:          14028 ms @inode_evictions: 31375
> ... 250 files - uncompressed:  1092 ms @inode_evictions: 499
> Zenwalk 15.0 Skywalker ---kernel 5.15.19 --------------- (kvm)
> ... 250 files - zstd:         14374 ms @inode_evictions: -
> ... 250 files - lzo:          14163 ms @inode_evictions: -
> ... 250 files - uncompressed:  2173 ms @inode_evictions: -
> ubuntu jammy jellyfish -- kernel 5.15.0.23 - (5.15.27) - (kvm) 
> ... 250 files - zstd:         17521 ms @inode_evictions: 31375
> ... 250 files - lzo:          17114 ms @inode_evictions: 31375
> ... 250 files - uncompressed:  1138 ms @inode_evictions: 499
> 
> 
> General test results for other kernels (x86_64)
> 
> opensuse leap 15.3 ------ kernel 5.3.18-150300.59.54----------
> ... 250 files - zstd:           668 ms @inode_evictions: 251
> ... 250 files - lzo:            693 ms @inode_evictions: 251
> ... 250 files - uncompressed:   661 ms @inode_evictions: 252
> opensuse leap 15.4 beta - kernel 5.14.21-150400.11 ----- (kvm)
> ... 250 files - zstd:           811 ms @inode_evictions: 251
> ... 250 files - lzo:            912 ms @inode_evictions: 251
> ... 250 files - uncompressed:   993 ms @inode_evictions: 251
> opensuse tumbleweed ----- kernel 5.14.14 --------------- (kvm)
> ... 250 files - zstd:           888 ms @inode_evictions: 251
> ... 250 files - lzo:           1063 ms @inode_evictions: 251
> ... 250 files - uncompressed:   778 ms @inode_evictions: 251
> opensuse tumbleweed ----- kernel 5.16.14----------------------
> ... 250 files - zstd:          1398 ms @inode_evictions: 250
> ... 250 files - lzo:           1323 ms @inode_evictions: 250
> ... 250 files - uncompressed:  1365 ms @inode_evictions: 250
> 
> 
> Load test results (x86_64):
> 
> opensuse leap 15.4 beta - kernel 5.14.21-150400.11 ----- (kvm)
> ...   50 files - zstd:            261 ms @inode_evictions: 51
> ...   50 files - lzo:             256 ms @inode_evictions: 51
> ...   50 files - uncompressed:    317 ms @inode_evictions: 51
> ...  100 files - zstd:            450 ms @inode_evictions: 101
> ...  100 files - lzo:             461 ms @inode_evictions: 101
> ...  100 files - uncompressed:    471 ms @inode_evictions: 101
> ...  150 files - zstd:            618 ms @inode_evictions: 151
> ...  150 files - lzo:             624 ms @inode_evictions: 151
> ...  150 files - uncompressed:    612 ms @inode_evictions: 151
> ...  200 files - zstd:            822 ms @inode_evictions: 201
> ...  200 files - lzo:             933 ms @inode_evictions: 201
> ...  200 files - uncompressed:    747 ms @inode_evictions: 201
> ...  250 files - zstd:           1128 ms @inode_evictions: 251
> ...  250 files - lzo:             974 ms @inode_evictions: 251
> ...  250 files - uncompressed:    936 ms @inode_evictions: 251
> ... 1000 files - zstd:           3517 ms @inode_evictions: 1001
> ... 1000 files - lzo:            4373 ms @inode_evictions: 1001
> ... 1000 files - uncompressed:   3797 ms @inode_evictions: 1001
> ubuntu jammy jellyfish -- kernel 5.15.0.23 - (5.15.27) - (kvm) 
> ...   50 files - zstd:            424 ms @inode_evictions: 1275
> ...   50 files - lzo:             423 ms @inode_evictions: 1275
> ...   50 files - uncompressed:    207 ms @inode_evictions: 99
> ...  100 files - zstd:           1744 ms @inode_evictions: 5050
> ...  100 files - lzo:            1838 ms @inode_evictions: 5050
> ...  100 files - uncompressed:    373 ms @inode_evictions: 199
> ...  150 files - zstd:           4785 ms @inode_evictions: 11325
> ...  150 files - lzo:            4660 ms @inode_evictions: 11325
> ...  150 files - uncompressed:    689 ms @inode_evictions: 299
> ...  200 files - zstd:           9763 ms @inode_evictions: 20100
> ...  200 files - lzo:           10106 ms @inode_evictions: 20100
> ...  200 files - uncompressed:    938 ms @inode_evictions: 399
> ...  250 files - zstd:          17550 ms @inode_evictions: 31375
> ...  250 files - lzo:           17337 ms @inode_evictions: 31375
> ...  250 files - uncompressed:   1373 ms @inode_evictions: 499
> ... 1000 files - zstd:         143614 ms @inode_evictions: 101132
> ... 1000 files - lzo:          146724 ms @inode_evictions: 100314
> ... 1000 files - uncompressed:   7735 ms @inode_evictions: 1999
> 
> 
> Load test results comparisson for compressed files (x86_64):
> ubuntu jammy jellyfish - compared to - opensuse leap 15.4 beta
> 
> 50   files gives aprox.  1.6 x more time and aprox.  25 x more inode evictions 
> 100  files gives aprox.  3.8 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. 10.8 x more time and aprox. 100 x more inode evictions 
> 250  files gives aprox. 15.5 x more time and aprox. 125 x more inode evictions 
> 1000 files gives aprox. 33.5 x more time and aprox. 100 x more inode evictions 
> 
> 
> Load test results comparisson for uncompressed files (x86_64):
> ubuntu jammy jellyfish - compared to - opensuse leap 15.4 beta
> 
> 50   files gives aprox. 0.6 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.1 x more time and aprox. 2 x more inode evictions 
> 200  files gives aprox. 1.2 x more time and aprox. 2 x more inode evictions 
> 250  files gives aprox. 1.4 x more time and aprox. 2 x more inode evictions 
> 1000 files gives aprox. 2.0 x more time and aprox. 2 x more inode evictions 
> 
> 
> CPU usage results:
> The regression causes significant CPU usage by the kernel.
> 
> ubuntu jammy jellyfish -- kernel  5.15.0.23 (5.15.27) - (kvm) 
> ... 1000 files - zstd:         137841 ms
>     real    2m17,881s
>     user    0m 1,704s
>     sys     2m11,937s
> ... 1000 files - lzo:          135456 ms
>     real    2m15,478s
>     user    0m 1,805s
>     sys     2m 9,758s
> ... 1000 files - uncompressed:   7496 ms
>     real    0m 7,517s
>     user    0m 1,386s
>     sys     0m 4,899s
> 
> 
> Test system specification:
> host: AMD FX-8370E 8 cores / 8GB RAM / ssd
> guests (kvm): 2 cores / 2G RAM / ssd
> test storage medium: RAM disk block device (host and guest)
> 
> 
> TIA, Bruno

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Bruno Damasceno Freire]

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@MN2PR20MB2512.namprd20.prod.outlook.com/
> 
> @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@hotmail.com.br>
# 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

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Thorsten Leemhuis]

Hi, this is your Linux kernel regression tracker. Top-posting for once,
to make this easily accessible to everyone.

Btrfs maintainers, what's up here? Yes, this regression report was a bit
confusing in the beginning, but Bruno worked on it. And apparently it's
already fixed in 5.16, but still in 5.15. Is this caused by a change
that is to big to backport or something?

Ciao, Thorsten

#regzbot poke

On 04.04.22 07:29, Bruno Damasceno Freire wrote:
> 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@MN2PR20MB2512.namprd20.prod.outlook.com/
>>
>> @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@hotmail.com.br>
> # 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
> 

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[David Sterba]

On Fri, Apr 08, 2022 at 12:32:20PM +0200, Thorsten Leemhuis wrote:
> Hi, this is your Linux kernel regression tracker. Top-posting for once,
> to make this easily accessible to everyone.
> 
> Btrfs maintainers, what's up here? Yes, this regression report was a bit
> confusing in the beginning, but Bruno worked on it. And apparently it's
> already fixed in 5.16, but still in 5.15. Is this caused by a change
> that is to big to backport or something?

I haven't identified possible fixes in 5.16 so I can't tell how much
backport efforts it could be. As the report is related to performance on
package updates, my best guess is that the patches fixing it are those
from Filipe related to fsync/logging, and there are several of such
improvements in 5.16. Or something else that fixes it indirectly.

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Filipe Manana]

On Fri, Apr 08, 2022 at 04:52:22PM +0200, David Sterba wrote:
> On Fri, Apr 08, 2022 at 12:32:20PM +0200, Thorsten Leemhuis wrote:
> > Hi, this is your Linux kernel regression tracker. Top-posting for once,
> > to make this easily accessible to everyone.
> > 
> > Btrfs maintainers, what's up here? Yes, this regression report was a bit
> > confusing in the beginning, but Bruno worked on it. And apparently it's
> > already fixed in 5.16, but still in 5.15. Is this caused by a change
> > that is to big to backport or something?
> 
> I haven't identified possible fixes in 5.16 so I can't tell how much
> backport efforts it could be. As the report is related to performance on
> package updates, my best guess is that the patches fixing it are those
> from Filipe related to fsync/logging, and there are several of such
> improvements in 5.16. Or something else that fixes it indirectly.

So there's a lot of confusion in the thread, and the original openSUSE 
bugzilla [1] is also a bit confusing and large to follow.

Let me try to make it clear:

1) For some reason, outside btrfs' control, inode eviction is triggered
   a lot on 5.15 kernels in Bruno's test machine when doing package
   installations/updates with zypper. It triggers about 100x times more
   compared to 5.13, 5.14, 5.16 kernels, etc. This was measured with the
   bpftrace script I provided him at [1], and he's including part of it
   in his test script from this thread too;

2) If an inode is evicted, reloaded and then we attempt to do a rename on
   it, it can trigger unnecessary log updates, for the inode and/or the
   parent directory. This is just btrfs not knowing if the inode was
   previously logged in the current transaction before the inode was
   evicted - since it doesn't know for sure, it assumes the worst case,
   that is was logged, and then updates the log (partially relog the inode
   and its parent directory), otherwise we could get into an inconsistency
   in case it was logged before and we don't update the log;

3) About the excessive inode eviction, there's nothing we can do in btrfs,
   it's outside btrfs' control;

4) What can be done, and was done in a recent patchset [2] (5.18-rc1), was
   to make the behaviour on rename to not be so pessimistic, and instead
   accurately determine if an inode was logged before or not, even if it was
   recently evicted, and then skip log updates.

   The test scripts in the change logs of the patches of that patchset,
   essentially mimic what was happening with the zypper package
   installations/updates. Bruno's test script basically copies/integrates
   those test scripts;

5) We can not just backport that patchset [2] into 5.15, because that depends
   on several other patchsets that landed in 5.16, 5.17 and 5.18-rc1, which
   mostly do a heavy rework regarding directory logging:

   https://lore.kernel.org/linux-btrfs/cover.1630419897.git.fdmanana@suse.com/ (5.16)
   https://lore.kernel.org/linux-btrfs/cover.1631787796.git.fdmanana@suse.com/ (5.16)
   https://lore.kernel.org/linux-btrfs/cover.1632482680.git.fdmanana@suse.com/ (5.16)
   https://lore.kernel.org/linux-btrfs/cover.1635178668.git.fdmanana@suse.com/ (5.17)
   https://lore.kernel.org/linux-btrfs/cover.1639568905.git.fdmanana@suse.com/ (5.18-rc1)

   And possibly other smaller dependencies in between those patchsets;

6) In short, it is not known what causes the excessive evictions on 5.15
   on his machine for that specific workload - we don't have a commit to
   point at and say it caused a regression. The previously mentioned
   patchset ([2]) will however make things much better, performance wise, in
   case excessive inode eviction happens (regarding renames on btrfs).

This thread is also basically a revamp of an older thread [3].

[1] https://bugzilla.opensuse.org/show_bug.cgi?id=1193549
[2] https://lore.kernel.org/linux-btrfs/cover.1642676248.git.fdmanana@suse.com/
[3] https://lore.kernel.org/linux-fsdevel/MN2PR20MB251235DDB741CD46A9DD5FAAD24E9@MN2PR20MB2512.namprd20.prod.outlook.com/

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Thorsten Leemhuis]

First off: David, Filipe, many thx for your answers, that helped me a
lot to get a better picture of the situation!

On 08.04.22 17:55, Filipe Manana wrote:
> On Fri, Apr 08, 2022 at 04:52:22PM +0200, David Sterba wrote:
>> On Fri, Apr 08, 2022 at 12:32:20PM +0200, Thorsten Leemhuis wrote:
>>> Hi, this is your Linux kernel regression tracker. Top-posting for once,
>>> to make this easily accessible to everyone.
>>>
>>> Btrfs maintainers, what's up here? Yes, this regression report was a bit
>>> confusing in the beginning, but Bruno worked on it. And apparently it's
>>> already fixed in 5.16, but still in 5.15. Is this caused by a change
>>> that is to big to backport or something?
>>
>> I haven't identified possible fixes in 5.16 so I can't tell how much
>> backport efforts it could be. As the report is related to performance on
>> package updates, my best guess is that the patches fixing it are those
>> from Filipe related to fsync/logging, and there are several of such
>> improvements in 5.16. Or something else that fixes it indirectly.
> 
> So there's a lot of confusion in the thread,

Yeah, definitely. That basically why I had hoped from a rough assessment
from the btrfs maintainers.

> and the original openSUSE 
> bugzilla [1] is also a bit confusing and large to follow.
> 
> Let me try to make it clear:
> 
> 1) For some reason, outside btrfs' control, inode eviction is triggered
>    a lot on 5.15 kernels in Bruno's test machine when doing package
>    installations/updates with zypper.

So I assume there are no other reports like this? Great!

> [...]

> 6) In short, it is not known what causes the excessive evictions on 5.15
>    on his machine for that specific workload - we don't have a commit to
>    point at and say it caused a regression. [...]

Bruno, under these circumstances I'd say you need to bisect this to get
us closer to the root of the problem (and a fix for it). Sadly that how
it is sometimes, as briefly explained here:

https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/tree/Documentation/admin-guide/reporting-regressions.rst#n140

> This thread is also basically a revamp of an older thread [3].
> 
> [1] https://bugzilla.opensuse.org/show_bug.cgi?id=1193549
> [2] https://lore.kernel.org/linux-btrfs/cover.1642676248.git.fdmanana@suse.com/
> [3] https://lore.kernel.org/linux-fsdevel/MN2PR20MB251235DDB741CD46A9DD5FAAD24E9@MN2PR20MB2512.namprd20.prod.outlook.com/

Yeah, but it was this thread that made me aware of the issue -- and just
like [3] it didn't get a single reply from a btrfs maintainer, so I had
to assume the report was ignored. A quick "we have no idea what my cause
this issue and it's the only report with such symptoms so far; could you
please bisect" would have made me happy already. :-D

Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)

P.S.: As the Linux kernel's regression tracker I'm getting a lot of
reports on my table. I can only look briefly into most of them and lack
knowledge about most of the areas they concern. I thus unfortunately
will sometimes get things wrong or miss something important. I hope
that's not the case here; if you think it is, don't hesitate to tell me
in a public reply, it's in everyone's interest to set the public record
straight.

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Bruno Damasceno Freire]

On 08.04.22 17:55, Filipe Manana wrote:
> On Fri, Apr 08, 2022 at 04:52:22PM +0200, David Sterba wrote:
> > On Fri, Apr 08, 2022 at 12:32:20PM +0200, Thorsten Leemhuis wrote:
> > > Hi, this is your Linux kernel regression tracker. Top-posting for once,
> > > to make this easily accessible to everyone.
> > >
> > > Btrfs maintainers, what's up here? Yes, this regression report was a bit
> > > confusing in the beginning, but Bruno worked on it. And apparently it's
> > > already fixed in 5.16, but still in 5.15. Is this caused by a change
> > > that is to big to backport or something?
> >
> > I haven't identified possible fixes in 5.16 so I can't tell how much
> > backport efforts it could be. As the report is related to performance on
> > package updates, my best guess is that the patches fixing it are those
> > from Filipe related to fsync/logging, and there are several of such
> > improvements in 5.16. Or something else that fixes it indirectly.
> 
> So there's a lot of confusion in the thread, and the original openSUSE
> bugzilla [1] is also a bit confusing and large to follow.

Sorry for the confusion.
It was not my intention.

> Let me try to make it clear:
> 
> [...]
> 
> 4) What can be done, and was done in a recent patchset [2] (5.18-rc1), was
>    to make the behaviour on rename to not be so pessimistic, and instead
>    accurately determine if an inode was logged before or not, even if it was
>    recently evicted, and then skip log updates.
> 
>    The test scripts in the change logs of the patches of that patchset,
>    essentially mimic what was happening with the zypper package
>    installations/updates. Bruno's test script basically copies/integrates
>    those test scripts;

I'm not sure if I understood why you are bringing out this last comparison.
Your test scripts don't trigger the regression, which is fine since they were
not made with this objective.

If you look at my research (https://github.com/bdamascen0/s3e) you'll see
that I clearly named you and your patches as my references.

Anyway, thank you for having published them.

> [...]
> 
> This thread is also basically a revamp of an older thread [3].
>
> [1] https://bugzilla.opensuse.org/show_bug.cgi?id=1193549
> [2] https://lore.kernel.org/linux-btrfs/cover.1642676248.git.fdmanana@suse.com/
> [3] https://lore.kernel.org/linux-fsdevel/MN2PR20MB251235DDB741CD46A9DD5FAAD24E9@MN2PR20MB2512.namprd20.prod.outlook.com/

Yes, it is a revamp for a reason:
- The older thread was 100% based on opensuse, rpm, tumbleweed kernels and
  tumbleweed rpm packages which is a hard selling point to attract any
  contribution.
- OTOH, this thread has a simple script that anyone can run on any
  distribution to reproduce the regression and further research it.

In my book, this is progress, even if its a tiny one.

Regards, Bruno.

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Bruno Damasceno Freire]

On 08.04.22 04:50, Thorsten Leemhuis wrote:
> First off: David, Filipe, many thx for your answers, that helped me a
> lot to get a better picture of the situation!
> 
> On 08.04.22 17:55, Filipe Manana wrote:
>> On Fri, Apr 08, 2022 at 04:52:22PM +0200, David Sterba wrote:
>>> On Fri, Apr 08, 2022 at 12:32:20PM +0200, Thorsten Leemhuis wrote:
>>>> Hi, this is your Linux kernel regression tracker. Top-posting for once,
>>>> to make this easily accessible to everyone.
>>>>
>>>> Btrfs maintainers, what's up here? Yes, this regression report was a bit
>>>> confusing in the beginning, but Bruno worked on it. And apparently it's
>>>> already fixed in 5.16, but still in 5.15. Is this caused by a change
>>>> that is to big to backport or something?
>>>
>>> I haven't identified possible fixes in 5.16 so I can't tell how much
>>> backport efforts it could be. As the report is related to performance on
>>> package updates, my best guess is that the patches fixing it are those
>>> from Filipe related to fsync/logging, and there are several of such
>>> improvements in 5.16. Or something else that fixes it indirectly.
>>
>> So there's a lot of confusion in the thread,
> 
> Yeah, definitely. That basically why I had hoped from a rough assessment
> from the btrfs maintainers.
> 
>> and the original openSUSE
>> bugzilla [1] is also a bit confusing and large to follow.
>>
>> Let me try to make it clear:
>>
>> 1) For some reason, outside btrfs' control, inode eviction is triggered
>>    a lot on 5.15 kernels in Bruno's test machine when doing package
>>    installations/updates with zypper.
> 
> So I assume there are no other reports like this? Great!

Well, "inode eviction is triggered a lot on 5.15 kernels in Bruno's test
machine when doing package installations/updates with zypper" is a little
misleading IMHO. While this was true at the very beginning it became more
than that. Now the high inode eviction is already know to be 100%
reproducible on:
- at least one real workload (opensuse package update).
- 3 different bare metal machines with different hardware configuration.
- 3 different cpus from 2 different cpu manufactures.
- one synthetic worklod (the scripts I provided).
- 4 different distributions on virtual machines.
- all 5.15 kernels that I tried on.

About the lack of reports, my only guess is that most users must choose the
compress mount option instead of manually setting the compression property:
- the compress mount option doesn't trigger the regression.
- the compression property does trigger the regression.

>> [...]
> 
>> 6) In short, it is not known what causes the excessive evictions on 5.15
>>    on his machine for that specific workload - we don't have a commit to
>>    point at and say it caused a regression. [...]
> 
> Bruno, under these circumstances I'd say you need to bisect this to get
> us closer to the root of the problem (and a fix for it). Sadly that how
> it is sometimes, as briefly explained here:
> 
> https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/tree/Documentation/admin-guide/reporting-regressions.rst#n140

Ok Thorsten.

It's not sad at all: I had a great time researching this regression and
gained a lot of knowledge while doing so. The problem is that I am just a
simple user at its limits here and additional bisection is probably beyond my
abilities. I can only hope some kernel developer feels motivated to further
investigate this subject.

Again, sorry for the confusion and thanks a lot for your patience and for the
directions.

>> This thread is also basically a revamp of an older thread [3].
>>
>> [1] https://bugzilla.opensuse.org/show_bug.cgi?id=1193549
>> [2] https://lore.kernel.org/linux-btrfs/cover.1642676248.git.fdmanana@suse.com/
>> [3] https://lore.kernel.org/linux-fsdevel/MN2PR20MB251235DDB741CD46A9DD5FAAD24E9@MN2PR20MB2512.namprd20.prod.outlook.com/
> 
> Yeah, but it was this thread that made me aware of the issue -- and just
> like [3] it didn't get a single reply from a btrfs maintainer, so I had
> to assume the report was ignored. A quick "we have no idea what my cause
> this issue and it's the only report with such symptoms so far; could you
> please bisect" would have made me happy already. :-D
> 
> Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)
> 
> P.S.: As the Linux kernel's regression tracker I'm getting a lot of
> reports on my table. I can only look briefly into most of them and lack
> knowledge about most of the areas they concern. I thus unfortunately
> will sometimes get things wrong or miss something important. I hope
> that's not the case here; if you think it is, don't hesitate to tell me
> in a public reply, it's in everyone's interest to set the public record
> straight.
> 

Grazie, Bruno.

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Thorsten Leemhuis]

On 09.04.22 19:12, Bruno Damasceno Freire wrote:
> On 08.04.22 04:50, Thorsten Leemhuis wrote:
>> First off: David, Filipe, many thx for your answers, that helped me a
>> lot to get a better picture of the situation!
>> On 08.04.22 17:55, Filipe Manana wrote:
>>> On Fri, Apr 08, 2022 at 04:52:22PM +0200, David Sterba wrote:
>>>> On Fri, Apr 08, 2022 at 12:32:20PM +0200, Thorsten Leemhuis wrote:
>
>>> [...]
>>
>>> 6) In short, it is not known what causes the excessive evictions on 5.15
>>>    on his machine for that specific workload - we don't have a commit to
>>>    point at and say it caused a regression. [...]
>>
>> Bruno, under these circumstances I'd say you need to bisect this to get
>> us closer to the root of the problem (and a fix for it). Sadly that how
>> it is sometimes, as briefly explained here:
>>
>> https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/tree/Documentation/admin-guide/reporting-regressions.rst#n140
> 
> Ok Thorsten.
> 
> It's not sad at all: I had a great time researching this regression and
> gained a lot of knowledge while doing so. The problem is that I am just a
> simple user at its limits here and additional bisection is probably beyond my
> abilities.

Maybe, but I think you underestimate yourself here. Give it a try, it's
not that hard once you figured out how to build and install a vanilla
kernel (which you did already afaics; and if not: it's not that hard and
you learn new stuff, too) and have some test case to check if the
problem is there or now (which you already have afaics).

Ciao, Thorsten

Re: [regression] 5.15 kernel triggering 100x more inode evictions

[Nicholas D Steeves]

[-- Attachment #1: Type: text/plain, Size: 2404 bytes --]

Hi Bruno,

Thorsten Leemhuis <regressions@leemhuis.info> writes:

> On 09.04.22 19:12, Bruno Damasceno Freire wrote:
>> On 08.04.22 04:50, Thorsten Leemhuis wrote:
>>> On 08.04.22 17:55, Filipe Manana wrote:
>>>> On Fri, Apr 08, 2022 at 04:52:22PM +0200, David Sterba wrote:
>>>>> On Fri, Apr 08, 2022 at 12:32:20PM +0200, Thorsten Leemhuis wrote:
>>> Bruno, under these circumstances I'd say you need to bisect this to get
>>> us closer to the root of the problem (and a fix for it). Sadly that how
>>> it is sometimes, as briefly explained here:
>>>
>>> https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/tree/Documentation/admin-guide/reporting-regressions.rst#n140
>> 
>> Ok Thorsten.
>> 
>> It's not sad at all: I had a great time researching this regression and
>> gained a lot of knowledge while doing so. The problem is that I am just a
>> simple user at its limits here and additional bisection is probably beyond my
>> abilities.
>
> Maybe, but I think you underestimate yourself here. Give it a try, it's
> not that hard once you figured out how to build and install a vanilla
> kernel (which you did already afaics; and if not: it's not that hard and
> you learn new stuff, too) and have some test case to check if the
> problem is there or now (which you already have afaics).
>

I also think it's something you can manage :-)

Something like:

1. Use the .config from /boot/config-ubuntu_5.14.x
2. git bisect start
3. git bisect good v5.14 (7d2a07b)
4. git bisect bad v5.15 (8bb7eca)
5. Open a guide like these ones on another device, or print it out:
  https://www.metaltoad.com/blog/beginners-guide-git-bisect-process-elimination
  https://wiki.gentoo.org/wiki/Kernel_git-bisect
  https://wiki.ubuntu.com/Kernel/KernelBisection
  https://ldpreload.com/blog/git-bisect-run ("Finding a kernel
  regression in half an hour with git bisect run")
6. make oldconfig
7. make bindeb-pkg
8. Deb packages are in ../
9. Install, reboot, run tests, confirm logs, iterate

Thank you for running these tests.  By chance, would you have time to
compare 5.10.x to 5.15.x, or have you already compared them?  I'm
always the most curious about how the latest LTS kernel compares to
latest_LTS-1 ;-)

Regards,
Nicholas

P.S. I'm sure you'll be able to find someone on IRC who'd be willing to
help you, should any help be necessary!

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 857 bytes --]