Re: [PATCH tip/core/rcu 5/7] torture: Trace long read-side delays

[Josh Triplett]

On Mon, Nov 14, 2016 at 08:57:11AM -0800, Paul E. McKenney wrote:
> Although rcutorture will occasionally do a 50-millisecond grace-period
> delay, these delays are quite rare.  And rightly so, because otherwise
> the read rate would be quite low.  Thie means that it can be important
> to identify whether or not a given run contained a long-delay read.
> This commit therefore inserts a trace_rcu_torture_read() event to flag
> runs containing long delays.
> 
> Signed-off-by: Paul E. McKenney <paulmck@xxxxxxxxxxxxxxxxxx>

A couple of apparent typos below.  With those fixed:
Reviewed-by: Josh Triplett <josh@xxxxxxxxxxxxxxxx>

>  include/trace/events/rcu.h |  5 ++++-
>  kernel/rcu/rcutorture.c    | 11 ++++++++++-
>  2 files changed, 14 insertions(+), 2 deletions(-)
> 
> diff --git a/include/trace/events/rcu.h b/include/trace/events/rcu.h
> index d3e756539d44..b31e05bc8e26 100644
> --- a/include/trace/events/rcu.h
> +++ b/include/trace/events/rcu.h
> @@ -698,7 +698,10 @@ TRACE_EVENT(rcu_batch_end,
>  /*
>   * Tracepoint for rcutorture readers.  The first argument is the name
>   * of the RCU flavor from rcutorture's viewpoint and the second argument
> - * is the callback address.
> + * is the callback address.  The third callback is the start time in
> + * seconds, and the last two arguments are the grace period numbers
> + * and the beginning and end of the read, respectively.  Note that the
> + * callback address can be NULL.

s/third callback/third argument/?

Also, s/and the beginning/of the beginning/?

>  TRACE_EVENT(rcu_torture_read,
>  
> diff --git a/kernel/rcu/rcutorture.c b/kernel/rcu/rcutorture.c
> index bf08fee53dc7..87c51225ceec 100644
> --- a/kernel/rcu/rcutorture.c
> +++ b/kernel/rcu/rcutorture.c
> @@ -289,15 +289,24 @@ static int rcu_torture_read_lock(void) __acquires(RCU)
>  
>  static void rcu_read_delay(struct torture_random_state *rrsp)
>  {
> +	unsigned long started;
> +	unsigned long completed;
>  	const unsigned long shortdelay_us = 200;
>  	const unsigned long longdelay_ms = 50;
> +	unsigned long long ts;
>  
>  	/* We want a short delay sometimes to make a reader delay the grace
>  	 * period, and we want a long delay occasionally to trigger
>  	 * force_quiescent_state. */
>  
> -	if (!(torture_random(rrsp) % (nrealreaders * 2000 * longdelay_ms)))
> +	if (!(torture_random(rrsp) % (nrealreaders * 2000 * longdelay_ms))) {
> +		started = cur_ops->completed();
> +		ts = rcu_trace_clock_local();
>  		mdelay(longdelay_ms);
> +		completed = cur_ops->completed();
> +		do_trace_rcu_torture_read(cur_ops->name, NULL, ts,
> +					  started, completed);
> +	}
>  	if (!(torture_random(rrsp) % (nrealreaders * 2 * shortdelay_us)))
>  		udelay(shortdelay_us);
>  #ifdef CONFIG_PREEMPT
> -- 
> 2.5.2
>