Re: Btrfs autodefrag wrote 5TB in one day to a 0.5TB SSD without a measurable benefit

[Qu Wenruo <quwenruo.btrfs@gmx.com>]

On 2022/3/11 05:31, Jan Ziak wrote:
> On Thu, Mar 10, 2022 at 7:42 AM Qu Wenruo <quwenruo.btrfs@gmx.com> wrote:
>>> The compressed trace is attached to this email. Inode 307273 is the
>>> 40GB sqlite file, it currently has 1689020 extents. This time, it took
>>> about 3 hours after "mount / -o remount,autodefrag" for the issue to
>>> start manifesting itself.
>>
>> Sorry, considering your sqlite file is so large, there are too many
>> defrag_one_locked_range() and defrag_add_target() calls.
>>
>> And the buffer size is a little too small.
>>
>> Mind to re-take the trace with the following commands?
>
> The compressed trace (size: 1.8 MB) can be downloaded from
> http://atom-symbol.net/f/2022-03-10/btrfs-autodefrag-trace.txt.zst
>
> According to compsize:
>
> - inode 307273, at the start of the trace: 1783756 regular extents
> (3045856 refs), 0 inline
>
> - inode 307273, at the end of the trace: 1787794 regular extents
> (3054334 refs), 0 inline
>
> - inode 307273, delta: +4038 regular extents (+8478 refs)

The trace results shows a pattern in the beginning, that around every
30s, autodefrag scans that inode once:

  67292.784930: defrag_file_start: root=5 ino=307273 start=0
len=42705735680 extent_thresh=65536
  67323.655798: defrag_file_start: root=5 ino=307273 start=0
len=42706268160 extent_thresh=65536
  67354.126797: defrag_file_start: root=5 ino=307273 start=0
len=42706268160 extent_thresh=65536
  67358.865643: defrag_file_start: root=5 ino=307273 start=0
len=42706268160 extent_thresh=65536
  67385.190417: defrag_file_start: root=5 ino=307273 start=0
len=42706554880 extent_thresh=65536
  67415.960153: defrag_file_start: root=5 ino=307273 start=0
len=42706554880 extent_thresh=65536
  67446.798930: defrag_file_start: root=5 ino=307273 start=0
len=42707038208 extent_thresh=65536

This part is the expected behavior.

But very soon, the autodefrag is scanning the file again and again in a
very short time:

  69188.802624: defrag_file_start: root=5 ino=307273 start=0
len=42720563200 extent_thresh=65536
  69189.235753: defrag_file_start: root=5 ino=307273 start=0
len=42720563200 extent_thresh=65536
  69189.896309: defrag_file_start: root=5 ino=307273 start=0
len=42720563200 extent_thresh=65536
  69190.594834: defrag_file_start: root=5 ino=307273 start=0
len=42720563200 extent_thresh=65536
  69191.185359: defrag_file_start: root=5 ino=307273 start=0
len=42720563200 extent_thresh=65536
  69191.543833: defrag_file_start: root=5 ino=307273 start=0
len=42720563200 extent_thresh=65536
  69192.275865: defrag_file_start: root=5 ino=307273 start=0
len=42720563200 extent_thresh=65536

That inode get defragged 7 times in just 5 seconds.
There are more similar patterns for the same inode.

The unexpected behavior is the same reported by another reporter.
(https://github.com/btrfs/linux/issues/423#issuecomment-1062338536)

Thus this patch should resolve the repeated defrag behavior:
https://patchwork.kernel.org/project/linux-btrfs/patch/318a1bcdabdd1218d631ddb1a6fe1b9ca3b6b529.1646782687.git.wqu@suse.com/

Mind to give it a try?

>
> Approximately 85% of lines in the trace are related to the mentioned
> inode, which means that btrfs-autodefrag is trying to defragment the
> file. The main issue, in my opinion, is that the number of extents
> increased by 4038 despite btrfs's defragmentation attempts.

Well, this is a trade-off between the effectiveness of defrag and IO.

Previously we have a larger extent threshold for autodefrag (256K vs 64K
now).
However that larger threshold will cause even more IO.

In the near future (hopefully v5.19), we will introduce more fine tuning
for autodefrag (allowing users to specify the autodefrag interval, and
target extent threshold).

Thanks,
Qu

>
> -Jan