blob: 3e3ab18e8f8023615ff8ae0e5b9701d310e330ce [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 */
16#undef LOG_TAG
17#define LOG_TAG "TimeStats"
18#define ATRACE_TAG ATRACE_TAG_GRAPHICS
19
20#include "TimeStats.h"
21
22#include <android-base/stringprintf.h>
23
24#include <log/log.h>
25
26#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>
31#include <regex>
32
33namespace android {
34
Alec Mourifb571ea2019-01-24 18:42:10 -080035namespace impl {
36
Dominik Laskowskic2867142019-01-21 11:33:38 -080037void TimeStats::parseArgs(bool asProto, const Vector<String16>& args, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -070038 ATRACE_CALL();
39
Yiwei Zhang0102ad22018-05-02 17:37:17 -070040 std::unordered_map<std::string, int32_t> argsMap;
Dominik Laskowskic2867142019-01-21 11:33:38 -080041 for (size_t index = 0; index < args.size(); ++index) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -070042 argsMap[std::string(String8(args[index]).c_str())] = index;
Yiwei Zhang0102ad22018-05-02 17:37:17 -070043 }
44
45 if (argsMap.count("-disable")) {
46 disable();
47 }
48
49 if (argsMap.count("-dump")) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -070050 std::optional<uint32_t> maxLayers = std::nullopt;
Yiwei Zhang0102ad22018-05-02 17:37:17 -070051 auto iter = argsMap.find("-maxlayers");
52 if (iter != argsMap.end() && iter->second + 1 < static_cast<int32_t>(args.size())) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -070053 int64_t value = strtol(String8(args[iter->second + 1]).c_str(), nullptr, 10);
54 value = std::clamp(value, int64_t(0), int64_t(UINT32_MAX));
55 maxLayers = static_cast<uint32_t>(value);
Yiwei Zhang0102ad22018-05-02 17:37:17 -070056 }
57
Yiwei Zhang8a4015c2018-05-08 16:03:47 -070058 dump(asProto, maxLayers, result);
Yiwei Zhang0102ad22018-05-02 17:37:17 -070059 }
60
61 if (argsMap.count("-clear")) {
62 clear();
63 }
64
65 if (argsMap.count("-enable")) {
66 enable();
67 }
68}
69
Yiwei Zhang7eb58b72019-04-22 19:00:02 -070070std::string TimeStats::miniDump() {
71 ATRACE_CALL();
72
73 std::string result = "TimeStats miniDump:\n";
74 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange926ab52019-08-14 15:16:00 -070075 android::base::StringAppendF(&result, "Number of layers currently being tracked is %zu\n",
Yiwei Zhang7eb58b72019-04-22 19:00:02 -070076 mTimeStatsTracker.size());
Yiwei Zhange926ab52019-08-14 15:16:00 -070077 android::base::StringAppendF(&result, "Number of layers in the stats pool is %zu\n",
78 mTimeStats.stats.size());
Yiwei Zhang7eb58b72019-04-22 19:00:02 -070079 return result;
80}
81
Yiwei Zhang0102ad22018-05-02 17:37:17 -070082void TimeStats::incrementTotalFrames() {
83 if (!mEnabled.load()) return;
84
85 ATRACE_CALL();
86
87 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -070088 mTimeStats.totalFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -070089}
90
Yiwei Zhang621f9d42018-05-07 10:40:55 -070091void TimeStats::incrementMissedFrames() {
Yiwei Zhang0102ad22018-05-02 17:37:17 -070092 if (!mEnabled.load()) return;
93
94 ATRACE_CALL();
95
96 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -070097 mTimeStats.missedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -070098}
99
100void TimeStats::incrementClientCompositionFrames() {
101 if (!mEnabled.load()) return;
102
103 ATRACE_CALL();
104
105 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700106 mTimeStats.clientCompositionFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700107}
108
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700109bool TimeStats::recordReadyLocked(int32_t layerID, TimeRecord* timeRecord) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700110 if (!timeRecord->ready) {
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700111 ALOGV("[%d]-[%" PRIu64 "]-presentFence is still not received", layerID,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700112 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700113 return false;
114 }
115
116 if (timeRecord->acquireFence != nullptr) {
117 if (timeRecord->acquireFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
118 return false;
119 }
120 if (timeRecord->acquireFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700121 timeRecord->frameTime.acquireTime = timeRecord->acquireFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700122 timeRecord->acquireFence = nullptr;
123 } else {
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700124 ALOGV("[%d]-[%" PRIu64 "]-acquireFence signal time is invalid", layerID,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700125 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700126 }
127 }
128
129 if (timeRecord->presentFence != nullptr) {
130 if (timeRecord->presentFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
131 return false;
132 }
133 if (timeRecord->presentFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700134 timeRecord->frameTime.presentTime = timeRecord->presentFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700135 timeRecord->presentFence = nullptr;
136 } else {
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700137 ALOGV("[%d]-[%" PRIu64 "]-presentFence signal time invalid", layerID,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700138 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700139 }
140 }
141
142 return true;
143}
144
145static int32_t msBetween(nsecs_t start, nsecs_t end) {
146 int64_t delta = (end - start) / 1000000;
147 delta = std::clamp(delta, int64_t(INT32_MIN), int64_t(INT32_MAX));
148 return static_cast<int32_t>(delta);
149}
150
Yiwei Zhangbd408322018-10-15 18:31:53 -0700151// This regular expression captures the following for instance:
152// StatusBar in StatusBar#0
153// com.appname in com.appname/com.appname.activity#0
154// com.appname in SurfaceView - com.appname/com.appname.activity#0
155static const std::regex packageNameRegex("(?:SurfaceView[-\\s\\t]+)?([^/]+).*#\\d+");
156
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700157static std::string getPackageName(const std::string& layerName) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700158 std::smatch match;
Yiwei Zhangbd408322018-10-15 18:31:53 -0700159 if (std::regex_match(layerName.begin(), layerName.end(), match, packageNameRegex)) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700160 // There must be a match for group 1 otherwise the whole string is not
161 // matched and the above will return false
162 return match[1];
163 }
164 return "";
165}
166
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700167void TimeStats::flushAvailableRecordsToStatsLocked(int32_t layerID) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700168 ATRACE_CALL();
169
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700170 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700171 TimeRecord& prevTimeRecord = layerRecord.prevTimeRecord;
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700172 std::deque<TimeRecord>& timeRecords = layerRecord.timeRecords;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700173 while (!timeRecords.empty()) {
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700174 if (!recordReadyLocked(layerID, &timeRecords[0])) break;
175 ALOGV("[%d]-[%" PRIu64 "]-presentFenceTime[%" PRId64 "]", layerID,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700176 timeRecords[0].frameTime.frameNumber, timeRecords[0].frameTime.presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700177
178 if (prevTimeRecord.ready) {
Yiwei Zhangeafa5cc2019-07-26 15:06:25 -0700179 const std::string& layerName = layerRecord.layerName;
Yiwei Zhangdc224042018-10-18 15:34:00 -0700180 if (!mTimeStats.stats.count(layerName)) {
181 mTimeStats.stats[layerName].layerName = layerName;
182 mTimeStats.stats[layerName].packageName = getPackageName(layerName);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700183 }
Yiwei Zhangdc224042018-10-18 15:34:00 -0700184 TimeStatsHelper::TimeStatsLayer& timeStatsLayer = mTimeStats.stats[layerName];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700185 timeStatsLayer.totalFrames++;
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700186 timeStatsLayer.droppedFrames += layerRecord.droppedFrames;
187 layerRecord.droppedFrames = 0;
188
189 const int32_t postToAcquireMs = msBetween(timeRecords[0].frameTime.postTime,
190 timeRecords[0].frameTime.acquireTime);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700191 ALOGV("[%d]-[%" PRIu64 "]-post2acquire[%d]", layerID,
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700192 timeRecords[0].frameTime.frameNumber, postToAcquireMs);
193 timeStatsLayer.deltas["post2acquire"].insert(postToAcquireMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700194
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700195 const int32_t postToPresentMs = msBetween(timeRecords[0].frameTime.postTime,
196 timeRecords[0].frameTime.presentTime);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700197 ALOGV("[%d]-[%" PRIu64 "]-post2present[%d]", layerID,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700198 timeRecords[0].frameTime.frameNumber, postToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700199 timeStatsLayer.deltas["post2present"].insert(postToPresentMs);
200
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700201 const int32_t acquireToPresentMs = msBetween(timeRecords[0].frameTime.acquireTime,
202 timeRecords[0].frameTime.presentTime);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700203 ALOGV("[%d]-[%" PRIu64 "]-acquire2present[%d]", layerID,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700204 timeRecords[0].frameTime.frameNumber, acquireToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700205 timeStatsLayer.deltas["acquire2present"].insert(acquireToPresentMs);
206
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700207 const int32_t latchToPresentMs = msBetween(timeRecords[0].frameTime.latchTime,
208 timeRecords[0].frameTime.presentTime);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700209 ALOGV("[%d]-[%" PRIu64 "]-latch2present[%d]", layerID,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700210 timeRecords[0].frameTime.frameNumber, latchToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700211 timeStatsLayer.deltas["latch2present"].insert(latchToPresentMs);
212
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700213 const int32_t desiredToPresentMs = msBetween(timeRecords[0].frameTime.desiredTime,
214 timeRecords[0].frameTime.presentTime);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700215 ALOGV("[%d]-[%" PRIu64 "]-desired2present[%d]", layerID,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700216 timeRecords[0].frameTime.frameNumber, desiredToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700217 timeStatsLayer.deltas["desired2present"].insert(desiredToPresentMs);
218
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700219 const int32_t presentToPresentMs = msBetween(prevTimeRecord.frameTime.presentTime,
220 timeRecords[0].frameTime.presentTime);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700221 ALOGV("[%d]-[%" PRIu64 "]-present2present[%d]", layerID,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700222 timeRecords[0].frameTime.frameNumber, presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700223 timeStatsLayer.deltas["present2present"].insert(presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700224 }
225 prevTimeRecord = timeRecords[0];
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700226 timeRecords.pop_front();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700227 layerRecord.waitData--;
228 }
229}
230
Yiwei Zhangbd408322018-10-15 18:31:53 -0700231// This regular expression captures the following layer names for instance:
232// 1) StatusBat#0
233// 2) NavigationBar#1
234// 3) co(m).*#0
235// 4) SurfaceView - co(m).*#0
236// Using [-\\s\t]+ for the conjunction part between SurfaceView and co(m).*
237// is a bit more robust in case there's a slight change.
238// The layer name would only consist of . / $ _ 0-9 a-z A-Z in most cases.
239static const std::regex layerNameRegex(
240 "(((SurfaceView[-\\s\\t]+)?com?\\.[./$\\w]+)|((Status|Navigation)Bar))#\\d+");
241
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700242static bool layerNameIsValid(const std::string& layerName) {
Yiwei Zhangbd408322018-10-15 18:31:53 -0700243 return std::regex_match(layerName.begin(), layerName.end(), layerNameRegex);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700244}
245
Yiwei Zhang8e8fe522018-11-02 18:34:07 -0700246void TimeStats::setPostTime(int32_t layerID, uint64_t frameNumber, const std::string& layerName,
247 nsecs_t postTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700248 if (!mEnabled.load()) return;
249
250 ATRACE_CALL();
Yiwei Zhang8e8fe522018-11-02 18:34:07 -0700251 ALOGV("[%d]-[%" PRIu64 "]-[%s]-PostTime[%" PRId64 "]", layerID, frameNumber, layerName.c_str(),
252 postTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700253
254 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange926ab52019-08-14 15:16:00 -0700255 if (!mTimeStats.stats.count(layerName) && mTimeStats.stats.size() >= MAX_NUM_LAYER_STATS) {
256 return;
257 }
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700258 if (!mTimeStatsTracker.count(layerID) && mTimeStatsTracker.size() < MAX_NUM_LAYER_RECORDS &&
259 layerNameIsValid(layerName)) {
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700260 mTimeStatsTracker[layerID].layerName = layerName;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700261 }
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700262 if (!mTimeStatsTracker.count(layerID)) return;
263 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700264 if (layerRecord.timeRecords.size() == MAX_NUM_TIME_RECORDS) {
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800265 ALOGE("[%d]-[%s]-timeRecords is at its maximum size[%zu]. Ignore this when unittesting.",
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700266 layerID, layerRecord.layerName.c_str(), MAX_NUM_TIME_RECORDS);
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800267 mTimeStatsTracker.erase(layerID);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700268 return;
269 }
270 // For most media content, the acquireFence is invalid because the buffer is
271 // ready at the queueBuffer stage. In this case, acquireTime should be given
272 // a default value as postTime.
273 TimeRecord timeRecord = {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700274 .frameTime =
275 {
276 .frameNumber = frameNumber,
277 .postTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800278 .latchTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700279 .acquireTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800280 .desiredTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700281 },
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700282 };
283 layerRecord.timeRecords.push_back(timeRecord);
284 if (layerRecord.waitData < 0 ||
285 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
286 layerRecord.waitData = layerRecord.timeRecords.size() - 1;
287}
288
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700289void TimeStats::setLatchTime(int32_t layerID, uint64_t frameNumber, nsecs_t latchTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700290 if (!mEnabled.load()) return;
291
292 ATRACE_CALL();
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700293 ALOGV("[%d]-[%" PRIu64 "]-LatchTime[%" PRId64 "]", layerID, frameNumber, latchTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700294
295 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700296 if (!mTimeStatsTracker.count(layerID)) return;
297 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700298 if (layerRecord.waitData < 0 ||
299 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
300 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700301 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700302 if (timeRecord.frameTime.frameNumber == frameNumber) {
303 timeRecord.frameTime.latchTime = latchTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700304 }
305}
306
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700307void TimeStats::setDesiredTime(int32_t layerID, uint64_t frameNumber, nsecs_t desiredTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700308 if (!mEnabled.load()) return;
309
310 ATRACE_CALL();
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700311 ALOGV("[%d]-[%" PRIu64 "]-DesiredTime[%" PRId64 "]", layerID, frameNumber, desiredTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700312
313 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700314 if (!mTimeStatsTracker.count(layerID)) return;
315 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700316 if (layerRecord.waitData < 0 ||
317 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
318 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700319 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700320 if (timeRecord.frameTime.frameNumber == frameNumber) {
321 timeRecord.frameTime.desiredTime = desiredTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700322 }
323}
324
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700325void TimeStats::setAcquireTime(int32_t layerID, uint64_t frameNumber, nsecs_t acquireTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700326 if (!mEnabled.load()) return;
327
328 ATRACE_CALL();
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700329 ALOGV("[%d]-[%" PRIu64 "]-AcquireTime[%" PRId64 "]", layerID, frameNumber, acquireTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700330
331 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700332 if (!mTimeStatsTracker.count(layerID)) return;
333 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700334 if (layerRecord.waitData < 0 ||
335 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
336 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700337 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700338 if (timeRecord.frameTime.frameNumber == frameNumber) {
339 timeRecord.frameTime.acquireTime = acquireTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700340 }
341}
342
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700343void TimeStats::setAcquireFence(int32_t layerID, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700344 const std::shared_ptr<FenceTime>& acquireFence) {
345 if (!mEnabled.load()) return;
346
347 ATRACE_CALL();
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700348 ALOGV("[%d]-[%" PRIu64 "]-AcquireFenceTime[%" PRId64 "]", layerID, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700349 acquireFence->getSignalTime());
350
351 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700352 if (!mTimeStatsTracker.count(layerID)) return;
353 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700354 if (layerRecord.waitData < 0 ||
355 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
356 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700357 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700358 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700359 timeRecord.acquireFence = acquireFence;
360 }
361}
362
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700363void TimeStats::setPresentTime(int32_t layerID, uint64_t frameNumber, nsecs_t presentTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700364 if (!mEnabled.load()) return;
365
366 ATRACE_CALL();
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700367 ALOGV("[%d]-[%" PRIu64 "]-PresentTime[%" PRId64 "]", layerID, frameNumber, presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700368
369 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700370 if (!mTimeStatsTracker.count(layerID)) return;
371 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700372 if (layerRecord.waitData < 0 ||
373 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
374 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700375 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700376 if (timeRecord.frameTime.frameNumber == frameNumber) {
377 timeRecord.frameTime.presentTime = presentTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700378 timeRecord.ready = true;
379 layerRecord.waitData++;
380 }
381
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700382 flushAvailableRecordsToStatsLocked(layerID);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700383}
384
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700385void TimeStats::setPresentFence(int32_t layerID, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700386 const std::shared_ptr<FenceTime>& presentFence) {
387 if (!mEnabled.load()) return;
388
389 ATRACE_CALL();
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700390 ALOGV("[%d]-[%" PRIu64 "]-PresentFenceTime[%" PRId64 "]", layerID, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700391 presentFence->getSignalTime());
392
393 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700394 if (!mTimeStatsTracker.count(layerID)) return;
395 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700396 if (layerRecord.waitData < 0 ||
397 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
398 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700399 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700400 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700401 timeRecord.presentFence = presentFence;
402 timeRecord.ready = true;
403 layerRecord.waitData++;
404 }
405
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700406 flushAvailableRecordsToStatsLocked(layerID);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700407}
408
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700409void TimeStats::onDestroy(int32_t layerID) {
Yiwei Zhangdc224042018-10-18 15:34:00 -0700410 if (!mEnabled.load()) return;
411
412 ATRACE_CALL();
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700413 ALOGV("[%d]-onDestroy", layerID);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700414
415 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700416 if (!mTimeStatsTracker.count(layerID)) return;
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700417 mTimeStatsTracker.erase(layerID);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700418}
419
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700420void TimeStats::removeTimeRecord(int32_t layerID, uint64_t frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700421 if (!mEnabled.load()) return;
422
423 ATRACE_CALL();
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700424 ALOGV("[%d]-[%" PRIu64 "]-removeTimeRecord", layerID, frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700425
426 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang9689e2f2018-05-11 12:33:23 -0700427 if (!mTimeStatsTracker.count(layerID)) return;
428 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700429 size_t removeAt = 0;
430 for (const TimeRecord& record : layerRecord.timeRecords) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700431 if (record.frameTime.frameNumber == frameNumber) break;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700432 removeAt++;
433 }
434 if (removeAt == layerRecord.timeRecords.size()) return;
435 layerRecord.timeRecords.erase(layerRecord.timeRecords.begin() + removeAt);
436 if (layerRecord.waitData > static_cast<int32_t>(removeAt)) {
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700437 layerRecord.waitData--;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700438 }
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700439 layerRecord.droppedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700440}
441
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700442void TimeStats::flushPowerTimeLocked() {
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700443 if (!mEnabled.load()) return;
444
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700445 nsecs_t curTime = systemTime();
446 // elapsedTime is in milliseconds.
447 int64_t elapsedTime = (curTime - mPowerTime.prevTime) / 1000000;
448
449 switch (mPowerTime.powerMode) {
450 case HWC_POWER_MODE_NORMAL:
451 mTimeStats.displayOnTime += elapsedTime;
452 break;
453 case HWC_POWER_MODE_OFF:
454 case HWC_POWER_MODE_DOZE:
455 case HWC_POWER_MODE_DOZE_SUSPEND:
456 default:
457 break;
458 }
459
460 mPowerTime.prevTime = curTime;
461}
462
463void TimeStats::setPowerMode(int32_t powerMode) {
464 if (!mEnabled.load()) {
465 std::lock_guard<std::mutex> lock(mMutex);
466 mPowerTime.powerMode = powerMode;
467 return;
468 }
469
470 std::lock_guard<std::mutex> lock(mMutex);
471 if (powerMode == mPowerTime.powerMode) return;
472
473 flushPowerTimeLocked();
474 mPowerTime.powerMode = powerMode;
475}
476
Alec Mourifb571ea2019-01-24 18:42:10 -0800477void TimeStats::recordRefreshRate(uint32_t fps, nsecs_t duration) {
478 std::lock_guard<std::mutex> lock(mMutex);
479 if (mTimeStats.refreshRateStats.count(fps)) {
480 mTimeStats.refreshRateStats[fps] += duration;
481 } else {
482 mTimeStats.refreshRateStats.insert({fps, duration});
483 }
484}
485
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700486void TimeStats::flushAvailableGlobalRecordsToStatsLocked() {
487 ATRACE_CALL();
488
489 while (!mGlobalRecord.presentFences.empty()) {
490 const nsecs_t curPresentTime = mGlobalRecord.presentFences.front()->getSignalTime();
491 if (curPresentTime == Fence::SIGNAL_TIME_PENDING) break;
492
493 if (curPresentTime == Fence::SIGNAL_TIME_INVALID) {
494 ALOGE("GlobalPresentFence is invalid!");
495 mGlobalRecord.prevPresentTime = 0;
496 mGlobalRecord.presentFences.pop_front();
497 continue;
498 }
499
500 ALOGV("GlobalPresentFenceTime[%" PRId64 "]",
501 mGlobalRecord.presentFences.front()->getSignalTime());
502
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700503 if (mGlobalRecord.prevPresentTime != 0) {
504 const int32_t presentToPresentMs =
505 msBetween(mGlobalRecord.prevPresentTime, curPresentTime);
506 ALOGV("Global present2present[%d] prev[%" PRId64 "] curr[%" PRId64 "]",
507 presentToPresentMs, mGlobalRecord.prevPresentTime, curPresentTime);
508 mTimeStats.presentToPresent.insert(presentToPresentMs);
509 }
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700510
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700511 mGlobalRecord.prevPresentTime = curPresentTime;
512 mGlobalRecord.presentFences.pop_front();
513 }
514}
515
516void TimeStats::setPresentFenceGlobal(const std::shared_ptr<FenceTime>& presentFence) {
517 if (!mEnabled.load()) return;
518
519 ATRACE_CALL();
520 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700521 if (presentFence == nullptr || !presentFence->isValid()) {
522 mGlobalRecord.prevPresentTime = 0;
523 return;
524 }
525
526 if (mPowerTime.powerMode != HWC_POWER_MODE_NORMAL) {
527 // Try flushing the last present fence on HWC_POWER_MODE_NORMAL.
528 flushAvailableGlobalRecordsToStatsLocked();
529 mGlobalRecord.presentFences.clear();
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700530 mGlobalRecord.prevPresentTime = 0;
531 return;
532 }
533
534 if (mGlobalRecord.presentFences.size() == MAX_NUM_TIME_RECORDS) {
535 // The front presentFence must be trapped in pending status in this
536 // case. Try dequeuing the front one to recover.
537 ALOGE("GlobalPresentFences is already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
538 mGlobalRecord.prevPresentTime = 0;
539 mGlobalRecord.presentFences.pop_front();
540 }
541
542 mGlobalRecord.presentFences.emplace_back(presentFence);
543 flushAvailableGlobalRecordsToStatsLocked();
544}
545
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700546void TimeStats::enable() {
547 if (mEnabled.load()) return;
548
549 ATRACE_CALL();
550
551 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700552 mEnabled.store(true);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700553 mTimeStats.statsStart = static_cast<int64_t>(std::time(0));
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700554 mPowerTime.prevTime = systemTime();
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700555 ALOGD("Enabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700556}
557
558void TimeStats::disable() {
559 if (!mEnabled.load()) return;
560
561 ATRACE_CALL();
562
563 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700564 flushPowerTimeLocked();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700565 mEnabled.store(false);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700566 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700567 ALOGD("Disabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700568}
569
570void TimeStats::clear() {
571 ATRACE_CALL();
572
573 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700574 mTimeStatsTracker.clear();
Yiwei Zhangdc224042018-10-18 15:34:00 -0700575 mTimeStats.stats.clear();
576 mTimeStats.statsStart = (mEnabled.load() ? static_cast<int64_t>(std::time(0)) : 0);
577 mTimeStats.statsEnd = 0;
578 mTimeStats.totalFrames = 0;
579 mTimeStats.missedFrames = 0;
580 mTimeStats.clientCompositionFrames = 0;
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700581 mTimeStats.displayOnTime = 0;
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700582 mTimeStats.presentToPresent.hist.clear();
Alec Mourifb571ea2019-01-24 18:42:10 -0800583 mTimeStats.refreshRateStats.clear();
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700584 mPowerTime.prevTime = systemTime();
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700585 mGlobalRecord.prevPresentTime = 0;
586 mGlobalRecord.presentFences.clear();
587 ALOGD("Cleared");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700588}
589
590bool TimeStats::isEnabled() {
591 return mEnabled.load();
592}
593
Yiwei Zhang5434a782018-12-05 18:06:32 -0800594void TimeStats::dump(bool asProto, std::optional<uint32_t> maxLayers, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700595 ATRACE_CALL();
596
597 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700598 if (mTimeStats.statsStart == 0) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700599 return;
600 }
601
Yiwei Zhangdc224042018-10-18 15:34:00 -0700602 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700603
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700604 flushPowerTimeLocked();
605
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700606 if (asProto) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700607 ALOGD("Dumping TimeStats as proto");
Yiwei Zhangdc224042018-10-18 15:34:00 -0700608 SFTimeStatsGlobalProto timeStatsProto = mTimeStats.toProto(maxLayers);
Dominik Laskowski46470112019-08-02 13:13:11 -0700609 result.append(timeStatsProto.SerializeAsString());
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700610 } else {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700611 ALOGD("Dumping TimeStats as text");
Yiwei Zhang5434a782018-12-05 18:06:32 -0800612 result.append(mTimeStats.toString(maxLayers));
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700613 result.append("\n");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700614 }
615}
616
Alec Mourifb571ea2019-01-24 18:42:10 -0800617} // namespace impl
618
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700619} // namespace android