rcu: Add event tracing for no-CBs CPUs' grace periods

Signed-off-by: Paul E. McKenney <paul.mckenney@linaro.org> Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>

rcu: Add event tracing for no-CBs CPUs' grace periods
Signed-off-by: Paul E. McKenney <paul.mckenney@linaro.org> Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
Paul E. McKenney · Paul E. McKenney
1 parent 21e7a60874
Showing 2 changed files with 85 additions and 0 deletions Side-by-side Diff
include/trace/events/rcu.h
kernel/rcutree_plugin.h
@@ -72,6 +72,58 @@
 );
  
 /*
+ * Tracepoint for no-callbacks grace-period events.  The caller should
+ * pull the data from the rcu_node structure, other than rcuname, which
+ * comes from the rcu_state structure, and event, which is one of the
+ * following:
+ *
+ * "Startleaf": Request a nocb grace period based on leaf-node data.
+ * "Startedleaf": Leaf-node start proved sufficient.
+ * "Startedleafroot": Leaf-node start proved sufficient after checking root.
+ * "Startedroot": Requested a nocb grace period based on root-node data.
+ * "StartWait": Start waiting for the requested grace period.
+ * "ResumeWait": Resume waiting after signal.
+ * "EndWait": Complete wait.
+ * "Cleanup": Clean up rcu_node structure after previous GP.
+ * "CleanupMore": Clean up, and another no-CB GP is needed.
+ */
+TRACE_EVENT(rcu_nocb_grace_period,
+
+	TP_PROTO(char *rcuname, unsigned long gpnum, unsigned long completed,
+		 unsigned long c, u8 level, int grplo, int grphi,
+		 char *gpevent),
+
+	TP_ARGS(rcuname, gpnum, completed, c, level, grplo, grphi, gpevent),
+
+	TP_STRUCT__entry(
+		__field(char *, rcuname)
+		__field(unsigned long, gpnum)
+		__field(unsigned long, completed)
+		__field(unsigned long, c)
+		__field(u8, level)
+		__field(int, grplo)
+		__field(int, grphi)
+		__field(char *, gpevent)
+	),
+
+	TP_fast_assign(
+		__entry->rcuname = rcuname;
+		__entry->gpnum = gpnum;
+		__entry->completed = completed;
+		__entry->c = c;
+		__entry->level = level;
+		__entry->grplo = grplo;
+		__entry->grphi = grphi;
+		__entry->gpevent = gpevent;
+	),
+
+	TP_printk("%s %lu %lu %lu %u %d %d %s",
+		  __entry->rcuname, __entry->gpnum, __entry->completed,
+		  __entry->c, __entry->level, __entry->grplo, __entry->grphi,
+		  __entry->gpevent)
+);
+
+/*
  * Tracepoint for grace-period-initialization events.  These are
  * distinguished by the type of RCU, the new grace-period number, the
  * rcu_node structure level, the starting and ending CPU covered by the
@@ -601,6 +653,9 @@
 #define trace_rcu_grace_period(rcuname, gpnum, gpevent) do { } while (0)
 #define trace_rcu_grace_period_init(rcuname, gpnum, level, grplo, grphi, \
 				    qsmask) do { } while (0)
+#define trace_rcu_nocb_grace_period(rcuname, gpnum, completed, c, \
+				    level, grplo, grphi, event) \
+				    do { } while (0)
 #define trace_rcu_preempt_task(rcuname, pid, gpnum) do { } while (0)
 #define trace_rcu_unlock_preempted_task(rcuname, gpnum, pid) do { } while (0)
 #define trace_rcu_quiescent_state_report(rcuname, gpnum, mask, qsmask, level, \
@@ -2201,6 +2201,9 @@
 	wake_up_all(&rnp->nocb_gp_wq[c & 0x1]);
 	rnp->n_nocb_gp_requests[c & 0x1] = 0;
 	needmore = rnp->n_nocb_gp_requests[(c + 1) & 0x1];
+	trace_rcu_nocb_grace_period(rsp->name, rnp->gpnum, rnp->completed,
+				    c, rnp->level, rnp->grplo, rnp->grphi,
+				    needmore ? "CleanupMore" : "Cleanup");
 	return needmore;
 }
  
@@ -2347,6 +2350,9 @@
  
 	/* Count our request for a grace period. */
 	rnp->n_nocb_gp_requests[c & 0x1]++;
