From 09979fbee7201b46158c2c033194529e4284ea13 Mon Sep 17 00:00:00 2001 From: John Reck Date: Mon, 12 Mar 2018 17:14:53 -0700 Subject: [PATCH] Break down jank between frame drops vs. triple buffered Bug: 70220906 Test: JankyScene vs. systrace vs. jankstats Change-Id: Ia012685020cc5bcabbd3f92f0bdeb84eaf50733d --- core/proto/android/service/graphicsstats.proto | 5 ++- libs/hwui/JankTracker.cpp | 32 +++++++++++++--- libs/hwui/JankTracker.h | 1 + libs/hwui/ProfileData.cpp | 3 +- libs/hwui/ProfileData.h | 1 + libs/hwui/service/GraphicsStatsService.cpp | 3 ++ libs/hwui/tests/common/scenes/JankyScene.cpp | 51 ++++++++++++++++++++++++++ 7 files changed, 87 insertions(+), 9 deletions(-) create mode 100644 libs/hwui/tests/common/scenes/JankyScene.cpp diff --git a/core/proto/android/service/graphicsstats.proto b/core/proto/android/service/graphicsstats.proto index f42206562fc4..c2fedf5a5722 100644 --- a/core/proto/android/service/graphicsstats.proto +++ b/core/proto/android/service/graphicsstats.proto @@ -56,7 +56,7 @@ message GraphicsStatsJankSummaryProto { // Number of "missed vsync" events. optional int32 missed_vsync_count = 3; - // Number of "high input latency" events. + // Number of frames in triple-buffering scenario (high input latency) optional int32 high_input_latency_count = 4; // Number of "slow UI thread" events. @@ -67,6 +67,9 @@ message GraphicsStatsJankSummaryProto { // Number of "slow draw" events. optional int32 slow_draw_count = 7; + + // Number of frames that missed their deadline (aka, visibly janked) + optional int32 missed_deadline_count = 8; } message GraphicsStatsHistogramBucketProto { diff --git a/libs/hwui/JankTracker.cpp b/libs/hwui/JankTracker.cpp index cf29e434a351..8110664ad44b 100644 --- a/libs/hwui/JankTracker.cpp +++ b/libs/hwui/JankTracker.cpp @@ -129,22 +129,42 @@ void JankTracker::finishFrame(const FrameInfo& frame) { totalDuration -= forgiveAmount; } } + LOG_ALWAYS_FATAL_IF(totalDuration <= 0, "Impossible totalDuration %" PRId64, totalDuration); mData->reportFrame(totalDuration); (*mGlobalData)->reportFrame(totalDuration); - // Keep the fast path as fast as possible. - if (CC_LIKELY(totalDuration < mFrameInterval)) { + // Only things like Surface.lockHardwareCanvas() are exempt from tracking + if (CC_UNLIKELY(frame[FrameInfoIndex::Flags] & EXEMPT_FRAMES_FLAGS)) { return; } - // Only things like Surface.lockHardwareCanvas() are exempt from tracking - if (frame[FrameInfoIndex::Flags] & EXEMPT_FRAMES_FLAGS) { + if (totalDuration > mFrameInterval) { + mData->reportJank(); + (*mGlobalData)->reportJank(); + } + + bool isTripleBuffered = mSwapDeadline > frame[FrameInfoIndex::IntendedVsync]; + + mSwapDeadline = std::max(mSwapDeadline + mFrameInterval, + frame[FrameInfoIndex::IntendedVsync] + mFrameInterval); + + // If we hit the deadline, cool! + if (frame[FrameInfoIndex::FrameCompleted] < mSwapDeadline) { + if (isTripleBuffered) { + mData->reportJankType(JankType::kHighInputLatency); + (*mGlobalData)->reportJankType(JankType::kHighInputLatency); + } return; } - mData->reportJank(); - (*mGlobalData)->reportJank(); + mData->reportJankType(JankType::kMissedDeadline); + (*mGlobalData)->reportJankType(JankType::kMissedDeadline); + + // Janked, reset the swap deadline + nsecs_t jitterNanos = frame[FrameInfoIndex::FrameCompleted] - frame[FrameInfoIndex::Vsync]; + nsecs_t lastFrameOffset = jitterNanos % mFrameInterval; + mSwapDeadline = frame[FrameInfoIndex::FrameCompleted] - lastFrameOffset + mFrameInterval; for (int i = 0; i < NUM_BUCKETS; i++) { int64_t delta = frame.duration(COMPARISONS[i].start, COMPARISONS[i].end); diff --git a/libs/hwui/JankTracker.h b/libs/hwui/JankTracker.h index dc6a7ff5ddb7..110211eda23a 100644 --- a/libs/hwui/JankTracker.h +++ b/libs/hwui/JankTracker.h @@ -75,6 +75,7 @@ private: std::array mThresholds; int64_t mFrameInterval; + nsecs_t mSwapDeadline; // The amount of time we will erase from the total duration to account // for SF vsync offsets with HWC2 blocking dequeueBuffers. // (Vsync + mDequeueBlockTolerance) is the point at which we expect diff --git a/libs/hwui/ProfileData.cpp b/libs/hwui/ProfileData.cpp index b392ecdde18f..f9cf54998032 100644 --- a/libs/hwui/ProfileData.cpp +++ b/libs/hwui/ProfileData.cpp @@ -23,8 +23,7 @@ namespace uirenderer { static const char* JANK_TYPE_NAMES[] = { "Missed Vsync", "High input latency", "Slow UI thread", - "Slow bitmap uploads", "Slow issue draw commands", -}; + "Slow bitmap uploads", "Slow issue draw commands", "Frame deadline missed"}; // The bucketing algorithm controls so to speak // If a frame is <= to this it goes in bucket 0 diff --git a/libs/hwui/ProfileData.h b/libs/hwui/ProfileData.h index 1e688ab6fa68..564920b60328 100644 --- a/libs/hwui/ProfileData.h +++ b/libs/hwui/ProfileData.h @@ -33,6 +33,7 @@ enum JankType { kSlowUI, kSlowSync, kSlowRT, + kMissedDeadline, // must be last NUM_BUCKETS, diff --git a/libs/hwui/service/GraphicsStatsService.cpp b/libs/hwui/service/GraphicsStatsService.cpp index e0303a8a62d5..599226bebe84 100644 --- a/libs/hwui/service/GraphicsStatsService.cpp +++ b/libs/hwui/service/GraphicsStatsService.cpp @@ -176,6 +176,8 @@ bool mergeProfileDataIntoProto(service::GraphicsStatsProto* proto, const std::st summary->set_slow_bitmap_upload_count(summary->slow_bitmap_upload_count() + data->jankTypeCount(kSlowSync)); summary->set_slow_draw_count(summary->slow_draw_count() + data->jankTypeCount(kSlowRT)); + summary->set_missed_deadline_count(summary->missed_deadline_count() + + data->jankTypeCount(kMissedDeadline)); bool creatingHistogram = false; if (proto->histogram_size() == 0) { @@ -246,6 +248,7 @@ void dumpAsTextToFd(service::GraphicsStatsProto* proto, int fd) { dprintf(fd, "\nNumber Slow UI thread: %d", summary.slow_ui_thread_count()); dprintf(fd, "\nNumber Slow bitmap uploads: %d", summary.slow_bitmap_upload_count()); dprintf(fd, "\nNumber Slow issue draw commands: %d", summary.slow_draw_count()); + dprintf(fd, "\nNumber Frame deadline missed: %d", summary.missed_deadline_count()); dprintf(fd, "\nHISTOGRAM:"); for (const auto& it : proto->histogram()) { dprintf(fd, " %dms=%d", it.render_millis(), it.frame_count()); diff --git a/libs/hwui/tests/common/scenes/JankyScene.cpp b/libs/hwui/tests/common/scenes/JankyScene.cpp new file mode 100644 index 000000000000..f5e6b317529a --- /dev/null +++ b/libs/hwui/tests/common/scenes/JankyScene.cpp @@ -0,0 +1,51 @@ +/* + * Copyright (C) 2018 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include "TestSceneBase.h" + +#include + +class JankyScene; + +static TestScene::Registrar _JankyScene(TestScene::Info{ + "janky", + "A scene that intentionally janks just enough to stay in " + "triple buffering.", + TestScene::simpleCreateScene}); + +class JankyScene : public TestScene { +public: + sp card; + + void createContent(int width, int height, Canvas& canvas) override { + card = TestUtils::createNode(0, 0, 200, 200, [](RenderProperties& props, Canvas& canvas) { + canvas.drawColor(0xFF0000FF, SkBlendMode::kSrcOver); + }); + canvas.drawColor(0xFFFFFFFF, SkBlendMode::kSrcOver); // background + canvas.drawRenderNode(card.get()); + } + + void doFrame(int frameNr) override { + int curFrame = frameNr % 150; + if (curFrame & 1) { + usleep(15000); + } + // we animate left and top coordinates, which in turn animates width and + // height (bottom/right coordinates are fixed) + card->mutateStagingProperties().setLeftTop(curFrame, curFrame); + card->setPropertyFieldsDirty(RenderNode::X | RenderNode::Y); + } +}; \ No newline at end of file -- 2.11.0