cat /sys/fs/cgroup/blkio/blkio.time_recursive took 1second to complete

[norman shen]

Issue:

```console
# time cat /sys/fs/cgroup/blkio/blkio.time_recursive
8:16 354721435

real 0m1.297s
user 0m0.000s
sys 0m1.297s
```

As could be seen from above result, cat blkio took about 1 second to complete which
is much longer than a normal case.

Kernel Version:

Linux compute08 4.15.0-72-generic #81-Ubuntu SMP Tue Nov 26 12:20:02 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

Would be appreciated to know any operations to identify the issue, Thank you very much for the help.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Kevin Brierly (kb1828)]

Was the cause of this ever determined? I am seeing something similar on some of my systems. Times are usually around 1s, sometimes higher. A recent high was 1.7s

# uname -r
4.15.0-193-generic

# time cat /sys/fs/cgroup/blkio/blkio.time_recursive
8:144 69349171178307
8:128 4718621058
8:112 4604996397
8:96 4625378704
8:80 4873085108
8:64 3777190161
8:48 4749702443
8:32 8346248400
8:16 9260262419
8:0 154939957376379

real 0m1.03s
user 0m0.00s
sys 0m1.03s

[norman shen (jshen28)]

Hi Kevin, have you used perf and analyze the flamegraph?

[Kevin Brierly (kb1828)]

yes. just confirms it takes a while.

[norman shen (jshen28)]

thank you and same for me. __percpu_counter_sum is very slow even though only one block device.. Not really figure why. Do you have any clue to reproduce this behavior?

[Kevin Brierly (kb1828)]

Do you have a lot of blkio devices coming and going? For example iscsi/usb/etc. We currently believe it's tree bloat due to added/removed devices. We are still digging into the issue.

[norman shen (jshen28)]

we might have around 50 multipath mappers per node and underline device is FC based disk. But disks added/removed should not be frequent. What machine are you using? For me, some nodes are intel 2650, not sure if it is relevant.

[Kevin Brierly (kb1828)]

the hardware does not seem to be relevant. Do you have anything calling "racadm lclog" on fairly regular basis? it creates and destroys a usb device over and over.

[norman shen (jshen28)]

I have no idea what racadm is ..

[norman shen (jshen28)]

do you know what __percpu_counter_sum does? I am wondering why it has been sampled a lot of times.

[Kevin Brierly (kb1828)]

It examines the blkio device tree and sums data as far as i know. Removed devices do not get deleted from the blkio statistics tree and are just marked as offline somehow.

In our case racadm lclog created and destroyed usb devices to pull data and the blkio tree reached over 65000 leafs. It takes time to process a tree that large. WE believe our issue was caused by accumulation over time of the usb device leafs from racadm lclog. WE had it running in a cron which has now been stopped.