[PATCH tip/core/rcu 2/4] rcu: Reduce rcutorture tracing
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
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) { -