bcache_writebac task 100% CPU

bcache_writebac task 100% CPU

[Rolf Fokkens]

Sometimes bcache_writebac task consumes 100% CPU during normal operation, but after a while (like a minute) this drops to normal.

It can be triggered in a reproducable fashion on my system by:

echo 0 > /sys/block/bcache0/bcache/writeback_percent

After this bcache_writebac starts to burn CPU cycles, and it never seems to stop doing so. changing the writeback_percent value back to 25 doesn't change anything.

Apart from a busy CPU there appear to be no problem (e.g. no "task bcache_writebac:286 blocked for more than 120 seconds" messages).

I filed this issue also on: https://bugzilla.kernel.org/show_bug.cgi?id=76391

[rolf.fokkens@home07 ~]$ bcache-status  -s
--- bcache ---
UUID                        4892b3d5-fd49-4d71-adb6-d7b0a799e913
Block Size                  512 B
Bucket Size                 512.00 KiB
Congested?                  False
Read Congestion             0.0ms
Write Congestion            0.0ms
Total Cache Size            30 GiB
Total Cache Used            2 GiB	(6%)
Total Cache Unused          28 GiB	(94%)
Evictable Cache             30 GiB	(100%)
Replacement Policy          [lru] fifo random
Cache Mode                  writethrough [writeback] writearound none
Total Hits                  31727	(99%)
Total Misses                76
Total Bypass Hits           3569	(100%)
Total Bypass Misses         0
Total Bypassed              27.5 MiB
--- Backing Device ---
   Device File               /dev/md2 (9:2)
   bcache Device File        /dev/bcache0 (252:0)
   Size                      140 GiB
   Cache Mode                writethrough [writeback] writearound none
   Readahead                 0
   Sequential Cutoff         0 B
   Merge sequential?         False
   State                     dirty
   Writeback?                True
   Dirty Data                6.1 MiB
   Total Hits                31727	(99%)
   Total Misses              76
   Total Bypass Hits         3569	(100%)
   Total Bypass Misses       0
   Total Bypassed            27.5 MiB
--- Cache Device ---
   Device File               /dev/sdd1 (8:49)
   Size                      30 GiB
   Block Size                512 B
   Bucket Size               512.00 KiB
   Replacement Policy        [lru] fifo random
   Discard?                  True
   I/O Errors                0
   Metadata Written          906.00 KiB
   Data Written              52.3 MiB
   Buckets                   61440
   Cache Used                2 GiB	(6%)
   Cache Unused              28 GiB	(94%)
[rolf.fokkens@home07 ~]$

Re: bcache_writebac task 100% CPU

[Kent Overstreet]

On Sun, May 18, 2014 at 10:23:30AM +0200, Rolf Fokkens wrote:
> Sometimes bcache_writebac task consumes 100% CPU during normal operation, but after a while (like a minute) this drops to normal.
> 
> It can be triggered in a reproducable fashion on my system by:
> 
> echo 0 > /sys/block/bcache0/bcache/writeback_percent
> 
> After this bcache_writebac starts to burn CPU cycles, and it never seems to stop doing so. changing the writeback_percent value back to 25 doesn't change anything.
> 
> Apart from a busy CPU there appear to be no problem (e.g. no "task bcache_writebac:286 blocked for more than 120 seconds" messages).

...Changing it back to 25% doesn't do anything? _that_ is odd...

Can you send me the output of writeback_rate_debug? Check it once before you've
done anything, when things are working normally (after a fresh boot when
writeback_percent is nonzero, probably), then grab it again after you've set
writeback_percent to 0 and then back to 25, when it's still spinning.

There seems to be two separate bugs here, the one I'm particularly concerned
about is why setting writeback_percent back to 25 doesn't restore the old
behaviour.

Also, what kernel are you running?

Re: bcache_writebac task 100% CPU

[Rolf Fokkens]

On 05/19/2014 06:55 PM, Kent Overstreet wrote:
> ...Changing it back to 25% doesn't do anything? _that_ is odd...

I was wrong on this one. At first the CPU usage stayed the same, but 
after a while (as in > 10 minutes) CPU usage dropped to normal 
behaviour. Sorry, I was too impatient.

> Can you send me the output of writeback_rate_debug? Check it once before you've
> done anything, when things are working normally (after a fresh boot when
> writeback_percent is nonzero, probably), then grab it again after you've set
> writeback_percent to 0 and then back to 25, when it's still spinning.
I will do so, probably tomorrow.
> There seems to be two separate bugs here, the one I'm particularly concerned
> about is why setting writeback_percent back to 25 doesn't restore the old
> behaviour.
>
> Also, what kernel are you running?
I am using Fedora kernel version kernel-3.14.4-200.fc20.x86_64

Re: bcache_writebac task 100% CPU

[Rolf Fokkens]

On 05/19/2014 06:55 PM, Kent Overstreet wrote:
> ...Changing it back to 25% doesn't do anything? _that_ is odd...
>
> Can you send me the output of writeback_rate_debug? Check it once before you've
> done anything, when things are working normally (after a fresh boot when
> writeback_percent is nonzero, probably), then grab it again after you've set
> writeback_percent to 0 and then back to 25, when it's still spinning.
I collected the requested data by logging both writeback_percent and 
writeback_rate_debug every second. Every second also the cumulative CPU 
usage of the bcache_writebac task is logged (as shown by ps -efw), 
showing that the task is burning CPU cycles.

Both the collecting script and the log file can be found here: 
https://bugzilla.kernel.org/show_bug.cgi?id=76391
> Also, what kernel are you running?
As mentioned before, the kernel is Fedora kernel 
kernel-3.14.4-200.fc20.x86_64