blob: b2cce7c932f921b1cdcaca7c24748340126a1ca2 [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
17// TODO(b/129481165): remove the #pragma below and fix conversion issues
18#pragma clang diagnostic push
19#pragma clang diagnostic ignored "-Wconversion"
Yiwei Zhang0102ad22018-05-02 17:37:17 -070020#undef LOG_TAG
21#define LOG_TAG "TimeStats"
22#define ATRACE_TAG ATRACE_TAG_GRAPHICS
23
24#include "TimeStats.h"
25
26#include <android-base/stringprintf.h>
Alec Mouri37384342020-01-02 17:23:37 -080027#include <android/util/ProtoOutputStream.h>
Yiwei Zhang0102ad22018-05-02 17:37:17 -070028#include <log/log.h>
Yiwei Zhang0102ad22018-05-02 17:37:17 -070029#include <utils/String8.h>
Yiwei Zhang3a226d22018-10-16 09:23:03 -070030#include <utils/Timers.h>
Yiwei Zhang0102ad22018-05-02 17:37:17 -070031#include <utils/Trace.h>
32
33#include <algorithm>
Alec Mouri9519bf12019-11-15 16:54:44 -080034#include <chrono>
Yiwei Zhang0102ad22018-05-02 17:37:17 -070035
36namespace android {
37
Alec Mourifb571ea2019-01-24 18:42:10 -080038namespace impl {
39
Tej Singh2a457b62020-01-31 16:16:10 -080040AStatsManager_PullAtomCallbackReturn TimeStats::pullAtomCallback(int32_t atom_tag,
41 AStatsEventList* data,
42 void* cookie) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +000043 impl::TimeStats* timeStats = reinterpret_cast<impl::TimeStats*>(cookie);
Tej Singh2a457b62020-01-31 16:16:10 -080044 AStatsManager_PullAtomCallbackReturn result = AStatsManager_PULL_SKIP;
Alec Mouri37384342020-01-02 17:23:37 -080045 if (atom_tag == android::util::SURFACEFLINGER_STATS_GLOBAL_INFO) {
Alec Mouri3ecd5cd2020-01-29 12:53:07 -080046 result = timeStats->populateGlobalAtom(data);
Alec Mouri37384342020-01-02 17:23:37 -080047 } else if (atom_tag == android::util::SURFACEFLINGER_STATS_LAYER_INFO) {
Alec Mouri3ecd5cd2020-01-29 12:53:07 -080048 result = timeStats->populateLayerAtom(data);
Alec Mouri8e2f31b2020-01-16 22:04:35 +000049 }
50
Alec Mouri3ecd5cd2020-01-29 12:53:07 -080051 // Enable timestats now. The first full pull for a given build is expected to
52 // have empty or very little stats, as stats are first enabled after the
53 // first pull is completed for either the global or layer stats.
54 timeStats->enable();
55 return result;
Alec Mouri37384342020-01-02 17:23:37 -080056}
Alec Mouri8e2f31b2020-01-16 22:04:35 +000057
Tej Singh2a457b62020-01-31 16:16:10 -080058AStatsManager_PullAtomCallbackReturn TimeStats::populateGlobalAtom(AStatsEventList* data) {
Alec Mouri37384342020-01-02 17:23:37 -080059 std::lock_guard<std::mutex> lock(mMutex);
60
61 if (mTimeStats.statsStart == 0) {
Tej Singh2a457b62020-01-31 16:16:10 -080062 return AStatsManager_PULL_SKIP;
Alec Mouri8e2f31b2020-01-16 22:04:35 +000063 }
Alec Mouri37384342020-01-02 17:23:37 -080064 flushPowerTimeLocked();
Alec Mouri8e2f31b2020-01-16 22:04:35 +000065
Tej Singh2a457b62020-01-31 16:16:10 -080066 AStatsEvent* event = mStatsDelegate->addStatsEventToPullData(data);
Alec Mouri37384342020-01-02 17:23:37 -080067 mStatsDelegate->statsEventSetAtomId(event, android::util::SURFACEFLINGER_STATS_GLOBAL_INFO);
68 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.totalFrames);
69 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.missedFrames);
70 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.clientCompositionFrames);
71 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.displayOnTime);
72 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.presentToPresent.totalTime());
73 mStatsDelegate->statsEventBuild(event);
74 clearGlobalLocked();
Alec Mouri8e2f31b2020-01-16 22:04:35 +000075
Tej Singh2a457b62020-01-31 16:16:10 -080076 return AStatsManager_PULL_SUCCESS;
Alec Mouri8e2f31b2020-01-16 22:04:35 +000077}
78
Alec Mouri37384342020-01-02 17:23:37 -080079namespace {
80// Histograms align with the order of fields in SurfaceflingerStatsLayerInfo.
81const std::array<std::string, 6> kHistogramNames = {
82 "present2present", "post2present", "acquire2present",
83 "latch2present", "desired2present", "post2acquire",
84};
Alec Mouri8e2f31b2020-01-16 22:04:35 +000085
Alec Mouri37384342020-01-02 17:23:37 -080086std::string histogramToProtoByteString(const std::unordered_map<int32_t, int32_t>& histogram,
87 size_t maxPulledHistogramBuckets) {
88 auto buckets = std::vector<std::pair<int32_t, int32_t>>(histogram.begin(), histogram.end());
89 std::sort(buckets.begin(), buckets.end(),
90 [](std::pair<int32_t, int32_t>& left, std::pair<int32_t, int32_t>& right) {
91 return left.second > right.second;
92 });
93
94 util::ProtoOutputStream proto;
95 int histogramSize = 0;
96 for (const auto& bucket : buckets) {
97 if (++histogramSize > maxPulledHistogramBuckets) {
98 break;
99 }
100 proto.write(android::util::FIELD_TYPE_INT32 | android::util::FIELD_COUNT_REPEATED |
101 1 /* field id */,
102 (int32_t)bucket.first);
103 proto.write(android::util::FIELD_TYPE_INT64 | android::util::FIELD_COUNT_REPEATED |
104 2 /* field id */,
105 (int64_t)bucket.second);
106 }
107
108 std::string byteString;
109 proto.serializeToString(&byteString);
110 return byteString;
111}
112} // namespace
113
Tej Singh2a457b62020-01-31 16:16:10 -0800114AStatsManager_PullAtomCallbackReturn TimeStats::populateLayerAtom(AStatsEventList* data) {
Alec Mouri37384342020-01-02 17:23:37 -0800115 std::lock_guard<std::mutex> lock(mMutex);
116
117 std::vector<TimeStatsHelper::TimeStatsLayer const*> dumpStats;
118 for (const auto& ele : mTimeStats.stats) {
119 dumpStats.push_back(&ele.second);
120 }
121
122 std::sort(dumpStats.begin(), dumpStats.end(),
123 [](TimeStatsHelper::TimeStatsLayer const* l,
124 TimeStatsHelper::TimeStatsLayer const* r) {
125 return l->totalFrames > r->totalFrames;
126 });
127
128 if (mMaxPulledLayers < dumpStats.size()) {
129 dumpStats.resize(mMaxPulledLayers);
130 }
131
132 for (const auto& layer : dumpStats) {
Tej Singh2a457b62020-01-31 16:16:10 -0800133 AStatsEvent* event = mStatsDelegate->addStatsEventToPullData(data);
Alec Mouri37384342020-01-02 17:23:37 -0800134 mStatsDelegate->statsEventSetAtomId(event, android::util::SURFACEFLINGER_STATS_LAYER_INFO);
135 mStatsDelegate->statsEventWriteString8(event, layer->layerName.c_str());
136 mStatsDelegate->statsEventWriteInt64(event, layer->totalFrames);
137 mStatsDelegate->statsEventWriteInt64(event, layer->droppedFrames);
138
139 for (const auto& name : kHistogramNames) {
140 const auto& histogram = layer->deltas.find(name);
141 if (histogram == layer->deltas.cend()) {
142 mStatsDelegate->statsEventWriteByteArray(event, nullptr, 0);
143 } else {
144 std::string bytes = histogramToProtoByteString(histogram->second.hist,
145 mMaxPulledHistogramBuckets);
146 mStatsDelegate->statsEventWriteByteArray(event, (const uint8_t*)bytes.c_str(),
147 bytes.size());
148 }
149 }
150
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -0800151 mStatsDelegate->statsEventWriteInt64(event, layer->lateAcquireFrames);
152 mStatsDelegate->statsEventWriteInt64(event, layer->badDesiredPresentFrames);
153
Alec Mouri37384342020-01-02 17:23:37 -0800154 mStatsDelegate->statsEventBuild(event);
155 }
156 clearLayersLocked();
157
Tej Singh2a457b62020-01-31 16:16:10 -0800158 return AStatsManager_PULL_SUCCESS;
Alec Mouri37384342020-01-02 17:23:37 -0800159}
160
161TimeStats::TimeStats() : TimeStats(nullptr, std::nullopt, std::nullopt) {}
162
163TimeStats::TimeStats(std::unique_ptr<StatsEventDelegate> statsDelegate,
164 std::optional<size_t> maxPulledLayers,
165 std::optional<size_t> maxPulledHistogramBuckets) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000166 if (statsDelegate != nullptr) {
167 mStatsDelegate = std::move(statsDelegate);
168 }
Alec Mouri37384342020-01-02 17:23:37 -0800169
170 if (maxPulledLayers) {
171 mMaxPulledLayers = *maxPulledLayers;
172 }
173
174 if (maxPulledHistogramBuckets) {
175 mMaxPulledHistogramBuckets = *maxPulledHistogramBuckets;
176 }
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000177}
178
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800179TimeStats::~TimeStats() {
180 std::lock_guard<std::mutex> lock(mMutex);
181 mStatsDelegate->unregisterStatsPullAtomCallback(
182 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO);
183 mStatsDelegate->unregisterStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO);
184}
185
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000186void TimeStats::onBootFinished() {
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800187 std::lock_guard<std::mutex> lock(mMutex);
188 mStatsDelegate->registerStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
189 TimeStats::pullAtomCallback, nullptr, this);
190 mStatsDelegate->registerStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
191 TimeStats::pullAtomCallback, nullptr, this);
Alec Mourib3885ad2019-09-06 17:08:55 -0700192}
193
Dominik Laskowskic2867142019-01-21 11:33:38 -0800194void TimeStats::parseArgs(bool asProto, const Vector<String16>& args, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700195 ATRACE_CALL();
196
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700197 std::unordered_map<std::string, int32_t> argsMap;
Dominik Laskowskic2867142019-01-21 11:33:38 -0800198 for (size_t index = 0; index < args.size(); ++index) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700199 argsMap[std::string(String8(args[index]).c_str())] = index;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700200 }
201
202 if (argsMap.count("-disable")) {
203 disable();
204 }
205
206 if (argsMap.count("-dump")) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700207 std::optional<uint32_t> maxLayers = std::nullopt;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700208 auto iter = argsMap.find("-maxlayers");
209 if (iter != argsMap.end() && iter->second + 1 < static_cast<int32_t>(args.size())) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700210 int64_t value = strtol(String8(args[iter->second + 1]).c_str(), nullptr, 10);
211 value = std::clamp(value, int64_t(0), int64_t(UINT32_MAX));
212 maxLayers = static_cast<uint32_t>(value);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700213 }
214
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700215 dump(asProto, maxLayers, result);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700216 }
217
218 if (argsMap.count("-clear")) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000219 clearAll();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700220 }
221
222 if (argsMap.count("-enable")) {
223 enable();
224 }
225}
226
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700227std::string TimeStats::miniDump() {
228 ATRACE_CALL();
229
230 std::string result = "TimeStats miniDump:\n";
231 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange926ab52019-08-14 15:16:00 -0700232 android::base::StringAppendF(&result, "Number of layers currently being tracked is %zu\n",
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700233 mTimeStatsTracker.size());
Yiwei Zhange926ab52019-08-14 15:16:00 -0700234 android::base::StringAppendF(&result, "Number of layers in the stats pool is %zu\n",
235 mTimeStats.stats.size());
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700236 return result;
237}
238
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700239void TimeStats::incrementTotalFrames() {
240 if (!mEnabled.load()) return;
241
242 ATRACE_CALL();
243
244 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700245 mTimeStats.totalFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700246}
247
Yiwei Zhang621f9d42018-05-07 10:40:55 -0700248void TimeStats::incrementMissedFrames() {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700249 if (!mEnabled.load()) return;
250
251 ATRACE_CALL();
252
253 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700254 mTimeStats.missedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700255}
256
257void TimeStats::incrementClientCompositionFrames() {
258 if (!mEnabled.load()) return;
259
260 ATRACE_CALL();
261
262 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700263 mTimeStats.clientCompositionFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700264}
265
Vishnu Nair9b079a22020-01-21 14:36:08 -0800266void TimeStats::incrementClientCompositionReusedFrames() {
267 if (!mEnabled.load()) return;
268
269 ATRACE_CALL();
270
271 std::lock_guard<std::mutex> lock(mMutex);
272 mTimeStats.clientCompositionReusedFrames++;
273}
274
Alec Mouri9519bf12019-11-15 16:54:44 -0800275static int32_t msBetween(nsecs_t start, nsecs_t end) {
276 int64_t delta = std::chrono::duration_cast<std::chrono::milliseconds>(
277 std::chrono::nanoseconds(end - start))
278 .count();
279 delta = std::clamp(delta, int64_t(INT32_MIN), int64_t(INT32_MAX));
280 return static_cast<int32_t>(delta);
281}
282
283void TimeStats::recordFrameDuration(nsecs_t startTime, nsecs_t endTime) {
284 if (!mEnabled.load()) return;
285
286 std::lock_guard<std::mutex> lock(mMutex);
287 if (mPowerTime.powerMode == HWC_POWER_MODE_NORMAL) {
288 mTimeStats.frameDuration.insert(msBetween(startTime, endTime));
289 }
290}
291
Alec Mourie4034bb2019-11-19 12:45:54 -0800292void TimeStats::recordRenderEngineDuration(nsecs_t startTime, nsecs_t endTime) {
293 if (!mEnabled.load()) return;
294
295 std::lock_guard<std::mutex> lock(mMutex);
296 if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
297 ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
298 mGlobalRecord.renderEngineDurations.pop_front();
299 }
300 mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
301}
302
303void TimeStats::recordRenderEngineDuration(nsecs_t startTime,
304 const std::shared_ptr<FenceTime>& endTime) {
305 if (!mEnabled.load()) return;
306
307 std::lock_guard<std::mutex> lock(mMutex);
308 if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
309 ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
310 mGlobalRecord.renderEngineDurations.pop_front();
311 }
312 mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
313}
314
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800315bool TimeStats::recordReadyLocked(int32_t layerId, TimeRecord* timeRecord) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700316 if (!timeRecord->ready) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800317 ALOGV("[%d]-[%" PRIu64 "]-presentFence is still not received", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700318 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700319 return false;
320 }
321
322 if (timeRecord->acquireFence != nullptr) {
323 if (timeRecord->acquireFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
324 return false;
325 }
326 if (timeRecord->acquireFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700327 timeRecord->frameTime.acquireTime = timeRecord->acquireFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700328 timeRecord->acquireFence = nullptr;
329 } else {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800330 ALOGV("[%d]-[%" PRIu64 "]-acquireFence signal time is invalid", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700331 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700332 }
333 }
334
335 if (timeRecord->presentFence != nullptr) {
336 if (timeRecord->presentFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
337 return false;
338 }
339 if (timeRecord->presentFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700340 timeRecord->frameTime.presentTime = timeRecord->presentFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700341 timeRecord->presentFence = nullptr;
342 } else {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800343 ALOGV("[%d]-[%" PRIu64 "]-presentFence signal time invalid", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700344 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700345 }
346 }
347
348 return true;
349}
350
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800351void TimeStats::flushAvailableRecordsToStatsLocked(int32_t layerId) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700352 ATRACE_CALL();
353
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800354 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700355 TimeRecord& prevTimeRecord = layerRecord.prevTimeRecord;
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700356 std::deque<TimeRecord>& timeRecords = layerRecord.timeRecords;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700357 while (!timeRecords.empty()) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800358 if (!recordReadyLocked(layerId, &timeRecords[0])) break;
359 ALOGV("[%d]-[%" PRIu64 "]-presentFenceTime[%" PRId64 "]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700360 timeRecords[0].frameTime.frameNumber, timeRecords[0].frameTime.presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700361
362 if (prevTimeRecord.ready) {
Yiwei Zhangeafa5cc2019-07-26 15:06:25 -0700363 const std::string& layerName = layerRecord.layerName;
Yiwei Zhangdc224042018-10-18 15:34:00 -0700364 if (!mTimeStats.stats.count(layerName)) {
365 mTimeStats.stats[layerName].layerName = layerName;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700366 }
Yiwei Zhangdc224042018-10-18 15:34:00 -0700367 TimeStatsHelper::TimeStatsLayer& timeStatsLayer = mTimeStats.stats[layerName];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700368 timeStatsLayer.totalFrames++;
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700369 timeStatsLayer.droppedFrames += layerRecord.droppedFrames;
Alec Mouri91f6df32020-01-30 08:48:58 -0800370 timeStatsLayer.lateAcquireFrames += layerRecord.lateAcquireFrames;
371 timeStatsLayer.badDesiredPresentFrames += layerRecord.badDesiredPresentFrames;
372
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700373 layerRecord.droppedFrames = 0;
Alec Mouri91f6df32020-01-30 08:48:58 -0800374 layerRecord.lateAcquireFrames = 0;
375 layerRecord.badDesiredPresentFrames = 0;
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700376
377 const int32_t postToAcquireMs = msBetween(timeRecords[0].frameTime.postTime,
378 timeRecords[0].frameTime.acquireTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800379 ALOGV("[%d]-[%" PRIu64 "]-post2acquire[%d]", layerId,
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700380 timeRecords[0].frameTime.frameNumber, postToAcquireMs);
381 timeStatsLayer.deltas["post2acquire"].insert(postToAcquireMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700382
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700383 const int32_t postToPresentMs = msBetween(timeRecords[0].frameTime.postTime,
384 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800385 ALOGV("[%d]-[%" PRIu64 "]-post2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700386 timeRecords[0].frameTime.frameNumber, postToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700387 timeStatsLayer.deltas["post2present"].insert(postToPresentMs);
388
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700389 const int32_t acquireToPresentMs = msBetween(timeRecords[0].frameTime.acquireTime,
390 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800391 ALOGV("[%d]-[%" PRIu64 "]-acquire2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700392 timeRecords[0].frameTime.frameNumber, acquireToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700393 timeStatsLayer.deltas["acquire2present"].insert(acquireToPresentMs);
394
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700395 const int32_t latchToPresentMs = msBetween(timeRecords[0].frameTime.latchTime,
396 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800397 ALOGV("[%d]-[%" PRIu64 "]-latch2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700398 timeRecords[0].frameTime.frameNumber, latchToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700399 timeStatsLayer.deltas["latch2present"].insert(latchToPresentMs);
400
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700401 const int32_t desiredToPresentMs = msBetween(timeRecords[0].frameTime.desiredTime,
402 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800403 ALOGV("[%d]-[%" PRIu64 "]-desired2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700404 timeRecords[0].frameTime.frameNumber, desiredToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700405 timeStatsLayer.deltas["desired2present"].insert(desiredToPresentMs);
406
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700407 const int32_t presentToPresentMs = msBetween(prevTimeRecord.frameTime.presentTime,
408 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800409 ALOGV("[%d]-[%" PRIu64 "]-present2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700410 timeRecords[0].frameTime.frameNumber, presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700411 timeStatsLayer.deltas["present2present"].insert(presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700412 }
413 prevTimeRecord = timeRecords[0];
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700414 timeRecords.pop_front();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700415 layerRecord.waitData--;
416 }
417}
418
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700419static constexpr const char* kPopupWindowPrefix = "PopupWindow";
420static const size_t kMinLenLayerName = std::strlen(kPopupWindowPrefix);
Yiwei Zhangbd408322018-10-15 18:31:53 -0700421
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700422// Avoid tracking the "PopupWindow:<random hash>#<number>" layers
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700423static bool layerNameIsValid(const std::string& layerName) {
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700424 return layerName.length() >= kMinLenLayerName &&
425 layerName.compare(0, kMinLenLayerName, kPopupWindowPrefix) != 0;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700426}
427
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800428void TimeStats::setPostTime(int32_t layerId, uint64_t frameNumber, const std::string& layerName,
Yiwei Zhang8e8fe522018-11-02 18:34:07 -0700429 nsecs_t postTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700430 if (!mEnabled.load()) return;
431
432 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800433 ALOGV("[%d]-[%" PRIu64 "]-[%s]-PostTime[%" PRId64 "]", layerId, frameNumber, layerName.c_str(),
Yiwei Zhang8e8fe522018-11-02 18:34:07 -0700434 postTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700435
436 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange926ab52019-08-14 15:16:00 -0700437 if (!mTimeStats.stats.count(layerName) && mTimeStats.stats.size() >= MAX_NUM_LAYER_STATS) {
438 return;
439 }
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800440 if (!mTimeStatsTracker.count(layerId) && mTimeStatsTracker.size() < MAX_NUM_LAYER_RECORDS &&
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700441 layerNameIsValid(layerName)) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800442 mTimeStatsTracker[layerId].layerName = layerName;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700443 }
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800444 if (!mTimeStatsTracker.count(layerId)) return;
445 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700446 if (layerRecord.timeRecords.size() == MAX_NUM_TIME_RECORDS) {
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800447 ALOGE("[%d]-[%s]-timeRecords is at its maximum size[%zu]. Ignore this when unittesting.",
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800448 layerId, layerRecord.layerName.c_str(), MAX_NUM_TIME_RECORDS);
449 mTimeStatsTracker.erase(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700450 return;
451 }
452 // For most media content, the acquireFence is invalid because the buffer is
453 // ready at the queueBuffer stage. In this case, acquireTime should be given
454 // a default value as postTime.
455 TimeRecord timeRecord = {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700456 .frameTime =
457 {
458 .frameNumber = frameNumber,
459 .postTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800460 .latchTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700461 .acquireTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800462 .desiredTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700463 },
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700464 };
465 layerRecord.timeRecords.push_back(timeRecord);
466 if (layerRecord.waitData < 0 ||
467 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
468 layerRecord.waitData = layerRecord.timeRecords.size() - 1;
469}
470
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800471void TimeStats::setLatchTime(int32_t layerId, uint64_t frameNumber, nsecs_t latchTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700472 if (!mEnabled.load()) return;
473
474 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800475 ALOGV("[%d]-[%" PRIu64 "]-LatchTime[%" PRId64 "]", layerId, frameNumber, latchTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700476
477 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800478 if (!mTimeStatsTracker.count(layerId)) return;
479 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700480 if (layerRecord.waitData < 0 ||
481 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
482 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700483 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700484 if (timeRecord.frameTime.frameNumber == frameNumber) {
485 timeRecord.frameTime.latchTime = latchTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700486 }
487}
488
Alec Mouri91f6df32020-01-30 08:48:58 -0800489void TimeStats::incrementLatchSkipped(int32_t layerId, LatchSkipReason reason) {
490 if (!mEnabled.load()) return;
491
492 ATRACE_CALL();
493 ALOGV("[%d]-LatchSkipped-Reason[%d]", layerId,
494 static_cast<std::underlying_type<LatchSkipReason>::type>(reason));
495
496 std::lock_guard<std::mutex> lock(mMutex);
497 if (!mTimeStatsTracker.count(layerId)) return;
498 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
499
500 switch (reason) {
501 case LatchSkipReason::LateAcquire:
502 layerRecord.lateAcquireFrames++;
503 break;
504 }
505}
506
507void TimeStats::incrementBadDesiredPresent(int32_t layerId) {
508 if (!mEnabled.load()) return;
509
510 ATRACE_CALL();
511 ALOGV("[%d]-BadDesiredPresent", layerId);
512
513 std::lock_guard<std::mutex> lock(mMutex);
514 if (!mTimeStatsTracker.count(layerId)) return;
515 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
516 layerRecord.badDesiredPresentFrames++;
517}
518
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800519void TimeStats::setDesiredTime(int32_t layerId, uint64_t frameNumber, nsecs_t desiredTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700520 if (!mEnabled.load()) return;
521
522 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800523 ALOGV("[%d]-[%" PRIu64 "]-DesiredTime[%" PRId64 "]", layerId, frameNumber, desiredTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700524
525 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800526 if (!mTimeStatsTracker.count(layerId)) return;
527 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700528 if (layerRecord.waitData < 0 ||
529 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
530 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700531 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700532 if (timeRecord.frameTime.frameNumber == frameNumber) {
533 timeRecord.frameTime.desiredTime = desiredTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700534 }
535}
536
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800537void TimeStats::setAcquireTime(int32_t layerId, uint64_t frameNumber, nsecs_t acquireTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700538 if (!mEnabled.load()) return;
539
540 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800541 ALOGV("[%d]-[%" PRIu64 "]-AcquireTime[%" PRId64 "]", layerId, frameNumber, acquireTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700542
543 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800544 if (!mTimeStatsTracker.count(layerId)) return;
545 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700546 if (layerRecord.waitData < 0 ||
547 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
548 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700549 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700550 if (timeRecord.frameTime.frameNumber == frameNumber) {
551 timeRecord.frameTime.acquireTime = acquireTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700552 }
553}
554
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800555void TimeStats::setAcquireFence(int32_t layerId, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700556 const std::shared_ptr<FenceTime>& acquireFence) {
557 if (!mEnabled.load()) return;
558
559 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800560 ALOGV("[%d]-[%" PRIu64 "]-AcquireFenceTime[%" PRId64 "]", layerId, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700561 acquireFence->getSignalTime());
562
563 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800564 if (!mTimeStatsTracker.count(layerId)) return;
565 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700566 if (layerRecord.waitData < 0 ||
567 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
568 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700569 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700570 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700571 timeRecord.acquireFence = acquireFence;
572 }
573}
574
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800575void TimeStats::setPresentTime(int32_t layerId, uint64_t frameNumber, nsecs_t presentTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700576 if (!mEnabled.load()) return;
577
578 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800579 ALOGV("[%d]-[%" PRIu64 "]-PresentTime[%" PRId64 "]", layerId, frameNumber, presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700580
581 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800582 if (!mTimeStatsTracker.count(layerId)) return;
583 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700584 if (layerRecord.waitData < 0 ||
585 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
586 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700587 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700588 if (timeRecord.frameTime.frameNumber == frameNumber) {
589 timeRecord.frameTime.presentTime = presentTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700590 timeRecord.ready = true;
591 layerRecord.waitData++;
592 }
593
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800594 flushAvailableRecordsToStatsLocked(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700595}
596
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800597void TimeStats::setPresentFence(int32_t layerId, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700598 const std::shared_ptr<FenceTime>& presentFence) {
599 if (!mEnabled.load()) return;
600
601 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800602 ALOGV("[%d]-[%" PRIu64 "]-PresentFenceTime[%" PRId64 "]", layerId, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700603 presentFence->getSignalTime());
604
605 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800606 if (!mTimeStatsTracker.count(layerId)) return;
607 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700608 if (layerRecord.waitData < 0 ||
609 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
610 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700611 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700612 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700613 timeRecord.presentFence = presentFence;
614 timeRecord.ready = true;
615 layerRecord.waitData++;
616 }
617
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800618 flushAvailableRecordsToStatsLocked(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700619}
620
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800621void TimeStats::onDestroy(int32_t layerId) {
Yiwei Zhangdc224042018-10-18 15:34:00 -0700622 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800623 ALOGV("[%d]-onDestroy", layerId);
Mikael Pessa90092f42019-08-26 17:22:04 -0700624 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800625 mTimeStatsTracker.erase(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700626}
627
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800628void TimeStats::removeTimeRecord(int32_t layerId, uint64_t frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700629 if (!mEnabled.load()) return;
630
631 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800632 ALOGV("[%d]-[%" PRIu64 "]-removeTimeRecord", layerId, frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700633
634 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800635 if (!mTimeStatsTracker.count(layerId)) return;
636 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700637 size_t removeAt = 0;
638 for (const TimeRecord& record : layerRecord.timeRecords) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700639 if (record.frameTime.frameNumber == frameNumber) break;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700640 removeAt++;
641 }
642 if (removeAt == layerRecord.timeRecords.size()) return;
643 layerRecord.timeRecords.erase(layerRecord.timeRecords.begin() + removeAt);
644 if (layerRecord.waitData > static_cast<int32_t>(removeAt)) {
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700645 layerRecord.waitData--;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700646 }
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700647 layerRecord.droppedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700648}
649
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700650void TimeStats::flushPowerTimeLocked() {
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700651 if (!mEnabled.load()) return;
652
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700653 nsecs_t curTime = systemTime();
654 // elapsedTime is in milliseconds.
655 int64_t elapsedTime = (curTime - mPowerTime.prevTime) / 1000000;
656
657 switch (mPowerTime.powerMode) {
658 case HWC_POWER_MODE_NORMAL:
659 mTimeStats.displayOnTime += elapsedTime;
660 break;
661 case HWC_POWER_MODE_OFF:
662 case HWC_POWER_MODE_DOZE:
663 case HWC_POWER_MODE_DOZE_SUSPEND:
664 default:
665 break;
666 }
667
668 mPowerTime.prevTime = curTime;
669}
670
671void TimeStats::setPowerMode(int32_t powerMode) {
672 if (!mEnabled.load()) {
673 std::lock_guard<std::mutex> lock(mMutex);
674 mPowerTime.powerMode = powerMode;
675 return;
676 }
677
678 std::lock_guard<std::mutex> lock(mMutex);
679 if (powerMode == mPowerTime.powerMode) return;
680
681 flushPowerTimeLocked();
682 mPowerTime.powerMode = powerMode;
683}
684
Alec Mourifb571ea2019-01-24 18:42:10 -0800685void TimeStats::recordRefreshRate(uint32_t fps, nsecs_t duration) {
686 std::lock_guard<std::mutex> lock(mMutex);
687 if (mTimeStats.refreshRateStats.count(fps)) {
688 mTimeStats.refreshRateStats[fps] += duration;
689 } else {
690 mTimeStats.refreshRateStats.insert({fps, duration});
691 }
692}
693
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700694void TimeStats::flushAvailableGlobalRecordsToStatsLocked() {
695 ATRACE_CALL();
696
697 while (!mGlobalRecord.presentFences.empty()) {
698 const nsecs_t curPresentTime = mGlobalRecord.presentFences.front()->getSignalTime();
699 if (curPresentTime == Fence::SIGNAL_TIME_PENDING) break;
700
701 if (curPresentTime == Fence::SIGNAL_TIME_INVALID) {
702 ALOGE("GlobalPresentFence is invalid!");
703 mGlobalRecord.prevPresentTime = 0;
704 mGlobalRecord.presentFences.pop_front();
705 continue;
706 }
707
708 ALOGV("GlobalPresentFenceTime[%" PRId64 "]",
709 mGlobalRecord.presentFences.front()->getSignalTime());
710
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700711 if (mGlobalRecord.prevPresentTime != 0) {
712 const int32_t presentToPresentMs =
713 msBetween(mGlobalRecord.prevPresentTime, curPresentTime);
714 ALOGV("Global present2present[%d] prev[%" PRId64 "] curr[%" PRId64 "]",
715 presentToPresentMs, mGlobalRecord.prevPresentTime, curPresentTime);
716 mTimeStats.presentToPresent.insert(presentToPresentMs);
717 }
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700718
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700719 mGlobalRecord.prevPresentTime = curPresentTime;
720 mGlobalRecord.presentFences.pop_front();
721 }
Alec Mourie4034bb2019-11-19 12:45:54 -0800722 while (!mGlobalRecord.renderEngineDurations.empty()) {
723 const auto duration = mGlobalRecord.renderEngineDurations.front();
724 const auto& endTime = duration.endTime;
725
726 nsecs_t endNs = -1;
727
728 if (auto val = std::get_if<nsecs_t>(&endTime)) {
729 endNs = *val;
730 } else {
731 endNs = std::get<std::shared_ptr<FenceTime>>(endTime)->getSignalTime();
732 }
733
734 if (endNs == Fence::SIGNAL_TIME_PENDING) break;
735
736 if (endNs < 0) {
737 ALOGE("RenderEngineTiming is invalid!");
738 mGlobalRecord.renderEngineDurations.pop_front();
739 continue;
740 }
741
742 const int32_t renderEngineMs = msBetween(duration.startTime, endNs);
743 mTimeStats.renderEngineTiming.insert(renderEngineMs);
744
745 mGlobalRecord.renderEngineDurations.pop_front();
746 }
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700747}
748
749void TimeStats::setPresentFenceGlobal(const std::shared_ptr<FenceTime>& presentFence) {
750 if (!mEnabled.load()) return;
751
752 ATRACE_CALL();
753 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700754 if (presentFence == nullptr || !presentFence->isValid()) {
755 mGlobalRecord.prevPresentTime = 0;
756 return;
757 }
758
759 if (mPowerTime.powerMode != HWC_POWER_MODE_NORMAL) {
760 // Try flushing the last present fence on HWC_POWER_MODE_NORMAL.
761 flushAvailableGlobalRecordsToStatsLocked();
762 mGlobalRecord.presentFences.clear();
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700763 mGlobalRecord.prevPresentTime = 0;
764 return;
765 }
766
767 if (mGlobalRecord.presentFences.size() == MAX_NUM_TIME_RECORDS) {
768 // The front presentFence must be trapped in pending status in this
769 // case. Try dequeuing the front one to recover.
770 ALOGE("GlobalPresentFences is already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
771 mGlobalRecord.prevPresentTime = 0;
772 mGlobalRecord.presentFences.pop_front();
773 }
774
775 mGlobalRecord.presentFences.emplace_back(presentFence);
776 flushAvailableGlobalRecordsToStatsLocked();
777}
778
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700779void TimeStats::enable() {
780 if (mEnabled.load()) return;
781
782 ATRACE_CALL();
783
784 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700785 mEnabled.store(true);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700786 mTimeStats.statsStart = static_cast<int64_t>(std::time(0));
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700787 mPowerTime.prevTime = systemTime();
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700788 ALOGD("Enabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700789}
790
791void TimeStats::disable() {
792 if (!mEnabled.load()) return;
793
794 ATRACE_CALL();
795
796 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700797 flushPowerTimeLocked();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700798 mEnabled.store(false);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700799 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700800 ALOGD("Disabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700801}
802
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000803void TimeStats::clearAll() {
804 std::lock_guard<std::mutex> lock(mMutex);
805 clearGlobalLocked();
806 clearLayersLocked();
807}
808
809void TimeStats::clearGlobalLocked() {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700810 ATRACE_CALL();
811
Yiwei Zhangdc224042018-10-18 15:34:00 -0700812 mTimeStats.statsStart = (mEnabled.load() ? static_cast<int64_t>(std::time(0)) : 0);
813 mTimeStats.statsEnd = 0;
814 mTimeStats.totalFrames = 0;
815 mTimeStats.missedFrames = 0;
816 mTimeStats.clientCompositionFrames = 0;
Vishnu Nair9b079a22020-01-21 14:36:08 -0800817 mTimeStats.clientCompositionReusedFrames = 0;
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700818 mTimeStats.displayOnTime = 0;
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700819 mTimeStats.presentToPresent.hist.clear();
Alec Mouri31ac64a2020-01-09 09:26:22 -0800820 mTimeStats.frameDuration.hist.clear();
821 mTimeStats.renderEngineTiming.hist.clear();
Alec Mourifb571ea2019-01-24 18:42:10 -0800822 mTimeStats.refreshRateStats.clear();
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700823 mPowerTime.prevTime = systemTime();
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700824 mGlobalRecord.prevPresentTime = 0;
825 mGlobalRecord.presentFences.clear();
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000826 ALOGD("Cleared global stats");
827}
828
829void TimeStats::clearLayersLocked() {
830 ATRACE_CALL();
831
832 mTimeStatsTracker.clear();
833 mTimeStats.stats.clear();
834 ALOGD("Cleared layer stats");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700835}
836
837bool TimeStats::isEnabled() {
838 return mEnabled.load();
839}
840
Yiwei Zhang5434a782018-12-05 18:06:32 -0800841void TimeStats::dump(bool asProto, std::optional<uint32_t> maxLayers, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700842 ATRACE_CALL();
843
844 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700845 if (mTimeStats.statsStart == 0) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700846 return;
847 }
848
Yiwei Zhangdc224042018-10-18 15:34:00 -0700849 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700850
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700851 flushPowerTimeLocked();
852
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700853 if (asProto) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700854 ALOGD("Dumping TimeStats as proto");
Yiwei Zhangdc224042018-10-18 15:34:00 -0700855 SFTimeStatsGlobalProto timeStatsProto = mTimeStats.toProto(maxLayers);
Dominik Laskowski46470112019-08-02 13:13:11 -0700856 result.append(timeStatsProto.SerializeAsString());
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700857 } else {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700858 ALOGD("Dumping TimeStats as text");
Yiwei Zhang5434a782018-12-05 18:06:32 -0800859 result.append(mTimeStats.toString(maxLayers));
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700860 result.append("\n");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700861 }
862}
863
Alec Mourifb571ea2019-01-24 18:42:10 -0800864} // namespace impl
865
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700866} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -0800867
868// TODO(b/129481165): remove the #pragma below and fix conversion issues
869#pragma clang diagnostic pop // ignored "-Wconversion"