[PATCH tip/core/rcu 2/4] rcu: Reduce rcutorture tracing

2013-01-26 Thread Paul E. McKenney
From: "Paul E. McKenney" 

Currently, rcutorture traces every read-side access.  This can be
problematic because even a two-minute rcutorture run on a two-CPU system
can generate 28,853,363 reads.  Normally, only a failing read is of
interest, so this commit traces adjusts rcutorture's tracing to only
trace failing reads.  The resulting event tracing records the time
and the ->completed value captured at the beginning of the RCU read-side
critical section, allowing correlation with other event-tracing messages.

Signed-off-by: Paul E. McKenney 
Signed-off-by: Paul E. McKenney 
Reviewed-by: Josh Triplett 
[ paulmck: Add fix to build problem located by Randy Dunlap based on
  diagnosis by Steven Rostedt. ]
---
 include/linux/rcupdate.h   |   13 ++---
 include/trace/events/rcu.h |   19 ++-
 kernel/rcupdate.c  |9 ++---
 kernel/rcutorture.c|   31 ---
 lib/Kconfig.debug  |1 +
 5 files changed, 55 insertions(+), 18 deletions(-)

diff --git a/include/linux/rcupdate.h b/include/linux/rcupdate.h
index 275aa3f..7f89cea 100644
--- a/include/linux/rcupdate.h
+++ b/include/linux/rcupdate.h
@@ -53,7 +53,10 @@ extern int rcutorture_runnable; /* for sysctl */
 extern void rcutorture_record_test_transition(void);
 extern void rcutorture_record_progress(unsigned long vernum);
 extern void do_trace_rcu_torture_read(char *rcutorturename,
- struct rcu_head *rhp);
+ struct rcu_head *rhp,
+ unsigned long secs,
+ unsigned long c_old,
+ unsigned long c);
 #else
 static inline void rcutorture_record_test_transition(void)
 {
@@ -63,9 +66,13 @@ static inline void rcutorture_record_progress(unsigned long 
vernum)
 }
 #ifdef CONFIG_RCU_TRACE
 extern void do_trace_rcu_torture_read(char *rcutorturename,
- struct rcu_head *rhp);
+ struct rcu_head *rhp,
+ unsigned long secs,
+ unsigned long c_old,
+ unsigned long c);
 #else
-#define do_trace_rcu_torture_read(rcutorturename, rhp) do { } while (0)
+#define do_trace_rcu_torture_read(rcutorturename, rhp, secs, c_old, c) \
+   do { } while (0)
 #endif
 #endif
 
diff --git a/include/trace/events/rcu.h b/include/trace/events/rcu.h
index d4f559b..09af021 100644
--- a/include/trace/events/rcu.h
+++ b/include/trace/events/rcu.h
@@ -523,22 +523,30 @@ TRACE_EVENT(rcu_batch_end,
  */
 TRACE_EVENT(rcu_torture_read,
 
-   TP_PROTO(char *rcutorturename, struct rcu_head *rhp),
+   TP_PROTO(char *rcutorturename, struct rcu_head *rhp,
+unsigned long secs, unsigned long c_old, unsigned long c),
 
-   TP_ARGS(rcutorturename, rhp),
+   TP_ARGS(rcutorturename, rhp, secs, c_old, c),
 
TP_STRUCT__entry(
__field(char *, rcutorturename)
__field(struct rcu_head *, rhp)
+   __field(unsigned long, secs)
+   __field(unsigned long, c_old)
+   __field(unsigned long, c)
),
 
TP_fast_assign(
__entry->rcutorturename = rcutorturename;
__entry->rhp = rhp;
+   __entry->secs = secs;
+   __entry->c_old = c_old;
+   __entry->c = c;
),
 
-   TP_printk("%s torture read %p",
- __entry->rcutorturename, __entry->rhp)
+   TP_printk("%s torture read %p %luus c: %lu %lu",
+ __entry->rcutorturename, __entry->rhp,
+ __entry->secs, __entry->c_old, __entry->c)
 );
 
 /*
@@ -608,7 +616,8 @@ TRACE_EVENT(rcu_barrier,
 #define trace_rcu_invoke_kfree_callback(rcuname, rhp, offset) do { } while (0)
 #define trace_rcu_batch_end(rcuname, callbacks_invoked, cb, nr, iit, risk) \
do { } while (0)
-#define trace_rcu_torture_read(rcutorturename, rhp) do { } while (0)
+#define trace_rcu_torture_read(rcutorturename, rhp, secs, c_old, c) \
+   do { } while (0)
 #define trace_rcu_barrier(name, s, cpu, cnt, done) do { } while (0)
 
 #endif /* #else #ifdef CONFIG_RCU_TRACE */
diff --git a/kernel/rcupdate.c b/kernel/rcupdate.c
index a2cf761..303359d 100644
--- a/kernel/rcupdate.c
+++ b/kernel/rcupdate.c
@@ -404,11 +404,14 @@ EXPORT_SYMBOL_GPL(rcuhead_debug_descr);
 #endif /* #ifdef CONFIG_DEBUG_OBJECTS_RCU_HEAD */
 
 #if defined(CONFIG_TREE_RCU) || defined(CONFIG_TREE_PREEMPT_RCU) || 
defined(CONFIG_RCU_TRACE)
-void do_trace_rcu_torture_read(char *rcutorturename, struct rcu_head *rhp)
+void do_trace_rcu_torture_read(char *rcutorturename, struct rcu_head *rhp,
+  unsigned long secs,
+  unsigned long c_old, unsigned long c)
 {
-   trace_rcu_torture_read(rcutorturename, rhp);
+   

[PATCH tip/core/rcu 2/4] rcu: Reduce rcutorture tracing

2013-01-26 Thread Paul E. McKenney
From: Paul E. McKenney paul.mcken...@linaro.org

Currently, rcutorture traces every read-side access.  This can be
problematic because even a two-minute rcutorture run on a two-CPU system
can generate 28,853,363 reads.  Normally, only a failing read is of
interest, so this commit traces adjusts rcutorture's tracing to only
trace failing reads.  The resulting event tracing records the time
and the -completed value captured at the beginning of the RCU read-side
critical section, allowing correlation with other event-tracing messages.

Signed-off-by: Paul E. McKenney paul.mcken...@linaro.org
Signed-off-by: Paul E. McKenney paul...@linux.vnet.ibm.com
Reviewed-by: Josh Triplett j...@joshtriplett.org
[ paulmck: Add fix to build problem located by Randy Dunlap based on
  diagnosis by Steven Rostedt. ]
---
 include/linux/rcupdate.h   |   13 ++---
 include/trace/events/rcu.h |   19 ++-
 kernel/rcupdate.c  |9 ++---
 kernel/rcutorture.c|   31 ---
 lib/Kconfig.debug  |1 +
 5 files changed, 55 insertions(+), 18 deletions(-)

diff --git a/include/linux/rcupdate.h b/include/linux/rcupdate.h
index 275aa3f..7f89cea 100644
--- a/include/linux/rcupdate.h
+++ b/include/linux/rcupdate.h
@@ -53,7 +53,10 @@ extern int rcutorture_runnable; /* for sysctl */
 extern void rcutorture_record_test_transition(void);
 extern void rcutorture_record_progress(unsigned long vernum);
 extern void do_trace_rcu_torture_read(char *rcutorturename,
- struct rcu_head *rhp);
+ struct rcu_head *rhp,
+ unsigned long secs,
+ unsigned long c_old,
+ unsigned long c);
 #else
 static inline void rcutorture_record_test_transition(void)
 {
@@ -63,9 +66,13 @@ static inline void rcutorture_record_progress(unsigned long 
vernum)
 }
 #ifdef CONFIG_RCU_TRACE
 extern void do_trace_rcu_torture_read(char *rcutorturename,
- struct rcu_head *rhp);
+ struct rcu_head *rhp,
+ unsigned long secs,
+ unsigned long c_old,
+ unsigned long c);
 #else
