Re: Debugging abysmal write performance with 100% cpu kworker/u16:X+flush-btrfs-2

["Holger Hoffstätte" <holger@applied-asynchrony.com>]

On 2020-07-25 18:43, Hans van Kranenburg wrote:
> On 7/25/20 5:37 PM, Holger Hoffstätte wrote:
>>> [<0>] rq_qos_wait+0xfa/0x170
>>> [<0>] wbt_wait+0x98/0xe0
>>> [<0>] __rq_qos_throttle+0x23/0x30
> 
> I need to cat /proc/<pid>/stack a huge number of times in a loop to once
> in a while get this sort of output shown.

Ahh! So that means you are just getting lucky and catch the occasional
throttle in action. Ok.

>> You can tune the expected latency of device writes via:
>> /sys/block/sda/queue/wbt_lat_usec.
> 
> Yes, I have been playing around with it earlier, without any effect on
> the symptoms.
> 
> I just did this again, echo 0 > all of the involved block devices. When
> looking at the events/wbt trace point, I see that wbt activity stops at
> that moment.
> 
> No difference in symptoms.

Ok. Worth a shot..but in retrospect not really, since I just realized
that I had your entire scenario backwards. Nevermind then.

> Dirty buffers were ~ 2G in size. I can modify the numbers to make it
> bigger or smaller. There's absolutely no change in behavior of the system.

Ok. I also have 2GB max-dirty and 1GB writeback-dirty, which is
plenty for a 10G pipe.

> It doesn't. It's idle, waiting to finally get some data sent to it.

Yup, looks like it.

> All processing speed is inversely proportional to the cpu usage of this
> kworker/u16:X+flush-btrfs-2 thread. If it reaches >95% kernel cpu usage,
> everything slows down. The network is idle, the disks are idle. Incoming
> rsync speed drops, the speed in which btrfs receive is reading input
> drops, etc. As soon as kworker/u16:X+flush-btrfs-2 busy cpu usage gets
> below ~ 95% again, throughput goes up.

Only thing I can think of is that your rsync runs create insane amounts
of small COW extents that need to be ordered/merged. Multiply by number of
processes and you're probably hitting some super contended part. Since
the kworker isn't stuck forever but apparently makes progress it's not
dead, just slow/overloaded.

A few years ago I started using rsync exclusively with --whole-file since
it's not just much faster but also creates significantly less fragmentation
at the expense of some disk space, but whatever...in my case snapshot rotation
takes care of that. Maybe it's an option for you.

So maybe things to try:

- run rsync with --whole-file
- run fewer rsyncs in parallel (might not be necessary with --whole-file!)

If that doesn't help someone else needs to chime in..

-h