All of lore.kernel.org
 help / color / mirror / Atom feed
* Still seeing high autodefrag IO with kernel 5.16.5
@ 2022-02-03 20:05 Benjamin Xiao
  2022-02-04  1:17 ` Qu Wenruo
  0 siblings, 1 reply; 16+ messages in thread
From: Benjamin Xiao @ 2022-02-03 20:05 UTC (permalink / raw)
  To: linux-btrfs

Hello all,

Even after the defrag patches that landed in 5.16.5, I am still seeing 
lots of cpu usage and disk writes to my SSD when autodefrag is enabled. 
I kinda expected slightly more IO during writes compared to 5.15, but 
what I am actually seeing is massive amounts of btrfs-cleaner i/o even 
when no programs are actively writing to the disk.

I can reproduce it quite reliably on my 2TB Btrfs Steam library 
partition. In my case, I was downloading Strange Brigade, which is a 
roughly 25GB download and 33.65GB on disk. Somewhere during the 
download, iostat will start reporting disk writes around 300 MB/s, even 
though Steam itself reports disk usage of 40-45MB/s. After the download 
finishes and nothing else is being written to disk, I still see around 
90-150MB/s worth of disk writes. Checking in iotop, I can see btrfs 
cleaner and other btrfs processes writing a lot of data.

I left it running for a while to see if it was just some maintenance 
tasks that Btrfs needed to do, but it just kept going. I tried to 
reboot, but it actually prevented me from properly rebooting. After 
systemd timed out, my system finally shutdown.

Here are my mount options:
rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/

I've disabled autodefrag again for now to save my SSD, but just wanted 
to say that there is still an issue. Have the defrag issues been fully 
fixed or are there more patches incoming despite what Reddit and 
Phoronix say? XD

Thanks!
Ben



^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-03 20:05 Still seeing high autodefrag IO with kernel 5.16.5 Benjamin Xiao
@ 2022-02-04  1:17 ` Qu Wenruo
  2022-02-04  1:54   ` Qu Wenruo
  0 siblings, 1 reply; 16+ messages in thread
From: Qu Wenruo @ 2022-02-04  1:17 UTC (permalink / raw)
  To: Benjamin Xiao, linux-btrfs



On 2022/2/4 04:05, Benjamin Xiao wrote:
> Hello all,
>
> Even after the defrag patches that landed in 5.16.5, I am still seeing
> lots of cpu usage and disk writes to my SSD when autodefrag is enabled.
> I kinda expected slightly more IO during writes compared to 5.15, but
> what I am actually seeing is massive amounts of btrfs-cleaner i/o even
> when no programs are actively writing to the disk.
>
> I can reproduce it quite reliably on my 2TB Btrfs Steam library
> partition. In my case, I was downloading Strange Brigade, which is a
> roughly 25GB download and 33.65GB on disk. Somewhere during the
> download, iostat will start reporting disk writes around 300 MB/s, even
> though Steam itself reports disk usage of 40-45MB/s. After the download
> finishes and nothing else is being written to disk, I still see around
> 90-150MB/s worth of disk writes. Checking in iotop, I can see btrfs
> cleaner and other btrfs processes writing a lot of data.
>
> I left it running for a while to see if it was just some maintenance
> tasks that Btrfs needed to do, but it just kept going. I tried to
> reboot, but it actually prevented me from properly rebooting. After
> systemd timed out, my system finally shutdown.
>
> Here are my mount options:
> rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/

Compression, I guess that's the reason.

 From the very beginning, btrfs defrag doesn't handle compressed extent
well.

Even if a compressed extent is already at its maximum capacity, btrfs
will still try to defrag it.

I believe the behavior is masked by other problems in older kernels thus
not that obvious.

But after rework of defrag in v5.16, this behavior is more exposed.

There are patches to address the compression related problem, but not
yet merged:

https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387

Mind to test them to see if that's the case?

Thanks,
Qu
>
>
> I've disabled autodefrag again for now to save my SSD, but just wanted
> to say that there is still an issue. Have the defrag issues been fully
> fixed or are there more patches incoming despite what Reddit and
> Phoronix say? XD
>
> Thanks!
> Ben
>
>

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-04  1:17 ` Qu Wenruo
@ 2022-02-04  1:54   ` Qu Wenruo
  2022-02-04  4:32     ` Benjamin Xiao
       [not found]     ` <SL2P216MB11112B447FB0400149D320C1AC2B9@SL2P216MB1111.KORP216.PROD.OUTLOOK.COM>
  0 siblings, 2 replies; 16+ messages in thread
From: Qu Wenruo @ 2022-02-04  1:54 UTC (permalink / raw)
  To: Benjamin Xiao, linux-btrfs



On 2022/2/4 09:17, Qu Wenruo wrote:
>
>
> On 2022/2/4 04:05, Benjamin Xiao wrote:
>> Hello all,
>>
>> Even after the defrag patches that landed in 5.16.5, I am still seeing
>> lots of cpu usage and disk writes to my SSD when autodefrag is enabled.
>> I kinda expected slightly more IO during writes compared to 5.15, but
>> what I am actually seeing is massive amounts of btrfs-cleaner i/o even
>> when no programs are actively writing to the disk.
>>
>> I can reproduce it quite reliably on my 2TB Btrfs Steam library
>> partition. In my case, I was downloading Strange Brigade, which is a
>> roughly 25GB download and 33.65GB on disk. Somewhere during the
>> download, iostat will start reporting disk writes around 300 MB/s, even
>> though Steam itself reports disk usage of 40-45MB/s. After the download
>> finishes and nothing else is being written to disk, I still see around
>> 90-150MB/s worth of disk writes. Checking in iotop, I can see btrfs
>> cleaner and other btrfs processes writing a lot of data.
>>
>> I left it running for a while to see if it was just some maintenance
>> tasks that Btrfs needed to do, but it just kept going. I tried to
>> reboot, but it actually prevented me from properly rebooting. After
>> systemd timed out, my system finally shutdown.
>>
>> Here are my mount options:
>> rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/
>>
>
> Compression, I guess that's the reason.
>
>  From the very beginning, btrfs defrag doesn't handle compressed extent
> well.
>
> Even if a compressed extent is already at its maximum capacity, btrfs
> will still try to defrag it.
>
> I believe the behavior is masked by other problems in older kernels thus
> not that obvious.
>
> But after rework of defrag in v5.16, this behavior is more exposed.

And if possible, please try this diff on v5.15.x, and see if v5.15 is
really doing less IO than v5.16.x.

The diff will solve a problem in the old code, where autodefrag is
almost not working.

diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
index cc61813213d8..f6f2468d4883 100644
--- a/fs/btrfs/ioctl.c
+++ b/fs/btrfs/ioctl.c
@@ -1524,13 +1524,8 @@ int btrfs_defrag_file(struct inode *inode, struct
file *file,
                         continue;
                 }

-               if (!newer_than) {
-                       cluster = (PAGE_ALIGN(defrag_end) >>
-                                  PAGE_SHIFT) - i;
-                       cluster = min(cluster, max_cluster);
-               } else {
-                       cluster = max_cluster;
-               }
+               cluster = (PAGE_ALIGN(defrag_end) >> PAGE_SHIFT) - i;
+               cluster = min(cluster, max_cluster);

                 if (i + cluster > ra_index) {
                         ra_index = max(i, ra_index);

>
> There are patches to address the compression related problem, but not
> yet merged:
>
> https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387
>
> Mind to test them to see if that's the case?
>
> Thanks,
> Qu
>>
>>
>> I've disabled autodefrag again for now to save my SSD, but just wanted
>> to say that there is still an issue. Have the defrag issues been fully
>> fixed or are there more patches incoming despite what Reddit and
>> Phoronix say? XD
>>
>> Thanks!
>> Ben
>>
>>

^ permalink raw reply related	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-04  1:54   ` Qu Wenruo
@ 2022-02-04  4:32     ` Benjamin Xiao
  2022-02-04  6:20       ` Qu Wenruo
       [not found]     ` <SL2P216MB11112B447FB0400149D320C1AC2B9@SL2P216MB1111.KORP216.PROD.OUTLOOK.COM>
  1 sibling, 1 reply; 16+ messages in thread
From: Benjamin Xiao @ 2022-02-04  4:32 UTC (permalink / raw)
  To: Qu Wenruo; +Cc: linux-btrfs

Okay, I just compiled a custom Arch kernel with your patches applied. 
Will test soon. Besides enabling autodefrag and redownloading a game 
from Steam, what other sorts of tests should I do?

Ben

On Fri, Feb 4 2022 at 09:54:19 AM +0800, Qu Wenruo 
<quwenruo.btrfs@gmx.com> wrote:
> 
> 
> On 2022/2/4 09:17, Qu Wenruo wrote:
>> 
>> 
>> On 2022/2/4 04:05, Benjamin Xiao wrote:
>>> Hello all,
>>> 
>>> Even after the defrag patches that landed in 5.16.5, I am still 
>>> seeing
>>> lots of cpu usage and disk writes to my SSD when autodefrag is 
>>> enabled.
>>> I kinda expected slightly more IO during writes compared to 5.15, 
>>> but
>>> what I am actually seeing is massive amounts of btrfs-cleaner i/o 
>>> even
>>> when no programs are actively writing to the disk.
>>> 
>>> I can reproduce it quite reliably on my 2TB Btrfs Steam library
>>> partition. In my case, I was downloading Strange Brigade, which is a
>>> roughly 25GB download and 33.65GB on disk. Somewhere during the
>>> download, iostat will start reporting disk writes around 300 MB/s, 
>>> even
>>> though Steam itself reports disk usage of 40-45MB/s. After the 
>>> download
>>> finishes and nothing else is being written to disk, I still see 
>>> around
>>> 90-150MB/s worth of disk writes. Checking in iotop, I can see btrfs
>>> cleaner and other btrfs processes writing a lot of data.
>>> 
>>> I left it running for a while to see if it was just some maintenance
>>> tasks that Btrfs needed to do, but it just kept going. I tried to
>>> reboot, but it actually prevented me from properly rebooting. After
>>> systemd timed out, my system finally shutdown.
>>> 
>>> Here are my mount options:
>>> rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/
>>> 
>> 
>> Compression, I guess that's the reason.
>> 
>>  From the very beginning, btrfs defrag doesn't handle compressed 
>> extent
>> well.
>> 
>> Even if a compressed extent is already at its maximum capacity, btrfs
>> will still try to defrag it.
>> 
>> I believe the behavior is masked by other problems in older kernels 
>> thus
>> not that obvious.
>> 
>> But after rework of defrag in v5.16, this behavior is more exposed.
> 
> And if possible, please try this diff on v5.15.x, and see if v5.15 is
> really doing less IO than v5.16.x.
> 
> The diff will solve a problem in the old code, where autodefrag is
> almost not working.
> 
> diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
> index cc61813213d8..f6f2468d4883 100644
> --- a/fs/btrfs/ioctl.c
> +++ b/fs/btrfs/ioctl.c
> @@ -1524,13 +1524,8 @@ int btrfs_defrag_file(struct inode *inode, 
> struct
> file *file,
>                         continue;
>                 }
> 
> -               if (!newer_than) {
> -                       cluster = (PAGE_ALIGN(defrag_end) >>
> -                                  PAGE_SHIFT) - i;
> -                       cluster = min(cluster, max_cluster);
> -               } else {
> -                       cluster = max_cluster;
> -               }
> +               cluster = (PAGE_ALIGN(defrag_end) >> PAGE_SHIFT) - i;
> +               cluster = min(cluster, max_cluster);
> 
>                 if (i + cluster > ra_index) {
>                         ra_index = max(i, ra_index);
> 
>> 
>> There are patches to address the compression related problem, but not
>> yet merged:
>> 
>> https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387
>> 
>> Mind to test them to see if that's the case?
>> 
>> Thanks,
>> Qu
>>> 
>>> 
>>> I've disabled autodefrag again for now to save my SSD, but just 
>>> wanted
>>> to say that there is still an issue. Have the defrag issues been 
>>> fully
>>> fixed or are there more patches incoming despite what Reddit and
>>> Phoronix say? XD
>>> 
>>> Thanks!
>>> Ben
>>> 
>>> 



^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-04  4:32     ` Benjamin Xiao
@ 2022-02-04  6:20       ` Qu Wenruo
  2022-02-04 17:36         ` Benjamin Xiao
  0 siblings, 1 reply; 16+ messages in thread
