Added trace data for latch and release buffers
It's helpful to see the specific layer and frame number that is being
latched and released in SF to ensure we can trace where buffers go.
Additionally, added new traces to BBQ where it could be flushing buffers
or waiting until there's a free buffer
Test: perfetto trace
Bug: 238328090
Change-Id: I88fa6db62092438ed7ada12c3f0740dc3ac282d5
diff --git a/libs/gui/BLASTBufferQueue.cpp b/libs/gui/BLASTBufferQueue.cpp
index 2212e58..3bf2e19 100644
--- a/libs/gui/BLASTBufferQueue.cpp
+++ b/libs/gui/BLASTBufferQueue.cpp
@@ -599,6 +599,7 @@
}
void BLASTBufferQueue::acquireAndReleaseBuffer() {
+ BBQ_TRACE();
BufferItem bufferItem;
status_t status =
mBufferItemConsumer->acquireBuffer(&bufferItem, 0 /* expectedPresent */, false);
@@ -612,6 +613,7 @@
}
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 @@
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 e5d2684..0009615 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 @@
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 fb15f1d..4ba5e90 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>
@@ -457,7 +458,8 @@
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 d88d7c9..574e2f5 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 @@
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 3f0dbe4..bf98a27 100644
--- a/services/surfaceflinger/BufferStateLayer.h
+++ b/services/surfaceflinger/BufferStateLayer.h
@@ -135,6 +135,11 @@
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;