JankTracker.cpp revision 126720aa65fd90105bdf54c04f327f146763c5cf
1/* 2 * Copyright (C) 2015 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16#include "JankTracker.h" 17 18#include "Properties.h" 19 20#include <algorithm> 21#include <cutils/ashmem.h> 22#include <cutils/log.h> 23#include <cstdio> 24#include <errno.h> 25#include <inttypes.h> 26#include <limits> 27#include <cmath> 28#include <sys/mman.h> 29 30namespace android { 31namespace uirenderer { 32 33static const char* JANK_TYPE_NAMES[] = { 34 "Missed Vsync", 35 "High input latency", 36 "Slow UI thread", 37 "Slow bitmap uploads", 38 "Slow issue draw commands", 39}; 40 41struct Comparison { 42 FrameInfoIndex start; 43 FrameInfoIndex end; 44}; 45 46static const Comparison COMPARISONS[] = { 47 {FrameInfoIndex::IntendedVsync, FrameInfoIndex::Vsync}, 48 {FrameInfoIndex::OldestInputEvent, FrameInfoIndex::Vsync}, 49 {FrameInfoIndex::Vsync, FrameInfoIndex::SyncStart}, 50 {FrameInfoIndex::SyncStart, FrameInfoIndex::IssueDrawCommandsStart}, 51 {FrameInfoIndex::IssueDrawCommandsStart, FrameInfoIndex::FrameCompleted}, 52}; 53 54// If the event exceeds 10 seconds throw it away, this isn't a jank event 55// it's an ANR and will be handled as such 56static const int64_t IGNORE_EXCEEDING = seconds_to_nanoseconds(10); 57 58/* 59 * We don't track direct-drawing via Surface:lockHardwareCanvas() 60 * for now 61 * 62 * TODO: kSurfaceCanvas can negatively impact other drawing by using up 63 * time on the RenderThread, figure out how to attribute that as a jank-causer 64 */ 65static const int64_t EXEMPT_FRAMES_FLAGS = FrameInfoFlags::SurfaceCanvas; 66 67// The bucketing algorithm controls so to speak 68// If a frame is <= to this it goes in bucket 0 69static const uint32_t kBucketMinThreshold = 5; 70// If a frame is > this, start counting in increments of 2ms 71static const uint32_t kBucket2msIntervals = 32; 72// If a frame is > this, start counting in increments of 4ms 73static const uint32_t kBucket4msIntervals = 48; 74 75// For testing purposes to try and eliminate test infra overhead we will 76// consider any unknown delay of frame start as part of the test infrastructure 77// and filter it out of the frame profile data 78static FrameInfoIndex sFrameStart = FrameInfoIndex::IntendedVsync; 79 80// The interval of the slow frame histogram 81static const uint32_t kSlowFrameBucketIntervalMs = 50; 82// The start point of the slow frame bucket in ms 83static const uint32_t kSlowFrameBucketStartMs = 150; 84 85// This will be called every frame, performance sensitive 86// Uses bit twiddling to avoid branching while achieving the packing desired 87static uint32_t frameCountIndexForFrameTime(nsecs_t frameTime) { 88 uint32_t index = static_cast<uint32_t>(ns2ms(frameTime)); 89 // If index > kBucketMinThreshold mask will be 0xFFFFFFFF as a result 90 // of negating 1 (twos compliment, yaay) else mask will be 0 91 uint32_t mask = -(index > kBucketMinThreshold); 92 // If index > threshold, this will essentially perform: 93 // amountAboveThreshold = index - threshold; 94 // index = threshold + (amountAboveThreshold / 2) 95 // However if index is <= this will do nothing. It will underflow, do 96 // a right shift by 0 (no-op), then overflow back to the original value 97 index = ((index - kBucket4msIntervals) >> (index > kBucket4msIntervals)) 98 + kBucket4msIntervals; 99 index = ((index - kBucket2msIntervals) >> (index > kBucket2msIntervals)) 100 + kBucket2msIntervals; 101 // If index was < minThreshold at the start of all this it's going to 102 // be a pretty garbage value right now. However, mask is 0 so we'll end 103 // up with the desired result of 0. 104 index = (index - kBucketMinThreshold) & mask; 105 return index; 106} 107 108// Only called when dumping stats, less performance sensitive 109static uint32_t frameTimeForFrameCountIndex(uint32_t index) { 110 index = index + kBucketMinThreshold; 111 if (index > kBucket2msIntervals) { 112 index += (index - kBucket2msIntervals); 113 } 114 if (index > kBucket4msIntervals) { 115 // This works because it was already doubled by the above if 116 // 1 is added to shift slightly more towards the middle of the bucket 117 index += (index - kBucket4msIntervals) + 1; 118 } 119 return index; 120} 121 122JankTracker::JankTracker(nsecs_t frameIntervalNanos) { 123 // By default this will use malloc memory. It may be moved later to ashmem 124 // if there is shared space for it and a request comes in to do that. 125 mData = new ProfileData; 126 reset(); 127 setFrameInterval(frameIntervalNanos); 128} 129 130JankTracker::~JankTracker() { 131 freeData(); 132} 133 134void JankTracker::freeData() { 135 if (mIsMapped) { 136 munmap(mData, sizeof(ProfileData)); 137 } else { 138 delete mData; 139 } 140 mIsMapped = false; 141 mData = nullptr; 142} 143 144void JankTracker::switchStorageToAshmem(int ashmemfd) { 145 int regionSize = ashmem_get_size_region(ashmemfd); 146 if (regionSize < static_cast<int>(sizeof(ProfileData))) { 147 ALOGW("Ashmem region is too small! Received %d, required %u", 148 regionSize, static_cast<unsigned int>(sizeof(ProfileData))); 149 return; 150 } 151 ProfileData* newData = reinterpret_cast<ProfileData*>( 152 mmap(NULL, sizeof(ProfileData), PROT_READ | PROT_WRITE, 153 MAP_SHARED, ashmemfd, 0)); 154 if (newData == MAP_FAILED) { 155 int err = errno; 156 ALOGW("Failed to move profile data to ashmem fd %d, error = %d", 157 ashmemfd, err); 158 return; 159 } 160 161 // The new buffer may have historical data that we want to build on top of 162 // But let's make sure we don't overflow Just In Case 163 uint32_t divider = 0; 164 if (newData->totalFrameCount > (1 << 24)) { 165 divider = 4; 166 } 167 for (size_t i = 0; i < mData->jankTypeCounts.size(); i++) { 168 newData->jankTypeCounts[i] >>= divider; 169 newData->jankTypeCounts[i] += mData->jankTypeCounts[i]; 170 } 171 for (size_t i = 0; i < mData->frameCounts.size(); i++) { 172 newData->frameCounts[i] >>= divider; 173 newData->frameCounts[i] += mData->frameCounts[i]; 174 } 175 newData->jankFrameCount >>= divider; 176 newData->jankFrameCount += mData->jankFrameCount; 177 newData->totalFrameCount >>= divider; 178 newData->totalFrameCount += mData->totalFrameCount; 179 if (newData->statStartTime > mData->statStartTime 180 || newData->statStartTime == 0) { 181 newData->statStartTime = mData->statStartTime; 182 } 183 184 freeData(); 185 mData = newData; 186 mIsMapped = true; 187} 188 189void JankTracker::setFrameInterval(nsecs_t frameInterval) { 190 mFrameInterval = frameInterval; 191 mThresholds[kMissedVsync] = 1; 192 /* 193 * Due to interpolation and sample rate differences between the touch 194 * panel and the display (example, 85hz touch panel driving a 60hz display) 195 * we call high latency 1.5 * frameinterval 196 * 197 * NOTE: Be careful when tuning this! A theoretical 1,000hz touch panel 198 * on a 60hz display will show kOldestInputEvent - kIntendedVsync of being 15ms 199 * Thus this must always be larger than frameInterval, or it will fail 200 */ 201 mThresholds[kHighInputLatency] = static_cast<int64_t>(1.5 * frameInterval); 202 203 // Note that these do not add up to 1. This is intentional. It's to deal 204 // with variance in values, and should be sort of an upper-bound on what 205 // is reasonable to expect. 206 mThresholds[kSlowUI] = static_cast<int64_t>(.5 * frameInterval); 207 mThresholds[kSlowSync] = static_cast<int64_t>(.2 * frameInterval); 208 mThresholds[kSlowRT] = static_cast<int64_t>(.75 * frameInterval); 209 210} 211 212void JankTracker::addFrame(const FrameInfo& frame) { 213 mData->totalFrameCount++; 214 // Fast-path for jank-free frames 215 int64_t totalDuration = frame.duration(sFrameStart, FrameInfoIndex::FrameCompleted); 216 uint32_t framebucket = frameCountIndexForFrameTime(totalDuration); 217 // Keep the fast path as fast as possible. 218 if (CC_LIKELY(totalDuration < mFrameInterval)) { 219 mData->frameCounts[framebucket]++; 220 return; 221 } 222 223 // Only things like Surface.lockHardwareCanvas() are exempt from tracking 224 if (frame[FrameInfoIndex::Flags] & EXEMPT_FRAMES_FLAGS) { 225 return; 226 } 227 228 if (framebucket <= mData->frameCounts.size()) { 229 mData->frameCounts[framebucket]++; 230 } else { 231 framebucket = (ns2ms(totalDuration) - kSlowFrameBucketStartMs) 232 / kSlowFrameBucketIntervalMs; 233 framebucket = std::min(framebucket, 234 static_cast<uint32_t>(mData->slowFrameCounts.size() - 1)); 235 framebucket = std::max(framebucket, 0u); 236 mData->slowFrameCounts[framebucket]++; 237 } 238 239 mData->jankFrameCount++; 240 241 for (int i = 0; i < NUM_BUCKETS; i++) { 242 int64_t delta = frame.duration(COMPARISONS[i].start, COMPARISONS[i].end); 243 if (delta >= mThresholds[i] && delta < IGNORE_EXCEEDING) { 244 mData->jankTypeCounts[i]++; 245 } 246 } 247} 248 249void JankTracker::dumpBuffer(const void* buffer, size_t bufsize, int fd) { 250 if (bufsize < sizeof(ProfileData)) { 251 return; 252 } 253 const ProfileData* data = reinterpret_cast<const ProfileData*>(buffer); 254 dumpData(data, fd); 255} 256 257void JankTracker::dumpData(const ProfileData* data, int fd) { 258 if (sFrameStart != FrameInfoIndex::IntendedVsync) { 259 dprintf(fd, "\nNote: Data has been filtered!"); 260 } 261 dprintf(fd, "\nStats since: %" PRIu64 "ns", data->statStartTime); 262 dprintf(fd, "\nTotal frames rendered: %u", data->totalFrameCount); 263 dprintf(fd, "\nJanky frames: %u (%.2f%%)", data->jankFrameCount, 264 (float) data->jankFrameCount / (float) data->totalFrameCount * 100.0f); 265 dprintf(fd, "\n50th percentile: %ums", findPercentile(data, 50)); 266 dprintf(fd, "\n90th percentile: %ums", findPercentile(data, 90)); 267 dprintf(fd, "\n95th percentile: %ums", findPercentile(data, 95)); 268 dprintf(fd, "\n99th percentile: %ums", findPercentile(data, 99)); 269 for (int i = 0; i < NUM_BUCKETS; i++) { 270 dprintf(fd, "\nNumber %s: %u", JANK_TYPE_NAMES[i], data->jankTypeCounts[i]); 271 } 272 dprintf(fd, "\nHISTOGRAM:"); 273 for (size_t i = 0; i < data->frameCounts.size(); i++) { 274 dprintf(fd, " %ums=%u", frameTimeForFrameCountIndex(i), 275 data->frameCounts[i]); 276 } 277 for (size_t i = 0; i < data->slowFrameCounts.size(); i++) { 278 dprintf(fd, " %zums=%u", (i * kSlowFrameBucketIntervalMs) + kSlowFrameBucketStartMs, 279 data->slowFrameCounts[i]); 280 } 281 dprintf(fd, "\n"); 282} 283 284void JankTracker::reset() { 285 mData->jankTypeCounts.fill(0); 286 mData->frameCounts.fill(0); 287 mData->slowFrameCounts.fill(0); 288 mData->totalFrameCount = 0; 289 mData->jankFrameCount = 0; 290 mData->statStartTime = systemTime(CLOCK_MONOTONIC); 291 sFrameStart = Properties::filterOutTestOverhead 292 ? FrameInfoIndex::HandleInputStart 293 : FrameInfoIndex::IntendedVsync; 294} 295 296uint32_t JankTracker::findPercentile(const ProfileData* data, int percentile) { 297 int pos = percentile * data->totalFrameCount / 100; 298 int remaining = data->totalFrameCount - pos; 299 for (int i = data->slowFrameCounts.size() - 1; i >= 0; i--) { 300 remaining -= data->slowFrameCounts[i]; 301 if (remaining <= 0) { 302 return (i * kSlowFrameBucketIntervalMs) + kSlowFrameBucketStartMs; 303 } 304 } 305 for (int i = data->frameCounts.size() - 1; i >= 0; i--) { 306 remaining -= data->frameCounts[i]; 307 if (remaining <= 0) { 308 return frameTimeForFrameCountIndex(i); 309 } 310 } 311 return 0; 312} 313 314} /* namespace uirenderer */ 315} /* namespace android */ 316