From 4d0f1f1ccefd91fe7ef9316d78d72fb4921cab97 Mon Sep 17 00:00:00 2001
From: Bo Liu <boliu@google.com>
Date: Thu, 6 May 2021 16:49:40 -0400
Subject: [PATCH] Ignore blocked-on-sf time for ADPF

Subtract out time spent blocked in dequeueBuffer. Also subtract out any
time UI spents waiting on render thread while render thread is blocked
dequeueBuffer, though this calculation is fairly crude.

Test: Checked bouncyball returns reasonable-ish numbers even when HWUI
      is ahead of surface flinger
Bug: 187556381
Change-Id: I368c446d93990ff8b7b645e30509405ba799c79c
---
 libs/hwui/renderthread/CanvasContext.cpp |  7 ++++---
 libs/hwui/renderthread/CanvasContext.h   |  3 ++-
 libs/hwui/renderthread/DrawFrameTask.cpp | 13 ++++++++++---
 libs/hwui/renderthread/DrawFrameTask.h   |  1 +
 4 files changed, 17 insertions(+), 7 deletions(-)

diff --git a/libs/hwui/renderthread/CanvasContext.cpp b/libs/hwui/renderthread/CanvasContext.cpp
index bba22071ecefd..bae1ab5bab44c 100644
--- a/libs/hwui/renderthread/CanvasContext.cpp
+++ b/libs/hwui/renderthread/CanvasContext.cpp
@@ -467,11 +467,11 @@ void CanvasContext::notifyFramePending() {
     mRenderThread.pushBackFrameCallback(this);
 }
 
-void CanvasContext::draw() {
+nsecs_t CanvasContext::draw() {
     if (auto grContext = getGrContext()) {
         if (grContext->abandoned()) {
             LOG_ALWAYS_FATAL("GrContext is abandoned/device lost at start of CanvasContext::draw");
-            return;
+            return 0;
         }
     }
     SkRect dirty;
@@ -486,7 +486,7 @@ void CanvasContext::draw() {
             std::invoke(func, mFrameNumber);
         }
         mFrameCompleteCallbacks.clear();
-        return;
+        return 0;
     }
 
     ScopedActiveContext activeContext(this);
@@ -616,6 +616,7 @@ void CanvasContext::draw() {
     }
 
     mRenderThread.cacheManager().onFrameCompleted();
+    return mCurrentFrameInfo->get(FrameInfoIndex::DequeueBufferDuration);
 }
 
 void CanvasContext::reportMetricsWithPresentTime() {
diff --git a/libs/hwui/renderthread/CanvasContext.h b/libs/hwui/renderthread/CanvasContext.h
index af1ebb288f214..4f8e4ca7f23a7 100644
--- a/libs/hwui/renderthread/CanvasContext.h
+++ b/libs/hwui/renderthread/CanvasContext.h
@@ -127,7 +127,8 @@ public:
     void setColorMode(ColorMode mode);
     bool makeCurrent();
     void prepareTree(TreeInfo& info, int64_t* uiFrameInfo, int64_t syncQueued, RenderNode* target);
-    void draw();
+    // Returns the DequeueBufferDuration.
+    nsecs_t draw();
     void destroy();
 
     // IFrameCallback, Choreographer-driven frame callback entry point
diff --git a/libs/hwui/renderthread/DrawFrameTask.cpp b/libs/hwui/renderthread/DrawFrameTask.cpp
index cb92aa1910736..8448b87b5948c 100644
--- a/libs/hwui/renderthread/DrawFrameTask.cpp
+++ b/libs/hwui/renderthread/DrawFrameTask.cpp
@@ -18,6 +18,7 @@
 
 #include <utils/Log.h>
 #include <utils/TraceUtils.h>
+#include <algorithm>
 
 #include "../DeferredLayerUpdater.h"
 #include "../DisplayList.h"
@@ -91,6 +92,7 @@ void DrawFrameTask::postAndWait() {
 void DrawFrameTask::run() {
     const int64_t vsyncId = mFrameInfo[static_cast<int>(FrameInfoIndex::FrameTimelineVsyncId)];
     ATRACE_FORMAT("DrawFrames %" PRId64, vsyncId);
+    nsecs_t syncDelayDuration = systemTime(SYSTEM_TIME_MONOTONIC) - mSyncQueued;
 
     bool canUnblockUiThread;
     bool canDrawThisFrame;
@@ -124,8 +126,9 @@ void DrawFrameTask::run() {
                 [callback, frameNr = context->getFrameNumber()]() { callback(frameNr); });
     }
 
+    nsecs_t dequeueBufferDuration = 0;
     if (CC_LIKELY(canDrawThisFrame)) {
-        context->draw();
+        dequeueBufferDuration = context->draw();
     } else {
         // wait on fences so tasks don't overlap next frame
         context->waitOnFences();
@@ -149,10 +152,14 @@ void DrawFrameTask::run() {
             mUpdateTargetWorkDuration(targetWorkDuration);
         }
         int64_t frameDuration = systemTime(SYSTEM_TIME_MONOTONIC) - frameStartTime;
-        if (frameDuration > kSanityCheckLowerBound && frameDuration < kSanityCheckUpperBound) {
-            mReportActualWorkDuration(frameDuration);
+        int64_t actualDuration = frameDuration -
+                                 (std::min(syncDelayDuration, mLastDequeueBufferDuration)) -
+                                 dequeueBufferDuration;
+        if (actualDuration > kSanityCheckLowerBound && actualDuration < kSanityCheckUpperBound) {
+            mReportActualWorkDuration(actualDuration);
         }
     }
+    mLastDequeueBufferDuration = dequeueBufferDuration;
 }
 
 bool DrawFrameTask::syncFrameState(TreeInfo& info) {
diff --git a/libs/hwui/renderthread/DrawFrameTask.h b/libs/hwui/renderthread/DrawFrameTask.h
index 3bb574aff59b8..2455ea84c94eb 100644
--- a/libs/hwui/renderthread/DrawFrameTask.h
+++ b/libs/hwui/renderthread/DrawFrameTask.h
@@ -110,6 +110,7 @@ private:
     std::function<void(int64_t)> mFrameCallback;
     std::function<void(int64_t)> mFrameCompleteCallback;
 
+    nsecs_t mLastDequeueBufferDuration = 0;
     nsecs_t mLastTargetWorkDuration = 0;
     std::function<void(int64_t)> mUpdateTargetWorkDuration;
     std::function<void(int64_t)> mReportActualWorkDuration;