blob: bed2471cd028d3c99d378d10b991bfdcfb2e1b4d [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
Alec Mouri37384342020-01-02 17:23:37 -080040status_pull_atom_return_t TimeStats::pullAtomCallback(int32_t atom_tag,
41 pulled_stats_event_list* data, void* cookie) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +000042 impl::TimeStats* timeStats = reinterpret_cast<impl::TimeStats*>(cookie);
Alec Mouri37384342020-01-02 17:23:37 -080043 if (atom_tag == android::util::SURFACEFLINGER_STATS_GLOBAL_INFO) {
44 return timeStats->populateGlobalAtom(data);
45 } else if (atom_tag == android::util::SURFACEFLINGER_STATS_LAYER_INFO) {
46 return timeStats->populateLayerAtom(data);
Alec Mouri8e2f31b2020-01-16 22:04:35 +000047 }
48
Alec Mouri37384342020-01-02 17:23:37 -080049 return STATS_PULL_SKIP;
50}
Alec Mouri8e2f31b2020-01-16 22:04:35 +000051
Alec Mouri37384342020-01-02 17:23:37 -080052status_pull_atom_return_t TimeStats::populateGlobalAtom(pulled_stats_event_list* data) {
53 std::lock_guard<std::mutex> lock(mMutex);
54
55 if (mTimeStats.statsStart == 0) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +000056 return STATS_PULL_SKIP;
57 }
Alec Mouri37384342020-01-02 17:23:37 -080058 flushPowerTimeLocked();
Alec Mouri8e2f31b2020-01-16 22:04:35 +000059
Alec Mouri37384342020-01-02 17:23:37 -080060 struct stats_event* event = mStatsDelegate->addStatsEventToPullData(data);
61 mStatsDelegate->statsEventSetAtomId(event, android::util::SURFACEFLINGER_STATS_GLOBAL_INFO);
62 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.totalFrames);
63 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.missedFrames);
64 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.clientCompositionFrames);
65 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.displayOnTime);
66 mStatsDelegate->statsEventWriteInt64(event, mTimeStats.presentToPresent.totalTime());
67 mStatsDelegate->statsEventBuild(event);
68 clearGlobalLocked();
Alec Mouri8e2f31b2020-01-16 22:04:35 +000069
70 return STATS_PULL_SUCCESS;
71}
72
Alec Mouri37384342020-01-02 17:23:37 -080073namespace {
74// Histograms align with the order of fields in SurfaceflingerStatsLayerInfo.
75const std::array<std::string, 6> kHistogramNames = {
76 "present2present", "post2present", "acquire2present",
77 "latch2present", "desired2present", "post2acquire",
78};
Alec Mouri8e2f31b2020-01-16 22:04:35 +000079
Alec Mouri37384342020-01-02 17:23:37 -080080std::string histogramToProtoByteString(const std::unordered_map<int32_t, int32_t>& histogram,
81 size_t maxPulledHistogramBuckets) {
82 auto buckets = std::vector<std::pair<int32_t, int32_t>>(histogram.begin(), histogram.end());
83 std::sort(buckets.begin(), buckets.end(),
84 [](std::pair<int32_t, int32_t>& left, std::pair<int32_t, int32_t>& right) {
85 return left.second > right.second;
86 });
87
88 util::ProtoOutputStream proto;
89 int histogramSize = 0;
90 for (const auto& bucket : buckets) {
91 if (++histogramSize > maxPulledHistogramBuckets) {
92 break;
93 }
94 proto.write(android::util::FIELD_TYPE_INT32 | android::util::FIELD_COUNT_REPEATED |
95 1 /* field id */,
96 (int32_t)bucket.first);
97 proto.write(android::util::FIELD_TYPE_INT64 | android::util::FIELD_COUNT_REPEATED |
98 2 /* field id */,
99 (int64_t)bucket.second);
100 }
101
102 std::string byteString;
103 proto.serializeToString(&byteString);
104 return byteString;
105}
106} // namespace
107
108status_pull_atom_return_t TimeStats::populateLayerAtom(pulled_stats_event_list* data) {
109 std::lock_guard<std::mutex> lock(mMutex);
110
111 std::vector<TimeStatsHelper::TimeStatsLayer const*> dumpStats;
112 for (const auto& ele : mTimeStats.stats) {
113 dumpStats.push_back(&ele.second);
114 }
115
116 std::sort(dumpStats.begin(), dumpStats.end(),
117 [](TimeStatsHelper::TimeStatsLayer const* l,
118 TimeStatsHelper::TimeStatsLayer const* r) {
119 return l->totalFrames > r->totalFrames;
120 });
121
122 if (mMaxPulledLayers < dumpStats.size()) {
123 dumpStats.resize(mMaxPulledLayers);
124 }
125
126 for (const auto& layer : dumpStats) {
127 struct stats_event* event = mStatsDelegate->addStatsEventToPullData(data);
128 mStatsDelegate->statsEventSetAtomId(event, android::util::SURFACEFLINGER_STATS_LAYER_INFO);
129 mStatsDelegate->statsEventWriteString8(event, layer->layerName.c_str());
130 mStatsDelegate->statsEventWriteInt64(event, layer->totalFrames);
131 mStatsDelegate->statsEventWriteInt64(event, layer->droppedFrames);
132
133 for (const auto& name : kHistogramNames) {
134 const auto& histogram = layer->deltas.find(name);
135 if (histogram == layer->deltas.cend()) {
136 mStatsDelegate->statsEventWriteByteArray(event, nullptr, 0);
137 } else {
138 std::string bytes = histogramToProtoByteString(histogram->second.hist,
139 mMaxPulledHistogramBuckets);
140 mStatsDelegate->statsEventWriteByteArray(event, (const uint8_t*)bytes.c_str(),
141 bytes.size());
142 }
143 }
144
145 mStatsDelegate->statsEventBuild(event);
146 }
147 clearLayersLocked();
148
149 return STATS_PULL_SUCCESS;
150}
151
152TimeStats::TimeStats() : TimeStats(nullptr, std::nullopt, std::nullopt) {}
153
154TimeStats::TimeStats(std::unique_ptr<StatsEventDelegate> statsDelegate,
155 std::optional<size_t> maxPulledLayers,
156 std::optional<size_t> maxPulledHistogramBuckets) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000157 if (statsDelegate != nullptr) {
158 mStatsDelegate = std::move(statsDelegate);
159 }
Alec Mouri37384342020-01-02 17:23:37 -0800160
161 if (maxPulledLayers) {
162 mMaxPulledLayers = *maxPulledLayers;
163 }
164
165 if (maxPulledHistogramBuckets) {
166 mMaxPulledHistogramBuckets = *maxPulledHistogramBuckets;
167 }
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000168}
169
170void TimeStats::onBootFinished() {
Alec Mourib3885ad2019-09-06 17:08:55 -0700171 // Temporarily enable TimeStats by default. Telemetry is disabled while
172 // we move onto statsd, so TimeStats is currently not exercised at all
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000173 // during testing without enabling by default.
174 // TODO: remove this, as we should only be paying this overhead on devices
175 // where statsd exists.
Alec Mourib3885ad2019-09-06 17:08:55 -0700176 enable();
177}
178
Dominik Laskowskic2867142019-01-21 11:33:38 -0800179void TimeStats::parseArgs(bool asProto, const Vector<String16>& args, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700180 ATRACE_CALL();
181
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700182 std::unordered_map<std::string, int32_t> argsMap;
Dominik Laskowskic2867142019-01-21 11:33:38 -0800183 for (size_t index = 0; index < args.size(); ++index) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700184 argsMap[std::string(String8(args[index]).c_str())] = index;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700185 }
186
187 if (argsMap.count("-disable")) {
188 disable();
189 }
190
191 if (argsMap.count("-dump")) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700192 std::optional<uint32_t> maxLayers = std::nullopt;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700193 auto iter = argsMap.find("-maxlayers");
194 if (iter != argsMap.end() && iter->second + 1 < static_cast<int32_t>(args.size())) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700195 int64_t value = strtol(String8(args[iter->second + 1]).c_str(), nullptr, 10);
196 value = std::clamp(value, int64_t(0), int64_t(UINT32_MAX));
197 maxLayers = static_cast<uint32_t>(value);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700198 }
199
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700200 dump(asProto, maxLayers, result);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700201 }
202
203 if (argsMap.count("-clear")) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000204 clearAll();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700205 }
206
207 if (argsMap.count("-enable")) {
208 enable();
209 }
210}
211
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700212std::string TimeStats::miniDump() {
213 ATRACE_CALL();
214
215 std::string result = "TimeStats miniDump:\n";
216 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange926ab52019-08-14 15:16:00 -0700217 android::base::StringAppendF(&result, "Number of layers currently being tracked is %zu\n",
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700218 mTimeStatsTracker.size());
Yiwei Zhange926ab52019-08-14 15:16:00 -0700219 android::base::StringAppendF(&result, "Number of layers in the stats pool is %zu\n",
220 mTimeStats.stats.size());
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700221 return result;
222}
223
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700224void TimeStats::incrementTotalFrames() {
225 if (!mEnabled.load()) return;
226
227 ATRACE_CALL();
228
229 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700230 mTimeStats.totalFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700231}
232
Yiwei Zhang621f9d42018-05-07 10:40:55 -0700233void TimeStats::incrementMissedFrames() {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700234 if (!mEnabled.load()) return;
235
236 ATRACE_CALL();
237
238 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700239 mTimeStats.missedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700240}
241
242void TimeStats::incrementClientCompositionFrames() {
243 if (!mEnabled.load()) return;
244
245 ATRACE_CALL();
246
247 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700248 mTimeStats.clientCompositionFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700249}
250
Vishnu Nair9b079a22020-01-21 14:36:08 -0800251void TimeStats::incrementClientCompositionReusedFrames() {
252 if (!mEnabled.load()) return;
253
254 ATRACE_CALL();
255
256 std::lock_guard<std::mutex> lock(mMutex);
257 mTimeStats.clientCompositionReusedFrames++;
258}
259
Alec Mouri9519bf12019-11-15 16:54:44 -0800260static int32_t msBetween(nsecs_t start, nsecs_t end) {
261 int64_t delta = std::chrono::duration_cast<std::chrono::milliseconds>(
262 std::chrono::nanoseconds(end - start))
263 .count();
264 delta = std::clamp(delta, int64_t(INT32_MIN), int64_t(INT32_MAX));
265 return static_cast<int32_t>(delta);
266}
267
268void TimeStats::recordFrameDuration(nsecs_t startTime, nsecs_t endTime) {
269 if (!mEnabled.load()) return;
270
271 std::lock_guard<std::mutex> lock(mMutex);
272 if (mPowerTime.powerMode == HWC_POWER_MODE_NORMAL) {
273 mTimeStats.frameDuration.insert(msBetween(startTime, endTime));
274 }
275}
276
Alec Mourie4034bb2019-11-19 12:45:54 -0800277void TimeStats::recordRenderEngineDuration(nsecs_t startTime, nsecs_t endTime) {
278 if (!mEnabled.load()) return;
279
280 std::lock_guard<std::mutex> lock(mMutex);
281 if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
282 ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
283 mGlobalRecord.renderEngineDurations.pop_front();
284 }
285 mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
286}
287
288void TimeStats::recordRenderEngineDuration(nsecs_t startTime,
289 const std::shared_ptr<FenceTime>& endTime) {
290 if (!mEnabled.load()) return;
291
292 std::lock_guard<std::mutex> lock(mMutex);
293 if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
294 ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
295 mGlobalRecord.renderEngineDurations.pop_front();
296 }
297 mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
298}
299
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800300bool TimeStats::recordReadyLocked(int32_t layerId, TimeRecord* timeRecord) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700301 if (!timeRecord->ready) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800302 ALOGV("[%d]-[%" PRIu64 "]-presentFence is still not received", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700303 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700304 return false;
305 }
306
307 if (timeRecord->acquireFence != nullptr) {
308 if (timeRecord->acquireFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
309 return false;
310 }
311 if (timeRecord->acquireFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700312 timeRecord->frameTime.acquireTime = timeRecord->acquireFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700313 timeRecord->acquireFence = nullptr;
314 } else {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800315 ALOGV("[%d]-[%" PRIu64 "]-acquireFence signal time is invalid", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700316 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700317 }
318 }
319
320 if (timeRecord->presentFence != nullptr) {
321 if (timeRecord->presentFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
322 return false;
323 }
324 if (timeRecord->presentFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700325 timeRecord->frameTime.presentTime = timeRecord->presentFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700326 timeRecord->presentFence = nullptr;
327 } else {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800328 ALOGV("[%d]-[%" PRIu64 "]-presentFence signal time invalid", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700329 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700330 }
331 }
332
333 return true;
334}
335
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800336void TimeStats::flushAvailableRecordsToStatsLocked(int32_t layerId) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700337 ATRACE_CALL();
338
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800339 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700340 TimeRecord& prevTimeRecord = layerRecord.prevTimeRecord;
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700341 std::deque<TimeRecord>& timeRecords = layerRecord.timeRecords;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700342 while (!timeRecords.empty()) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800343 if (!recordReadyLocked(layerId, &timeRecords[0])) break;
344 ALOGV("[%d]-[%" PRIu64 "]-presentFenceTime[%" PRId64 "]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700345 timeRecords[0].frameTime.frameNumber, timeRecords[0].frameTime.presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700346
347 if (prevTimeRecord.ready) {
Yiwei Zhangeafa5cc2019-07-26 15:06:25 -0700348 const std::string& layerName = layerRecord.layerName;
Yiwei Zhangdc224042018-10-18 15:34:00 -0700349 if (!mTimeStats.stats.count(layerName)) {
350 mTimeStats.stats[layerName].layerName = layerName;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700351 }
Yiwei Zhangdc224042018-10-18 15:34:00 -0700352 TimeStatsHelper::TimeStatsLayer& timeStatsLayer = mTimeStats.stats[layerName];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700353 timeStatsLayer.totalFrames++;
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700354 timeStatsLayer.droppedFrames += layerRecord.droppedFrames;
Alec Mouri91f6df32020-01-30 08:48:58 -0800355 timeStatsLayer.lateAcquireFrames += layerRecord.lateAcquireFrames;
356 timeStatsLayer.badDesiredPresentFrames += layerRecord.badDesiredPresentFrames;
357
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700358 layerRecord.droppedFrames = 0;
Alec Mouri91f6df32020-01-30 08:48:58 -0800359 layerRecord.lateAcquireFrames = 0;
360 layerRecord.badDesiredPresentFrames = 0;
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700361
362 const int32_t postToAcquireMs = msBetween(timeRecords[0].frameTime.postTime,
363 timeRecords[0].frameTime.acquireTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800364 ALOGV("[%d]-[%" PRIu64 "]-post2acquire[%d]", layerId,
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700365 timeRecords[0].frameTime.frameNumber, postToAcquireMs);
366 timeStatsLayer.deltas["post2acquire"].insert(postToAcquireMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700367
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700368 const int32_t postToPresentMs = msBetween(timeRecords[0].frameTime.postTime,
369 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800370 ALOGV("[%d]-[%" PRIu64 "]-post2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700371 timeRecords[0].frameTime.frameNumber, postToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700372 timeStatsLayer.deltas["post2present"].insert(postToPresentMs);
373
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700374 const int32_t acquireToPresentMs = msBetween(timeRecords[0].frameTime.acquireTime,
375 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800376 ALOGV("[%d]-[%" PRIu64 "]-acquire2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700377 timeRecords[0].frameTime.frameNumber, acquireToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700378 timeStatsLayer.deltas["acquire2present"].insert(acquireToPresentMs);
379
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700380 const int32_t latchToPresentMs = msBetween(timeRecords[0].frameTime.latchTime,
381 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800382 ALOGV("[%d]-[%" PRIu64 "]-latch2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700383 timeRecords[0].frameTime.frameNumber, latchToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700384 timeStatsLayer.deltas["latch2present"].insert(latchToPresentMs);
385
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700386 const int32_t desiredToPresentMs = msBetween(timeRecords[0].frameTime.desiredTime,
387 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800388 ALOGV("[%d]-[%" PRIu64 "]-desired2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700389 timeRecords[0].frameTime.frameNumber, desiredToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700390 timeStatsLayer.deltas["desired2present"].insert(desiredToPresentMs);
391
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700392 const int32_t presentToPresentMs = msBetween(prevTimeRecord.frameTime.presentTime,
393 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800394 ALOGV("[%d]-[%" PRIu64 "]-present2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700395 timeRecords[0].frameTime.frameNumber, presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700396 timeStatsLayer.deltas["present2present"].insert(presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700397 }
398 prevTimeRecord = timeRecords[0];
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700399 timeRecords.pop_front();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700400 layerRecord.waitData--;
401 }
402}
403
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700404static constexpr const char* kPopupWindowPrefix = "PopupWindow";
405static const size_t kMinLenLayerName = std::strlen(kPopupWindowPrefix);
Yiwei Zhangbd408322018-10-15 18:31:53 -0700406
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700407// Avoid tracking the "PopupWindow:<random hash>#<number>" layers
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700408static bool layerNameIsValid(const std::string& layerName) {
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700409 return layerName.length() >= kMinLenLayerName &&
410 layerName.compare(0, kMinLenLayerName, kPopupWindowPrefix) != 0;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700411}
412
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800413void TimeStats::setPostTime(int32_t layerId, uint64_t frameNumber, const std::string& layerName,
Yiwei Zhang8e8fe522018-11-02 18:34:07 -0700414 nsecs_t postTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700415 if (!mEnabled.load()) return;
416
417 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800418 ALOGV("[%d]-[%" PRIu64 "]-[%s]-PostTime[%" PRId64 "]", layerId, frameNumber, layerName.c_str(),
Yiwei Zhang8e8fe522018-11-02 18:34:07 -0700419 postTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700420
421 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange926ab52019-08-14 15:16:00 -0700422 if (!mTimeStats.stats.count(layerName) && mTimeStats.stats.size() >= MAX_NUM_LAYER_STATS) {
423 return;
424 }
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800425 if (!mTimeStatsTracker.count(layerId) && mTimeStatsTracker.size() < MAX_NUM_LAYER_RECORDS &&
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700426 layerNameIsValid(layerName)) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800427 mTimeStatsTracker[layerId].layerName = layerName;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700428 }
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800429 if (!mTimeStatsTracker.count(layerId)) return;
430 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700431 if (layerRecord.timeRecords.size() == MAX_NUM_TIME_RECORDS) {
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800432 ALOGE("[%d]-[%s]-timeRecords is at its maximum size[%zu]. Ignore this when unittesting.",
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800433 layerId, layerRecord.layerName.c_str(), MAX_NUM_TIME_RECORDS);
434 mTimeStatsTracker.erase(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700435 return;
436 }
437 // For most media content, the acquireFence is invalid because the buffer is
438 // ready at the queueBuffer stage. In this case, acquireTime should be given
439 // a default value as postTime.
440 TimeRecord timeRecord = {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700441 .frameTime =
442 {
443 .frameNumber = frameNumber,
444 .postTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800445 .latchTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700446 .acquireTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800447 .desiredTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700448 },
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700449 };
450 layerRecord.timeRecords.push_back(timeRecord);
451 if (layerRecord.waitData < 0 ||
452 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
453 layerRecord.waitData = layerRecord.timeRecords.size() - 1;
454}
455
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800456void TimeStats::setLatchTime(int32_t layerId, uint64_t frameNumber, nsecs_t latchTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700457 if (!mEnabled.load()) return;
458
459 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800460 ALOGV("[%d]-[%" PRIu64 "]-LatchTime[%" PRId64 "]", layerId, frameNumber, latchTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700461
462 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800463 if (!mTimeStatsTracker.count(layerId)) return;
464 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700465 if (layerRecord.waitData < 0 ||
466 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
467 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700468 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700469 if (timeRecord.frameTime.frameNumber == frameNumber) {
470 timeRecord.frameTime.latchTime = latchTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700471 }
472}
473
Alec Mouri91f6df32020-01-30 08:48:58 -0800474void TimeStats::incrementLatchSkipped(int32_t layerId, LatchSkipReason reason) {
475 if (!mEnabled.load()) return;
476
477 ATRACE_CALL();
478 ALOGV("[%d]-LatchSkipped-Reason[%d]", layerId,
479 static_cast<std::underlying_type<LatchSkipReason>::type>(reason));
480
481 std::lock_guard<std::mutex> lock(mMutex);
482 if (!mTimeStatsTracker.count(layerId)) return;
483 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
484
485 switch (reason) {
486 case LatchSkipReason::LateAcquire:
487 layerRecord.lateAcquireFrames++;
488 break;
489 }
490}
491
492void TimeStats::incrementBadDesiredPresent(int32_t layerId) {
493 if (!mEnabled.load()) return;
494
495 ATRACE_CALL();
496 ALOGV("[%d]-BadDesiredPresent", layerId);
497
498 std::lock_guard<std::mutex> lock(mMutex);
499 if (!mTimeStatsTracker.count(layerId)) return;
500 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
501 layerRecord.badDesiredPresentFrames++;
502}
503
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800504void TimeStats::setDesiredTime(int32_t layerId, uint64_t frameNumber, nsecs_t desiredTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700505 if (!mEnabled.load()) return;
506
507 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800508 ALOGV("[%d]-[%" PRIu64 "]-DesiredTime[%" PRId64 "]", layerId, frameNumber, desiredTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700509
510 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800511 if (!mTimeStatsTracker.count(layerId)) return;
512 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700513 if (layerRecord.waitData < 0 ||
514 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
515 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700516 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700517 if (timeRecord.frameTime.frameNumber == frameNumber) {
518 timeRecord.frameTime.desiredTime = desiredTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700519 }
520}
521
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800522void TimeStats::setAcquireTime(int32_t layerId, uint64_t frameNumber, nsecs_t acquireTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700523 if (!mEnabled.load()) return;
524
525 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800526 ALOGV("[%d]-[%" PRIu64 "]-AcquireTime[%" PRId64 "]", layerId, frameNumber, acquireTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700527
528 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800529 if (!mTimeStatsTracker.count(layerId)) return;
530 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700531 if (layerRecord.waitData < 0 ||
532 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
533 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700534 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700535 if (timeRecord.frameTime.frameNumber == frameNumber) {
536 timeRecord.frameTime.acquireTime = acquireTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700537 }
538}
539
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800540void TimeStats::setAcquireFence(int32_t layerId, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700541 const std::shared_ptr<FenceTime>& acquireFence) {
542 if (!mEnabled.load()) return;
543
544 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800545 ALOGV("[%d]-[%" PRIu64 "]-AcquireFenceTime[%" PRId64 "]", layerId, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700546 acquireFence->getSignalTime());
547
548 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800549 if (!mTimeStatsTracker.count(layerId)) return;
550 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700551 if (layerRecord.waitData < 0 ||
552 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
553 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700554 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700555 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700556 timeRecord.acquireFence = acquireFence;
557 }
558}
559
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800560void TimeStats::setPresentTime(int32_t layerId, uint64_t frameNumber, nsecs_t presentTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700561 if (!mEnabled.load()) return;
562
563 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800564 ALOGV("[%d]-[%" PRIu64 "]-PresentTime[%" PRId64 "]", layerId, frameNumber, presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700565
566 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800567 if (!mTimeStatsTracker.count(layerId)) return;
568 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700569 if (layerRecord.waitData < 0 ||
570 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
571 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700572 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700573 if (timeRecord.frameTime.frameNumber == frameNumber) {
574 timeRecord.frameTime.presentTime = presentTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700575 timeRecord.ready = true;
576 layerRecord.waitData++;
577 }
578
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800579 flushAvailableRecordsToStatsLocked(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700580}
581
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800582void TimeStats::setPresentFence(int32_t layerId, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700583 const std::shared_ptr<FenceTime>& presentFence) {
584 if (!mEnabled.load()) return;
585
586 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800587 ALOGV("[%d]-[%" PRIu64 "]-PresentFenceTime[%" PRId64 "]", layerId, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700588 presentFence->getSignalTime());
589
590 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800591 if (!mTimeStatsTracker.count(layerId)) return;
592 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700593 if (layerRecord.waitData < 0 ||
594 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
595 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700596 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700597 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700598 timeRecord.presentFence = presentFence;
599 timeRecord.ready = true;
600 layerRecord.waitData++;
601 }
602
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800603 flushAvailableRecordsToStatsLocked(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700604}
605
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800606void TimeStats::onDestroy(int32_t layerId) {
Yiwei Zhangdc224042018-10-18 15:34:00 -0700607 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800608 ALOGV("[%d]-onDestroy", layerId);
Mikael Pessa90092f42019-08-26 17:22:04 -0700609 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800610 mTimeStatsTracker.erase(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700611}
612
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800613void TimeStats::removeTimeRecord(int32_t layerId, uint64_t frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700614 if (!mEnabled.load()) return;
615
616 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800617 ALOGV("[%d]-[%" PRIu64 "]-removeTimeRecord", layerId, frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700618
619 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800620 if (!mTimeStatsTracker.count(layerId)) return;
621 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700622 size_t removeAt = 0;
623 for (const TimeRecord& record : layerRecord.timeRecords) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700624 if (record.frameTime.frameNumber == frameNumber) break;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700625 removeAt++;
626 }
627 if (removeAt == layerRecord.timeRecords.size()) return;
628 layerRecord.timeRecords.erase(layerRecord.timeRecords.begin() + removeAt);
629 if (layerRecord.waitData > static_cast<int32_t>(removeAt)) {
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700630 layerRecord.waitData--;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700631 }
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700632 layerRecord.droppedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700633}
634
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700635void TimeStats::flushPowerTimeLocked() {
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700636 if (!mEnabled.load()) return;
637
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700638 nsecs_t curTime = systemTime();
639 // elapsedTime is in milliseconds.
640 int64_t elapsedTime = (curTime - mPowerTime.prevTime) / 1000000;
641
642 switch (mPowerTime.powerMode) {
643 case HWC_POWER_MODE_NORMAL:
644 mTimeStats.displayOnTime += elapsedTime;
645 break;
646 case HWC_POWER_MODE_OFF:
647 case HWC_POWER_MODE_DOZE:
648 case HWC_POWER_MODE_DOZE_SUSPEND:
649 default:
650 break;
651 }
652
653 mPowerTime.prevTime = curTime;
654}
655
656void TimeStats::setPowerMode(int32_t powerMode) {
657 if (!mEnabled.load()) {
658 std::lock_guard<std::mutex> lock(mMutex);
659 mPowerTime.powerMode = powerMode;
660 return;
661 }
662
663 std::lock_guard<std::mutex> lock(mMutex);
664 if (powerMode == mPowerTime.powerMode) return;
665
666 flushPowerTimeLocked();
667 mPowerTime.powerMode = powerMode;
668}
669
Alec Mourifb571ea2019-01-24 18:42:10 -0800670void TimeStats::recordRefreshRate(uint32_t fps, nsecs_t duration) {
671 std::lock_guard<std::mutex> lock(mMutex);
672 if (mTimeStats.refreshRateStats.count(fps)) {
673 mTimeStats.refreshRateStats[fps] += duration;
674 } else {
675 mTimeStats.refreshRateStats.insert({fps, duration});
676 }
677}
678
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700679void TimeStats::flushAvailableGlobalRecordsToStatsLocked() {
680 ATRACE_CALL();
681
682 while (!mGlobalRecord.presentFences.empty()) {
683 const nsecs_t curPresentTime = mGlobalRecord.presentFences.front()->getSignalTime();
684 if (curPresentTime == Fence::SIGNAL_TIME_PENDING) break;
685
686 if (curPresentTime == Fence::SIGNAL_TIME_INVALID) {
687 ALOGE("GlobalPresentFence is invalid!");
688 mGlobalRecord.prevPresentTime = 0;
689 mGlobalRecord.presentFences.pop_front();
690 continue;
691 }
692
693 ALOGV("GlobalPresentFenceTime[%" PRId64 "]",
694 mGlobalRecord.presentFences.front()->getSignalTime());
695
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700696 if (mGlobalRecord.prevPresentTime != 0) {
697 const int32_t presentToPresentMs =
698 msBetween(mGlobalRecord.prevPresentTime, curPresentTime);
699 ALOGV("Global present2present[%d] prev[%" PRId64 "] curr[%" PRId64 "]",
700 presentToPresentMs, mGlobalRecord.prevPresentTime, curPresentTime);
701 mTimeStats.presentToPresent.insert(presentToPresentMs);
702 }
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700703
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700704 mGlobalRecord.prevPresentTime = curPresentTime;
705 mGlobalRecord.presentFences.pop_front();
706 }
Alec Mourie4034bb2019-11-19 12:45:54 -0800707 while (!mGlobalRecord.renderEngineDurations.empty()) {
708 const auto duration = mGlobalRecord.renderEngineDurations.front();
709 const auto& endTime = duration.endTime;
710
711 nsecs_t endNs = -1;
712
713 if (auto val = std::get_if<nsecs_t>(&endTime)) {
714 endNs = *val;
715 } else {
716 endNs = std::get<std::shared_ptr<FenceTime>>(endTime)->getSignalTime();
717 }
718
719 if (endNs == Fence::SIGNAL_TIME_PENDING) break;
720
721 if (endNs < 0) {
722 ALOGE("RenderEngineTiming is invalid!");
723 mGlobalRecord.renderEngineDurations.pop_front();
724 continue;
725 }
726
727 const int32_t renderEngineMs = msBetween(duration.startTime, endNs);
728 mTimeStats.renderEngineTiming.insert(renderEngineMs);
729
730 mGlobalRecord.renderEngineDurations.pop_front();
731 }
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700732}
733
734void TimeStats::setPresentFenceGlobal(const std::shared_ptr<FenceTime>& presentFence) {
735 if (!mEnabled.load()) return;
736
737 ATRACE_CALL();
738 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700739 if (presentFence == nullptr || !presentFence->isValid()) {
740 mGlobalRecord.prevPresentTime = 0;
741 return;
742 }
743
744 if (mPowerTime.powerMode != HWC_POWER_MODE_NORMAL) {
745 // Try flushing the last present fence on HWC_POWER_MODE_NORMAL.
746 flushAvailableGlobalRecordsToStatsLocked();
747 mGlobalRecord.presentFences.clear();
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700748 mGlobalRecord.prevPresentTime = 0;
749 return;
750 }
751
752 if (mGlobalRecord.presentFences.size() == MAX_NUM_TIME_RECORDS) {
753 // The front presentFence must be trapped in pending status in this
754 // case. Try dequeuing the front one to recover.
755 ALOGE("GlobalPresentFences is already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
756 mGlobalRecord.prevPresentTime = 0;
757 mGlobalRecord.presentFences.pop_front();
758 }
759
760 mGlobalRecord.presentFences.emplace_back(presentFence);
761 flushAvailableGlobalRecordsToStatsLocked();
762}
763
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700764void TimeStats::enable() {
765 if (mEnabled.load()) return;
766
767 ATRACE_CALL();
768
769 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700770 mEnabled.store(true);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700771 mTimeStats.statsStart = static_cast<int64_t>(std::time(0));
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700772 mPowerTime.prevTime = systemTime();
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000773 mStatsDelegate->registerStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
Alec Mouri37384342020-01-02 17:23:37 -0800774 TimeStats::pullAtomCallback, nullptr, this);
775 mStatsDelegate->registerStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
776 TimeStats::pullAtomCallback, nullptr, this);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700777 ALOGD("Enabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700778}
779
780void TimeStats::disable() {
781 if (!mEnabled.load()) return;
782
783 ATRACE_CALL();
784
785 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700786 flushPowerTimeLocked();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700787 mEnabled.store(false);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700788 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000789 mStatsDelegate->unregisterStatsPullAtomCallback(
790 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO);
Alec Mouri37384342020-01-02 17:23:37 -0800791 mStatsDelegate->unregisterStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700792 ALOGD("Disabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700793}
794
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000795void TimeStats::clearAll() {
796 std::lock_guard<std::mutex> lock(mMutex);
797 clearGlobalLocked();
798 clearLayersLocked();
799}
800
801void TimeStats::clearGlobalLocked() {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700802 ATRACE_CALL();
803
Yiwei Zhangdc224042018-10-18 15:34:00 -0700804 mTimeStats.statsStart = (mEnabled.load() ? static_cast<int64_t>(std::time(0)) : 0);
805 mTimeStats.statsEnd = 0;
806 mTimeStats.totalFrames = 0;
807 mTimeStats.missedFrames = 0;
808 mTimeStats.clientCompositionFrames = 0;
Vishnu Nair9b079a22020-01-21 14:36:08 -0800809 mTimeStats.clientCompositionReusedFrames = 0;
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700810 mTimeStats.displayOnTime = 0;
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700811 mTimeStats.presentToPresent.hist.clear();
Alec Mouri31ac64a2020-01-09 09:26:22 -0800812 mTimeStats.frameDuration.hist.clear();
813 mTimeStats.renderEngineTiming.hist.clear();
Alec Mourifb571ea2019-01-24 18:42:10 -0800814 mTimeStats.refreshRateStats.clear();
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700815 mPowerTime.prevTime = systemTime();
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700816 mGlobalRecord.prevPresentTime = 0;
817 mGlobalRecord.presentFences.clear();
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000818 ALOGD("Cleared global stats");
819}
820
821void TimeStats::clearLayersLocked() {
822 ATRACE_CALL();
823
824 mTimeStatsTracker.clear();
825 mTimeStats.stats.clear();
826 ALOGD("Cleared layer stats");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700827}
828
829bool TimeStats::isEnabled() {
830 return mEnabled.load();
831}
832
Yiwei Zhang5434a782018-12-05 18:06:32 -0800833void TimeStats::dump(bool asProto, std::optional<uint32_t> maxLayers, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700834 ATRACE_CALL();
835
836 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700837 if (mTimeStats.statsStart == 0) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700838 return;
839 }
840
Yiwei Zhangdc224042018-10-18 15:34:00 -0700841 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700842
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700843 flushPowerTimeLocked();
844
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700845 if (asProto) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700846 ALOGD("Dumping TimeStats as proto");
Yiwei Zhangdc224042018-10-18 15:34:00 -0700847 SFTimeStatsGlobalProto timeStatsProto = mTimeStats.toProto(maxLayers);
Dominik Laskowski46470112019-08-02 13:13:11 -0700848 result.append(timeStatsProto.SerializeAsString());
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700849 } else {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700850 ALOGD("Dumping TimeStats as text");
Yiwei Zhang5434a782018-12-05 18:06:32 -0800851 result.append(mTimeStats.toString(maxLayers));
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700852 result.append("\n");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700853 }
854}
855
Alec Mourifb571ea2019-01-24 18:42:10 -0800856} // namespace impl
857
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700858} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -0800859
860// TODO(b/129481165): remove the #pragma below and fix conversion issues
861#pragma clang diagnostic pop // ignored "-Wconversion"