blob: f4a0319e7ca597a721d55ba07ecd3c1fe6089689 [file] [log] [blame]
Yiwei Zhang0102ad22018-05-02 17:37:17 -07001/*
2 * Copyright 2018 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 */
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -080016
Yiwei Zhang0102ad22018-05-02 17:37:17 -070017#undef LOG_TAG
18#define LOG_TAG "TimeStats"
19#define ATRACE_TAG ATRACE_TAG_GRAPHICS
20
21#include "TimeStats.h"
22
23#include <android-base/stringprintf.h>
Alec Mouri37384342020-01-02 17:23:37 -080024#include <android/util/ProtoOutputStream.h>
Yiwei Zhang0102ad22018-05-02 17:37:17 -070025#include <log/log.h>
Yiwei Zhang0102ad22018-05-02 17:37:17 -070026#include <utils/String8.h>
Yiwei Zhang3a226d22018-10-16 09:23:03 -070027#include <utils/Timers.h>
Yiwei Zhang0102ad22018-05-02 17:37:17 -070028#include <utils/Trace.h>
29
30#include <algorithm>
Alec Mouri9519bf12019-11-15 16:54:44 -080031#include <chrono>
Yiwei Zhang0102ad22018-05-02 17:37:17 -070032
Alec Mouri9a29e672020-09-14 12:39:14 -070033#include "timestatsproto/TimeStatsHelper.h"
34
Yiwei Zhang0102ad22018-05-02 17:37:17 -070035namespace android {
36
Alec Mourifb571ea2019-01-24 18:42:10 -080037namespace impl {
38
Tej Singh2a457b62020-01-31 16:16:10 -080039AStatsManager_PullAtomCallbackReturn TimeStats::pullAtomCallback(int32_t atom_tag,
40 AStatsEventList* data,
41 void* cookie) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +000042 impl::TimeStats* timeStats = reinterpret_cast<impl::TimeStats*>(cookie);
Tej Singh2a457b62020-01-31 16:16:10 -080043 AStatsManager_PullAtomCallbackReturn result = AStatsManager_PULL_SKIP;
Alec Mouri37384342020-01-02 17:23:37 -080044 if (atom_tag == android::util::SURFACEFLINGER_STATS_GLOBAL_INFO) {
Alec Mouri3ecd5cd2020-01-29 12:53:07 -080045 result = timeStats->populateGlobalAtom(data);
Alec Mouri37384342020-01-02 17:23:37 -080046 } else if (atom_tag == android::util::SURFACEFLINGER_STATS_LAYER_INFO) {
Alec Mouri3ecd5cd2020-01-29 12:53:07 -080047 result = timeStats->populateLayerAtom(data);
Alec Mouri8e2f31b2020-01-16 22:04:35 +000048 }
49
Alec Mouri3ecd5cd2020-01-29 12:53:07 -080050 // Enable timestats now. The first full pull for a given build is expected to
51 // have empty or very little stats, as stats are first enabled after the
52 // first pull is completed for either the global or layer stats.
53 timeStats->enable();
54 return result;
Alec Mouri37384342020-01-02 17:23:37 -080055}
Alec Mouri8e2f31b2020-01-16 22:04:35 +000056
Alec Mouri37384342020-01-02 17:23:37 -080057namespace {
58// Histograms align with the order of fields in SurfaceflingerStatsLayerInfo.
59const std::array<std::string, 6> kHistogramNames = {
60 "present2present", "post2present", "acquire2present",
61 "latch2present", "desired2present", "post2acquire",
62};
Alec Mouri8e2f31b2020-01-16 22:04:35 +000063
Alec Mouri37384342020-01-02 17:23:37 -080064std::string histogramToProtoByteString(const std::unordered_map<int32_t, int32_t>& histogram,
65 size_t maxPulledHistogramBuckets) {
66 auto buckets = std::vector<std::pair<int32_t, int32_t>>(histogram.begin(), histogram.end());
67 std::sort(buckets.begin(), buckets.end(),
68 [](std::pair<int32_t, int32_t>& left, std::pair<int32_t, int32_t>& right) {
69 return left.second > right.second;
70 });
71
72 util::ProtoOutputStream proto;
73 int histogramSize = 0;
74 for (const auto& bucket : buckets) {
75 if (++histogramSize > maxPulledHistogramBuckets) {
76 break;
77 }
78 proto.write(android::util::FIELD_TYPE_INT32 | android::util::FIELD_COUNT_REPEATED |
79 1 /* field id */,
80 (int32_t)bucket.first);
81 proto.write(android::util::FIELD_TYPE_INT64 | android::util::FIELD_COUNT_REPEATED |
82 2 /* field id */,
83 (int64_t)bucket.second);
84 }
85
86 std::string byteString;
87 proto.serializeToString(&byteString);
88 return byteString;
89}
90} // namespace
91
Alec Mouridfad9002020-02-12 17:49:09 -080092AStatsManager_PullAtomCallbackReturn TimeStats::populateGlobalAtom(AStatsEventList* data) {
93 std::lock_guard<std::mutex> lock(mMutex);
94
95 if (mTimeStats.statsStart == 0) {
96 return AStatsManager_PULL_SKIP;
97 }
98 flushPowerTimeLocked();
99
100 AStatsEvent* event = mStatsDelegate->addStatsEventToPullData(data);
101 mStatsDelegate->statsEventSetAtomId(event, android::util::SURFACEFLINGER_STATS_GLOBAL_INFO);
102 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.totalFrames);
103 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.missedFrames);
104 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.clientCompositionFrames);
105 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.displayOnTime);
106 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.presentToPresent.totalTime());
107 mStatsDelegate->statsEventWriteInt32(event, mTimeStats.displayEventConnectionsCount);
108 std::string frameDurationBytes =
109 histogramToProtoByteString(mTimeStats.frameDuration.hist, mMaxPulledHistogramBuckets);
110 mStatsDelegate->statsEventWriteByteArray(event, (const uint8_t*)frameDurationBytes.c_str(),
111 frameDurationBytes.size());
112 std::string renderEngineTimingBytes =
113 histogramToProtoByteString(mTimeStats.renderEngineTiming.hist,
114 mMaxPulledHistogramBuckets);
115 mStatsDelegate->statsEventWriteByteArray(event, (const uint8_t*)renderEngineTimingBytes.c_str(),
116 renderEngineTimingBytes.size());
Alec Mouri9a29e672020-09-14 12:39:14 -0700117
118 mStatsDelegate->statsEventWriteInt32(event, mTimeStats.jankPayload.totalFrames);
119 mStatsDelegate->statsEventWriteInt32(event, mTimeStats.jankPayload.totalJankyFrames);
120 mStatsDelegate->statsEventWriteInt32(event, mTimeStats.jankPayload.totalSFLongCpu);
121 mStatsDelegate->statsEventWriteInt32(event, mTimeStats.jankPayload.totalSFLongGpu);
122 mStatsDelegate->statsEventWriteInt32(event, mTimeStats.jankPayload.totalSFUnattributed);
123 mStatsDelegate->statsEventWriteInt32(event, mTimeStats.jankPayload.totalAppUnattributed);
Alec Mouridfad9002020-02-12 17:49:09 -0800124 mStatsDelegate->statsEventBuild(event);
125 clearGlobalLocked();
126
127 return AStatsManager_PULL_SUCCESS;
128}
129
Tej Singh2a457b62020-01-31 16:16:10 -0800130AStatsManager_PullAtomCallbackReturn TimeStats::populateLayerAtom(AStatsEventList* data) {
Alec Mouri37384342020-01-02 17:23:37 -0800131 std::lock_guard<std::mutex> lock(mMutex);
132
133 std::vector<TimeStatsHelper::TimeStatsLayer const*> dumpStats;
134 for (const auto& ele : mTimeStats.stats) {
135 dumpStats.push_back(&ele.second);
136 }
137
138 std::sort(dumpStats.begin(), dumpStats.end(),
139 [](TimeStatsHelper::TimeStatsLayer const* l,
140 TimeStatsHelper::TimeStatsLayer const* r) {
141 return l->totalFrames > r->totalFrames;
142 });
143
144 if (mMaxPulledLayers < dumpStats.size()) {
145 dumpStats.resize(mMaxPulledLayers);
146 }
147
148 for (const auto& layer : dumpStats) {
Tej Singh2a457b62020-01-31 16:16:10 -0800149 AStatsEvent* event = mStatsDelegate->addStatsEventToPullData(data);
Alec Mouri37384342020-01-02 17:23:37 -0800150 mStatsDelegate->statsEventSetAtomId(event, android::util::SURFACEFLINGER_STATS_LAYER_INFO);
151 mStatsDelegate->statsEventWriteString8(event, layer->layerName.c_str());
152 mStatsDelegate->statsEventWriteInt64(event, layer->totalFrames);
153 mStatsDelegate->statsEventWriteInt64(event, layer->droppedFrames);
154
155 for (const auto& name : kHistogramNames) {
156 const auto& histogram = layer->deltas.find(name);
157 if (histogram == layer->deltas.cend()) {
158 mStatsDelegate->statsEventWriteByteArray(event, nullptr, 0);
159 } else {
160 std::string bytes = histogramToProtoByteString(histogram->second.hist,
161 mMaxPulledHistogramBuckets);
162 mStatsDelegate->statsEventWriteByteArray(event, (const uint8_t*)bytes.c_str(),
163 bytes.size());
164 }
165 }
166
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -0800167 mStatsDelegate->statsEventWriteInt64(event, layer->lateAcquireFrames);
168 mStatsDelegate->statsEventWriteInt64(event, layer->badDesiredPresentFrames);
Alec Mouri9a29e672020-09-14 12:39:14 -0700169 mStatsDelegate->statsEventWriteInt32(event, layer->uid);
170 mStatsDelegate->statsEventWriteInt32(event, layer->jankPayload.totalFrames);
171 mStatsDelegate->statsEventWriteInt32(event, layer->jankPayload.totalJankyFrames);
172 mStatsDelegate->statsEventWriteInt32(event, layer->jankPayload.totalSFLongCpu);
173 mStatsDelegate->statsEventWriteInt32(event, layer->jankPayload.totalSFLongGpu);
174 mStatsDelegate->statsEventWriteInt32(event, layer->jankPayload.totalSFUnattributed);
175 mStatsDelegate->statsEventWriteInt32(event, layer->jankPayload.totalAppUnattributed);
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -0800176
Alec Mouri37384342020-01-02 17:23:37 -0800177 mStatsDelegate->statsEventBuild(event);
178 }
179 clearLayersLocked();
180
Tej Singh2a457b62020-01-31 16:16:10 -0800181 return AStatsManager_PULL_SUCCESS;
Alec Mouri37384342020-01-02 17:23:37 -0800182}
183
184TimeStats::TimeStats() : TimeStats(nullptr, std::nullopt, std::nullopt) {}
185
186TimeStats::TimeStats(std::unique_ptr<StatsEventDelegate> statsDelegate,
187 std::optional<size_t> maxPulledLayers,
188 std::optional<size_t> maxPulledHistogramBuckets) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000189 if (statsDelegate != nullptr) {
190 mStatsDelegate = std::move(statsDelegate);
191 }
Alec Mouri37384342020-01-02 17:23:37 -0800192
193 if (maxPulledLayers) {
194 mMaxPulledLayers = *maxPulledLayers;
195 }
196
197 if (maxPulledHistogramBuckets) {
198 mMaxPulledHistogramBuckets = *maxPulledHistogramBuckets;
199 }
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000200}
201
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800202TimeStats::~TimeStats() {
203 std::lock_guard<std::mutex> lock(mMutex);
Tej Singh38a4b212020-03-13 19:04:51 -0700204 mStatsDelegate->clearStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO);
205 mStatsDelegate->clearStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO);
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800206}
207
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000208void TimeStats::onBootFinished() {
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800209 std::lock_guard<std::mutex> lock(mMutex);
Tej Singh38a4b212020-03-13 19:04:51 -0700210 mStatsDelegate->setStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
211 nullptr, TimeStats::pullAtomCallback, this);
212 mStatsDelegate->setStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
213 nullptr, TimeStats::pullAtomCallback, this);
Alec Mourib3885ad2019-09-06 17:08:55 -0700214}
215
Dominik Laskowskic2867142019-01-21 11:33:38 -0800216void TimeStats::parseArgs(bool asProto, const Vector<String16>& args, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700217 ATRACE_CALL();
218
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700219 std::unordered_map<std::string, int32_t> argsMap;
Dominik Laskowskic2867142019-01-21 11:33:38 -0800220 for (size_t index = 0; index < args.size(); ++index) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700221 argsMap[std::string(String8(args[index]).c_str())] = index;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700222 }
223
224 if (argsMap.count("-disable")) {
225 disable();
226 }
227
228 if (argsMap.count("-dump")) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700229 std::optional<uint32_t> maxLayers = std::nullopt;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700230 auto iter = argsMap.find("-maxlayers");
231 if (iter != argsMap.end() && iter->second + 1 < static_cast<int32_t>(args.size())) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700232 int64_t value = strtol(String8(args[iter->second + 1]).c_str(), nullptr, 10);
233 value = std::clamp(value, int64_t(0), int64_t(UINT32_MAX));
234 maxLayers = static_cast<uint32_t>(value);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700235 }
236
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700237 dump(asProto, maxLayers, result);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700238 }
239
240 if (argsMap.count("-clear")) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000241 clearAll();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700242 }
243
244 if (argsMap.count("-enable")) {
245 enable();
246 }
247}
248
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700249std::string TimeStats::miniDump() {
250 ATRACE_CALL();
251
252 std::string result = "TimeStats miniDump:\n";
253 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange926ab52019-08-14 15:16:00 -0700254 android::base::StringAppendF(&result, "Number of layers currently being tracked is %zu\n",
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700255 mTimeStatsTracker.size());
Yiwei Zhange926ab52019-08-14 15:16:00 -0700256 android::base::StringAppendF(&result, "Number of layers in the stats pool is %zu\n",
257 mTimeStats.stats.size());
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700258 return result;
259}
260
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700261void TimeStats::incrementTotalFrames() {
262 if (!mEnabled.load()) return;
263
264 ATRACE_CALL();
265
266 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700267 mTimeStats.totalFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700268}
269
Yiwei Zhang621f9d42018-05-07 10:40:55 -0700270void TimeStats::incrementMissedFrames() {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700271 if (!mEnabled.load()) return;
272
273 ATRACE_CALL();
274
275 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700276 mTimeStats.missedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700277}
278
279void TimeStats::incrementClientCompositionFrames() {
280 if (!mEnabled.load()) return;
281
282 ATRACE_CALL();
283
284 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700285 mTimeStats.clientCompositionFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700286}
287
Vishnu Nair9b079a22020-01-21 14:36:08 -0800288void TimeStats::incrementClientCompositionReusedFrames() {
289 if (!mEnabled.load()) return;
290
291 ATRACE_CALL();
292
293 std::lock_guard<std::mutex> lock(mMutex);
294 mTimeStats.clientCompositionReusedFrames++;
295}
296
Alec Mouri8de697e2020-03-19 10:52:01 -0700297void TimeStats::incrementRefreshRateSwitches() {
298 if (!mEnabled.load()) return;
299
300 ATRACE_CALL();
301
302 std::lock_guard<std::mutex> lock(mMutex);
303 mTimeStats.refreshRateSwitches++;
304}
305
Alec Mouri8f7a0102020-04-15 12:11:10 -0700306void TimeStats::incrementCompositionStrategyChanges() {
307 if (!mEnabled.load()) return;
308
309 ATRACE_CALL();
310
311 std::lock_guard<std::mutex> lock(mMutex);
312 mTimeStats.compositionStrategyChanges++;
313}
314
Alec Mouri717bcb62020-02-10 17:07:19 -0800315void TimeStats::recordDisplayEventConnectionCount(int32_t count) {
316 if (!mEnabled.load()) return;
317
318 ATRACE_CALL();
319
320 std::lock_guard<std::mutex> lock(mMutex);
321 mTimeStats.displayEventConnectionsCount =
322 std::max(mTimeStats.displayEventConnectionsCount, count);
323}
324
Alec Mouri9519bf12019-11-15 16:54:44 -0800325static int32_t msBetween(nsecs_t start, nsecs_t end) {
326 int64_t delta = std::chrono::duration_cast<std::chrono::milliseconds>(
327 std::chrono::nanoseconds(end - start))
328 .count();
329 delta = std::clamp(delta, int64_t(INT32_MIN), int64_t(INT32_MAX));
330 return static_cast<int32_t>(delta);
331}
332
333void TimeStats::recordFrameDuration(nsecs_t startTime, nsecs_t endTime) {
334 if (!mEnabled.load()) return;
335
336 std::lock_guard<std::mutex> lock(mMutex);
Peiyong Lin65248e02020-04-18 21:15:07 -0700337 if (mPowerTime.powerMode == PowerMode::ON) {
Alec Mouri9519bf12019-11-15 16:54:44 -0800338 mTimeStats.frameDuration.insert(msBetween(startTime, endTime));
339 }
340}
341
Alec Mourie4034bb2019-11-19 12:45:54 -0800342void TimeStats::recordRenderEngineDuration(nsecs_t startTime, nsecs_t endTime) {
343 if (!mEnabled.load()) return;
344
345 std::lock_guard<std::mutex> lock(mMutex);
346 if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
347 ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
348 mGlobalRecord.renderEngineDurations.pop_front();
349 }
350 mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
351}
352
353void TimeStats::recordRenderEngineDuration(nsecs_t startTime,
354 const std::shared_ptr<FenceTime>& endTime) {
355 if (!mEnabled.load()) return;
356
357 std::lock_guard<std::mutex> lock(mMutex);
358 if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
359 ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
360 mGlobalRecord.renderEngineDurations.pop_front();
361 }
362 mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
363}
364
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800365bool TimeStats::recordReadyLocked(int32_t layerId, TimeRecord* timeRecord) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700366 if (!timeRecord->ready) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800367 ALOGV("[%d]-[%" PRIu64 "]-presentFence is still not received", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700368 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700369 return false;
370 }
371
372 if (timeRecord->acquireFence != nullptr) {
373 if (timeRecord->acquireFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
374 return false;
375 }
376 if (timeRecord->acquireFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700377 timeRecord->frameTime.acquireTime = timeRecord->acquireFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700378 timeRecord->acquireFence = nullptr;
379 } else {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800380 ALOGV("[%d]-[%" PRIu64 "]-acquireFence signal time is invalid", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700381 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700382 }
383 }
384
385 if (timeRecord->presentFence != nullptr) {
386 if (timeRecord->presentFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
387 return false;
388 }
389 if (timeRecord->presentFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700390 timeRecord->frameTime.presentTime = timeRecord->presentFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700391 timeRecord->presentFence = nullptr;
392 } else {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800393 ALOGV("[%d]-[%" PRIu64 "]-presentFence signal time invalid", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700394 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700395 }
396 }
397
398 return true;
399}
400
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800401void TimeStats::flushAvailableRecordsToStatsLocked(int32_t layerId) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700402 ATRACE_CALL();
403
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800404 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700405 TimeRecord& prevTimeRecord = layerRecord.prevTimeRecord;
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700406 std::deque<TimeRecord>& timeRecords = layerRecord.timeRecords;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700407 while (!timeRecords.empty()) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800408 if (!recordReadyLocked(layerId, &timeRecords[0])) break;
409 ALOGV("[%d]-[%" PRIu64 "]-presentFenceTime[%" PRId64 "]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700410 timeRecords[0].frameTime.frameNumber, timeRecords[0].frameTime.presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700411
412 if (prevTimeRecord.ready) {
Alec Mouri9a29e672020-09-14 12:39:14 -0700413 uid_t uid = layerRecord.uid;
Yiwei Zhangeafa5cc2019-07-26 15:06:25 -0700414 const std::string& layerName = layerRecord.layerName;
Alec Mouri9a29e672020-09-14 12:39:14 -0700415 if (!mTimeStats.stats.count({uid, layerName})) {
416 mTimeStats.stats[{uid, layerName}].uid = uid;
417 mTimeStats.stats[{uid, layerName}].layerName = layerName;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700418 }
Alec Mouri9a29e672020-09-14 12:39:14 -0700419 TimeStatsHelper::TimeStatsLayer& timeStatsLayer = mTimeStats.stats[{uid, layerName}];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700420 timeStatsLayer.totalFrames++;
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700421 timeStatsLayer.droppedFrames += layerRecord.droppedFrames;
Alec Mouri91f6df32020-01-30 08:48:58 -0800422 timeStatsLayer.lateAcquireFrames += layerRecord.lateAcquireFrames;
423 timeStatsLayer.badDesiredPresentFrames += layerRecord.badDesiredPresentFrames;
424
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700425 layerRecord.droppedFrames = 0;
Alec Mouri91f6df32020-01-30 08:48:58 -0800426 layerRecord.lateAcquireFrames = 0;
427 layerRecord.badDesiredPresentFrames = 0;
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700428
429 const int32_t postToAcquireMs = msBetween(timeRecords[0].frameTime.postTime,
430 timeRecords[0].frameTime.acquireTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800431 ALOGV("[%d]-[%" PRIu64 "]-post2acquire[%d]", layerId,
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700432 timeRecords[0].frameTime.frameNumber, postToAcquireMs);
433 timeStatsLayer.deltas["post2acquire"].insert(postToAcquireMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700434
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700435 const int32_t postToPresentMs = msBetween(timeRecords[0].frameTime.postTime,
436 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800437 ALOGV("[%d]-[%" PRIu64 "]-post2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700438 timeRecords[0].frameTime.frameNumber, postToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700439 timeStatsLayer.deltas["post2present"].insert(postToPresentMs);
440
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700441 const int32_t acquireToPresentMs = msBetween(timeRecords[0].frameTime.acquireTime,
442 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800443 ALOGV("[%d]-[%" PRIu64 "]-acquire2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700444 timeRecords[0].frameTime.frameNumber, acquireToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700445 timeStatsLayer.deltas["acquire2present"].insert(acquireToPresentMs);
446
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700447 const int32_t latchToPresentMs = msBetween(timeRecords[0].frameTime.latchTime,
448 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800449 ALOGV("[%d]-[%" PRIu64 "]-latch2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700450 timeRecords[0].frameTime.frameNumber, latchToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700451 timeStatsLayer.deltas["latch2present"].insert(latchToPresentMs);
452
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700453 const int32_t desiredToPresentMs = msBetween(timeRecords[0].frameTime.desiredTime,
454 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800455 ALOGV("[%d]-[%" PRIu64 "]-desired2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700456 timeRecords[0].frameTime.frameNumber, desiredToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700457 timeStatsLayer.deltas["desired2present"].insert(desiredToPresentMs);
458
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700459 const int32_t presentToPresentMs = msBetween(prevTimeRecord.frameTime.presentTime,
460 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800461 ALOGV("[%d]-[%" PRIu64 "]-present2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700462 timeRecords[0].frameTime.frameNumber, presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700463 timeStatsLayer.deltas["present2present"].insert(presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700464 }
465 prevTimeRecord = timeRecords[0];
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700466 timeRecords.pop_front();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700467 layerRecord.waitData--;
468 }
469}
470
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700471static constexpr const char* kPopupWindowPrefix = "PopupWindow";
472static const size_t kMinLenLayerName = std::strlen(kPopupWindowPrefix);
Yiwei Zhangbd408322018-10-15 18:31:53 -0700473
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700474// Avoid tracking the "PopupWindow:<random hash>#<number>" layers
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700475static bool layerNameIsValid(const std::string& layerName) {
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700476 return layerName.length() >= kMinLenLayerName &&
477 layerName.compare(0, kMinLenLayerName, kPopupWindowPrefix) != 0;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700478}
479
Alec Mouri9a29e672020-09-14 12:39:14 -0700480bool TimeStats::canAddNewAggregatedStats(uid_t uid, const std::string& layerName) {
481 return mTimeStats.stats.count({uid, layerName}) > 0 ||
482 mTimeStats.stats.size() < MAX_NUM_LAYER_STATS;
483}
484
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800485void TimeStats::setPostTime(int32_t layerId, uint64_t frameNumber, const std::string& layerName,
Alec Mouri9a29e672020-09-14 12:39:14 -0700486 uid_t uid, nsecs_t postTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700487 if (!mEnabled.load()) return;
488
489 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800490 ALOGV("[%d]-[%" PRIu64 "]-[%s]-PostTime[%" PRId64 "]", layerId, frameNumber, layerName.c_str(),
Yiwei Zhang8e8fe522018-11-02 18:34:07 -0700491 postTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700492
493 std::lock_guard<std::mutex> lock(mMutex);
Alec Mouri9a29e672020-09-14 12:39:14 -0700494 if (!canAddNewAggregatedStats(uid, layerName)) {
Yiwei Zhange926ab52019-08-14 15:16:00 -0700495 return;
496 }
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800497 if (!mTimeStatsTracker.count(layerId) && mTimeStatsTracker.size() < MAX_NUM_LAYER_RECORDS &&
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700498 layerNameIsValid(layerName)) {
Alec Mouri9a29e672020-09-14 12:39:14 -0700499 mTimeStatsTracker[layerId].uid = uid;
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800500 mTimeStatsTracker[layerId].layerName = layerName;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700501 }
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800502 if (!mTimeStatsTracker.count(layerId)) return;
503 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700504 if (layerRecord.timeRecords.size() == MAX_NUM_TIME_RECORDS) {
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800505 ALOGE("[%d]-[%s]-timeRecords is at its maximum size[%zu]. Ignore this when unittesting.",
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800506 layerId, layerRecord.layerName.c_str(), MAX_NUM_TIME_RECORDS);
507 mTimeStatsTracker.erase(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700508 return;
509 }
510 // For most media content, the acquireFence is invalid because the buffer is
511 // ready at the queueBuffer stage. In this case, acquireTime should be given
512 // a default value as postTime.
513 TimeRecord timeRecord = {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700514 .frameTime =
515 {
516 .frameNumber = frameNumber,
517 .postTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800518 .latchTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700519 .acquireTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800520 .desiredTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700521 },
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700522 };
523 layerRecord.timeRecords.push_back(timeRecord);
524 if (layerRecord.waitData < 0 ||
525 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
526 layerRecord.waitData = layerRecord.timeRecords.size() - 1;
527}
528
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800529void TimeStats::setLatchTime(int32_t layerId, uint64_t frameNumber, nsecs_t latchTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700530 if (!mEnabled.load()) return;
531
532 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800533 ALOGV("[%d]-[%" PRIu64 "]-LatchTime[%" PRId64 "]", layerId, frameNumber, latchTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700534
535 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800536 if (!mTimeStatsTracker.count(layerId)) return;
537 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700538 if (layerRecord.waitData < 0 ||
539 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
540 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700541 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700542 if (timeRecord.frameTime.frameNumber == frameNumber) {
543 timeRecord.frameTime.latchTime = latchTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700544 }
545}
546
Alec Mouri91f6df32020-01-30 08:48:58 -0800547void TimeStats::incrementLatchSkipped(int32_t layerId, LatchSkipReason reason) {
548 if (!mEnabled.load()) return;
549
550 ATRACE_CALL();
551 ALOGV("[%d]-LatchSkipped-Reason[%d]", layerId,
552 static_cast<std::underlying_type<LatchSkipReason>::type>(reason));
553
554 std::lock_guard<std::mutex> lock(mMutex);
555 if (!mTimeStatsTracker.count(layerId)) return;
556 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
557
558 switch (reason) {
559 case LatchSkipReason::LateAcquire:
560 layerRecord.lateAcquireFrames++;
561 break;
562 }
563}
564
565void TimeStats::incrementBadDesiredPresent(int32_t layerId) {
566 if (!mEnabled.load()) return;
567
568 ATRACE_CALL();
569 ALOGV("[%d]-BadDesiredPresent", layerId);
570
571 std::lock_guard<std::mutex> lock(mMutex);
572 if (!mTimeStatsTracker.count(layerId)) return;
573 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
574 layerRecord.badDesiredPresentFrames++;
575}
576
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800577void TimeStats::setDesiredTime(int32_t layerId, uint64_t frameNumber, nsecs_t desiredTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700578 if (!mEnabled.load()) return;
579
580 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800581 ALOGV("[%d]-[%" PRIu64 "]-DesiredTime[%" PRId64 "]", layerId, frameNumber, desiredTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700582
583 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800584 if (!mTimeStatsTracker.count(layerId)) return;
585 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700586 if (layerRecord.waitData < 0 ||
587 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
588 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700589 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700590 if (timeRecord.frameTime.frameNumber == frameNumber) {
591 timeRecord.frameTime.desiredTime = desiredTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700592 }
593}
594
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800595void TimeStats::setAcquireTime(int32_t layerId, uint64_t frameNumber, nsecs_t acquireTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700596 if (!mEnabled.load()) return;
597
598 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800599 ALOGV("[%d]-[%" PRIu64 "]-AcquireTime[%" PRId64 "]", layerId, frameNumber, acquireTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700600
601 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800602 if (!mTimeStatsTracker.count(layerId)) return;
603 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700604 if (layerRecord.waitData < 0 ||
605 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
606 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700607 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700608 if (timeRecord.frameTime.frameNumber == frameNumber) {
609 timeRecord.frameTime.acquireTime = acquireTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700610 }
611}
612
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800613void TimeStats::setAcquireFence(int32_t layerId, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700614 const std::shared_ptr<FenceTime>& acquireFence) {
615 if (!mEnabled.load()) return;
616
617 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800618 ALOGV("[%d]-[%" PRIu64 "]-AcquireFenceTime[%" PRId64 "]", layerId, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700619 acquireFence->getSignalTime());
620
621 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800622 if (!mTimeStatsTracker.count(layerId)) return;
623 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700624 if (layerRecord.waitData < 0 ||
625 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
626 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700627 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700628 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700629 timeRecord.acquireFence = acquireFence;
630 }
631}
632
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800633void TimeStats::setPresentTime(int32_t layerId, uint64_t frameNumber, nsecs_t presentTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700634 if (!mEnabled.load()) return;
635
636 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800637 ALOGV("[%d]-[%" PRIu64 "]-PresentTime[%" PRId64 "]", layerId, frameNumber, presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700638
639 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800640 if (!mTimeStatsTracker.count(layerId)) return;
641 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700642 if (layerRecord.waitData < 0 ||
643 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
644 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700645 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700646 if (timeRecord.frameTime.frameNumber == frameNumber) {
647 timeRecord.frameTime.presentTime = presentTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700648 timeRecord.ready = true;
649 layerRecord.waitData++;
650 }
651
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800652 flushAvailableRecordsToStatsLocked(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700653}
654
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800655void TimeStats::setPresentFence(int32_t layerId, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700656 const std::shared_ptr<FenceTime>& presentFence) {
657 if (!mEnabled.load()) return;
658
659 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800660 ALOGV("[%d]-[%" PRIu64 "]-PresentFenceTime[%" PRId64 "]", layerId, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700661 presentFence->getSignalTime());
662
663 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800664 if (!mTimeStatsTracker.count(layerId)) return;
665 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700666 if (layerRecord.waitData < 0 ||
667 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
668 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700669 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700670 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700671 timeRecord.presentFence = presentFence;
672 timeRecord.ready = true;
673 layerRecord.waitData++;
674 }
675
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800676 flushAvailableRecordsToStatsLocked(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700677}
678
Alec Mouri9a29e672020-09-14 12:39:14 -0700679template <class T>
680static void updateJankPayload(T& t, int32_t reasons) {
681 t.jankPayload.totalFrames++;
682
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800683 static const constexpr int32_t kValidJankyReason = JankType::SurfaceFlingerCpuDeadlineMissed |
684 JankType::SurfaceFlingerGpuDeadlineMissed | JankType::AppDeadlineMissed |
685 JankType::DisplayHAL;
Alec Mouri9a29e672020-09-14 12:39:14 -0700686 if (reasons & kValidJankyReason) {
687 t.jankPayload.totalJankyFrames++;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800688 if ((reasons & JankType::SurfaceFlingerCpuDeadlineMissed) != 0) {
Alec Mouri9a29e672020-09-14 12:39:14 -0700689 t.jankPayload.totalSFLongCpu++;
690 }
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100691 if ((reasons & JankType::SurfaceFlingerGpuDeadlineMissed) != 0) {
Alec Mouri9a29e672020-09-14 12:39:14 -0700692 t.jankPayload.totalSFLongGpu++;
693 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800694 if ((reasons & JankType::DisplayHAL) != 0) {
Alec Mouri9a29e672020-09-14 12:39:14 -0700695 t.jankPayload.totalSFUnattributed++;
696 }
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100697 if ((reasons & JankType::AppDeadlineMissed) != 0) {
Alec Mouri9a29e672020-09-14 12:39:14 -0700698 t.jankPayload.totalAppUnattributed++;
699 }
700 }
701}
702
703void TimeStats::incrementJankyFrames(int32_t reasons) {
704 if (!mEnabled.load()) return;
705
706 ATRACE_CALL();
707 std::lock_guard<std::mutex> lock(mMutex);
708
709 updateJankPayload<TimeStatsHelper::TimeStatsGlobal>(mTimeStats, reasons);
710}
711
712void TimeStats::incrementJankyFrames(uid_t uid, const std::string& layerName, int32_t reasons) {
713 if (!mEnabled.load()) return;
714
715 ATRACE_CALL();
716 std::lock_guard<std::mutex> lock(mMutex);
717
Alec Mouri542de112020-11-13 12:07:32 -0800718 // Only update layer stats if we're already tracking the layer in TimeStats.
719 // Otherwise, continue tracking the statistic but use a default layer name instead.
Alec Mouri9a29e672020-09-14 12:39:14 -0700720 // As an implementation detail, we do this because this method is expected to be
Alec Mouri542de112020-11-13 12:07:32 -0800721 // called from FrameTimeline, whose jank classification includes transaction jank
722 // that occurs without a buffer. But, in general those layer names are not suitable as
723 // aggregation keys: e.g., it's normal and expected for Window Manager to include the hash code
724 // for an animation leash. So while we can show that jank in dumpsys, aggregating based on the
725 // layer blows up the stats size, so as a workaround drop those stats. This assumes that
726 // TimeStats will flush the first present fence for a layer *before* FrameTimeline does so that
727 // the first jank record is not dropped.
Alec Mouri9a29e672020-09-14 12:39:14 -0700728
Alec Mouri542de112020-11-13 12:07:32 -0800729 bool useDefaultLayerKey = false;
730 static const std::string kDefaultLayerName = "none";
Alec Mouri9a29e672020-09-14 12:39:14 -0700731 if (!mTimeStats.stats.count({uid, layerName})) {
Alec Mouri542de112020-11-13 12:07:32 -0800732 mTimeStats.stats[{uid, kDefaultLayerName}].uid = uid;
733 mTimeStats.stats[{uid, kDefaultLayerName}].layerName = kDefaultLayerName;
734 useDefaultLayerKey = true;
Alec Mouri9a29e672020-09-14 12:39:14 -0700735 }
736
Alec Mouri542de112020-11-13 12:07:32 -0800737 TimeStatsHelper::TimeStatsLayer& timeStatsLayer =
738 mTimeStats.stats[{uid, useDefaultLayerKey ? kDefaultLayerName : layerName}];
Alec Mouri9a29e672020-09-14 12:39:14 -0700739 updateJankPayload<TimeStatsHelper::TimeStatsLayer>(timeStatsLayer, reasons);
740}
741
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800742void TimeStats::onDestroy(int32_t layerId) {
Yiwei Zhangdc224042018-10-18 15:34:00 -0700743 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800744 ALOGV("[%d]-onDestroy", layerId);
Mikael Pessa90092f42019-08-26 17:22:04 -0700745 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800746 mTimeStatsTracker.erase(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700747}
748
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800749void TimeStats::removeTimeRecord(int32_t layerId, uint64_t frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700750 if (!mEnabled.load()) return;
751
752 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800753 ALOGV("[%d]-[%" PRIu64 "]-removeTimeRecord", layerId, frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700754
755 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800756 if (!mTimeStatsTracker.count(layerId)) return;
757 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700758 size_t removeAt = 0;
759 for (const TimeRecord& record : layerRecord.timeRecords) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700760 if (record.frameTime.frameNumber == frameNumber) break;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700761 removeAt++;
762 }
763 if (removeAt == layerRecord.timeRecords.size()) return;
764 layerRecord.timeRecords.erase(layerRecord.timeRecords.begin() + removeAt);
765 if (layerRecord.waitData > static_cast<int32_t>(removeAt)) {
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700766 layerRecord.waitData--;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700767 }
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700768 layerRecord.droppedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700769}
770
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700771void TimeStats::flushPowerTimeLocked() {
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700772 if (!mEnabled.load()) return;
773
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700774 nsecs_t curTime = systemTime();
775 // elapsedTime is in milliseconds.
776 int64_t elapsedTime = (curTime - mPowerTime.prevTime) / 1000000;
777
778 switch (mPowerTime.powerMode) {
Peiyong Lin65248e02020-04-18 21:15:07 -0700779 case PowerMode::ON:
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700780 mTimeStats.displayOnTime += elapsedTime;
781 break;
Peiyong Lin65248e02020-04-18 21:15:07 -0700782 case PowerMode::OFF:
783 case PowerMode::DOZE:
784 case PowerMode::DOZE_SUSPEND:
785 case PowerMode::ON_SUSPEND:
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700786 default:
787 break;
788 }
789
790 mPowerTime.prevTime = curTime;
791}
792
Peiyong Lin65248e02020-04-18 21:15:07 -0700793void TimeStats::setPowerMode(PowerMode powerMode) {
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700794 if (!mEnabled.load()) {
795 std::lock_guard<std::mutex> lock(mMutex);
796 mPowerTime.powerMode = powerMode;
797 return;
798 }
799
800 std::lock_guard<std::mutex> lock(mMutex);
801 if (powerMode == mPowerTime.powerMode) return;
802
803 flushPowerTimeLocked();
804 mPowerTime.powerMode = powerMode;
805}
806
Alec Mourifb571ea2019-01-24 18:42:10 -0800807void TimeStats::recordRefreshRate(uint32_t fps, nsecs_t duration) {
808 std::lock_guard<std::mutex> lock(mMutex);
809 if (mTimeStats.refreshRateStats.count(fps)) {
810 mTimeStats.refreshRateStats[fps] += duration;
811 } else {
812 mTimeStats.refreshRateStats.insert({fps, duration});
813 }
814}
815
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700816void TimeStats::flushAvailableGlobalRecordsToStatsLocked() {
817 ATRACE_CALL();
818
819 while (!mGlobalRecord.presentFences.empty()) {
820 const nsecs_t curPresentTime = mGlobalRecord.presentFences.front()->getSignalTime();
821 if (curPresentTime == Fence::SIGNAL_TIME_PENDING) break;
822
823 if (curPresentTime == Fence::SIGNAL_TIME_INVALID) {
824 ALOGE("GlobalPresentFence is invalid!");
825 mGlobalRecord.prevPresentTime = 0;
826 mGlobalRecord.presentFences.pop_front();
827 continue;
828 }
829
830 ALOGV("GlobalPresentFenceTime[%" PRId64 "]",
831 mGlobalRecord.presentFences.front()->getSignalTime());
832
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700833 if (mGlobalRecord.prevPresentTime != 0) {
834 const int32_t presentToPresentMs =
835 msBetween(mGlobalRecord.prevPresentTime, curPresentTime);
836 ALOGV("Global present2present[%d] prev[%" PRId64 "] curr[%" PRId64 "]",
837 presentToPresentMs, mGlobalRecord.prevPresentTime, curPresentTime);
838 mTimeStats.presentToPresent.insert(presentToPresentMs);
839 }
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700840
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700841 mGlobalRecord.prevPresentTime = curPresentTime;
842 mGlobalRecord.presentFences.pop_front();
843 }
Alec Mourie4034bb2019-11-19 12:45:54 -0800844 while (!mGlobalRecord.renderEngineDurations.empty()) {
845 const auto duration = mGlobalRecord.renderEngineDurations.front();
846 const auto& endTime = duration.endTime;
847
848 nsecs_t endNs = -1;
849
850 if (auto val = std::get_if<nsecs_t>(&endTime)) {
851 endNs = *val;
852 } else {
853 endNs = std::get<std::shared_ptr<FenceTime>>(endTime)->getSignalTime();
854 }
855
856 if (endNs == Fence::SIGNAL_TIME_PENDING) break;
857
858 if (endNs < 0) {
859 ALOGE("RenderEngineTiming is invalid!");
860 mGlobalRecord.renderEngineDurations.pop_front();
861 continue;
862 }
863
864 const int32_t renderEngineMs = msBetween(duration.startTime, endNs);
865 mTimeStats.renderEngineTiming.insert(renderEngineMs);
866
867 mGlobalRecord.renderEngineDurations.pop_front();
868 }
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700869}
870
871void TimeStats::setPresentFenceGlobal(const std::shared_ptr<FenceTime>& presentFence) {
872 if (!mEnabled.load()) return;
873
874 ATRACE_CALL();
875 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700876 if (presentFence == nullptr || !presentFence->isValid()) {
877 mGlobalRecord.prevPresentTime = 0;
878 return;
879 }
880
Peiyong Lin65248e02020-04-18 21:15:07 -0700881 if (mPowerTime.powerMode != PowerMode::ON) {
882 // Try flushing the last present fence on PowerMode::ON.
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700883 flushAvailableGlobalRecordsToStatsLocked();
884 mGlobalRecord.presentFences.clear();
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700885 mGlobalRecord.prevPresentTime = 0;
886 return;
887 }
888
889 if (mGlobalRecord.presentFences.size() == MAX_NUM_TIME_RECORDS) {
890 // The front presentFence must be trapped in pending status in this
891 // case. Try dequeuing the front one to recover.
892 ALOGE("GlobalPresentFences is already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
893 mGlobalRecord.prevPresentTime = 0;
894 mGlobalRecord.presentFences.pop_front();
895 }
896
897 mGlobalRecord.presentFences.emplace_back(presentFence);
898 flushAvailableGlobalRecordsToStatsLocked();
899}
900
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700901void TimeStats::enable() {
902 if (mEnabled.load()) return;
903
904 ATRACE_CALL();
905
906 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700907 mEnabled.store(true);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700908 mTimeStats.statsStart = static_cast<int64_t>(std::time(0));
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700909 mPowerTime.prevTime = systemTime();
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700910 ALOGD("Enabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700911}
912
913void TimeStats::disable() {
914 if (!mEnabled.load()) return;
915
916 ATRACE_CALL();
917
918 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700919 flushPowerTimeLocked();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700920 mEnabled.store(false);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700921 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700922 ALOGD("Disabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700923}
924
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000925void TimeStats::clearAll() {
926 std::lock_guard<std::mutex> lock(mMutex);
927 clearGlobalLocked();
928 clearLayersLocked();
929}
930
931void TimeStats::clearGlobalLocked() {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700932 ATRACE_CALL();
933
Yiwei Zhangdc224042018-10-18 15:34:00 -0700934 mTimeStats.statsStart = (mEnabled.load() ? static_cast<int64_t>(std::time(0)) : 0);
935 mTimeStats.statsEnd = 0;
936 mTimeStats.totalFrames = 0;
937 mTimeStats.missedFrames = 0;
938 mTimeStats.clientCompositionFrames = 0;
Vishnu Nair9b079a22020-01-21 14:36:08 -0800939 mTimeStats.clientCompositionReusedFrames = 0;
Alec Mouri8de697e2020-03-19 10:52:01 -0700940 mTimeStats.refreshRateSwitches = 0;
Alec Mouri8f7a0102020-04-15 12:11:10 -0700941 mTimeStats.compositionStrategyChanges = 0;
Alec Mouri717bcb62020-02-10 17:07:19 -0800942 mTimeStats.displayEventConnectionsCount = 0;
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700943 mTimeStats.displayOnTime = 0;
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700944 mTimeStats.presentToPresent.hist.clear();
Alec Mouri31ac64a2020-01-09 09:26:22 -0800945 mTimeStats.frameDuration.hist.clear();
946 mTimeStats.renderEngineTiming.hist.clear();
Alec Mouri9a29e672020-09-14 12:39:14 -0700947 mTimeStats.jankPayload = TimeStatsHelper::JankPayload();
Alec Mourifb571ea2019-01-24 18:42:10 -0800948 mTimeStats.refreshRateStats.clear();
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700949 mPowerTime.prevTime = systemTime();
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700950 mGlobalRecord.prevPresentTime = 0;
951 mGlobalRecord.presentFences.clear();
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000952 ALOGD("Cleared global stats");
953}
954
955void TimeStats::clearLayersLocked() {
956 ATRACE_CALL();
957
958 mTimeStatsTracker.clear();
959 mTimeStats.stats.clear();
960 ALOGD("Cleared layer stats");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700961}
962
963bool TimeStats::isEnabled() {
964 return mEnabled.load();
965}
966
Yiwei Zhang5434a782018-12-05 18:06:32 -0800967void TimeStats::dump(bool asProto, std::optional<uint32_t> maxLayers, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700968 ATRACE_CALL();
969
970 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700971 if (mTimeStats.statsStart == 0) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700972 return;
973 }
974
Yiwei Zhangdc224042018-10-18 15:34:00 -0700975 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700976
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700977 flushPowerTimeLocked();
978
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700979 if (asProto) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700980 ALOGD("Dumping TimeStats as proto");
Yiwei Zhangdc224042018-10-18 15:34:00 -0700981 SFTimeStatsGlobalProto timeStatsProto = mTimeStats.toProto(maxLayers);
Dominik Laskowski46470112019-08-02 13:13:11 -0700982 result.append(timeStatsProto.SerializeAsString());
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700983 } else {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700984 ALOGD("Dumping TimeStats as text");
Yiwei Zhang5434a782018-12-05 18:06:32 -0800985 result.append(mTimeStats.toString(maxLayers));
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700986 result.append("\n");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700987 }
988}
989
Alec Mourifb571ea2019-01-24 18:42:10 -0800990} // namespace impl
991
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700992} // namespace android