blob: 606e137dd24c4ef39676820d05dae59d588793de [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
Alec Mouri37384342020-01-02 17:23:37 -080058namespace {
59// Histograms align with the order of fields in SurfaceflingerStatsLayerInfo.
60const std::array<std::string, 6> kHistogramNames = {
61 "present2present", "post2present", "acquire2present",
62 "latch2present", "desired2present", "post2acquire",
63};
Alec Mouri8e2f31b2020-01-16 22:04:35 +000064
Alec Mouri37384342020-01-02 17:23:37 -080065std::string histogramToProtoByteString(const std::unordered_map<int32_t, int32_t>& histogram,
66 size_t maxPulledHistogramBuckets) {
67 auto buckets = std::vector<std::pair<int32_t, int32_t>>(histogram.begin(), histogram.end());
68 std::sort(buckets.begin(), buckets.end(),
69 [](std::pair<int32_t, int32_t>& left, std::pair<int32_t, int32_t>& right) {
70 return left.second > right.second;
71 });
72
73 util::ProtoOutputStream proto;
74 int histogramSize = 0;
75 for (const auto& bucket : buckets) {
76 if (++histogramSize > maxPulledHistogramBuckets) {
77 break;
78 }
79 proto.write(android::util::FIELD_TYPE_INT32 | android::util::FIELD_COUNT_REPEATED |
80 1 /* field id */,
81 (int32_t)bucket.first);
82 proto.write(android::util::FIELD_TYPE_INT64 | android::util::FIELD_COUNT_REPEATED |
83 2 /* field id */,
84 (int64_t)bucket.second);
85 }
86
87 std::string byteString;
88 proto.serializeToString(&byteString);
89 return byteString;
90}
91} // namespace
92
Alec Mouridfad9002020-02-12 17:49:09 -080093AStatsManager_PullAtomCallbackReturn TimeStats::populateGlobalAtom(AStatsEventList* data) {
94 std::lock_guard<std::mutex> lock(mMutex);
95
96 if (mTimeStats.statsStart == 0) {
97 return AStatsManager_PULL_SKIP;
98 }
99 flushPowerTimeLocked();
100
101 AStatsEvent* event = mStatsDelegate->addStatsEventToPullData(data);
102 mStatsDelegate->statsEventSetAtomId(event, android::util::SURFACEFLINGER_STATS_GLOBAL_INFO);
103 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.totalFrames);
104 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.missedFrames);
105 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.clientCompositionFrames);
106 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.displayOnTime);
107 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.presentToPresent.totalTime());
108 mStatsDelegate->statsEventWriteInt32(event, mTimeStats.displayEventConnectionsCount);
109 std::string frameDurationBytes =
110 histogramToProtoByteString(mTimeStats.frameDuration.hist, mMaxPulledHistogramBuckets);
111 mStatsDelegate->statsEventWriteByteArray(event, (const uint8_t*)frameDurationBytes.c_str(),
112 frameDurationBytes.size());
113 std::string renderEngineTimingBytes =
114 histogramToProtoByteString(mTimeStats.renderEngineTiming.hist,
115 mMaxPulledHistogramBuckets);
116 mStatsDelegate->statsEventWriteByteArray(event, (const uint8_t*)renderEngineTimingBytes.c_str(),
117 renderEngineTimingBytes.size());
118 mStatsDelegate->statsEventBuild(event);
119 clearGlobalLocked();
120
121 return AStatsManager_PULL_SUCCESS;
122}
123
Tej Singh2a457b62020-01-31 16:16:10 -0800124AStatsManager_PullAtomCallbackReturn TimeStats::populateLayerAtom(AStatsEventList* data) {
Alec Mouri37384342020-01-02 17:23:37 -0800125 std::lock_guard<std::mutex> lock(mMutex);
126
127 std::vector<TimeStatsHelper::TimeStatsLayer const*> dumpStats;
128 for (const auto& ele : mTimeStats.stats) {
129 dumpStats.push_back(&ele.second);
130 }
131
132 std::sort(dumpStats.begin(), dumpStats.end(),
133 [](TimeStatsHelper::TimeStatsLayer const* l,
134 TimeStatsHelper::TimeStatsLayer const* r) {
135 return l->totalFrames > r->totalFrames;
136 });
137
138 if (mMaxPulledLayers < dumpStats.size()) {
139 dumpStats.resize(mMaxPulledLayers);
140 }
141
142 for (const auto& layer : dumpStats) {
Tej Singh2a457b62020-01-31 16:16:10 -0800143 AStatsEvent* event = mStatsDelegate->addStatsEventToPullData(data);
Alec Mouri37384342020-01-02 17:23:37 -0800144 mStatsDelegate->statsEventSetAtomId(event, android::util::SURFACEFLINGER_STATS_LAYER_INFO);
145 mStatsDelegate->statsEventWriteString8(event, layer->layerName.c_str());
146 mStatsDelegate->statsEventWriteInt64(event, layer->totalFrames);
147 mStatsDelegate->statsEventWriteInt64(event, layer->droppedFrames);
148
149 for (const auto& name : kHistogramNames) {
150 const auto& histogram = layer->deltas.find(name);
151 if (histogram == layer->deltas.cend()) {
152 mStatsDelegate->statsEventWriteByteArray(event, nullptr, 0);
153 } else {
154 std::string bytes = histogramToProtoByteString(histogram->second.hist,
155 mMaxPulledHistogramBuckets);
156 mStatsDelegate->statsEventWriteByteArray(event, (const uint8_t*)bytes.c_str(),
157 bytes.size());
158 }
159 }
160
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -0800161 mStatsDelegate->statsEventWriteInt64(event, layer->lateAcquireFrames);
162 mStatsDelegate->statsEventWriteInt64(event, layer->badDesiredPresentFrames);
163
Alec Mouri37384342020-01-02 17:23:37 -0800164 mStatsDelegate->statsEventBuild(event);
165 }
166 clearLayersLocked();
167
Tej Singh2a457b62020-01-31 16:16:10 -0800168 return AStatsManager_PULL_SUCCESS;
Alec Mouri37384342020-01-02 17:23:37 -0800169}
170
171TimeStats::TimeStats() : TimeStats(nullptr, std::nullopt, std::nullopt) {}
172
173TimeStats::TimeStats(std::unique_ptr<StatsEventDelegate> statsDelegate,
174 std::optional<size_t> maxPulledLayers,
175 std::optional<size_t> maxPulledHistogramBuckets) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000176 if (statsDelegate != nullptr) {
177 mStatsDelegate = std::move(statsDelegate);
178 }
Alec Mouri37384342020-01-02 17:23:37 -0800179
180 if (maxPulledLayers) {
181 mMaxPulledLayers = *maxPulledLayers;
182 }
183
184 if (maxPulledHistogramBuckets) {
185 mMaxPulledHistogramBuckets = *maxPulledHistogramBuckets;
186 }
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000187}
188
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800189TimeStats::~TimeStats() {
190 std::lock_guard<std::mutex> lock(mMutex);
Tej Singh38a4b212020-03-13 19:04:51 -0700191 mStatsDelegate->clearStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO);
192 mStatsDelegate->clearStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO);
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800193}
194
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000195void TimeStats::onBootFinished() {
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800196 std::lock_guard<std::mutex> lock(mMutex);
Tej Singh38a4b212020-03-13 19:04:51 -0700197 mStatsDelegate->setStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
198 nullptr, TimeStats::pullAtomCallback, this);
199 mStatsDelegate->setStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
200 nullptr, TimeStats::pullAtomCallback, this);
Alec Mourib3885ad2019-09-06 17:08:55 -0700201}
202
Dominik Laskowskic2867142019-01-21 11:33:38 -0800203void TimeStats::parseArgs(bool asProto, const Vector<String16>& args, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700204 ATRACE_CALL();
205
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700206 std::unordered_map<std::string, int32_t> argsMap;
Dominik Laskowskic2867142019-01-21 11:33:38 -0800207 for (size_t index = 0; index < args.size(); ++index) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700208 argsMap[std::string(String8(args[index]).c_str())] = index;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700209 }
210
211 if (argsMap.count("-disable")) {
212 disable();
213 }
214
215 if (argsMap.count("-dump")) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700216 std::optional<uint32_t> maxLayers = std::nullopt;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700217 auto iter = argsMap.find("-maxlayers");
218 if (iter != argsMap.end() && iter->second + 1 < static_cast<int32_t>(args.size())) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700219 int64_t value = strtol(String8(args[iter->second + 1]).c_str(), nullptr, 10);
220 value = std::clamp(value, int64_t(0), int64_t(UINT32_MAX));
221 maxLayers = static_cast<uint32_t>(value);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700222 }
223
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700224 dump(asProto, maxLayers, result);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700225 }
226
227 if (argsMap.count("-clear")) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000228 clearAll();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700229 }
230
231 if (argsMap.count("-enable")) {
232 enable();
233 }
234}
235
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700236std::string TimeStats::miniDump() {
237 ATRACE_CALL();
238
239 std::string result = "TimeStats miniDump:\n";
240 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange926ab52019-08-14 15:16:00 -0700241 android::base::StringAppendF(&result, "Number of layers currently being tracked is %zu\n",
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700242 mTimeStatsTracker.size());
Yiwei Zhange926ab52019-08-14 15:16:00 -0700243 android::base::StringAppendF(&result, "Number of layers in the stats pool is %zu\n",
244 mTimeStats.stats.size());
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700245 return result;
246}
247
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700248void TimeStats::incrementTotalFrames() {
249 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.totalFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700255}
256
Yiwei Zhang621f9d42018-05-07 10:40:55 -0700257void TimeStats::incrementMissedFrames() {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700258 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.missedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700264}
265
266void TimeStats::incrementClientCompositionFrames() {
267 if (!mEnabled.load()) return;
268
269 ATRACE_CALL();
270
271 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700272 mTimeStats.clientCompositionFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700273}
274
Vishnu Nair9b079a22020-01-21 14:36:08 -0800275void TimeStats::incrementClientCompositionReusedFrames() {
276 if (!mEnabled.load()) return;
277
278 ATRACE_CALL();
279
280 std::lock_guard<std::mutex> lock(mMutex);
281 mTimeStats.clientCompositionReusedFrames++;
282}
283
Alec Mouri8de697e2020-03-19 10:52:01 -0700284void TimeStats::incrementRefreshRateSwitches() {
285 if (!mEnabled.load()) return;
286
287 ATRACE_CALL();
288
289 std::lock_guard<std::mutex> lock(mMutex);
290 mTimeStats.refreshRateSwitches++;
291}
292
Alec Mouri717bcb62020-02-10 17:07:19 -0800293void TimeStats::recordDisplayEventConnectionCount(int32_t count) {
294 if (!mEnabled.load()) return;
295
296 ATRACE_CALL();
297
298 std::lock_guard<std::mutex> lock(mMutex);
299 mTimeStats.displayEventConnectionsCount =
300 std::max(mTimeStats.displayEventConnectionsCount, count);
301}
302
Alec Mouri9519bf12019-11-15 16:54:44 -0800303static int32_t msBetween(nsecs_t start, nsecs_t end) {
304 int64_t delta = std::chrono::duration_cast<std::chrono::milliseconds>(
305 std::chrono::nanoseconds(end - start))
306 .count();
307 delta = std::clamp(delta, int64_t(INT32_MIN), int64_t(INT32_MAX));
308 return static_cast<int32_t>(delta);
309}
310
311void TimeStats::recordFrameDuration(nsecs_t startTime, nsecs_t endTime) {
312 if (!mEnabled.load()) return;
313
314 std::lock_guard<std::mutex> lock(mMutex);
315 if (mPowerTime.powerMode == HWC_POWER_MODE_NORMAL) {
316 mTimeStats.frameDuration.insert(msBetween(startTime, endTime));
317 }
318}
319
Alec Mourie4034bb2019-11-19 12:45:54 -0800320void TimeStats::recordRenderEngineDuration(nsecs_t startTime, nsecs_t endTime) {
321 if (!mEnabled.load()) return;
322
323 std::lock_guard<std::mutex> lock(mMutex);
324 if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
325 ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
326 mGlobalRecord.renderEngineDurations.pop_front();
327 }
328 mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
329}
330
331void TimeStats::recordRenderEngineDuration(nsecs_t startTime,
332 const std::shared_ptr<FenceTime>& endTime) {
333 if (!mEnabled.load()) return;
334
335 std::lock_guard<std::mutex> lock(mMutex);
336 if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
337 ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
338 mGlobalRecord.renderEngineDurations.pop_front();
339 }
340 mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
341}
342
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800343bool TimeStats::recordReadyLocked(int32_t layerId, TimeRecord* timeRecord) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700344 if (!timeRecord->ready) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800345 ALOGV("[%d]-[%" PRIu64 "]-presentFence is still not received", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700346 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700347 return false;
348 }
349
350 if (timeRecord->acquireFence != nullptr) {
351 if (timeRecord->acquireFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
352 return false;
353 }
354 if (timeRecord->acquireFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700355 timeRecord->frameTime.acquireTime = timeRecord->acquireFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700356 timeRecord->acquireFence = nullptr;
357 } else {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800358 ALOGV("[%d]-[%" PRIu64 "]-acquireFence signal time is invalid", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700359 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700360 }
361 }
362
363 if (timeRecord->presentFence != nullptr) {
364 if (timeRecord->presentFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
365 return false;
366 }
367 if (timeRecord->presentFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700368 timeRecord->frameTime.presentTime = timeRecord->presentFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700369 timeRecord->presentFence = nullptr;
370 } else {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800371 ALOGV("[%d]-[%" PRIu64 "]-presentFence signal time invalid", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700372 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700373 }
374 }
375
376 return true;
377}
378
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800379void TimeStats::flushAvailableRecordsToStatsLocked(int32_t layerId) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700380 ATRACE_CALL();
381
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800382 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700383 TimeRecord& prevTimeRecord = layerRecord.prevTimeRecord;
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700384 std::deque<TimeRecord>& timeRecords = layerRecord.timeRecords;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700385 while (!timeRecords.empty()) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800386 if (!recordReadyLocked(layerId, &timeRecords[0])) break;
387 ALOGV("[%d]-[%" PRIu64 "]-presentFenceTime[%" PRId64 "]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700388 timeRecords[0].frameTime.frameNumber, timeRecords[0].frameTime.presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700389
390 if (prevTimeRecord.ready) {
Yiwei Zhangeafa5cc2019-07-26 15:06:25 -0700391 const std::string& layerName = layerRecord.layerName;
Yiwei Zhangdc224042018-10-18 15:34:00 -0700392 if (!mTimeStats.stats.count(layerName)) {
393 mTimeStats.stats[layerName].layerName = layerName;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700394 }
Yiwei Zhangdc224042018-10-18 15:34:00 -0700395 TimeStatsHelper::TimeStatsLayer& timeStatsLayer = mTimeStats.stats[layerName];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700396 timeStatsLayer.totalFrames++;
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700397 timeStatsLayer.droppedFrames += layerRecord.droppedFrames;
Alec Mouri91f6df32020-01-30 08:48:58 -0800398 timeStatsLayer.lateAcquireFrames += layerRecord.lateAcquireFrames;
399 timeStatsLayer.badDesiredPresentFrames += layerRecord.badDesiredPresentFrames;
400
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700401 layerRecord.droppedFrames = 0;
Alec Mouri91f6df32020-01-30 08:48:58 -0800402 layerRecord.lateAcquireFrames = 0;
403 layerRecord.badDesiredPresentFrames = 0;
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700404
405 const int32_t postToAcquireMs = msBetween(timeRecords[0].frameTime.postTime,
406 timeRecords[0].frameTime.acquireTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800407 ALOGV("[%d]-[%" PRIu64 "]-post2acquire[%d]", layerId,
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700408 timeRecords[0].frameTime.frameNumber, postToAcquireMs);
409 timeStatsLayer.deltas["post2acquire"].insert(postToAcquireMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700410
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700411 const int32_t postToPresentMs = msBetween(timeRecords[0].frameTime.postTime,
412 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800413 ALOGV("[%d]-[%" PRIu64 "]-post2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700414 timeRecords[0].frameTime.frameNumber, postToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700415 timeStatsLayer.deltas["post2present"].insert(postToPresentMs);
416
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700417 const int32_t acquireToPresentMs = msBetween(timeRecords[0].frameTime.acquireTime,
418 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800419 ALOGV("[%d]-[%" PRIu64 "]-acquire2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700420 timeRecords[0].frameTime.frameNumber, acquireToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700421 timeStatsLayer.deltas["acquire2present"].insert(acquireToPresentMs);
422
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700423 const int32_t latchToPresentMs = msBetween(timeRecords[0].frameTime.latchTime,
424 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800425 ALOGV("[%d]-[%" PRIu64 "]-latch2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700426 timeRecords[0].frameTime.frameNumber, latchToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700427 timeStatsLayer.deltas["latch2present"].insert(latchToPresentMs);
428
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700429 const int32_t desiredToPresentMs = msBetween(timeRecords[0].frameTime.desiredTime,
430 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800431 ALOGV("[%d]-[%" PRIu64 "]-desired2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700432 timeRecords[0].frameTime.frameNumber, desiredToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700433 timeStatsLayer.deltas["desired2present"].insert(desiredToPresentMs);
434
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700435 const int32_t presentToPresentMs = msBetween(prevTimeRecord.frameTime.presentTime,
436 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800437 ALOGV("[%d]-[%" PRIu64 "]-present2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700438 timeRecords[0].frameTime.frameNumber, presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700439 timeStatsLayer.deltas["present2present"].insert(presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700440 }
441 prevTimeRecord = timeRecords[0];
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700442 timeRecords.pop_front();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700443 layerRecord.waitData--;
444 }
445}
446
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700447static constexpr const char* kPopupWindowPrefix = "PopupWindow";
448static const size_t kMinLenLayerName = std::strlen(kPopupWindowPrefix);
Yiwei Zhangbd408322018-10-15 18:31:53 -0700449
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700450// Avoid tracking the "PopupWindow:<random hash>#<number>" layers
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700451static bool layerNameIsValid(const std::string& layerName) {
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700452 return layerName.length() >= kMinLenLayerName &&
453 layerName.compare(0, kMinLenLayerName, kPopupWindowPrefix) != 0;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700454}
455
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800456void TimeStats::setPostTime(int32_t layerId, uint64_t frameNumber, const std::string& layerName,
Yiwei Zhang8e8fe522018-11-02 18:34:07 -0700457 nsecs_t postTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700458 if (!mEnabled.load()) return;
459
460 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800461 ALOGV("[%d]-[%" PRIu64 "]-[%s]-PostTime[%" PRId64 "]", layerId, frameNumber, layerName.c_str(),
Yiwei Zhang8e8fe522018-11-02 18:34:07 -0700462 postTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700463
464 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange926ab52019-08-14 15:16:00 -0700465 if (!mTimeStats.stats.count(layerName) && mTimeStats.stats.size() >= MAX_NUM_LAYER_STATS) {
466 return;
467 }
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800468 if (!mTimeStatsTracker.count(layerId) && mTimeStatsTracker.size() < MAX_NUM_LAYER_RECORDS &&
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700469 layerNameIsValid(layerName)) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800470 mTimeStatsTracker[layerId].layerName = layerName;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700471 }
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800472 if (!mTimeStatsTracker.count(layerId)) return;
473 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700474 if (layerRecord.timeRecords.size() == MAX_NUM_TIME_RECORDS) {
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800475 ALOGE("[%d]-[%s]-timeRecords is at its maximum size[%zu]. Ignore this when unittesting.",
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800476 layerId, layerRecord.layerName.c_str(), MAX_NUM_TIME_RECORDS);
477 mTimeStatsTracker.erase(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700478 return;
479 }
480 // For most media content, the acquireFence is invalid because the buffer is
481 // ready at the queueBuffer stage. In this case, acquireTime should be given
482 // a default value as postTime.
483 TimeRecord timeRecord = {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700484 .frameTime =
485 {
486 .frameNumber = frameNumber,
487 .postTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800488 .latchTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700489 .acquireTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800490 .desiredTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700491 },
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700492 };
493 layerRecord.timeRecords.push_back(timeRecord);
494 if (layerRecord.waitData < 0 ||
495 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
496 layerRecord.waitData = layerRecord.timeRecords.size() - 1;
497}
498
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800499void TimeStats::setLatchTime(int32_t layerId, uint64_t frameNumber, nsecs_t latchTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700500 if (!mEnabled.load()) return;
501
502 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800503 ALOGV("[%d]-[%" PRIu64 "]-LatchTime[%" PRId64 "]", layerId, frameNumber, latchTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700504
505 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800506 if (!mTimeStatsTracker.count(layerId)) return;
507 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700508 if (layerRecord.waitData < 0 ||
509 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
510 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700511 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700512 if (timeRecord.frameTime.frameNumber == frameNumber) {
513 timeRecord.frameTime.latchTime = latchTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700514 }
515}
516
Alec Mouri91f6df32020-01-30 08:48:58 -0800517void TimeStats::incrementLatchSkipped(int32_t layerId, LatchSkipReason reason) {
518 if (!mEnabled.load()) return;
519
520 ATRACE_CALL();
521 ALOGV("[%d]-LatchSkipped-Reason[%d]", layerId,
522 static_cast<std::underlying_type<LatchSkipReason>::type>(reason));
523
524 std::lock_guard<std::mutex> lock(mMutex);
525 if (!mTimeStatsTracker.count(layerId)) return;
526 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
527
528 switch (reason) {
529 case LatchSkipReason::LateAcquire:
530 layerRecord.lateAcquireFrames++;
531 break;
532 }
533}
534
535void TimeStats::incrementBadDesiredPresent(int32_t layerId) {
536 if (!mEnabled.load()) return;
537
538 ATRACE_CALL();
539 ALOGV("[%d]-BadDesiredPresent", layerId);
540
541 std::lock_guard<std::mutex> lock(mMutex);
542 if (!mTimeStatsTracker.count(layerId)) return;
543 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
544 layerRecord.badDesiredPresentFrames++;
545}
546
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800547void TimeStats::setDesiredTime(int32_t layerId, uint64_t frameNumber, nsecs_t desiredTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700548 if (!mEnabled.load()) return;
549
550 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800551 ALOGV("[%d]-[%" PRIu64 "]-DesiredTime[%" PRId64 "]", layerId, frameNumber, desiredTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700552
553 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800554 if (!mTimeStatsTracker.count(layerId)) return;
555 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700556 if (layerRecord.waitData < 0 ||
557 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
558 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700559 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700560 if (timeRecord.frameTime.frameNumber == frameNumber) {
561 timeRecord.frameTime.desiredTime = desiredTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700562 }
563}
564
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800565void TimeStats::setAcquireTime(int32_t layerId, uint64_t frameNumber, nsecs_t acquireTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700566 if (!mEnabled.load()) return;
567
568 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800569 ALOGV("[%d]-[%" PRIu64 "]-AcquireTime[%" PRId64 "]", layerId, frameNumber, acquireTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700570
571 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800572 if (!mTimeStatsTracker.count(layerId)) return;
573 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700574 if (layerRecord.waitData < 0 ||
575 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
576 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700577 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700578 if (timeRecord.frameTime.frameNumber == frameNumber) {
579 timeRecord.frameTime.acquireTime = acquireTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700580 }
581}
582
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800583void TimeStats::setAcquireFence(int32_t layerId, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700584 const std::shared_ptr<FenceTime>& acquireFence) {
585 if (!mEnabled.load()) return;
586
587 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800588 ALOGV("[%d]-[%" PRIu64 "]-AcquireFenceTime[%" PRId64 "]", layerId, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700589 acquireFence->getSignalTime());
590
591 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800592 if (!mTimeStatsTracker.count(layerId)) return;
593 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700594 if (layerRecord.waitData < 0 ||
595 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
596 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700597 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700598 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700599 timeRecord.acquireFence = acquireFence;
600 }
601}
602
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800603void TimeStats::setPresentTime(int32_t layerId, uint64_t frameNumber, nsecs_t presentTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700604 if (!mEnabled.load()) return;
605
606 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800607 ALOGV("[%d]-[%" PRIu64 "]-PresentTime[%" PRId64 "]", layerId, frameNumber, presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700608
609 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800610 if (!mTimeStatsTracker.count(layerId)) return;
611 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700612 if (layerRecord.waitData < 0 ||
613 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
614 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700615 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700616 if (timeRecord.frameTime.frameNumber == frameNumber) {
617 timeRecord.frameTime.presentTime = presentTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700618 timeRecord.ready = true;
619 layerRecord.waitData++;
620 }
621
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800622 flushAvailableRecordsToStatsLocked(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700623}
624
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800625void TimeStats::setPresentFence(int32_t layerId, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700626 const std::shared_ptr<FenceTime>& presentFence) {
627 if (!mEnabled.load()) return;
628
629 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800630 ALOGV("[%d]-[%" PRIu64 "]-PresentFenceTime[%" PRId64 "]", layerId, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700631 presentFence->getSignalTime());
632
633 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800634 if (!mTimeStatsTracker.count(layerId)) return;
635 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700636 if (layerRecord.waitData < 0 ||
637 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
638 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700639 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700640 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700641 timeRecord.presentFence = presentFence;
642 timeRecord.ready = true;
643 layerRecord.waitData++;
644 }
645
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800646 flushAvailableRecordsToStatsLocked(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700647}
648
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800649void TimeStats::onDestroy(int32_t layerId) {
Yiwei Zhangdc224042018-10-18 15:34:00 -0700650 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800651 ALOGV("[%d]-onDestroy", layerId);
Mikael Pessa90092f42019-08-26 17:22:04 -0700652 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800653 mTimeStatsTracker.erase(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700654}
655
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800656void TimeStats::removeTimeRecord(int32_t layerId, uint64_t frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700657 if (!mEnabled.load()) return;
658
659 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800660 ALOGV("[%d]-[%" PRIu64 "]-removeTimeRecord", layerId, frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700661
662 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800663 if (!mTimeStatsTracker.count(layerId)) return;
664 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700665 size_t removeAt = 0;
666 for (const TimeRecord& record : layerRecord.timeRecords) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700667 if (record.frameTime.frameNumber == frameNumber) break;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700668 removeAt++;
669 }
670 if (removeAt == layerRecord.timeRecords.size()) return;
671 layerRecord.timeRecords.erase(layerRecord.timeRecords.begin() + removeAt);
672 if (layerRecord.waitData > static_cast<int32_t>(removeAt)) {
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700673 layerRecord.waitData--;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700674 }
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700675 layerRecord.droppedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700676}
677
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700678void TimeStats::flushPowerTimeLocked() {
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700679 if (!mEnabled.load()) return;
680
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700681 nsecs_t curTime = systemTime();
682 // elapsedTime is in milliseconds.
683 int64_t elapsedTime = (curTime - mPowerTime.prevTime) / 1000000;
684
685 switch (mPowerTime.powerMode) {
686 case HWC_POWER_MODE_NORMAL:
687 mTimeStats.displayOnTime += elapsedTime;
688 break;
689 case HWC_POWER_MODE_OFF:
690 case HWC_POWER_MODE_DOZE:
691 case HWC_POWER_MODE_DOZE_SUSPEND:
692 default:
693 break;
694 }
695
696 mPowerTime.prevTime = curTime;
697}
698
699void TimeStats::setPowerMode(int32_t powerMode) {
700 if (!mEnabled.load()) {
701 std::lock_guard<std::mutex> lock(mMutex);
702 mPowerTime.powerMode = powerMode;
703 return;
704 }
705
706 std::lock_guard<std::mutex> lock(mMutex);
707 if (powerMode == mPowerTime.powerMode) return;
708
709 flushPowerTimeLocked();
710 mPowerTime.powerMode = powerMode;
711}
712
Alec Mourifb571ea2019-01-24 18:42:10 -0800713void TimeStats::recordRefreshRate(uint32_t fps, nsecs_t duration) {
714 std::lock_guard<std::mutex> lock(mMutex);
715 if (mTimeStats.refreshRateStats.count(fps)) {
716 mTimeStats.refreshRateStats[fps] += duration;
717 } else {
718 mTimeStats.refreshRateStats.insert({fps, duration});
719 }
720}
721
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700722void TimeStats::flushAvailableGlobalRecordsToStatsLocked() {
723 ATRACE_CALL();
724
725 while (!mGlobalRecord.presentFences.empty()) {
726 const nsecs_t curPresentTime = mGlobalRecord.presentFences.front()->getSignalTime();
727 if (curPresentTime == Fence::SIGNAL_TIME_PENDING) break;
728
729 if (curPresentTime == Fence::SIGNAL_TIME_INVALID) {
730 ALOGE("GlobalPresentFence is invalid!");
731 mGlobalRecord.prevPresentTime = 0;
732 mGlobalRecord.presentFences.pop_front();
733 continue;
734 }
735
736 ALOGV("GlobalPresentFenceTime[%" PRId64 "]",
737 mGlobalRecord.presentFences.front()->getSignalTime());
738
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700739 if (mGlobalRecord.prevPresentTime != 0) {
740 const int32_t presentToPresentMs =
741 msBetween(mGlobalRecord.prevPresentTime, curPresentTime);
742 ALOGV("Global present2present[%d] prev[%" PRId64 "] curr[%" PRId64 "]",
743 presentToPresentMs, mGlobalRecord.prevPresentTime, curPresentTime);
744 mTimeStats.presentToPresent.insert(presentToPresentMs);
745 }
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700746
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700747 mGlobalRecord.prevPresentTime = curPresentTime;
748 mGlobalRecord.presentFences.pop_front();
749 }
Alec Mourie4034bb2019-11-19 12:45:54 -0800750 while (!mGlobalRecord.renderEngineDurations.empty()) {
751 const auto duration = mGlobalRecord.renderEngineDurations.front();
752 const auto& endTime = duration.endTime;
753
754 nsecs_t endNs = -1;
755
756 if (auto val = std::get_if<nsecs_t>(&endTime)) {
757 endNs = *val;
758 } else {
759 endNs = std::get<std::shared_ptr<FenceTime>>(endTime)->getSignalTime();
760 }
761
762 if (endNs == Fence::SIGNAL_TIME_PENDING) break;
763
764 if (endNs < 0) {
765 ALOGE("RenderEngineTiming is invalid!");
766 mGlobalRecord.renderEngineDurations.pop_front();
767 continue;
768 }
769
770 const int32_t renderEngineMs = msBetween(duration.startTime, endNs);
771 mTimeStats.renderEngineTiming.insert(renderEngineMs);
772
773 mGlobalRecord.renderEngineDurations.pop_front();
774 }
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700775}
776
777void TimeStats::setPresentFenceGlobal(const std::shared_ptr<FenceTime>& presentFence) {
778 if (!mEnabled.load()) return;
779
780 ATRACE_CALL();
781 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700782 if (presentFence == nullptr || !presentFence->isValid()) {
783 mGlobalRecord.prevPresentTime = 0;
784 return;
785 }
786
787 if (mPowerTime.powerMode != HWC_POWER_MODE_NORMAL) {
788 // Try flushing the last present fence on HWC_POWER_MODE_NORMAL.
789 flushAvailableGlobalRecordsToStatsLocked();
790 mGlobalRecord.presentFences.clear();
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700791 mGlobalRecord.prevPresentTime = 0;
792 return;
793 }
794
795 if (mGlobalRecord.presentFences.size() == MAX_NUM_TIME_RECORDS) {
796 // The front presentFence must be trapped in pending status in this
797 // case. Try dequeuing the front one to recover.
798 ALOGE("GlobalPresentFences is already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
799 mGlobalRecord.prevPresentTime = 0;
800 mGlobalRecord.presentFences.pop_front();
801 }
802
803 mGlobalRecord.presentFences.emplace_back(presentFence);
804 flushAvailableGlobalRecordsToStatsLocked();
805}
806
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700807void TimeStats::enable() {
808 if (mEnabled.load()) return;
809
810 ATRACE_CALL();
811
812 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700813 mEnabled.store(true);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700814 mTimeStats.statsStart = static_cast<int64_t>(std::time(0));
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700815 mPowerTime.prevTime = systemTime();
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700816 ALOGD("Enabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700817}
818
819void TimeStats::disable() {
820 if (!mEnabled.load()) return;
821
822 ATRACE_CALL();
823
824 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700825 flushPowerTimeLocked();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700826 mEnabled.store(false);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700827 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700828 ALOGD("Disabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700829}
830
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000831void TimeStats::clearAll() {
832 std::lock_guard<std::mutex> lock(mMutex);
833 clearGlobalLocked();
834 clearLayersLocked();
835}
836
837void TimeStats::clearGlobalLocked() {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700838 ATRACE_CALL();
839
Yiwei Zhangdc224042018-10-18 15:34:00 -0700840 mTimeStats.statsStart = (mEnabled.load() ? static_cast<int64_t>(std::time(0)) : 0);
841 mTimeStats.statsEnd = 0;
842 mTimeStats.totalFrames = 0;
843 mTimeStats.missedFrames = 0;
844 mTimeStats.clientCompositionFrames = 0;
Vishnu Nair9b079a22020-01-21 14:36:08 -0800845 mTimeStats.clientCompositionReusedFrames = 0;
Alec Mouri8de697e2020-03-19 10:52:01 -0700846 mTimeStats.refreshRateSwitches = 0;
Alec Mouri717bcb62020-02-10 17:07:19 -0800847 mTimeStats.displayEventConnectionsCount = 0;
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700848 mTimeStats.displayOnTime = 0;
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700849 mTimeStats.presentToPresent.hist.clear();
Alec Mouri31ac64a2020-01-09 09:26:22 -0800850 mTimeStats.frameDuration.hist.clear();
851 mTimeStats.renderEngineTiming.hist.clear();
Alec Mourifb571ea2019-01-24 18:42:10 -0800852 mTimeStats.refreshRateStats.clear();
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700853 mPowerTime.prevTime = systemTime();
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700854 mGlobalRecord.prevPresentTime = 0;
855 mGlobalRecord.presentFences.clear();
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000856 ALOGD("Cleared global stats");
857}
858
859void TimeStats::clearLayersLocked() {
860 ATRACE_CALL();
861
862 mTimeStatsTracker.clear();
863 mTimeStats.stats.clear();
864 ALOGD("Cleared layer stats");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700865}
866
867bool TimeStats::isEnabled() {
868 return mEnabled.load();
869}
870
Yiwei Zhang5434a782018-12-05 18:06:32 -0800871void TimeStats::dump(bool asProto, std::optional<uint32_t> maxLayers, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700872 ATRACE_CALL();
873
874 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700875 if (mTimeStats.statsStart == 0) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700876 return;
877 }
878
Yiwei Zhangdc224042018-10-18 15:34:00 -0700879 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700880
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700881 flushPowerTimeLocked();
882
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700883 if (asProto) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700884 ALOGD("Dumping TimeStats as proto");
Yiwei Zhangdc224042018-10-18 15:34:00 -0700885 SFTimeStatsGlobalProto timeStatsProto = mTimeStats.toProto(maxLayers);
Dominik Laskowski46470112019-08-02 13:13:11 -0700886 result.append(timeStatsProto.SerializeAsString());
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700887 } else {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700888 ALOGD("Dumping TimeStats as text");
Yiwei Zhang5434a782018-12-05 18:06:32 -0800889 result.append(mTimeStats.toString(maxLayers));
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700890 result.append("\n");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700891 }
892}
893
Alec Mourifb571ea2019-01-24 18:42:10 -0800894} // namespace impl
895
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700896} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -0800897
898// TODO(b/129481165): remove the #pragma below and fix conversion issues
899#pragma clang diagnostic pop // ignored "-Wconversion"