From 0e4864725aaca48a289ae1e0237377ed5b135f7a Mon Sep 17 00:00:00 2001 From: John Reck Date: Mon, 19 Mar 2018 14:06:16 -0700 Subject: [PATCH] Revert "Revert "Break down jank between frame drops vs. triple buffered"" This reverts commit a6d8fbf4ea634f5f605b2b7db3ca98975f8625b5. Fixes an out-of-bounds read in COMPARISONS by switching up how comparisons works. Instead of requiring all jank types to have an associated COMPARISON's entry, which kHighInputLatency and kMissedDeadline don't, instead have each COMPARISON indicate which JankType it applies to so it can be independently sized from JankTypes. Bug: 70220906 Bug: 75566601 Test: launching & using maps works Change-Id: I7fd90daeb320b4627e42c3418c89726d860998c1 --- .../proto/android/service/graphicsstats.proto | 5 +- libs/hwui/JankTracker.cpp | 89 +++++++++++-------- 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, 114 insertions(+), 39 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 f42206562fc47..c2fedf5a57223 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 cf29e434a3515..81a79801073c3 100644 --- a/libs/hwui/JankTracker.cpp +++ b/libs/hwui/JankTracker.cpp @@ -38,16 +38,27 @@ namespace android { namespace uirenderer { struct Comparison { + JankType type; + std::function computeThreadshold; FrameInfoIndex start; FrameInfoIndex end; }; -static const Comparison COMPARISONS[] = { - {FrameInfoIndex::IntendedVsync, FrameInfoIndex::Vsync}, - {FrameInfoIndex::OldestInputEvent, FrameInfoIndex::Vsync}, - {FrameInfoIndex::Vsync, FrameInfoIndex::SyncStart}, - {FrameInfoIndex::SyncStart, FrameInfoIndex::IssueDrawCommandsStart}, - {FrameInfoIndex::IssueDrawCommandsStart, FrameInfoIndex::FrameCompleted}, +static const std::array COMPARISONS{ + Comparison{JankType::kMissedVsync, [](nsecs_t) { return 1; }, FrameInfoIndex::IntendedVsync, + FrameInfoIndex::Vsync}, + + Comparison{JankType::kSlowUI, + [](nsecs_t frameInterval) { return static_cast(.5 * frameInterval); }, + FrameInfoIndex::Vsync, FrameInfoIndex::SyncStart}, + + Comparison{JankType::kSlowSync, + [](nsecs_t frameInterval) { return static_cast(.2 * frameInterval); }, + FrameInfoIndex::SyncStart, FrameInfoIndex::IssueDrawCommandsStart}, + + Comparison{JankType::kSlowRT, + [](nsecs_t frameInterval) { return static_cast(.75 * frameInterval); }, + FrameInfoIndex::IssueDrawCommandsStart, FrameInfoIndex::FrameCompleted}, }; // If the event exceeds 10 seconds throw it away, this isn't a jank event @@ -91,24 +102,10 @@ JankTracker::JankTracker(ProfileDataContainer* globalData, const DisplayInfo& di void JankTracker::setFrameInterval(nsecs_t frameInterval) { mFrameInterval = frameInterval; - mThresholds[kMissedVsync] = 1; - /* - * Due to interpolation and sample rate differences between the touch - * panel and the display (example, 85hz touch panel driving a 60hz display) - * we call high latency 1.5 * frameinterval - * - * NOTE: Be careful when tuning this! A theoretical 1,000hz touch panel - * on a 60hz display will show kOldestInputEvent - kIntendedVsync of being 15ms - * Thus this must always be larger than frameInterval, or it will fail - */ - mThresholds[kHighInputLatency] = static_cast(1.5 * frameInterval); - // Note that these do not add up to 1. This is intentional. It's to deal - // with variance in values, and should be sort of an upper-bound on what - // is reasonable to expect. - mThresholds[kSlowUI] = static_cast(.5 * frameInterval); - mThresholds[kSlowSync] = static_cast(.2 * frameInterval); - mThresholds[kSlowRT] = static_cast(.75 * frameInterval); + for (auto& comparison : COMPARISONS) { + mThresholds[comparison.type] = comparison.computeThreadshold(frameInterval); + } } void JankTracker::finishFrame(const FrameInfo& frame) { @@ -129,28 +126,48 @@ 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)) { - return; - } - // Only things like Surface.lockHardwareCanvas() are exempt from tracking - if (frame[FrameInfoIndex::Flags] & EXEMPT_FRAMES_FLAGS) { + if (CC_UNLIKELY(frame[FrameInfoIndex::Flags] & EXEMPT_FRAMES_FLAGS)) { return; } - mData->reportJank(); - (*mGlobalData)->reportJank(); + if (totalDuration > mFrameInterval) { + mData->reportJank(); + (*mGlobalData)->reportJank(); + } - for (int i = 0; i < NUM_BUCKETS; i++) { - int64_t delta = frame.duration(COMPARISONS[i].start, COMPARISONS[i].end); - if (delta >= mThresholds[i] && delta < IGNORE_EXCEEDING) { - mData->reportJankType((JankType)i); - (*mGlobalData)->reportJankType((JankType)i); + 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->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 (auto& comparison : COMPARISONS) { + int64_t delta = frame.duration(comparison.start, comparison.end); + if (delta >= mThresholds[comparison.type] && delta < IGNORE_EXCEEDING) { + mData->reportJankType(comparison.type); + (*mGlobalData)->reportJankType(comparison.type); } } diff --git a/libs/hwui/JankTracker.h b/libs/hwui/JankTracker.h index dc6a7ff5ddb73..110211eda23a7 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 b392ecdde18f8..f9cf549980327 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 1e688ab6fa683..564920b603289 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 e0303a8a62d58..599226bebe845 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 0000000000000..f5e6b317529a0 --- /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