+	trace_rcu_nocb_grace_period(rdp->rsp->name, rnp->gpnum, rnp->completed,
+				    c, rnp->level, rnp->grplo, rnp->grphi,
+				    "Startleaf");
  
 	if (rnp->gpnum != rnp->completed) {
  
@@ -2355,6 +2361,10 @@
 		 * is in progress, so we are done.  When this grace
 		 * period ends, our request will be acted upon.
 		 */
+		trace_rcu_nocb_grace_period(rdp->rsp->name,
+					    rnp->gpnum, rnp->completed, c,
+					    rnp->level, rnp->grplo, rnp->grphi,
+					    "Startedleaf");
 		raw_spin_unlock_irqrestore(&rnp->lock, flags);
  
 	} else {
@@ -2366,6 +2376,11 @@
 		if (rnp != rnp_root)
 			raw_spin_lock(&rnp_root->lock); /* irqs disabled. */
 		if (rnp_root->gpnum != rnp_root->completed) {
+			trace_rcu_nocb_grace_period(rdp->rsp->name,
+						    rnp->gpnum, rnp->completed,
+						    c, rnp->level,
+						    rnp->grplo, rnp->grphi,
+						    "Startedleafroot");
 			raw_spin_unlock(&rnp_root->lock); /* irqs disabled. */
 		} else {
  
@@ -2381,6 +2396,11 @@
 			c = rnp_root->completed + 1;
 			rnp->n_nocb_gp_requests[c & 0x1]++;
 			rnp_root->n_nocb_gp_requests[c & 0x1]++;
+			trace_rcu_nocb_grace_period(rdp->rsp->name,
+						    rnp->gpnum, rnp->completed,
+						    c, rnp->level,
+						    rnp->grplo, rnp->grphi,
+						    "Startedroot");
 			local_save_flags(flags1);
 			rcu_start_gp(rdp->rsp, flags1); /* Rlses ->lock. */
 		}
@@ -2396,6 +2416,9 @@
 	 * Wait for the grace period.  Do so interruptibly to avoid messing
 	 * up the load average.
 	 */
+	trace_rcu_nocb_grace_period(rdp->rsp->name, rnp->gpnum, rnp->completed,
+				    c, rnp->level, rnp->grplo, rnp->grphi,
+				    "StartWait");
 	for (;;) {
 		wait_event_interruptible(
 			rnp->nocb_gp_wq[c & 0x1],
  
@@ -2403,7 +2426,14 @@
 		if (likely(d))
 			break;
 		flush_signals(current);
+		trace_rcu_nocb_grace_period(rdp->rsp->name,
+					    rnp->gpnum, rnp->completed, c,
+					    rnp->level, rnp->grplo, rnp->grphi,
+					    "ResumeWait");
 	}
+	trace_rcu_nocb_grace_period(rdp->rsp->name, rnp->gpnum, rnp->completed,
+				    c, rnp->level, rnp->grplo, rnp->grphi,
+				    "EndWait");
 	smp_mb(); /* Ensure that CB invocation happens after GP end. */
 }
...	...	@@ -72,6 +72,58 @@
72	72	);
73	73
74	74	/*
	75	+ * Tracepoint for no-callbacks grace-period events. The caller should
	76	+ * pull the data from the rcu_node structure, other than rcuname, which
	77	+ * comes from the rcu_state structure, and event, which is one of the
	78	+ * following:
	79	+ *
	80	+ * "Startleaf": Request a nocb grace period based on leaf-node data.
	81	+ * "Startedleaf": Leaf-node start proved sufficient.
	82	+ * "Startedleafroot": Leaf-node start proved sufficient after checking root.
	83	+ * "Startedroot": Requested a nocb grace period based on root-node data.
	84	+ * "StartWait": Start waiting for the requested grace period.
	85	+ * "ResumeWait": Resume waiting after signal.
	86	+ * "EndWait": Complete wait.
	87	+ * "Cleanup": Clean up rcu_node structure after previous GP.
	88	+ * "CleanupMore": Clean up, and another no-CB GP is needed.
	89	+ */
	90	+TRACE_EVENT(rcu_nocb_grace_period,
	91	+
	92	+ TP_PROTO(char *rcuname, unsigned long gpnum, unsigned long completed,
	93	+ unsigned long c, u8 level, int grplo, int grphi,
	94	+ char *gpevent),
	95	+
	96	+ TP_ARGS(rcuname, gpnum, completed, c, level, grplo, grphi, gpevent),
	97	+
	98	+ TP_STRUCT__entry(
	99	+ __field(char *, rcuname)
	100	+ __field(unsigned long, gpnum)
	101	+ __field(unsigned long, completed)
	102	+ __field(unsigned long, c)
	103	+ __field(u8, level)
	104	+ __field(int, grplo)
	105	+ __field(int, grphi)
	106	+ __field(char *, gpevent)
	107	+ ),
	108	+
	109	+ TP_fast_assign(
	110	+ __entry->rcuname = rcuname;
	111	+ __entry->gpnum = gpnum;
	112	+ __entry->completed = completed;
	113	+ __entry->c = c;
	114	+ __entry->level = level;
	115	+ __entry->grplo = grplo;
	116	+ __entry->grphi = grphi;
	117	+ __entry->gpevent = gpevent;
	118	+ ),
	119	+
	120	+ TP_printk("%s %lu %lu %lu %u %d %d %s",
	121	+ __entry->rcuname, __entry->gpnum, __entry->completed,
	122	+ __entry->c, __entry->level, __entry->grplo, __entry->grphi,
	123	+ __entry->gpevent)
	124	+);
	125	+
	126	+/*
75	127	* Tracepoint for grace-period-initialization events. These are
76	128	* distinguished by the type of RCU, the new grace-period number, the
77	129	* rcu_node structure level, the starting and ending CPU covered by the
...	...	@@ -601,6 +653,9 @@
601	653	#define trace_rcu_grace_period(rcuname, gpnum, gpevent) do { } while (0)
602	654	#define trace_rcu_grace_period_init(rcuname, gpnum, level, grplo, grphi, \
603	655	qsmask) do { } while (0)
	656	+#define trace_rcu_nocb_grace_period(rcuname, gpnum, completed, c, \
	657	+ level, grplo, grphi, event) \
	658	+ do { } while (0)
604	659	#define trace_rcu_preempt_task(rcuname, pid, gpnum) do { } while (0)
605	660	#define trace_rcu_unlock_preempted_task(rcuname, gpnum, pid) do { } while (0)
606	661	#define trace_rcu_quiescent_state_report(rcuname, gpnum, mask, qsmask, level, \
...	...	@@ -2201,6 +2201,9 @@
2201	2201	wake_up_all(&rnp->nocb_gp_wq[c & 0x1]);
2202	2202	rnp->n_nocb_gp_requests[c & 0x1] = 0;
2203	2203	needmore = rnp->n_nocb_gp_requests[(c + 1) & 0x1];
	2204	+ trace_rcu_nocb_grace_period(rsp->name, rnp->gpnum, rnp->completed,
	2205	+ c, rnp->level, rnp->grplo, rnp->grphi,
	2206	+ needmore ? "CleanupMore" : "Cleanup");
2204	2207	return needmore;
2205	2208	}
2206	2209
...	...	@@ -2347,6 +2350,9 @@
2347	2350
2348	2351	/* Count our request for a grace period. */
2349	2352	rnp->n_nocb_gp_requests[c & 0x1]++;
	2353	+ trace_rcu_nocb_grace_period(rdp->rsp->name, rnp->gpnum, rnp->completed,
	2354	+ c, rnp->level, rnp->grplo, rnp->grphi,
	2355	+ "Startleaf");
