On 17/07/2024 18.31, Yosry Ahmed wrote:
[..]
I agree that description should be updated as patch have evolved, and
you suggestions make sense, thanks.
But I'm not sure we are finished evolving this patch, because the scheme
of allowing all sub-cgroups to become the ongoing flusher (and only
avoiding lock-spinning when cgroup_is_descendant), is causing issues in
production.
Sure, I just wanted to point out the the commit log should be updated
going forward, not implying that we are done here :)
We are using cadvisor in production for collecting metrics, which walks
all the cgroups reading stat files e.g. io.stat, cpu.stat , memory.stat
(doing 3 flushes of same cgroup in short timespan), but individual
cgroups don't overlap much to benefit from ongoing_flusher scheme.
Below is (1 sec) production data, where cadvisor and kswapd collide:
> 02:01:33 @ongoing_flusher_cnt[kworker/u395:14]: 1
> @ongoing_flusher_cnt[kswapd5]: 3
> @ongoing_flusher_cnt[kswapd7]: 4
> @ongoing_flusher_cnt[kswapd6]: 4
> @ongoing_flusher_cnt[kswapd8]: 4
> @ongoing_flusher_cnt[kswapd9]: 5
> @ongoing_flusher_cnt[kswapd2]: 5
> @ongoing_flusher_cnt[kswapd10]: 5
> @ongoing_flusher_cnt[kswapd3]: 5
> @ongoing_flusher_cnt[kswapd11]: 5
> @ongoing_flusher_cnt[kswapd0]: 5
> @ongoing_flusher_cnt[kswapd4]: 6
> @ongoing_flusher_cnt[kswapd1]: 7
> @ongoing_flusher_cnt[cadvisor]: 9
For cadvisor ongoing_flusher only helps 9 times to avoid flush.
> @ongoing_flusher_cnt[handled_race]: 18
> @ongoing_flusher_cnt[all]: 61
Our ongoing_flusher scheme detects overlap and avoid 61 out of 462 flushes.
> @cnt[tracepoint:cgroup:cgroup_ongoing_flusher_wait]: 61
> @cnt[kfunc:vmlinux:cgroup_rstat_flush_locked]: 462
> @cnt[tracepoint:cgroup:cgroup_rstat_lock_contended]: 9032
This is bad: Lock is contended 9032 time within this 1 sec period.
Below, lock_contended cases is captured in more detail.
> @cnt[tracepoint:cgroup:cgroup_rstat_locked]: 9435
> @lock_contended[normal, 4]: 1
> @lock_contended[normal, 1]: 2
> @lock_contended[normal, 3]: 6
> @lock_contended[normal, 2]: 15
> @lock_contended[yield, 4]: 49
> @lock_contended[after_obtaining_lock, 4]: 49
> @lock_contended[normal, 0]: 59
The "normal" lock_contended for level 0,
meaning the cgroup root is contended 59 times within this 1 sec period.
> @lock_contended[after_obtaining_lock, 1]: 117
> @lock_contended[yield, 1]: 118
> @lock_contended[yield, 3]: 258
> @lock_contended[after_obtaining_lock, 3]: 258
> @lock_contended[after_obtaining_lock, 2]: 946
> @lock_contended[yield, 2]: 946
Lock contention for 'yielded' case for level 2.
Goes crazy with 946/sec.
> @lock_contended[yield, 0]: 7579
Lock contention for 'yielded' case for level 0, the root.
Is really crazy with 7579/sec lock spin cases.
> @lock_contended[after_obtaining_lock, 0]: 7579
IMHO this shows that, due to lock yielding, the scheme of
ongoing_flusher for sub-trees only cause issues.
Just to make sure I understand correctly, allowing non-root to become
ongoing_flushers is problematic because we only support a single
ongoing_flusher, so if we have a subsequent root flush, it won't be
the ongoing_flusher and we won't benefit from skipping other flushes.
Correct?
Yes, basically... keep in mind, what will happen is that subsequent root
flush will busy-wait/spin on getting lock, which in case of a yield from
ongoing-flusher, will result in multiple flushers being active, despite
our efforts to have a single ongoing-flusher.
I honestly think the problem here is not that we support
ongoing_flusher for subtrees, which imo is nice to have at a low
additional cost, and does have its benefits (see below). I think the
problem is that lock yielding means that we can have multiple ongoing
flushers, while the current scheme only records one.
Yes, the yielding is causing multiple flushers to be active the same time.
What I think we should be doing is either supporting multiple
ongoing_flushers (by replacing the global variable with a per-cgroup
flag, perhaps), or biting the bullet and start using a mutex to drop
lock yielding. If there aren't any concerns beyond priority inversion
(raised by Shakeel), maybe adding a mutex_lock_timeout() variant as I
suggested could fix this issue (and also put a bound on the flushing
latency in general)?
The mutex_lock_timeout is an interesting idea, but not a primitive we
have available today, right?
p.s. I have 5 prod machines running with mutex change, and I've not
gotten any SRE complaints.
(I suppose the latter is preferrable)
IMHO we should go back to only doing ongoing_flusher for root-cgroup.
There is really low chance of sub-trees flushes being concurrent enough
to benefit from this, and it cause issues and needs (ugly) race handling.
Further more sub-tree flushing doesn't take as long time as level 0
flushing, which further lower the chance of concurrent flushes.
I agree that the race handling is not pretty, and we can try to
improve the implementation or handle the race in other ways. However,
I think that skipping flushes for subtrees is valuable. I am not sure
about the cgroup arrangement in your use case, but we do have cgroups
with a lot of tasks in them (and/or child cgroups). If there is memory
pressure (or hit the cgroup limit), they all may go into direct
reclaim concurrently, so skipping flushes could really be beneficial.
Of course, if the difference in complexity is not justified, we can go
back to only supporting root cgroups for ongoing_flusher for now. But
as I mentioned in the v4 email thread, some of the complexity may
still remain anyway as we have multiple root cgroups in v1.
Having an incremental step with "only supporting root cgroups for
ongoing_flusher for now" is a good step forward IMHO.
As you could see in grafana plot, this would be a significant production
improvement on its own, as it avoids wasting CPU resources spinning on
the lock.
Being able to have multiple root cgroups, due to in v1, does pose an
implementation problem. Only having a single root, would allow to have
a race-free cmpxchg scheme.
Would it be reasonable to only support v2?
If so, how can I match on this?
Let's get some quick data on flush times from production, to support my
claim:
Thanks for the data. I agree that in general root flushes will be a
lot more expensive than subtree flushes, but keep in mind that the
data may look really different depends on the cgroup setup. As I
mentioned, I think we should still support subtree flushes unless the
difference in complexity is not justified.
It would be really valuable if you could provide production data on the
lock-hold times, just like I did with below bpftrace script...
Is that possible, please?
The bpftrace onliner:
sudo bpftrace -e '
tracepoint:cgroup:cgroup_rstat_locked {
if (args->cpu == -1) { @start[tid]=nsecs; }
@cnt[probe]=count();
if (args->contended) {
@lock_contended["after_obtaining_lock", args->level]=count();
}}
tracepoint:cgroup:cgroup_rstat_unlock {
if (args->cpu == -1) {
$now=nsecs; $start=@start[tid]; $diff=$now-$start;
@locked_time_level[args->level]=hist($diff);
}
@cnt[probe]=count()}
kfunc:cgroup_rstat_flush_locked {@cnt[probe]=count()}
interval:s:1 {time("%H:%M:%S ");
print(@cnt);
print(@lock_contended);
print(@locked_time_level);
clear (@cnt);
clear (@lock_contended); }
END {clear(@start)}'
Time below is in nanosec.
@locked_time_level[0]:
[4M, 8M) 623 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
|
[8M, 16M) 860
|@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[16M, 32M) 295 |@@@@@@@@@@@@@@@@@
|
[32M, 64M) 275 |@@@@@@@@@@@@@@@@
|
@locked_time_level[1]:
[4K, 8K) 6 |@@@@
|
[8K, 16K) 65
|@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[16K, 32K) 52 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
|
[32K, 64K) 23 |@@@@@@@@@@@@@@@@@@
|
[64K, 128K) 15 |@@@@@@@@@@@@
|
[128K, 256K) 10 |@@@@@@@@
|
[256K, 512K) 6 |@@@@
|
[512K, 1M) 15 |@@@@@@@@@@@@
|
[1M, 2M) 2 |@
|
[2M, 4M) 14 |@@@@@@@@@@@
|
[4M, 8M) 6 |@@@@
|
[8M, 16M) 7 |@@@@@
|
[16M, 32M) 1 |
|
@locked_time_level[2]:
[2K, 4K) 1 |
|
[4K, 8K) 160 |@@@@@@@@@
|
[8K, 16K) 733 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
|
[16K, 32K) 901
|@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[32K, 64K) 191 |@@@@@@@@@@@
|
[64K, 128K) 115 |@@@@@@
|
[128K, 256K) 61 |@@@
|
[256K, 512K) 70 |@@@@
|
[512K, 1M) 59 |@@@
|
[1M, 2M) 27 |@
|
[2M, 4M) 9 |
|
@locked_time_level[3]:
[1K, 2K) 3 |
|
[2K, 4K) 2 |
|
[4K, 8K) 5 |
|
[8K, 16K) 147 |@@@@@@
|
[16K, 32K) 1222
|@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[32K, 64K) 266 |@@@@@@@@@@@
|
[64K, 128K) 199 |@@@@@@@@
|
[128K, 256K) 146 |@@@@@@
|
[256K, 512K) 124 |@@@@@
|
[512K, 1M) 17 |
|
[1M, 2M) 0 |
|
[2M, 4M) 0 |
|
[4M, 8M) 1 |
|
@locked_time_level[4]:
[4K, 8K) 2 |@@
|
[8K, 16K) 17 |@@@@@@@@@@@@@@@@@@@@@@
|
[16K, 32K) 40
|@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[32K, 64K) 4 |@@@@@
|
--Jesper
