commit baac04adddccceb84b88d200c5fcb2c9dbb677df
author Adithya Srinivasan <adsrini@google.com> Fri Jun 19 14:57:06 2020 -0700
committer Adithya Srinivasan <adsrini@google.com> Fri Jul 17 19:01:52 2020 +0000
tree 831f0d9d24693d0b6a150f4976c1016f1ac5e192
parent 56892df0aa2edcfd2f0a00a1aad402a615cdebc5

Trace acquire fence at queue time instead of at latch time

For apps that do not use frame pacing, there is a chance that they keep
dequeueing and queueing a buffer before the SF wake up. In this case,
the older queue item gets dropped by SurfaceFlinger if the expected present
time of the later submitted buffer gets satisfied. The GPU work still
happens for all the submissions however. The acquire fence gets signalled
whenever GPU is done with such work. We currently do not trace this
acquirefence and instead, we trace only the one that gets latched by
flinger. This behavior can break the new phases UI where the slices are
formed based on certain assumptions. This change fixes that by tracing
AcquireFence at queue time instead of latch time.

Test: Take a trace with blur enabled.
Bug: 159472563
Change-Id: I329a11c53dc18eb5d03df096c19dba5c9704ea4a
(cherry picked from commit f1e87abccf9b394ab903579c5e0b6ffe3d5da7b4)

services/surfaceflinger/BufferQueueLayer.cpp

diff --git a/services/surfaceflinger/BufferQueueLayer.cpp b/services/surfaceflinger/BufferQueueLayer.cpp
index 07be791..6e4235e 100644
--- a/services/surfaceflinger/BufferQueueLayer.cpp
+++ b/services/surfaceflinger/BufferQueueLayer.cpp
@@ -324,9 +324,6 @@
         }
 
         uint64_t bufferID = mQueueItems[0].mGraphicBuffer->getId();
-        mFlinger->mFrameTracer->traceFence(layerId, bufferID, currentFrameNumber,
-                                           mQueueItems[0].mFenceTime,
-                                           FrameTracer::FrameEvent::ACQUIRE_FENCE);
         mFlinger->mTimeStats->setLatchTime(layerId, currentFrameNumber, latchTime);
         mFlinger->mFrameTracer->traceTimestamp(layerId, bufferID, currentFrameNumber, latchTime,
                                                FrameTracer::FrameEvent::LATCH);
@@ -393,8 +390,12 @@
 
 void BufferQueueLayer::onFrameAvailable(const BufferItem& item) {
     const int32_t layerId = getSequence();
-    mFlinger->mFrameTracer->traceTimestamp(layerId, item.mGraphicBuffer->getId(), item.mFrameNumber,
-                                           systemTime(), FrameTracer::FrameEvent::QUEUE);
+    const uint64_t bufferId = item.mGraphicBuffer->getId();
+    mFlinger->mFrameTracer->traceTimestamp(layerId, bufferId, item.mFrameNumber, systemTime(),
+                                           FrameTracer::FrameEvent::QUEUE);
+    mFlinger->mFrameTracer->traceFence(layerId, bufferId, item.mFrameNumber,
+                                       std::make_shared<FenceTime>(item.mFence),
+                                       FrameTracer::FrameEvent::ACQUIRE_FENCE);
 
     ATRACE_CALL();
     // Add this buffer from our internal queue tracker
@@ -460,8 +461,12 @@
     }
 
     const int32_t layerId = getSequence();
-    mFlinger->mFrameTracer->traceTimestamp(layerId, item.mGraphicBuffer->getId(), item.mFrameNumber,
-                                           systemTime(), FrameTracer::FrameEvent::QUEUE);
+    const uint64_t bufferId = item.mGraphicBuffer->getId();
+    mFlinger->mFrameTracer->traceTimestamp(layerId, bufferId, item.mFrameNumber, systemTime(),
+                                           FrameTracer::FrameEvent::QUEUE);
+    mFlinger->mFrameTracer->traceFence(layerId, bufferId, item.mFrameNumber,
+                                       std::make_shared<FenceTime>(item.mFence),
+                                       FrameTracer::FrameEvent::ACQUIRE_FENCE);
     mConsumer->onBufferAvailable(item);
 }