Added check for out of order event handling in average_lag_tracker.

The average_lag_tracker assumes that all events have nondecreasing
timestamps. However, the assumption breaks when the main thread takes a
long time to handle a scroll update and the compositor thread starts a
new scroll in the meantime.

This CL removes the invalid DCHECK and instead ignores the out-of-order
event.

Bug: 1015492
Change-Id: I3dcee2be9c0ba9b6e295d391b4c114f7ef05510b
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1869378Reviewed-by: Daniel Libby <dlibby@microsoft.com>
Reviewed-by: Ella Ge <eirage@chromium.org>
Reviewed-by: Navid Zolghadr <nzolghadr@chromium.org>
Commit-Queue: Daniel Libby <dlibby@microsoft.com>
Cr-Commit-Position: refs/heads/master@{#712910}

ui/latency/average_lag_tracker.cc

@@ -51,7 +51,10 @@ void AverageLagTracker::AddLatencyInFrame(
     is_begin_ = true;
   } else if (scroll_name == "ScrollUpdate" &&
              !last_event_timestamp_.is_null()) {
-    DCHECK((event_timestamp - last_event_timestamp_).InMilliseconds() >= 0);
+    // Only accept events in nondecreasing order.
+    if ((event_timestamp - last_event_timestamp_).InMilliseconds() < 0)
+      return;
+
     // Pop all frames where frame_time <= event_timestamp.
     while (!frame_lag_infos_.empty() &&
            frame_lag_infos_.front().frame_time <= event_timestamp) {

ui/latency/average_lag_tracker_unittest.cc

@@ -495,5 +495,46 @@ TEST_F(AverageLagTrackerTest, NoPredictionEffect) {
       "Event.Latency.ScrollUpdate.Touch.AverageLag.PredictionNegative", 0);
 }
 
+// Tests that when an event arrives out-of-order, the average lag tracker
+// properly ignores it.
+TEST_F(AverageLagTrackerTest, EventOutOfOrder) {
+  base::TimeTicks event_time = MillisecondsToTimeTicks(5);
+  base::TimeTicks frame_time = MillisecondsToTimeTicks(10);
+  float scroll_delta = 5.f;
+  SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, scroll_delta);
+
+  event_time = MillisecondsToTimeTicks(15);
+  frame_time = MillisecondsToTimeTicks(20);
+  SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, scroll_delta);
+
+  event_time = MillisecondsToTimeTicks(25);
+  frame_time = MillisecondsToTimeTicks(30);
+  SyntheticTouchScrollUpdateLatencyInfo(event_time, frame_time, scroll_delta);
+
+  // A ScrollBegin to flush unfinished frames.
+  event_time = MillisecondsToTimeTicks(1000);
+  frame_time = MillisecondsToTimeTicks(1000);
+  SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, 0);
+
+  histogram_tester().ExpectTotalCount(
+      "Event.Latency.ScrollUpdate.Touch.AverageLag", 1);
+
+  // Send an event whose timestamp is earlier than the most recent event,
+  // representing an event that gets process out of order.
+  base::TimeTicks earlier_event_time = MillisecondsToTimeTicks(15);
+  frame_time = MillisecondsToTimeTicks(1010);
+  SyntheticTouchScrollUpdateLatencyInfo(earlier_event_time, frame_time,
+                                        scroll_delta);
+
+  // Another ScrollBegin to flush unfinished frames.
+  event_time = MillisecondsToTimeTicks(2000);
+  frame_time = MillisecondsToTimeTicks(2000);
+  SyntheticTouchScrollBeginLatencyInfo(event_time, frame_time, 0);
+
+  // Ensure that the event was ignored.
+  histogram_tester().ExpectTotalCount(
+      "Event.Latency.ScrollUpdate.Touch.AverageLag", 1);
+}
+
 }  // namespace
 }  // namespace ui