cc: Add a Scheduling.SwapAckWasFast UMA.

cc/scheduler/compositor_timing_history.cc

Index: cc/scheduler/compositor_timing_history.cc
diff --git a/cc/scheduler/compositor_timing_history.cc b/cc/scheduler/compositor_timing_history.cc
index 8b474c09b3d20a070095c45f3c6cb3caf722bedd..c9b7d5840fb0e3dd59e312536acc98885dd3f185 100644
--- a/cc/scheduler/compositor_timing_history.cc
+++ b/cc/scheduler/compositor_timing_history.cc
@@ -37,6 +37,7 @@ class CompositorTimingHistory::UMAReporter {
   virtual void AddActivateDuration(base::TimeDelta duration) = 0;
   virtual void AddDrawDuration(base::TimeDelta duration) = 0;
   virtual void AddSwapToAckLatency(base::TimeDelta duration) = 0;
+  virtual void AddSwapAckWasFast(bool was_fast) = 0;
 
   // Synchronization measurements
   virtual void AddMainAndImplFrameTimeDelta(base::TimeDelta delta) = 0;
@@ -58,6 +59,9 @@ const double kPrepareTilesEstimationPercentile = 90.0;
 const double kActivateEstimationPercentile = 90.0;
 const double kDrawEstimationPercentile = 90.0;
 
+const base::TimeDelta kSwapAckWatchdogTimeout =

[sunnyps, 2016/09/28 21:19:39]

base::TimeDelta is a non-POD type and those cannot be static according to the
style guide:
https://google.github.io/styleguide/cppguide.html#Static_and_Global_Variables

Can you please make this constexpr instead? That should work because
FromMicroseconds is constexpr.

(Or you can use a static int64.)

+    base::TimeDelta::FromMicroseconds(8000000);
+
 const int kUmaDurationMinMicros = 1;
 const int64_t kUmaDurationMaxMicros = base::Time::kMicrosecondsPerSecond / 5;
 const int kUmaDurationBucketCount = 100;
@@ -191,6 +195,10 @@ class RendererUMAReporter : public CompositorTimingHistory::UMAReporter {
                                         duration);
   }
 
+  void AddSwapAckWasFast(bool was_fast) override {
+    UMA_HISTOGRAM_BOOLEAN("Scheduling.Renderer.SwapAckWasFast", was_fast);
+  }
+
   void AddMainAndImplFrameTimeDelta(base::TimeDelta delta) override {
     UMA_HISTOGRAM_CUSTOM_TIMES_VSYNC_ALIGNED(
         "Scheduling.Renderer.MainAndImplFrameTimeDelta", delta);
@@ -264,6 +272,10 @@ class BrowserUMAReporter : public CompositorTimingHistory::UMAReporter {
                                         duration);
   }
 
+  void AddSwapAckWasFast(bool was_fast) override {
+    UMA_HISTOGRAM_BOOLEAN("Scheduling.Browser.SwapAckWasFast", was_fast);
+  }
+
   void AddMainAndImplFrameTimeDelta(base::TimeDelta delta) override {
     UMA_HISTOGRAM_CUSTOM_TIMES_VSYNC_ALIGNED(
         "Scheduling.Browser.MainAndImplFrameTimeDelta", delta);
@@ -289,6 +301,7 @@ class NullUMAReporter : public CompositorTimingHistory::UMAReporter {
   void AddActivateDuration(base::TimeDelta duration) override {}
   void AddDrawDuration(base::TimeDelta duration) override {}
   void AddSwapToAckLatency(base::TimeDelta duration) override {}
+  void AddSwapAckWasFast(bool was_fast) override {}
   void AddMainAndImplFrameTimeDelta(base::TimeDelta delta) override {}
 };
 
@@ -315,6 +328,7 @@ CompositorTimingHistory::CompositorTimingHistory(
       activate_duration_history_(kDurationHistorySize),
       draw_duration_history_(kDurationHistorySize),
       begin_main_frame_on_critical_path_(false),
+      swap_ack_watchdog_enabled_(false),
       uma_reporter_(CreateUMAReporter(uma_category)),
       rendering_stats_instrumentation_(rendering_stats_instrumentation) {}
 
@@ -443,6 +457,7 @@ void CompositorTimingHistory::DidCreateAndInitializeOutputSurface() {
   // After we get a new output surface, we won't get a spurious
   // swap ack from the old output surface.
   swap_start_time_ = base::TimeTicks();
+  swap_ack_watchdog_enabled_ = false;

[sunnyps, 2016/09/28 21:19:39]

nit: If we lose the output surface or if it's reinitialized we should get the
DidSwapBuffersComplete callback (if there was a pending swap) so maybe this can
be a DCHECK(!swap_ack_watchdog_enabled_)?

 }
 
 void CompositorTimingHistory::WillBeginImplFrame(
@@ -458,6 +473,15 @@ void CompositorTimingHistory::WillBeginImplFrame(
     SetBeginMainFrameCommittingContinuously(false);
   }
 
+  if (swap_ack_watchdog_enabled_) {
+    base::TimeDelta swap_not_acked_time_ = Now() - swap_start_time_;
+    if (swap_not_acked_time_ > kSwapAckWatchdogTimeout) {

[sunnyps, 2016/09/28 21:19:39]

nit: >= here because we use < in DidSwapBuffersComplete

+      uma_reporter_->AddSwapAckWasFast(false);
+      // Only record this UMA once per swap.
+      swap_ack_watchdog_enabled_ = false;
+    }
+  }
+
   did_send_begin_main_frame_ = false;
 }
 
@@ -697,12 +721,18 @@ void CompositorTimingHistory::DidDraw(bool used_new_active_tree,
 void CompositorTimingHistory::DidSwapBuffers() {
   DCHECK_EQ(base::TimeTicks(), swap_start_time_);
   swap_start_time_ = Now();
+  swap_ack_watchdog_enabled_ = true;
 }
 
 void CompositorTimingHistory::DidSwapBuffersComplete() {
   DCHECK_NE(base::TimeTicks(), swap_start_time_);
   base::TimeDelta swap_to_ack_duration = Now() - swap_start_time_;
   uma_reporter_->AddSwapToAckLatency(swap_to_ack_duration);
+  if (swap_ack_watchdog_enabled_) {
+    bool was_fast = swap_to_ack_duration < kSwapAckWatchdogTimeout;
+    uma_reporter_->AddSwapAckWasFast(was_fast);
+    swap_ack_watchdog_enabled_ = false;
+  }
   swap_start_time_ = base::TimeTicks();
 }