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 0E45DEB64DC for ; Fri, 14 Jul 2023 17:23:51 +0000 (UTC) Received: by kanga.kvack.org (Postfix) id 43D808E0007; Fri, 14 Jul 2023 13:23:51 -0400 (EDT) Received: by kanga.kvack.org (Postfix, from userid 40) id 3EBC98E0006; Fri, 14 Jul 2023 13:23:51 -0400 (EDT) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id 2B3578E0007; Fri, 14 Jul 2023 13:23:51 -0400 (EDT) X-Delivered-To: linux-mm@kvack.org Received: from relay.hostedemail.com (smtprelay0014.hostedemail.com [216.40.44.14]) by kanga.kvack.org (Postfix) with ESMTP id 18A6D8E0006 for ; Fri, 14 Jul 2023 13:23:51 -0400 (EDT) Received: from smtpin02.hostedemail.com (a10.router.float.18 [10.200.18.1]) by unirelay04.hostedemail.com (Postfix) with ESMTP id C41C51A02E6 for ; Fri, 14 Jul 2023 17:23:50 +0000 (UTC) X-FDA: 81010889820.02.D34AE87 Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.133.124]) by imf12.hostedemail.com (Postfix) with ESMTP id BC71740011 for ; Fri, 14 Jul 2023 17:23:48 +0000 (UTC) Authentication-Results: imf12.hostedemail.com; dkim=pass header.d=redhat.com header.s=mimecast20190719 header.b=G7EHlYsN; dmarc=pass (policy=none) header.from=redhat.com; spf=pass (imf12.hostedemail.com: domain of longman@redhat.com designates 170.10.133.124 as permitted sender) smtp.mailfrom=longman@redhat.com ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=hostedemail.com; s=arc-20220608; t=1689355428; 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=IjSCUEVQqiObQodmnZyPQvDEZ31gPn7XJ/bLLSzzo2c=; b=tvxWtU7NVIdHUYboYvvWlHKNBdfQC6EfVbXC8kqCX3zyD6pLFAVb1jzGhHbb8COMID97Tu exw5UxzSvstqvHqWcRWDPcxBwElYchjGRS3O07IMniZwMUBEgJqd8Rm589KL6tmnL1Pztz Az54hsvHOGwVhKk0C47D7A3YiTXTQ9o= ARC-Authentication-Results: i=1; imf12.hostedemail.com; dkim=pass header.d=redhat.com header.s=mimecast20190719 header.b=G7EHlYsN; dmarc=pass (policy=none) header.from=redhat.com; spf=pass (imf12.hostedemail.com: domain of longman@redhat.com designates 170.10.133.124 as permitted sender) smtp.mailfrom=longman@redhat.com ARC-Seal: i=1; s=arc-20220608; d=hostedemail.com; t=1689355428; a=rsa-sha256; cv=none; b=1h/KWkzgxf+VFyfBAFya3S4ZyxUR6B+p/2LnIKj19kGn/khry9COZdDwZiXywgvtQJ5URY w5gS+ogJmhnF4vvuV8+i1uMECWpjZ2RjqotQBYbNpW8JlzJjsrSDwX+3FJytf/JEqATfGH MIvtsy8ko/HPymK16n5i8rPOyMa+V/U= DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1689355428; h=from:from: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; bh=IjSCUEVQqiObQodmnZyPQvDEZ31gPn7XJ/bLLSzzo2c=; b=G7EHlYsN9BxuOKBhudcioQVvtVk46H0MzLZGw6w7hoE5FhlJvFM2WRR5q99DQAG1H9PG2K fPYuG2YwRsLY+lMZKD0ViW+8HiyB+X2pz1zir2PSJdq7X0S0lI9r/RjZ/3rfrxWs7hlkG+ OsEiIixGVrDXb+Gd1x1qkDfndnlzz7M= Received: from mimecast-mx02.redhat.com (mimecast-mx02.redhat.com [66.187.233.88]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-250-1q70EXljPLGuQ4wmDRDicA-1; Fri, 14 Jul 2023 13:23:44 -0400 X-MC-Unique: 1q70EXljPLGuQ4wmDRDicA-1 Received: from smtp.corp.redhat.com (int-mx08.intmail.prod.int.rdu2.redhat.com [10.11.54.8]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mimecast-mx02.redhat.com (Postfix) with ESMTPS id E4614185A78F; Fri, 14 Jul 2023 17:23:43 +0000 (UTC) Received: from [10.22.9.81] (unknown [10.22.9.81]) by smtp.corp.redhat.com (Postfix) with ESMTP id 35CD5C2C856; Fri, 14 Jul 2023 17:23:43 +0000 (UTC) Message-ID: Date: Fri, 14 Jul 2023 13:23:42 -0400 MIME-Version: 1.0 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101 Thunderbird/102.7.1 Subject: Re: Expensive memory.stat + cpu.stat reads Content-Language: en-US To: Ivan Babrou Cc: Shakeel Butt , cgroups@vger.kernel.org, Linux MM , kernel-team , Johannes Weiner , Michal Hocko , Roman Gushchin , Muchun Song , Andrew Morton , linux-kernel References: <20230706062045.xwmwns7cm4fxd7iu@google.com> From: Waiman Long In-Reply-To: Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8bit X-Scanned-By: MIMEDefang 3.1 on 10.11.54.8 X-Rspamd-Server: rspam09 X-Rspamd-Queue-Id: BC71740011 X-Stat-Signature: 3ai6x1im6p9sjq5c859mhmaxhkrk8y3g X-Rspam-User: X-HE-Tag: 1689355428-527668 X-HE-Meta: U2FsdGVkX19NKogxlkOQEArwOiKHG1mb+4hF1DvwG2V3jBdFKllCb3xoQdkuHkldI54fgtwXf6UT/FvGOgyvwi3TUtr/aDAr4eKSoChZzyN7cPyesUBNRIBQUEGdNTRt/7WQRfvSf3PbCLswuui0OxkXxba7yCx6V2+UoPBtCNY4rqctDem3UjuPjN4LihVV4AvuCSfH4Zo2Q2GVbeVhG3hSwNv1LFf5rofzz0RbQF+TNdmRXfXpd06AWZfRx6zypQSYrVkUvzBqSop9lgsLeH6/RK/86/G7ol2SDv2jOHvfrhlUNfiVIcCg6rvK7vVYGr/9pWwwgh3hC7S7iCxXBuuNNlaWD0sbbgIeRxudzsp354XH4CkL6kBRN0PPCkB8Slc91zKSw9qy/Dq3qNI9Nsi2gYLb/1wTWSPAVf1tOe2N5SGG9ltRNuq5AQ/mjvCJpraKYTvqoKLQxX6xdmO6QNjR9QgTMOK/CF2W8LWt3GXJxLefP0ywVAm0broByI8h//wc/V/RGOXE0lgTLG5QCCSb2MQ8l9R7xb/ZWu1qtMZCt6BfPzO3sXLc6dubLWmi26FBzXU8YVKoP2r2pjCHBu3Wf0a2YAgkozmpYP7VU9MHgona8mosYvfOpnyCtYok19Fgepl/8/w4EKh0+aVP8WcCQglv4R0lQH+1GqpAA5pBmfbu/ysZENVJ3ZY62zRCisbgIRgNI6e3W6PXiQnAVWNMvRdl2P9/PLXPV7FMHVj1N+WcwUcp8FFrbX0uWvnVWSXfZeR/R8qdaDBxJ9ysuh98fc1CNWNOEvbadUh5G3EP+fly1VzMpgPz/iBxQ12mzY4Ii2t2N8ip8z6lKa9Hal33B5W0j1w/SRHhFMV4SFX25uWWzQoZRCwmbV+xaE8iPGOH2Y/JPDOqo36eretH3RKC4uIc+U7DA5KJlZvIyVtEjOKyhB/m6R5T2wTyiQe+uQshWNCkZrIZgMvESj4 jNlwoQAk mNwEZqbW5bNYkk9xFWSSMmyywrDWW9U4y5fgyRFFUPaqJ+OWkxj4ZmGirfCA3bxPp/03YHCYO+w2cmN7Nd1vBag+G5nXaKIYItirlUdqz9zCvYsb2jONrUphlhDD8GxE02j3C6OqO+FqyYBxs8yt8N9AXFCobz0vhPbzeHz6J3kpD1vZNnMRaZqDsqLzIwr/iyYNjQ8sFOWAfuPeQArAc3t0bwd5/z87HnG5B7gT79kmuyJk/co6IQdvG+N3U1kQvO8gC7T1v0ell7KlwvnZ7Y72M0Q== 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 7/13/23 19:25, Ivan Babrou wrote: > On Mon, Jul 10, 2023 at 5:44 PM Waiman Long wrote: >> On 7/10/23 19:21, Ivan Babrou wrote: >>> On Wed, Jul 5, 2023 at 11:20 PM 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 flamegraphs: >>>>> >>>>> * 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.stat >>>>> /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.stat >>>>>> /dev/null; done >>>>> As you might've noticed from the output, splitting the loop into two >>>>> 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 patches >>>>> that touch the cgroup or mm subsystems, so you can assume vanilla >>>>> kernel. >>>>> >>>>> From the flamegraph it just looks like rstat flushing takes longer. 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 understand >>>>> this better. >>>> Hi Ivan, >>>> >>>> Thanks a lot, as always, for reporting this. This is not expected and >>>> should be fixed. Is the issue easy to repro or some specific workload or >>>> high load/traffic is required? Can you repro this with the latest linus >>>> tree? Also do you see any difference of root's cgroup.stat where this >>>> 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 reading >> repetitively in a loop, it is likely that all the data are in the cache >> 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 such >> 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. Cheers, Longman