1 /*
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>
27 #include <utils/Timers.h>
28 #include <utils/Trace.h>
29
30 #include <algorithm>
31 #include <regex>
32
33 namespace android {
34
35 namespace impl {
36
parseArgs(bool asProto,const Vector<String16> & args,std::string & result)37 void TimeStats::parseArgs(bool asProto, const Vector<String16>& args, std::string& result) {
38 ATRACE_CALL();
39
40 std::unordered_map<std::string, int32_t> argsMap;
41 for (size_t index = 0; index < args.size(); ++index) {
42 argsMap[std::string(String8(args[index]).c_str())] = index;
43 }
44
45 if (argsMap.count("-disable")) {
46 disable();
47 }
48
49 if (argsMap.count("-dump")) {
50 std::optional<uint32_t> maxLayers = std::nullopt;
51 auto iter = argsMap.find("-maxlayers");
52 if (iter != argsMap.end() && iter->second + 1 < static_cast<int32_t>(args.size())) {
53 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);
56 }
57
58 dump(asProto, maxLayers, result);
59 }
60
61 if (argsMap.count("-clear")) {
62 clear();
63 }
64
65 if (argsMap.count("-enable")) {
66 enable();
67 }
68 }
69
miniDump()70 std::string TimeStats::miniDump() {
71 ATRACE_CALL();
72
73 std::string result = "TimeStats miniDump:\n";
74 std::lock_guard<std::mutex> lock(mMutex);
75 android::base::StringAppendF(&result, "Number of tracked layers is %zu\n",
76 mTimeStatsTracker.size());
77 return result;
78 }
79
incrementTotalFrames()80 void TimeStats::incrementTotalFrames() {
81 if (!mEnabled.load()) return;
82
83 ATRACE_CALL();
84
85 std::lock_guard<std::mutex> lock(mMutex);
86 mTimeStats.totalFrames++;
87 }
88
incrementMissedFrames()89 void TimeStats::incrementMissedFrames() {
90 if (!mEnabled.load()) return;
91
92 ATRACE_CALL();
93
94 std::lock_guard<std::mutex> lock(mMutex);
95 mTimeStats.missedFrames++;
96 }
97
incrementClientCompositionFrames()98 void TimeStats::incrementClientCompositionFrames() {
99 if (!mEnabled.load()) return;
100
101 ATRACE_CALL();
102
103 std::lock_guard<std::mutex> lock(mMutex);
104 mTimeStats.clientCompositionFrames++;
105 }
106
recordReadyLocked(int32_t layerID,TimeRecord * timeRecord)107 bool TimeStats::recordReadyLocked(int32_t layerID, TimeRecord* timeRecord) {
108 if (!timeRecord->ready) {
109 ALOGV("[%d]-[%" PRIu64 "]-presentFence is still not received", layerID,
110 timeRecord->frameTime.frameNumber);
111 return false;
112 }
113
114 if (timeRecord->acquireFence != nullptr) {
115 if (timeRecord->acquireFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
116 return false;
117 }
118 if (timeRecord->acquireFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
119 timeRecord->frameTime.acquireTime = timeRecord->acquireFence->getSignalTime();
120 timeRecord->acquireFence = nullptr;
121 } else {
122 ALOGV("[%d]-[%" PRIu64 "]-acquireFence signal time is invalid", layerID,
123 timeRecord->frameTime.frameNumber);
124 }
125 }
126
127 if (timeRecord->presentFence != nullptr) {
128 if (timeRecord->presentFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
129 return false;
130 }
131 if (timeRecord->presentFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
132 timeRecord->frameTime.presentTime = timeRecord->presentFence->getSignalTime();
133 timeRecord->presentFence = nullptr;
134 } else {
135 ALOGV("[%d]-[%" PRIu64 "]-presentFence signal time invalid", layerID,
136 timeRecord->frameTime.frameNumber);
137 }
138 }
139
140 return true;
141 }
142
msBetween(nsecs_t start,nsecs_t end)143 static int32_t msBetween(nsecs_t start, nsecs_t end) {
144 int64_t delta = (end - start) / 1000000;
145 delta = std::clamp(delta, int64_t(INT32_MIN), int64_t(INT32_MAX));
146 return static_cast<int32_t>(delta);
147 }
148
149 // This regular expression captures the following for instance:
150 // StatusBar in StatusBar#0
151 // com.appname in com.appname/com.appname.activity#0
152 // com.appname in SurfaceView - com.appname/com.appname.activity#0
153 static const std::regex packageNameRegex("(?:SurfaceView[-\\s\\t]+)?([^/]+).*#\\d+");
154
getPackageName(const std::string & layerName)155 static std::string getPackageName(const std::string& layerName) {
156 std::smatch match;
157 if (std::regex_match(layerName.begin(), layerName.end(), match, packageNameRegex)) {
158 // There must be a match for group 1 otherwise the whole string is not
159 // matched and the above will return false
160 return match[1];
161 }
162 return "";
163 }
164
flushAvailableRecordsToStatsLocked(int32_t layerID)165 void TimeStats::flushAvailableRecordsToStatsLocked(int32_t layerID) {
166 ATRACE_CALL();
167
168 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
169 TimeRecord& prevTimeRecord = layerRecord.prevTimeRecord;
170 std::deque<TimeRecord>& timeRecords = layerRecord.timeRecords;
171 while (!timeRecords.empty()) {
172 if (!recordReadyLocked(layerID, &timeRecords[0])) break;
173 ALOGV("[%d]-[%" PRIu64 "]-presentFenceTime[%" PRId64 "]", layerID,
174 timeRecords[0].frameTime.frameNumber, timeRecords[0].frameTime.presentTime);
175
176 const std::string& layerName = layerRecord.layerName;
177 if (prevTimeRecord.ready) {
178 if (!mTimeStats.stats.count(layerName)) {
179 mTimeStats.stats[layerName].layerName = layerName;
180 mTimeStats.stats[layerName].packageName = getPackageName(layerName);
181 }
182 TimeStatsHelper::TimeStatsLayer& timeStatsLayer = mTimeStats.stats[layerName];
183 timeStatsLayer.totalFrames++;
184 timeStatsLayer.droppedFrames += layerRecord.droppedFrames;
185 layerRecord.droppedFrames = 0;
186
187 const int32_t postToAcquireMs = msBetween(timeRecords[0].frameTime.postTime,
188 timeRecords[0].frameTime.acquireTime);
189 ALOGV("[%d]-[%" PRIu64 "]-post2acquire[%d]", layerID,
190 timeRecords[0].frameTime.frameNumber, postToAcquireMs);
191 timeStatsLayer.deltas["post2acquire"].insert(postToAcquireMs);
192
193 const int32_t postToPresentMs = msBetween(timeRecords[0].frameTime.postTime,
194 timeRecords[0].frameTime.presentTime);
195 ALOGV("[%d]-[%" PRIu64 "]-post2present[%d]", layerID,
196 timeRecords[0].frameTime.frameNumber, postToPresentMs);
197 timeStatsLayer.deltas["post2present"].insert(postToPresentMs);
198
199 const int32_t acquireToPresentMs = msBetween(timeRecords[0].frameTime.acquireTime,
200 timeRecords[0].frameTime.presentTime);
201 ALOGV("[%d]-[%" PRIu64 "]-acquire2present[%d]", layerID,
202 timeRecords[0].frameTime.frameNumber, acquireToPresentMs);
203 timeStatsLayer.deltas["acquire2present"].insert(acquireToPresentMs);
204
205 const int32_t latchToPresentMs = msBetween(timeRecords[0].frameTime.latchTime,
206 timeRecords[0].frameTime.presentTime);
207 ALOGV("[%d]-[%" PRIu64 "]-latch2present[%d]", layerID,
208 timeRecords[0].frameTime.frameNumber, latchToPresentMs);
209 timeStatsLayer.deltas["latch2present"].insert(latchToPresentMs);
210
211 const int32_t desiredToPresentMs = msBetween(timeRecords[0].frameTime.desiredTime,
212 timeRecords[0].frameTime.presentTime);
213 ALOGV("[%d]-[%" PRIu64 "]-desired2present[%d]", layerID,
214 timeRecords[0].frameTime.frameNumber, desiredToPresentMs);
215 timeStatsLayer.deltas["desired2present"].insert(desiredToPresentMs);
216
217 const int32_t presentToPresentMs = msBetween(prevTimeRecord.frameTime.presentTime,
218 timeRecords[0].frameTime.presentTime);
219 ALOGV("[%d]-[%" PRIu64 "]-present2present[%d]", layerID,
220 timeRecords[0].frameTime.frameNumber, presentToPresentMs);
221 timeStatsLayer.deltas["present2present"].insert(presentToPresentMs);
222 }
223
224 // Output additional trace points to track frame time.
225 ATRACE_INT64(("TimeStats-Post - " + layerName).c_str(), timeRecords[0].frameTime.postTime);
226 ATRACE_INT64(("TimeStats-Acquire - " + layerName).c_str(),
227 timeRecords[0].frameTime.acquireTime);
228 ATRACE_INT64(("TimeStats-Latch - " + layerName).c_str(),
229 timeRecords[0].frameTime.latchTime);
230 ATRACE_INT64(("TimeStats-Desired - " + layerName).c_str(),
231 timeRecords[0].frameTime.desiredTime);
232 ATRACE_INT64(("TimeStats-Present - " + layerName).c_str(),
233 timeRecords[0].frameTime.presentTime);
234
235 prevTimeRecord = timeRecords[0];
236 timeRecords.pop_front();
237 layerRecord.waitData--;
238 }
239 }
240
241 // This regular expression captures the following layer names for instance:
242 // 1) StatusBat#0
243 // 2) NavigationBar#1
244 // 3) co(m).*#0
245 // 4) SurfaceView - co(m).*#0
246 // Using [-\\s\t]+ for the conjunction part between SurfaceView and co(m).*
247 // is a bit more robust in case there's a slight change.
248 // The layer name would only consist of . / $ _ 0-9 a-z A-Z in most cases.
249 static const std::regex layerNameRegex(
250 "(((SurfaceView[-\\s\\t]+)?com?\\.[./$\\w]+)|((Status|Navigation)Bar))#\\d+");
251
layerNameIsValid(const std::string & layerName)252 static bool layerNameIsValid(const std::string& layerName) {
253 return std::regex_match(layerName.begin(), layerName.end(), layerNameRegex);
254 }
255
setPostTime(int32_t layerID,uint64_t frameNumber,const std::string & layerName,nsecs_t postTime)256 void TimeStats::setPostTime(int32_t layerID, uint64_t frameNumber, const std::string& layerName,
257 nsecs_t postTime) {
258 if (!mEnabled.load()) return;
259
260 ATRACE_CALL();
261 ALOGV("[%d]-[%" PRIu64 "]-[%s]-PostTime[%" PRId64 "]", layerID, frameNumber, layerName.c_str(),
262 postTime);
263
264 std::lock_guard<std::mutex> lock(mMutex);
265 if (!mTimeStatsTracker.count(layerID) && mTimeStatsTracker.size() < MAX_NUM_LAYER_RECORDS &&
266 layerNameIsValid(layerName)) {
267 mTimeStatsTracker[layerID].layerName = layerName;
268 }
269 if (!mTimeStatsTracker.count(layerID)) return;
270 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
271 if (layerRecord.timeRecords.size() == MAX_NUM_TIME_RECORDS) {
272 ALOGE("[%d]-[%s]-timeRecords is at its maximum size[%zu]. Ignore this when unittesting.",
273 layerID, layerRecord.layerName.c_str(), MAX_NUM_TIME_RECORDS);
274 mTimeStatsTracker.erase(layerID);
275 return;
276 }
277 // For most media content, the acquireFence is invalid because the buffer is
278 // ready at the queueBuffer stage. In this case, acquireTime should be given
279 // a default value as postTime.
280 TimeRecord timeRecord = {
281 .frameTime =
282 {
283 .frameNumber = frameNumber,
284 .postTime = postTime,
285 .latchTime = postTime,
286 .acquireTime = postTime,
287 .desiredTime = postTime,
288 },
289 };
290 layerRecord.timeRecords.push_back(timeRecord);
291 if (layerRecord.waitData < 0 ||
292 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
293 layerRecord.waitData = layerRecord.timeRecords.size() - 1;
294 }
295
setLatchTime(int32_t layerID,uint64_t frameNumber,nsecs_t latchTime)296 void TimeStats::setLatchTime(int32_t layerID, uint64_t frameNumber, nsecs_t latchTime) {
297 if (!mEnabled.load()) return;
298
299 ATRACE_CALL();
300 ALOGV("[%d]-[%" PRIu64 "]-LatchTime[%" PRId64 "]", layerID, frameNumber, latchTime);
301
302 std::lock_guard<std::mutex> lock(mMutex);
303 if (!mTimeStatsTracker.count(layerID)) return;
304 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
305 if (layerRecord.waitData < 0 ||
306 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
307 return;
308 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
309 if (timeRecord.frameTime.frameNumber == frameNumber) {
310 timeRecord.frameTime.latchTime = latchTime;
311 }
312 }
313
setDesiredTime(int32_t layerID,uint64_t frameNumber,nsecs_t desiredTime)314 void TimeStats::setDesiredTime(int32_t layerID, uint64_t frameNumber, nsecs_t desiredTime) {
315 if (!mEnabled.load()) return;
316
317 ATRACE_CALL();
318 ALOGV("[%d]-[%" PRIu64 "]-DesiredTime[%" PRId64 "]", layerID, frameNumber, desiredTime);
319
320 std::lock_guard<std::mutex> lock(mMutex);
321 if (!mTimeStatsTracker.count(layerID)) return;
322 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
323 if (layerRecord.waitData < 0 ||
324 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
325 return;
326 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
327 if (timeRecord.frameTime.frameNumber == frameNumber) {
328 timeRecord.frameTime.desiredTime = desiredTime;
329 }
330 }
331
setAcquireTime(int32_t layerID,uint64_t frameNumber,nsecs_t acquireTime)332 void TimeStats::setAcquireTime(int32_t layerID, uint64_t frameNumber, nsecs_t acquireTime) {
333 if (!mEnabled.load()) return;
334
335 ATRACE_CALL();
336 ALOGV("[%d]-[%" PRIu64 "]-AcquireTime[%" PRId64 "]", layerID, frameNumber, acquireTime);
337
338 std::lock_guard<std::mutex> lock(mMutex);
339 if (!mTimeStatsTracker.count(layerID)) return;
340 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
341 if (layerRecord.waitData < 0 ||
342 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
343 return;
344 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
345 if (timeRecord.frameTime.frameNumber == frameNumber) {
346 timeRecord.frameTime.acquireTime = acquireTime;
347 }
348 }
349
setAcquireFence(int32_t layerID,uint64_t frameNumber,const std::shared_ptr<FenceTime> & acquireFence)350 void TimeStats::setAcquireFence(int32_t layerID, uint64_t frameNumber,
351 const std::shared_ptr<FenceTime>& acquireFence) {
352 if (!mEnabled.load()) return;
353
354 ATRACE_CALL();
355 ALOGV("[%d]-[%" PRIu64 "]-AcquireFenceTime[%" PRId64 "]", layerID, frameNumber,
356 acquireFence->getSignalTime());
357
358 std::lock_guard<std::mutex> lock(mMutex);
359 if (!mTimeStatsTracker.count(layerID)) return;
360 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
361 if (layerRecord.waitData < 0 ||
362 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
363 return;
364 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
365 if (timeRecord.frameTime.frameNumber == frameNumber) {
366 timeRecord.acquireFence = acquireFence;
367 }
368 }
369
setPresentTime(int32_t layerID,uint64_t frameNumber,nsecs_t presentTime)370 void TimeStats::setPresentTime(int32_t layerID, uint64_t frameNumber, nsecs_t presentTime) {
371 if (!mEnabled.load()) return;
372
373 ATRACE_CALL();
374 ALOGV("[%d]-[%" PRIu64 "]-PresentTime[%" PRId64 "]", layerID, frameNumber, presentTime);
375
376 std::lock_guard<std::mutex> lock(mMutex);
377 if (!mTimeStatsTracker.count(layerID)) return;
378 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
379 if (layerRecord.waitData < 0 ||
380 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
381 return;
382 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
383 if (timeRecord.frameTime.frameNumber == frameNumber) {
384 timeRecord.frameTime.presentTime = presentTime;
385 timeRecord.ready = true;
386 layerRecord.waitData++;
387 }
388
389 flushAvailableRecordsToStatsLocked(layerID);
390 }
391
setPresentFence(int32_t layerID,uint64_t frameNumber,const std::shared_ptr<FenceTime> & presentFence)392 void TimeStats::setPresentFence(int32_t layerID, uint64_t frameNumber,
393 const std::shared_ptr<FenceTime>& presentFence) {
394 if (!mEnabled.load()) return;
395
396 ATRACE_CALL();
397 ALOGV("[%d]-[%" PRIu64 "]-PresentFenceTime[%" PRId64 "]", layerID, frameNumber,
398 presentFence->getSignalTime());
399
400 std::lock_guard<std::mutex> lock(mMutex);
401 if (!mTimeStatsTracker.count(layerID)) return;
402 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
403 if (layerRecord.waitData < 0 ||
404 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
405 return;
406 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
407 if (timeRecord.frameTime.frameNumber == frameNumber) {
408 timeRecord.presentFence = presentFence;
409 timeRecord.ready = true;
410 layerRecord.waitData++;
411 }
412
413 flushAvailableRecordsToStatsLocked(layerID);
414 }
415
onDestroy(int32_t layerID)416 void TimeStats::onDestroy(int32_t layerID) {
417 if (!mEnabled.load()) return;
418
419 ATRACE_CALL();
420 ALOGV("[%d]-onDestroy", layerID);
421
422 std::lock_guard<std::mutex> lock(mMutex);
423 if (!mTimeStatsTracker.count(layerID)) return;
424 mTimeStatsTracker.erase(layerID);
425 }
426
removeTimeRecord(int32_t layerID,uint64_t frameNumber)427 void TimeStats::removeTimeRecord(int32_t layerID, uint64_t frameNumber) {
428 if (!mEnabled.load()) return;
429
430 ATRACE_CALL();
431 ALOGV("[%d]-[%" PRIu64 "]-removeTimeRecord", layerID, frameNumber);
432
433 std::lock_guard<std::mutex> lock(mMutex);
434 if (!mTimeStatsTracker.count(layerID)) return;
435 LayerRecord& layerRecord = mTimeStatsTracker[layerID];
436 size_t removeAt = 0;
437 for (const TimeRecord& record : layerRecord.timeRecords) {
438 if (record.frameTime.frameNumber == frameNumber) break;
439 removeAt++;
440 }
441 if (removeAt == layerRecord.timeRecords.size()) return;
442 layerRecord.timeRecords.erase(layerRecord.timeRecords.begin() + removeAt);
443 if (layerRecord.waitData > static_cast<int32_t>(removeAt)) {
444 layerRecord.waitData--;
445 }
446 layerRecord.droppedFrames++;
447 }
448
flushPowerTimeLocked()449 void TimeStats::flushPowerTimeLocked() {
450 if (!mEnabled.load()) return;
451
452 nsecs_t curTime = systemTime();
453 // elapsedTime is in milliseconds.
454 int64_t elapsedTime = (curTime - mPowerTime.prevTime) / 1000000;
455
456 switch (mPowerTime.powerMode) {
457 case HWC_POWER_MODE_NORMAL:
458 mTimeStats.displayOnTime += elapsedTime;
459 break;
460 case HWC_POWER_MODE_OFF:
461 case HWC_POWER_MODE_DOZE:
462 case HWC_POWER_MODE_DOZE_SUSPEND:
463 default:
464 break;
465 }
466
467 mPowerTime.prevTime = curTime;
468 }
469
setPowerMode(int32_t powerMode)470 void TimeStats::setPowerMode(int32_t powerMode) {
471 if (!mEnabled.load()) {
472 std::lock_guard<std::mutex> lock(mMutex);
473 mPowerTime.powerMode = powerMode;
474 return;
475 }
476
477 std::lock_guard<std::mutex> lock(mMutex);
478 if (powerMode == mPowerTime.powerMode) return;
479
480 flushPowerTimeLocked();
481 mPowerTime.powerMode = powerMode;
482 }
483
recordRefreshRate(uint32_t fps,nsecs_t duration)484 void TimeStats::recordRefreshRate(uint32_t fps, nsecs_t duration) {
485 std::lock_guard<std::mutex> lock(mMutex);
486 if (mTimeStats.refreshRateStats.count(fps)) {
487 mTimeStats.refreshRateStats[fps] += duration;
488 } else {
489 mTimeStats.refreshRateStats.insert({fps, duration});
490 }
491 }
492
flushAvailableGlobalRecordsToStatsLocked()493 void TimeStats::flushAvailableGlobalRecordsToStatsLocked() {
494 ATRACE_CALL();
495
496 while (!mGlobalRecord.presentFences.empty()) {
497 const nsecs_t curPresentTime = mGlobalRecord.presentFences.front()->getSignalTime();
498 if (curPresentTime == Fence::SIGNAL_TIME_PENDING) break;
499
500 if (curPresentTime == Fence::SIGNAL_TIME_INVALID) {
501 ALOGE("GlobalPresentFence is invalid!");
502 mGlobalRecord.prevPresentTime = 0;
503 mGlobalRecord.presentFences.pop_front();
504 continue;
505 }
506
507 ALOGV("GlobalPresentFenceTime[%" PRId64 "]",
508 mGlobalRecord.presentFences.front()->getSignalTime());
509
510 if (mGlobalRecord.prevPresentTime != 0) {
511 const int32_t presentToPresentMs =
512 msBetween(mGlobalRecord.prevPresentTime, curPresentTime);
513 ALOGV("Global present2present[%d] prev[%" PRId64 "] curr[%" PRId64 "]",
514 presentToPresentMs, mGlobalRecord.prevPresentTime, curPresentTime);
515 mTimeStats.presentToPresent.insert(presentToPresentMs);
516 }
517
518 mGlobalRecord.prevPresentTime = curPresentTime;
519 mGlobalRecord.presentFences.pop_front();
520 }
521 }
522
setPresentFenceGlobal(const std::shared_ptr<FenceTime> & presentFence)523 void TimeStats::setPresentFenceGlobal(const std::shared_ptr<FenceTime>& presentFence) {
524 if (!mEnabled.load()) return;
525
526 ATRACE_CALL();
527 std::lock_guard<std::mutex> lock(mMutex);
528 if (presentFence == nullptr || !presentFence->isValid()) {
529 mGlobalRecord.prevPresentTime = 0;
530 return;
531 }
532
533 if (mPowerTime.powerMode != HWC_POWER_MODE_NORMAL) {
534 // Try flushing the last present fence on HWC_POWER_MODE_NORMAL.
535 flushAvailableGlobalRecordsToStatsLocked();
536 mGlobalRecord.presentFences.clear();
537 mGlobalRecord.prevPresentTime = 0;
538 return;
539 }
540
541 if (mGlobalRecord.presentFences.size() == MAX_NUM_TIME_RECORDS) {
542 // The front presentFence must be trapped in pending status in this
543 // case. Try dequeuing the front one to recover.
544 ALOGE("GlobalPresentFences is already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
545 mGlobalRecord.prevPresentTime = 0;
546 mGlobalRecord.presentFences.pop_front();
547 }
548
549 mGlobalRecord.presentFences.emplace_back(presentFence);
550 flushAvailableGlobalRecordsToStatsLocked();
551 }
552
enable()553 void TimeStats::enable() {
554 if (mEnabled.load()) return;
555
556 ATRACE_CALL();
557
558 std::lock_guard<std::mutex> lock(mMutex);
559 mEnabled.store(true);
560 mTimeStats.statsStart = static_cast<int64_t>(std::time(0));
561 mPowerTime.prevTime = systemTime();
562 ALOGD("Enabled");
563 }
564
disable()565 void TimeStats::disable() {
566 if (!mEnabled.load()) return;
567
568 ATRACE_CALL();
569
570 std::lock_guard<std::mutex> lock(mMutex);
571 flushPowerTimeLocked();
572 mEnabled.store(false);
573 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
574 ALOGD("Disabled");
575 }
576
clear()577 void TimeStats::clear() {
578 ATRACE_CALL();
579
580 std::lock_guard<std::mutex> lock(mMutex);
581 mTimeStatsTracker.clear();
582 mTimeStats.stats.clear();
583 mTimeStats.statsStart = (mEnabled.load() ? static_cast<int64_t>(std::time(0)) : 0);
584 mTimeStats.statsEnd = 0;
585 mTimeStats.totalFrames = 0;
586 mTimeStats.missedFrames = 0;
587 mTimeStats.clientCompositionFrames = 0;
588 mTimeStats.displayOnTime = 0;
589 mTimeStats.presentToPresent.hist.clear();
590 mTimeStats.refreshRateStats.clear();
591 mPowerTime.prevTime = systemTime();
592 mGlobalRecord.prevPresentTime = 0;
593 mGlobalRecord.presentFences.clear();
594 ALOGD("Cleared");
595 }
596
isEnabled()597 bool TimeStats::isEnabled() {
598 return mEnabled.load();
599 }
600
dump(bool asProto,std::optional<uint32_t> maxLayers,std::string & result)601 void TimeStats::dump(bool asProto, std::optional<uint32_t> maxLayers, std::string& result) {
602 ATRACE_CALL();
603
604 std::lock_guard<std::mutex> lock(mMutex);
605 if (mTimeStats.statsStart == 0) {
606 return;
607 }
608
609 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
610
611 flushPowerTimeLocked();
612
613 if (asProto) {
614 ALOGD("Dumping TimeStats as proto");
615 SFTimeStatsGlobalProto timeStatsProto = mTimeStats.toProto(maxLayers);
616 result.append(timeStatsProto.SerializeAsString().c_str(), timeStatsProto.ByteSize());
617 } else {
618 ALOGD("Dumping TimeStats as text");
619 result.append(mTimeStats.toString(maxLayers));
620 result.append("\n");
621 }
622 }
623
624 } // namespace impl
625
626 } // namespace android
627