From: "Paul E. McKenney" <paulmck@kernel.org>
To: "Joel Fernandes (Google)" <joel@joelfernandes.org>
Cc: linux-kernel@vger.kernel.org, Davidlohr Bueso <dave@stgolabs.net>,
Ingo Molnar <mingo@redhat.com>,
Josh Triplett <josh@joshtriplett.org>,
Lai Jiangshan <jiangshanlai@gmail.com>,
Marco Elver <elver@google.com>,
Mathieu Desnoyers <mathieu.desnoyers@efficios.com>,
rcu@vger.kernel.org, Steven Rostedt <rostedt@goodmis.org>,
"Uladzislau Rezki (Sony)" <urezki@gmail.com>
Subject: Re: [PATCH 3/7] rcu/trace: Add name of the source for gp_seq
Date: Thu, 18 Jun 2020 15:19:01 -0700 [thread overview]
Message-ID: <20200618221901.GZ2723@paulmck-ThinkPad-P72> (raw)
In-Reply-To: <20200618202955.4024-3-joel@joelfernandes.org>
On Thu, Jun 18, 2020 at 04:29:51PM -0400, Joel Fernandes (Google) wrote:
> The gp_seq value can come from either of rdp, rsp or rnp.
>
> Only the rsp is the global source of truth (most accurate GP info). The
> rnp can be off by ~1 and the rdp can be off by way more. Add some more
> context to traces to clarify where it comes from.
This would be better done in scripting that processes the trace messages.
I must pass on this one.
For future reference, the TPS() around strings is not optional. Without
it, trace messages from crash dumps are garbled, if I remember correctly.
Thanx, Paul
> Signed-off-by: Joel Fernandes (Google) <joel@joelfernandes.org>
> ---
> include/trace/events/rcu.h | 12 ++++++++----
> kernel/rcu/tree.c | 32 ++++++++++++++++----------------
> kernel/rcu/tree_plugin.h | 2 +-
> 3 files changed, 25 insertions(+), 21 deletions(-)
>
> diff --git a/include/trace/events/rcu.h b/include/trace/events/rcu.h
> index a6d49864dcc27..cb5363564f7ed 100644
> --- a/include/trace/events/rcu.h
> +++ b/include/trace/events/rcu.h
> @@ -68,24 +68,28 @@ TRACE_EVENT(rcu_utilization,
> */
> TRACE_EVENT_RCU(rcu_grace_period,
>
> - TP_PROTO(const char *rcuname, unsigned long gp_seq, const char *gpevent),
> + TP_PROTO(const char *rcuname, const char *gp_seq_src,
> + unsigned long gp_seq, const char *gpevent),
>
> - TP_ARGS(rcuname, gp_seq, gpevent),
> + TP_ARGS(rcuname, gp_seq_src, gp_seq, gpevent),
>
> TP_STRUCT__entry(
> __field(const char *, rcuname)
> + __field(const char *, gp_seq_src)
> __field(unsigned long, gp_seq)
> __field(const char *, gpevent)
> ),
>
> TP_fast_assign(
> __entry->rcuname = rcuname;
> + __entry->gp_seq_src = gp_seq_src;
> __entry->gp_seq = gp_seq;
> __entry->gpevent = gpevent;
> ),
>
> - TP_printk("%s %lu %s",
> - __entry->rcuname, __entry->gp_seq, __entry->gpevent)
> + TP_printk("%s %s_gp_seq=%lu %s",
> + __entry->rcuname, __entry->gp_seq_src,
> + __entry->gp_seq, __entry->gpevent)
> );
>
> /*
> diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c
> index c61af6a33fbfd..81df1b837dd9d 100644
> --- a/kernel/rcu/tree.c
> +++ b/kernel/rcu/tree.c
> @@ -1334,7 +1334,7 @@ static bool rcu_start_this_gp(struct rcu_node *rnp_start, struct rcu_data *rdp,
> trace_rcu_this_gp(rnp, rdp, gp_seq_req, TPS("NoGPkthread"));
> goto unlock_out;
> }
> - trace_rcu_grace_period(rcu_state.name, data_race(rcu_state.gp_seq), TPS("newreq"));
> + trace_rcu_grace_period(rcu_state.name, "rsp", data_race(rcu_state.gp_seq), TPS("newreq"));
> ret = true; /* Caller must wake GP kthread. */
> unlock_out:
> /* Push furthest requested GP to leaf node and rcu_data structure. */
> @@ -1437,9 +1437,9 @@ static bool rcu_accelerate_cbs(struct rcu_node *rnp, struct rcu_data *rdp)
>
> /* Trace depending on how much we were able to accelerate. */
> if (rcu_segcblist_restempty(&rdp->cblist, RCU_WAIT_TAIL))
> - trace_rcu_grace_period(rcu_state.name, rdp->gp_seq, TPS("AccWaitCB"));
> + trace_rcu_grace_period(rcu_state.name, "rdp", rdp->gp_seq, TPS("AccWaitCB"));
> else
> - trace_rcu_grace_period(rcu_state.name, rdp->gp_seq, TPS("AccReadyCB"));
> + trace_rcu_grace_period(rcu_state.name, "rdp", rdp->gp_seq, TPS("AccReadyCB"));
>
> /* Count CBs for tracing. */
> rcu_segcblist_countseq(&rdp->cblist, cbs, gps);
> @@ -1543,7 +1543,7 @@ static bool __note_gp_changes(struct rcu_node *rnp, struct rcu_data *rdp)
> if (!offloaded)
> ret = rcu_advance_cbs(rnp, rdp); /* Advance CBs. */
> rdp->core_needs_qs = false;
> - trace_rcu_grace_period(rcu_state.name, rdp->gp_seq, TPS("cpuend"));
> + trace_rcu_grace_period(rcu_state.name, "rdp", rdp->gp_seq, TPS("cpuend"));
> } else {
> if (!offloaded)
> ret = rcu_accelerate_cbs(rnp, rdp); /* Recent CBs. */
> @@ -1559,7 +1559,7 @@ static bool __note_gp_changes(struct rcu_node *rnp, struct rcu_data *rdp)
> * set up to detect a quiescent state, otherwise don't
> * go looking for one.
> */
> - trace_rcu_grace_period(rcu_state.name, rnp->gp_seq, TPS("cpustart"));
> + trace_rcu_grace_period(rcu_state.name, "rnp", rnp->gp_seq, TPS("cpustart"));
> need_qs = !!(rnp->qsmask & rdp->grpmask);
> rdp->cpu_no_qs.b.norm = need_qs;
> rdp->core_needs_qs = need_qs;
> @@ -1660,7 +1660,7 @@ static bool rcu_gp_init(void)
> /* Record GP times before starting GP, hence rcu_seq_start(). */
> rcu_seq_start(&rcu_state.gp_seq);
> ASSERT_EXCLUSIVE_WRITER(rcu_state.gp_seq);
> - trace_rcu_grace_period(rcu_state.name, rcu_state.gp_seq, TPS("start"));
> + trace_rcu_grace_period(rcu_state.name, "rsp", rcu_state.gp_seq, TPS("start"));
> raw_spin_unlock_irq_rcu_node(rnp);
>
> /*
> @@ -1828,7 +1828,7 @@ static void rcu_gp_fqs_loop(void)
> WRITE_ONCE(rcu_state.jiffies_kick_kthreads,
> jiffies + (j ? 3 * j : 2));
> }
> - trace_rcu_grace_period(rcu_state.name, rcu_state.gp_seq,
> + trace_rcu_grace_period(rcu_state.name, "rsp", rcu_state.gp_seq,
> TPS("fqswait"));
> rcu_state.gp_state = RCU_GP_WAIT_FQS;
> ret = swait_event_idle_timeout_exclusive(
> @@ -1843,7 +1843,7 @@ static void rcu_gp_fqs_loop(void)
> /* If time for quiescent-state forcing, do it. */
> if (!time_after(rcu_state.jiffies_force_qs, jiffies) ||
> (gf & RCU_GP_FLAG_FQS)) {
> - trace_rcu_grace_period(rcu_state.name, rcu_state.gp_seq,
> + trace_rcu_grace_period(rcu_state.name, "rsp", rcu_state.gp_seq,
> TPS("fqsstart"));
> rcu_gp_fqs(first_gp_fqs);
> gf = 0;
> @@ -1851,7 +1851,7 @@ static void rcu_gp_fqs_loop(void)
> first_gp_fqs = false;
> gf = rcu_state.cbovld ? RCU_GP_FLAG_OVLD : 0;
> }
> - trace_rcu_grace_period(rcu_state.name, rcu_state.gp_seq,
> + trace_rcu_grace_period(rcu_state.name, "rsp", rcu_state.gp_seq,
> TPS("fqsend"));
> cond_resched_tasks_rcu_qs();
> WRITE_ONCE(rcu_state.gp_activity, jiffies);
> @@ -1862,7 +1862,7 @@ static void rcu_gp_fqs_loop(void)
> cond_resched_tasks_rcu_qs();
> WRITE_ONCE(rcu_state.gp_activity, jiffies);
> WARN_ON(signal_pending(current));
> - trace_rcu_grace_period(rcu_state.name, rcu_state.gp_seq,
> + trace_rcu_grace_period(rcu_state.name, "rsp", rcu_state.gp_seq,
> TPS("fqswaitsig"));
> ret = 1; /* Keep old FQS timing. */
> j = jiffies;
> @@ -1945,7 +1945,7 @@ static void rcu_gp_cleanup(void)
> raw_spin_lock_irq_rcu_node(rnp); /* GP before ->gp_seq update. */
>
> /* Declare grace period done, trace first to use old GP number. */
> - trace_rcu_grace_period(rcu_state.name, rcu_state.gp_seq, TPS("end"));
> + trace_rcu_grace_period(rcu_state.name, "rsp", rcu_state.gp_seq, TPS("end"));
> rcu_seq_end(&rcu_state.gp_seq);
> ASSERT_EXCLUSIVE_WRITER(rcu_state.gp_seq);
> rcu_state.gp_state = RCU_GP_IDLE;
> @@ -1962,7 +1962,7 @@ static void rcu_gp_cleanup(void)
> if ((offloaded || !rcu_accelerate_cbs(rnp, rdp)) && needgp) {
> WRITE_ONCE(rcu_state.gp_flags, RCU_GP_FLAG_INIT);
> WRITE_ONCE(rcu_state.gp_req_activity, jiffies);
> - trace_rcu_grace_period(rcu_state.name,
> + trace_rcu_grace_period(rcu_state.name, "rsp",
> rcu_state.gp_seq,
> TPS("newreq"));
> } else {
> @@ -1982,7 +1982,7 @@ static int __noreturn rcu_gp_kthread(void *unused)
>
> /* Handle grace-period start. */
> for (;;) {
> - trace_rcu_grace_period(rcu_state.name, rcu_state.gp_seq,
> + trace_rcu_grace_period(rcu_state.name, "rsp", rcu_state.gp_seq,
> TPS("reqwait"));
> rcu_state.gp_state = RCU_GP_WAIT_GPS;
> swait_event_idle_exclusive(rcu_state.gp_wq,
> @@ -1996,7 +1996,7 @@ static int __noreturn rcu_gp_kthread(void *unused)
> cond_resched_tasks_rcu_qs();
> WRITE_ONCE(rcu_state.gp_activity, jiffies);
> WARN_ON(signal_pending(current));
> - trace_rcu_grace_period(rcu_state.name, rcu_state.gp_seq,
> + trace_rcu_grace_period(rcu_state.name, "rsp", rcu_state.gp_seq,
> TPS("reqwaitsig"));
> }
>
> @@ -2240,7 +2240,7 @@ int rcutree_dying_cpu(unsigned int cpu)
> return 0;
>
> blkd = !!(rnp->qsmask & rdp->grpmask);
> - trace_rcu_grace_period(rcu_state.name, READ_ONCE(rnp->gp_seq),
> + trace_rcu_grace_period(rcu_state.name, "rsp", READ_ONCE(rnp->gp_seq),
> blkd ? TPS("cpuofl") : TPS("cpuofl-bgp"));
> return 0;
> }
> @@ -3733,7 +3733,7 @@ int rcutree_prepare_cpu(unsigned int cpu)
> rdp->core_needs_qs = false;
> rdp->rcu_iw_pending = false;
> rdp->rcu_iw_gp_seq = rdp->gp_seq - 1;
> - trace_rcu_grace_period(rcu_state.name, rdp->gp_seq, TPS("cpuonl"));
> + trace_rcu_grace_period(rcu_state.name, "rdp", rdp->gp_seq, TPS("cpuonl"));
> raw_spin_unlock_irqrestore_rcu_node(rnp, flags);
> rcu_prepare_kthreads(cpu);
> rcu_spawn_cpu_nocb_kthread(cpu);
> diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h
> index 982fc5be52698..32f761cf16c33 100644
> --- a/kernel/rcu/tree_plugin.h
> +++ b/kernel/rcu/tree_plugin.h
> @@ -262,7 +262,7 @@ static void rcu_qs(void)
> {
> RCU_LOCKDEP_WARN(preemptible(), "rcu_qs() invoked with preemption enabled!!!\n");
> if (__this_cpu_read(rcu_data.cpu_no_qs.s)) {
> - trace_rcu_grace_period(TPS("rcu_preempt"),
> + trace_rcu_grace_period(TPS("rcu_preempt"), "rdp",
> __this_cpu_read(rcu_data.gp_seq),
> TPS("cpuqs"));
> __this_cpu_write(rcu_data.cpu_no_qs.b.norm, false);
> --
> 2.27.0.111.gc72c7da667-goog
>
next prev parent reply other threads:[~2020-06-18 22:19 UTC|newest]
Thread overview: 28+ messages / expand[flat|nested] mbox.gz Atom feed top
2020-06-18 20:29 [PATCH 1/7] rcu/segcblist: Prevent useless GP start if no CBs to accelerate Joel Fernandes (Google)
2020-06-18 20:29 ` [PATCH 2/7] rcu/trace: Add tracing for how segcb list changes Joel Fernandes (Google)
2020-06-18 22:16 ` Paul E. McKenney
2020-06-18 23:52 ` Joel Fernandes
2020-06-18 20:29 ` [PATCH 3/7] rcu/trace: Add name of the source for gp_seq Joel Fernandes (Google)
2020-06-18 22:19 ` Paul E. McKenney [this message]
2020-06-18 23:51 ` Joel Fernandes
2020-06-19 0:12 ` Paul E. McKenney
2020-06-19 0:56 ` Joel Fernandes
2020-06-19 1:08 ` Joel Fernandes
2020-06-19 0:01 ` Steven Rostedt
2020-06-19 1:01 ` Joel Fernandes
2020-06-18 20:29 ` [PATCH 4/7] rcu/trace: Print negative GP numbers correctly Joel Fernandes (Google)
2020-06-18 22:30 ` Paul E. McKenney
2020-06-18 20:29 ` [PATCH 5/7] rcu/trace: Use rsp's gp_seq in acceleration's rcu_grace_period tracepoint Joel Fernandes (Google)
2020-06-18 22:27 ` Paul E. McKenney
2020-06-18 23:54 ` Joel Fernandes
2020-06-18 20:29 ` [PATCH 6/7] rcutorture: Add support to get the number of wakeups of main GP kthread Joel Fernandes (Google)
2020-06-18 22:40 ` Paul E. McKenney
2020-06-19 0:01 ` Joel Fernandes
2020-06-19 0:12 ` Paul E. McKenney
2020-06-19 1:00 ` Joel Fernandes
2020-06-19 3:23 ` Paul E. McKenney
2020-06-18 20:29 ` [PATCH 7/7] rcutorture: Add number of GP information to reports Joel Fernandes (Google)
2020-06-18 23:27 ` Paul E. McKenney
2020-06-18 22:11 ` [PATCH 1/7] rcu/segcblist: Prevent useless GP start if no CBs to accelerate Paul E. McKenney
2020-06-18 23:09 ` Paul E. McKenney
2020-06-19 0:04 ` Joel Fernandes
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20200618221901.GZ2723@paulmck-ThinkPad-P72 \
--to=paulmck@kernel.org \
--cc=dave@stgolabs.net \
--cc=elver@google.com \
--cc=jiangshanlai@gmail.com \
--cc=joel@joelfernandes.org \
--cc=josh@joshtriplett.org \
--cc=linux-kernel@vger.kernel.org \
--cc=mathieu.desnoyers@efficios.com \
--cc=mingo@redhat.com \
--cc=rcu@vger.kernel.org \
--cc=rostedt@goodmis.org \
--cc=urezki@gmail.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox
all inboxes | Powered by JetHome®