Bug 1338347 - Add code to measure the maximum number of contiguous frame drops in a compositor animation. r?botond draft
authorKartikaya Gupta <kgupta@mozilla.com>
Mon, 20 Mar 2017 11:41:05 -0400
changeset 501575 53c5f1a8a47af54f152f997fc190670ad83f27ca
parent 501574 2f271e4830d90aaab4841be62eb79dab2bd6955e
child 549924 30fea46e7e5e9fc77dc1a909bc49e613e281b8ac
push id50031
push userkgupta@mozilla.com
push dateMon, 20 Mar 2017 15:42:18 +0000
reviewersbotond
bugs1338347
milestone55.0a1
Bug 1338347 - Add code to measure the maximum number of contiguous frame drops in a compositor animation. r?botond This value is computed directly from the longest frame length using the vsync interval. MozReview-Commit-ID: 9ALXBqAVyb8
gfx/layers/composite/AnimationMetricsTracker.cpp
gfx/layers/composite/AnimationMetricsTracker.h
--- a/gfx/layers/composite/AnimationMetricsTracker.cpp
+++ b/gfx/layers/composite/AnimationMetricsTracker.cpp
@@ -44,33 +44,36 @@ AnimationMetricsTracker::UpdateAnimation
       mMaxLayerAreaAnimated = std::max(mMaxLayerAreaAnimated, aLayerArea);
     }
   }
 
   UpdateAnimationThroughput("chrome",
                             (aActive & AnimationProcessTypes::eChrome) != AnimationProcessTypes::eNone,
                             mChromeAnimation,
                             aVsyncInterval,
-                            Telemetry::COMPOSITOR_ANIMATION_THROUGHPUT_CHROME);
+                            Telemetry::COMPOSITOR_ANIMATION_THROUGHPUT_CHROME,
+                            Telemetry::COMPOSITOR_ANIMATION_MAX_CONTIGUOUS_DROPS_CHROME);
   UpdateAnimationThroughput("content",
                             (aActive & AnimationProcessTypes::eContent) != AnimationProcessTypes::eNone,
                             mContentAnimation,
                             aVsyncInterval,
-                            Telemetry::COMPOSITOR_ANIMATION_THROUGHPUT_CONTENT);
+                            Telemetry::COMPOSITOR_ANIMATION_THROUGHPUT_CONTENT,
+                            Telemetry::COMPOSITOR_ANIMATION_MAX_CONTIGUOUS_DROPS_CONTENT);
 }
 
 void
 AnimationMetricsTracker::UpdateApzAnimationInProgress(bool aInProgress,
                                                       TimeDuration aVsyncInterval)
 {
   UpdateAnimationThroughput("apz",
                             aInProgress,
                             mApzAnimation,
                             aVsyncInterval,
-                            Telemetry::COMPOSITOR_ANIMATION_THROUGHPUT_APZ);
+                            Telemetry::COMPOSITOR_ANIMATION_THROUGHPUT_APZ,
+                            Telemetry::COMPOSITOR_ANIMATION_MAX_CONTIGUOUS_DROPS_APZ);
 }
 
 void
 AnimationMetricsTracker::AnimationStarted()
 {
 }
 
 void
