linux-kernel - RE: [PATCH] rcu: Fix incorrect trace string in rcu_boost

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [day] [month] [year] [list]

Date:   Sun, 19 Mar 2023 02:03:43 +0000
From:   "Zhang, Qiang1" <qiang1.zhang@...el.com>
To:     Joel Fernandes <joel@...lfernandes.org>
CC:     "paulmck@...nel.org" <paulmck@...nel.org>,
        "frederic@...nel.org" <frederic@...nel.org>,
        "quic_neeraju@...cinc.com" <quic_neeraju@...cinc.com>,
        "rcu@...r.kernel.org" <rcu@...r.kernel.org>,
        "linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>,
        Steven Rostedt <rostedt@...dmis.org>
Subject: RE: [PATCH] rcu: Fix incorrect trace string in rcu_boost_kthread()

On Sat, Mar 18, 2023 at 9:20 AM Zqiang <qiang1.zhang@...el.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@...el.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@...t"));
>         for (;;) {
>                 WRITE_ONCE(rnp->boost_kthread_status, RCU_KTHREAD_WAITING);
> -               trace_rcu_utilization(TPS("End boost kthread@..._wait"));
> +               trace_rcu_utilization(TPS("Start boost kthread@..._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@..._wait"));
> +               trace_rcu_utilization(TPS("End boost kthread@..._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@...t"));

	for (;;) {
		trace_rcu_utilization(TPS("Start boost kthread@..._wait"));
		rcu_wait();
		trace_rcu_utilization(TPS("End boost kthread@..._wait"));

		rcu_boost()
		
		trace_rcu_utilization(TPS("Start boost kthread@..._yield"));
		schedule_timeout_idle(2);
		trace_rcu_utilization(TPS("End boost kthread@..._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@..._yield"));
> -                       schedule_timeout_idle(2);
>                         trace_rcu_utilization(TPS("Start boost kthread@..._yield"));
> +                       schedule_timeout_idle(2);
> +                       trace_rcu_utilization(TPS("End boost kthread@..._yield"));
>                         spincnt = 0;
>                 }
>         }
> --
> 2.25.1
>