btrfs seems extremely slow on kernel 5.15

[Paulo da Silva]

Hi!

I have a USB external backup volume with btrfs.
The backup script is a simple cp -al <prev> <next> followed by a rsync
to update <next>.

The cp -al took 10-20 mins. in kernel 5.13 and before that.
Now, with 5.15, without any changes, it is taking a few hours!!

NOTES:
I have noticed that before, during the cp -al there were outputs to the
memory cache during which we could "visit" the drive followed by periods
of flushing where a simple attempt to change to another dir took a while
(sometimes ~1 min).

Now, I can always navigate inside the drive without any delay when cp
-al is in course! It seems like there is no memory cache although the
memory cache still grows and shrinks.

BTW, my mount command is
mount /dev/mapper/TEMP /mnt1 -onoatime,compress-force=zstd

There is an encryption layer below the fs.

Thanks for any comments.
Paulo

[J.O. Aho]

On 14/07/2022 04.16, Paulo da Silva wrote:
> Hi!
>
> I have a USB external backup volume with btrfs.
> The backup script is a simple cp -al <prev> <next> followed by a rsync
> to update <next>.

I prefer to use snapshots and then send/receive, this tend to take a lot
shorter time than cp or rsync as you will only send the changes and
nothing more.

> The cp -al took 10-20 mins. in kernel 5.13 and before that.
> Now, with 5.15, without any changes, it is taking a few hours!!

I don't remember which kernel 5 version had a change in local cache,
which could in some cases cause things to work differently.

Have you tested with other file system on a similar usb device? This to
figure out if it's related to btrfs or usb.

There are speed optimization in 5.16 regarding btrfs, so an upgrade
could be good.

> Now, I can always navigate inside the drive without any delay when cp
> -al is in course! It seems like there is no memory cache although the
> memory cache still grows and shrinks.
>
> BTW, my mount command is
> mount /dev/mapper/TEMP /mnt1 -onoatime,compress-force=zstd > There is an encryption layer below the fs.

Could be this that causing the problem and not btrfs itself.

I would recommend you check up changes in the crypto layer too.

Also it could be a combination of crypto + btrfs, but should in such
case been resolved in later kernel versions.

--

//Aho

[Paul]

What happens if you turn off the encryption ?

I would want to study the component parts of
the stack, to see if they behave decently by
themselves.

Even if you temporarily had two disk drives,
one set up with the full stack of stuff,
the second drive with the encryption layer
nullified, that may allow you to bench the
two and see how much worse one is than the other.

Paul

[Andrei Z.]

Latency issue with encrypted and compressed BTRFS filesystem - Stack
Overflow
https://stackoverflow.com/questions/69962997/latency-issue-with-encrypted-and-compressed-btrfs-filesystem/72566823

"I have switched to Fedora 36 without modifying the default hard disk
auto configuration and BTRFS is working like a charm. Very very fast. So
I might have missed something on my configuration" – Jun 11

Fedora 36 - Kernel 5.17

[Paulo da Silva]

Às 11:35 de 14/07/22, J.O. Aho escreveu:

>
> On 14/07/2022 04.16, Paulo da Silva wrote:
>> Hi!
>>
>> I have a USB external backup volume with btrfs.
>> The backup script is a simple cp -al <prev> <next> followed by a rsync
>> to update <next>.
>
> I prefer to use snapshots and then send/receive, this tend to take a lot
> shorter time than cp or rsync as you will only send the changes and
> nothing more.

The script I wrote also allow for snapshots.
But I tend to have a lot of them for copies I need to last for a year,
for ex.
And for a big number of snapshots the fs tend to get problems, at least
for kernels until 5.13.
In my work disk I had "btrfs check" issues which disappeared after
deleting all snapshots.

>
>
>> The cp -al took 10-20 mins. in kernel 5.13 and before that.
>> Now, with 5.15, without any changes, it is taking a few hours!!
>
> I don't remember which kernel 5 version had a change in local cache,
> which could in some cases cause things to work differently.
>
> Have you tested with other file system on a similar usb device? This to
> figure out if it's related to btrfs or usb.