2350	2356
2351	2357	if (rnp->gpnum != rnp->completed) {
2352	2358
...	...	@@ -2355,6 +2361,10 @@
2355	2361	* is in progress, so we are done. When this grace
2356	2362	* period ends, our request will be acted upon.
2357	2363	*/
	2364	+ trace_rcu_nocb_grace_period(rdp->rsp->name,
	2365	+ rnp->gpnum, rnp->completed, c,
	2366	+ rnp->level, rnp->grplo, rnp->grphi,
	2367	+ "Startedleaf");
2358	2368	raw_spin_unlock_irqrestore(&rnp->lock, flags);
2359	2369
2360	2370	} else {
...	...	@@ -2366,6 +2376,11 @@
2366	2376	if (rnp != rnp_root)
2367	2377	raw_spin_lock(&rnp_root->lock); /* irqs disabled. */
2368	2378	if (rnp_root->gpnum != rnp_root->completed) {
	2379	+ trace_rcu_nocb_grace_period(rdp->rsp->name,
	2380	+ rnp->gpnum, rnp->completed,
	2381	+ c, rnp->level,
	2382	+ rnp->grplo, rnp->grphi,
	2383	+ "Startedleafroot");
2369	2384	raw_spin_unlock(&rnp_root->lock); /* irqs disabled. */
2370	2385	} else {
2371	2386
...	...	@@ -2381,6 +2396,11 @@
2381	2396	c = rnp_root->completed + 1;
2382	2397	rnp->n_nocb_gp_requests[c & 0x1]++;
2383	2398	rnp_root->n_nocb_gp_requests[c & 0x1]++;
	2399	+ trace_rcu_nocb_grace_period(rdp->rsp->name,
	2400	+ rnp->gpnum, rnp->completed,
	2401	+ c, rnp->level,
	2402	+ rnp->grplo, rnp->grphi,
	2403	+ "Startedroot");
2384	2404	local_save_flags(flags1);
2385	2405	rcu_start_gp(rdp->rsp, flags1); /* Rlses ->lock. */
2386	2406	}
...	...	@@ -2396,6 +2416,9 @@
2396	2416	* Wait for the grace period. Do so interruptibly to avoid messing
2397	2417	* up the load average.
2398	2418	*/
	2419	+ trace_rcu_nocb_grace_period(rdp->rsp->name, rnp->gpnum, rnp->completed,
	2420	+ c, rnp->level, rnp->grplo, rnp->grphi,
	2421	+ "StartWait");
2399	2422	for (;;) {
2400	2423	wait_event_interruptible(
2401	2424	rnp->nocb_gp_wq[c & 0x1],
2402	2425
...	...	@@ -2403,7 +2426,14 @@
2403	2426	if (likely(d))
2404	2427	break;
2405	2428	flush_signals(current);
	2429	+ trace_rcu_nocb_grace_period(rdp->rsp->name,
	2430	+ rnp->gpnum, rnp->completed, c,
	2431	+ rnp->level, rnp->grplo, rnp->grphi,
	2432	+ "ResumeWait");
2406	2433	}
	2434	+ trace_rcu_nocb_grace_period(rdp->rsp->name, rnp->gpnum, rnp->completed,
	2435	+ c, rnp->level, rnp->grplo, rnp->grphi,
	2436	+ "EndWait");
2407	2437	smp_mb(); /* Ensure that CB invocation happens after GP end. */
2408	2438	}
2409	2439