rcutorture: Print forward-progress test interval on error

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>

diff --git a/kernel/rcu/rcutorture.c b/kernel/rcu/rcutorture.c
index 50015b78a43f413e455338539ebdb73f832883a7..7df8142a6a22cdccfb79c86764f84b78721f6897 100644 (file)
--- 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;
 }