From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by smtp.lore.kernel.org (Postfix) with ESMTP id 90C0CEB64DC for ; Sat, 15 Jul 2023 00:01:06 +0000 (UTC) Received: by kanga.kvack.org (Postfix) id C314D6B0071; Fri, 14 Jul 2023 20:01:05 -0400 (EDT) Received: by kanga.kvack.org (Postfix, from userid 40) id BBAA96B0072; Fri, 14 Jul 2023 20:01:05 -0400 (EDT) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id A335A6B0074; Fri, 14 Jul 2023 20:01:05 -0400 (EDT) X-Delivered-To: linux-mm@kvack.org Received: from relay.hostedemail.com (smtprelay0015.hostedemail.com [216.40.44.15]) by kanga.kvack.org (Postfix) with ESMTP id 8E0FC6B0071 for ; Fri, 14 Jul 2023 20:01:05 -0400 (EDT) Received: from smtpin28.hostedemail.com (a10.router.float.18 [10.200.18.1]) by unirelay02.hostedemail.com (Postfix) with ESMTP id 5587212039F for ; Sat, 15 Jul 2023 00:01:05 +0000 (UTC) X-FDA: 81011890890.28.2138CB6 Received: from mail-wr1-f42.google.com (mail-wr1-f42.google.com [209.85.221.42]) by imf24.hostedemail.com (Postfix) with ESMTP id 44709180019 for ; Sat, 15 Jul 2023 00:01:02 +0000 (UTC) Authentication-Results: imf24.hostedemail.com; dkim=pass header.d=cloudflare.com header.s=google header.b="w1so6/uR"; spf=pass (imf24.hostedemail.com: domain of ivan@cloudflare.com designates 209.85.221.42 as permitted sender) smtp.mailfrom=ivan@cloudflare.com; dmarc=pass (policy=reject) header.from=cloudflare.com ARC-Seal: i=1; s=arc-20220608; d=hostedemail.com; t=1689379263; a=rsa-sha256; cv=none; b=7X0bAvaY8z7RwwZI9Plk+TpGTsjhuC7pIcOJR8x0HnofDCGFQ8Br/jOV1/UZN2+BQWyWJO csI/jfvHYkFl6ZIvmmuLSuJ3Mhrjfe8IQhGnfzGpiq9ayZdgLyMxWY8wCxqwX0g5tL5rMa 4gpupVfsD84sNSNWlwolNrRAEnrAsMM= ARC-Authentication-Results: i=1; imf24.hostedemail.com; dkim=pass header.d=cloudflare.com header.s=google header.b="w1so6/uR"; spf=pass (imf24.hostedemail.com: domain of ivan@cloudflare.com designates 209.85.221.42 as permitted sender) smtp.mailfrom=ivan@cloudflare.com; dmarc=pass (policy=reject) header.from=cloudflare.com ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=hostedemail.com; s=arc-20220608; t=1689379263; h=from:from:sender:reply-to:subject:subject:date:date: message-id:message-id:to:to:cc:cc:mime-version:mime-version: content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references:dkim-signature; bh=9qCsYq5AfQu15dBgFcUhM5i+Y9hdaw4Di+rchoqRa1A=; b=ZjQASZk9ovlq85ekEMud2zUMoaZFJOsEYx/X2SZyYS0Vsz4qYrgig92WEE+vlvzyB86WA+ iaZT97qipiRdXRKwUbBQ5LaYOf6uKMTArQxymfLvwWi79awQ2mZkI8xKb8rJlVU3GeGnY3 XlHlh+/9ftb7b/V4/1O4YQe+Yq/WPZ0= Received: by mail-wr1-f42.google.com with SMTP id ffacd0b85a97d-3142a9ffa89so2699469f8f.0 for ; Fri, 14 Jul 2023 17:01:02 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=cloudflare.com; s=google; t=1689379261; x=1691971261; h=content-transfer-encoding:cc:to:subject:message-id:date:from :in-reply-to:references:mime-version:from:to:cc:subject:date :message-id:reply-to; bh=9qCsYq5AfQu15dBgFcUhM5i+Y9hdaw4Di+rchoqRa1A=; b=w1so6/uRCSkF2JfOE4Lp7UEUm7H2/SnJOrUe5GP0/6Hoc5lu/q59ef2oEAIUdNGlPu 1oBomtwOZE28hBXuVf9l6r3h/U7PyWOeBibY6Emk7xzVuyXK6RJfTioxx73MA4Ej67Ft gK1kNyPKvTTQneIkrmuHgWBjmDfq96bq6Y21Q= X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20221208; t=1689379261; x=1691971261; h=content-transfer-encoding:cc:to:subject:message-id:date:from :in-reply-to:references:mime-version:x-gm-message-state:from:to:cc :subject:date:message-id:reply-to; bh=9qCsYq5AfQu15dBgFcUhM5i+Y9hdaw4Di+rchoqRa1A=; b=Qx4lxt3zh+X6YMVCn8R3QlW0NmeLe8T0RElVvywhHu5jh8g65+4z2ViFTqUXNAH4++ dIbvf83ZSgyHxcxL/t+a6YsSiBNF0OUsGNK3b02rsJ38f5qLf1A8j9PjhOuJQq1Q8x1C Y21d82EWrXDpyzF4vL3Q8icPeV2qDunWQcSoFzUl5mu+v+pgAY64I+Kk81brYPYxzknz yGpocDXoZo3G8C9e22gEV7cbwrO/KSMTfN4YbYzZVvQNdQh3xnd6TZsbj1bX+093cnWj H5HhCR/D9A2WLbe+/MEAlEcX3VY8En7uiXRQ6/cX+MPxypA7S3GgOoOgGt6MMLt9eAJe IolQ== X-Gm-Message-State: ABy/qLbMJjRn9UUSq+biVOuEIsFGqyeffPR5hHpRyAbN5hEasQt3q8Yj zjqU/PvEHvKyXxtlv5mEePVu4XaIZwMBt1jAwyDEgA== X-Google-Smtp-Source: APBJJlEvCf0BSl7GtqyQou6Cs0GD8ZpzFZvUUaUmW+z6ihNa4/16dJUC5WbYXRU1+zLyptJm0Uqq3GnsW0ohBqtQtKI= X-Received: by 2002:a5d:66c5:0:b0:316:e073:e547 with SMTP id k5-20020a5d66c5000000b00316e073e547mr5135314wrw.28.1689379261115; Fri, 14 Jul 2023 17:01:01 -0700 (PDT) MIME-Version: 1.0 References: <20230706062045.xwmwns7cm4fxd7iu@google.com> In-Reply-To: From: Ivan Babrou Date: Fri, 14 Jul 2023 17:00:50 -0700 Message-ID: Subject: Re: Expensive memory.stat + cpu.stat reads To: Waiman Long Cc: Shakeel Butt , cgroups@vger.kernel.org, Linux MM , kernel-team , Johannes Weiner , Michal Hocko , Roman Gushchin , Muchun Song , Andrew Morton , linux-kernel Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable X-Rspamd-Server: rspam08 X-Rspamd-Queue-Id: 44709180019 X-Stat-Signature: nyaer55praja5dm4kzyip45b36b6u97w X-Rspam-User: X-HE-Tag: 1689379262-191595 X-HE-Meta: U2FsdGVkX1+H1xa4he0sysVrUq8mRVj/eY7E8QNSL1mrHC34fGVUZdSAi6p50FJ2ZtZl7Z5pErfjlCSShiCcZ0kptjaYQe+9KKWjQ7xdzDmI8X4x8PhdNpbNMf/TnEH+LFtjXbMmBhS0lK0qwy8axv8/kX5pdaj2GEBih5oVzxnJYbp21sTzEJQR8GDFsMqcSH4HWyt6qqD6JZgYHxwosRwNSuupfv3P6jehQYap8QP4R4Mbizi7p6Z6u/XnlS/diRJR2HJU8OphVuu6HJsgxlyvZpZurPy69Q7aE0TaNNM2RyDjTAgag14LWuQz3yEh0kY6AvRncpReQZ6hI5WcJx6CPpLcOQ1gyAg6CRoLwqUGdNMedYK2qy251evAfw19wASdCv2QR51TiibTXuSaNFhj8nHHfJnNt5Z9FwqPehZ5vuWKrDsrVIYkl/1biUMgLtViJpDTUnzRk9snQLchOycMCpMvd8DK1z/OfiIC1bEQU2+cAWJcwBdWENRRHHDIA4TFj3fYTZCPLn4zmOasu0V4ffKUefspiDAJKjBsxPKByOKbZW+chPwVg0n6efYpTEvqRdMebdEftSL0v6ntmZb3TCnaZ5RXiJXCdW5Z24GYimCiMqHQwDOhBmnFSIgFBSJZA52I4HGqjUdsE5O45WE4qGumP65xR0iTnWz+Zfq+rdruu3hmGuFa+C3SPfkiFELBw/NmpDVR15DKHkc3Zoqu/+v86YeEI+bLoPhfY8pQmbfi6fQkj7F64R/tRsiElJd13pfh4xZ2o5siFACRf17rXMxawiD5s+nAOfYdFkvBWq1av1ygoFTwsP4LWuIRyx+3aIrX5x4Lw9fBsdYqkqwTtilaY/dKOsIzJtyEzCj5ZJAqAP5S/m/bjSEW7LeUZKRO07DiI16+yWqRVtUGOnolHdzT0j7w0nJ8luQSEsY/vqOmMXbrRruum+y5NsHv8/Z2xdwRq+3KFAxomoP F7hdiT1e L4UQH+EeStMgXbpBBP3ebSJaHHozC1klHO2fN0iQBUbXDND29X++a6UsNUKE+9npkYVfz61ptRgCfKmVfRvcbCFbBLEAPe9bfaEm2l2Auz7YiL5h+070F4VxSBa4VK0oWbMA6KNPu1odXKPLPpUnybgA/HFEQidBRQajksgIOjp9VtQ94N4l1CYO/miHxwhbKjR20STpxZq5v/1Z7LPcqZsXbzL9ZNoEHw5gKUx5OhJiKVVcUOaeD957bUOwzFpZBmmNITTm2Z07HW1VjTtQL43ojQs/VFmbQpcHJ9Ic3BlM5hhg7CMRqSNVbCaY3soNFVnrA7yrLPmLRfIV9awCvAmw76ih4/9EiZaGj X-Bogosity: Ham, tests=bogofilter, spamicity=0.000000, version=1.2.4 Sender: owner-linux-mm@kvack.org Precedence: bulk X-Loop: owner-majordomo@kvack.org List-ID: On Fri, Jul 14, 2023 at 10:23=E2=80=AFAM Waiman Long w= rote: > > On 7/13/23 19:25, Ivan Babrou wrote: > > On Mon, Jul 10, 2023 at 5:44=E2=80=AFPM Waiman Long wrote: > >> On 7/10/23 19:21, Ivan Babrou wrote: > >>> On Wed, Jul 5, 2023 at 11:20=E2=80=AFPM Shakeel Butt wrote: > >>>> On Fri, Jun 30, 2023 at 04:22:28PM -0700, Ivan Babrou wrote: > >>>>> Hello, > >>>>> > >>>>> We're seeing CPU load issues with cgroup stats retrieval. I made a > >>>>> public gist with all the details, including the repro code (which > >>>>> unfortunately requires heavily loaded hardware) and some flamegraph= s: > >>>>> > >>>>> * https://gist.github.com/bobrik/5ba58fb75a48620a1965026ad30a0a13 > >>>>> > >>>>> I'll repeat the gist of that gist here. Our repro has the following > >>>>> output after a warm-up run: > >>>>> > >>>>> completed: 5.17s [manual / mem-stat + cpu-stat] > >>>>> completed: 5.59s [manual / cpu-stat + mem-stat] > >>>>> completed: 0.52s [manual / mem-stat] > >>>>> completed: 0.04s [manual / cpu-stat] > >>>>> > >>>>> The first two lines do effectively the following: > >>>>> > >>>>> for _ in $(seq 1 1000); do cat /sys/fs/cgroup/system.slice/memory.s= tat > >>>>> /sys/fs/cgroup/system.slice/cpu.stat > /dev/null > >>>>> > >>>>> The latter two are the same thing, but via two loops: > >>>>> > >>>>> for _ in $(seq 1 1000); do cat /sys/fs/cgroup/system.slice/cpu.stat= > > >>>>> /dev/null; done > >>>>> for _ in $(seq 1 1000); do cat /sys/fs/cgroup/system.slice/memory.s= tat > >>>>>> /dev/null; done > >>>>> As you might've noticed from the output, splitting the loop into tw= o > >>>>> makes the code run 10x faster. This isn't great, because most > >>>>> monitoring software likes to get all stats for one service before > >>>>> reading the stats for the next one, which maps to the slow and > >>>>> expensive way of doing this. > >>>>> > >>>>> We're running Linux v6.1 (the output is from v6.1.25) with no patch= es > >>>>> that touch the cgroup or mm subsystems, so you can assume vanilla > >>>>> kernel. > >>>>> > >>>>> From the flamegraph it just looks like rstat flushing takes longe= r. I > >>>>> used the following flags on an AMD EPYC 7642 system (our usual pick > >>>>> cpu-clock was blaming spinlock irqrestore, which was questionable): > >>>>> > >>>>> perf -e cycles -g --call-graph fp -F 999 -- /tmp/repro > >>>>> > >>>>> Naturally, there are two questions that arise: > >>>>> > >>>>> * Is this expected (I guess not, but good to be sure)? > >>>>> * What can we do to make this better? > >>>>> > >>>>> I am happy to try out patches or to do some tracing to help underst= and > >>>>> this better. > >>>> Hi Ivan, > >>>> > >>>> Thanks a lot, as always, for reporting this. This is not expected an= d > >>>> should be fixed. Is the issue easy to repro or some specific workloa= d or > >>>> high load/traffic is required? Can you repro this with the latest li= nus > >>>> tree? Also do you see any difference of root's cgroup.stat where thi= s > >>>> issue happens vs good state? > >>> I'm afraid there's no easy way to reproduce. We see it from time to > >>> time in different locations. The one that I was looking at for the > >>> initial email does not reproduce it anymore: > >> My understanding of mem-stat and cpu-stat is that they are independent > >> of each other. In theory, reading one shouldn't affect the performance > >> of reading the others. Since you are doing mem-stat and cpu-stat readi= ng > >> repetitively in a loop, it is likely that all the data are in the cach= e > >> most of the time resulting in very fast processing time. If it happens > >> that the specific memory location of mem-stat and cpu-stat data are su= ch > >> that reading one will cause the other data to be flushed out of the > >> cache and have to be re-read from memory again, you could see > >> significant performance regression. > >> > >> It is one of the possible causes, but I may be wrong. > > Do you think it's somewhat similar to how iterating a matrix in rows > > is faster than in columns due to sequential vs random memory reads? > > > > * https://stackoverflow.com/q/9936132 > > * https://en.wikipedia.org/wiki/Row-_and_column-major_order > > * https://en.wikipedia.org/wiki/Loop_interchange > > Yes, it is similar to what is being described in those articles. > > > > > > I've had a similar suspicion and it would be good to confirm whether > > it's that or something else. I can probably collect perf counters for > > different runs, but I'm not sure which ones I'll need. > > > > In a similar vein, if we could come up with a tracepoint that would > > tell us the amount of work done (or any other relevant metric that > > would help) during rstat flushing, I can certainly collect that > > information as well for every reading combination. > > The perf-c2c tool may be able to help. The data to look for is how often > the data is from caches vs direct memory load/store. It looks like c2c only works for the whole system, not individual treads. There's a lot of noise from the rest of the system.