Fix broken FrameLifecycle due to Blast adapter

Since the BLASTBQ adapter removed the BQ path from SurfaceViews to
SurfaecFlinger, FrameLifecycle is completely broken as it works only for
BQ so far. This change adds FrameLifecycle coverage to BLAST buffers
that send dequeueTime along with the Transaction.

Bug: 176931912
Test: TransactionFrameTracerTest
Test: Take a trace of any game and make sure Frame Lifecycle events show
up.

Change-Id: I1429c86f2890c3ff8e5a06d6136df0282cf439ea
diff --git a/services/surfaceflinger/BufferStateLayer.cpp b/services/surfaceflinger/BufferStateLayer.cpp
index e470eb9..076c707 100644
--- a/services/surfaceflinger/BufferStateLayer.cpp
+++ b/services/surfaceflinger/BufferStateLayer.cpp
@@ -35,6 +35,7 @@
 #include <renderengine/Image.h>
 
 #include "EffectLayer.h"
+#include "FrameTracer/FrameTracer.h"
 #include "TimeStats/TimeStats.h"
 
 namespace android {
@@ -337,7 +338,7 @@
 bool BufferStateLayer::setBuffer(const sp<GraphicBuffer>& buffer, const sp<Fence>& acquireFence,
                                  nsecs_t postTime, nsecs_t desiredPresentTime, bool isAutoTimestamp,
                                  const client_cache_t& clientCacheId, uint64_t frameNumber,
-                                 std::optional<nsecs_t> /* dequeueTime */,
+                                 std::optional<nsecs_t> dequeueTime,
                                  const FrameTimelineInfo& info) {
     ATRACE_CALL();
 
@@ -377,6 +378,14 @@
         setFrameTimelineVsyncForBufferTransaction(info, postTime);
     }
 
+    if (dequeueTime && *dequeueTime != 0) {
+        const uint64_t bufferId = buffer->getId();
+        mFlinger->mFrameTracer->traceNewLayer(layerId, getName().c_str());
+        mFlinger->mFrameTracer->traceTimestamp(layerId, bufferId, frameNumber, *dequeueTime,
+                                               FrameTracer::FrameEvent::DEQUEUE);
+        mFlinger->mFrameTracer->traceTimestamp(layerId, bufferId, frameNumber, postTime,
+                                               FrameTracer::FrameEvent::QUEUE);
+    }
     return true;
 }
 
@@ -628,9 +637,16 @@
     }
 
     const int32_t layerId = getSequence();
