BlastBufferQueue: Pass client dequeue times to SurfaceFlinger

SF keeps track of client dequeue, queue, acquire etc. timestamps to
construct frame rendering timelines for developers. With BBQ, SF no
longer has access to this data, so pass the dequeue time along with
the buffers.

Ideally this data should flow to the perfetto trace directly from the client
but this is a temp solution while some perf issues with client logging
is sorted out.

Bug: 176931912
Test: manual tests
Change-Id: Ic88170c1fb20850662cb99325ac42b7232a02817
diff --git a/aidl/gui/android/view/LayerMetadataKey.aidl b/aidl/gui/android/view/LayerMetadataKey.aidl
index 491c629..a1d8ce5 100644
--- a/aidl/gui/android/view/LayerMetadataKey.aidl
+++ b/aidl/gui/android/view/LayerMetadataKey.aidl
@@ -25,4 +25,5 @@
     METADATA_MOUSE_CURSOR = 4,
     METADATA_ACCESSIBILITY_ID = 5,
     METADATA_OWNER_PID = 6,
+    METADATA_DEQUEUE_TIME = 7,
 }
diff --git a/libs/gui/BLASTBufferQueue.cpp b/libs/gui/BLASTBufferQueue.cpp
index eaa47f9..f4b5a26 100644
--- a/libs/gui/BLASTBufferQueue.cpp
+++ b/libs/gui/BLASTBufferQueue.cpp
@@ -354,6 +354,16 @@
         t->setAutoRefresh(mSurfaceControl, bufferItem.mAutoRefresh);
         mAutoRefresh = bufferItem.mAutoRefresh;
     }
+    {
+        std::unique_lock _lock{mTimestampMutex};
+        auto dequeueTime = mDequeueTimestamps.find(buffer->getId());
+        if (dequeueTime != mDequeueTimestamps.end()) {
+            Parcel p;
+            p.writeInt64(dequeueTime->second);
+            t->setMetadata(mSurfaceControl, METADATA_DEQUEUE_TIME, p);
+            mDequeueTimestamps.erase(dequeueTime);
+        }
+    }
 
     auto mergeTransaction =
             [&t, currentFrameNumber = bufferItem.mFrameNumber](
@@ -412,6 +422,16 @@
     // Do nothing since we are not storing unacquired buffer items locally.
 }
 
+void BLASTBufferQueue::onFrameDequeued(const uint64_t bufferId) {
+    std::unique_lock _lock{mTimestampMutex};
+    mDequeueTimestamps[bufferId] = systemTime();
+};
+
+void BLASTBufferQueue::onFrameCancelled(const uint64_t bufferId) {
+    std::unique_lock _lock{mTimestampMutex};
+    mDequeueTimestamps.erase(bufferId);
+};
+
 void BLASTBufferQueue::setNextTransaction(SurfaceComposerClient::Transaction* t) {
     std::lock_guard _lock{mMutex};
     mNextTransaction = t;
diff --git a/libs/gui/LayerMetadata.cpp b/libs/gui/LayerMetadata.cpp
index 30c9b37..634d8b7 100644
--- a/libs/gui/LayerMetadata.cpp
+++ b/libs/gui/LayerMetadata.cpp
@@ -17,6 +17,7 @@
 #include <android-base/stringprintf.h>
 #include <binder/Parcel.h>
 #include <gui/LayerMetadata.h>
+#include <inttypes.h>
 
 #include "android/view/LayerMetadataKey.h"
 
@@ -113,6 +114,15 @@
     memcpy(data.data(), p.data(), p.dataSize());
 }
 
