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