Make GPU duration metrics more accurate for Vulkan

In the Vulkan pipeline, the GPU start time was measured to be when
swapBuffers starts. But the command queue has already been submitted at
this point, which means that the GPU work would already have begun. This
means that it's possible to measure a negative time since for very light
GPU workloads, the GPU fence can fire prior to CPU making it to
swapBuffers().

To compensate, instead measure from after skia completed submitting GPU
commands, until the GPU fence fires. Since it is theoretically possible
for GPU work to complete if the render thread gets descheduled
immediately after submitting the GPU, we also add some clamping to
ensure that the duration from command submission -> completion of GPU
work is nonnegative.

Bug: 230713131
Test: atest android.view.cts.FrameMetricsListenerTest
Change-Id: Ia30b7732eaab71e4e29766f788d5cd94ec63c38a
diff --git a/libs/hwui/FrameInfo.cpp b/libs/hwui/FrameInfo.cpp
index fecf269..8191f5e 100644
--- a/libs/hwui/FrameInfo.cpp
+++ b/libs/hwui/FrameInfo.cpp
@@ -20,19 +20,33 @@
 namespace android {
 namespace uirenderer {
 
-const std::array FrameInfoNames{
-        "Flags",               "FrameTimelineVsyncId",   "IntendedVsync",
-        "Vsync",               "InputEventId",           "HandleInputStart",
-        "AnimationStart",      "PerformTraversalsStart", "DrawStart",
-        "FrameDeadline",       "FrameInterval",          "FrameStartTime",
-        "SyncQueued",          "SyncStart",              "IssueDrawCommandsStart",
-        "SwapBuffers",         "FrameCompleted",         "DequeueBufferDuration",
-        "QueueBufferDuration", "GpuCompleted",           "SwapBuffersCompleted",
-        "DisplayPresentTime",
+const std::array FrameInfoNames{"Flags",
+                                "FrameTimelineVsyncId",
+                                "IntendedVsync",
+                                "Vsync",
+                                "InputEventId",
+                                "HandleInputStart",
+                                "AnimationStart",
+                                "PerformTraversalsStart",
+                                "DrawStart",
+                                "FrameDeadline",
+                                "FrameInterval",
+                                "FrameStartTime",
+                                "SyncQueued",
+                                "SyncStart",
+                                "IssueDrawCommandsStart",
+                                "SwapBuffers",
+                                "FrameCompleted",
+                                "DequeueBufferDuration",
+                                "QueueBufferDuration",
+                                "GpuCompleted",
+                                "SwapBuffersCompleted",
+                                "DisplayPresentTime",
+                                "CommandSubmissionCompleted"
 
 };
 
-static_assert(static_cast<int>(FrameInfoIndex::NumIndexes) == 22,
+static_assert(static_cast<int>(FrameInfoIndex::NumIndexes) == 23,
               "Must update value in FrameMetrics.java#FRAME_STATS_COUNT (and here)");
 
 void FrameInfo::importUiThreadInfo(int64_t* info) {
diff --git a/libs/hwui/FrameInfo.h b/libs/hwui/FrameInfo.h
index 540a88b..564ee4f 100644
--- a/libs/hwui/FrameInfo.h
+++ b/libs/hwui/FrameInfo.h
@@ -58,6 +58,7 @@
     GpuCompleted,
     SwapBuffersCompleted,
     DisplayPresentTime,
+    CommandSubmissionCompleted,
 
     // Must be the last value!
     // Also must be kept in sync with FrameMetrics.java#FRAME_STATS_COUNT
diff --git a/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.cpp b/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.cpp
index 744739a..2aca41e 100644
--- a/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.cpp
+++ b/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.cpp
@@ -16,8 +16,15 @@
 
 #include "SkiaOpenGLPipeline.h"
 
+#include <GrBackendSurface.h>
+#include <SkBlendMode.h>
+#include <SkImageInfo.h>
+#include <cutils/properties.h>
 #include <gui/TraceUtils.h>
+#include <strings.h>
+
 #include "DeferredLayerUpdater.h"
+#include "FrameInfo.h"
 #include "LayerDrawable.h"
 #include "LightingInfo.h"
 #include "SkiaPipeline.h"
@@ -27,17 +34,9 @@
 #include "renderstate/RenderState.h"
 #include "renderthread/EglManager.h"
 #include "renderthread/Frame.h"
+#include "renderthread/IRenderPipeline.h"
 #include "utils/GLUtils.h"
 
-#include <GLES3/gl3.h>
-
-#include <GrBackendSurface.h>
-#include <SkBlendMode.h>
-#include <SkImageInfo.h>
-
-#include <cutils/properties.h>
-#include <strings.h>
-
 using namespace android::uirenderer::renderthread;
 
 namespace android {
@@ -69,12 +68,11 @@
     return mEglManager.beginFrame(mEglSurface);
 }
 
-bool SkiaOpenGLPipeline::draw(const Frame& frame, const SkRect& screenDirty, const SkRect& dirty,
-                              const LightGeometry& lightGeometry,
-                              LayerUpdateQueue* layerUpdateQueue, const Rect& contentDrawBounds,
-                              bool opaque, const LightInfo& lightInfo,
-                              const std::vector<sp<RenderNode>>& renderNodes,
-                              FrameInfoVisualizer* profiler) {
+IRenderPipeline::DrawResult SkiaOpenGLPipeline::draw(
+        const Frame& frame, const SkRect& screenDirty, const SkRect& dirty,
+        const LightGeometry& lightGeometry, LayerUpdateQueue* layerUpdateQueue,
+        const Rect& contentDrawBounds, bool opaque, const LightInfo& lightInfo,
+        const std::vector<sp<RenderNode>>& renderNodes, FrameInfoVisualizer* profiler) {
     if (!isCapturingSkp()) {
         mEglManager.damageFrame(frame, dirty);
     }
@@ -129,7 +127,7 @@
         dumpResourceCacheUsage();
     }
 
-    return true;
+    return {true, IRenderPipeline::DrawResult::kUnknownTime};
 }
 
 bool SkiaOpenGLPipeline::swapBuffers(const Frame& frame, bool drew, const SkRect& screenDirty,
diff --git a/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.h b/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.h
index fddd97f..186998a 100644
--- a/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.h
+++ b/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.h
@@ -36,11 +36,14 @@
 
     renderthread::MakeCurrentResult makeCurrent() override;
     renderthread::Frame getFrame() override;
-    bool draw(const renderthread::Frame& frame, const SkRect& screenDirty, const SkRect& dirty,
-              const LightGeometry& lightGeometry, LayerUpdateQueue* layerUpdateQueue,
-              const Rect& contentDrawBounds, bool opaque, const LightInfo& lightInfo,
-              const std::vector<sp<RenderNode> >& renderNodes,
-              FrameInfoVisualizer* profiler) override;
+    renderthread::IRenderPipeline::DrawResult draw(const renderthread::Frame& frame,
+                                                   const SkRect& screenDirty, const SkRect& dirty,
+                                                   const LightGeometry& lightGeometry,
+                                                   LayerUpdateQueue* layerUpdateQueue,
+                                                   const Rect& contentDrawBounds, bool opaque,
+                                                   const LightInfo& lightInfo,
+                                                   const std::vector<sp<RenderNode> >& renderNodes,
+                                                   FrameInfoVisualizer* profiler) override;
     GrSurfaceOrigin getSurfaceOrigin() override { return kBottomLeft_GrSurfaceOrigin; }
     bool swapBuffers(const renderthread::Frame& frame, bool drew, const SkRect& screenDirty,
                      FrameInfo* currentFrameInfo, bool* requireSwap) override;
diff --git a/libs/hwui/pipeline/skia/SkiaVulkanPipeline.cpp b/libs/hwui/pipeline/skia/SkiaVulkanPipeline.cpp
index 99fd463..905d46e 100644
--- a/libs/hwui/pipeline/skia/SkiaVulkanPipeline.cpp
+++ b/libs/hwui/pipeline/skia/SkiaVulkanPipeline.cpp
@@ -16,7 +16,15 @@
 
 #include "SkiaVulkanPipeline.h"
 
+#include <GrDirectContext.h>
+#include <GrTypes.h>
+#include <SkSurface.h>
+#include <SkTypes.h>
+#include <cutils/properties.h>
 #include <gui/TraceUtils.h>
+#include <strings.h>
+#include <vk/GrVkTypes.h>
+
 #include "DeferredLayerUpdater.h"
 #include "LightingInfo.h"
 #include "Readback.h"
@@ -26,16 +34,7 @@
 #include "VkInteropFunctorDrawable.h"
 #include "renderstate/RenderState.h"
 #include "renderthread/Frame.h"
-
-#include <SkSurface.h>
-#include <SkTypes.h>
-
-#include <GrDirectContext.h>
-#include <GrTypes.h>
-#include <vk/GrVkTypes.h>
-
-#include <cutils/properties.h>
-#include <strings.h>
+#include "renderthread/IRenderPipeline.h"
 
 using namespace android::uirenderer::renderthread;
 
@@ -64,15 +63,14 @@
     return vulkanManager().dequeueNextBuffer(mVkSurface);
 }
 
-bool SkiaVulkanPipeline::draw(const Frame& frame, const SkRect& screenDirty, const SkRect& dirty,
-                              const LightGeometry& lightGeometry,
-                              LayerUpdateQueue* layerUpdateQueue, const Rect& contentDrawBounds,
-                              bool opaque, const LightInfo& lightInfo,
-                              const std::vector<sp<RenderNode>>& renderNodes,
-                              FrameInfoVisualizer* profiler) {
+IRenderPipeline::DrawResult SkiaVulkanPipeline::draw(
+        const Frame& frame, const SkRect& screenDirty, const SkRect& dirty,
+        const LightGeometry& lightGeometry, LayerUpdateQueue* layerUpdateQueue,
+        const Rect& contentDrawBounds, bool opaque, const LightInfo& lightInfo,
+        const std::vector<sp<RenderNode>>& renderNodes, FrameInfoVisualizer* profiler) {
     sk_sp<SkSurface> backBuffer = mVkSurface->getCurrentSkSurface();
     if (backBuffer.get() == nullptr) {
-        return false;
+        return {false, -1};
     }
 
     // update the coordinates of the global light position based on surface rotation
@@ -94,9 +92,10 @@
         profiler->draw(profileRenderer);
     }
 
+    nsecs_t submissionTime = IRenderPipeline::DrawResult::kUnknownTime;
     {
         ATRACE_NAME("flush commands");
-        vulkanManager().finishFrame(backBuffer.get());
+        submissionTime = vulkanManager().finishFrame(backBuffer.get());
     }
     layerUpdateQueue->clear();
 
@@ -105,7 +104,7 @@
         dumpResourceCacheUsage();
     }
 
-    return true;
+    return {true, submissionTime};
 }
 
 bool SkiaVulkanPipeline::swapBuffers(const Frame& frame, bool drew, const SkRect& screenDirty,
diff --git a/libs/hwui/pipeline/skia/SkiaVulkanPipeline.h b/libs/hwui/pipeline/skia/SkiaVulkanPipeline.h
index 56d42e0..ada6af6 100644
--- a/libs/hwui/pipeline/skia/SkiaVulkanPipeline.h
+++ b/libs/hwui/pipeline/skia/SkiaVulkanPipeline.h
@@ -33,11 +33,14 @@
 
     renderthread::MakeCurrentResult makeCurrent() override;
     renderthread::Frame getFrame() override;
-    bool draw(const renderthread::Frame& frame, const SkRect& screenDirty, const SkRect& dirty,
-              const LightGeometry& lightGeometry, LayerUpdateQueue* layerUpdateQueue,
-              const Rect& contentDrawBounds, bool opaque, const LightInfo& lightInfo,
-              const std::vector<sp<RenderNode> >& renderNodes,
-              FrameInfoVisualizer* profiler) override;
+    renderthread::IRenderPipeline::DrawResult draw(const renderthread::Frame& frame,
+                                                   const SkRect& screenDirty, const SkRect& dirty,
+                                                   const LightGeometry& lightGeometry,
+                                                   LayerUpdateQueue* layerUpdateQueue,
+                                                   const Rect& contentDrawBounds, bool opaque,
+                                                   const LightInfo& lightInfo,
+                                                   const std::vector<sp<RenderNode> >& renderNodes,
+                                                   FrameInfoVisualizer* profiler) override;
     GrSurfaceOrigin getSurfaceOrigin() override { return kTopLeft_GrSurfaceOrigin; }
     bool swapBuffers(const renderthread::Frame& frame, bool drew, const SkRect& screenDirty,
                      FrameInfo* currentFrameInfo, bool* requireSwap) override;
diff --git a/libs/hwui/renderthread/CanvasContext.cpp b/libs/hwui/renderthread/CanvasContext.cpp
index 122c77f..976117b 100644
--- a/libs/hwui/renderthread/CanvasContext.cpp
+++ b/libs/hwui/renderthread/CanvasContext.cpp
@@ -512,9 +512,9 @@
 
     ATRACE_FORMAT("Drawing " RECT_STRING, SK_RECT_ARGS(dirty));
 
-    bool drew = mRenderPipeline->draw(frame, windowDirty, dirty, mLightGeometry, &mLayerUpdateQueue,
-                                      mContentDrawBounds, mOpaque, mLightInfo, mRenderNodes,
-                                      &(profiler()));
+    const auto drawResult = mRenderPipeline->draw(frame, windowDirty, dirty, mLightGeometry,
+                                                  &mLayerUpdateQueue, mContentDrawBounds, mOpaque,
+                                                  mLightInfo, mRenderNodes, &(profiler()));
 
     uint64_t frameCompleteNr = getFrameNumber();
 
@@ -534,8 +534,11 @@
 
     bool requireSwap = false;
     int error = OK;
-    bool didSwap =
-            mRenderPipeline->swapBuffers(frame, drew, windowDirty, mCurrentFrameInfo, &requireSwap);
+    bool didSwap = mRenderPipeline->swapBuffers(frame, drawResult.success, windowDirty,
+                                                mCurrentFrameInfo, &requireSwap);
+
+    mCurrentFrameInfo->set(FrameInfoIndex::CommandSubmissionCompleted) = std::max(
+            drawResult.commandSubmissionTime, mCurrentFrameInfo->get(FrameInfoIndex::SwapBuffers));
 
     mIsDirty = false;
 
@@ -753,7 +756,8 @@
     if (frameInfo != nullptr) {
         frameInfo->set(FrameInfoIndex::FrameCompleted) = std::max(gpuCompleteTime,
                 frameInfo->get(FrameInfoIndex::SwapBuffersCompleted));
-        frameInfo->set(FrameInfoIndex::GpuCompleted) = gpuCompleteTime;
+        frameInfo->set(FrameInfoIndex::GpuCompleted) = std::max(
+                gpuCompleteTime, frameInfo->get(FrameInfoIndex::CommandSubmissionCompleted));
         std::scoped_lock lock(instance->mFrameMetricsReporterMutex);
         instance->mJankTracker.finishFrame(*frameInfo, instance->mFrameMetricsReporter, frameNumber,
                                            surfaceControlId);
diff --git a/libs/hwui/renderthread/IRenderPipeline.h b/libs/hwui/renderthread/IRenderPipeline.h
index aceb5a5..ef58bc5 100644
--- a/libs/hwui/renderthread/IRenderPipeline.h
+++ b/libs/hwui/renderthread/IRenderPipeline.h
@@ -49,11 +49,21 @@
 public:
     virtual MakeCurrentResult makeCurrent() = 0;
     virtual Frame getFrame() = 0;
-    virtual bool draw(const Frame& frame, const SkRect& screenDirty, const SkRect& dirty,
-                      const LightGeometry& lightGeometry, LayerUpdateQueue* layerUpdateQueue,
-                      const Rect& contentDrawBounds, bool opaque, const LightInfo& lightInfo,
-                      const std::vector<sp<RenderNode>>& renderNodes,
-                      FrameInfoVisualizer* profiler) = 0;
+
+    // Result of IRenderPipeline::draw
+    struct DrawResult {
+        // True if draw() succeeded, false otherwise
+        bool success = false;
+        // If drawing was successful, reports the time at which command
+        // submission occurred. -1 if this time is unknown.
+        static constexpr nsecs_t kUnknownTime = -1;
+        nsecs_t commandSubmissionTime = kUnknownTime;
+    };
+    virtual DrawResult draw(const Frame& frame, const SkRect& screenDirty, const SkRect& dirty,
+                            const LightGeometry& lightGeometry, LayerUpdateQueue* layerUpdateQueue,
+                            const Rect& contentDrawBounds, bool opaque, const LightInfo& lightInfo,
+                            const std::vector<sp<RenderNode>>& renderNodes,
+                            FrameInfoVisualizer* profiler) = 0;
     virtual bool swapBuffers(const Frame& frame, bool drew, const SkRect& screenDirty,
                              FrameInfo* currentFrameInfo, bool* requireSwap) = 0;
     virtual DeferredLayerUpdater* createTextureLayer() = 0;
diff --git a/libs/hwui/renderthread/VulkanManager.cpp b/libs/hwui/renderthread/VulkanManager.cpp
index a9ff2c6..718d4a1 100644
--- a/libs/hwui/renderthread/VulkanManager.cpp
+++ b/libs/hwui/renderthread/VulkanManager.cpp
@@ -494,7 +494,7 @@
     }
 }
 
-void VulkanManager::finishFrame(SkSurface* surface) {
+nsecs_t VulkanManager::finishFrame(SkSurface* surface) {
     ATRACE_NAME("Vulkan finish frame");
     ALOGE_IF(mSwapSemaphore != VK_NULL_HANDLE || mDestroySemaphoreContext != nullptr,
              "finishFrame already has an outstanding semaphore");
@@ -530,6 +530,7 @@
     GrDirectContext* context = GrAsDirectContext(surface->recordingContext());
     ALOGE_IF(!context, "Surface is not backed by gpu");
     context->submit();
+    const nsecs_t submissionTime = systemTime();
     if (semaphore != VK_NULL_HANDLE) {
         if (submitted == GrSemaphoresSubmitted::kYes) {
             mSwapSemaphore = semaphore;
@@ -558,6 +559,8 @@
         }
     }
     skiapipeline::ShaderCache::get().onVkFrameFlushed(context);
+
+    return submissionTime;
 }
 
 void VulkanManager::swapBuffers(VulkanSurface* surface, const SkRect& dirtyRect) {
diff --git a/libs/hwui/renderthread/VulkanManager.h b/libs/hwui/renderthread/VulkanManager.h
index b816649..b8c2bdf 100644
--- a/libs/hwui/renderthread/VulkanManager.h
+++ b/libs/hwui/renderthread/VulkanManager.h
@@ -84,7 +84,9 @@
     void destroySurface(VulkanSurface* surface);
 
     Frame dequeueNextBuffer(VulkanSurface* surface);
-    void finishFrame(SkSurface* surface);
+    // Finishes the frame and submits work to the GPU
+    // Returns the estimated start time for intiating GPU work, -1 otherwise.
+    nsecs_t finishFrame(SkSurface* surface);
     void swapBuffers(VulkanSurface* surface, const SkRect& dirtyRect);
 
     // Inserts a wait on fence command into the Vulkan command buffer.