I don't have a spare USB to test. These are 4TB disks and are all being
used!
...

> I would recommend you check up changes in the crypto layer too.
>
> Also it could be a combination of crypto + btrfs, but should in such
> case been resolved in later kernel versions.

Are there any parameters I can play with in the crypto layer?

[Paulo da Silva]

Às 15:48 de 14/07/22, Andrei Z. escreveu:

This not a CPU overhead. I have a very powerfull CPU (5GHz) 8 core.

Currently cp -al copies a little bit more than 1000 files per minute.
This is too low.
As much as I know, it only have to make an enter in the tree of file
names and increment a counter per file. Caching, this should take very
short times.
As I said, now the drive is always ready for navigation inside it!
Before, sometimes I needed to wait a minute or perhaps more when it is
in the flushing process (I have 32GB RAM). So, there was a change in the
way memory cache is handled by btrfs now.

[Paulo da Silva]

Às 12:00 de 14/07/22, Paul escreveu:

Unfortunately I cannot test this. I needed a spare similar drive which I
don't have now.

[J.O. Aho]

On 14/07/2022 18.34, Paulo da Silva wrote:

>> I would recommend you check up changes in the crypto layer too.
>>
>> Also it could be a combination of crypto + btrfs, but should in such
>> case been resolved in later kernel versions.
> Are there any parameters I can play with in the crypto layer?

Much depends on the crypto layer you are using, there was some years ago
some changes in luksfs that made some performance difference depending
if you had older/newer type of "crypto-key".

I tend to be quite conservative when I use encryption to change on the
settings, so that I don't break it, so I usually use defaults.

Not sure how it's with other cryptos like VeraCrypt/TrueCrypt and so on...

--

//Aho

[Paulo da Silva]

Às 03:16 de 14/07/22, Paulo da Silva escreveu:

There must be something very wrong with this 5.15 btrfs in kubuntu 20.04!
cp -al is more than 16 times faster in 5.13 (btrfs+luks+usb)!!

[Andrei Z.]

In both cases they don't mention CPU overhead - only "latency", "long
time" and here
https://www.reddit.com/r/pop_os/comments/ry72tb/really_poor_btrfs_performance_on_clean_install/
"5.15.12 and btrfs v5.15.1"

[Andrei Z.]

btrfs is under active development
https://btrfs.wiki.kernel.org/index.php/Changelog

[Paulo da Silva]

Às 04:37 de 15/07/22, Andrei Z. escreveu:

From the first link response:
"The luks encryption is probably the biggest latency hog. Than you can
try to switch off zstd compression. Both take severely cpu cycles and
cause your latency issues!"

It's very unlikely this thing has something to do with cpu cycles.

As I said, it is very strange that while cp -al is running, in 5.15 I
can always access the drive without any delay!
In 5.13 and before, there were periods (~1 min, sometimes more), when
flushing, that access to the drive completely blocks. Out of those
periods I can access it normally.
Notice that I have 32GB RAM. So the long flushing periods.

In 5.15 cp -al copies a little more than 1000 files per minute while in
5.13 it copies more than 16000! This is a huge difference and a no go.

Regards.
Paulo

[Paulo da Silva]

Às 04:39 de 15/07/22, Andrei Z. escreveu:

Because of its features I am using it since the I was unable to
jeopardize the fs. Never had such issue.

[Paul]

Do you use "slabtop" to examine cache memory usage ?

https://wiki.gentoo.org/wiki/Btrfs/en

root # slabtop

Active / Total Objects (% used) : 5011373 / 5052626 (99.2%)
Active / Total Slabs (% used) : 1158843 / 1158843 (100.0%)
Active / Total Caches (% used) : 103 / 220 (46.8%)
Active / Total Size (% used) : 3874182.66K / 3881148.34K (99.8%)
Minimum / Average / Maximum Object : 0.02K / 0.77K / 4096.00K