From: Qu Wenruo @ 2022-02-04  6:20 UTC (permalink / raw)
  To: Benjamin Xiao; +Cc: linux-btrfs



On 2022/2/4 12:32, Benjamin Xiao wrote:
> Okay, I just compiled a custom Arch kernel with your patches applied.
> Will test soon. Besides enabling autodefrag and redownloading a game
> from Steam, what other sorts of tests should I do?

As long as your workload can trigger the problem reliably, nothing else.

Thanks,
Qu

>
> Ben
>
> On Fri, Feb 4 2022 at 09:54:19 AM +0800, Qu Wenruo
> <quwenruo.btrfs@gmx.com> wrote:
>>
>>
>> On 2022/2/4 09:17, Qu Wenruo wrote:
>>>
>>>
>>> On 2022/2/4 04:05, Benjamin Xiao wrote:
>>>> Hello all,
>>>>
>>>> Even after the defrag patches that landed in 5.16.5, I am still seeing
>>>> lots of cpu usage and disk writes to my SSD when autodefrag is enabled.
>>>> I kinda expected slightly more IO during writes compared to 5.15, but
>>>> what I am actually seeing is massive amounts of btrfs-cleaner i/o even
>>>> when no programs are actively writing to the disk.
>>>>
>>>> I can reproduce it quite reliably on my 2TB Btrfs Steam library
>>>> partition. In my case, I was downloading Strange Brigade, which is a
>>>> roughly 25GB download and 33.65GB on disk. Somewhere during the
>>>> download, iostat will start reporting disk writes around 300 MB/s, even
>>>> though Steam itself reports disk usage of 40-45MB/s. After the download
>>>> finishes and nothing else is being written to disk, I still see around
>>>> 90-150MB/s worth of disk writes. Checking in iotop, I can see btrfs
>>>> cleaner and other btrfs processes writing a lot of data.
>>>>
>>>> I left it running for a while to see if it was just some maintenance
>>>> tasks that Btrfs needed to do, but it just kept going. I tried to
>>>> reboot, but it actually prevented me from properly rebooting. After
>>>> systemd timed out, my system finally shutdown.
>>>>
>>>> Here are my mount options:
>>>> rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/
>>>>
>>>>
>>>
>>> Compression, I guess that's the reason.
>>>
>>>  From the very beginning, btrfs defrag doesn't handle compressed extent
>>> well.
>>>
>>> Even if a compressed extent is already at its maximum capacity, btrfs
>>> will still try to defrag it.
>>>
>>> I believe the behavior is masked by other problems in older kernels thus
>>> not that obvious.
>>>
>>> But after rework of defrag in v5.16, this behavior is more exposed.
>>
>> And if possible, please try this diff on v5.15.x, and see if v5.15 is
>> really doing less IO than v5.16.x.
>>
>> The diff will solve a problem in the old code, where autodefrag is
>> almost not working.
>>
>> diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
>> index cc61813213d8..f6f2468d4883 100644
>> --- a/fs/btrfs/ioctl.c
>> +++ b/fs/btrfs/ioctl.c
>> @@ -1524,13 +1524,8 @@ int btrfs_defrag_file(struct inode *inode, struct
>> file *file,
>>                         continue;
>>                 }
>>
>> -               if (!newer_than) {
>> -                       cluster = (PAGE_ALIGN(defrag_end) >>
>> -                                  PAGE_SHIFT) - i;
>> -                       cluster = min(cluster, max_cluster);
>> -               } else {
>> -                       cluster = max_cluster;
>> -               }
>> +               cluster = (PAGE_ALIGN(defrag_end) >> PAGE_SHIFT) - i;
>> +               cluster = min(cluster, max_cluster);
>>
>>                 if (i + cluster > ra_index) {
>>                         ra_index = max(i, ra_index);
>>
>>>
>>> There are patches to address the compression related problem, but not
>>> yet merged:
>>>
>>> https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387
>>>
>>> Mind to test them to see if that's the case?
>>>
>>> Thanks,
>>> Qu
>>>>
>>>>
>>>> I've disabled autodefrag again for now to save my SSD, but just wanted
>>>> to say that there is still an issue. Have the defrag issues been fully
>>>> fixed or are there more patches incoming despite what Reddit and
>>>> Phoronix say? XD
>>>>
>>>> Thanks!
>>>> Ben
>>>>
>>>>
>
>

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-04  6:20       ` Qu Wenruo
@ 2022-02-04 17:36         ` Benjamin Xiao
  2022-02-04 19:34           ` Benjamin Xiao
  0 siblings, 1 reply; 16+ messages in thread
From: Benjamin Xiao @ 2022-02-04 17:36 UTC (permalink / raw)
  To: Qu Wenruo; +Cc: linux-btrfs

Okay, I just tested right now with my custom 5.16.5 kernel with your 3 
patches applied. Redownloading the same game, I noticed that there was 
significantly less IO load during the download, which is great. It 
looked kinda bursty instead, with periods of no load, and then periods 
of load ranging in the 150-200MB/s range.

After the download, I am no longer getting that constant 90-150MB/s 
disk write from btrfs-cleaner, but I am seeing periodic bursts of it 
every 10 seconds or so. These bursts last for around 3 seconds and load 
is anywhere from 50-300MB/s.

Is this normal? Does autodefrag only defrag newly written data, or does 
it sometimes go back and run defrag on data written previously? I am 
gonna let it run for a bit to see if it eventually subsides.

Ben

On Fri, Feb 4 2022 at 02:20:44 PM +0800, Qu Wenruo 
<quwenruo.btrfs@gmx.com> wrote:
> 
> 
> On 2022/2/4 12:32, Benjamin Xiao wrote:
>> Okay, I just compiled a custom Arch kernel with your patches applied.
>> Will test soon. Besides enabling autodefrag and redownloading a game
>> from Steam, what other sorts of tests should I do?
> 
> As long as your workload can trigger the problem reliably, nothing 
> else.
> 
> Thanks,
> Qu
> 
>> 
>> Ben
>> 
>> On Fri, Feb 4 2022 at 09:54:19 AM +0800, Qu Wenruo
>> <quwenruo.btrfs@gmx.com> wrote:
>>> 
>>> 
>>> On 2022/2/4 09:17, Qu Wenruo wrote:
>>>> 
>>>> 
>>>> On 2022/2/4 04:05, Benjamin Xiao wrote:
>>>>> Hello all,
>>>>> 
>>>>> Even after the defrag patches that landed in 5.16.5, I am still 
>>>>> seeing
>>>>> lots of cpu usage and disk writes to my SSD when autodefrag is 
>>>>> enabled.
>>>>> I kinda expected slightly more IO during writes compared to 5.15, 
>>>>> but
>>>>> what I am actually seeing is massive amounts of btrfs-cleaner i/o 
>>>>> even
>>>>> when no programs are actively writing to the disk.
>>>>> 
>>>>> I can reproduce it quite reliably on my 2TB Btrfs Steam library
>>>>> partition. In my case, I was downloading Strange Brigade, which 
>>>>> is a
>>>>> roughly 25GB download and 33.65GB on disk. Somewhere during the
>>>>> download, iostat will start reporting disk writes around 300 
>>>>> MB/s, even
>>>>> though Steam itself reports disk usage of 40-45MB/s. After the 
>>>>> download
>>>>> finishes and nothing else is being written to disk, I still see 
>>>>> around
>>>>> 90-150MB/s worth of disk writes. Checking in iotop, I can see 
>>>>> btrfs
>>>>> cleaner and other btrfs processes writing a lot of data.
>>>>> 
>>>>> I left it running for a while to see if it was just some 
>>>>> maintenance
>>>>> tasks that Btrfs needed to do, but it just kept going. I tried to
>>>>> reboot, but it actually prevented me from properly rebooting. 
>>>>> After
>>>>> systemd timed out, my system finally shutdown.
>>>>> 
>>>>> Here are my mount options:
>>>>> rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/
>>>>> 
>>>>> 
>>>> 
>>>> Compression, I guess that's the reason.
>>>> 
>>>>  From the very beginning, btrfs defrag doesn't handle compressed 
>>>> extent
>>>> well.
>>>> 
>>>> Even if a compressed extent is already at its maximum capacity, 
>>>> btrfs
>>>> will still try to defrag it.
>>>> 
>>>> I believe the behavior is masked by other problems in older 
>>>> kernels thus
>>>> not that obvious.
>>>> 
>>>> But after rework of defrag in v5.16, this behavior is more exposed.
>>> 
>>> And if possible, please try this diff on v5.15.x, and see if v5.15 
>>> is
>>> really doing less IO than v5.16.x.
>>> 
>>> The diff will solve a problem in the old code, where autodefrag is
>>> almost not working.
>>> 
>>> diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
>>> index cc61813213d8..f6f2468d4883 100644
>>> --- a/fs/btrfs/ioctl.c
>>> +++ b/fs/btrfs/ioctl.c
>>> @@ -1524,13 +1524,8 @@ int btrfs_defrag_file(struct inode *inode, 
>>> struct
>>> file *file,
>>>                         continue;
>>>                 }
>>> 
>>> -               if (!newer_than) {
>>> -                       cluster = (PAGE_ALIGN(defrag_end) >>
>>> -                                  PAGE_SHIFT) - i;
>>> -                       cluster = min(cluster, max_cluster);
>>> -               } else {
>>> -                       cluster = max_cluster;
>>> -               }
>>> +               cluster = (PAGE_ALIGN(defrag_end) >> PAGE_SHIFT) - 
>>> i;
>>> +               cluster = min(cluster, max_cluster);
>>> 
>>>                 if (i + cluster > ra_index) {
>>>                         ra_index = max(i, ra_index);
>>> 
>>>> 
>>>> There are patches to address the compression related problem, but 
>>>> not
>>>> yet merged:
>>>> 
>>>> https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387
>>>> 
>>>> Mind to test them to see if that's the case?
>>>> 
>>>> Thanks,
>>>> Qu
>>>>> 
>>>>> 
>>>>> I've disabled autodefrag again for now to save my SSD, but just 
>>>>> wanted
>>>>> to say that there is still an issue. Have the defrag issues been 
>>>>> fully
>>>>> fixed or are there more patches incoming despite what Reddit and
>>>>> Phoronix say? XD
>>>>> 
>>>>> Thanks!
>>>>> Ben
>>>>> 
>>>>> 
>> 
>> 



^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-04 17:36         ` Benjamin Xiao
@ 2022-02-04 19:34           ` Benjamin Xiao
  2022-02-04 23:51             ` Qu Wenruo
  0 siblings, 1 reply; 16+ messages in thread
From: Benjamin Xiao @ 2022-02-04 19:34 UTC (permalink / raw)
  To: Qu Wenruo; +Cc: linux-btrfs

There's definitely still an issue even with the patches. I ended up 
disabling autodefrag again and rebooting my computer after 
btrfs-cleaner wrote about 300-ish GB to my SSD.

The patch does help things out a bit compared to before where it was a 
constant non-stop stream of IO, but 300GB worth of extra writes for 
33GB of actual data doesn't seem normal.

Ben

On Fri, Feb 4 2022 at 09:36:22 AM -0800, Benjamin Xiao 
<ben.r.xiao@gmail.com> wrote:
> Okay, I just tested right now with my custom 5.16.5 kernel with your 
> 3 patches applied. Redownloading the same game, I noticed that there 
> was significantly less IO load during the download, which is great. 
> It looked kinda bursty instead, with periods of no load, and then 
> periods of load ranging in the 150-200MB/s range.
> 
> After the download, I am no longer getting that constant 90-150MB/s 
> disk write from btrfs-cleaner, but I am seeing periodic bursts of it 
> every 10 seconds or so. These bursts last for around 3 seconds and 
> load is anywhere from 50-300MB/s.
> 
> Is this normal? Does autodefrag only defrag newly written data, or 
> does it sometimes go back and run defrag on data written previously? 
> I am gonna let it run for a bit to see if it eventually subsides.
> 
> Ben
> 
> On Fri, Feb 4 2022 at 02:20:44 PM +0800, Qu Wenruo 
> <quwenruo.btrfs@gmx.com> wrote:
>> 
>> 
>> On 2022/2/4 12:32, Benjamin Xiao wrote:
>>> Okay, I just compiled a custom Arch kernel with your patches 
>>> applied.
>>> Will test soon. Besides enabling autodefrag and redownloading a game
>>> from Steam, what other sorts of tests should I do?
>> 
>> As long as your workload can trigger the problem reliably, nothing 
>> \x7felse.
>> 
>> Thanks,
>> Qu
>> 
>>> 
>>> Ben
>>> 
>>> On Fri, Feb 4 2022 at 09:54:19 AM +0800, Qu Wenruo
>>> <quwenruo.btrfs@gmx.com> wrote:
>>>> 
>>>> 
>>>> On 2022/2/4 09:17, Qu Wenruo wrote:
>>>>> 
>>>>> 
>>>>> On 2022/2/4 04:05, Benjamin Xiao wrote:
>>>>>> Hello all,
>>>>>> 
>>>>>> Even after the defrag patches that landed in 5.16.5, I am still 
>>>>>> \x7f\x7f\x7f\x7f\x7fseeing
>>>>>> lots of cpu usage and disk writes to my SSD when autodefrag is 
>>>>>> \x7f\x7f\x7f\x7f\x7fenabled.
>>>>>> I kinda expected slightly more IO during writes compared to 
>>>>>> 5.15, \x7f\x7f\x7f\x7f\x7fbut
>>>>>> what I am actually seeing is massive amounts of btrfs-cleaner 
>>>>>> i/o \x7f\x7f\x7f\x7f\x7feven
>>>>>> when no programs are actively writing to the disk.
>>>>>> 
>>>>>> I can reproduce it quite reliably on my 2TB Btrfs Steam library
>>>>>> partition. In my case, I was downloading Strange Brigade, which 
>>>>>> \x7f\x7f\x7f\x7f\x7fis a
>>>>>> roughly 25GB download and 33.65GB on disk. Somewhere during the
>>>>>> download, iostat will start reporting disk writes around 300 
>>>>>> \x7f\x7f\x7f\x7f\x7fMB/s, even
>>>>>> though Steam itself reports disk usage of 40-45MB/s. After the 
>>>>>> \x7f\x7f\x7f\x7f\x7fdownload
>>>>>> finishes and nothing else is being written to disk, I still see 
>>>>>> \x7f\x7f\x7f\x7f\x7faround
>>>>>> 90-150MB/s worth of disk writes. Checking in iotop, I can see 
>>>>>> \x7f\x7f\x7f\x7f\x7fbtrfs
>>>>>> cleaner and other btrfs processes writing a lot of data.
>>>>>> 
>>>>>> I left it running for a while to see if it was just some 
>>>>>> \x7f\x7f\x7f\x7f\x7fmaintenance
>>>>>> tasks that Btrfs needed to do, but it just kept going. I tried to
>>>>>> reboot, but it actually prevented me from properly rebooting. 
>>>>>> \x7f\x7f\x7f\x7f\x7fAfter
>>>>>> systemd timed out, my system finally shutdown.
>>>>>> 
>>>>>> Here are my mount options:
>>>>>> rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/
>>>>>> 
>>>>>> 
>>>>> 
>>>>> Compression, I guess that's the reason.
>>>>> 
>>>>>  From the very beginning, btrfs defrag doesn't handle compressed 
>>>>> \x7f\x7f\x7f\x7fextent
>>>>> well.
>>>>> 
>>>>> Even if a compressed extent is already at its maximum capacity, 
>>>>> \x7f\x7f\x7f\x7fbtrfs
>>>>> will still try to defrag it.
>>>>> 
>>>>> I believe the behavior is masked by other problems in older 
>>>>> \x7f\x7f\x7f\x7fkernels thus
>>>>> not that obvious.
>>>>> 
>>>>> But after rework of defrag in v5.16, this behavior is more 
>>>>> exposed.
>>>> 
>>>> And if possible, please try this diff on v5.15.x, and see if v5.15 
>>>> \x7f\x7f\x7fis
>>>> really doing less IO than v5.16.x.
>>>> 
>>>> The diff will solve a problem in the old code, where autodefrag is
>>>> almost not working.
>>>> 
>>>> diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
>>>> index cc61813213d8..f6f2468d4883 100644
>>>> --- a/fs/btrfs/ioctl.c
>>>> +++ b/fs/btrfs/ioctl.c
>>>> @@ -1524,13 +1524,8 @@ int btrfs_defrag_file(struct inode *inode, 
>>>> \x7f\x7f\x7fstruct
>>>> file *file,
>>>>                         continue;
>>>>                 }
>>>> 
>>>> -               if (!newer_than) {
>>>> -                       cluster = (PAGE_ALIGN(defrag_end) >>
>>>> -                                  PAGE_SHIFT) - i;
>>>> -                       cluster = min(cluster, max_cluster);
>>>> -               } else {
>>>> -                       cluster = max_cluster;
>>>> -               }
>>>> +               cluster = (PAGE_ALIGN(defrag_end) >> PAGE_SHIFT) - 
>>>> \x7f\x7f\x7fi;
>>>> +               cluster = min(cluster, max_cluster);
>>>> 
>>>>                 if (i + cluster > ra_index) {
>>>>                         ra_index = max(i, ra_index);
>>>> 
>>>>> 
>>>>> There are patches to address the compression related problem, but 
>>>>> \x7f\x7f\x7f\x7fnot
>>>>> yet merged:
>>>>> 
>>>>> https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387
>>>>> 
>>>>> Mind to test them to see if that's the case?
>>>>> 
>>>>> Thanks,
>>>>> Qu
>>>>>> 
>>>>>> 
>>>>>> I've disabled autodefrag again for now to save my SSD, but just 
>>>>>> \x7f\x7f\x7f\x7f\x7fwanted
>>>>>> to say that there is still an issue. Have the defrag issues been 
>>>>>> \x7f\x7f\x7f\x7f\x7ffully
>>>>>> fixed or are there more patches incoming despite what Reddit and
>>>>>> Phoronix say? XD
>>>>>> 
>>>>>> Thanks!
>>>>>> Ben
>>>>>> 
>>>>>> 
>>> 
>>> 
> 
> 



^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-04 19:34           ` Benjamin Xiao
@ 2022-02-04 23:51             ` Qu Wenruo
  0 siblings, 0 replies; 16+ messages in thread
From: Qu Wenruo @ 2022-02-04 23:51 UTC (permalink / raw)
  To: Benjamin Xiao; +Cc: linux-btrfs



On 2022/2/5 03:34, Benjamin Xiao wrote:
> There's definitely still an issue even with the patches. I ended up
> disabling autodefrag again and rebooting my computer after btrfs-cleaner
> wrote about 300-ish GB to my SSD.
>
> The patch does help things out a bit compared to before where it was a
> constant non-stop stream of IO, but 300GB worth of extra writes for 33GB
> of actual data doesn't seem normal.

Have you tried v5.15.x with that diff?

Thanks,
Qu

>
> Ben
>
> On Fri, Feb 4 2022 at 09:36:22 AM -0800, Benjamin Xiao
> <ben.r.xiao@gmail.com> wrote:
>> Okay, I just tested right now with my custom 5.16.5 kernel with your 3
>> patches applied. Redownloading the same game, I noticed that there was
>> significantly less IO load during the download, which is great. It
>> looked kinda bursty instead, with periods of no load, and then periods
>> of load ranging in the 150-200MB/s range.
>>
>> After the download, I am no longer getting that constant 90-150MB/s
>> disk write from btrfs-cleaner, but I am seeing periodic bursts of it
>> every 10 seconds or so. These bursts last for around 3 seconds and
>> load is anywhere from 50-300MB/s.
>>
>> Is this normal? Does autodefrag only defrag newly written data, or
>> does it sometimes go back and run defrag on data written previously? I
>> am gonna let it run for a bit to see if it eventually subsides.
>>
>> Ben
>>
>> On Fri, Feb 4 2022 at 02:20:44 PM +0800, Qu Wenruo
>> <quwenruo.btrfs@gmx.com> wrote:
>>>
>>>
>>> On 2022/2/4 12:32, Benjamin Xiao wrote:
>>>> Okay, I just compiled a custom Arch kernel with your patches applied.
>>>> Will test soon. Besides enabling autodefrag and redownloading a game
>>>> from Steam, what other sorts of tests should I do?
>>>
>>> As long as your workload can trigger the problem reliably, nothing
>>> \x7felse.
>>>
>>> Thanks,
>>> Qu
>>>
>>>>
>>>> Ben
>>>>
>>>> On Fri, Feb 4 2022 at 09:54:19 AM +0800, Qu Wenruo
>>>> <quwenruo.btrfs@gmx.com> wrote:
>>>>>
>>>>>
>>>>> On 2022/2/4 09:17, Qu Wenruo wrote:
>>>>>>
>>>>>>
>>>>>> On 2022/2/4 04:05, Benjamin Xiao wrote:
>>>>>>> Hello all,
>>>>>>>
>>>>>>> Even after the defrag patches that landed in 5.16.5, I
>>>>>>> am still \x7f\x7f\x7f\x7f\x7fseeing
>>>>>>> lots of cpu usage and disk writes to my SSD when
>>>>>>> autodefrag is \x7f\x7f\x7f\x7f\x7fenabled.
>>>>>>> I kinda expected slightly more IO during writes
>>>>>>> compared to 5.15, \x7f\x7f\x7f\x7f\x7fbut
>>>>>>> what I am actually seeing is massive amounts of
>>>>>>> btrfs-cleaner i/o \x7f\x7f\x7f\x7f\x7feven
>>>>>>> when no programs are actively writing to the disk.
>>>>>>>
>>>>>>> I can reproduce it quite reliably on my 2TB Btrfs Steam library
>>>>>>> partition. In my case, I was downloading Strange
>>>>>>> Brigade, which \x7f\x7f\x7f\x7f\x7fis a
>>>>>>> roughly 25GB download and 33.65GB on disk. Somewhere during the
>>>>>>> download, iostat will start reporting disk writes
>>>>>>> around 300 \x7f\x7f\x7f\x7f\x7fMB/s, even
>>>>>>> though Steam itself reports disk usage of 40-45MB/s.
>>>>>>> After the \x7f\x7f\x7f\x7f\x7fdownload
>>>>>>> finishes and nothing else is being written to disk, I
>>>>>>> still see \x7f\x7f\x7f\x7f\x7faround
>>>>>>> 90-150MB/s worth of disk writes. Checking in iotop, I
>>>>>>> can see \x7f\x7f\x7f\x7f\x7fbtrfs
>>>>>>> cleaner and other btrfs processes writing a lot of data.
>>>>>>>
>>>>>>> I left it running for a while to see if it was just some
>>>>>>> \x7f\x7f\x7f\x7f\x7fmaintenance
>>>>>>> tasks that Btrfs needed to do, but it just kept going. I tried to
>>>>>>> reboot, but it actually prevented me from properly
>>>>>>> rebooting. \x7f\x7f\x7f\x7f\x7fAfter
>>>>>>> systemd timed out, my system finally shutdown.
>>>>>>>
>>>>>>> Here are my mount options:
>>>>>>> rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>
>>>>>> Compression, I guess that's the reason.
>>>>>>
>>>>>>  From the very beginning, btrfs defrag doesn't handle
>>>>>> compressed \x7f\x7f\x7f\x7fextent
>>>>>> well.
>>>>>>
>>>>>> Even if a compressed extent is already at its maximum
>>>>>> capacity, \x7f\x7f\x7f\x7fbtrfs
>>>>>> will still try to defrag it.
>>>>>>
>>>>>> I believe the behavior is masked by other problems in older
>>>>>> \x7f\x7f\x7f\x7fkernels thus
>>>>>> not that obvious.
>>>>>>
>>>>>> But after rework of defrag in v5.16, this behavior is more exposed.
>>>>>
>>>>> And if possible, please try this diff on v5.15.x, and see if
>>>>> v5.15 \x7f\x7f\x7fis
>>>>> really doing less IO than v5.16.x.
>>>>>
>>>>> The diff will solve a problem in the old code, where autodefrag is
>>>>> almost not working.
>>>>>
>>>>> diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
>>>>> index cc61813213d8..f6f2468d4883 100644
>>>>> --- a/fs/btrfs/ioctl.c
>>>>> +++ b/fs/btrfs/ioctl.c
>>>>> @@ -1524,13 +1524,8 @@ int btrfs_defrag_file(struct inode
>>>>> *inode, \x7f\x7f\x7fstruct
>>>>> file *file,
>>>>>                         continue;
>>>>>                 }
>>>>>
>>>>> -               if (!newer_than) {
>>>>> -                       cluster = (PAGE_ALIGN(defrag_end) >>
>>>>> -                                  PAGE_SHIFT) - i;
>>>>> -                       cluster = min(cluster, max_cluster);
>>>>> -               } else {
>>>>> -                       cluster = max_cluster;
>>>>> -               }
>>>>> +               cluster = (PAGE_ALIGN(defrag_end) >>
>>>>> PAGE_SHIFT) - \x7f\x7f\x7fi;
>>>>> +               cluster = min(cluster, max_cluster);
>>>>>
>>>>>                 if (i + cluster > ra_index) {
>>>>>                         ra_index = max(i, ra_index);
>>>>>
>>>>>>
>>>>>> There are patches to address the compression related
>>>>>> problem, but \x7f\x7f\x7f\x7fnot
>>>>>> yet merged:
>>>>>>
>>>>>> https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387
>>>>>>
>>>>>> Mind to test them to see if that's the case?
>>>>>>
>>>>>> Thanks,
>>>>>> Qu
>>>>>>>
>>>>>>>
>>>>>>> I've disabled autodefrag again for now to save my SSD,
>>>>>>> but just \x7f\x7f\x7f\x7f\x7fwanted
>>>>>>> to say that there is still an issue. Have the defrag
>>>>>>> issues been \x7f\x7f\x7f\x7f\x7ffully
>>>>>>> fixed or are there more patches incoming despite what Reddit and
>>>>>>> Phoronix say? XD
>>>>>>>
>>>>>>> Thanks!
>>>>>>> Ben
>>>>>>>
>>>>>>>
>>>>
>>>>
>>
>>
>
>

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
       [not found]     ` <SL2P216MB11112B447FB0400149D320C1AC2B9@SL2P216MB1111.KORP216.PROD.OUTLOOK.COM>
@ 2022-02-06  9:26       ` Qu Wenruo
  2022-02-06 17:43         ` Jean-Denis Girard
  2022-02-07  3:05         ` Qu Wenruo
  0 siblings, 2 replies; 16+ messages in thread
From: Qu Wenruo @ 2022-02-06  9:26 UTC (permalink / raw)
  To: Rylee Randall, Benjamin Xiao, linux-btrfs



On 2022/2/6 15:51, Rylee Randall wrote:
> I am experiencing the same issue on 5.16.7, near the end of a large
> steam game download btrfs-cleaner sits at the top of iotop, and shut
> downs take about ten minutes because of various btrfs hangs.
>
> I compiled 5.15.21 with the mentioned patch and tried to recreate the
> issue and so far have been unable to. I seem to get far faster an dmore
> consistent write speeds from steam, and rather than btrfs-cleaner being
> the main source of io usage it is steam. btrfs-cleaner is far down the
> list along with various other btrfs- tasks.

Thanks for the report, this indeed looks like the bug in v5.15 that it
doesn't defrag a lot of extents is not the root cause.

Mind to re-check with the following branch?

https://github.com/adam900710/linux/tree/autodefrag_fixes

It has one extra patch to emulate the older behavior of not using
btrfs_get_em(), which can cause quite some problem for autodefrag.

Thanks,
Qu

>
> On 4/2/22 12:54, Qu Wenruo wrote:
>>
>>
>> On 2022/2/4 09:17, Qu Wenruo wrote:
>>>
>>>
>>> On 2022/2/4 04:05, Benjamin Xiao wrote:
>>>> Hello all,
>>>>
>>>> Even after the defrag patches that landed in 5.16.5, I am still seeing
>>>> lots of cpu usage and disk writes to my SSD when autodefrag is enabled.
>>>> I kinda expected slightly more IO during writes compared to 5.15, but
>>>> what I am actually seeing is massive amounts of btrfs-cleaner i/o even
>>>> when no programs are actively writing to the disk.
>>>>
>>>> I can reproduce it quite reliably on my 2TB Btrfs Steam library
>>>> partition. In my case, I was downloading Strange Brigade, which is a
>>>> roughly 25GB download and 33.65GB on disk. Somewhere during the
>>>> download, iostat will start reporting disk writes around 300 MB/s, even
>>>> though Steam itself reports disk usage of 40-45MB/s. After the download
>>>> finishes and nothing else is being written to disk, I still see around
>>>> 90-150MB/s worth of disk writes. Checking in iotop, I can see btrfs
>>>> cleaner and other btrfs processes writing a lot of data.
>>>>
>>>> I left it running for a while to see if it was just some maintenance
>>>> tasks that Btrfs needed to do, but it just kept going. I tried to
>>>> reboot, but it actually prevented me from properly rebooting. After
>>>> systemd timed out, my system finally shutdown.
>>>>
>>>> Here are my mount options:
>>>> rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/
>>>>
>>>>
>>>
>>> Compression, I guess that's the reason.
>>>
>>>  From the very beginning, btrfs defrag doesn't handle compressed extent
>>> well.
>>>
>>> Even if a compressed extent is already at its maximum capacity, btrfs
>>> will still try to defrag it.
>>>
>>> I believe the behavior is masked by other problems in older kernels thus
>>> not that obvious.
>>>
>>> But after rework of defrag in v5.16, this behavior is more exposed.
>>
>> And if possible, please try this diff on v5.15.x, and see if v5.15 is
>> really doing less IO than v5.16.x.
>>
>> The diff will solve a problem in the old code, where autodefrag is
>> almost not working.
>>
>> diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
>> index cc61813213d8..f6f2468d4883 100644
>> --- a/fs/btrfs/ioctl.c
>> +++ b/fs/btrfs/ioctl.c
>> @@ -1524,13 +1524,8 @@ int btrfs_defrag_file(struct inode *inode, struct
>> file *file,
>>                         continue;
>>                 }
>>
>> -               if (!newer_than) {
>> -                       cluster = (PAGE_ALIGN(defrag_end) >>
>> -                                  PAGE_SHIFT) - i;
>> -                       cluster = min(cluster, max_cluster);
>> -               } else {
>> -                       cluster = max_cluster;
>> -               }
>> +               cluster = (PAGE_ALIGN(defrag_end) >> PAGE_SHIFT) - i;
>> +               cluster = min(cluster, max_cluster);
>>
>>                 if (i + cluster > ra_index) {
>>                         ra_index = max(i, ra_index);
>>
>>>
>>> There are patches to address the compression related problem, but not
>>> yet merged:
>>>
>>> https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387
>>>
>>> Mind to test them to see if that's the case?
>>>
>>> Thanks,
>>> Qu
>>>>
>>>>
>>>> I've disabled autodefrag again for now to save my SSD, but just wanted
>>>> to say that there is still an issue. Have the defrag issues been fully
>>>> fixed or are there more patches incoming despite what Reddit and
>>>> Phoronix say? XD
>>>>
>>>> Thanks!
>>>> Ben
>>>>
>>>>

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-06  9:26       ` Qu Wenruo
@ 2022-02-06 17:43         ` Jean-Denis Girard
  2022-02-07  1:16           ` Qu Wenruo
  2022-02-07  3:05         ` Qu Wenruo
  1 sibling, 1 reply; 16+ messages in thread
From: Jean-Denis Girard @ 2022-02-06 17:43 UTC (permalink / raw)
  To: linux-btrfs

Hi list,

I'm also experiencing high IO with autodefrag on 5.16.6 patched with:
  - https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387,
  - https://patchwork.kernel.org/project/linux-btrfs/list/?series=611509,
  - btrfs-defrag-bring-back-the-old-file-extent-search-behavior.diff.

After about 24 hours uptime, btrfs-cleaner is most of the time at 90 % 
CPU usage

%CPU  %MEM     TIME+ COMMAND
77,6   0,0  29:03.25 btrfs-cleaner
19,1   0,0   3:40.22 kworker/u24:8-btrfs-endio-write
19,1   0,0   1:50.46 kworker/u24:27-btrfs-endio-write
18,4   0,0   4:14.82 kworker/u24:7-btrfs-endio-write
17,4   0,0   4:08.08 kworker/u24:10-events_unbound
17,4   0,0   4:23.41 kworker/u24:9-btrfs-delalloc
15,8   0,0   3:41.21 kworker/u24:3-btrfs-endio-write
15,1   0,0   2:12.61 kworker/u24:26-blkcg_punt_bio
14,8   0,0   3:40.13 kworker/u24:18-btrfs-delalloc
12,8   0,0   3:55.70 kworker/u24:20-btrfs-delalloc
12,5   0,0   4:01.79 kworker/u24:1-btrfs-delalloc
12,2   0,0   4:04.63 kworker/u24:22-btrfs-endio-write
11,5   0,0   1:11.90 kworker/u24:11-btrfs-endio-write
11,2   0,0   1:25.96 kworker/u24:0-blkcg_punt_bio
10,2   0,0   4:24.17 kworker/u24:24+events_unbound
...

Load average is 5,56, 6,88, 6,71 while just writing that mail.

And iostat shows:

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
            1,5%    0,0%   26,8%    6,3%    0,0%   65,4%

       tps    kB_read/s    kB_wrtn/s    kB_dscd/s    kB_read    kB_wrtn 
   kB_dscd Device
  33893,50         0,0k       172,2M        57,8M       0,0k       1,7G 
    577,7M nvme0n1
    169,40         0,0k         1,2M         0,0k       0,0k      12,5M 
      0,0k sda
    178,90         0,0k         1,3M         0,0k       0,0k      12,5M 
      0,0k sdb

I hope that helps.


Thanks,
-- 
Jean-Denis Girard

SysNux                   Systèmes   Linux   en   Polynésie  française
https://www.sysnux.pf/   Tél: +689 40.50.10.40 / GSM: +689 87.797.527


Le 05/02/2022 à 23:26, Qu Wenruo a écrit :
> 
> 
> On 2022/2/6 15:51, Rylee Randall wrote:
>> I am experiencing the same issue on 5.16.7, near the end of a large
>> steam game download btrfs-cleaner sits at the top of iotop, and shut
>> downs take about ten minutes because of various btrfs hangs.
>>
>> I compiled 5.15.21 with the mentioned patch and tried to recreate the
>> issue and so far have been unable to. I seem to get far faster an dmore
>> consistent write speeds from steam, and rather than btrfs-cleaner being
>> the main source of io usage it is steam. btrfs-cleaner is far down the
>> list along with various other btrfs- tasks.
> 
> Thanks for the report, this indeed looks like the bug in v5.15 that it
> doesn't defrag a lot of extents is not the root cause.
> 
> Mind to re-check with the following branch?
> 
> https://github.com/adam900710/linux/tree/autodefrag_fixes
> 
> It has one extra patch to emulate the older behavior of not using
> btrfs_get_em(), which can cause quite some problem for autodefrag.
> 
> Thanks,
> Qu
> 
>>
>> On 4/2/22 12:54, Qu Wenruo wrote:
>>>
>>>
>>> On 2022/2/4 09:17, Qu Wenruo wrote:
>>>>
>>>>
>>>> On 2022/2/4 04:05, Benjamin Xiao wrote:
>>>>> Hello all,
>>>>>
>>>>> Even after the defrag patches that landed in 5.16.5, I am still seeing
>>>>> lots of cpu usage and disk writes to my SSD when autodefrag is 
>>>>> enabled.
>>>>> I kinda expected slightly more IO during writes compared to 5.15, but
>>>>> what I am actually seeing is massive amounts of btrfs-cleaner i/o even
>>>>> when no programs are actively writing to the disk.
>>>>>
>>>>> I can reproduce it quite reliably on my 2TB Btrfs Steam library
>>>>> partition. In my case, I was downloading Strange Brigade, which is a
>>>>> roughly 25GB download and 33.65GB on disk. Somewhere during the
>>>>> download, iostat will start reporting disk writes around 300 MB/s, 
>>>>> even
>>>>> though Steam itself reports disk usage of 40-45MB/s. After the 
>>>>> download
>>>>> finishes and nothing else is being written to disk, I still see around
>>>>> 90-150MB/s worth of disk writes. Checking in iotop, I can see btrfs
>>>>> cleaner and other btrfs processes writing a lot of data.
>>>>>
>>>>> I left it running for a while to see if it was just some maintenance
>>>>> tasks that Btrfs needed to do, but it just kept going. I tried to
>>>>> reboot, but it actually prevented me from properly rebooting. After
>>>>> systemd timed out, my system finally shutdown.
>>>>>
>>>>> Here are my mount options:
>>>>> rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/ 
>>>>>
>>>>>
>>>>>
>>>>
>>>> Compression, I guess that's the reason.
>>>>
>>>>  From the very beginning, btrfs defrag doesn't handle compressed extent
>>>> well.
>>>>
>>>> Even if a compressed extent is already at its maximum capacity, btrfs
>>>> will still try to defrag it.
>>>>
>>>> I believe the behavior is masked by other problems in older kernels 
>>>> thus
>>>> not that obvious.
>>>>
>>>> But after rework of defrag in v5.16, this behavior is more exposed.
>>>
>>> And if possible, please try this diff on v5.15.x, and see if v5.15 is
>>> really doing less IO than v5.16.x.
>>>
>>> The diff will solve a problem in the old code, where autodefrag is
>>> almost not working.
>>>
>>> diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
>>> index cc61813213d8..f6f2468d4883 100644
>>> --- a/fs/btrfs/ioctl.c
>>> +++ b/fs/btrfs/ioctl.c
>>> @@ -1524,13 +1524,8 @@ int btrfs_defrag_file(struct inode *inode, struct
>>> file *file,
>>>                         continue;
>>>                 }
>>>
>>> -               if (!newer_than) {
>>> -                       cluster = (PAGE_ALIGN(defrag_end) >>
>>> -                                  PAGE_SHIFT) - i;
>>> -                       cluster = min(cluster, max_cluster);
>>> -               } else {
>>> -                       cluster = max_cluster;
>>> -               }
>>> +               cluster = (PAGE_ALIGN(defrag_end) >> PAGE_SHIFT) - i;
>>> +               cluster = min(cluster, max_cluster);
>>>
>>>                 if (i + cluster > ra_index) {
>>>                         ra_index = max(i, ra_index);
>>>
>>>>
>>>> There are patches to address the compression related problem, but not
>>>> yet merged:
>>>>
>>>> https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387
>>>>
>>>> Mind to test them to see if that's the case?
>>>>
>>>> Thanks,
>>>> Qu
>>>>>
>>>>>
>>>>> I've disabled autodefrag again for now to save my SSD, but just wanted
>>>>> to say that there is still an issue. Have the defrag issues been fully
>>>>> fixed or are there more patches incoming despite what Reddit and
>>>>> Phoronix say? XD
>>>>>
>>>>> Thanks!
>>>>> Ben
>>>>>
>>>>>
> 



^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-06 17:43         ` Jean-Denis Girard
@ 2022-02-07  1:16           ` Qu Wenruo
  2022-02-07  1:45             ` Jean-Denis Girard
  2022-02-09  1:56             ` Jean-Denis Girard
  0 siblings, 2 replies; 16+ messages in thread
From: Qu Wenruo @ 2022-02-07  1:16 UTC (permalink / raw)
  To: Jean-Denis Girard, linux-btrfs

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



On 2022/2/7 01:43, Jean-Denis Girard wrote:
> Hi list,
>
> I'm also experiencing high IO with autodefrag on 5.16.6 patched
> with: -
> https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387,
>
>
- https://patchwork.kernel.org/project/linux-btrfs/list/?series=611509,
> - btrfs-defrag-bring-back-the-old-file-extent-search-behavior.diff.

OK, btrfs_search_forward() doesn't help in this case I guess.

>
> After about 24 hours uptime, btrfs-cleaner is most of the time at 90
> % CPU usage
>
> %CPU  %MEM     TIME+ COMMAND 77,6   0,0  29:03.25 btrfs-cleaner 19,1
> 0,0   3:40.22 kworker/u24:8-btrfs-endio-write 19,1   0,0   1:50.46
> kworker/u24:27-btrfs-endio-write 18,4   0,0   4:14.82
> kworker/u24:7-btrfs-endio-write 17,4   0,0   4:08.08
> kworker/u24:10-events_unbound 17,4   0,0   4:23.41
> kworker/u24:9-btrfs-delalloc 15,8   0,0   3:41.21
> kworker/u24:3-btrfs-endio-write 15,1   0,0   2:12.61
> kworker/u24:26-blkcg_punt_bio 14,8   0,0   3:40.13
> kworker/u24:18-btrfs-delalloc 12,8   0,0   3:55.70
> kworker/u24:20-btrfs-delalloc 12,5   0,0   4:01.79
> kworker/u24:1-btrfs-delalloc 12,2   0,0   4:04.63
> kworker/u24:22-btrfs-endio-write 11,5   0,0   1:11.90
> kworker/u24:11-btrfs-endio-write 11,2   0,0   1:25.96
> kworker/u24:0-blkcg_punt_bio 10,2   0,0   4:24.17
> kworker/u24:24+events_unbound ...
>
> Load average is 5,56, 6,88, 6,71 while just writing that mail.
>
> And iostat shows:
>
> avg-cpu:  %user   %nice %system %iowait  %steal   %idle 1,5%    0,0%
> 26,8%    6,3%    0,0%   65,4%
>
> tps    kB_read/s    kB_wrtn/s    kB_dscd/s    kB_read    kB_wrtn
> kB_dscd Device 33893,50         0,0k       172,2M        57,8M
> 0,0k       1,7G 577,7M nvme0n1 169,40         0,0k         1,2M
> 0,0k       0,0k      12,5M 0,0k sda 178,90         0,0k         1,3M
> 0,0k       0,0k      12,5M 0,0k sdb
>
> I hope that helps.

And what are the mount options?

 From the CPU usage, it looks like there are some infinite loop, but I
can't find out why by a quick glance.

And since there is no extra read, it looks like it's doing defrag again
and again on the same inode and range.


Mind to apply attached `debug.diff`?

Then you still need to provide `/sys/kernel/debug/tracing/trace`, which
can be very large and full of added debug info.
(This means this can slow down your system)

The example of my local test would result something like this in above
trace file:

# tracer: nop
#
# entries-in-buffer/entries-written: 11/11   #P:16
#
#                                _-----=> irqs-off/BH-disabled
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| / _-=> migrate-disable
#                              |||| /     delay
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |
    btrfs-cleaner-1770    [014] .....   961.534329: btrfs_defrag_file:
entry r/i=5/257 start=0 len=131072 newer=7 thres=262144
    btrfs-cleaner-1770    [014] .....   961.534333:
defrag_collect_targets: add target r/i=5/257 start=0 len=16384 em=0
len=16384 gen=7 newer=7
    btrfs-cleaner-1770    [014] .....   961.534335:
defrag_collect_targets: add target r/i=5/257 start=16384 len=16384
em=16384 len=16384 gen=7 newer=7
    btrfs-cleaner-1770    [014] .....   961.534336:
defrag_collect_targets: add target r/i=5/257 start=32768 len=16384
em=32768 len=16384 gen=7 newer=7
    btrfs-cleaner-1770    [014] .....   961.534337:
defrag_collect_targets: add target r/i=5/257 start=49152 len=16384
em=49152 len=16384 gen=7 newer=7
    btrfs-cleaner-1770    [014] .....   961.534564:
defrag_collect_targets: add target r/i=5/257 start=0 len=16384 em=0
len=16384 gen=7 newer=7
    btrfs-cleaner-1770    [014] .....   961.534567:
defrag_collect_targets: add target r/i=5/257 start=16384 len=16384
em=16384 len=16384 gen=7 newer=7
    btrfs-cleaner-1770    [014] .....   961.534568:
defrag_collect_targets: add target r/i=5/257 start=32768 len=16384
em=32768 len=16384 gen=7 newer=7
    btrfs-cleaner-1770    [014] .....   961.534569:
defrag_collect_targets: add target r/i=5/257 start=49152 len=16384
em=49152 len=16384 gen=7 newer=7
    btrfs-cleaner-1770    [014] .....   961.534580: btrfs_defrag_file:
defrag target r/i=5/257 start=0 len=65536
    btrfs-cleaner-1770    [014] .....   961.534681:
btrfs_run_defrag_inodes: defrag finish r/i=5/257 ret=0 defragged=16
last_scanned=131072 last_off=0 cycled=0

Thanks,
Qu


>
>
> Thanks,

[-- Attachment #2: debug.diff --]
[-- Type: text/x-patch, Size: 2457 bytes --]

diff --git a/fs/btrfs/file.c b/fs/btrfs/file.c
index f5de8ab9787e..be2e20d163ef 100644
--- a/fs/btrfs/file.c
+++ b/fs/btrfs/file.c
@@ -304,6 +304,11 @@ static int __btrfs_run_defrag_inode(struct btrfs_fs_info *fs_info,
 	sb_start_write(fs_info->sb);
 	ret = btrfs_defrag_file(inode, NULL, &ctrl);
 	sb_end_write(fs_info->sb);
+	trace_printk("defrag finish r/i=%lld/%llu ret=%d defragged=%llu last_scanned=%llu last_off=%llu cycled=%d\n",
+		     BTRFS_I(inode)->root->root_key.objectid,
+		     btrfs_ino(BTRFS_I(inode)), ret, ctrl.sectors_defragged,
+		     ctrl.last_scanned,
+		     defrag->last_offset, defrag->cycled);
 	/*
 	 * if we filled the whole defrag batch, there
 	 * must be more work to do.  Queue this defrag
diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
index 133e3e2e2e79..a0501c88922b 100644
--- a/fs/btrfs/ioctl.c
+++ b/fs/btrfs/ioctl.c
@@ -1420,6 +1420,11 @@ static int defrag_collect_targets(struct btrfs_inode *inode,
 add:
 		last_is_target = true;
 		range_len = min(extent_map_end(em), start + len) - cur;
+
+		trace_printk("add target r/i=%lld/%llu start=%llu len=%llu em=%llu len=%llu gen=%lld newer=%llu\n",
+			inode->root->root_key.objectid,
+			btrfs_ino(inode), cur, range_len, em->start, em->len,
+			em->generation, ctrl->newer_than);
 		/*
 		 * This one is a good target, check if it can be merged into
 		 * last range of the target list.
@@ -1520,6 +1525,9 @@ static int defrag_one_locked_target(struct btrfs_inode *inode,
 			 EXTENT_DEFRAG, 0, 0, cached_state);
 	set_extent_defrag(&inode->io_tree, start, start + len - 1, cached_state);
 
+	trace_printk("defrag target r/i=%lld/%llu start=%llu len=%llu\n",
+			inode->root->root_key.objectid,
+			btrfs_ino(inode), start, len);
 	/* Update the page status */
 	for (i = start_index - first_index; i <= last_index - first_index; i++) {
 		ClearPageChecked(pages[i]);
@@ -1786,6 +1794,12 @@ int btrfs_defrag_file(struct inode *inode, struct file_ra_state *ra,
 	if (start_index < inode->i_mapping->writeback_index)
 		inode->i_mapping->writeback_index = start_index;
 
+	trace_printk("entry r/i=%lld/%llu start=%llu len=%llu newer=%llu thres=%u\n",
+		BTRFS_I(inode)->root->root_key.objectid,
+		btrfs_ino(BTRFS_I(inode)),
+		ctrl->last_scanned, last_byte + 1 - ctrl->last_scanned,
+		ctrl->newer_than, ctrl->extent_thresh);
+
 	while (ctrl->last_scanned < last_byte) {
 		const unsigned long prev_sectors_defragged = ctrl->sectors_defragged;
 		u64 cluster_end;

^ permalink raw reply related	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-07  1:16           ` Qu Wenruo
@ 2022-02-07  1:45             ` Jean-Denis Girard
  2022-02-09  1:56             ` Jean-Denis Girard
  1 sibling, 0 replies; 16+ messages in thread
From: Jean-Denis Girard @ 2022-02-07  1:45 UTC (permalink / raw)
  To: Qu Wenruo, linux-btrfs

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

Le 06/02/2022 à 15:16, Qu Wenruo a écrit :
> And what are the mount options?

Here are the mount options:

/dev/nvme0n1p2 on / type btrfs 
(rw,noatime,nodiratime,seclabel,compress-force=zstd:3,ssd,discard=async,space_cache,autodefrag,skip_balance,subvolid=5,subvol=/)
/dev/sdb on /home/Partage type btrfs 
(rw,noatime,nodiratime,seclabel,compress-force=zstd:3,space_cache=v2,autodefrag,skip_balance,subvolid=1061,subvol=/Partage)
/dev/sdb on /home/Photos type btrfs 
(rw,noatime,nodiratime,seclabel,compress-force=zstd:3,space_cache=v2,autodefrag,skip_balance,subvolid=1062,subvol=/Photos)
  ...

I have 13 subvolumes on /dev/sdb.

> Mind to apply attached `debug.diff`?

I can't try that immediately, but will do.


Thanks,
-- 
Jean-Denis Girard

SysNux                   Systèmes   Linux   en   Polynésie  française
https://www.sysnux.pf/   Tél: +689 40.50.10.40 / GSM: +689 87.797.527

[-- Attachment #2: Signature cryptographique S/MIME --]
[-- Type: application/pkcs7-signature, Size: 4003 bytes --]

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-06  9:26       ` Qu Wenruo
  2022-02-06 17:43         ` Jean-Denis Girard
@ 2022-02-07  3:05         ` Qu Wenruo
       [not found]           ` <SL2P216MB1111994F81CE0006D495511DAC2C9@SL2P216MB1111.KORP216.PROD.OUTLOOK.COM>
  1 sibling, 1 reply; 16+ messages in thread
From: Qu Wenruo @ 2022-02-07  3:05 UTC (permalink / raw)
  To: Rylee Randall, Benjamin Xiao, linux-btrfs

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



On 2022/2/6 17:26, Qu Wenruo wrote:
>
>
> On 2022/2/6 15:51, Rylee Randall wrote:
>> I am experiencing the same issue on 5.16.7, near the end of a large
>> steam game download btrfs-cleaner sits at the top of iotop, and shut
>> downs take about ten minutes because of various btrfs hangs.
>>
>> I compiled 5.15.21 with the mentioned patch and tried to recreate the
>> issue and so far have been unable to. I seem to get far faster an dmore
>> consistent write speeds from steam, and rather than btrfs-cleaner being
>> the main source of io usage it is steam. btrfs-cleaner is far down the
>> list along with various other btrfs- tasks.
>
> Thanks for the report, this indeed looks like the bug in v5.15 that it
> doesn't defrag a lot of extents is not the root cause.
>
> Mind to re-check with the following branch?
>
> https://github.com/adam900710/linux/tree/autodefrag_fixes
>
> It has one extra patch to emulate the older behavior of not using
> btrfs_get_em(), which can cause quite some problem for autodefrag.


And if anyone is still experiencing the problem even with that branch,
there is a diff to do the ultimate debug (thus can slow down the system).

After applying this diff upon that branch, every auto defrag try will
have several lines added to `/sys/kernel/debug/tracing/trace`.
(Which can be pretty large).

And that trace file would greatly help us to locate which extent is
defragged again and again.

Thanks,
Qu
>
> Thanks,
> Qu
>
>>
>> On 4/2/22 12:54, Qu Wenruo wrote:
>>>
>>>
>>> On 2022/2/4 09:17, Qu Wenruo wrote:
>>>>
>>>>
>>>> On 2022/2/4 04:05, Benjamin Xiao wrote:
>>>>> Hello all,
>>>>>
>>>>> Even after the defrag patches that landed in 5.16.5, I am still seeing
>>>>> lots of cpu usage and disk writes to my SSD when autodefrag is
>>>>> enabled.
>>>>> I kinda expected slightly more IO during writes compared to 5.15, but
>>>>> what I am actually seeing is massive amounts of btrfs-cleaner i/o even
>>>>> when no programs are actively writing to the disk.
>>>>>
>>>>> I can reproduce it quite reliably on my 2TB Btrfs Steam library
>>>>> partition. In my case, I was downloading Strange Brigade, which is a
>>>>> roughly 25GB download and 33.65GB on disk. Somewhere during the
>>>>> download, iostat will start reporting disk writes around 300 MB/s,
>>>>> even
>>>>> though Steam itself reports disk usage of 40-45MB/s. After the
>>>>> download
>>>>> finishes and nothing else is being written to disk, I still see around
>>>>> 90-150MB/s worth of disk writes. Checking in iotop, I can see btrfs
>>>>> cleaner and other btrfs processes writing a lot of data.
>>>>>
>>>>> I left it running for a while to see if it was just some maintenance
>>>>> tasks that Btrfs needed to do, but it just kept going. I tried to
>>>>> reboot, but it actually prevented me from properly rebooting. After
>>>>> systemd timed out, my system finally shutdown.
>>>>>
>>>>> Here are my mount options:
>>>>> rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/
>>>>>
>>>>>
>>>>>
>>>>
>>>> Compression, I guess that's the reason.
>>>>
>>>>  From the very beginning, btrfs defrag doesn't handle compressed extent
>>>> well.
>>>>
>>>> Even if a compressed extent is already at its maximum capacity, btrfs
>>>> will still try to defrag it.
>>>>
>>>> I believe the behavior is masked by other problems in older kernels
>>>> thus
>>>> not that obvious.
>>>>
>>>> But after rework of defrag in v5.16, this behavior is more exposed.
>>>
>>> And if possible, please try this diff on v5.15.x, and see if v5.15 is
>>> really doing less IO than v5.16.x.
>>>
>>> The diff will solve a problem in the old code, where autodefrag is
>>> almost not working.
>>>
>>> diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
>>> index cc61813213d8..f6f2468d4883 100644
>>> --- a/fs/btrfs/ioctl.c
>>> +++ b/fs/btrfs/ioctl.c
>>> @@ -1524,13 +1524,8 @@ int btrfs_defrag_file(struct inode *inode, struct
>>> file *file,
>>>                         continue;
>>>                 }
>>>
>>> -               if (!newer_than) {
>>> -                       cluster = (PAGE_ALIGN(defrag_end) >>
>>> -                                  PAGE_SHIFT) - i;
>>> -                       cluster = min(cluster, max_cluster);
>>> -               } else {
>>> -                       cluster = max_cluster;
>>> -               }
>>> +               cluster = (PAGE_ALIGN(defrag_end) >> PAGE_SHIFT) - i;
>>> +               cluster = min(cluster, max_cluster);
>>>
>>>                 if (i + cluster > ra_index) {
>>>                         ra_index = max(i, ra_index);
>>>
>>>>
>>>> There are patches to address the compression related problem, but not
>>>> yet merged:
>>>>
>>>> https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387
>>>>
>>>> Mind to test them to see if that's the case?
>>>>
>>>> Thanks,
>>>> Qu
>>>>>
>>>>>
>>>>> I've disabled autodefrag again for now to save my SSD, but just wanted
>>>>> to say that there is still an issue. Have the defrag issues been fully
>>>>> fixed or are there more patches incoming despite what Reddit and
>>>>> Phoronix say? XD
>>>>>
>>>>> Thanks!
>>>>> Ben
>>>>>
>>>>>

[-- Attachment #2: debug.diff --]
[-- Type: text/x-patch, Size: 2457 bytes --]

diff --git a/fs/btrfs/file.c b/fs/btrfs/file.c
index f5de8ab9787e..be2e20d163ef 100644
--- a/fs/btrfs/file.c
+++ b/fs/btrfs/file.c
@@ -304,6 +304,11 @@ static int __btrfs_run_defrag_inode(struct btrfs_fs_info *fs_info,
 	sb_start_write(fs_info->sb);
 	ret = btrfs_defrag_file(inode, NULL, &ctrl);
 	sb_end_write(fs_info->sb);
+	trace_printk("defrag finish r/i=%lld/%llu ret=%d defragged=%llu last_scanned=%llu last_off=%llu cycled=%d\n",
+		     BTRFS_I(inode)->root->root_key.objectid,
+		     btrfs_ino(BTRFS_I(inode)), ret, ctrl.sectors_defragged,
+		     ctrl.last_scanned,
+		     defrag->last_offset, defrag->cycled);
 	/*
 	 * if we filled the whole defrag batch, there
 	 * must be more work to do.  Queue this defrag
diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
index 133e3e2e2e79..a0501c88922b 100644
--- a/fs/btrfs/ioctl.c
+++ b/fs/btrfs/ioctl.c
@@ -1420,6 +1420,11 @@ static int defrag_collect_targets(struct btrfs_inode *inode,
 add:
 		last_is_target = true;
 		range_len = min(extent_map_end(em), start + len) - cur;
+
+		trace_printk("add target r/i=%lld/%llu start=%llu len=%llu em=%llu len=%llu gen=%lld newer=%llu\n",
+			inode->root->root_key.objectid,
+			btrfs_ino(inode), cur, range_len, em->start, em->len,
+			em->generation, ctrl->newer_than);
 		/*
 		 * This one is a good target, check if it can be merged into
 		 * last range of the target list.
@@ -1520,6 +1525,9 @@ static int defrag_one_locked_target(struct btrfs_inode *inode,
 			 EXTENT_DEFRAG, 0, 0, cached_state);
 	set_extent_defrag(&inode->io_tree, start, start + len - 1, cached_state);
 
+	trace_printk("defrag target r/i=%lld/%llu start=%llu len=%llu\n",
+			inode->root->root_key.objectid,
+			btrfs_ino(inode), start, len);
 	/* Update the page status */
 	for (i = start_index - first_index; i <= last_index - first_index; i++) {
 		ClearPageChecked(pages[i]);
@@ -1786,6 +1794,12 @@ int btrfs_defrag_file(struct inode *inode, struct file_ra_state *ra,
 	if (start_index < inode->i_mapping->writeback_index)
 		inode->i_mapping->writeback_index = start_index;
 
+	trace_printk("entry r/i=%lld/%llu start=%llu len=%llu newer=%llu thres=%u\n",
+		BTRFS_I(inode)->root->root_key.objectid,
+		btrfs_ino(BTRFS_I(inode)),
+		ctrl->last_scanned, last_byte + 1 - ctrl->last_scanned,
+		ctrl->newer_than, ctrl->extent_thresh);
+
 	while (ctrl->last_scanned < last_byte) {
 		const unsigned long prev_sectors_defragged = ctrl->sectors_defragged;
 		u64 cluster_end;

^ permalink raw reply related	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
       [not found]           ` <SL2P216MB1111994F81CE0006D495511DAC2C9@SL2P216MB1111.KORP216.PROD.OUTLOOK.COM>
@ 2022-02-07  5:23             ` Qu Wenruo
  0 siblings, 0 replies; 16+ messages in thread
From: Qu Wenruo @ 2022-02-07  5:23 UTC (permalink / raw)
  To: Rylee Randall, Benjamin Xiao, linux-btrfs



On 2022/2/7 12:29, Rylee Randall wrote:
> I built a kernel from that branch and tried everything I could think of
> to try to reproduce the issue, but no matter what I tried btrfs-cleaner
> would only show up on iotop briefly every now and then, io did not hang
> and disk performance was as expected.
>
>
> I think the branch resolves the issue, or at least prevents me from
> being able to reproduce.

Just in case, you can still use that diff, it will only populate ftrace
event log buffer, which is much faster than dmesg log buffer.

And since you haven't seen huge IO/CPU usage, the extra debug message
shouldn't cause any observable performance drop.

And in case you observed huge CPU usage from btrfs-cleaner under
whatever load, you can direct grab the trace file, and no need to
rebuild a kernel module (and may fail to reproduce in next try).

Thanks,
Qu

>
> On 7/2/22 14:05, Qu Wenruo wrote:
>>
>>
>> On 2022/2/6 17:26, Qu Wenruo wrote:
>>>
>>>
>>> On 2022/2/6 15:51, Rylee Randall wrote:
>>>> I am experiencing the same issue on 5.16.7, near the end of a large
>>>> steam game download btrfs-cleaner sits at the top of iotop, and shut
>>>> downs take about ten minutes because of various btrfs hangs.
>>>>
>>>> I compiled 5.15.21 with the mentioned patch and tried to recreate the
>>>> issue and so far have been unable to. I seem to get far faster an dmore
>>>> consistent write speeds from steam, and rather than btrfs-cleaner being
>>>> the main source of io usage it is steam. btrfs-cleaner is far down the
>>>> list along with various other btrfs- tasks.
>>>
>>> Thanks for the report, this indeed looks like the bug in v5.15 that it
>>> doesn't defrag a lot of extents is not the root cause.
>>>
>>> Mind to re-check with the following branch?
>>>
>>> https://apac01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fadam900710%2Flinux%2Ftree%2Fautodefrag_fixes&amp;data=04%7C01%7C%7C4ca72e2e2774416246b208d9e9e6c2d8%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637797999607143470%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&amp;sdata=LQyHFTmNG%2FKIQzPT6gt%2BZugspRGTHISPFtwi7zRdqhQ%3D&amp;reserved=0
>>>
>>>
>>> It has one extra patch to emulate the older behavior of not using
>>> btrfs_get_em(), which can cause quite some problem for autodefrag.
>>
>>
>> And if anyone is still experiencing the problem even with that branch,
>> there is a diff to do the ultimate debug (thus can slow down the system).
>>
>> After applying this diff upon that branch, every auto defrag try will
>> have several lines added to `/sys/kernel/debug/tracing/trace`.
>> (Which can be pretty large).
>>
>> And that trace file would greatly help us to locate which extent is
>> defragged again and again.
>>
>> Thanks,
>> Qu
>>>
>>> Thanks,
>>> Qu
>>>
>>>>
>>>> On 4/2/22 12:54, Qu Wenruo wrote:
>>>>>
>>>>>
>>>>> On 2022/2/4 09:17, Qu Wenruo wrote:
>>>>>>
>>>>>>
>>>>>> On 2022/2/4 04:05, Benjamin Xiao wrote:
>>>>>>> Hello all,
>>>>>>>
>>>>>>> Even after the defrag patches that landed in 5.16.5, I am still
>>>>>>> seeing
>>>>>>> lots of cpu usage and disk writes to my SSD when autodefrag is
>>>>>>> enabled.
>>>>>>> I kinda expected slightly more IO during writes compared to 5.15,
>>>>>>> but
>>>>>>> what I am actually seeing is massive amounts of btrfs-cleaner i/o
>>>>>>> even
>>>>>>> when no programs are actively writing to the disk.
>>>>>>>
>>>>>>> I can reproduce it quite reliably on my 2TB Btrfs Steam library
>>>>>>> partition. In my case, I was downloading Strange Brigade, which is a
>>>>>>> roughly 25GB download and 33.65GB on disk. Somewhere during the
>>>>>>> download, iostat will start reporting disk writes around 300 MB/s,
>>>>>>> even
>>>>>>> though Steam itself reports disk usage of 40-45MB/s. After the
>>>>>>> download
>>>>>>> finishes and nothing else is being written to disk, I still see
>>>>>>> around
>>>>>>> 90-150MB/s worth of disk writes. Checking in iotop, I can see btrfs
>>>>>>> cleaner and other btrfs processes writing a lot of data.
>>>>>>>
>>>>>>> I left it running for a while to see if it was just some maintenance
>>>>>>> tasks that Btrfs needed to do, but it just kept going. I tried to
>>>>>>> reboot, but it actually prevented me from properly rebooting. After
>>>>>>> systemd timed out, my system finally shutdown.
>>>>>>>
>>>>>>> Here are my mount options:
>>>>>>> rw,relatime,compress-force=zstd:2,ssd,autodefrag,space_cache=v2,subvolid=5,subvol=/
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>
>>>>>> Compression, I guess that's the reason.
>>>>>>
>>>>>>  From the very beginning, btrfs defrag doesn't handle compressed
>>>>>> extent
>>>>>> well.
>>>>>>
>>>>>> Even if a compressed extent is already at its maximum capacity, btrfs
>>>>>> will still try to defrag it.
>>>>>>
>>>>>> I believe the behavior is masked by other problems in older kernels
>>>>>> thus
>>>>>> not that obvious.
>>>>>>
>>>>>> But after rework of defrag in v5.16, this behavior is more exposed.
>>>>>
>>>>> And if possible, please try this diff on v5.15.x, and see if v5.15 is
>>>>> really doing less IO than v5.16.x.
>>>>>
>>>>> The diff will solve a problem in the old code, where autodefrag is
>>>>> almost not working.
>>>>>
>>>>> diff --git a/fs/btrfs/ioctl.c b/fs/btrfs/ioctl.c
>>>>> index cc61813213d8..f6f2468d4883 100644
>>>>> --- a/fs/btrfs/ioctl.c
>>>>> +++ b/fs/btrfs/ioctl.c
>>>>> @@ -1524,13 +1524,8 @@ int btrfs_defrag_file(struct inode *inode,
>>>>> struct
>>>>> file *file,
>>>>>                         continue;
>>>>>                 }
>>>>>
>>>>> -               if (!newer_than) {
>>>>> -                       cluster = (PAGE_ALIGN(defrag_end) >>
>>>>> -                                  PAGE_SHIFT) - i;
>>>>> -                       cluster = min(cluster, max_cluster);
>>>>> -               } else {
>>>>> -                       cluster = max_cluster;
>>>>> -               }
>>>>> +               cluster = (PAGE_ALIGN(defrag_end) >> PAGE_SHIFT) - i;
>>>>> +               cluster = min(cluster, max_cluster);
>>>>>
>>>>>                 if (i + cluster > ra_index) {
>>>>>                         ra_index = max(i, ra_index);
>>>>>
>>>>>>
>>>>>> There are patches to address the compression related problem, but not
>>>>>> yet merged:
>>>>>>
>>>>>> https://apac01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fpatchwork.kernel.org%2Fproject%2Flinux-btrfs%2Flist%2F%3Fseries%3D609387&amp;data=04%7C01%7C%7C4ca72e2e2774416246b208d9e9e6c2d8%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637797999607143470%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&amp;sdata=FfyqNM8d%2BTXZXq3jE4d5M1OdO9hPeTIk5Ly6yaWWeuM%3D&amp;reserved=0
>>>>>>
>>>>>>
>>>>>> Mind to test them to see if that's the case?
>>>>>>
>>>>>> Thanks,
>>>>>> Qu
>>>>>>>
>>>>>>>
>>>>>>> I've disabled autodefrag again for now to save my SSD, but just
>>>>>>> wanted
>>>>>>> to say that there is still an issue. Have the defrag issues been
>>>>>>> fully
>>>>>>> fixed or are there more patches incoming despite what Reddit and
>>>>>>> Phoronix say? XD
>>>>>>>
>>>>>>> Thanks!
>>>>>>> Ben
>>>>>>>
>>>>>>>

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-07  1:16           ` Qu Wenruo
  2022-02-07  1:45             ` Jean-Denis Girard
@ 2022-02-09  1:56             ` Jean-Denis Girard
  2022-02-09  2:51               ` Qu Wenruo
  1 sibling, 1 reply; 16+ messages in thread
From: Jean-Denis Girard @ 2022-02-09  1:56 UTC (permalink / raw)
  To: Qu Wenruo, linux-btrfs

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

Hi Qu,

Sorry for late reply, and I still have not applied the last diff you sent.

But I wanted to report that without rebooting (uptime is 3 days 7 hours) 
or doing anything special, my system now behaves much better. 
btrfs-cleaner sometimes appears in top, but not for long period, and CPU 
usage is low. iostat seems reasonnable too.

Not sure what to conclude...


Thanks,
-- 
Jean-Denis Girard

SysNux                   Systèmes   Linux   en   Polynésie  française
https://www.sysnux.pf/   Tél: +689 40.50.10.40 / GSM: +689 87.797.527


Le 06/02/2022 à 15:16, Qu Wenruo a écrit :
> 
> 
> On 2022/2/7 01:43, Jean-Denis Girard wrote:
>> Hi list,
>>
>> I'm also experiencing high IO with autodefrag on 5.16.6 patched
>> with: -
>> https://patchwork.kernel.org/project/linux-btrfs/list/?series=609387,
>>
>>
> - https://patchwork.kernel.org/project/linux-btrfs/list/?series=611509,
>> - btrfs-defrag-bring-back-the-old-file-extent-search-behavior.diff.
> 
> OK, btrfs_search_forward() doesn't help in this case I guess.
> 
>>
>> After about 24 hours uptime, btrfs-cleaner is most of the time at 90
>> % CPU usage
>>
>> %CPU  %MEM     TIME+ COMMAND 77,6   0,0  29:03.25 btrfs-cleaner 19,1
>> 0,0   3:40.22 kworker/u24:8-btrfs-endio-write 19,1   0,0   1:50.46
>> kworker/u24:27-btrfs-endio-write 18,4   0,0   4:14.82
>> kworker/u24:7-btrfs-endio-write 17,4   0,0   4:08.08
>> kworker/u24:10-events_unbound 17,4   0,0   4:23.41
>> kworker/u24:9-btrfs-delalloc 15,8   0,0   3:41.21
>> kworker/u24:3-btrfs-endio-write 15,1   0,0   2:12.61
>> kworker/u24:26-blkcg_punt_bio 14,8   0,0   3:40.13
>> kworker/u24:18-btrfs-delalloc 12,8   0,0   3:55.70
>> kworker/u24:20-btrfs-delalloc 12,5   0,0   4:01.79
>> kworker/u24:1-btrfs-delalloc 12,2   0,0   4:04.63
>> kworker/u24:22-btrfs-endio-write 11,5   0,0   1:11.90
>> kworker/u24:11-btrfs-endio-write 11,2   0,0   1:25.96
>> kworker/u24:0-blkcg_punt_bio 10,2   0,0   4:24.17
>> kworker/u24:24+events_unbound ...
>>
>> Load average is 5,56, 6,88, 6,71 while just writing that mail.
>>
>> And iostat shows:
>>
  hours uptime>> avg-cpu:  %user   %nice %system %iowait  %st days eal   
%idle 1,5%    0,0%
>> 26,8%    6,3%    0,0%   65,4%
>>
>> tps    kB_read/s    kB_wrtn/s    kB_dscd/s    kB_read    kB_wrtn
>> kB_dscd Device 33893,50         0,0k       172,2M        57,8M
>> 0,0k       1,7G 577,7M nvme0n1 169,40         0,0k         1,2M
>> 0,0k       0,0k      12,5M 0,0k sda 178,90         0,0k         1,3M
>> 0,0k       0,0k      12,5M 0,0k sdb
>>
>> I hope that helps.
> 
> And what are the mount options?
> 
>  From the CPU usage, it looks like there are some infinite loop, but I
> can't find out why by a quick glance.
> 
> And since there is no extra read, it looks like it's doing defrag again
> and again on the same inode and range.
> 
> 
> Mind to apply attached `debug.diff`?
> 
> Then you still need to provide `/sys/kernel/debug/tracing/trace`, which
> can be very large and full of added debug info.
> (This means this can slow down your system)
> 
> The example of my local test would result something like this in above
> trace file:
> 
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 11/11   #P:16
> #
> #                                _-----=> irqs-off/BH-disabled
> #                               / _----=> need-resched
> #                              | / _---=> hardirq/softirq
> #                              || / _--=> preempt-depth
> #                              ||| / _-=> migrate-disable
> #                              |||| /     delay
> #           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
> #              | |         |   |||||     |         |
>     btrfs-cleaner-1770    [014] .....   961.534329: btrfs_defrag_file:
> entry r/i=5/257 start=0 len=131072 newer=7 thres=262144
>     btrfs-cleaner-1770    [014] .....   961.534333:
> defrag_collect_targets: add target r/i=5/257 start=0 len=16384 em=0
> len=16384 gen=7 newer=7
>     btrfs-cleaner-1770    [014] .....   961.534335:
> defrag_collect_targets: add target r/i=5/257 start=16384 len=16384
> em=16384 len=16384 gen=7 newer=7
>     btrfs-cleaner-1770    [014] .....   961.534336:
> defrag_collect_targets: add target r/i=5/257 start=32768 len=16384
> em=32768 len=16384 gen=7 newer=7
>     btrfs-cleaner-1770    [014] .....   961.534337:
> defrag_collect_targets: add target r/i=5/257 start=49152 len=16384
> em=49152 len=16384 gen=7 newer=7
>     btrfs-cleaner-1770    [014] .....   961.534564:
> defrag_collect_targets: add target r/i=5/257 start=0 len=16384 em=0
> len=16384 gen=7 newer=7
>     btrfs-cleaner-1770    [014] .....   961.534567:
> defrag_collect_targets: add target r/i=5/257 start=16384 len=16384
> em=16384 len=16384 gen=7 newer=7
>     btrfs-cleaner-1770    [014] .....   961.534568:
> defrag_collect_targets: add target r/i=5/257 start=32768 len=16384
> em=32768 len=16384 gen=7 newer=7
>     btrfs-cleaner-1770    [014] .....   961.534569:
> defrag_collect_targets: add target r/i=5/257 start=49152 len=16384
> em=49152 len=16384 gen=7 newer=7
>     btrfs-cleaner-1770    [014] .....   961.534580: btrfs_defrag_file:
> defrag target r/i=5/257 start=0 len=65536
>     btrfs-cleaner-1770    [014] .....   961.534681:
> btrfs_run_defrag_inodes: defrag finish r/i=5/257 ret=0 defragged=16
> last_scanned=131072 last_off=0 cycled=0
> 
> Thanks,
> Qu
> 
> 
>>
>>
>> Thanks,

[-- Attachment #2: Signature cryptographique S/MIME --]
[-- Type: application/pkcs7-signature, Size: 4003 bytes --]

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Still seeing high autodefrag IO with kernel 5.16.5
  2022-02-09  1:56             ` Jean-Denis Girard
@ 2022-02-09  2:51               ` Qu Wenruo
  0 siblings, 0 replies; 16+ messages in thread
From: Qu Wenruo @ 2022-02-09  2:51 UTC (permalink / raw)
  To: Jean-Denis Girard, linux-btrfs



On 2022/2/9 09:56, Jean-Denis Girard wrote:
> Hi Qu,
>
> Sorry for late reply, and I still have not applied the last diff you sent.
>
> But I wanted to report that without rebooting (uptime is 3 days 7 hours)
> or doing anything special, my system now behaves much better.
> btrfs-cleaner sometimes appears in top, but not for long period, and CPU
> usage is low. iostat seems reasonnable too.

Well, at least it's some good news.

BTW I have updated that branch on github, feel free to try (better with
the extra diff).

Just in case you have hit such situation again.

Meanwhile I'll try to rework autodefrag behavior to be more accurate.

Right now, autodefrag will try to scan the whole file if there is any
small writ to it.
And there is some questionable check on whether autodefrag should rescan
the whole file.

I want to change it to only scan ranges adjacent to the small write, so
we can avoid possible problem related to the whole file scan behavior.

Thanks,
Qu

>
> Not sure what to conclude...
>
>
> Thanks,

^ permalink raw reply	[flat|nested] 16+ messages in thread

end of thread, other threads:[~2022-02-09  3:08 UTC | newest]

Thread overview: 16+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-02-03 20:05 Still seeing high autodefrag IO with kernel 5.16.5 Benjamin Xiao
2022-02-04  1:17 ` Qu Wenruo
2022-02-04  1:54   ` Qu Wenruo
2022-02-04  4:32     ` Benjamin Xiao
2022-02-04  6:20       ` Qu Wenruo
2022-02-04 17:36         ` Benjamin Xiao
2022-02-04 19:34           ` Benjamin Xiao
2022-02-04 23:51             ` Qu Wenruo
     [not found]     ` <SL2P216MB11112B447FB0400149D320C1AC2B9@SL2P216MB1111.KORP216.PROD.OUTLOOK.COM>
2022-02-06  9:26       ` Qu Wenruo
2022-02-06 17:43         ` Jean-Denis Girard
2022-02-07  1:16           ` Qu Wenruo
2022-02-07  1:45             ` Jean-Denis Girard
2022-02-09  1:56             ` Jean-Denis Girard
2022-02-09  2:51               ` Qu Wenruo
2022-02-07  3:05         ` Qu Wenruo
     [not found]           ` <SL2P216MB1111994F81CE0006D495511DAC2C9@SL2P216MB1111.KORP216.PROD.OUTLOOK.COM>
2022-02-07  5:23             ` Qu Wenruo

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.