-    mFlinger->mTimeStats->setAcquireFence(layerId, mDrawingState.frameNumber,
-                                          std::make_shared<FenceTime>(mDrawingState.acquireFence));
-    mFlinger->mTimeStats->setLatchTime(layerId, mDrawingState.frameNumber, latchTime);
+    const uint64_t bufferId = mDrawingState.buffer->getId();
+    const uint64_t frameNumber = mDrawingState.frameNumber;
+    const auto acquireFence = std::make_shared<FenceTime>(mDrawingState.acquireFence);
+    mFlinger->mTimeStats->setAcquireFence(layerId, frameNumber, acquireFence);
+    mFlinger->mTimeStats->setLatchTime(layerId, frameNumber, latchTime);
+
+    mFlinger->mFrameTracer->traceFence(layerId, bufferId, frameNumber, acquireFence,
+                                       FrameTracer::FrameEvent::ACQUIRE_FENCE);
+    mFlinger->mFrameTracer->traceTimestamp(layerId, bufferId, frameNumber, latchTime,
+                                           FrameTracer::FrameEvent::LATCH);
 
     auto& bufferSurfaceFrame = mDrawingState.bufferSurfaceFrameTX;
     if (bufferSurfaceFrame != nullptr &&
diff --git a/services/surfaceflinger/BufferStateLayer.h b/services/surfaceflinger/BufferStateLayer.h
index ea832a2..175a40b 100644
--- a/services/surfaceflinger/BufferStateLayer.h
+++ b/services/surfaceflinger/BufferStateLayer.h
@@ -124,6 +124,7 @@
 
 private:
     friend class SlotGenerationTest;
+    friend class TransactionFrameTracerTest;
     friend class TransactionSurfaceFrameTest;
 
     inline void tracePendingBufferCount();
diff --git a/services/surfaceflinger/Layer.h b/services/surfaceflinger/Layer.h
index 9cd15e8..4c2fd44 100644
--- a/services/surfaceflinger/Layer.h
+++ b/services/surfaceflinger/Layer.h
@@ -1004,6 +1004,7 @@
     friend class TestableSurfaceFlinger;
     friend class RefreshRateSelectionTest;
     friend class SetFrameRateTest;
+    friend class TransactionFrameTracerTest;
     friend class TransactionSurfaceFrameTest;
 
     virtual void setInitialValuesForClone(const sp<Layer>& clonedFrom);
diff --git a/services/surfaceflinger/tests/unittests/Android.bp b/services/surfaceflinger/tests/unittests/Android.bp
index 17928a0..e55821f 100644
--- a/services/surfaceflinger/tests/unittests/Android.bp
+++ b/services/surfaceflinger/tests/unittests/Android.bp
@@ -73,6 +73,7 @@
         "FrameTracerTest.cpp",
         "TimerTest.cpp",
         "TransactionApplicationTest.cpp",
+        "TransactionFrameTracerTest.cpp",
         "TransactionSurfaceFrameTest.cpp",
         "StrongTypingTest.cpp",
         "VSyncDispatchTimerQueueTest.cpp",
diff --git a/services/surfaceflinger/tests/unittests/TestableSurfaceFlinger.h b/services/surfaceflinger/tests/unittests/TestableSurfaceFlinger.h
index 3787c43..a94b9bd 100644
--- a/services/surfaceflinger/tests/unittests/TestableSurfaceFlinger.h
+++ b/services/surfaceflinger/tests/unittests/TestableSurfaceFlinger.h
@@ -405,6 +405,10 @@
 
     const auto& getCompositorTiming() const { return mFlinger->getBE().mCompositorTiming; }
 
+    mock::FrameTracer* getFrameTracer() const {
+        return static_cast<mock::FrameTracer*>(mFlinger->mFrameTracer.get());
+    }
+
     /* ------------------------------------------------------------------------
      * Read-write access to private data to set up preconditions and assert
      * post-conditions.
diff --git a/services/surfaceflinger/tests/unittests/TransactionFrameTracerTest.cpp b/services/surfaceflinger/tests/unittests/TransactionFrameTracerTest.cpp
new file mode 100644
index 0000000..dbadf75
--- /dev/null
+++ b/services/surfaceflinger/tests/unittests/TransactionFrameTracerTest.cpp
@@ -0,0 +1,153 @@
+/*
+ * Copyright (C) 2021 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#undef LOG_TAG
+#define LOG_TAG "LibSurfaceFlingerUnittests"
+
+#include <gmock/gmock.h>
+#include <gtest/gtest.h>
+#include <gui/SurfaceComposerClient.h>
+#include <log/log.h>
+#include <utils/String8.h>
+
+#include "TestableSurfaceFlinger.h"
+#include "mock/DisplayHardware/MockComposer.h"
+#include "mock/MockEventThread.h"
+#include "mock/MockVsyncController.h"
+
+namespace android {
+
+using testing::_;
+using testing::Mock;
+using testing::Return;
+using FakeHwcDisplayInjector = TestableSurfaceFlinger::FakeHwcDisplayInjector;
+using PresentState = frametimeline::SurfaceFrame::PresentState;
+
+class TransactionFrameTracerTest : public testing::Test {
+public:
+    TransactionFrameTracerTest() {
+        const ::testing::TestInfo* const test_info =
+                ::testing::UnitTest::GetInstance()->current_test_info();
+        ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
+        setupScheduler();
+        setupComposer(0);
+    }
+
+    ~TransactionFrameTracerTest() {
+        const ::testing::TestInfo* const test_info =
+                ::testing::UnitTest::GetInstance()->current_test_info();
+        ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
+    }
+
+    sp<BufferStateLayer> createBufferStateLayer() {
+        sp<Client> client;
+        LayerCreationArgs args(mFlinger.flinger(), client, "buffer-state-layer", 100, 100, 0,
+                               LayerMetadata());
+        return new BufferStateLayer(args);
+    }
+
+    void commitTransaction(Layer* layer) {
+        layer->pushPendingState();
+        auto c = layer->getCurrentState();
+        if (layer->applyPendingStates(&c)) {
+            layer->commitTransaction(c);
+        }
+    }
+
+    void setupScheduler() {
+        auto eventThread = std::make_unique<mock::EventThread>();
+        auto sfEventThread = std::make_unique<mock::EventThread>();
+
+        EXPECT_CALL(*eventThread, registerDisplayEventConnection(_));
+        EXPECT_CALL(*eventThread, createEventConnection(_, _))
+                .WillOnce(Return(new EventThreadConnection(eventThread.get(), /*callingUid=*/0,
+                                                           ResyncCallback())));
+
+        EXPECT_CALL(*sfEventThread, registerDisplayEventConnection(_));
+        EXPECT_CALL(*sfEventThread, createEventConnection(_, _))
+                .WillOnce(Return(new EventThreadConnection(sfEventThread.get(), /*callingUid=*/0,
+                                                           ResyncCallback())));
+
+        auto vsyncController = std::make_unique<mock::VsyncController>();
+        auto vsyncTracker = std::make_unique<mock::VSyncTracker>();
+
+        EXPECT_CALL(*vsyncTracker, nextAnticipatedVSyncTimeFrom(_)).WillRepeatedly(Return(0));
+        EXPECT_CALL(*vsyncTracker, currentPeriod())
+                .WillRepeatedly(Return(FakeHwcDisplayInjector::DEFAULT_VSYNC_PERIOD));
+        EXPECT_CALL(*vsyncTracker, nextAnticipatedVSyncTimeFrom(_)).WillRepeatedly(Return(0));
+        mFlinger.setupScheduler(std::move(vsyncController), std::move(vsyncTracker),
+                                std::move(eventThread), std::move(sfEventThread));
+    }
+
+    void setupComposer(uint32_t virtualDisplayCount) {
+        mComposer = new Hwc2::mock::Composer();
+        EXPECT_CALL(*mComposer, getMaxVirtualDisplayCount()).WillOnce(Return(virtualDisplayCount));
+        mFlinger.setupComposer(std::unique_ptr<Hwc2::Composer>(mComposer));
+
+        Mock::VerifyAndClear(mComposer);
+    }
+
+    TestableSurfaceFlinger mFlinger;
+    Hwc2::mock::Composer* mComposer = nullptr;
+    FenceToFenceTimeMap fenceFactory;
+    client_cache_t mClientCache;
+
+    void BLASTTransactionSendsFrameTracerEvents() {
+        sp<BufferStateLayer> layer = createBufferStateLayer();
+
+        sp<Fence> fence(new Fence());
+        sp<GraphicBuffer> buffer{new GraphicBuffer(1, 1, HAL_PIXEL_FORMAT_RGBA_8888, 1, 0)};
+        int32_t layerId = layer->getSequence();
+        uint64_t bufferId = buffer->getId();
+        uint64_t frameNumber = 5;
+        nsecs_t dequeueTime = 10;
+        nsecs_t postTime = 20;
+        EXPECT_CALL(*mFlinger.getFrameTracer(), traceNewLayer(layerId, "buffer-state-layer"));
+        EXPECT_CALL(*mFlinger.getFrameTracer(),
+                    traceTimestamp(layerId, bufferId, frameNumber, dequeueTime,
+                                   FrameTracer::FrameEvent::DEQUEUE, /*duration*/ 0));
+        EXPECT_CALL(*mFlinger.getFrameTracer(),
+                    traceTimestamp(layerId, bufferId, frameNumber, postTime,
+                                   FrameTracer::FrameEvent::QUEUE, /*duration*/ 0));
+        layer->setBuffer(buffer, fence, postTime, /*desiredPresentTime*/ 30, false, mClientCache,
+                         frameNumber, dequeueTime, FrameTimelineInfo{});
+
+        commitTransaction(layer.get());
+        bool computeVisisbleRegions;
+        nsecs_t latchTime = 25;
+        EXPECT_CALL(*mFlinger.getFrameTracer(),
+                    traceFence(layerId, bufferId, frameNumber, _,
+                               FrameTracer::FrameEvent::ACQUIRE_FENCE, /*startTime*/ 0));
+        EXPECT_CALL(*mFlinger.getFrameTracer(),
+                    traceTimestamp(layerId, bufferId, frameNumber, latchTime,
+                                   FrameTracer::FrameEvent::LATCH, /*duration*/ 0));
+        layer->updateTexImage(computeVisisbleRegions, latchTime, /*expectedPresentTime*/ 0);
+
+        auto glDoneFence = fenceFactory.createFenceTimeForTest(fence);
+        auto presentFence = fenceFactory.createFenceTimeForTest(fence);
+        CompositorTiming compositorTiming;
+        EXPECT_CALL(*mFlinger.getFrameTracer(),
+                    traceFence(layerId, bufferId, frameNumber, presentFence,
+                               FrameTracer::FrameEvent::PRESENT_FENCE, /*startTime*/ 0));
+        layer->onPostComposition(nullptr, glDoneFence, presentFence, compositorTiming);
+    }
+};
+
+TEST_F(TransactionFrameTracerTest, BLASTTransactionSendsFrameTracerEvents) {
+    BLASTTransactionSendsFrameTracerEvents();
+}
+
+} // namespace android
\ No newline at end of file