OBJS ACTIVE USE OBJ SIZE SLABS OBJ/SLAB CACHE SIZE NAME
2974761 2974485 99% 1.10K 991587 3 3966348K btrfs_inode
1501479 1496052 99% 0.19K 71499 21 285996K dentry

Paul

[J.O. Aho]

On 15/07/2022 07.28, Paulo da Silva wrote:

> It's very unlikely this thing has something to do with cpu cycles.
>
> As I said, it is very strange that while cp -al is running, in 5.15 I
> can always access the drive without any delay!
> In 5.13 and before, there were periods (~1 min, sometimes more), when
> flushing, that access to the drive completely blocks. Out of those
> periods I can access it normally.
> Notice that I have 32GB RAM. So the long flushing periods.
>
> In 5.15 cp -al copies a little more than 1000 files per minute while in
> 5.13 it copies more than 16000! This is a huge difference and a no go.

What do you get when you hook up the usb drive in dmesg?

something like
[ 1367542] sd 0:0:0:0: [sdb] Write cache: enabled, read cache:
enabled, doesn't support DPO or FUA

In such cases it could be related to this bug:
https://bugzilla.kernel.org/show_bug.cgi?id=215137

--
//Aho

[Andrei Z.]

Linux 5.15.54
https://lwn.net/Articles/900911/

"All users of the 5.15 kernel series must upgrade." :)

[Paulo da Silva]

Às 08:21 de 15/07/22, Paul escreveu:

No, I just hava a small applet where I can find that the whole cache
mamory grows up to the almost limit of physical memory and then shrinks
to almost nothing. This is, as much as I can see, the same for 5.13 and
5.15. Neverthless the behaviour of the drive is completely different.

Thanks Paul for the suggestion. I'll take a look at that.

Paulo

[Paulo da Silva]

Às 10:54 de 15/07/22, Andrei Z. escreveu:

I am using the last version available in *ubuntu, i.e. 5.15.0 :-(
Thanks
Paulo

[Paulo da Silva]

Às 09:12 de 15/07/22, J.O. Aho escreveu:

> On 15/07/2022 07.28, Paulo da Silva wrote:
>
>> It's very unlikely this thing has something to do with cpu cycles.
>>
>> As I said, it is very strange that while cp -al is running, in 5.15 I
>> can always access the drive without any delay!
>> In 5.13 and before, there were periods (~1 min, sometimes more), when
>> flushing, that access to the drive completely blocks. Out of those
>> periods I can access it normally.
>> Notice that I have 32GB RAM. So the long flushing periods.
>>
>> In 5.15 cp -al copies a little more than 1000 files per minute while
>> in 5.13 it copies more than 16000! This is a huge difference and a no go.
>
> What do you get when you hook up the usb drive in dmesg?
>
> something like
> [     1367542] sd 0:0:0:0: [sdb] Write cache: enabled, read cache:
> enabled, doesn't support DPO or FUA
>

Can't find anything like this! Thanks anyway.

[Paulo da Silva]

Às 03:16 de 14/07/22, Paulo da Silva escreveu:

Testing with hdparm -tTv, the drive has the same values for both kernels!

Paulo

[Mark Bourne]

If I've understood the bug report correctly, the line Aho posted is what
would be expected in the working 5.15.4 kernel, while the problematic
one instead has:
[ 2.607070] sd 0:0:0:0: [sda] Asking for cache data failed
[ 2.607109] sd 0:0:0:0: [sda] Assuming drive cache: write through

So if you have those lines, and not the one Aho mentioned, it might be
that bug. Looks like it's fixed in 5.15.6. I think Ubuntu cherry-pick
certain fixes/changes from newer kernels, so it may be that they pulled
the problematic change into 5.15.0-something and hopefully will pull the
fix into 5.15.0-something_newer.

--
Mark.

[Paulo da Silva]

Às 12:15 de 16/07/22, Mark Bourne escreveu:

No, I don't see any of these messages.
Thank you.