| Message ID | 20230318132435.3671003-1-qiang1.zhang@intel.com |
|---|---|
| State | New |
| Headers |
Return-Path: <linux-kernel-owner@vger.kernel.org>
Delivered-To: ouuuleilei@gmail.com
Received: by 2002:a5d:604a:0:0:0:0:0 with SMTP id j10csp295501wrt;
Sat, 18 Mar 2023 06:43:33 -0700 (PDT)
X-Google-Smtp-Source:
AK7set9sukVmBZacq5UQClDZPJ21XaW4RlB7kRF5Z77XaGRiCEo+rz1rxXjKBzjr7Uj6rASN7aS5
X-Received: by 2002:a17:90b:380d:b0:23c:8ee2:bc14 with SMTP id
mq13-20020a17090b380d00b0023c8ee2bc14mr12598559pjb.24.1679147012820;
Sat, 18 Mar 2023 06:43:32 -0700 (PDT)
ARC-Seal: i=1; a=rsa-sha256; t=1679147012; cv=none;
d=google.com; s=arc-20160816;
b=LaG5UcXymvfNcMwqMK0Bxw2qTxV83v5C+uL4yuNzY7wu8921nkWyJYFf+oWM2S2hEO
s8XpFmqkjJRCbY9uegfWLcJcvccjY7dWkV05lEuBQP+zSYC+g1fr/ACPeKmtcXTHmT5B
avIbjUYR3n8gOxuj19JZdR5r9os+VOBrs2v9LSF/51BssdRlU+Ex4Wx/JdJ4JfWHTyTo
lcu9p1R24dnQgZXk4gcwvWjqR1wcIdtd/rQb2tOkP30xZe2Sf5IfXVYx6VSwfoQaD3WT
lstCyYDUjyNFHmUGDd4UsmFfZm4XKZk3pynySAygP4Tsc87wHY9Hm5MjgHkpBgVjKoFv
K0NQ==
ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com;
s=arc-20160816;
h=list-id:precedence:content-transfer-encoding:mime-version
:message-id:date:subject:cc:to:from:dkim-signature;
bh=Gs6XeJwHvjQI+hT4c/CCKftTDKK0P5mxkaWpzAEvsgg=;
b=Pwm0q+qUDgvFqOQ0DMzbeLYuT8fLb18SHgK1fkUWmeft9ZU7JflHqp0w8bWn6CzQY+
Ja4XnDRWZaqQHsAcPLOxhuC2ERudl+pUVlk8rrewwE7xhN0C98ffbYXsqVZz+dUKlWH5
tElBlLjwjLFKMR6hEh8eWE4YxKB/UgwzILtDEc7FvH0zBIgAw5iygQFiXrRYslpHh69q
gdVwteVXDkStpDpqE5R0eUEsbwCDsfsu+MsS1yYvYSJgS+qC3Xuem3DvMYtsEe2aC03e
FX6PNszaZZ8Ls4/RgTLkAyAfvU3wcAPNMBHXWQ8i7ZnOg6ec+VLgh1229Z0cqToeHNY2
Te5A==
ARC-Authentication-Results: i=1; mx.google.com;
dkim=pass header.i=@intel.com header.s=Intel header.b=C+YXQlIE;
spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org
designates 2620:137:e000::1:20 as permitted sender)
smtp.mailfrom=linux-kernel-owner@vger.kernel.org;
dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=intel.com
Received: from out1.vger.email (out1.vger.email. [2620:137:e000::1:20])
by mx.google.com with ESMTP id
pf17-20020a17090b1d9100b00228e80888c9si11955464pjb.14.2023.03.18.06.43.15;
Sat, 18 Mar 2023 06:43:32 -0700 (PDT)
Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org
designates 2620:137:e000::1:20 as permitted sender)
client-ip=2620:137:e000::1:20;
Authentication-Results: mx.google.com;
dkim=pass header.i=@intel.com header.s=Intel header.b=C+YXQlIE;
spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org
designates 2620:137:e000::1:20 as permitted sender)
smtp.mailfrom=linux-kernel-owner@vger.kernel.org;
dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=intel.com
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
id S229550AbjCRNUD (ORCPT <rfc822;pusanteemu@gmail.com> + 99 others);
Sat, 18 Mar 2023 09:20:03 -0400
Received: from lindbergh.monkeyblade.net ([23.128.96.19]:39846 "EHLO
lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
with ESMTP id S229502AbjCRNUB (ORCPT
<rfc822;linux-kernel@vger.kernel.org>);
Sat, 18 Mar 2023 09:20:01 -0400
Received: from mga05.intel.com (mga05.intel.com [192.55.52.43])
by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 4B53712BD8;
Sat, 18 Mar 2023 06:19:59 -0700 (PDT)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple;
d=intel.com; i=@intel.com; q=dns/txt; s=Intel;
t=1679145599; x=1710681599;
h=from:to:cc:subject:date:message-id:mime-version:
content-transfer-encoding;
bh=4yNcKM9zVdmfoXuxxRmQqn/SArvovMwG9AXxCmxyH8E=;
b=C+YXQlIE2reC6R2128NNrF+GoE7Z6vni1zb3Uak1+AQOdATrT88n/zmY
9XGib+e3nTGkIKZqYRGI//6ygZ/3Bh3OoyjGEemoNJvaJPU2wM7VSgllZ
39EiUI3iNCP2IyyNSJGL67NsgCcziwWBdyZQ/WjonBKKwbl6XJq+tnAef
rZpHp+UUjCjBVKtzsCCct48Wnh1Vxs8eK0XqQ+TtLs8WwrjSQhmT6UdMa
cKy1iY+8d6264QT62PaeQgBJL5tC9YhR8yiBuKehwhjfl1ofj1F2Cp8jf
OTAy0jnUa9nyq29QNpUvM372RCJFTrWkikUSYRfBSZjVdNfDt5N7x7idI
A==;
X-IronPort-AV: E=McAfee;i="6600,9927,10652"; a="424711112"
X-IronPort-AV: E=Sophos;i="5.98,271,1673942400";
d="scan'208";a="424711112"
Received: from fmsmga008.fm.intel.com ([10.253.24.58])
by fmsmga105.fm.intel.com with ESMTP/TLS/ECDHE-RSA-AES256-GCM-SHA384;
18 Mar 2023 06:19:59 -0700
X-ExtLoop1: 1
X-IronPort-AV: E=McAfee;i="6600,9927,10652"; a="744845455"
X-IronPort-AV: E=Sophos;i="5.98,271,1673942400";
d="scan'208";a="744845455"
Received: from zq-optiplex-7090.bj.intel.com ([10.238.156.129])
by fmsmga008-auth.fm.intel.com with ESMTP/TLS/ECDHE-RSA-AES256-GCM-SHA384;
18 Mar 2023 06:19:57 -0700
From: Zqiang <qiang1.zhang@intel.com>
To: paulmck@kernel.org, frederic@kernel.org, quic_neeraju@quicinc.com,
joel@joelfernandes.org
Cc: rcu@vger.kernel.org, linux-kernel@vger.kernel.org
Subject: [PATCH] rcu: Fix incorrect trace string in rcu_boost_kthread()
Date: Sat, 18 Mar 2023 21:24:35 +0800
Message-Id: <20230318132435.3671003-1-qiang1.zhang@intel.com>
X-Mailer: git-send-email 2.25.1
MIME-Version: 1.0
Content-Transfer-Encoding: 8bit
X-Spam-Status: No, score=-4.4 required=5.0 tests=BAYES_00,DKIMWL_WL_HIGH,
DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,RCVD_IN_DNSWL_MED,
SPF_HELO_NONE,SPF_NONE,URIBL_BLOCKED autolearn=ham autolearn_force=no
version=3.4.6
X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on
lindbergh.monkeyblade.net
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org
X-getmail-retrieved-from-mailbox: =?utf-8?q?INBOX?=
X-GMAIL-THRID: =?utf-8?q?1760713257905063784?=
X-GMAIL-MSGID: =?utf-8?q?1760713257905063784?=
|
| Series |
rcu: Fix incorrect trace string in rcu_boost_kthread()
|
|
Commit Message
Zqiang
March 18, 2023, 1:24 p.m. UTC
Currently, the trace string information before and after rcu_wait()
and schedule_timeout_idle() are reversed, this commit therefore
switches these strings in order to correctly trace.
Signed-off-by: Zqiang <qiang1.zhang@intel.com>
---
kernel/rcu/tree_plugin.h | 8 ++++----
1 file changed, 4 insertions(+), 4 deletions(-)
Comments
On Sat, Mar 18, 2023 at 9:20 AM Zqiang <qiang1.zhang@intel.com> wrote: > > Currently, the trace string information before and after rcu_wait() > and schedule_timeout_idle() are reversed, this commit therefore > switches these strings in order to correctly trace. I suggest provide more details of how this affects your tracing. One commit to draw inspiration from could be: f7f7bac9cb1c ("rcu: Have the RCU tracepoints use the tracepoint_string infrastructure") Which also modifies the same code. > > Signed-off-by: Zqiang <qiang1.zhang@intel.com> > --- > kernel/rcu/tree_plugin.h | 8 ++++---- > 1 file changed, 4 insertions(+), 4 deletions(-) > > diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h > index 7b0fe741a088..7b622b5196a8 100644 > --- a/kernel/rcu/tree_plugin.h > +++ b/kernel/rcu/tree_plugin.h > @@ -1114,10 +1114,10 @@ static int rcu_boost_kthread(void *arg) > trace_rcu_utilization(TPS("Start boost kthread@init")); > for (;;) { > WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_WAITING); > - trace_rcu_utilization(TPS("End boost kthread@rcu_wait")); > + trace_rcu_utilization(TPS("Start boost kthread@rcu_wait")); Doesn't that look weird because now you will have 2 "Start boost kthread@" messages in succession (one of them coming before the for loop) ? > rcu_wait(READ_ONCE(rnp->boost_tasks) || > READ_ONCE(rnp->exp_tasks)); > - trace_rcu_utilization(TPS("Start boost kthread@rcu_wait")); > + trace_rcu_utilization(TPS("End boost kthread@rcu_wait")); > WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_RUNNING); > more2boost = rcu_boost(rnp); Also, it is weird here that you are calling rcu_boost() right after printing "End boost kthread". thanks, - Joel > if (more2boost) > @@ -1126,9 +1126,9 @@ static int rcu_boost_kthread(void *arg) > spincnt = 0; > if (spincnt > 10) { > WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_YIELDING); > - trace_rcu_utilization(TPS("End boost kthread@rcu_yield")); > - schedule_timeout_idle(2); > trace_rcu_utilization(TPS("Start boost kthread@rcu_yield")); > + schedule_timeout_idle(2); > + trace_rcu_utilization(TPS("End boost kthread@rcu_yield")); > spincnt = 0; > } > } > -- > 2.25.1 >
> > Currently, the trace string information before and after rcu_wait() > and schedule_timeout_idle() are reversed, this commit therefore > switches these strings in order to correctly trace. > >I suggest provide more details of how this affects your tracing. One >commit to draw inspiration from could be: > >f7f7bac9cb1c ("rcu: Have the RCU tracepoints use the tracepoint_string >infrastructure") > >Which also modifies the same code. > > > Signed-off-by: Zqiang <qiang1.zhang@intel.com> > --- > kernel/rcu/tree_plugin.h | 8 ++++---- > 1 file changed, 4 insertions(+), 4 deletions(-) > > diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h > index 7b0fe741a088..7b622b5196a8 100644 > --- a/kernel/rcu/tree_plugin.h > +++ b/kernel/rcu/tree_plugin.h > @@ -1114,10 +1114,10 @@ static int rcu_boost_kthread(void *arg) > trace_rcu_utilization(TPS("Start boost kthread@init")); > for (;;) { > WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_WAITING); > - trace_rcu_utilization(TPS("End boost kthread@rcu_wait")); > + trace_rcu_utilization(TPS("Start boost kthread@rcu_wait")); Doesn't that look weird because now you will have 2 "Start boost kthread@" messages in succession (one of them coming before the for loop) ? > rcu_wait(READ_ONCE(rnp->boost_tasks) || > READ_ONCE(rnp->exp_tasks)); > - trace_rcu_utilization(TPS("Start boost kthread@rcu_wait")); > + trace_rcu_utilization(TPS("End boost kthread@rcu_wait")); > WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_RUNNING); > more2boost = rcu_boost(rnp); > >Also, it is weird here that you are calling rcu_boost() right after >printing "End boost kthread". > Hi Joel Shouldn't that be the normal logic? Or I misunderstood? trace_rcu_utilization(TPS("Start boost kthread@rcu_wait")); //start wait rcu_wait(); trace_rcu_utilization(TPS("End boost kthread@rcu_wait")); // end wait Thanks Zqiang >thanks, > >- Joel > > > > if (more2boost) > @@ -1126,9 +1126,9 @@ static int rcu_boost_kthread(void *arg) > spincnt = 0; > if (spincnt > 10) { > WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_YIELDING); > - trace_rcu_utilization(TPS("End boost kthread@rcu_yield")); > - schedule_timeout_idle(2); > trace_rcu_utilization(TPS("Start boost kthread@rcu_yield")); > + schedule_timeout_idle(2); > + trace_rcu_utilization(TPS("End boost kthread@rcu_yield")); > spincnt = 0; > } > } > -- > 2.25.1 >
On Sat, Mar 18, 2023 at 9:20 AM Zqiang <qiang1.zhang@intel.com> wrote: > > Currently, the trace string information before and after rcu_wait() > and schedule_timeout_idle() are reversed, this commit therefore > switches these strings in order to correctly trace. > >I suggest provide more details of how this affects your tracing. One >commit to draw inspiration from could be: > >f7f7bac9cb1c ("rcu: Have the RCU tracepoints use the tracepoint_string >infrastructure") > >Which also modifies the same code. > > > Signed-off-by: Zqiang <qiang1.zhang@intel.com> > --- > kernel/rcu/tree_plugin.h | 8 ++++---- > 1 file changed, 4 insertions(+), 4 deletions(-) > > diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h > index 7b0fe741a088..7b622b5196a8 100644 > --- a/kernel/rcu/tree_plugin.h > +++ b/kernel/rcu/tree_plugin.h > @@ -1114,10 +1114,10 @@ static int rcu_boost_kthread(void *arg) > trace_rcu_utilization(TPS("Start boost kthread@init")); > for (;;) { > WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_WAITING); > - trace_rcu_utilization(TPS("End boost kthread@rcu_wait")); > + trace_rcu_utilization(TPS("Start boost kthread@rcu_wait")); > >Doesn't that look weird because now you will have 2 "Start boost >kthread@" messages in succession (one of them coming before the for >loop) ? > > rcu_wait(READ_ONCE(rnp->boost_tasks) || > READ_ONCE(rnp->exp_tasks)); > - trace_rcu_utilization(TPS("Start boost kthread@rcu_wait")); > + trace_rcu_utilization(TPS("End boost kthread@rcu_wait")); > WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_RUNNING); > more2boost = rcu_boost(rnp); > >Also, it is weird here that you are calling rcu_boost() right after >printing "End boost kthread". The trace I understand should be like this: rcu_boost_kthread() { trace_rcu_utilization(TPS("Start boost kthread@init")); for (;;) { trace_rcu_utilization(TPS("Start boost kthread@rcu_wait")); rcu_wait(); trace_rcu_utilization(TPS("End boost kthread@rcu_wait")); rcu_boost() trace_rcu_utilization(TPS("Start boost kthread@rcu_yield")); schedule_timeout_idle(2); trace_rcu_utilization(TPS("End boost kthread@rcu_yield")); } } Thanks Zqiang > >thanks, > > - Joel > > > > if (more2boost) > @@ -1126,9 +1126,9 @@ static int rcu_boost_kthread(void *arg) > spincnt = 0; > if (spincnt > 10) { > WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_YIELDING); > - trace_rcu_utilization(TPS("End boost kthread@rcu_yield")); > - schedule_timeout_idle(2); > trace_rcu_utilization(TPS("Start boost kthread@rcu_yield")); > + schedule_timeout_idle(2); > + trace_rcu_utilization(TPS("End boost kthread@rcu_yield")); > spincnt = 0; > } > } > -- > 2.25.1 >
diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h index 7b0fe741a088..7b622b5196a8 100644 --- a/kernel/rcu/tree_plugin.h +++ b/kernel/rcu/tree_plugin.h @@ -1114,10 +1114,10 @@ static int rcu_boost_kthread(void *arg) trace_rcu_utilization(TPS("Start boost kthread@init")); for (;;) { WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_WAITING); - trace_rcu_utilization(TPS("End boost kthread@rcu_wait")); + trace_rcu_utilization(TPS("Start boost kthread@rcu_wait")); rcu_wait(READ_ONCE(rnp->boost_tasks) || READ_ONCE(rnp->exp_tasks)); - trace_rcu_utilization(TPS("Start boost kthread@rcu_wait")); + trace_rcu_utilization(TPS("End boost kthread@rcu_wait")); WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_RUNNING); more2boost = rcu_boost(rnp); if (more2boost) @@ -1126,9 +1126,9 @@ static int rcu_boost_kthread(void *arg) spincnt = 0; if (spincnt > 10) { WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_YIELDING); - trace_rcu_utilization(TPS("End boost kthread@rcu_yield")); - schedule_timeout_idle(2); trace_rcu_utilization(TPS("Start boost kthread@rcu_yield")); + schedule_timeout_idle(2); + trace_rcu_utilization(TPS("End boost kthread@rcu_yield")); spincnt = 0; } }