[TimeStats] Track per-frame CPU time.

This measures from the beginning of the invalidate message, until
CompositionEngine::present finishes.

Bug: 144037240
Test: dumpsys SurfaceFlinger --timestats -dump
Change-Id: I1c686db9fa1746518c48810bf385041806ce06d2
diff --git a/services/surfaceflinger/SurfaceFlinger.cpp b/services/surfaceflinger/SurfaceFlinger.cpp
index b4d748d..010b52e 100644
--- a/services/surfaceflinger/SurfaceFlinger.cpp
+++ b/services/surfaceflinger/SurfaceFlinger.cpp
@@ -1601,6 +1601,7 @@
     ATRACE_CALL();
     switch (what) {
         case MessageQueue::INVALIDATE: {
+            const nsecs_t frameStart = systemTime();
             // calculate the expected present time once and use the cached
             // value throughout this frame to make sure all layers are
             // seeing this same value.
@@ -1665,6 +1666,13 @@
                 // Signal a refresh if a transaction modified the window state,
                 // a new buffer was latched, or if HWC has requested a full
                 // repaint
+                if (mFrameStartTime <= 0) {
+                    // We should only use the time of the first invalidate
+                    // message that signals a refresh as the beginning of the
+                    // frame. Otherwise the real frame time will be
+                    // underestimated.
+                    mFrameStartTime = frameStart;
+                }
                 signalRefresh();
             }
             break;
@@ -1748,6 +1756,9 @@
     mGeometryInvalid = false;
 
     mCompositionEngine->present(refreshArgs);
+    mTimeStats->recordFrameDuration(mFrameStartTime, systemTime());
+    // Reset the frame start time now that we've recorded this frame.
+    mFrameStartTime = 0;
 
     postFrame();
     postComposition();