+std::optional<int64_t> LayerMetadata::getInt64(uint32_t key) const {
+    if (!has(key)) return std::nullopt;
+    const std::vector<uint8_t>& data = mMap.at(key);
+    if (data.size() < sizeof(int64_t)) return std::nullopt;
+    Parcel p;
+    p.setData(data.data(), data.size());
+    return p.readInt64();
+}
+
 std::string LayerMetadata::itemToString(uint32_t key, const char* separator) const {
     if (!has(key)) return std::string();
     switch (static_cast<view::LayerMetadataKey>(key)) {
@@ -124,6 +134,8 @@
             return StringPrintf("taskId%s%d", separator, getInt32(key, 0));
         case view::LayerMetadataKey::METADATA_OWNER_PID:
             return StringPrintf("ownerPID%s%d", separator, getInt32(key, 0));
+        case view::LayerMetadataKey::METADATA_DEQUEUE_TIME:
+            return StringPrintf("dequeueTime%s%" PRId64, separator, *getInt64(key));
         default:
             return StringPrintf("%d%s%dbytes", key, separator,
                                 static_cast<int>(mMap.at(key).size()));
diff --git a/libs/gui/include/gui/BLASTBufferQueue.h b/libs/gui/include/gui/BLASTBufferQueue.h
index 1198135..0fbcbdc 100644
--- a/libs/gui/include/gui/BLASTBufferQueue.h
+++ b/libs/gui/include/gui/BLASTBufferQueue.h
@@ -78,6 +78,8 @@
     void onBufferFreed(const wp<GraphicBuffer>&/* graphicBuffer*/) override { /* TODO */ }
     void onFrameReplaced(const BufferItem& item) override;
     void onFrameAvailable(const BufferItem& item) override;
+    void onFrameDequeued(const uint64_t) override;
+    void onFrameCancelled(const uint64_t) override;
 
     void transactionCallback(nsecs_t latchTime, const sp<Fence>& presentFence,
             const std::vector<SurfaceControlStats>& stats);
@@ -168,7 +170,15 @@
 
     // Queues up transactions using this token in SurfaceFlinger. This prevents queued up
     // transactions from other parts of the client from blocking this transaction.
-    const sp<IBinder> mApplyToken = new BBinder();
+    const sp<IBinder> mApplyToken GUARDED_BY(mMutex) = new BBinder();
+
+    // Guards access to mDequeueTimestamps since we cannot hold to mMutex in onFrameDequeued or
+    // we will deadlock.
+    std::mutex mTimestampMutex;
+    // Tracks buffer dequeue times by the client. This info is sent to SurfaceFlinger which uses
+    // it for debugging purposes.
+    std::unordered_map<uint64_t /* bufferId */, nsecs_t> mDequeueTimestamps
+            GUARDED_BY(mTimestampMutex);
 };
 
 } // namespace android
diff --git a/libs/gui/include/gui/LayerMetadata.h b/libs/gui/include/gui/LayerMetadata.h
index ac48aef..41982c2 100644
--- a/libs/gui/include/gui/LayerMetadata.h
+++ b/libs/gui/include/gui/LayerMetadata.h
@@ -29,6 +29,7 @@
     METADATA_MOUSE_CURSOR = 4,
     METADATA_ACCESSIBILITY_ID = 5,
     METADATA_OWNER_PID = 6,
+    METADATA_DEQUEUE_TIME = 7
 };
 
 struct LayerMetadata : public Parcelable {
@@ -51,6 +52,8 @@
     bool has(uint32_t key) const;
     int32_t getInt32(uint32_t key, int32_t fallback) const;
     void setInt32(uint32_t key, int32_t value);
+    std::optional<int64_t> getInt64(uint32_t key) const;
+    void setInt64(uint32_t key, int64_t value);
 
     std::string itemToString(uint32_t key, const char* separator) const;
 };
diff --git a/services/surfaceflinger/BufferStateLayer.cpp b/services/surfaceflinger/BufferStateLayer.cpp
index bca1c69..a431028 100644
--- a/services/surfaceflinger/BufferStateLayer.cpp
+++ b/services/surfaceflinger/BufferStateLayer.cpp
@@ -343,7 +343,8 @@
 
 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) {
+                                 const client_cache_t& clientCacheId, uint64_t frameNumber,
+                                 std::optional<nsecs_t> /* dequeueTime */) {
     ATRACE_CALL();
 
     if (mCurrentState.buffer) {
diff --git a/services/surfaceflinger/BufferStateLayer.h b/services/surfaceflinger/BufferStateLayer.h
index 6414e6b..1098606 100644
--- a/services/surfaceflinger/BufferStateLayer.h
+++ b/services/surfaceflinger/BufferStateLayer.h
@@ -71,7 +71,8 @@
     bool setFrame(const Rect& frame) override;
     bool 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) override;
+                   const client_cache_t& clientCacheId, uint64_t frameNumber,
+                   std::optional<nsecs_t> dequeueTime) override;
     bool setAcquireFence(const sp<Fence>& fence) override;
     bool setDataspace(ui::Dataspace dataspace) override;
     bool setHdrMetadata(const HdrMetadata& hdrMetadata) override;
