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/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.