Blast: Populate compositor timings

Compositor timings are populated in BufferLayer::onPostComposition
but the callback handles were cleared before in
BufferStateLayer::releasePendingBuffer. Fix the ordering and add a
test.

Test: atest BLASTFrameEventHistoryTest
Fixes: 191247797
Change-Id: I5f93ed7f80cdcb4c0c6763fa37bad5e77588a20a
diff --git a/libs/gui/include/gui/FrameTimestamps.h b/libs/gui/include/gui/FrameTimestamps.h
index 0750080..dd3de58 100644
--- a/libs/gui/include/gui/FrameTimestamps.h
+++ b/libs/gui/include/gui/FrameTimestamps.h
@@ -131,6 +131,7 @@
     // Public for testing.
     static nsecs_t snapToNextTick(
             nsecs_t timestamp, nsecs_t tickPhase, nsecs_t tickInterval);
+    nsecs_t getReportedCompositeDeadline() const { return mCompositorTiming.deadline; };
 
     nsecs_t getNextCompositeDeadline(const nsecs_t now) const;
     nsecs_t getCompositeInterval() const { return mCompositorTiming.interval; }
diff --git a/libs/gui/tests/BLASTBufferQueue_test.cpp b/libs/gui/tests/BLASTBufferQueue_test.cpp
index 06660b8..7ed4023 100644
--- a/libs/gui/tests/BLASTBufferQueue_test.cpp
+++ b/libs/gui/tests/BLASTBufferQueue_test.cpp
@@ -1075,4 +1075,31 @@
     ASSERT_GE(events->postedTime, postedTimeB);
 }
 
+TEST_F(BLASTFrameEventHistoryTest, FrameEventHistory_CompositorTimings) {
+    BLASTBufferQueueHelper adapter(mSurfaceControl, mDisplayWidth, mDisplayHeight);
+    sp<IGraphicBufferProducer> igbProducer;
+    ProducerFrameEventHistory history;
+    setUpProducer(adapter, igbProducer);
+
+    IGraphicBufferProducer::QueueBufferOutput qbOutput;
+    nsecs_t requestedPresentTimeA = 0;
+    nsecs_t postedTimeA = 0;
+    adapter.setTransactionCompleteCallback(1);
+    setUpAndQueueBuffer(igbProducer, &requestedPresentTimeA, &postedTimeA, &qbOutput, true);
+    history.applyDelta(qbOutput.frameTimestamps);
+    adapter.waitForCallback(1);
+
+    // queue another buffer so we query for frame event deltas
+    nsecs_t requestedPresentTimeB = 0;
+    nsecs_t postedTimeB = 0;
+    setUpAndQueueBuffer(igbProducer, &requestedPresentTimeB, &postedTimeB, &qbOutput, true);
+    history.applyDelta(qbOutput.frameTimestamps);
+
+    // check for a valid compositor deadline
+    ASSERT_NE(0, history.getReportedCompositeDeadline());
+
+    // wait for any callbacks that have not been received
+    adapter.waitForCallbacks();
+}
+
 } // namespace android
diff --git a/services/surfaceflinger/SurfaceFlinger.cpp b/services/surfaceflinger/SurfaceFlinger.cpp
index e7187b1..23fb102 100644
--- a/services/surfaceflinger/SurfaceFlinger.cpp
+++ b/services/surfaceflinger/SurfaceFlinger.cpp
@@ -2231,18 +2231,15 @@
 
     getBE().mDisplayTimeline.push(mPreviousPresentFences[0].fenceTime);
 
+    nsecs_t now = systemTime();
+
     // Set presentation information before calling Layer::releasePendingBuffer, such that jank
     // information from previous' frame classification is already available when sending jank info
     // to clients, so they get jank classification as early as possible.
-    mFrameTimeline->setSfPresent(systemTime(), mPreviousPresentFences[0].fenceTime,
+    mFrameTimeline->setSfPresent(/* sfPresentTime */ now, mPreviousPresentFences[0].fenceTime,
                                  glCompositionDoneFenceTime);
 
-    nsecs_t dequeueReadyTime = systemTime();
-    for (const auto& layer : mLayersWithQueuedFrames) {
-        layer->releasePendingBuffer(dequeueReadyTime);
-    }
-
-    const DisplayStatInfo stats = mScheduler->getDisplayStatInfo(systemTime());
+    const DisplayStatInfo stats = mScheduler->getDisplayStatInfo(now);
 
     // We use the CompositionEngine::getLastFrameRefreshTimestamp() which might
     // be sampled a little later than when we started doing work for this frame,
@@ -2259,6 +2256,7 @@
         const bool frameLatched =
                 layer->onPostComposition(display, glCompositionDoneFenceTime,
                                          mPreviousPresentFences[0].fenceTime, compositorTiming);
+        layer->releasePendingBuffer(/*dequeueReadyTime*/ now);
         if (frameLatched) {
             recordBufferingStats(layer->getName(), layer->getOccupancyHistory(false));
         }
@@ -4467,10 +4465,11 @@
     d.height = 0;
     displays.add(d);
 
+    nsecs_t now = systemTime();
     // It should be on the main thread, apply it directly.
     applyTransactionState(FrameTimelineInfo{}, state, displays, 0, mInputWindowCommands,
-                          systemTime(), true, {}, systemTime(), true, false, {}, getpid(), getuid(),
-                          0 /* Undefined transactionId */);
+                          /* desiredPresentTime */ now, true, {}, /* postTime */ now, true, false,
+                          {}, getpid(), getuid(), 0 /* Undefined transactionId */);
 
     setPowerModeInternal(display, hal::PowerMode::ON);
     const nsecs_t vsyncPeriod = mRefreshRateConfigs->getCurrentRefreshRate().getVsyncPeriod();