John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 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 | |
John Reck | e70c575 | 2015-03-06 14:40:50 -0800 | [diff] [blame] | 18 | #include <algorithm> |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 19 | #include <cutils/ashmem.h> |
| 20 | #include <cutils/log.h> |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 21 | #include <cstdio> |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 22 | #include <errno.h> |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 23 | #include <inttypes.h> |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 24 | #include <sys/mman.h> |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 25 | |
| 26 | namespace android { |
| 27 | namespace uirenderer { |
| 28 | |
| 29 | static const char* JANK_TYPE_NAMES[] = { |
| 30 | "Missed Vsync", |
| 31 | "High input latency", |
| 32 | "Slow UI thread", |
| 33 | "Slow bitmap uploads", |
| 34 | "Slow draw", |
| 35 | }; |
| 36 | |
| 37 | struct Comparison { |
John Reck | c87be99 | 2015-02-20 10:57:22 -0800 | [diff] [blame] | 38 | FrameInfoIndex start; |
| 39 | FrameInfoIndex end; |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 40 | }; |
| 41 | |
| 42 | static const Comparison COMPARISONS[] = { |
| 43 | {FrameInfoIndex::kIntendedVsync, FrameInfoIndex::kVsync}, |
| 44 | {FrameInfoIndex::kOldestInputEvent, FrameInfoIndex::kVsync}, |
| 45 | {FrameInfoIndex::kVsync, FrameInfoIndex::kSyncStart}, |
| 46 | {FrameInfoIndex::kSyncStart, FrameInfoIndex::kIssueDrawCommandsStart}, |
| 47 | {FrameInfoIndex::kIssueDrawCommandsStart, FrameInfoIndex::kFrameCompleted}, |
| 48 | }; |
| 49 | |
| 50 | // If the event exceeds 10 seconds throw it away, this isn't a jank event |
| 51 | // it's an ANR and will be handled as such |
| 52 | static const int64_t IGNORE_EXCEEDING = seconds_to_nanoseconds(10); |
| 53 | |
| 54 | /* |
| 55 | * Frames that are exempt from jank metrics. |
| 56 | * First-draw frames, for example, are expected to |
| 57 | * be slow, this is hidden from the user with window animations and |
| 58 | * other tricks |
| 59 | * |
| 60 | * Similarly, we don't track direct-drawing via Surface:lockHardwareCanvas() |
| 61 | * for now |
| 62 | * |
| 63 | * TODO: kSurfaceCanvas can negatively impact other drawing by using up |
| 64 | * time on the RenderThread, figure out how to attribute that as a jank-causer |
| 65 | */ |
| 66 | static const int64_t EXEMPT_FRAMES_FLAGS |
| 67 | = FrameInfoFlags::kWindowLayoutChanged |
| 68 | | FrameInfoFlags::kSurfaceCanvas; |
| 69 | |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 70 | // The bucketing algorithm controls so to speak |
| 71 | // If a frame is <= to this it goes in bucket 0 |
| 72 | static const uint32_t kBucketMinThreshold = 7; |
| 73 | // If a frame is > this, start counting in increments of 2ms |
| 74 | static const uint32_t kBucket2msIntervals = 32; |
| 75 | // If a frame is > this, start counting in increments of 4ms |
| 76 | static const uint32_t kBucket4msIntervals = 48; |
| 77 | |
| 78 | // This will be called every frame, performance sensitive |
| 79 | // Uses bit twiddling to avoid branching while achieving the packing desired |
| 80 | static uint32_t frameCountIndexForFrameTime(nsecs_t frameTime, uint32_t max) { |
| 81 | uint32_t index = static_cast<uint32_t>(ns2ms(frameTime)); |
| 82 | // If index > kBucketMinThreshold mask will be 0xFFFFFFFF as a result |
| 83 | // of negating 1 (twos compliment, yaay) else mask will be 0 |
| 84 | uint32_t mask = -(index > kBucketMinThreshold); |
| 85 | // If index > threshold, this will essentially perform: |
| 86 | // amountAboveThreshold = index - threshold; |
| 87 | // index = threshold + (amountAboveThreshold / 2) |
| 88 | // However if index is <= this will do nothing. It will underflow, do |
| 89 | // a right shift by 0 (no-op), then overflow back to the original value |
| 90 | index = ((index - kBucket4msIntervals) >> (index > kBucket4msIntervals)) |
| 91 | + kBucket4msIntervals; |
| 92 | index = ((index - kBucket2msIntervals) >> (index > kBucket2msIntervals)) |
| 93 | + kBucket2msIntervals; |
| 94 | // If index was < minThreshold at the start of all this it's going to |
| 95 | // be a pretty garbage value right now. However, mask is 0 so we'll end |
| 96 | // up with the desired result of 0. |
| 97 | index = (index - kBucketMinThreshold) & mask; |
| 98 | return index < max ? index : max; |
| 99 | } |
| 100 | |
| 101 | // Only called when dumping stats, less performance sensitive |
| 102 | static uint32_t frameTimeForFrameCountIndex(uint32_t index) { |
| 103 | index = index + kBucketMinThreshold; |
| 104 | if (index > kBucket2msIntervals) { |
| 105 | index += (index - kBucket2msIntervals); |
| 106 | } |
| 107 | if (index > kBucket4msIntervals) { |
| 108 | // This works because it was already doubled by the above if |
| 109 | // 1 is added to shift slightly more towards the middle of the bucket |
| 110 | index += (index - kBucket4msIntervals) + 1; |
| 111 | } |
| 112 | return index; |
| 113 | } |
| 114 | |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 115 | JankTracker::JankTracker(nsecs_t frameIntervalNanos) { |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 116 | // By default this will use malloc memory. It may be moved later to ashmem |
| 117 | // if there is shared space for it and a request comes in to do that. |
| 118 | mData = new ProfileData; |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 119 | reset(); |
| 120 | setFrameInterval(frameIntervalNanos); |
| 121 | } |
| 122 | |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 123 | JankTracker::~JankTracker() { |
| 124 | freeData(); |
| 125 | } |
| 126 | |
| 127 | void JankTracker::freeData() { |
| 128 | if (mIsMapped) { |
| 129 | munmap(mData, sizeof(ProfileData)); |
| 130 | } else { |
| 131 | delete mData; |
| 132 | } |
| 133 | mIsMapped = false; |
| 134 | mData = nullptr; |
| 135 | } |
| 136 | |
| 137 | void JankTracker::switchStorageToAshmem(int ashmemfd) { |
| 138 | int regionSize = ashmem_get_size_region(ashmemfd); |
| 139 | if (regionSize < static_cast<int>(sizeof(ProfileData))) { |
| 140 | ALOGW("Ashmem region is too small! Received %d, required %u", |
| 141 | regionSize, sizeof(ProfileData)); |
| 142 | return; |
| 143 | } |
| 144 | ProfileData* newData = reinterpret_cast<ProfileData*>( |
| 145 | mmap(NULL, sizeof(ProfileData), PROT_READ | PROT_WRITE, |
| 146 | MAP_SHARED, ashmemfd, 0)); |
| 147 | if (newData == MAP_FAILED) { |
| 148 | int err = errno; |
| 149 | ALOGW("Failed to move profile data to ashmem fd %d, error = %d", |
| 150 | ashmemfd, err); |
| 151 | return; |
| 152 | } |
| 153 | |
| 154 | // The new buffer may have historical data that we want to build on top of |
| 155 | // But let's make sure we don't overflow Just In Case |
| 156 | uint32_t divider = 0; |
| 157 | if (newData->totalFrameCount > (1 << 24)) { |
| 158 | divider = 4; |
| 159 | } |
| 160 | for (size_t i = 0; i < mData->jankTypeCounts.size(); i++) { |
| 161 | newData->jankTypeCounts[i] >>= divider; |
| 162 | newData->jankTypeCounts[i] += mData->jankTypeCounts[i]; |
| 163 | } |
| 164 | for (size_t i = 0; i < mData->frameCounts.size(); i++) { |
| 165 | newData->frameCounts[i] >>= divider; |
| 166 | newData->frameCounts[i] += mData->frameCounts[i]; |
| 167 | } |
| 168 | newData->jankFrameCount >>= divider; |
| 169 | newData->jankFrameCount += mData->jankFrameCount; |
| 170 | newData->totalFrameCount >>= divider; |
| 171 | newData->totalFrameCount += mData->totalFrameCount; |
| 172 | |
| 173 | freeData(); |
| 174 | mData = newData; |
| 175 | mIsMapped = true; |
| 176 | } |
| 177 | |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 178 | void JankTracker::setFrameInterval(nsecs_t frameInterval) { |
| 179 | mFrameInterval = frameInterval; |
| 180 | mThresholds[kMissedVsync] = 1; |
| 181 | /* |
| 182 | * Due to interpolation and sample rate differences between the touch |
| 183 | * panel and the display (example, 85hz touch panel driving a 60hz display) |
| 184 | * we call high latency 1.5 * frameinterval |
| 185 | * |
| 186 | * NOTE: Be careful when tuning this! A theoretical 1,000hz touch panel |
| 187 | * on a 60hz display will show kOldestInputEvent - kIntendedVsync of being 15ms |
| 188 | * Thus this must always be larger than frameInterval, or it will fail |
| 189 | */ |
| 190 | mThresholds[kHighInputLatency] = static_cast<int64_t>(1.5 * frameInterval); |
| 191 | |
| 192 | // Note that these do not add up to 1. This is intentional. It's to deal |
| 193 | // with variance in values, and should be sort of an upper-bound on what |
| 194 | // is reasonable to expect. |
| 195 | mThresholds[kSlowUI] = static_cast<int64_t>(.5 * frameInterval); |
| 196 | mThresholds[kSlowSync] = static_cast<int64_t>(.2 * frameInterval); |
| 197 | mThresholds[kSlowRT] = static_cast<int64_t>(.75 * frameInterval); |
| 198 | |
| 199 | } |
| 200 | |
| 201 | void JankTracker::addFrame(const FrameInfo& frame) { |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 202 | mData->totalFrameCount++; |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 203 | // Fast-path for jank-free frames |
John Reck | c87be99 | 2015-02-20 10:57:22 -0800 | [diff] [blame] | 204 | int64_t totalDuration = |
| 205 | frame[FrameInfoIndex::kFrameCompleted] - frame[FrameInfoIndex::kIntendedVsync]; |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 206 | uint32_t framebucket = frameCountIndexForFrameTime( |
| 207 | totalDuration, mData->frameCounts.size()); |
John Reck | e70c575 | 2015-03-06 14:40:50 -0800 | [diff] [blame] | 208 | // Keep the fast path as fast as possible. |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 209 | if (CC_LIKELY(totalDuration < mFrameInterval)) { |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 210 | mData->frameCounts[framebucket]++; |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 211 | return; |
| 212 | } |
| 213 | |
John Reck | c87be99 | 2015-02-20 10:57:22 -0800 | [diff] [blame] | 214 | if (frame[FrameInfoIndex::kFlags] & EXEMPT_FRAMES_FLAGS) { |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 215 | return; |
| 216 | } |
| 217 | |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 218 | mData->frameCounts[framebucket]++; |
| 219 | mData->jankFrameCount++; |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 220 | |
| 221 | for (int i = 0; i < NUM_BUCKETS; i++) { |
| 222 | int64_t delta = frame[COMPARISONS[i].end] - frame[COMPARISONS[i].start]; |
| 223 | if (delta >= mThresholds[i] && delta < IGNORE_EXCEEDING) { |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 224 | mData->jankTypeCounts[i]++; |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 225 | } |
| 226 | } |
| 227 | } |
| 228 | |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 229 | void JankTracker::dumpBuffer(const void* buffer, size_t bufsize, int fd) { |
| 230 | if (bufsize < sizeof(ProfileData)) { |
| 231 | return; |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 232 | } |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 233 | const ProfileData* data = reinterpret_cast<const ProfileData*>(buffer); |
| 234 | dumpData(data, fd); |
| 235 | } |
| 236 | |
| 237 | void JankTracker::dumpData(const ProfileData* data, int fd) { |
| 238 | dprintf(fd, "\nTotal frames rendered: %u", data->totalFrameCount); |
| 239 | dprintf(fd, "\nJanky frames: %u (%.2f%%)", data->jankFrameCount, |
| 240 | (float) data->jankFrameCount / (float) data->totalFrameCount * 100.0f); |
| 241 | dprintf(fd, "\n90th percentile: %ums", findPercentile(data, 90)); |
| 242 | dprintf(fd, "\n95th percentile: %ums", findPercentile(data, 95)); |
| 243 | dprintf(fd, "\n99th percentile: %ums", findPercentile(data, 99)); |
| 244 | for (int i = 0; i < NUM_BUCKETS; i++) { |
| 245 | dprintf(fd, "\nNumber %s: %u", JANK_TYPE_NAMES[i], data->jankTypeCounts[i]); |
| 246 | } |
| 247 | dprintf(fd, "\n"); |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 248 | } |
| 249 | |
| 250 | void JankTracker::reset() { |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 251 | mData->jankTypeCounts.fill(0); |
| 252 | mData->frameCounts.fill(0); |
| 253 | mData->totalFrameCount = 0; |
| 254 | mData->jankFrameCount = 0; |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 255 | } |
| 256 | |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 257 | uint32_t JankTracker::findPercentile(const ProfileData* data, int percentile) { |
| 258 | int pos = percentile * data->totalFrameCount / 100; |
| 259 | int remaining = data->totalFrameCount - pos; |
| 260 | for (int i = data->frameCounts.size() - 1; i >= 0; i--) { |
| 261 | remaining -= data->frameCounts[i]; |
John Reck | e70c575 | 2015-03-06 14:40:50 -0800 | [diff] [blame] | 262 | if (remaining <= 0) { |
John Reck | edc524c | 2015-03-18 15:24:33 -0700 | [diff] [blame^] | 263 | return frameTimeForFrameCountIndex(i); |
John Reck | e70c575 | 2015-03-06 14:40:50 -0800 | [diff] [blame] | 264 | } |
| 265 | } |
| 266 | return 0; |
| 267 | } |
| 268 | |
John Reck | ba6adf6 | 2015-02-19 14:36:50 -0800 | [diff] [blame] | 269 | } /* namespace uirenderer */ |
| 270 | } /* namespace android */ |