| Message ID | 20230320024341.3956543-1-qiang1.zhang@intel.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | [v2] rcu: Fix some incorrect trace log in rcu_boost and rcuc kthreads | expand |
On Sun, Mar 19, 2023 at 10:39 PM Zqiang <qiang1.zhang@intel.com> wrote: > > In rcu_boost kthreads, before invoke rcu_wait(), the trace string > should mark "Start boost kthread@rcu_wait", after rcu_wait() end, > mark "End boost kthread@rcu_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@rcu_yield")); schedule_timeout_idle(2); trace_rcu_utilization(TPS("End CPU kthread@rcu_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@intel.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@rcu_wait")); > + trace_rcu_utilization(TPS("Start CPU kthread@rcu_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@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; > } > } > -- > 2.25.1 >
>On Sun, Mar 19, 2023 at 10:39 PM Zqiang <qiang1.zhang@intel.com> wrote: > > In rcu_boost kthreads, before invoke rcu_wait(), the trace string > should mark "Start boost kthread@rcu_wait", after rcu_wait() end, > mark "End boost kthread@rcu_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@rcu_yield")); >schedule_timeout_idle(2); >trace_rcu_utilization(TPS("End CPU kthread@rcu_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@intel.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@rcu_wait")); > + trace_rcu_utilization(TPS("Start CPU kthread@rcu_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@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")); 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@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; > } > } > -- > 2.25.1 >
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@rcu_wait")); + trace_rcu_utilization(TPS("Start CPU kthread@rcu_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@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; } }
In rcu_boost kthreads, before invoke rcu_wait(), the trace string should mark "Start boost kthread@rcu_wait", after rcu_wait() end, mark "End boost kthread@rcu_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". Signed-off-by: Zqiang <qiang1.zhang@intel.com> --- kernel/rcu/tree.c | 2 +- kernel/rcu/tree_plugin.h | 8 ++++---- 2 files changed, 5 insertions(+), 5 deletions(-)