[2/3] kudu git commit: stopwatch: ensure LOG_TIMING always prints

[to...@apache.org]

stopwatch: ensure LOG_TIMING always prints

On rare occasion in benchmark runs, the LOG_TIMING macro doesn't produce
any output. It's not entirely clear why this happens, but it seems the
only possibility is that the so-called monotonic clock is going
backwards. This change ensures that the macro always prints even if the
clock moves backwards.

Change-Id: I67fe658801be153cbcb6efb31cc8f3bf9eaf944f
Reviewed-on: http://gerrit.cloudera.org:8080/7333
Tested-by: Kudu Jenkins
Reviewed-by: Adar Dembo <ad...@cloudera.com>


Project: http://git-wip-us.apache.org/repos/asf/kudu/repo
Commit: http://git-wip-us.apache.org/repos/asf/kudu/commit/41a3aeab
Tree: http://git-wip-us.apache.org/repos/asf/kudu/tree/41a3aeab
Diff: http://git-wip-us.apache.org/repos/asf/kudu/diff/41a3aeab

Branch: refs/heads/master
Commit: 41a3aeabb902f5b46e97ea0edaaa2efd9f7cc006
Parents: b33689e
Author: Todd Lipcon <to...@apache.org>
Authored: Thu Jun 29 11:14:33 2017 -0700
Committer: Todd Lipcon <to...@apache.org>
Committed: Fri Jun 30 01:38:35 2017 +0000

----------------------------------------------------------------------
 src/kudu/util/stopwatch.h | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/kudu/blob/41a3aeab/src/kudu/util/stopwatch.h
----------------------------------------------------------------------
diff --git a/src/kudu/util/stopwatch.h b/src/kudu/util/stopwatch.h
index e86d90c..ea9a1be 100644
--- a/src/kudu/util/stopwatch.h
+++ b/src/kudu/util/stopwatch.h
@@ -327,7 +327,10 @@ class LogTiming {
   void Print(int64_t max_expected_millis) {
     stopwatch_.stop();
     CpuTimes times = stopwatch_.elapsed();
-    if (times.wall_millis() > max_expected_millis) {
+    // TODO(todd): for some reason, times.wall_millis() sometimes ends up negative
+    // on rare occasion, for unclear reasons, so we have to check max_expected_millis
+    // < 0 to be sure we always print when requested.
+    if (max_expected_millis < 0 || times.wall_millis() > max_expected_millis) {
       google::LogMessage(file_, line_, severity_).stream()
         << prefix_ << "Time spent " << description_ << ": "
         << times.ToString();