linux-kernel - RE: [PATCH v2] rcu: Fix some incorrect trace log in rcu

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 linux-cve-announce 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]

Message-ID: <PH0PR11MB588000D59C94F8CF45E72FEDDA809@PH0PR11MB5880.namprd11.prod.outlook.com>
Date:   Mon, 20 Mar 2023 03:15:56 +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>,
        "rcu@...r.kernel.org" <rcu@...r.kernel.org>,
        "linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>
Subject: RE: [PATCH v2] rcu: Fix some incorrect trace log in rcu_boost and
 rcuc kthreads

>On Sun, Mar 19, 2023 at 10:39 PM Zqiang <qiang1.zhang@...el.com> wrote:
>
> In rcu_boost kthreads, before invoke rcu_wait(), the trace string
> should mark "Start boost kthread@..._wait", after rcu_wait() end,
> mark "End boost kthread@..._wait". for boost kthread enter idle
> state, the trace should also do same.
> In rcuc kthreads, when the rcu_cpu_has_work is set zero, indicates
> that there are no works to process, the rcuc kthreads will enter
> waiting state, so the trace string should mark "Start @rcu_wait".
>
>Nope. Unfortunately, in this hard to read change log, you are making
>the "Start @rcu_wait" up.
>
>The trace clearly says "Start boost kthread @...",
>
>So first of all, don't make things up please based on imagination. Let
>us go by the actual trace message precisely and not skip important
>words in it.
>
>Now, an interpretation of the trace might be , we print a "Start"
>whenever the thread is RUNNING and "End" whenever the thread is
>SLEEPING. That makes much more sense so the existing code for the
>boost kthread is already correct.
>
>However, I did notice this bit of code in tree.c might have been
>causing confusion:
>
>*statusp = RCU_KTHREAD_YIELDING;
>trace_rcu_utilization(TPS("Start CPU kthread@..._yield"));
>schedule_timeout_idle(2);
>trace_rcu_utilization(TPS("End CPU kthread@..._yield"));
>*statusp = RCU_KTHREAD_WAITING;
>
>So perhaps a proper fix might be - in this fragment the Start and End
>should be swapped instead.
>
>thanks,
>
> - Joel
>
>
>
> Signed-off-by: Zqiang <qiang1.zhang@...el.com>
> ---
>  kernel/rcu/tree.c        | 2 +-
>  kernel/rcu/tree_plugin.h | 8 ++++----
>  2 files changed, 5 insertions(+), 5 deletions(-)
>
> diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c
> index 734c252c1e80..c1915408796f 100644
> --- a/kernel/rcu/tree.c
> +++ b/kernel/rcu/tree.c
> @@ -2465,7 +2465,7 @@ static void rcu_cpu_kthread(unsigned int cpu)
>                         rcu_core();
>                 local_bh_enable();
>                 if (*workp == 0) {
> -                       trace_rcu_utilization(TPS("End CPU kthread@..._wait"));
> +                       trace_rcu_utilization(TPS("Start CPU kthread@..._wait"));
>                         *statusp = RCU_KTHREAD_WAITING;
>                         return;
>                 }
> 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"));

Hi Joel,

Sorry now I understand what you mean, the start you describe is for boost kthread, 
and the start I describe is for rcu_wait().  

Thanks
Zqiang


>                 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);
>                 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
>