[14/19] impala git commit: IMPALA-6450: fix EventSequence::Start()

[ph...@apache.org]

IMPALA-6450: fix EventSequence::Start()

It looks like this newly-added DCHECK is being hit because of the same
underlying issue as IMPALA-4631. This patch loosens the DCHECK to accept
time going backward 1 tick, the same as the original workaround for
IMPALA-4631.

'offset_' also isn't being used, so fix that too.

Change-Id: I62317149cb8428f7d29e945a538f6cc8dd45342f
Reviewed-on: http://gerrit.cloudera.org:8080/9155
Reviewed-by: Tim Armstrong <ta...@cloudera.com>
Tested-by: Impala Public Jenkins


Project: http://git-wip-us.apache.org/repos/asf/impala/repo
Commit: http://git-wip-us.apache.org/repos/asf/impala/commit/489e5dc0
Tree: http://git-wip-us.apache.org/repos/asf/impala/tree/489e5dc0
Diff: http://git-wip-us.apache.org/repos/asf/impala/diff/489e5dc0

Branch: refs/heads/2.x
Commit: 489e5dc0028433e17323028a5d867bcca1822bbf
Parents: 5aab4d4
Author: Tim Armstrong <ta...@cloudera.com>
Authored: Mon Jan 29 15:52:59 2018 -0800
Committer: Impala Public Jenkins <im...@gerrit.cloudera.org>
Committed: Fri Feb 2 01:10:15 2018 +0000

----------------------------------------------------------------------
 be/src/util/runtime-profile-counters.h | 10 +++++++---
 1 file changed, 7 insertions(+), 3 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/impala/blob/489e5dc0/be/src/util/runtime-profile-counters.h
----------------------------------------------------------------------
diff --git a/be/src/util/runtime-profile-counters.h b/be/src/util/runtime-profile-counters.h
index 62281f1..c8d8bcd 100644
--- a/be/src/util/runtime-profile-counters.h
+++ b/be/src/util/runtime-profile-counters.h
@@ -302,14 +302,17 @@ class RuntimeProfile::EventSequence {
   /// 'start_time_ns', which must have been obtained by calling MonotonicStopWatch::Now().
   void Start(int64_t start_time_ns) {
     offset_ = MonotonicStopWatch::Now() - start_time_ns;
-    DCHECK_GE(offset_, 0);
+    // TODO: IMPALA-4631: Occasionally we see MonotonicStopWatch::Now() return
+    // (start_time_ns - 1), even though 'start_time_ns' was obtained using
+    // MonotonicStopWatch::Now().
+    DCHECK_GE(offset_, -1);
     sw_.Start();
   }
 
   /// Stores an event in sequence with the given label and the current time
   /// (relative to the first time Start() was called) as the timestamp.
   void MarkEvent(std::string label) {
-    Event event = make_pair(move(label), sw_.ElapsedTime());
+    Event event = make_pair(move(label), sw_.ElapsedTime() + offset_);
     boost::lock_guard<SpinLock> event_lock(lock_);
     events_.emplace_back(move(event));
   }
@@ -334,7 +337,8 @@ class RuntimeProfile::EventSequence {
   }
 
   /// Adds all events from the input parameters that are newer than the last member of
-  /// 'events_'. The caller must make sure that 'timestamps' is sorted.
+  /// 'events_'. The caller must make sure that 'timestamps' is sorted. Does not adjust
+  /// added timestamps by 'offset_'.
   void AddNewerEvents(
       const std::vector<int64_t>& timestamps, const std::vector<std::string>& labels) {
     DCHECK_EQ(timestamps.size(), labels.size());