Date: Mon, 14 Nov 2016 09:21:10 -0800
From: Josh Triplett <josh@joshtriplett.org>
To: "Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
Cc: linux-kernel@vger.kernel.org, mingo@kernel.org, jiangshanlai@gmail.com,
        dipankar@in.ibm.com, akpm@linux-foundation.org,
        mathieu.desnoyers@efficios.com, tglx@linutronix.de,
        peterz@infradead.org, rostedt@goodmis.org, dhowells@redhat.com,
        edumazet@google.com, dvhart@linux.intel.com, fweisbec@gmail.com,
        oleg@redhat.com, bobby.prani@gmail.com
Subject: Re: [PATCH tip/core/rcu 5/7] torture: Trace long read-side delays
Message-ID: <20161114172110.yybjdk6p6754nlih@jtriplet-mobl2.jf.intel.com>
References: <20161114165648.GA15216@linux.vnet.ibm.com>
 <1479142633-15315-5-git-send-email-paulmck@linux.vnet.ibm.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <1479142633-15315-5-git-send-email-paulmck@linux.vnet.ibm.com>
User-Agent: NeoMutt/20161104 (1.7.1)
Sender: linux-kernel-owner@vger.kernel.org
Content-Length: 2755
Lines: 70

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@linux.vnet.ibm.com>

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

>  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
>