From 3afb3972f458c299c92933d9856a542d837c1998 Mon Sep 17 00:00:00 2001 From: Alec Mouri Date: Fri, 27 May 2022 22:03:11 +0000 Subject: [PATCH] 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 --- core/java/android/view/FrameMetrics.java | 5 ++- libs/hwui/FrameInfo.cpp | 34 ++++++++++++----- libs/hwui/FrameInfo.h | 1 + .../hwui/pipeline/skia/SkiaOpenGLPipeline.cpp | 30 +++++++-------- libs/hwui/pipeline/skia/SkiaOpenGLPipeline.h | 13 ++++--- .../hwui/pipeline/skia/SkiaVulkanPipeline.cpp | 37 +++++++++---------- libs/hwui/pipeline/skia/SkiaVulkanPipeline.h | 13 ++++--- libs/hwui/renderthread/CanvasContext.cpp | 16 +++++--- libs/hwui/renderthread/IRenderPipeline.h | 20 +++++++--- libs/hwui/renderthread/VulkanManager.cpp | 5 ++- libs/hwui/renderthread/VulkanManager.h | 4 +- 11 files changed, 108 insertions(+), 70 deletions(-) diff --git a/core/java/android/view/FrameMetrics.java b/core/java/android/view/FrameMetrics.java index 3cffeb0578d42..380c1045aea81 100644 --- a/core/java/android/view/FrameMetrics.java +++ b/core/java/android/view/FrameMetrics.java @@ -254,8 +254,9 @@ public final class FrameMetrics { int GPU_COMPLETED = 19; int SWAP_BUFFERS_COMPLETED = 20; int DISPLAY_PRESENT_TIME = 21; + int COMMAND_SUBMISSION_COMPLETED = 22; - int FRAME_STATS_COUNT = 22; // must always be last and in sync with + int FRAME_STATS_COUNT = 23; // must always be last and in sync with // FrameInfoIndex::NumIndexes in libs/hwui/FrameInfo.h } @@ -291,7 +292,7 @@ public final class FrameMetrics { // RESERVED VSYNC_TIMESTAMP 0, 0, // GPU_DURATION - Index.SWAP_BUFFERS, Index.GPU_COMPLETED, + Index.COMMAND_SUBMISSION_COMPLETED, Index.GPU_COMPLETED, // DEADLINE Index.INTENDED_VSYNC, Index.FRAME_DEADLINE, }; diff --git a/libs/hwui/FrameInfo.cpp b/libs/hwui/FrameInfo.cpp index fecf26906c04e..8191f5e6a83ae 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(FrameInfoIndex::NumIndexes) == 22, +static_assert(static_cast(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 540a88b16dc98..564ee4f53a54d 100644 --- a/libs/hwui/FrameInfo.h +++ b/libs/hwui/FrameInfo.h @@ -58,6 +58,7 @@ enum class FrameInfoIndex { 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 744739accb2c2..2aca41e419055 100644 --- a/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.cpp +++ b/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.cpp @@ -16,8 +16,15 @@ #include "SkiaOpenGLPipeline.h" +#include +#include +#include +#include #include +#include + #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 - -#include -#include -#include - -#include -#include - using namespace android::uirenderer::renderthread; namespace android { @@ -69,12 +68,11 @@ Frame SkiaOpenGLPipeline::getFrame() { 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>& 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>& renderNodes, FrameInfoVisualizer* profiler) { if (!isCapturingSkp()) { mEglManager.damageFrame(frame, dirty); } @@ -129,7 +127,7 @@ bool SkiaOpenGLPipeline::draw(const Frame& frame, const SkRect& screenDirty, con 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 fddd97f1c5b30..186998a017455 100644 --- a/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.h +++ b/libs/hwui/pipeline/skia/SkiaOpenGLPipeline.h @@ -36,11 +36,14 @@ public: 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 >& 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 >& 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 99fd463b06603..905d46e580143 100644 --- a/libs/hwui/pipeline/skia/SkiaVulkanPipeline.cpp +++ b/libs/hwui/pipeline/skia/SkiaVulkanPipeline.cpp @@ -16,7 +16,15 @@ #include "SkiaVulkanPipeline.h" +#include +#include +#include +#include +#include #include +#include +#include + #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 -#include - -#include -#include -#include - -#include -#include +#include "renderthread/IRenderPipeline.h" using namespace android::uirenderer::renderthread; @@ -64,15 +63,14 @@ Frame SkiaVulkanPipeline::getFrame() { 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>& 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>& renderNodes, FrameInfoVisualizer* profiler) { sk_sp 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 @@ bool SkiaVulkanPipeline::draw(const Frame& frame, const SkRect& screenDirty, con 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 @@ bool SkiaVulkanPipeline::draw(const Frame& frame, const SkRect& screenDirty, con 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 56d42e013f312..ada6af67d4a04 100644 --- a/libs/hwui/pipeline/skia/SkiaVulkanPipeline.h +++ b/libs/hwui/pipeline/skia/SkiaVulkanPipeline.h @@ -33,11 +33,14 @@ public: 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 >& 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 >& 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 122c77f3dadce..976117b9bbd45 100644 --- a/libs/hwui/renderthread/CanvasContext.cpp +++ b/libs/hwui/renderthread/CanvasContext.cpp @@ -512,9 +512,9 @@ nsecs_t CanvasContext::draw() { 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 @@ nsecs_t CanvasContext::draw() { 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 @@ void CanvasContext::onSurfaceStatsAvailable(void* context, int32_t surfaceContro 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 aceb5a528fc86..ef58bc553c235 100644 --- a/libs/hwui/renderthread/IRenderPipeline.h +++ b/libs/hwui/renderthread/IRenderPipeline.h @@ -49,11 +49,21 @@ class IRenderPipeline { 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>& 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>& 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 a9ff2c60fdbe4..718d4a16d5c8d 100644 --- a/libs/hwui/renderthread/VulkanManager.cpp +++ b/libs/hwui/renderthread/VulkanManager.cpp @@ -494,7 +494,7 @@ static void destroy_semaphore(void* context) { } } -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 @@ void VulkanManager::finishFrame(SkSurface* surface) { 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 @@ void VulkanManager::finishFrame(SkSurface* surface) { } } 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 b816649edf6eb..b8c2bdf112f87 100644 --- a/libs/hwui/renderthread/VulkanManager.h +++ b/libs/hwui/renderthread/VulkanManager.h @@ -84,7 +84,9 @@ public: 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.