• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright 2018 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 
17 #include <unordered_map>
18 #undef LOG_TAG
19 #define LOG_TAG "TimeStats"
20 #define ATRACE_TAG ATRACE_TAG_GRAPHICS
21 
22 #include <android-base/stringprintf.h>
23 #include <log/log.h>
24 #include <timestatsatomsproto/TimeStatsAtomsProtoHeader.h>
25 #include <utils/String8.h>
26 #include <utils/Timers.h>
27 #include <utils/Trace.h>
28 
29 #include <algorithm>
30 #include <chrono>
31 
32 #include "TimeStats.h"
33 #include "timestatsproto/TimeStatsHelper.h"
34 
35 namespace android {
36 
37 namespace impl {
38 
39 namespace {
40 
histogramToProto(const std::unordered_map<int32_t,int32_t> & histogram,size_t maxPulledHistogramBuckets)41 FrameTimingHistogram histogramToProto(const std::unordered_map<int32_t, int32_t>& histogram,
42                                       size_t maxPulledHistogramBuckets) {
43     auto buckets = std::vector<std::pair<int32_t, int32_t>>(histogram.begin(), histogram.end());
44     std::sort(buckets.begin(), buckets.end(),
45               [](std::pair<int32_t, int32_t>& left, std::pair<int32_t, int32_t>& right) {
46                   return left.second > right.second;
47               });
48 
49     FrameTimingHistogram histogramProto;
50     int histogramSize = 0;
51     for (const auto& bucket : buckets) {
52         if (++histogramSize > maxPulledHistogramBuckets) {
53             break;
54         }
55         histogramProto.add_time_millis_buckets((int32_t)bucket.first);
56         histogramProto.add_frame_counts((int64_t)bucket.second);
57     }
58     return histogramProto;
59 }
60 
gameModeToProto(int32_t gameMode)61 SurfaceflingerStatsLayerInfo_GameMode gameModeToProto(int32_t gameMode) {
62     switch (gameMode) {
63         case TimeStatsHelper::GameModeUnsupported:
64             return SurfaceflingerStatsLayerInfo::GAME_MODE_UNSUPPORTED;
65         case TimeStatsHelper::GameModeStandard:
66             return SurfaceflingerStatsLayerInfo::GAME_MODE_STANDARD;
67         case TimeStatsHelper::GameModePerformance:
68             return SurfaceflingerStatsLayerInfo::GAME_MODE_PERFORMANCE;
69         case TimeStatsHelper::GameModeBattery:
70             return SurfaceflingerStatsLayerInfo::GAME_MODE_BATTERY;
71         default:
72             return SurfaceflingerStatsLayerInfo::GAME_MODE_UNSPECIFIED;
73     }
74 }
75 
frameRateVoteToProto(const TimeStats::SetFrameRateVote & setFrameRateVote)76 SurfaceflingerStatsLayerInfo_SetFrameRateVote frameRateVoteToProto(
77         const TimeStats::SetFrameRateVote& setFrameRateVote) {
78     using FrameRateCompatibilityEnum =
79             SurfaceflingerStatsLayerInfo::SetFrameRateVote::FrameRateCompatibility;
80     using SeamlessnessEnum = SurfaceflingerStatsLayerInfo::SetFrameRateVote::Seamlessness;
81 
82     SurfaceflingerStatsLayerInfo_SetFrameRateVote proto;
83     proto.set_frame_rate(setFrameRateVote.frameRate);
84     proto.set_frame_rate_compatibility(
85             static_cast<FrameRateCompatibilityEnum>(setFrameRateVote.frameRateCompatibility));
86     proto.set_seamlessness(static_cast<SeamlessnessEnum>(setFrameRateVote.seamlessness));
87     return proto;
88 }
89 } // namespace
90 
populateGlobalAtom(std::string * pulledData)91 bool TimeStats::populateGlobalAtom(std::string* pulledData) {
92     std::lock_guard<std::mutex> lock(mMutex);
93 
94     if (mTimeStats.statsStartLegacy == 0) {
95         return false;
96     }
97     flushPowerTimeLocked();
98     SurfaceflingerStatsGlobalInfoWrapper atomList;
99     for (const auto& globalSlice : mTimeStats.stats) {
100         SurfaceflingerStatsGlobalInfo* atom = atomList.add_atom();
101         atom->set_total_frames(mTimeStats.totalFramesLegacy);
102         atom->set_missed_frames(mTimeStats.missedFramesLegacy);
103         atom->set_client_composition_frames(mTimeStats.clientCompositionFramesLegacy);
104         atom->set_display_on_millis(mTimeStats.displayOnTimeLegacy);
105         atom->set_animation_millis(mTimeStats.presentToPresentLegacy.totalTime());
106         atom->set_event_connection_count(mTimeStats.displayEventConnectionsCountLegacy);
107         *atom->mutable_frame_duration() =
108                 histogramToProto(mTimeStats.frameDurationLegacy.hist, mMaxPulledHistogramBuckets);
109         *atom->mutable_render_engine_timing() =
110                 histogramToProto(mTimeStats.renderEngineTimingLegacy.hist,
111                                  mMaxPulledHistogramBuckets);
112         atom->set_total_timeline_frames(globalSlice.second.jankPayload.totalFrames);
113         atom->set_total_janky_frames(globalSlice.second.jankPayload.totalJankyFrames);
114         atom->set_total_janky_frames_with_long_cpu(globalSlice.second.jankPayload.totalSFLongCpu);
115         atom->set_total_janky_frames_with_long_gpu(globalSlice.second.jankPayload.totalSFLongGpu);
116         atom->set_total_janky_frames_sf_unattributed(
117                 globalSlice.second.jankPayload.totalSFUnattributed);
118         atom->set_total_janky_frames_app_unattributed(
119                 globalSlice.second.jankPayload.totalAppUnattributed);
120         atom->set_total_janky_frames_sf_scheduling(
121                 globalSlice.second.jankPayload.totalSFScheduling);
122         atom->set_total_jank_frames_sf_prediction_error(
123                 globalSlice.second.jankPayload.totalSFPredictionError);
124         atom->set_total_jank_frames_app_buffer_stuffing(
125                 globalSlice.second.jankPayload.totalAppBufferStuffing);
126         atom->set_display_refresh_rate_bucket(globalSlice.first.displayRefreshRateBucket);
127         *atom->mutable_sf_deadline_misses() =
128                 histogramToProto(globalSlice.second.displayDeadlineDeltas.hist,
129                                  mMaxPulledHistogramBuckets);
130         *atom->mutable_sf_prediction_errors() =
131                 histogramToProto(globalSlice.second.displayPresentDeltas.hist,
132                                  mMaxPulledHistogramBuckets);
133         atom->set_render_rate_bucket(globalSlice.first.renderRateBucket);
134     }
135 
136     // Always clear data.
137     clearGlobalLocked();
138 
139     return atomList.SerializeToString(pulledData);
140 }
141 
populateLayerAtom(std::string * pulledData)142 bool TimeStats::populateLayerAtom(std::string* pulledData) {
143     std::lock_guard<std::mutex> lock(mMutex);
144 
145     std::vector<TimeStatsHelper::TimeStatsLayer*> dumpStats;
146     uint32_t numLayers = 0;
147     for (const auto& globalSlice : mTimeStats.stats) {
148         numLayers += globalSlice.second.stats.size();
149     }
150 
151     dumpStats.reserve(numLayers);
152 
153     for (auto& globalSlice : mTimeStats.stats) {
154         for (auto& layerSlice : globalSlice.second.stats) {
155             dumpStats.push_back(&layerSlice.second);
156         }
157     }
158 
159     std::sort(dumpStats.begin(), dumpStats.end(),
160               [](TimeStatsHelper::TimeStatsLayer const* l,
161                  TimeStatsHelper::TimeStatsLayer const* r) {
162                   return l->totalFrames > r->totalFrames;
163               });
164 
165     if (mMaxPulledLayers < dumpStats.size()) {
166         dumpStats.resize(mMaxPulledLayers);
167     }
168 
169     SurfaceflingerStatsLayerInfoWrapper atomList;
170     for (auto& layer : dumpStats) {
171         SurfaceflingerStatsLayerInfo* atom = atomList.add_atom();
172         atom->set_layer_name(layer->layerName);
173         atom->set_total_frames(layer->totalFrames);
174         atom->set_dropped_frames(layer->droppedFrames);
175         const auto& present2PresentHist = layer->deltas.find("present2present");
176         if (present2PresentHist != layer->deltas.cend()) {
177             *atom->mutable_present_to_present() =
178                     histogramToProto(present2PresentHist->second.hist, mMaxPulledHistogramBuckets);
179         }
180         const auto& post2presentHist = layer->deltas.find("post2present");
181         if (post2presentHist != layer->deltas.cend()) {
182             *atom->mutable_post_to_present() =
183                     histogramToProto(post2presentHist->second.hist, mMaxPulledHistogramBuckets);
184         }
185         const auto& acquire2presentHist = layer->deltas.find("acquire2present");
186         if (acquire2presentHist != layer->deltas.cend()) {
187             *atom->mutable_acquire_to_present() =
188                     histogramToProto(acquire2presentHist->second.hist, mMaxPulledHistogramBuckets);
189         }
190         const auto& latch2presentHist = layer->deltas.find("latch2present");
191         if (latch2presentHist != layer->deltas.cend()) {
192             *atom->mutable_latch_to_present() =
193                     histogramToProto(latch2presentHist->second.hist, mMaxPulledHistogramBuckets);
194         }
195         const auto& desired2presentHist = layer->deltas.find("desired2present");
196         if (desired2presentHist != layer->deltas.cend()) {
197             *atom->mutable_desired_to_present() =
198                     histogramToProto(desired2presentHist->second.hist, mMaxPulledHistogramBuckets);
199         }
200         const auto& post2acquireHist = layer->deltas.find("post2acquire");
201         if (post2acquireHist != layer->deltas.cend()) {
202             *atom->mutable_post_to_acquire() =
203                     histogramToProto(post2acquireHist->second.hist, mMaxPulledHistogramBuckets);
204         }
205 
206         atom->set_late_acquire_frames(layer->lateAcquireFrames);
207         atom->set_bad_desired_present_frames(layer->badDesiredPresentFrames);
208         atom->set_uid(layer->uid);
209         atom->set_total_timeline_frames(layer->jankPayload.totalFrames);
210         atom->set_total_janky_frames(layer->jankPayload.totalJankyFrames);
211         atom->set_total_janky_frames_with_long_cpu(layer->jankPayload.totalSFLongCpu);
212         atom->set_total_janky_frames_with_long_gpu(layer->jankPayload.totalSFLongGpu);
213         atom->set_total_janky_frames_sf_unattributed(layer->jankPayload.totalSFUnattributed);
214         atom->set_total_janky_frames_app_unattributed(layer->jankPayload.totalAppUnattributed);
215         atom->set_total_janky_frames_sf_scheduling(layer->jankPayload.totalSFScheduling);
216         atom->set_total_jank_frames_sf_prediction_error(layer->jankPayload.totalSFPredictionError);
217         atom->set_total_jank_frames_app_buffer_stuffing(layer->jankPayload.totalAppBufferStuffing);
218         atom->set_display_refresh_rate_bucket(layer->displayRefreshRateBucket);
219         atom->set_render_rate_bucket(layer->renderRateBucket);
220         *atom->mutable_set_frame_rate_vote() = frameRateVoteToProto(layer->setFrameRateVote);
221         *atom->mutable_app_deadline_misses() =
222                 histogramToProto(layer->deltas["appDeadlineDeltas"].hist,
223                                  mMaxPulledHistogramBuckets);
224         atom->set_game_mode(gameModeToProto(layer->gameMode));
225     }
226 
227     // Always clear data.
228     clearLayersLocked();
229 
230     return atomList.SerializeToString(pulledData);
231 }
232 
TimeStats()233 TimeStats::TimeStats() : TimeStats(std::nullopt, std::nullopt) {}
234 
TimeStats(std::optional<size_t> maxPulledLayers,std::optional<size_t> maxPulledHistogramBuckets)235 TimeStats::TimeStats(std::optional<size_t> maxPulledLayers,
236                      std::optional<size_t> maxPulledHistogramBuckets) {
237     if (maxPulledLayers) {
238         mMaxPulledLayers = *maxPulledLayers;
239     }
240 
241     if (maxPulledHistogramBuckets) {
242         mMaxPulledHistogramBuckets = *maxPulledHistogramBuckets;
243     }
244 }
245 
onPullAtom(const int atomId,std::string * pulledData)246 bool TimeStats::onPullAtom(const int atomId, std::string* pulledData) {
247     bool success = false;
248     if (atomId == 10062) { // SURFACEFLINGER_STATS_GLOBAL_INFO
249         success = populateGlobalAtom(pulledData);
250     } else if (atomId == 10063) { // SURFACEFLINGER_STATS_LAYER_INFO
251         success = populateLayerAtom(pulledData);
252     }
253 
254     // Enable timestats now. The first full pull for a given build is expected to
255     // have empty or very little stats, as stats are first enabled after the
256     // first pull is completed for either the global or layer stats.
257     enable();
258     return success;
259 }
260 
parseArgs(bool asProto,const Vector<String16> & args,std::string & result)261 void TimeStats::parseArgs(bool asProto, const Vector<String16>& args, std::string& result) {
262     ATRACE_CALL();
263 
264     std::unordered_map<std::string, int32_t> argsMap;
265     for (size_t index = 0; index < args.size(); ++index) {
266         argsMap[std::string(String8(args[index]).c_str())] = index;
267     }
268 
269     if (argsMap.count("-disable")) {
270         disable();
271     }
272 
273     if (argsMap.count("-dump")) {
274         std::optional<uint32_t> maxLayers = std::nullopt;
275         auto iter = argsMap.find("-maxlayers");
276         if (iter != argsMap.end() && iter->second + 1 < static_cast<int32_t>(args.size())) {
277             int64_t value = strtol(String8(args[iter->second + 1]).c_str(), nullptr, 10);
278             value = std::clamp(value, int64_t(0), int64_t(UINT32_MAX));
279             maxLayers = static_cast<uint32_t>(value);
280         }
281 
282         dump(asProto, maxLayers, result);
283     }
284 
285     if (argsMap.count("-clear")) {
286         clearAll();
287     }
288 
289     if (argsMap.count("-enable")) {
290         enable();
291     }
292 }
293 
miniDump()294 std::string TimeStats::miniDump() {
295     ATRACE_CALL();
296 
297     std::string result = "TimeStats miniDump:\n";
298     std::lock_guard<std::mutex> lock(mMutex);
299     android::base::StringAppendF(&result, "Number of layers currently being tracked is %zu\n",
300                                  mTimeStatsTracker.size());
301     android::base::StringAppendF(&result, "Number of layers in the stats pool is %zu\n",
302                                  mTimeStats.stats.size());
303     return result;
304 }
305 
incrementTotalFrames()306 void TimeStats::incrementTotalFrames() {
307     if (!mEnabled.load()) return;
308 
309     ATRACE_CALL();
310 
311     std::lock_guard<std::mutex> lock(mMutex);
312     mTimeStats.totalFramesLegacy++;
313 }
314 
incrementMissedFrames()315 void TimeStats::incrementMissedFrames() {
316     if (!mEnabled.load()) return;
317 
318     ATRACE_CALL();
319 
320     std::lock_guard<std::mutex> lock(mMutex);
321     mTimeStats.missedFramesLegacy++;
322 }
323 
incrementClientCompositionFrames()324 void TimeStats::incrementClientCompositionFrames() {
325     if (!mEnabled.load()) return;
326 
327     ATRACE_CALL();
328 
329     std::lock_guard<std::mutex> lock(mMutex);
330     mTimeStats.clientCompositionFramesLegacy++;
331 }
332 
incrementClientCompositionReusedFrames()333 void TimeStats::incrementClientCompositionReusedFrames() {
334     if (!mEnabled.load()) return;
335 
336     ATRACE_CALL();
337 
338     std::lock_guard<std::mutex> lock(mMutex);
339     mTimeStats.clientCompositionReusedFramesLegacy++;
340 }
341 
incrementRefreshRateSwitches()342 void TimeStats::incrementRefreshRateSwitches() {
343     if (!mEnabled.load()) return;
344 
345     ATRACE_CALL();
346 
347     std::lock_guard<std::mutex> lock(mMutex);
348     mTimeStats.refreshRateSwitchesLegacy++;
349 }
350 
incrementCompositionStrategyChanges()351 void TimeStats::incrementCompositionStrategyChanges() {
352     if (!mEnabled.load()) return;
353 
354     ATRACE_CALL();
355 
356     std::lock_guard<std::mutex> lock(mMutex);
357     mTimeStats.compositionStrategyChangesLegacy++;
358 }
359 
recordDisplayEventConnectionCount(int32_t count)360 void TimeStats::recordDisplayEventConnectionCount(int32_t count) {
361     if (!mEnabled.load()) return;
362 
363     ATRACE_CALL();
364 
365     std::lock_guard<std::mutex> lock(mMutex);
366     mTimeStats.displayEventConnectionsCountLegacy =
367             std::max(mTimeStats.displayEventConnectionsCountLegacy, count);
368 }
369 
toMs(nsecs_t nanos)370 static int32_t toMs(nsecs_t nanos) {
371     int64_t millis =
372             std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::nanoseconds(nanos))
373                     .count();
374     millis = std::clamp(millis, int64_t(INT32_MIN), int64_t(INT32_MAX));
375     return static_cast<int32_t>(millis);
376 }
377 
msBetween(nsecs_t start,nsecs_t end)378 static int32_t msBetween(nsecs_t start, nsecs_t end) {
379     return toMs(end - start);
380 }
381 
recordFrameDuration(nsecs_t startTime,nsecs_t endTime)382 void TimeStats::recordFrameDuration(nsecs_t startTime, nsecs_t endTime) {
383     if (!mEnabled.load()) return;
384 
385     std::lock_guard<std::mutex> lock(mMutex);
386     if (mPowerTime.powerMode == PowerMode::ON) {
387         mTimeStats.frameDurationLegacy.insert(msBetween(startTime, endTime));
388     }
389 }
390 
recordRenderEngineDuration(nsecs_t startTime,nsecs_t endTime)391 void TimeStats::recordRenderEngineDuration(nsecs_t startTime, nsecs_t endTime) {
392     if (!mEnabled.load()) return;
393 
394     std::lock_guard<std::mutex> lock(mMutex);
395     if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
396         ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
397         mGlobalRecord.renderEngineDurations.pop_front();
398     }
399     mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
400 }
401 
recordRenderEngineDuration(nsecs_t startTime,const std::shared_ptr<FenceTime> & endTime)402 void TimeStats::recordRenderEngineDuration(nsecs_t startTime,
403                                            const std::shared_ptr<FenceTime>& endTime) {
404     if (!mEnabled.load()) return;
405 
406     std::lock_guard<std::mutex> lock(mMutex);
407     if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
408         ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
409         mGlobalRecord.renderEngineDurations.pop_front();
410     }
411     mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
412 }
413 
recordReadyLocked(int32_t layerId,TimeRecord * timeRecord)414 bool TimeStats::recordReadyLocked(int32_t layerId, TimeRecord* timeRecord) {
415     if (!timeRecord->ready) {
416         ALOGV("[%d]-[%" PRIu64 "]-presentFence is still not received", layerId,
417               timeRecord->frameTime.frameNumber);
418         return false;
419     }
420 
421     if (timeRecord->acquireFence != nullptr) {
422         if (timeRecord->acquireFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
423             return false;
424         }
425         if (timeRecord->acquireFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
426             timeRecord->frameTime.acquireTime = timeRecord->acquireFence->getSignalTime();
427             timeRecord->acquireFence = nullptr;
428         } else {
429             ALOGV("[%d]-[%" PRIu64 "]-acquireFence signal time is invalid", layerId,
430                   timeRecord->frameTime.frameNumber);
431         }
432     }
433 
434     if (timeRecord->presentFence != nullptr) {
435         if (timeRecord->presentFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
436             return false;
437         }
438         if (timeRecord->presentFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
439             timeRecord->frameTime.presentTime = timeRecord->presentFence->getSignalTime();
440             timeRecord->presentFence = nullptr;
441         } else {
442             ALOGV("[%d]-[%" PRIu64 "]-presentFence signal time invalid", layerId,
443                   timeRecord->frameTime.frameNumber);
444         }
445     }
446 
447     return true;
448 }
449 
clampToNearestBucket(Fps fps,size_t bucketWidth)450 static int32_t clampToNearestBucket(Fps fps, size_t bucketWidth) {
451     return std::round(fps.getValue() / bucketWidth) * bucketWidth;
452 }
453 
flushAvailableRecordsToStatsLocked(int32_t layerId,Fps displayRefreshRate,std::optional<Fps> renderRate,SetFrameRateVote frameRateVote,int32_t gameMode)454 void TimeStats::flushAvailableRecordsToStatsLocked(int32_t layerId, Fps displayRefreshRate,
455                                                    std::optional<Fps> renderRate,
456                                                    SetFrameRateVote frameRateVote,
457                                                    int32_t gameMode) {
458     ATRACE_CALL();
459     ALOGV("[%d]-flushAvailableRecordsToStatsLocked", layerId);
460 
461     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
462     TimeRecord& prevTimeRecord = layerRecord.prevTimeRecord;
463     std::deque<TimeRecord>& timeRecords = layerRecord.timeRecords;
464     const int32_t refreshRateBucket =
465             clampToNearestBucket(displayRefreshRate, REFRESH_RATE_BUCKET_WIDTH);
466     const int32_t renderRateBucket =
467             clampToNearestBucket(renderRate ? *renderRate : displayRefreshRate,
468                                  RENDER_RATE_BUCKET_WIDTH);
469     while (!timeRecords.empty()) {
470         if (!recordReadyLocked(layerId, &timeRecords[0])) break;
471         ALOGV("[%d]-[%" PRIu64 "]-presentFenceTime[%" PRId64 "]", layerId,
472               timeRecords[0].frameTime.frameNumber, timeRecords[0].frameTime.presentTime);
473 
474         if (prevTimeRecord.ready) {
475             uid_t uid = layerRecord.uid;
476             const std::string& layerName = layerRecord.layerName;
477             TimeStatsHelper::TimelineStatsKey timelineKey = {refreshRateBucket, renderRateBucket};
478             if (!mTimeStats.stats.count(timelineKey)) {
479                 mTimeStats.stats[timelineKey].key = timelineKey;
480             }
481 
482             TimeStatsHelper::TimelineStats& displayStats = mTimeStats.stats[timelineKey];
483 
484             TimeStatsHelper::LayerStatsKey layerKey = {uid, layerName, gameMode};
485             if (!displayStats.stats.count(layerKey)) {
486                 displayStats.stats[layerKey].displayRefreshRateBucket = refreshRateBucket;
487                 displayStats.stats[layerKey].renderRateBucket = renderRateBucket;
488                 displayStats.stats[layerKey].uid = uid;
489                 displayStats.stats[layerKey].layerName = layerName;
490                 displayStats.stats[layerKey].gameMode = gameMode;
491             }
492             if (frameRateVote.frameRate > 0.0f) {
493                 displayStats.stats[layerKey].setFrameRateVote = frameRateVote;
494             }
495             TimeStatsHelper::TimeStatsLayer& timeStatsLayer = displayStats.stats[layerKey];
496             timeStatsLayer.totalFrames++;
497             timeStatsLayer.droppedFrames += layerRecord.droppedFrames;
498             timeStatsLayer.lateAcquireFrames += layerRecord.lateAcquireFrames;
499             timeStatsLayer.badDesiredPresentFrames += layerRecord.badDesiredPresentFrames;
500 
501             layerRecord.droppedFrames = 0;
502             layerRecord.lateAcquireFrames = 0;
503             layerRecord.badDesiredPresentFrames = 0;
504 
505             const int32_t postToAcquireMs = msBetween(timeRecords[0].frameTime.postTime,
506                                                       timeRecords[0].frameTime.acquireTime);
507             ALOGV("[%d]-[%" PRIu64 "]-post2acquire[%d]", layerId,
508                   timeRecords[0].frameTime.frameNumber, postToAcquireMs);
509             timeStatsLayer.deltas["post2acquire"].insert(postToAcquireMs);
510 
511             const int32_t postToPresentMs = msBetween(timeRecords[0].frameTime.postTime,
512                                                       timeRecords[0].frameTime.presentTime);
513             ALOGV("[%d]-[%" PRIu64 "]-post2present[%d]", layerId,
514                   timeRecords[0].frameTime.frameNumber, postToPresentMs);
515             timeStatsLayer.deltas["post2present"].insert(postToPresentMs);
516 
517             const int32_t acquireToPresentMs = msBetween(timeRecords[0].frameTime.acquireTime,
518                                                          timeRecords[0].frameTime.presentTime);
519             ALOGV("[%d]-[%" PRIu64 "]-acquire2present[%d]", layerId,
520                   timeRecords[0].frameTime.frameNumber, acquireToPresentMs);
521             timeStatsLayer.deltas["acquire2present"].insert(acquireToPresentMs);
522 
523             const int32_t latchToPresentMs = msBetween(timeRecords[0].frameTime.latchTime,
524                                                        timeRecords[0].frameTime.presentTime);
525             ALOGV("[%d]-[%" PRIu64 "]-latch2present[%d]", layerId,
526                   timeRecords[0].frameTime.frameNumber, latchToPresentMs);
527             timeStatsLayer.deltas["latch2present"].insert(latchToPresentMs);
528 
529             const int32_t desiredToPresentMs = msBetween(timeRecords[0].frameTime.desiredTime,
530                                                          timeRecords[0].frameTime.presentTime);
531             ALOGV("[%d]-[%" PRIu64 "]-desired2present[%d]", layerId,
532                   timeRecords[0].frameTime.frameNumber, desiredToPresentMs);
533             timeStatsLayer.deltas["desired2present"].insert(desiredToPresentMs);
534 
535             const int32_t presentToPresentMs = msBetween(prevTimeRecord.frameTime.presentTime,
536                                                          timeRecords[0].frameTime.presentTime);
537             ALOGV("[%d]-[%" PRIu64 "]-present2present[%d]", layerId,
538                   timeRecords[0].frameTime.frameNumber, presentToPresentMs);
539             timeStatsLayer.deltas["present2present"].insert(presentToPresentMs);
540         }
541         prevTimeRecord = timeRecords[0];
542         timeRecords.pop_front();
543         layerRecord.waitData--;
544     }
545 }
546 
547 static constexpr const char* kPopupWindowPrefix = "PopupWindow";
548 static const size_t kMinLenLayerName = std::strlen(kPopupWindowPrefix);
549 
550 // Avoid tracking the "PopupWindow:<random hash>#<number>" layers
layerNameIsValid(const std::string & layerName)551 static bool layerNameIsValid(const std::string& layerName) {
552     return layerName.length() >= kMinLenLayerName &&
553             layerName.compare(0, kMinLenLayerName, kPopupWindowPrefix) != 0;
554 }
555 
canAddNewAggregatedStats(uid_t uid,const std::string & layerName,int32_t gameMode)556 bool TimeStats::canAddNewAggregatedStats(uid_t uid, const std::string& layerName,
557                                          int32_t gameMode) {
558     uint32_t layerRecords = 0;
559     for (const auto& record : mTimeStats.stats) {
560         if (record.second.stats.count({uid, layerName, gameMode}) > 0) {
561             return true;
562         }
563 
564         layerRecords += record.second.stats.size();
565     }
566 
567     return mTimeStats.stats.size() < MAX_NUM_LAYER_STATS;
568 }
569 
setPostTime(int32_t layerId,uint64_t frameNumber,const std::string & layerName,uid_t uid,nsecs_t postTime,int32_t gameMode)570 void TimeStats::setPostTime(int32_t layerId, uint64_t frameNumber, const std::string& layerName,
571                             uid_t uid, nsecs_t postTime, int32_t gameMode) {
572     if (!mEnabled.load()) return;
573 
574     ATRACE_CALL();
575     ALOGV("[%d]-[%" PRIu64 "]-[%s]-PostTime[%" PRId64 "]", layerId, frameNumber, layerName.c_str(),
576           postTime);
577 
578     std::lock_guard<std::mutex> lock(mMutex);
579     if (!canAddNewAggregatedStats(uid, layerName, gameMode)) {
580         return;
581     }
582     if (!mTimeStatsTracker.count(layerId) && mTimeStatsTracker.size() < MAX_NUM_LAYER_RECORDS &&
583         layerNameIsValid(layerName)) {
584         mTimeStatsTracker[layerId].uid = uid;
585         mTimeStatsTracker[layerId].layerName = layerName;
586         mTimeStatsTracker[layerId].gameMode = gameMode;
587     }
588     if (!mTimeStatsTracker.count(layerId)) return;
589     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
590     if (layerRecord.timeRecords.size() == MAX_NUM_TIME_RECORDS) {
591         ALOGE("[%d]-[%s]-timeRecords is at its maximum size[%zu]. Ignore this when unittesting.",
592               layerId, layerRecord.layerName.c_str(), MAX_NUM_TIME_RECORDS);
593         mTimeStatsTracker.erase(layerId);
594         return;
595     }
596     // For most media content, the acquireFence is invalid because the buffer is
597     // ready at the queueBuffer stage. In this case, acquireTime should be given
598     // a default value as postTime.
599     TimeRecord timeRecord = {
600             .frameTime =
601                     {
602                             .frameNumber = frameNumber,
603                             .postTime = postTime,
604                             .latchTime = postTime,
605                             .acquireTime = postTime,
606                             .desiredTime = postTime,
607                     },
608     };
609     layerRecord.timeRecords.push_back(timeRecord);
610     if (layerRecord.waitData < 0 ||
611         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
612         layerRecord.waitData = layerRecord.timeRecords.size() - 1;
613 }
614 
setLatchTime(int32_t layerId,uint64_t frameNumber,nsecs_t latchTime)615 void TimeStats::setLatchTime(int32_t layerId, uint64_t frameNumber, nsecs_t latchTime) {
616     if (!mEnabled.load()) return;
617 
618     ATRACE_CALL();
619     ALOGV("[%d]-[%" PRIu64 "]-LatchTime[%" PRId64 "]", layerId, frameNumber, latchTime);
620 
621     std::lock_guard<std::mutex> lock(mMutex);
622     if (!mTimeStatsTracker.count(layerId)) return;
623     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
624     if (layerRecord.waitData < 0 ||
625         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
626         return;
627     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
628     if (timeRecord.frameTime.frameNumber == frameNumber) {
629         timeRecord.frameTime.latchTime = latchTime;
630     }
631 }
632 
incrementLatchSkipped(int32_t layerId,LatchSkipReason reason)633 void TimeStats::incrementLatchSkipped(int32_t layerId, LatchSkipReason reason) {
634     if (!mEnabled.load()) return;
635 
636     ATRACE_CALL();
637     ALOGV("[%d]-LatchSkipped-Reason[%d]", layerId,
638           static_cast<std::underlying_type<LatchSkipReason>::type>(reason));
639 
640     std::lock_guard<std::mutex> lock(mMutex);
641     if (!mTimeStatsTracker.count(layerId)) return;
642     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
643 
644     switch (reason) {
645         case LatchSkipReason::LateAcquire:
646             layerRecord.lateAcquireFrames++;
647             break;
648     }
649 }
650 
incrementBadDesiredPresent(int32_t layerId)651 void TimeStats::incrementBadDesiredPresent(int32_t layerId) {
652     if (!mEnabled.load()) return;
653 
654     ATRACE_CALL();
655     ALOGV("[%d]-BadDesiredPresent", layerId);
656 
657     std::lock_guard<std::mutex> lock(mMutex);
658     if (!mTimeStatsTracker.count(layerId)) return;
659     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
660     layerRecord.badDesiredPresentFrames++;
661 }
662 
setDesiredTime(int32_t layerId,uint64_t frameNumber,nsecs_t desiredTime)663 void TimeStats::setDesiredTime(int32_t layerId, uint64_t frameNumber, nsecs_t desiredTime) {
664     if (!mEnabled.load()) return;
665 
666     ATRACE_CALL();
667     ALOGV("[%d]-[%" PRIu64 "]-DesiredTime[%" PRId64 "]", layerId, frameNumber, desiredTime);
668 
669     std::lock_guard<std::mutex> lock(mMutex);
670     if (!mTimeStatsTracker.count(layerId)) return;
671     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
672     if (layerRecord.waitData < 0 ||
673         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
674         return;
675     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
676     if (timeRecord.frameTime.frameNumber == frameNumber) {
677         timeRecord.frameTime.desiredTime = desiredTime;
678     }
679 }
680 
setAcquireTime(int32_t layerId,uint64_t frameNumber,nsecs_t acquireTime)681 void TimeStats::setAcquireTime(int32_t layerId, uint64_t frameNumber, nsecs_t acquireTime) {
682     if (!mEnabled.load()) return;
683 
684     ATRACE_CALL();
685     ALOGV("[%d]-[%" PRIu64 "]-AcquireTime[%" PRId64 "]", layerId, frameNumber, acquireTime);
686 
687     std::lock_guard<std::mutex> lock(mMutex);
688     if (!mTimeStatsTracker.count(layerId)) return;
689     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
690     if (layerRecord.waitData < 0 ||
691         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
692         return;
693     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
694     if (timeRecord.frameTime.frameNumber == frameNumber) {
695         timeRecord.frameTime.acquireTime = acquireTime;
696     }
697 }
698 
setAcquireFence(int32_t layerId,uint64_t frameNumber,const std::shared_ptr<FenceTime> & acquireFence)699 void TimeStats::setAcquireFence(int32_t layerId, uint64_t frameNumber,
700                                 const std::shared_ptr<FenceTime>& acquireFence) {
701     if (!mEnabled.load()) return;
702 
703     ATRACE_CALL();
704     ALOGV("[%d]-[%" PRIu64 "]-AcquireFenceTime[%" PRId64 "]", layerId, frameNumber,
705           acquireFence->getSignalTime());
706 
707     std::lock_guard<std::mutex> lock(mMutex);
708     if (!mTimeStatsTracker.count(layerId)) return;
709     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
710     if (layerRecord.waitData < 0 ||
711         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
712         return;
713     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
714     if (timeRecord.frameTime.frameNumber == frameNumber) {
715         timeRecord.acquireFence = acquireFence;
716     }
717 }
718 
setPresentTime(int32_t layerId,uint64_t frameNumber,nsecs_t presentTime,Fps displayRefreshRate,std::optional<Fps> renderRate,SetFrameRateVote frameRateVote,int32_t gameMode)719 void TimeStats::setPresentTime(int32_t layerId, uint64_t frameNumber, nsecs_t presentTime,
720                                Fps displayRefreshRate, std::optional<Fps> renderRate,
721                                SetFrameRateVote frameRateVote, int32_t gameMode) {
722     if (!mEnabled.load()) return;
723 
724     ATRACE_CALL();
725     ALOGV("[%d]-[%" PRIu64 "]-PresentTime[%" PRId64 "]", layerId, frameNumber, presentTime);
726 
727     std::lock_guard<std::mutex> lock(mMutex);
728     if (!mTimeStatsTracker.count(layerId)) return;
729     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
730     if (layerRecord.waitData < 0 ||
731         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
732         return;
733     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
734     if (timeRecord.frameTime.frameNumber == frameNumber) {
735         timeRecord.frameTime.presentTime = presentTime;
736         timeRecord.ready = true;
737         layerRecord.waitData++;
738     }
739 
740     flushAvailableRecordsToStatsLocked(layerId, displayRefreshRate, renderRate, frameRateVote,
741                                        gameMode);
742 }
743 
setPresentFence(int32_t layerId,uint64_t frameNumber,const std::shared_ptr<FenceTime> & presentFence,Fps displayRefreshRate,std::optional<Fps> renderRate,SetFrameRateVote frameRateVote,int32_t gameMode)744 void TimeStats::setPresentFence(int32_t layerId, uint64_t frameNumber,
745                                 const std::shared_ptr<FenceTime>& presentFence,
746                                 Fps displayRefreshRate, std::optional<Fps> renderRate,
747                                 SetFrameRateVote frameRateVote, int32_t gameMode) {
748     if (!mEnabled.load()) return;
749 
750     ATRACE_CALL();
751     ALOGV("[%d]-[%" PRIu64 "]-PresentFenceTime[%" PRId64 "]", layerId, frameNumber,
752           presentFence->getSignalTime());
753 
754     std::lock_guard<std::mutex> lock(mMutex);
755     if (!mTimeStatsTracker.count(layerId)) return;
756     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
757     if (layerRecord.waitData < 0 ||
758         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
759         return;
760     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
761     if (timeRecord.frameTime.frameNumber == frameNumber) {
762         timeRecord.presentFence = presentFence;
763         timeRecord.ready = true;
764         layerRecord.waitData++;
765     }
766 
767     flushAvailableRecordsToStatsLocked(layerId, displayRefreshRate, renderRate, frameRateVote,
768                                        gameMode);
769 }
770 
771 static const constexpr int32_t kValidJankyReason = JankType::DisplayHAL |
772         JankType::SurfaceFlingerCpuDeadlineMissed | JankType::SurfaceFlingerGpuDeadlineMissed |
773         JankType::AppDeadlineMissed | JankType::PredictionError |
774         JankType::SurfaceFlingerScheduling;
775 
776 template <class T>
updateJankPayload(T & t,int32_t reasons)777 static void updateJankPayload(T& t, int32_t reasons) {
778     t.jankPayload.totalFrames++;
779 
780     if (reasons & kValidJankyReason) {
781         t.jankPayload.totalJankyFrames++;
782         if ((reasons & JankType::SurfaceFlingerCpuDeadlineMissed) != 0) {
783             t.jankPayload.totalSFLongCpu++;
784         }
785         if ((reasons & JankType::SurfaceFlingerGpuDeadlineMissed) != 0) {
786             t.jankPayload.totalSFLongGpu++;
787         }
788         if ((reasons & JankType::DisplayHAL) != 0) {
789             t.jankPayload.totalSFUnattributed++;
790         }
791         if ((reasons & JankType::AppDeadlineMissed) != 0) {
792             t.jankPayload.totalAppUnattributed++;
793         }
794         if ((reasons & JankType::PredictionError) != 0) {
795             t.jankPayload.totalSFPredictionError++;
796         }
797         if ((reasons & JankType::SurfaceFlingerScheduling) != 0) {
798             t.jankPayload.totalSFScheduling++;
799         }
800     }
801 
802     // We want to track BufferStuffing separately as it can provide info on latency issues
803     if (reasons & JankType::BufferStuffing) {
804         t.jankPayload.totalAppBufferStuffing++;
805     }
806 }
807 
incrementJankyFrames(const JankyFramesInfo & info)808 void TimeStats::incrementJankyFrames(const JankyFramesInfo& info) {
809     if (!mEnabled.load()) return;
810 
811     ATRACE_CALL();
812     std::lock_guard<std::mutex> lock(mMutex);
813 
814     // Only update layer stats if we're already tracking the layer in TimeStats.
815     // Otherwise, continue tracking the statistic but use a default layer name instead.
816     // As an implementation detail, we do this because this method is expected to be
817     // called from FrameTimeline, whose jank classification includes transaction jank
818     // that occurs without a buffer. But, in general those layer names are not suitable as
819     // aggregation keys: e.g., it's normal and expected for Window Manager to include the hash code
820     // for an animation leash. So while we can show that jank in dumpsys, aggregating based on the
821     // layer blows up the stats size, so as a workaround drop those stats. This assumes that
822     // TimeStats will flush the first present fence for a layer *before* FrameTimeline does so that
823     // the first jank record is not dropped.
824 
825     static const std::string kDefaultLayerName = "none";
826     static constexpr int32_t kDefaultGameMode = TimeStatsHelper::GameModeUnsupported;
827 
828     const int32_t refreshRateBucket =
829             clampToNearestBucket(info.refreshRate, REFRESH_RATE_BUCKET_WIDTH);
830     const int32_t renderRateBucket =
831             clampToNearestBucket(info.renderRate ? *info.renderRate : info.refreshRate,
832                                  RENDER_RATE_BUCKET_WIDTH);
833     const TimeStatsHelper::TimelineStatsKey timelineKey = {refreshRateBucket, renderRateBucket};
834 
835     if (!mTimeStats.stats.count(timelineKey)) {
836         mTimeStats.stats[timelineKey].key = timelineKey;
837     }
838 
839     TimeStatsHelper::TimelineStats& timelineStats = mTimeStats.stats[timelineKey];
840 
841     updateJankPayload<TimeStatsHelper::TimelineStats>(timelineStats, info.reasons);
842 
843     TimeStatsHelper::LayerStatsKey layerKey = {info.uid, info.layerName, info.gameMode};
844     if (!timelineStats.stats.count(layerKey)) {
845         layerKey = {info.uid, kDefaultLayerName, kDefaultGameMode};
846         timelineStats.stats[layerKey].displayRefreshRateBucket = refreshRateBucket;
847         timelineStats.stats[layerKey].renderRateBucket = renderRateBucket;
848         timelineStats.stats[layerKey].uid = info.uid;
849         timelineStats.stats[layerKey].layerName = kDefaultLayerName;
850         timelineStats.stats[layerKey].gameMode = kDefaultGameMode;
851     }
852 
853     TimeStatsHelper::TimeStatsLayer& timeStatsLayer = timelineStats.stats[layerKey];
854     updateJankPayload<TimeStatsHelper::TimeStatsLayer>(timeStatsLayer, info.reasons);
855 
856     if (info.reasons & kValidJankyReason) {
857         // TimeStats Histograms only retain positive values, so we don't need to check if these
858         // deadlines were really missed if we know that the frame had jank, since deadlines
859         // that were met will be dropped.
860         timelineStats.displayDeadlineDeltas.insert(toMs(info.displayDeadlineDelta));
861         timelineStats.displayPresentDeltas.insert(toMs(info.displayPresentJitter));
862         timeStatsLayer.deltas["appDeadlineDeltas"].insert(toMs(info.appDeadlineDelta));
863     }
864 }
865 
onDestroy(int32_t layerId)866 void TimeStats::onDestroy(int32_t layerId) {
867     ATRACE_CALL();
868     ALOGV("[%d]-onDestroy", layerId);
869     std::lock_guard<std::mutex> lock(mMutex);
870     mTimeStatsTracker.erase(layerId);
871 }
872 
removeTimeRecord(int32_t layerId,uint64_t frameNumber)873 void TimeStats::removeTimeRecord(int32_t layerId, uint64_t frameNumber) {
874     if (!mEnabled.load()) return;
875 
876     ATRACE_CALL();
877     ALOGV("[%d]-[%" PRIu64 "]-removeTimeRecord", layerId, frameNumber);
878 
879     std::lock_guard<std::mutex> lock(mMutex);
880     if (!mTimeStatsTracker.count(layerId)) return;
881     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
882     size_t removeAt = 0;
883     for (const TimeRecord& record : layerRecord.timeRecords) {
884         if (record.frameTime.frameNumber == frameNumber) break;
885         removeAt++;
886     }
887     if (removeAt == layerRecord.timeRecords.size()) return;
888     layerRecord.timeRecords.erase(layerRecord.timeRecords.begin() + removeAt);
889     if (layerRecord.waitData > static_cast<int32_t>(removeAt)) {
890         layerRecord.waitData--;
891     }
892     layerRecord.droppedFrames++;
893 }
894 
flushPowerTimeLocked()895 void TimeStats::flushPowerTimeLocked() {
896     if (!mEnabled.load()) return;
897 
898     nsecs_t curTime = systemTime();
899     // elapsedTime is in milliseconds.
900     int64_t elapsedTime = (curTime - mPowerTime.prevTime) / 1000000;
901 
902     switch (mPowerTime.powerMode) {
903         case PowerMode::ON:
904             mTimeStats.displayOnTimeLegacy += elapsedTime;
905             break;
906         case PowerMode::OFF:
907         case PowerMode::DOZE:
908         case PowerMode::DOZE_SUSPEND:
909         case PowerMode::ON_SUSPEND:
910         default:
911             break;
912     }
913 
914     mPowerTime.prevTime = curTime;
915 }
916 
setPowerMode(PowerMode powerMode)917 void TimeStats::setPowerMode(PowerMode powerMode) {
918     if (!mEnabled.load()) {
919         std::lock_guard<std::mutex> lock(mMutex);
920         mPowerTime.powerMode = powerMode;
921         return;
922     }
923 
924     std::lock_guard<std::mutex> lock(mMutex);
925     if (powerMode == mPowerTime.powerMode) return;
926 
927     flushPowerTimeLocked();
928     mPowerTime.powerMode = powerMode;
929 }
930 
recordRefreshRate(uint32_t fps,nsecs_t duration)931 void TimeStats::recordRefreshRate(uint32_t fps, nsecs_t duration) {
932     std::lock_guard<std::mutex> lock(mMutex);
933     if (mTimeStats.refreshRateStatsLegacy.count(fps)) {
934         mTimeStats.refreshRateStatsLegacy[fps] += duration;
935     } else {
936         mTimeStats.refreshRateStatsLegacy.insert({fps, duration});
937     }
938 }
939 
flushAvailableGlobalRecordsToStatsLocked()940 void TimeStats::flushAvailableGlobalRecordsToStatsLocked() {
941     ATRACE_CALL();
942 
943     while (!mGlobalRecord.presentFences.empty()) {
944         const nsecs_t curPresentTime = mGlobalRecord.presentFences.front()->getSignalTime();
945         if (curPresentTime == Fence::SIGNAL_TIME_PENDING) break;
946 
947         if (curPresentTime == Fence::SIGNAL_TIME_INVALID) {
948             ALOGE("GlobalPresentFence is invalid!");
949             mGlobalRecord.prevPresentTime = 0;
950             mGlobalRecord.presentFences.pop_front();
951             continue;
952         }
953 
954         ALOGV("GlobalPresentFenceTime[%" PRId64 "]",
955               mGlobalRecord.presentFences.front()->getSignalTime());
956 
957         if (mGlobalRecord.prevPresentTime != 0) {
958             const int32_t presentToPresentMs =
959                     msBetween(mGlobalRecord.prevPresentTime, curPresentTime);
960             ALOGV("Global present2present[%d] prev[%" PRId64 "] curr[%" PRId64 "]",
961                   presentToPresentMs, mGlobalRecord.prevPresentTime, curPresentTime);
962             mTimeStats.presentToPresentLegacy.insert(presentToPresentMs);
963         }
964 
965         mGlobalRecord.prevPresentTime = curPresentTime;
966         mGlobalRecord.presentFences.pop_front();
967     }
968     while (!mGlobalRecord.renderEngineDurations.empty()) {
969         const auto duration = mGlobalRecord.renderEngineDurations.front();
970         const auto& endTime = duration.endTime;
971 
972         nsecs_t endNs = -1;
973 
974         if (auto val = std::get_if<nsecs_t>(&endTime)) {
975             endNs = *val;
976         } else {
977             endNs = std::get<std::shared_ptr<FenceTime>>(endTime)->getSignalTime();
978         }
979 
980         if (endNs == Fence::SIGNAL_TIME_PENDING) break;
981 
982         if (endNs < 0) {
983             ALOGE("RenderEngineTiming is invalid!");
984             mGlobalRecord.renderEngineDurations.pop_front();
985             continue;
986         }
987 
988         const int32_t renderEngineMs = msBetween(duration.startTime, endNs);
989         mTimeStats.renderEngineTimingLegacy.insert(renderEngineMs);
990 
991         mGlobalRecord.renderEngineDurations.pop_front();
992     }
993 }
994 
setPresentFenceGlobal(const std::shared_ptr<FenceTime> & presentFence)995 void TimeStats::setPresentFenceGlobal(const std::shared_ptr<FenceTime>& presentFence) {
996     if (!mEnabled.load()) return;
997 
998     ATRACE_CALL();
999     std::lock_guard<std::mutex> lock(mMutex);
1000     if (presentFence == nullptr || !presentFence->isValid()) {
1001         mGlobalRecord.prevPresentTime = 0;
1002         return;
1003     }
1004 
1005     if (mPowerTime.powerMode != PowerMode::ON) {
1006         // Try flushing the last present fence on PowerMode::ON.
1007         flushAvailableGlobalRecordsToStatsLocked();
1008         mGlobalRecord.presentFences.clear();
1009         mGlobalRecord.prevPresentTime = 0;
1010         return;
1011     }
1012 
1013     if (mGlobalRecord.presentFences.size() == MAX_NUM_TIME_RECORDS) {
1014         // The front presentFence must be trapped in pending status in this
1015         // case. Try dequeuing the front one to recover.
1016         ALOGE("GlobalPresentFences is already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
1017         mGlobalRecord.prevPresentTime = 0;
1018         mGlobalRecord.presentFences.pop_front();
1019     }
1020 
1021     mGlobalRecord.presentFences.emplace_back(presentFence);
1022     flushAvailableGlobalRecordsToStatsLocked();
1023 }
1024 
enable()1025 void TimeStats::enable() {
1026     if (mEnabled.load()) return;
1027 
1028     ATRACE_CALL();
1029 
1030     std::lock_guard<std::mutex> lock(mMutex);
1031     mEnabled.store(true);
1032     mTimeStats.statsStartLegacy = static_cast<int64_t>(std::time(0));
1033     mPowerTime.prevTime = systemTime();
1034     ALOGD("Enabled");
1035 }
1036 
disable()1037 void TimeStats::disable() {
1038     if (!mEnabled.load()) return;
1039 
1040     ATRACE_CALL();
1041 
1042     std::lock_guard<std::mutex> lock(mMutex);
1043     flushPowerTimeLocked();
1044     mEnabled.store(false);
1045     mTimeStats.statsEndLegacy = static_cast<int64_t>(std::time(0));
1046     ALOGD("Disabled");
1047 }
1048 
clearAll()1049 void TimeStats::clearAll() {
1050     std::lock_guard<std::mutex> lock(mMutex);
1051     mTimeStats.stats.clear();
1052     clearGlobalLocked();
1053     clearLayersLocked();
1054 }
1055 
clearGlobalLocked()1056 void TimeStats::clearGlobalLocked() {
1057     ATRACE_CALL();
1058 
1059     mTimeStats.statsStartLegacy = (mEnabled.load() ? static_cast<int64_t>(std::time(0)) : 0);
1060     mTimeStats.statsEndLegacy = 0;
1061     mTimeStats.totalFramesLegacy = 0;
1062     mTimeStats.missedFramesLegacy = 0;
1063     mTimeStats.clientCompositionFramesLegacy = 0;
1064     mTimeStats.clientCompositionReusedFramesLegacy = 0;
1065     mTimeStats.refreshRateSwitchesLegacy = 0;
1066     mTimeStats.compositionStrategyChangesLegacy = 0;
1067     mTimeStats.displayEventConnectionsCountLegacy = 0;
1068     mTimeStats.displayOnTimeLegacy = 0;
1069     mTimeStats.presentToPresentLegacy.hist.clear();
1070     mTimeStats.frameDurationLegacy.hist.clear();
1071     mTimeStats.renderEngineTimingLegacy.hist.clear();
1072     mTimeStats.refreshRateStatsLegacy.clear();
1073     mPowerTime.prevTime = systemTime();
1074     for (auto& globalRecord : mTimeStats.stats) {
1075         globalRecord.second.clearGlobals();
1076     }
1077     mGlobalRecord.prevPresentTime = 0;
1078     mGlobalRecord.presentFences.clear();
1079     ALOGD("Cleared global stats");
1080 }
1081 
clearLayersLocked()1082 void TimeStats::clearLayersLocked() {
1083     ATRACE_CALL();
1084 
1085     mTimeStatsTracker.clear();
1086 
1087     for (auto& globalRecord : mTimeStats.stats) {
1088         globalRecord.second.stats.clear();
1089     }
1090     ALOGD("Cleared layer stats");
1091 }
1092 
isEnabled()1093 bool TimeStats::isEnabled() {
1094     return mEnabled.load();
1095 }
1096 
dump(bool asProto,std::optional<uint32_t> maxLayers,std::string & result)1097 void TimeStats::dump(bool asProto, std::optional<uint32_t> maxLayers, std::string& result) {
1098     ATRACE_CALL();
1099 
1100     std::lock_guard<std::mutex> lock(mMutex);
1101     if (mTimeStats.statsStartLegacy == 0) {
1102         return;
1103     }
1104 
1105     mTimeStats.statsEndLegacy = static_cast<int64_t>(std::time(0));
1106 
1107     flushPowerTimeLocked();
1108 
1109     if (asProto) {
1110         ALOGD("Dumping TimeStats as proto");
1111         SFTimeStatsGlobalProto timeStatsProto = mTimeStats.toProto(maxLayers);
1112         result.append(timeStatsProto.SerializeAsString());
1113     } else {
1114         ALOGD("Dumping TimeStats as text");
1115         result.append(mTimeStats.toString(maxLayers));
1116         result.append("\n");
1117     }
1118 }
1119 
1120 } // namespace impl
1121 
1122 } // namespace android
1123