Merge "Added trace data for latch and release buffers"

5 files changed, 37 insertions, 8 deletions

diff --git a/libs/gui/BLASTBufferQueue.cpp b/libs/gui/BLASTBufferQueue.cpp
index 2212e58e4d..3bf2e195c5 100644
--- a/libs/gui/BLASTBufferQueue.cpp
+++ b/libs/gui/BLASTBufferQueue.cpp
@@ -599,6 +599,7 @@ Rect BLASTBufferQueue::computeCrop(const BufferItem& item) {
 }
 
 void BLASTBufferQueue::acquireAndReleaseBuffer() {
+    BBQ_TRACE();
     BufferItem bufferItem;
     status_t status =
             mBufferItemConsumer->acquireBuffer(&bufferItem, 0 /* expectedPresent */, false);
@@ -612,6 +613,7 @@ void BLASTBufferQueue::acquireAndReleaseBuffer() {
 }
 
 void BLASTBufferQueue::flushAndWaitForFreeBuffer(std::unique_lock<std::mutex>& lock) {
+    BBQ_TRACE();
     if (!mSyncedFrameNumbers.empty() && mNumFrameAvailable > 0) {
         // We are waiting on a previous sync's transaction callback so allow another sync
         // transaction to proceed.
@@ -642,8 +644,8 @@ void BLASTBufferQueue::onFrameAvailable(const BufferItem& item) {
     bool waitForTransactionCallback = !mSyncedFrameNumbers.empty();
 
     {
-        BBQ_TRACE();
         std::unique_lock _lock{mMutex};
+        BBQ_TRACE();
         const bool syncTransactionSet = mTransactionReadyCallback != nullptr;
         BQA_LOGV("onFrameAvailable-start syncTransactionSet=%s", boolToString(syncTransactionSet));
 
diff --git a/libs/gui/include/gui/TraceUtils.h b/libs/gui/include/gui/TraceUtils.h
index e5d268445c..00096158e7 100644
--- a/libs/gui/include/gui/TraceUtils.h
+++ b/libs/gui/include/gui/TraceUtils.h
@@ -27,6 +27,8 @@
 
 #define ATRACE_FORMAT_BEGIN(fmt, ...) TraceUtils::atraceFormatBegin(fmt, ##__VA_ARGS__)
 
+#define ATRACE_FORMAT_INSTANT(fmt, ...) TraceUtils::intantFormat(fmt, ##__VA_ARGS__)
+
 namespace android {
 
 class TraceUtils {
@@ -50,6 +52,20 @@ public:
         ATRACE_BEGIN(buf);
     }
 
+    static void intantFormat(const char* fmt, ...) {
+        if (CC_LIKELY(!ATRACE_ENABLED())) return;
+
+        const int BUFFER_SIZE = 256;
+        va_list ap;
+        char buf[BUFFER_SIZE];
+
+        va_start(ap, fmt);
+        vsnprintf(buf, BUFFER_SIZE, fmt, ap);
+        va_end(ap);
+
+        ATRACE_INSTANT(buf);
+    }
+
 }; // class TraceUtils
 
 } /* namespace android */
diff --git a/services/surfaceflinger/BufferLayer.cpp b/services/surfaceflinger/BufferLayer.cpp
index 5d7d293580..dd918c5338 100644
--- a/services/surfaceflinger/BufferLayer.cpp
+++ b/services/surfaceflinger/BufferLayer.cpp
@@ -37,6 +37,7 @@
 #include <gui/GLConsumer.h>
 #include <gui/LayerDebugInfo.h>
 #include <gui/Surface.h>
+#include <gui/TraceUtils.h>
 #include <renderengine/RenderEngine.h>
 #include <ui/DebugUtils.h>
 #include <utils/Errors.h>
@@ -456,7 +457,8 @@ bool BufferLayer::shouldPresentNow(nsecs_t expectedPresentTime) const {
 
 bool BufferLayer::latchBuffer(bool& recomputeVisibleRegions, nsecs_t latchTime,
                               nsecs_t expectedPresentTime) {
-    ATRACE_CALL();
+    ATRACE_FORMAT_INSTANT("latchBuffer %s - %" PRIu64, getDebugName(),
+                          getDrawingState().frameNumber);
 
     bool refreshRequired = latchSidebandStream(recomputeVisibleRegions);
 
diff --git a/services/surfaceflinger/BufferStateLayer.cpp b/services/surfaceflinger/BufferStateLayer.cpp
index d88d7c99e9..574e2f5bed 100644
--- a/services/surfaceflinger/BufferStateLayer.cpp
+++ b/services/surfaceflinger/BufferStateLayer.cpp
@@ -30,6 +30,7 @@
 #include <renderengine/Image.h>
 #include "TunnelModeEnabledReporter.h"
 
+#include <gui/TraceUtils.h>
 #include "EffectLayer.h"
 #include "FrameTracer/FrameTracer.h"
 #include "TimeStats/TimeStats.h"
@@ -39,19 +40,20 @@
 namespace android {
 
 using PresentState = frametimeline::SurfaceFrame::PresentState;
-namespace {
-void callReleaseBufferCallback(const sp<ITransactionCompletedListener>& listener,
-                               const sp<GraphicBuffer>& buffer, uint64_t framenumber,
-                               const sp<Fence>& releaseFence,
-                               uint32_t currentMaxAcquiredBufferCount) {
+
+void BufferStateLayer::callReleaseBufferCallback(const sp<ITransactionCompletedListener>& listener,
+                                                 const sp<GraphicBuffer>& buffer,
+                                                 uint64_t framenumber,
+                                                 const sp<Fence>& releaseFence,
+                                                 uint32_t currentMaxAcquiredBufferCount) {
     if (!listener) {
         return;
     }
+    ATRACE_FORMAT_INSTANT("callReleaseBufferCallback %s - %" PRIu64, getDebugName(), framenumber);
     listener->onReleaseBuffer({buffer->getId(), framenumber},
                               releaseFence ? releaseFence : Fence::NO_FENCE,
                               currentMaxAcquiredBufferCount);
 }
-} // namespace
 
 BufferStateLayer::BufferStateLayer(const LayerCreationArgs& args)
       : BufferLayer(args), mHwcSlotGenerator(new HwcSlotGenerator()) {
@@ -145,6 +147,8 @@ void BufferStateLayer::releasePendingBuffer(nsecs_t dequeueReadyTime) {
         handle->dequeueReadyTime = dequeueReadyTime;
         handle->currentMaxAcquiredBufferCount =
                 mFlinger->getMaxAcquiredBufferCountForCurrentRefreshRate(mOwnerUid);
+        ATRACE_FORMAT_INSTANT("releasePendingBuffer %s - %" PRIu64, getDebugName(),
+                              handle->previousReleaseCallbackId.framenumber);
     }
 
     for (auto& handle : mDrawingState.callbackHandles) {
diff --git a/services/surfaceflinger/BufferStateLayer.h b/services/surfaceflinger/BufferStateLayer.h
index 3f0dbe4039..bf98a279a3 100644
--- a/services/surfaceflinger/BufferStateLayer.h
+++ b/services/surfaceflinger/BufferStateLayer.h
@@ -135,6 +135,11 @@ private:
 
     bool simpleBufferUpdate(const layer_state_t& s) const override;
 
+    void callReleaseBufferCallback(const sp<ITransactionCompletedListener>& listener,
+                                   const sp<GraphicBuffer>& buffer, uint64_t framenumber,
+                                   const sp<Fence>& releaseFence,
+                                   uint32_t currentMaxAcquiredBufferCount);
+
     ReleaseCallbackId mPreviousReleaseCallbackId = ReleaseCallbackId::INVALID_ID;
     uint64_t mPreviousReleasedFrameNumber = 0;