diff --git a/services/surfaceflinger/Layer.h b/services/surfaceflinger/Layer.h
index d6023b6..f78b5f3 100644
--- a/services/surfaceflinger/Layer.h
+++ b/services/surfaceflinger/Layer.h
@@ -446,7 +446,7 @@
     virtual bool 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 */) {
+                           uint64_t /* frameNumber */, std::optional<nsecs_t> /* dequeueTime */) {
         return false;
     };
     virtual bool setAcquireFence(const sp<Fence>& /*fence*/) { return false; };
diff --git a/services/surfaceflinger/RefreshRateOverlay.cpp b/services/surfaceflinger/RefreshRateOverlay.cpp
index 6a511a8..32110e9 100644
--- a/services/surfaceflinger/RefreshRateOverlay.cpp
+++ b/services/surfaceflinger/RefreshRateOverlay.cpp
@@ -237,7 +237,8 @@
     mCurrentFps = refreshRate.getFps().getIntValue();
     auto buffer = getOrCreateBuffers(*mCurrentFps)[mFrame];
     mLayer->setBuffer(buffer, Fence::NO_FENCE, 0, 0, true, {},
-                      mLayer->getHeadFrameNumber(-1 /* expectedPresentTime */));
+                      mLayer->getHeadFrameNumber(-1 /* expectedPresentTime */),
+                      std::nullopt /* dequeueTime */);
 
     mFlinger.mTransactionFlags.fetch_or(eTransactionMask);
 }
@@ -249,7 +250,8 @@
     mFrame = (mFrame + 1) % buffers.size();
     auto buffer = buffers[mFrame];
     mLayer->setBuffer(buffer, Fence::NO_FENCE, 0, 0, true, {},
-                      mLayer->getHeadFrameNumber(-1 /* expectedPresentTime */));
+                      mLayer->getHeadFrameNumber(-1 /* expectedPresentTime */),
+                      std::nullopt /* dequeueTime */);
 
     mFlinger.mTransactionFlags.fetch_or(eTransactionMask);
 }
diff --git a/services/surfaceflinger/SurfaceFlinger.cpp b/services/surfaceflinger/SurfaceFlinger.cpp
index 6967f69..6938d5d 100644
--- a/services/surfaceflinger/SurfaceFlinger.cpp
+++ b/services/surfaceflinger/SurfaceFlinger.cpp
@@ -3840,7 +3840,9 @@
             ALOGE("Attempt to update InputWindowInfo without permission ACCESS_SURFACE_FLINGER");
         }
     }
+    std::optional<nsecs_t> dequeueBufferTimestamp;
     if (what & layer_state_t::eMetadataChanged) {
+        dequeueBufferTimestamp = s.metadata.getInt64(METADATA_DEQUEUE_TIME);
         if (layer->setMetadata(s.metadata)) flags |= eTraversalNeeded;
     }
     if (what & layer_state_t::eColorSpaceAgnosticChanged) {
@@ -3928,7 +3930,7 @@
                 : layer->getHeadFrameNumber(-1 /* expectedPresentTime */) + 1;
 
         if (layer->setBuffer(buffer, s.acquireFence, postTime, desiredPresentTime, isAutoTimestamp,
-                             s.cachedBuffer, frameNumber)) {
+                             s.cachedBuffer, frameNumber, dequeueBufferTimestamp)) {
             flags |= eTraversalNeeded;
         }
     }