From 57ae4b20546df7666303fd649bd49ab89a3bcc7f Mon Sep 17 00:00:00 2001
From: chaviw <chaviw@google.com>
Date: Thu, 3 Feb 2022 16:51:39 -0600
Subject: Add more info in BBQ Tracing

Added the buffer name, mNumFrameAvailable,  mNumAcquired to all
traces in BBQ.

Also added frameNum for acquire and release to help match up when the
release is called.

Test: Trace shows new data
Bug: 217621394
Change-Id: I86bf0c12741a2651bb3802c6142ac341b0fb362e
---
 libs/gui/BLASTBufferQueue.cpp | 18 +++++++++++++-----
 1 file changed, 13 insertions(+), 5 deletions(-)

(limited to 'libs/gui/BLASTBufferQueue.cpp')

diff --git a/libs/gui/BLASTBufferQueue.cpp b/libs/gui/BLASTBufferQueue.cpp
index dd966837f4..aeb237deb4 100644
--- a/libs/gui/BLASTBufferQueue.cpp
+++ b/libs/gui/BLASTBufferQueue.cpp
@@ -28,6 +28,7 @@
 #include <gui/GLConsumer.h>
 #include <gui/IProducerListener.h>
 #include <gui/Surface.h>
+#include <gui/TraceUtils.h>
 #include <utils/Singleton.h>
 #include <utils/Trace.h>
 
@@ -57,6 +58,10 @@ namespace android {
 #define BQA_LOGE(x, ...) \
     ALOGE("[%s](f:%u,a:%u) " x, mName.c_str(), mNumFrameAvailable, mNumAcquired, ##__VA_ARGS__)
 
+#define BBQ_TRACE(x, ...)                                                                  \
+    ATRACE_FORMAT("%s - %s(f:%u,a:%u)" x, __FUNCTION__, mName.c_str(), mNumFrameAvailable, \
+                  mNumAcquired, ##__VA_ARGS__)
+
 void BLASTBufferItemConsumer::onDisconnect() {
     Mutex::Autolock lock(mMutex);
     mPreviouslyConnected = mCurrentlyConnected;
@@ -254,7 +259,7 @@ void BLASTBufferQueue::transactionCommittedCallback(nsecs_t /*latchTime*/,
                                                     const std::vector<SurfaceControlStats>& stats) {
     {
         std::unique_lock _lock{mMutex};
-        ATRACE_CALL();
+        BBQ_TRACE();
         BQA_LOGV("transactionCommittedCallback");
         if (!mSurfaceControlsWithPendingCallback.empty()) {
             sp<SurfaceControl> pendingSC = mSurfaceControlsWithPendingCallback.front();
@@ -304,7 +309,7 @@ void BLASTBufferQueue::transactionCallback(nsecs_t /*latchTime*/, const sp<Fence
                                            const std::vector<SurfaceControlStats>& stats) {
     {
         std::unique_lock _lock{mMutex};
-        ATRACE_CALL();
+        BBQ_TRACE();
         BQA_LOGV("transactionCallback");
 
         if (!mSurfaceControlsWithPendingCallback.empty()) {
@@ -367,7 +372,7 @@ void BLASTBufferQueue::flushShadowQueue() {
 void BLASTBufferQueue::releaseBufferCallback(
         const ReleaseCallbackId& id, const sp<Fence>& releaseFence,
         std::optional<uint32_t> currentMaxAcquiredBufferCount) {
-    ATRACE_CALL();
+    BBQ_TRACE();
     std::unique_lock _lock{mMutex};
     BQA_LOGV("releaseBufferCallback %s", id.to_string().c_str());
 
@@ -415,6 +420,7 @@ void BLASTBufferQueue::releaseBuffer(const ReleaseCallbackId& callbackId,
         return;
     }
     mNumAcquired--;
+    BBQ_TRACE("frame=%" PRIu64, callbackId.framenumber);
     BQA_LOGV("released %s", callbackId.to_string().c_str());
     mBufferItemConsumer->releaseBuffer(it->second, releaseFence);
     mSubmitted.erase(it);
@@ -422,7 +428,6 @@ void BLASTBufferQueue::releaseBuffer(const ReleaseCallbackId& callbackId,
 
 void BLASTBufferQueue::acquireNextBufferLocked(
         const std::optional<SurfaceComposerClient::Transaction*> transaction) {
-    ATRACE_CALL();
     // If the next transaction is set, we want to guarantee the our acquire will not fail, so don't
     // include the extra buffer when checking if we can acquire the next buffer.
     const bool includeExtraAcquire = !transaction;
@@ -456,8 +461,10 @@ void BLASTBufferQueue::acquireNextBufferLocked(
         BQA_LOGE("Failed to acquire a buffer, err=%s", statusToString(status).c_str());
         return;
     }
+
     auto buffer = bufferItem.mGraphicBuffer;
     mNumFrameAvailable--;
+    BBQ_TRACE("frame=%" PRIu64, bufferItem.mFrameNumber);
 
     if (buffer == nullptr) {
         mBufferItemConsumer->releaseBuffer(bufferItem, Fence::NO_FENCE);
@@ -600,7 +607,7 @@ void BLASTBufferQueue::flushAndWaitForFreeBuffer(std::unique_lock<std::mutex>& l
 }
 
 void BLASTBufferQueue::onFrameAvailable(const BufferItem& item) {
-    ATRACE_CALL();
+    BBQ_TRACE();
     std::unique_lock _lock{mMutex};
 
     const bool syncTransactionSet = mSyncTransaction != nullptr;
@@ -674,6 +681,7 @@ void BLASTBufferQueue::onFrameCancelled(const uint64_t bufferId) {
 
 void BLASTBufferQueue::setSyncTransaction(SurfaceComposerClient::Transaction* t,
                                           bool acquireSingleBuffer) {
+    BBQ_TRACE();
     std::lock_guard _lock{mMutex};
     mSyncTransaction = t;
     mAcquireSingleBuffer = mSyncTransaction ? acquireSingleBuffer : true;
-- 
cgit v1.2.3-59-g8ed1b