Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
From:   "Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
To:     linux-kernel@vger.kernel.org
Cc:     mingo@kernel.org, jiangshanlai@gmail.com, dipankar@in.ibm.com,
        akpm@linux-foundation.org, mathieu.desnoyers@efficios.com,
        josh@joshtriplett.org, tglx@linutronix.de, peterz@infradead.org,
        rostedt@goodmis.org, dhowells@redhat.com, edumazet@google.com,
        fweisbec@gmail.com, oleg@redhat.com, joel@joelfernandes.org,
        "Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
Subject: [PATCH tip/core/rcu 15/17] rcutorture: Print forward-progress test interval on error
Date:   Wed, 29 Aug 2018 14:47:48 -0700
In-Reply-To: <20180829214722.GA23411@linux.vnet.ibm.com>
References: <20180829214722.GA23411@linux.vnet.ibm.com>
Message-Id: <20180829214750.26972-15-paulmck@linux.vnet.ibm.com>
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

This commit prints the duration of the forward-progress test interval in
the case that no forward progress was observed as an aid to debugging.
When forward progress does happen, it prints out the number of
rcu_torture_writer() versions and grace periods that elapsed during the
forward-progress test.  At the end of the run, it also prints the number
of attempted and actual forward-progress tests.

Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
---
 kernel/rcu/rcutorture.c | 14 +++++++++-----
 1 file changed, 9 insertions(+), 5 deletions(-)

diff --git a/kernel/rcu/rcutorture.c b/kernel/rcu/rcutorture.c
index 50015b78a43f..7df8142a6a22 100644
--- a/kernel/rcu/rcutorture.c
+++ b/kernel/rcu/rcutorture.c
@@ -1702,6 +1702,7 @@ static void rcu_torture_fwd_prog_cb(struct rcu_head *rhp)
 static int rcu_torture_fwd_prog(void *args)
 {
 	unsigned long cver;
+	unsigned long dur;
 	struct fwd_cb_state fcs = { .stop = 0 };
 	unsigned long gps;
 	int idx;
@@ -1709,7 +1710,7 @@ static int rcu_torture_fwd_prog(void *args)
 	int sd4;
 	bool selfpropcb = false;
 	unsigned long stopat;
-	bool tested = false;
+	int tested = 0;
 	int tested_tries = 0;
 	static DEFINE_TORTURE_RANDOM(trs);
 
@@ -1727,7 +1728,8 @@ static int rcu_torture_fwd_prog(void *args)
 		gps = cur_ops->get_gp_seq();
 		sd = cur_ops->stall_dur() + 1;
 		sd4 = (sd + fwd_progress_div - 1) / fwd_progress_div;
-		stopat = jiffies + sd4 + torture_random(&trs) % (sd - sd4);
+		dur = sd4 + torture_random(&trs) % (sd - sd4);
+		stopat = jiffies + dur;
 		while (time_before(jiffies, stopat) && !torture_must_stop()) {
 			idx = cur_ops->readlock();
 			udelay(10);
@@ -1737,10 +1739,11 @@ static int rcu_torture_fwd_prog(void *args)
 		}
 		tested_tries++;
 		if (!time_before(jiffies, stopat) && !torture_must_stop()) {
-			tested = true;
-			cver = cver == READ_ONCE(rcu_torture_current_version);
+			tested++;
+			cver = READ_ONCE(rcu_torture_current_version) - cver;
 			gps = rcutorture_seq_diff(cur_ops->get_gp_seq(), gps);
-			WARN_ON_ONCE(cver && gps < 2);
+			WARN_ON(!cver && gps < 2);
+			pr_alert("%s: Duration %ld cver %ld gps %ld\n", __func__, dur, cver, gps);
 		}
 		/* Avoid slow periods, better to test when busy. */
 		stutter_wait("rcu_torture_fwd_prog");
@@ -1754,6 +1757,7 @@ static int rcu_torture_fwd_prog(void *args)
 	}
 	/* Short runs might not contain a valid forward-progress attempt. */
 	WARN_ON(!tested && tested_tries >= 5);
+	pr_alert("%s: tested %d tested_tries %d\n", __func__, tested, tested_tries);
 	torture_kthread_stopping("rcu_torture_fwd_prog");
 	return 0;
 }
-- 
2.17.1