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