blob: 7c8c28e87bc1b41232537fec47074e8d0d4e9fc0 [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());
Alec Mouri717bcb62020-02-10 17:07:19 -080073 mStatsDelegate->statsEventWriteInt32(event, mTimeStats.displayEventConnectionsCount);
Alec Mouri37384342020-01-02 17:23:37 -080074 mStatsDelegate->statsEventBuild(event);
75 clearGlobalLocked();
Alec Mouri8e2f31b2020-01-16 22:04:35 +000076
Tej Singh2a457b62020-01-31 16:16:10 -080077 return AStatsManager_PULL_SUCCESS;
Alec Mouri8e2f31b2020-01-16 22:04:35 +000078}
79
Alec Mouri37384342020-01-02 17:23:37 -080080namespace {
81// Histograms align with the order of fields in SurfaceflingerStatsLayerInfo.
82const std::array<std::string, 6> kHistogramNames = {
83 "present2present", "post2present", "acquire2present",
84 "latch2present", "desired2present", "post2acquire",
85};
Alec Mouri8e2f31b2020-01-16 22:04:35 +000086
Alec Mouri37384342020-01-02 17:23:37 -080087std::string histogramToProtoByteString(const std::unordered_map<int32_t, int32_t>& histogram,
88 size_t maxPulledHistogramBuckets) {
89 auto buckets = std::vector<std::pair<int32_t, int32_t>>(histogram.begin(), histogram.end());
90 std::sort(buckets.begin(), buckets.end(),
91 [](std::pair<int32_t, int32_t>& left, std::pair<int32_t, int32_t>& right) {
92 return left.second > right.second;
93 });
94
95 util::ProtoOutputStream proto;
96 int histogramSize = 0;
97 for (const auto& bucket : buckets) {
98 if (++histogramSize > maxPulledHistogramBuckets) {
99 break;
100 }
101 proto.write(android::util::FIELD_TYPE_INT32 | android::util::FIELD_COUNT_REPEATED |
102 1 /* field id */,
103 (int32_t)bucket.first);
104 proto.write(android::util::FIELD_TYPE_INT64 | android::util::FIELD_COUNT_REPEATED |
105 2 /* field id */,
106 (int64_t)bucket.second);
107 }
108
109 std::string byteString;
110 proto.serializeToString(&byteString);
111 return byteString;
112}
113} // namespace
114
Tej Singh2a457b62020-01-31 16:16:10 -0800115AStatsManager_PullAtomCallbackReturn TimeStats::populateLayerAtom(AStatsEventList* data) {
Alec Mouri37384342020-01-02 17:23:37 -0800116 std::lock_guard<std::mutex> lock(mMutex);
117
118 std::vector<TimeStatsHelper::TimeStatsLayer const*> dumpStats;
119 for (const auto& ele : mTimeStats.stats) {
120 dumpStats.push_back(&ele.second);
121 }
122
123 std::sort(dumpStats.begin(), dumpStats.end(),
124 [](TimeStatsHelper::TimeStatsLayer const* l,
125 TimeStatsHelper::TimeStatsLayer const* r) {
126 return l->totalFrames > r->totalFrames;
127 });
128
129 if (mMaxPulledLayers < dumpStats.size()) {
130 dumpStats.resize(mMaxPulledLayers);
131 }
132
133 for (const auto& layer : dumpStats) {
Tej Singh2a457b62020-01-31 16:16:10 -0800134 AStatsEvent* event = mStatsDelegate->addStatsEventToPullData(data);
Alec Mouri37384342020-01-02 17:23:37 -0800135 mStatsDelegate->statsEventSetAtomId(event, android::util::SURFACEFLINGER_STATS_LAYER_INFO);
136 mStatsDelegate->statsEventWriteString8(event, layer->layerName.c_str());
137 mStatsDelegate->statsEventWriteInt64(event, layer->totalFrames);
138 mStatsDelegate->statsEventWriteInt64(event, layer->droppedFrames);
139
140 for (const auto& name : kHistogramNames) {
141 const auto& histogram = layer->deltas.find(name);
142 if (histogram == layer->deltas.cend()) {
143 mStatsDelegate->statsEventWriteByteArray(event, nullptr, 0);
144 } else {
145 std::string bytes = histogramToProtoByteString(histogram->second.hist,
146 mMaxPulledHistogramBuckets);
147 mStatsDelegate->statsEventWriteByteArray(event, (const uint8_t*)bytes.c_str(),
148 bytes.size());
149 }
150 }
151
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -0800152 mStatsDelegate->statsEventWriteInt64(event, layer->lateAcquireFrames);
153 mStatsDelegate->statsEventWriteInt64(event, layer->badDesiredPresentFrames);
154
Alec Mouri37384342020-01-02 17:23:37 -0800155 mStatsDelegate->statsEventBuild(event);
156 }
157 clearLayersLocked();
158
Tej Singh2a457b62020-01-31 16:16:10 -0800159 return AStatsManager_PULL_SUCCESS;
Alec Mouri37384342020-01-02 17:23:37 -0800160}
161
162TimeStats::TimeStats() : TimeStats(nullptr, std::nullopt, std::nullopt) {}
163
164TimeStats::TimeStats(std::unique_ptr<StatsEventDelegate> statsDelegate,
165 std::optional<size_t> maxPulledLayers,
166 std::optional<size_t> maxPulledHistogramBuckets) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000167 if (statsDelegate != nullptr) {
168 mStatsDelegate = std::move(statsDelegate);
169 }
Alec Mouri37384342020-01-02 17:23:37 -0800170
171 if (maxPulledLayers) {
172 mMaxPulledLayers = *maxPulledLayers;
173 }
174
175 if (maxPulledHistogramBuckets) {
176 mMaxPulledHistogramBuckets = *maxPulledHistogramBuckets;
177 }
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000178}
179
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800180TimeStats::~TimeStats() {
181 std::lock_guard<std::mutex> lock(mMutex);
182 mStatsDelegate->unregisterStatsPullAtomCallback(
183 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO);
184 mStatsDelegate->unregisterStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO);
185}
186
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000187void TimeStats::onBootFinished() {
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800188 std::lock_guard<std::mutex> lock(mMutex);
189 mStatsDelegate->registerStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
190 TimeStats::pullAtomCallback, nullptr, this);
191 mStatsDelegate->registerStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
192 TimeStats::pullAtomCallback, nullptr, this);
Alec Mourib3885ad2019-09-06 17:08:55 -0700193}
194
Dominik Laskowskic2867142019-01-21 11:33:38 -0800195void TimeStats::parseArgs(bool asProto, const Vector<String16>& args, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700196 ATRACE_CALL();
197
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700198 std::unordered_map<std::string, int32_t> argsMap;
Dominik Laskowskic2867142019-01-21 11:33:38 -0800199 for (size_t index = 0; index < args.size(); ++index) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700200 argsMap[std::string(String8(args[index]).c_str())] = index;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700201 }
202
203 if (argsMap.count("-disable")) {
204 disable();
205 }
206
207 if (argsMap.count("-dump")) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700208 std::optional<uint32_t> maxLayers = std::nullopt;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700209 auto iter = argsMap.find("-maxlayers");
210 if (iter != argsMap.end() && iter->second + 1 < static_cast<int32_t>(args.size())) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700211 int64_t value = strtol(String8(args[iter->second + 1]).c_str(), nullptr, 10);
212 value = std::clamp(value, int64_t(0), int64_t(UINT32_MAX));
213 maxLayers = static_cast<uint32_t>(value);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700214 }
215
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700216 dump(asProto, maxLayers, result);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700217 }
218
219 if (argsMap.count("-clear")) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000220 clearAll();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700221 }
222
223 if (argsMap.count("-enable")) {
224 enable();
225 }
226}
227
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700228std::string TimeStats::miniDump() {
229 ATRACE_CALL();
230
231 std::string result = "TimeStats miniDump:\n";
232 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange926ab52019-08-14 15:16:00 -0700233 android::base::StringAppendF(&result, "Number of layers currently being tracked is %zu\n",
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700234 mTimeStatsTracker.size());
Yiwei Zhange926ab52019-08-14 15:16:00 -0700235 android::base::StringAppendF(&result, "Number of layers in the stats pool is %zu\n",
236 mTimeStats.stats.size());
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700237 return result;
238}
239
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700240void TimeStats::incrementTotalFrames() {
241 if (!mEnabled.load()) return;
242
243 ATRACE_CALL();
244
245 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700246 mTimeStats.totalFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700247}
248
Yiwei Zhang621f9d42018-05-07 10:40:55 -0700249void TimeStats::incrementMissedFrames() {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700250 if (!mEnabled.load()) return;
251
252 ATRACE_CALL();
253
254 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700255 mTimeStats.missedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700256}
257
258void TimeStats::incrementClientCompositionFrames() {
259 if (!mEnabled.load()) return;
260
261 ATRACE_CALL();
262
263 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700264 mTimeStats.clientCompositionFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700265}
266
Vishnu Nair9b079a22020-01-21 14:36:08 -0800267void TimeStats::incrementClientCompositionReusedFrames() {
268 if (!mEnabled.load()) return;
269
270 ATRACE_CALL();
271
272 std::lock_guard<std::mutex> lock(mMutex);
273 mTimeStats.clientCompositionReusedFrames++;
274}
275
Alec Mouri717bcb62020-02-10 17:07:19 -0800276void TimeStats::recordDisplayEventConnectionCount(int32_t count) {
277 if (!mEnabled.load()) return;
278
279 ATRACE_CALL();
280
281 std::lock_guard<std::mutex> lock(mMutex);
282 mTimeStats.displayEventConnectionsCount =
283 std::max(mTimeStats.displayEventConnectionsCount, count);
284}
285
Alec Mouri9519bf12019-11-15 16:54:44 -0800286static int32_t msBetween(nsecs_t start, nsecs_t end) {
287 int64_t delta = std::chrono::duration_cast<std::chrono::milliseconds>(
288 std::chrono::nanoseconds(end - start))
289 .count();
290 delta = std::clamp(delta, int64_t(INT32_MIN), int64_t(INT32_MAX));
291 return static_cast<int32_t>(delta);
292}
293
294void TimeStats::recordFrameDuration(nsecs_t startTime, nsecs_t endTime) {
295 if (!mEnabled.load()) return;
296
297 std::lock_guard<std::mutex> lock(mMutex);
298 if (mPowerTime.powerMode == HWC_POWER_MODE_NORMAL) {
299 mTimeStats.frameDuration.insert(msBetween(startTime, endTime));
300 }
301}
302
Alec Mourie4034bb2019-11-19 12:45:54 -0800303void TimeStats::recordRenderEngineDuration(nsecs_t startTime, nsecs_t endTime) {
304 if (!mEnabled.load()) return;
305
306 std::lock_guard<std::mutex> lock(mMutex);
307 if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
308 ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
309 mGlobalRecord.renderEngineDurations.pop_front();
310 }
311 mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
312}
313
314void TimeStats::recordRenderEngineDuration(nsecs_t startTime,
315 const std::shared_ptr<FenceTime>& endTime) {
316 if (!mEnabled.load()) return;
317
318 std::lock_guard<std::mutex> lock(mMutex);
319 if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
320 ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
321 mGlobalRecord.renderEngineDurations.pop_front();
322 }
323 mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
324}
325
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800326bool TimeStats::recordReadyLocked(int32_t layerId, TimeRecord* timeRecord) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700327 if (!timeRecord->ready) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800328 ALOGV("[%d]-[%" PRIu64 "]-presentFence is still not received", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700329 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700330 return false;
331 }
332
333 if (timeRecord->acquireFence != nullptr) {
334 if (timeRecord->acquireFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
335 return false;
336 }
337 if (timeRecord->acquireFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700338 timeRecord->frameTime.acquireTime = timeRecord->acquireFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700339 timeRecord->acquireFence = nullptr;
340 } else {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800341 ALOGV("[%d]-[%" PRIu64 "]-acquireFence signal time is invalid", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700342 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700343 }
344 }
345
346 if (timeRecord->presentFence != nullptr) {
347 if (timeRecord->presentFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
348 return false;
349 }
350 if (timeRecord->presentFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700351 timeRecord->frameTime.presentTime = timeRecord->presentFence->getSignalTime();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700352 timeRecord->presentFence = nullptr;
353 } else {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800354 ALOGV("[%d]-[%" PRIu64 "]-presentFence signal time invalid", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700355 timeRecord->frameTime.frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700356 }
357 }
358
359 return true;
360}
361
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800362void TimeStats::flushAvailableRecordsToStatsLocked(int32_t layerId) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700363 ATRACE_CALL();
364
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800365 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700366 TimeRecord& prevTimeRecord = layerRecord.prevTimeRecord;
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700367 std::deque<TimeRecord>& timeRecords = layerRecord.timeRecords;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700368 while (!timeRecords.empty()) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800369 if (!recordReadyLocked(layerId, &timeRecords[0])) break;
370 ALOGV("[%d]-[%" PRIu64 "]-presentFenceTime[%" PRId64 "]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700371 timeRecords[0].frameTime.frameNumber, timeRecords[0].frameTime.presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700372
373 if (prevTimeRecord.ready) {
Yiwei Zhangeafa5cc2019-07-26 15:06:25 -0700374 const std::string& layerName = layerRecord.layerName;
Yiwei Zhangdc224042018-10-18 15:34:00 -0700375 if (!mTimeStats.stats.count(layerName)) {
376 mTimeStats.stats[layerName].layerName = layerName;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700377 }
Yiwei Zhangdc224042018-10-18 15:34:00 -0700378 TimeStatsHelper::TimeStatsLayer& timeStatsLayer = mTimeStats.stats[layerName];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700379 timeStatsLayer.totalFrames++;
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700380 timeStatsLayer.droppedFrames += layerRecord.droppedFrames;
Alec Mouri91f6df32020-01-30 08:48:58 -0800381 timeStatsLayer.lateAcquireFrames += layerRecord.lateAcquireFrames;
382 timeStatsLayer.badDesiredPresentFrames += layerRecord.badDesiredPresentFrames;
383
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700384 layerRecord.droppedFrames = 0;
Alec Mouri91f6df32020-01-30 08:48:58 -0800385 layerRecord.lateAcquireFrames = 0;
386 layerRecord.badDesiredPresentFrames = 0;
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700387
388 const int32_t postToAcquireMs = msBetween(timeRecords[0].frameTime.postTime,
389 timeRecords[0].frameTime.acquireTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800390 ALOGV("[%d]-[%" PRIu64 "]-post2acquire[%d]", layerId,
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700391 timeRecords[0].frameTime.frameNumber, postToAcquireMs);
392 timeStatsLayer.deltas["post2acquire"].insert(postToAcquireMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700393
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700394 const int32_t postToPresentMs = msBetween(timeRecords[0].frameTime.postTime,
395 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800396 ALOGV("[%d]-[%" PRIu64 "]-post2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700397 timeRecords[0].frameTime.frameNumber, postToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700398 timeStatsLayer.deltas["post2present"].insert(postToPresentMs);
399
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700400 const int32_t acquireToPresentMs = msBetween(timeRecords[0].frameTime.acquireTime,
401 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800402 ALOGV("[%d]-[%" PRIu64 "]-acquire2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700403 timeRecords[0].frameTime.frameNumber, acquireToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700404 timeStatsLayer.deltas["acquire2present"].insert(acquireToPresentMs);
405
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700406 const int32_t latchToPresentMs = msBetween(timeRecords[0].frameTime.latchTime,
407 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800408 ALOGV("[%d]-[%" PRIu64 "]-latch2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700409 timeRecords[0].frameTime.frameNumber, latchToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700410 timeStatsLayer.deltas["latch2present"].insert(latchToPresentMs);
411
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700412 const int32_t desiredToPresentMs = msBetween(timeRecords[0].frameTime.desiredTime,
413 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800414 ALOGV("[%d]-[%" PRIu64 "]-desired2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700415 timeRecords[0].frameTime.frameNumber, desiredToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700416 timeStatsLayer.deltas["desired2present"].insert(desiredToPresentMs);
417
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700418 const int32_t presentToPresentMs = msBetween(prevTimeRecord.frameTime.presentTime,
419 timeRecords[0].frameTime.presentTime);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800420 ALOGV("[%d]-[%" PRIu64 "]-present2present[%d]", layerId,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700421 timeRecords[0].frameTime.frameNumber, presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700422 timeStatsLayer.deltas["present2present"].insert(presentToPresentMs);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700423 }
424 prevTimeRecord = timeRecords[0];
Yiwei Zhangc5f2c452018-05-08 16:31:56 -0700425 timeRecords.pop_front();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700426 layerRecord.waitData--;
427 }
428}
429
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700430static constexpr const char* kPopupWindowPrefix = "PopupWindow";
431static const size_t kMinLenLayerName = std::strlen(kPopupWindowPrefix);
Yiwei Zhangbd408322018-10-15 18:31:53 -0700432
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700433// Avoid tracking the "PopupWindow:<random hash>#<number>" layers
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700434static bool layerNameIsValid(const std::string& layerName) {
Yiwei Zhang8bec7e82019-10-07 18:08:26 -0700435 return layerName.length() >= kMinLenLayerName &&
436 layerName.compare(0, kMinLenLayerName, kPopupWindowPrefix) != 0;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700437}
438
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800439void TimeStats::setPostTime(int32_t layerId, uint64_t frameNumber, const std::string& layerName,
Yiwei Zhang8e8fe522018-11-02 18:34:07 -0700440 nsecs_t postTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700441 if (!mEnabled.load()) return;
442
443 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800444 ALOGV("[%d]-[%" PRIu64 "]-[%s]-PostTime[%" PRId64 "]", layerId, frameNumber, layerName.c_str(),
Yiwei Zhang8e8fe522018-11-02 18:34:07 -0700445 postTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700446
447 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange926ab52019-08-14 15:16:00 -0700448 if (!mTimeStats.stats.count(layerName) && mTimeStats.stats.size() >= MAX_NUM_LAYER_STATS) {
449 return;
450 }
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800451 if (!mTimeStatsTracker.count(layerId) && mTimeStatsTracker.size() < MAX_NUM_LAYER_RECORDS &&
Yiwei Zhang7eb58b72019-04-22 19:00:02 -0700452 layerNameIsValid(layerName)) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800453 mTimeStatsTracker[layerId].layerName = layerName;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700454 }
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800455 if (!mTimeStatsTracker.count(layerId)) return;
456 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700457 if (layerRecord.timeRecords.size() == MAX_NUM_TIME_RECORDS) {
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800458 ALOGE("[%d]-[%s]-timeRecords is at its maximum size[%zu]. Ignore this when unittesting.",
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800459 layerId, layerRecord.layerName.c_str(), MAX_NUM_TIME_RECORDS);
460 mTimeStatsTracker.erase(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700461 return;
462 }
463 // For most media content, the acquireFence is invalid because the buffer is
464 // ready at the queueBuffer stage. In this case, acquireTime should be given
465 // a default value as postTime.
466 TimeRecord timeRecord = {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700467 .frameTime =
468 {
469 .frameNumber = frameNumber,
470 .postTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800471 .latchTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700472 .acquireTime = postTime,
Yiwei Zhangaf8ee942018-11-22 00:15:23 -0800473 .desiredTime = postTime,
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700474 },
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700475 };
476 layerRecord.timeRecords.push_back(timeRecord);
477 if (layerRecord.waitData < 0 ||
478 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
479 layerRecord.waitData = layerRecord.timeRecords.size() - 1;
480}
481
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800482void TimeStats::setLatchTime(int32_t layerId, uint64_t frameNumber, nsecs_t latchTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700483 if (!mEnabled.load()) return;
484
485 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800486 ALOGV("[%d]-[%" PRIu64 "]-LatchTime[%" PRId64 "]", layerId, frameNumber, latchTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700487
488 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800489 if (!mTimeStatsTracker.count(layerId)) return;
490 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700491 if (layerRecord.waitData < 0 ||
492 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
493 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700494 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700495 if (timeRecord.frameTime.frameNumber == frameNumber) {
496 timeRecord.frameTime.latchTime = latchTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700497 }
498}
499
Alec Mouri91f6df32020-01-30 08:48:58 -0800500void TimeStats::incrementLatchSkipped(int32_t layerId, LatchSkipReason reason) {
501 if (!mEnabled.load()) return;
502
503 ATRACE_CALL();
504 ALOGV("[%d]-LatchSkipped-Reason[%d]", layerId,
505 static_cast<std::underlying_type<LatchSkipReason>::type>(reason));
506
507 std::lock_guard<std::mutex> lock(mMutex);
508 if (!mTimeStatsTracker.count(layerId)) return;
509 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
510
511 switch (reason) {
512 case LatchSkipReason::LateAcquire:
513 layerRecord.lateAcquireFrames++;
514 break;
515 }
516}
517
518void TimeStats::incrementBadDesiredPresent(int32_t layerId) {
519 if (!mEnabled.load()) return;
520
521 ATRACE_CALL();
522 ALOGV("[%d]-BadDesiredPresent", layerId);
523
524 std::lock_guard<std::mutex> lock(mMutex);
525 if (!mTimeStatsTracker.count(layerId)) return;
526 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
527 layerRecord.badDesiredPresentFrames++;
528}
529
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800530void TimeStats::setDesiredTime(int32_t layerId, uint64_t frameNumber, nsecs_t desiredTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700531 if (!mEnabled.load()) return;
532
533 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800534 ALOGV("[%d]-[%" PRIu64 "]-DesiredTime[%" PRId64 "]", layerId, frameNumber, desiredTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700535
536 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800537 if (!mTimeStatsTracker.count(layerId)) return;
538 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700539 if (layerRecord.waitData < 0 ||
540 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
541 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700542 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700543 if (timeRecord.frameTime.frameNumber == frameNumber) {
544 timeRecord.frameTime.desiredTime = desiredTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700545 }
546}
547
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800548void TimeStats::setAcquireTime(int32_t layerId, uint64_t frameNumber, nsecs_t acquireTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700549 if (!mEnabled.load()) return;
550
551 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800552 ALOGV("[%d]-[%" PRIu64 "]-AcquireTime[%" PRId64 "]", layerId, frameNumber, acquireTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700553
554 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800555 if (!mTimeStatsTracker.count(layerId)) return;
556 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700557 if (layerRecord.waitData < 0 ||
558 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
559 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700560 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700561 if (timeRecord.frameTime.frameNumber == frameNumber) {
562 timeRecord.frameTime.acquireTime = acquireTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700563 }
564}
565
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800566void TimeStats::setAcquireFence(int32_t layerId, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700567 const std::shared_ptr<FenceTime>& acquireFence) {
568 if (!mEnabled.load()) return;
569
570 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800571 ALOGV("[%d]-[%" PRIu64 "]-AcquireFenceTime[%" PRId64 "]", layerId, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700572 acquireFence->getSignalTime());
573
574 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800575 if (!mTimeStatsTracker.count(layerId)) return;
576 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700577 if (layerRecord.waitData < 0 ||
578 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
579 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700580 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700581 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700582 timeRecord.acquireFence = acquireFence;
583 }
584}
585
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800586void TimeStats::setPresentTime(int32_t layerId, uint64_t frameNumber, nsecs_t presentTime) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700587 if (!mEnabled.load()) return;
588
589 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800590 ALOGV("[%d]-[%" PRIu64 "]-PresentTime[%" PRId64 "]", layerId, frameNumber, presentTime);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700591
592 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800593 if (!mTimeStatsTracker.count(layerId)) return;
594 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700595 if (layerRecord.waitData < 0 ||
596 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
597 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700598 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700599 if (timeRecord.frameTime.frameNumber == frameNumber) {
600 timeRecord.frameTime.presentTime = presentTime;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700601 timeRecord.ready = true;
602 layerRecord.waitData++;
603 }
604
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800605 flushAvailableRecordsToStatsLocked(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700606}
607
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800608void TimeStats::setPresentFence(int32_t layerId, uint64_t frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700609 const std::shared_ptr<FenceTime>& presentFence) {
610 if (!mEnabled.load()) return;
611
612 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800613 ALOGV("[%d]-[%" PRIu64 "]-PresentFenceTime[%" PRId64 "]", layerId, frameNumber,
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700614 presentFence->getSignalTime());
615
616 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800617 if (!mTimeStatsTracker.count(layerId)) return;
618 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhangcb7dd002019-04-16 11:03:01 -0700619 if (layerRecord.waitData < 0 ||
620 layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
621 return;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700622 TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700623 if (timeRecord.frameTime.frameNumber == frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700624 timeRecord.presentFence = presentFence;
625 timeRecord.ready = true;
626 layerRecord.waitData++;
627 }
628
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800629 flushAvailableRecordsToStatsLocked(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700630}
631
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800632void TimeStats::onDestroy(int32_t layerId) {
Yiwei Zhangdc224042018-10-18 15:34:00 -0700633 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800634 ALOGV("[%d]-onDestroy", layerId);
Mikael Pessa90092f42019-08-26 17:22:04 -0700635 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800636 mTimeStatsTracker.erase(layerId);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700637}
638
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800639void TimeStats::removeTimeRecord(int32_t layerId, uint64_t frameNumber) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700640 if (!mEnabled.load()) return;
641
642 ATRACE_CALL();
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800643 ALOGV("[%d]-[%" PRIu64 "]-removeTimeRecord", layerId, frameNumber);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700644
645 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800646 if (!mTimeStatsTracker.count(layerId)) return;
647 LayerRecord& layerRecord = mTimeStatsTracker[layerId];
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700648 size_t removeAt = 0;
649 for (const TimeRecord& record : layerRecord.timeRecords) {
Yiwei Zhangcf50ab92018-06-14 10:50:12 -0700650 if (record.frameTime.frameNumber == frameNumber) break;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700651 removeAt++;
652 }
653 if (removeAt == layerRecord.timeRecords.size()) return;
654 layerRecord.timeRecords.erase(layerRecord.timeRecords.begin() + removeAt);
655 if (layerRecord.waitData > static_cast<int32_t>(removeAt)) {
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700656 layerRecord.waitData--;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700657 }
Yiwei Zhangeaeea062018-06-28 14:46:51 -0700658 layerRecord.droppedFrames++;
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700659}
660
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700661void TimeStats::flushPowerTimeLocked() {
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700662 if (!mEnabled.load()) return;
663
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700664 nsecs_t curTime = systemTime();
665 // elapsedTime is in milliseconds.
666 int64_t elapsedTime = (curTime - mPowerTime.prevTime) / 1000000;
667
668 switch (mPowerTime.powerMode) {
669 case HWC_POWER_MODE_NORMAL:
670 mTimeStats.displayOnTime += elapsedTime;
671 break;
672 case HWC_POWER_MODE_OFF:
673 case HWC_POWER_MODE_DOZE:
674 case HWC_POWER_MODE_DOZE_SUSPEND:
675 default:
676 break;
677 }
678
679 mPowerTime.prevTime = curTime;
680}
681
682void TimeStats::setPowerMode(int32_t powerMode) {
683 if (!mEnabled.load()) {
684 std::lock_guard<std::mutex> lock(mMutex);
685 mPowerTime.powerMode = powerMode;
686 return;
687 }
688
689 std::lock_guard<std::mutex> lock(mMutex);
690 if (powerMode == mPowerTime.powerMode) return;
691
692 flushPowerTimeLocked();
693 mPowerTime.powerMode = powerMode;
694}
695
Alec Mourifb571ea2019-01-24 18:42:10 -0800696void TimeStats::recordRefreshRate(uint32_t fps, nsecs_t duration) {
697 std::lock_guard<std::mutex> lock(mMutex);
698 if (mTimeStats.refreshRateStats.count(fps)) {
699 mTimeStats.refreshRateStats[fps] += duration;
700 } else {
701 mTimeStats.refreshRateStats.insert({fps, duration});
702 }
703}
704
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700705void TimeStats::flushAvailableGlobalRecordsToStatsLocked() {
706 ATRACE_CALL();
707
708 while (!mGlobalRecord.presentFences.empty()) {
709 const nsecs_t curPresentTime = mGlobalRecord.presentFences.front()->getSignalTime();
710 if (curPresentTime == Fence::SIGNAL_TIME_PENDING) break;
711
712 if (curPresentTime == Fence::SIGNAL_TIME_INVALID) {
713 ALOGE("GlobalPresentFence is invalid!");
714 mGlobalRecord.prevPresentTime = 0;
715 mGlobalRecord.presentFences.pop_front();
716 continue;
717 }
718
719 ALOGV("GlobalPresentFenceTime[%" PRId64 "]",
720 mGlobalRecord.presentFences.front()->getSignalTime());
721
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700722 if (mGlobalRecord.prevPresentTime != 0) {
723 const int32_t presentToPresentMs =
724 msBetween(mGlobalRecord.prevPresentTime, curPresentTime);
725 ALOGV("Global present2present[%d] prev[%" PRId64 "] curr[%" PRId64 "]",
726 presentToPresentMs, mGlobalRecord.prevPresentTime, curPresentTime);
727 mTimeStats.presentToPresent.insert(presentToPresentMs);
728 }
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700729
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700730 mGlobalRecord.prevPresentTime = curPresentTime;
731 mGlobalRecord.presentFences.pop_front();
732 }
Alec Mourie4034bb2019-11-19 12:45:54 -0800733 while (!mGlobalRecord.renderEngineDurations.empty()) {
734 const auto duration = mGlobalRecord.renderEngineDurations.front();
735 const auto& endTime = duration.endTime;
736
737 nsecs_t endNs = -1;
738
739 if (auto val = std::get_if<nsecs_t>(&endTime)) {
740 endNs = *val;
741 } else {
742 endNs = std::get<std::shared_ptr<FenceTime>>(endTime)->getSignalTime();
743 }
744
745 if (endNs == Fence::SIGNAL_TIME_PENDING) break;
746
747 if (endNs < 0) {
748 ALOGE("RenderEngineTiming is invalid!");
749 mGlobalRecord.renderEngineDurations.pop_front();
750 continue;
751 }
752
753 const int32_t renderEngineMs = msBetween(duration.startTime, endNs);
754 mTimeStats.renderEngineTiming.insert(renderEngineMs);
755
756 mGlobalRecord.renderEngineDurations.pop_front();
757 }
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700758}
759
760void TimeStats::setPresentFenceGlobal(const std::shared_ptr<FenceTime>& presentFence) {
761 if (!mEnabled.load()) return;
762
763 ATRACE_CALL();
764 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700765 if (presentFence == nullptr || !presentFence->isValid()) {
766 mGlobalRecord.prevPresentTime = 0;
767 return;
768 }
769
770 if (mPowerTime.powerMode != HWC_POWER_MODE_NORMAL) {
771 // Try flushing the last present fence on HWC_POWER_MODE_NORMAL.
772 flushAvailableGlobalRecordsToStatsLocked();
773 mGlobalRecord.presentFences.clear();
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700774 mGlobalRecord.prevPresentTime = 0;
775 return;
776 }
777
778 if (mGlobalRecord.presentFences.size() == MAX_NUM_TIME_RECORDS) {
779 // The front presentFence must be trapped in pending status in this
780 // case. Try dequeuing the front one to recover.
781 ALOGE("GlobalPresentFences is already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
782 mGlobalRecord.prevPresentTime = 0;
783 mGlobalRecord.presentFences.pop_front();
784 }
785
786 mGlobalRecord.presentFences.emplace_back(presentFence);
787 flushAvailableGlobalRecordsToStatsLocked();
788}
789
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700790void TimeStats::enable() {
791 if (mEnabled.load()) return;
792
793 ATRACE_CALL();
794
795 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700796 mEnabled.store(true);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700797 mTimeStats.statsStart = static_cast<int64_t>(std::time(0));
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700798 mPowerTime.prevTime = systemTime();
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700799 ALOGD("Enabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700800}
801
802void TimeStats::disable() {
803 if (!mEnabled.load()) return;
804
805 ATRACE_CALL();
806
807 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700808 flushPowerTimeLocked();
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700809 mEnabled.store(false);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700810 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700811 ALOGD("Disabled");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700812}
813
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000814void TimeStats::clearAll() {
815 std::lock_guard<std::mutex> lock(mMutex);
816 clearGlobalLocked();
817 clearLayersLocked();
818}
819
820void TimeStats::clearGlobalLocked() {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700821 ATRACE_CALL();
822
Yiwei Zhangdc224042018-10-18 15:34:00 -0700823 mTimeStats.statsStart = (mEnabled.load() ? static_cast<int64_t>(std::time(0)) : 0);
824 mTimeStats.statsEnd = 0;
825 mTimeStats.totalFrames = 0;
826 mTimeStats.missedFrames = 0;
827 mTimeStats.clientCompositionFrames = 0;
Vishnu Nair9b079a22020-01-21 14:36:08 -0800828 mTimeStats.clientCompositionReusedFrames = 0;
Alec Mouri717bcb62020-02-10 17:07:19 -0800829 mTimeStats.displayEventConnectionsCount = 0;
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700830 mTimeStats.displayOnTime = 0;
Yiwei Zhangce6ebc02018-10-20 12:42:38 -0700831 mTimeStats.presentToPresent.hist.clear();
Alec Mouri31ac64a2020-01-09 09:26:22 -0800832 mTimeStats.frameDuration.hist.clear();
833 mTimeStats.renderEngineTiming.hist.clear();
Alec Mourifb571ea2019-01-24 18:42:10 -0800834 mTimeStats.refreshRateStats.clear();
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700835 mPowerTime.prevTime = systemTime();
Yiwei Zhange5c49d52018-10-29 00:15:31 -0700836 mGlobalRecord.prevPresentTime = 0;
837 mGlobalRecord.presentFences.clear();
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000838 ALOGD("Cleared global stats");
839}
840
841void TimeStats::clearLayersLocked() {
842 ATRACE_CALL();
843
844 mTimeStatsTracker.clear();
845 mTimeStats.stats.clear();
846 ALOGD("Cleared layer stats");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700847}
848
849bool TimeStats::isEnabled() {
850 return mEnabled.load();
851}
852
Yiwei Zhang5434a782018-12-05 18:06:32 -0800853void TimeStats::dump(bool asProto, std::optional<uint32_t> maxLayers, std::string& result) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700854 ATRACE_CALL();
855
856 std::lock_guard<std::mutex> lock(mMutex);
Yiwei Zhangdc224042018-10-18 15:34:00 -0700857 if (mTimeStats.statsStart == 0) {
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700858 return;
859 }
860
Yiwei Zhangdc224042018-10-18 15:34:00 -0700861 mTimeStats.statsEnd = static_cast<int64_t>(std::time(0));
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700862
Yiwei Zhang3a226d22018-10-16 09:23:03 -0700863 flushPowerTimeLocked();
864
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700865 if (asProto) {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700866 ALOGD("Dumping TimeStats as proto");
Yiwei Zhangdc224042018-10-18 15:34:00 -0700867 SFTimeStatsGlobalProto timeStatsProto = mTimeStats.toProto(maxLayers);
Dominik Laskowski46470112019-08-02 13:13:11 -0700868 result.append(timeStatsProto.SerializeAsString());
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700869 } else {
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700870 ALOGD("Dumping TimeStats as text");
Yiwei Zhang5434a782018-12-05 18:06:32 -0800871 result.append(mTimeStats.toString(maxLayers));
Yiwei Zhang8a4015c2018-05-08 16:03:47 -0700872 result.append("\n");
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700873 }
874}
875
Alec Mourifb571ea2019-01-24 18:42:10 -0800876} // namespace impl
877
Yiwei Zhang0102ad22018-05-02 17:37:17 -0700878} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -0800879
880// TODO(b/129481165): remove the #pragma below and fix conversion issues
881#pragma clang diagnostic pop // ignored "-Wconversion"