rcu: Add tracing to rcu_gp_kthread()

This commit adds tracing to the rcu_gp_kthread() function in order to
help trace down hangs potentially involving this kthread.

Reported-by: Clark Williams <williams@redhat.com>
Reported-by: Carsten Emde <C.Emde@osadl.org>
Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>

2 files changed, 37 insertions, 9 deletions

diff --git a/include/trace/events/rcu.h b/include/trace/events/rcu.h
index ee2376cfaab3..60077e12093c 100644
--- a/include/trace/events/rcu.h
+++ b/include/trace/events/rcu.h
@@ -39,15 +39,25 @@ TRACE_EVENT(rcu_utilization,
 #if defined(CONFIG_TREE_RCU) || defined(CONFIG_TREE_PREEMPT_RCU)
 
 /*
- * Tracepoint for grace-period events: starting and ending a grace
- * period ("start" and "end", respectively), a CPU noting the start
- * of a new grace period or the end of an old grace period ("cpustart"
- * and "cpuend", respectively), a CPU passing through a quiescent
- * state ("cpuqs"), a CPU coming online or going offline ("cpuonl"
- * and "cpuofl", respectively), a CPU being kicked for being too
- * long in dyntick-idle mode ("kick"), a CPU accelerating its new
- * callbacks to RCU_NEXT_READY_TAIL ("AccReadyCB"), and a CPU
- * accelerating its new callbacks to RCU_WAIT_TAIL ("AccWaitCB").
+ * Tracepoint for grace-period events.  Takes a string identifying the
+ * RCU flavor, the grace-period number, and a string identifying the
+ * grace-period-related event as follows:
+ *
+ *      "AccReadyCB": CPU acclerates new callbacks to RCU_NEXT_READY_TAIL.
+ *      "AccWaitCB": CPU accelerates new callbacks to RCU_WAIT_TAIL.
+ *      "start": Start a grace period.
+ *      "cpustart": CPU first notices a grace-period start.
+ *      "cpuqs": CPU passes through a quiescent state.
+ *      "cpuonl": CPU comes online.
+ *      "cpuofl": CPU goes offline.
+ *      "reqwait": GP kthread sleeps waiting for grace-period request.
+ *      "reqwaitsig": GP kthread awakened by signal from reqwait state.
+ *      "fqswait": GP kthread waiting until time to force quiescent states.
+ *      "fqsstart": GP kthread starts forcing quiescent states.
+ *      "fqsend": GP kthread done forcing quiescent states.
+ *      "fqswaitsig": GP kthread awakened by signal from fqswait state.
+ *      "end": End a grace period.
+ *      "cpuend": CPU first notices a grace-period end.
  */
 TRACE_EVENT(rcu_grace_period,
 
diff --git a/kernel/rcutree.c b/kernel/rcutree.c
index 6d028fdbf86c..78d371526667 100644
--- a/kernel/rcutree.c
+++ b/kernel/rcutree.c
@@ -1480,6 +1480,9 @@ static int __noreturn rcu_gp_kthread(void *arg)
 
                 /* Handle grace-period start. */
                 for (;;) {
+                        trace_rcu_grace_period(rsp->name,
+                                               ACCESS_ONCE(rsp->gpnum),
+                                               TPS("reqwait"));
                         wait_event_interruptible(rsp->gp_wq,
                                                  ACCESS_ONCE(rsp->gp_flags) &
                                                  RCU_GP_FLAG_INIT);
@@ -1487,6 +1490,9 @@ static int __noreturn rcu_gp_kthread(void *arg)
                                 break;
                         cond_resched();
                         flush_signals(current);
+                        trace_rcu_grace_period(rsp->name,
+                                               ACCESS_ONCE(rsp->gpnum),
+                                               TPS("reqwaitsig"));
                 }
 
                 /* Handle quiescent-state forcing. */
@@ -1500,6 +1506,9 @@ static int __noreturn rcu_gp_kthread(void *arg)
                 for (;;) {
                         if (!ret)
                                 rsp->jiffies_force_qs = jiffies + j;
+                        trace_rcu_grace_period(rsp->name,
+                                               ACCESS_ONCE(rsp->gpnum),
+                                               TPS("fqswait"));
                         ret = wait_event_interruptible_timeout(rsp->gp_wq,
                                         ((gf = ACCESS_ONCE(rsp->gp_flags)) &
                                          RCU_GP_FLAG_FQS) ||
@@ -1513,12 +1522,21 @@ static int __noreturn rcu_gp_kthread(void *arg)
                         /* If time for quiescent-state forcing, do it. */
                         if (ULONG_CMP_GE(jiffies, rsp->jiffies_force_qs) ||
                             (gf & RCU_GP_FLAG_FQS)) {
+                                trace_rcu_grace_period(rsp->name,
+                                                       ACCESS_ONCE(rsp->gpnum),
+                                                       TPS("fqsstart"));
                                 fqs_state = rcu_gp_fqs(rsp, fqs_state);
+                                trace_rcu_grace_period(rsp->name,
+                                                       ACCESS_ONCE(rsp->gpnum),
+                                                       TPS("fqsend"));
                                 cond_resched();
                         } else {
                                 /* Deal with stray signal. */
                                 cond_resched();
                                 flush_signals(current);
+                                trace_rcu_grace_period(rsp->name,
+                                                       ACCESS_ONCE(rsp->gpnum),
+                                                       TPS("fqswaitsig"));
                         }
                         j = jiffies_till_next_fqs;
                         if (j > HZ) {