@@ -85,31 +88,38 @@ AnimationMetricsTracker::AnimationEnded(
     mMaxLayerAreaAnimated);
 }
 
 void
 AnimationMetricsTracker::UpdateAnimationThroughput(const char* aLabel,
                                                    bool aInProgress,
                                                    AnimationData& aAnimation,
                                                    TimeDuration aVsyncInterval,
-                                                   Telemetry::HistogramID aHistogram)
+                                                   Telemetry::HistogramID aThroughputHistogram,
+                                                   Telemetry::HistogramID aMaxDropsHistogram)
 {
   if (aInProgress && !aAnimation.mStart) {
     // the animation just started
     aAnimation.mStart = TimeStamp::Now();
+    aAnimation.mLastFrameTime = aAnimation.mStart;
+    aAnimation.mLongestFrame = TimeDuration();
     aAnimation.mFrameCount = 1;
     AMT_LOG("Compositor animation of type %s just started\n", aLabel);
   } else if (aInProgress && aAnimation.mStart) {
     // the animation continues
     aAnimation.mFrameCount++;
+    TimeStamp now = TimeStamp::Now();
+    aAnimation.mLongestFrame = std::max(aAnimation.mLongestFrame, now - aAnimation.mLastFrameTime);
+    aAnimation.mLastFrameTime = now;
   } else if (!aInProgress && aAnimation.mStart) {
     // the animation just ended
 
+    TimeStamp now = TimeStamp::Now();
     // Get the length and clear aAnimation.mStart before the early-returns below
-    TimeDuration animationLength = TimeStamp::Now() - aAnimation.mStart;
+    TimeDuration animationLength = now - aAnimation.mStart;
     aAnimation.mStart = TimeStamp();
 
     if (aVsyncInterval == TimeDuration::Forever()) {
       AMT_LOG("Invalid vsync interval: forever\n");
       return;
     }
     double vsyncIntervalMs = aVsyncInterval.ToMilliseconds();
     if (vsyncIntervalMs < 1.0f) {
@@ -125,21 +135,31 @@ AnimationMetricsTracker::UpdateAnimation
     // from one composite to another.
     uint32_t expectedFrameCount = std::lround(animationLength.ToMilliseconds() / vsyncIntervalMs);
     AMT_LOG("Type %s ran for %fms (interval: %fms), %u frames (expected: %u)\n",
         aLabel, animationLength.ToMilliseconds(), vsyncIntervalMs,
         aAnimation.mFrameCount, expectedFrameCount);
     if (expectedFrameCount <= 0) {
       // Graceful handling of probably impossible thing, unless the clock
       // changes while running?
+      // Note that we also skip the frames-dropped probe if this happens,
+      // because we cannot be sure that the frame length measurements are valid.
       return;
     }
 
     // Scale up by 1000 because telemetry takes ints, truncate intentionally
     // to avoid artificial inflation of the result.
     uint32_t frameHitRatio = (uint32_t)(1000.0f * aAnimation.mFrameCount / expectedFrameCount);
-    Telemetry::Accumulate(aHistogram, frameHitRatio);
+    Telemetry::Accumulate(aThroughputHistogram, frameHitRatio);
     AMT_LOG("Reported frameHitRatio %u\n", frameHitRatio);
+
+    // Get the longest frame time (make sure to check the final frame as well)
+    TimeDuration longestFrame = std::max(aAnimation.mLongestFrame, now - aAnimation.mLastFrameTime);
+    // As above, we round to get the frame count. Additionally we subtract one
+    // from the frame count to get the number of dropped frames.
+    uint32_t framesDropped = std::lround(longestFrame.ToMilliseconds() / vsyncIntervalMs) - 1;
+    AMT_LOG("Longest frame was %fms (%d drops)\n", longestFrame.ToMilliseconds(), framesDropped);
+    Telemetry::Accumulate(aMaxDropsHistogram, framesDropped);
   }
 }
 
 } // namespace layers
 } // namespace mozilla
--- a/gfx/layers/composite/AnimationMetricsTracker.h
+++ b/gfx/layers/composite/AnimationMetricsTracker.h
@@ -44,32 +44,37 @@ public:
    */
   void UpdateApzAnimationInProgress(bool aInProgress, TimeDuration aVsyncInterval);
 
 private:
   // A struct to group data that we need for each type of compositor animation.
   struct AnimationData {
     // The start time of the current animation.
     TimeStamp mStart;
+    // The timestamp of the most recent animation frame.
+    TimeStamp mLastFrameTime;
+    // The longest animation frame length encountered so far.
+    TimeDuration mLongestFrame;
     // The number of frames composited for the current animation.
     uint32_t mFrameCount;
 
     AnimationData()
       : mFrameCount(0)
     {
     }
   };
 
   void AnimationStarted();
   void AnimationEnded();
   void UpdateAnimationThroughput(const char* aLabel,
                                  bool aInProgress,
                                  AnimationData& aAnimationData,
                                  TimeDuration aVsyncInterval,
-                                 Telemetry::HistogramID aHistogram);
+                                 Telemetry::HistogramID aThroughputHistogram,
+                                 Telemetry::HistogramID aMaxDropsHistogram);
 
   // The start time of the current compositor animation. This just tracks
   // whether the compositor is running an animation, without regard to which
   // process the animation is coming from.
   TimeStamp mCurrentAnimationStart;
   // The max area (in layer pixels) that the current compositor animation
   // has touched on any given animation frame.
   uint64_t mMaxLayerAreaAnimated;