Discussion:
bcache_writebac task 100% CPU
Rolf Fokkens
2014-05-18 08:23:30 UTC
Permalink
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

[***@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%)
[***@home07 ~]$
Kent Overstreet
2014-05-19 16:55:50 UTC
Permalink
Post by Rolf Fokkens
Sometimes bcache_writebac task consumes 100% CPU during normal operation, but after a while (like a minute) this drops to normal.
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?
Rolf Fokkens
2014-05-19 18:01:46 UTC
Permalink
Post by Kent Overstreet
...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.
Post by Kent Overstreet
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.
Post by Kent Overstreet
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
Rolf Fokkens
2014-05-20 19:38:35 UTC
Permalink
Post by Kent Overstreet
...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
Post by Kent Overstreet
Also, what kernel are you running?
As mentioned before, the kernel is Fedora kernel
kernel-3.14.4-200.fc20.x86_64

Loading...