commit 2e1608ff49148a8d99c2e33897fa0e5c3ce532c2
author Mikael Pessa <mikaelpessa@google.com> Fri Jul 19 11:25:35 2019 -0700
committer Mikael Pessa <mikaelpessa@google.com> Wed Aug 28 11:15:25 2019 -0700
tree 2ff7a03aa1db3c25e86490396e282135a59aed33
parent f0aa9016e99a441e2bc2048ddd55b1437b3f6daa

Add per-buffer perfetto trace points for SurfaceFlinger frame events

In order to track how buffers move through the system, we add per-buffer perfetto trace points for SurfaceFlinger.
The majority of these were already tracked through TimeStats, so the new tracing was built on top of TimeStats.

Test: atest libsurfaceflinger_unittest

Run trace with:
{ adb shell perfetto   -c - --txt   -o /data/misc/perfetto-traces/trace <<EOF
buffers: {
    size_kb: 1280
}
data_sources: {
    config {
        name: "android.surfaceflinger.timestats"
    }
}
duration_ms: 3000
EOF
} && adb pull /data/misc/perfetto-traces/trace ~/Desktop/trace

Change-Id: Ifb38c64a9966fece735f0ad72438c7c9c5e07baa

services/surfaceflinger/BufferStateLayer.cpp

diff --git a/services/surfaceflinger/BufferStateLayer.cpp b/services/surfaceflinger/BufferStateLayer.cpp
index e0804ff..4a8261d 100644
--- a/services/surfaceflinger/BufferStateLayer.cpp
+++ b/services/surfaceflinger/BufferStateLayer.cpp
@@ -87,6 +87,14 @@
             break;
         }
     }
+
+    // Prevent tracing the same release multiple times.
+    if (mPreviousFrameNumber != mPreviousReleasedFrameNumber) {
+        mFlinger->mTimeStats->traceFence(getSequence(), mPreviousBufferId, mPreviousFrameNumber,
+                                         std::make_shared<FenceTime>(releaseFence),
+                                         TimeStats::FrameEvent::RELEASE_FENCE);
+        mPreviousReleasedFrameNumber = mPreviousFrameNumber;
+    }
 }
 
 void BufferStateLayer::setTransformHint(uint32_t /*orientation*/) const {
@@ -226,7 +234,11 @@
     mCurrentState.modified = true;
     setTransactionFlags(eTransactionNeeded);
 
-    mFlinger->mTimeStats->setPostTime(getSequence(), mFrameNumber, getName().c_str(), postTime);
+    const int32_t layerID = getSequence();
+    mFlinger->mTimeStats->setPostTime(layerID, mFrameNumber, getName().c_str(), postTime);
+    mFlinger->mTimeStats->traceNewLayer(layerID, getName().c_str());
+    mFlinger->mTimeStats->traceTimestamp(layerID, buffer->getId(), mFrameNumber, postTime,
+                                         TimeStats::FrameEvent::POST);
     mCurrentState.desiredPresentTime = desiredPresentTime;
 
     if (mFlinger->mUseSmart90ForVideo) {
@@ -561,8 +573,13 @@
         }
     }
 
+    const uint64_t bufferID = getCurrentBufferId();
     mFlinger->mTimeStats->setAcquireFence(layerID, mFrameNumber, getCurrentFenceTime());
+    mFlinger->mTimeStats->traceFence(layerID, bufferID, mFrameNumber, getCurrentFenceTime(),
+                                     TimeStats::FrameEvent::ACQUIRE_FENCE);
     mFlinger->mTimeStats->setLatchTime(layerID, mFrameNumber, latchTime);
+    mFlinger->mTimeStats->traceTimestamp(layerID, bufferID, mFrameNumber, latchTime,
+                                         TimeStats::FrameEvent::LATCH);
 
     mCurrentStateModified = false;
 
@@ -576,6 +593,7 @@
         return BAD_VALUE;
     }
 
+    mPreviousBufferId = getCurrentBufferId();
     mActiveBuffer = s.buffer;
     mActiveBufferFence = s.acquireFence;
     auto& layerCompositionState = getCompositionLayer()->editState().frontEnd;
@@ -586,6 +604,7 @@
 
 status_t BufferStateLayer::updateFrameNumber(nsecs_t /*latchTime*/) {
     // TODO(marissaw): support frame history events
+    mPreviousFrameNumber = mCurrentFrameNumber;
     mCurrentFrameNumber = mFrameNumber;
     return NO_ERROR;
 }