-#define do_trace_rcu_torture_read(rcutorturename, rhp) do { } while (0)
+#define do_trace_rcu_torture_read(rcutorturename, rhp, secs, c_old, c) \
+   do { } while (0)
 #endif
 #endif
 
diff --git a/include/trace/events/rcu.h b/include/trace/events/rcu.h
index d4f559b..09af021 100644
--- a/include/trace/events/rcu.h
+++ b/include/trace/events/rcu.h
@@ -523,22 +523,30 @@ TRACE_EVENT(rcu_batch_end,
  */
 TRACE_EVENT(rcu_torture_read,
 
-   TP_PROTO(char *rcutorturename, struct rcu_head *rhp),
+   TP_PROTO(char *rcutorturename, struct rcu_head *rhp,
+unsigned long secs, unsigned long c_old, unsigned long c),
 
-   TP_ARGS(rcutorturename, rhp),
+   TP_ARGS(rcutorturename, rhp, secs, c_old, c),
 
TP_STRUCT__entry(
__field(char *, rcutorturename)
__field(struct rcu_head *, rhp)
+   __field(unsigned long, secs)
+   __field(unsigned long, c_old)
+   __field(unsigned long, c)
),
 
TP_fast_assign(
__entry-rcutorturename = rcutorturename;
__entry-rhp = rhp;
+   __entry-secs = secs;
+   __entry-c_old = c_old;
+   __entry-c = c;
),
 
-   TP_printk(%s torture read %p,
- __entry-rcutorturename, __entry-rhp)
+   TP_printk(%s torture read %p %luus c: %lu %lu,
+ __entry-rcutorturename, __entry-rhp,
+ __entry-secs, __entry-c_old, __entry-c)
 );
 
 /*
@@ -608,7 +616,8 @@ TRACE_EVENT(rcu_barrier,
 #define trace_rcu_invoke_kfree_callback(rcuname, rhp, offset) do { } while (0)
 #define trace_rcu_batch_end(rcuname, callbacks_invoked, cb, nr, iit, risk) \
do { } while (0)
-#define trace_rcu_torture_read(rcutorturename, rhp) do { } while (0)
+#define trace_rcu_torture_read(rcutorturename, rhp, secs, c_old, c) \
+   do { } while (0)
 #define trace_rcu_barrier(name, s, cpu, cnt, done) do { } while (0)
 
 #endif /* #else #ifdef CONFIG_RCU_TRACE */
diff --git a/kernel/rcupdate.c b/kernel/rcupdate.c
index a2cf761..303359d 100644
--- a/kernel/rcupdate.c
+++ b/kernel/rcupdate.c
@@ -404,11 +404,14 @@ EXPORT_SYMBOL_GPL(rcuhead_debug_descr);
 #endif /* #ifdef CONFIG_DEBUG_OBJECTS_RCU_HEAD */
 
 #if defined(CONFIG_TREE_RCU) || defined(CONFIG_TREE_PREEMPT_RCU) || 
defined(CONFIG_RCU_TRACE)
-void do_trace_rcu_torture_read(char *rcutorturename, struct rcu_head *rhp)
+void do_trace_rcu_torture_read(char *rcutorturename, struct rcu_head *rhp,
+  unsigned long secs,
+  unsigned long c_old, unsigned long c)
 {
-