[tip: core/rcu] torture: Print run duration at end of kvm.sh execution

[tip: core/rcu] torture: Print run duration at end of kvm.sh execution

[tip-bot2 for Paul E. McKenney]

The following commit has been merged into the core/rcu branch of tip:

Commit-ID:     0bcca18348cfde8e59b77cdf6f3e278289a16e67
Gitweb:        https://git.kernel.org/tip/0bcca18348cfde8e59b77cdf6f3e278289a16e67
Author:        Paul E. McKenney <paulmck@kernel.org>
AuthorDate:    Sun, 22 Nov 2020 09:55:34 -08:00
Committer:     Paul E. McKenney <paulmck@kernel.org>
CommitterDate: Mon, 04 Jan 2021 14:01:21 -08:00

torture: Print run duration at end of kvm.sh execution

Yes, you can mentally subtract the timestamps, but this commit makes
the computer do this work.

Signed-off-by: Paul E. McKenney <paulmck@kernel.org>
---
 tools/testing/selftests/rcutorture/bin/functions.sh | 33 ++++++++++++-
 tools/testing/selftests/rcutorture/bin/kvm.sh       |  6 ++-
 2 files changed, 39 insertions(+)

diff --git a/tools/testing/selftests/rcutorture/bin/functions.sh b/tools/testing/selftests/rcutorture/bin/functions.sh
index fef8b4b..97c3a17 100644
--- a/tools/testing/selftests/rcutorture/bin/functions.sh
+++ b/tools/testing/selftests/rcutorture/bin/functions.sh
@@ -108,6 +108,39 @@ configfrag_hotplug_cpu () {
 	grep -q '^CONFIG_HOTPLUG_CPU=y$' "$1"
 }
 
+# get_starttime
+#
+# Returns a cookie identifying the current time.
+get_starttime () {
+	awk 'BEGIN { print systime() }' < /dev/null
+}
+
+# get_starttime_duration starttime
+#
+# Given the return value from get_starttime, compute a human-readable
+# string denoting the time since get_starttime.
+get_starttime_duration () {
+	awk -v starttime=$1 '
+	BEGIN {
+		ts = systime() - starttime; 
+		tm = int(ts / 60);
+		th = int(ts / 3600);
+		td = int(ts / 86400);
+		d = td;
+		h = th - td * 24;
+		m = tm - th * 60;
+		s = ts - tm * 60;
+		if (d >= 1)
+			printf "%dd %d:%02d:%02d\n", d, h, m, s
+		else if (h >= 1)
+			printf "%d:%02d:%02d\n", h, m, s
+		else if (m >= 1)
+			printf "%d:%02d.0\n", m, s
+		else
+			print s " seconds"
+	}' < /dev/null
+}
+
 # identify_boot_image qemu-cmd
 #
 # Returns the relative path to the kernel build image.  This will be
diff --git a/tools/testing/selftests/rcutorture/bin/kvm.sh b/tools/testing/selftests/rcutorture/bin/kvm.sh
index 6fd7ef7..6f21268 100755
--- a/tools/testing/selftests/rcutorture/bin/kvm.sh
+++ b/tools/testing/selftests/rcutorture/bin/kvm.sh
@@ -47,6 +47,9 @@ cpus=0
 ds=`date +%Y.%m.%d-%H.%M.%S`
 jitter="-1"
 
+startdate="`date`"
+starttime="`get_starttime`"
+
 usage () {
 	echo "Usage: $scriptname optional arguments:"
 	echo "       --allcpus"
@@ -548,6 +551,9 @@ then
 else
 	# Not a dryrun, so run the script.
 	sh $T/script
+	ret=$?
+	echo " --- Done at `date` (`get_starttime_duration $starttime`)"
+	exit $ret
 fi
 
 # Tracing: trace_event=rcu:rcu_grace_period,rcu:rcu_future_grace_period,rcu:rcu_grace_period_init,rcu:rcu_nocb_wake,rcu:rcu_preempt_task,rcu:rcu_unlock_preempted_task,rcu:rcu_quiescent_state_report,rcu:rcu_fqs,rcu:rcu_callback,rcu:rcu_kfree_callback,rcu:rcu_batch_start,rcu:rcu_invoke_callback,rcu:rcu_invoke_kfree_callback,rcu:rcu_batch_end,rcu:rcu_torture_read,rcu:rcu_barrier