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 vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id AE152C4332F for ; Thu, 17 Nov 2022 02:03:28 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S233965AbiKQCD0 (ORCPT ); Wed, 16 Nov 2022 21:03:26 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50614 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229939AbiKQCDV (ORCPT ); Wed, 16 Nov 2022 21:03:21 -0500 Received: from szxga02-in.huawei.com (szxga02-in.huawei.com [45.249.212.188]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id F10956A745; Wed, 16 Nov 2022 18:03:19 -0800 (PST) Received: from dggpemm500022.china.huawei.com (unknown [172.30.72.54]) by szxga02-in.huawei.com (SkyGuard) with ESMTP id 4NCNV95hY7zRpNf; Thu, 17 Nov 2022 10:02:57 +0800 (CST) Received: from dggpemm500006.china.huawei.com (7.185.36.236) by dggpemm500022.china.huawei.com (7.185.36.162) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256) id 15.1.2375.31; Thu, 17 Nov 2022 10:03:18 +0800 Received: from [10.174.178.55] (10.174.178.55) by dggpemm500006.china.huawei.com (7.185.36.236) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256) id 15.1.2375.31; Thu, 17 Nov 2022 10:03:17 +0800 Subject: Re: [PATCH v7 5/6] doc: Document CONFIG_RCU_CPU_STALL_CPUTIME=y stall information To: Frederic Weisbecker CC: "Paul E . McKenney" , Neeraj Upadhyay , Josh Triplett , "Steven Rostedt" , Mathieu Desnoyers , Lai Jiangshan , Joel Fernandes , , , Robert Elliott References: <20221111130709.247-1-thunder.leizhen@huawei.com> <20221111130709.247-6-thunder.leizhen@huawei.com> <20221116225507.GA839220@lothringen> From: "Leizhen (ThunderTown)" Message-ID: <1d007125-9e1a-8018-d6b4-8838ecc1a873@huawei.com> Date: Thu, 17 Nov 2022 10:03:17 +0800 User-Agent: Mozilla/5.0 (Windows NT 10.0; WOW64; rv:60.0) Gecko/20100101 Thunderbird/60.7.0 MIME-Version: 1.0 In-Reply-To: <20221116225507.GA839220@lothringen> Content-Type: text/plain; charset="utf-8" Content-Language: en-US Content-Transfer-Encoding: 7bit X-Originating-IP: [10.174.178.55] X-ClientProxiedBy: dggems704-chm.china.huawei.com (10.3.19.181) To dggpemm500006.china.huawei.com (7.185.36.236) X-CFilter-Loop: Reflected Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On 2022/11/17 6:55, Frederic Weisbecker wrote: > On Fri, Nov 11, 2022 at 09:07:08PM +0800, Zhen Lei wrote: >> +1. A CPU looping with interrupts disabled.:: >> + >> + rcu: hardirqs softirqs csw/system >> + rcu: number: 0 0 0 >> +65;6003;1c rcu: cputime: 0 0 0 ==> 2500(ms) >> + >> + Because interrupts have been disabled throughout the measurement >> + interval, there are no interrupts and no context switches. >> + Furthermore, because CPU time consumption was measured using interrupt >> + handlers, the system CPU consumption is misleadingly measured as zero. >> + This scenario will normally also have "(0 ticks this GP)" printed on >> + this CPU's summary line. >> + >> +2. A CPU looping with bottom halves disabled. >> + >> + This is similar to the previous example, but with non-zero number of >> + and CPU time consumed by hard interrupts, along with non-zero CPU >> + time consumed by in-kernel execution.:: >> + >> + rcu: hardirqs softirqs csw/system >> + rcu: number: 624 0 0 >> + rcu: cputime: 49 0 2446 ==> 2500(ms) >> + >> + The fact that there are zero softirqs gives a hint that these were >> + disabled, perhaps via local_bh_disable(). It is of course possible >> + that there were no softirqs, perhaps because all events that would >> + result in softirq execution are confined to other CPUs. In this case, >> + the diagnosis should continue as shown in the next example. >> + >> +3. A CPU looping with preemption disabled. >> + >> + Here, only the number of context switches is zero.:: >> + >> + rcu: hardirqs softirqs csw/system >> + rcu: number: 624 45 0 >> + rcu: cputime: 69 1 2425 ==> 2500(ms) >> + >> + This situation hints that the stalled CPU was looping with preemption >> + disabled. >> + >> +4. No looping, but massive hard and soft interrupts.:: >> + >> + rcu: hardirqs softirqs csw/system >> + rcu: number: xx xx 0 >> + rcu: cputime: xx xx 0 ==> 2500(ms) >> + >> + Here, the number and CPU time of hard interrupts are all non-zero, >> + but the number of context switches and the in-kernel CPU time consumed >> + are zero. The number and cputime of soft interrupts will usually be >> + non-zero, but could be zero, for example, if the CPU was spinning >> + within a single hard interrupt handler. >> + >> + If this type of RCU CPU stall warning can be reproduced, you can >> + narrow it down by looking at /proc/interrupts or by writing code to >> + trace each interrupt, for example, by referring to show_interrupts(). > > One last question I have. Usually all these informations can be deduced by > just looking at the stacktrace that comes along an RCU stall report. So on > which kind of situation the stacktrace is not enough? Interrupt storm. > > Thanks. > . > -- Regards, Zhen Lei