• 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 #undef LOG_TAG
18 #define LOG_TAG "TimeStats"
19 #define ATRACE_TAG ATRACE_TAG_GRAPHICS
20 
21 #include <android-base/stringprintf.h>
22 #include <log/log.h>
23 #include <timestatsatomsproto/TimeStatsAtomsProtoHeader.h>
24 #include <utils/String8.h>
25 #include <utils/Timers.h>
26 #include <utils/Trace.h>
27 
28 #include <algorithm>
29 #include <chrono>
30 #include <unordered_map>
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(GameMode gameMode)61 SurfaceflingerStatsLayerInfo_GameMode gameModeToProto(GameMode gameMode) {
62     switch (gameMode) {
63         case GameMode::Unsupported:
64             return SurfaceflingerStatsLayerInfo::GAME_MODE_UNSUPPORTED;
65         case GameMode::Standard:
66             return SurfaceflingerStatsLayerInfo::GAME_MODE_STANDARD;
67         case GameMode::Performance:
68             return SurfaceflingerStatsLayerInfo::GAME_MODE_PERFORMANCE;
69         case GameMode::Battery:
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 
pushCompositionStrategyState(const TimeStats::ClientCompositionRecord & record)324 void TimeStats::pushCompositionStrategyState(const TimeStats::ClientCompositionRecord& record) {
325     if (!mEnabled.load() || !record.hasInterestingData()) {
326         return;
327     }
328 
329     ATRACE_CALL();
330 
331     std::lock_guard<std::mutex> lock(mMutex);
332     if (record.changed) mTimeStats.compositionStrategyChangesLegacy++;
333     if (record.hadClientComposition) mTimeStats.clientCompositionFramesLegacy++;
334     if (record.reused) mTimeStats.clientCompositionReusedFramesLegacy++;
335     if (record.predicted) mTimeStats.compositionStrategyPredictedLegacy++;
336     if (record.predictionSucceeded) mTimeStats.compositionStrategyPredictionSucceededLegacy++;
337 }
338 
incrementRefreshRateSwitches()339 void TimeStats::incrementRefreshRateSwitches() {
340     if (!mEnabled.load()) return;
341 
342     ATRACE_CALL();
343 
344     std::lock_guard<std::mutex> lock(mMutex);
345     mTimeStats.refreshRateSwitchesLegacy++;
346 }
347 
recordDisplayEventConnectionCount(int32_t count)348 void TimeStats::recordDisplayEventConnectionCount(int32_t count) {
349     if (!mEnabled.load()) return;
350 
351     ATRACE_CALL();
352 
353     std::lock_guard<std::mutex> lock(mMutex);
354     mTimeStats.displayEventConnectionsCountLegacy =
355             std::max(mTimeStats.displayEventConnectionsCountLegacy, count);
356 }
357 
toMs(nsecs_t nanos)358 static int32_t toMs(nsecs_t nanos) {
359     int64_t millis =
360             std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::nanoseconds(nanos))
361                     .count();
362     millis = std::clamp(millis, int64_t(INT32_MIN), int64_t(INT32_MAX));
363     return static_cast<int32_t>(millis);
364 }
365 
msBetween(nsecs_t start,nsecs_t end)366 static int32_t msBetween(nsecs_t start, nsecs_t end) {
367     return toMs(end - start);
368 }
369 
recordFrameDuration(nsecs_t startTime,nsecs_t endTime)370 void TimeStats::recordFrameDuration(nsecs_t startTime, nsecs_t endTime) {
371     if (!mEnabled.load()) return;
372 
373     std::lock_guard<std::mutex> lock(mMutex);
374     if (mPowerTime.powerMode == PowerMode::ON) {
375         mTimeStats.frameDurationLegacy.insert(msBetween(startTime, endTime));
376     }
377 }
378 
recordRenderEngineDuration(nsecs_t startTime,nsecs_t endTime)379 void TimeStats::recordRenderEngineDuration(nsecs_t startTime, nsecs_t endTime) {
380     if (!mEnabled.load()) return;
381 
382     std::lock_guard<std::mutex> lock(mMutex);
383     if (mGlobalRecord.renderEngineDurations.size() == MAX_NUM_TIME_RECORDS) {
384         ALOGE("RenderEngineTimes are already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
385         mGlobalRecord.renderEngineDurations.pop_front();
386     }
387     mGlobalRecord.renderEngineDurations.push_back({startTime, endTime});
388 }
389 
recordRenderEngineDuration(nsecs_t startTime,const std::shared_ptr<FenceTime> & endTime)390 void TimeStats::recordRenderEngineDuration(nsecs_t startTime,
391                                            const std::shared_ptr<FenceTime>& 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 
recordReadyLocked(int32_t layerId,TimeRecord * timeRecord)402 bool TimeStats::recordReadyLocked(int32_t layerId, TimeRecord* timeRecord) {
403     if (!timeRecord->ready) {
404         ALOGV("[%d]-[%" PRIu64 "]-presentFence is still not received", layerId,
405               timeRecord->frameTime.frameNumber);
406         return false;
407     }
408 
409     if (timeRecord->acquireFence != nullptr) {
410         if (timeRecord->acquireFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
411             return false;
412         }
413         if (timeRecord->acquireFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
414             timeRecord->frameTime.acquireTime = timeRecord->acquireFence->getSignalTime();
415             timeRecord->acquireFence = nullptr;
416         } else {
417             ALOGV("[%d]-[%" PRIu64 "]-acquireFence signal time is invalid", layerId,
418                   timeRecord->frameTime.frameNumber);
419         }
420     }
421 
422     if (timeRecord->presentFence != nullptr) {
423         if (timeRecord->presentFence->getSignalTime() == Fence::SIGNAL_TIME_PENDING) {
424             return false;
425         }
426         if (timeRecord->presentFence->getSignalTime() != Fence::SIGNAL_TIME_INVALID) {
427             timeRecord->frameTime.presentTime = timeRecord->presentFence->getSignalTime();
428             timeRecord->presentFence = nullptr;
429         } else {
430             ALOGV("[%d]-[%" PRIu64 "]-presentFence signal time invalid", layerId,
431                   timeRecord->frameTime.frameNumber);
432         }
433     }
434 
435     return true;
436 }
437 
clampToNearestBucket(Fps fps,size_t bucketWidth)438 static int32_t clampToNearestBucket(Fps fps, size_t bucketWidth) {
439     return std::round(fps.getValue() / bucketWidth) * bucketWidth;
440 }
441 
flushAvailableRecordsToStatsLocked(int32_t layerId,Fps displayRefreshRate,std::optional<Fps> renderRate,SetFrameRateVote frameRateVote,GameMode gameMode)442 void TimeStats::flushAvailableRecordsToStatsLocked(int32_t layerId, Fps displayRefreshRate,
443                                                    std::optional<Fps> renderRate,
444                                                    SetFrameRateVote frameRateVote,
445                                                    GameMode gameMode) {
446     ATRACE_CALL();
447     ALOGV("[%d]-flushAvailableRecordsToStatsLocked", layerId);
448 
449     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
450     TimeRecord& prevTimeRecord = layerRecord.prevTimeRecord;
451     std::deque<TimeRecord>& timeRecords = layerRecord.timeRecords;
452     const int32_t refreshRateBucket =
453             clampToNearestBucket(displayRefreshRate, REFRESH_RATE_BUCKET_WIDTH);
454     const int32_t renderRateBucket =
455             clampToNearestBucket(renderRate ? *renderRate : displayRefreshRate,
456                                  RENDER_RATE_BUCKET_WIDTH);
457     while (!timeRecords.empty()) {
458         if (!recordReadyLocked(layerId, &timeRecords[0])) break;
459         ALOGV("[%d]-[%" PRIu64 "]-presentFenceTime[%" PRId64 "]", layerId,
460               timeRecords[0].frameTime.frameNumber, timeRecords[0].frameTime.presentTime);
461 
462         if (prevTimeRecord.ready) {
463             uid_t uid = layerRecord.uid;
464             const std::string& layerName = layerRecord.layerName;
465             TimeStatsHelper::TimelineStatsKey timelineKey = {refreshRateBucket, renderRateBucket};
466             if (!mTimeStats.stats.count(timelineKey)) {
467                 mTimeStats.stats[timelineKey].key = timelineKey;
468             }
469 
470             TimeStatsHelper::TimelineStats& displayStats = mTimeStats.stats[timelineKey];
471 
472             TimeStatsHelper::LayerStatsKey layerKey = {uid, layerName, gameMode};
473             if (!displayStats.stats.count(layerKey)) {
474                 displayStats.stats[layerKey].displayRefreshRateBucket = refreshRateBucket;
475                 displayStats.stats[layerKey].renderRateBucket = renderRateBucket;
476                 displayStats.stats[layerKey].uid = uid;
477                 displayStats.stats[layerKey].layerName = layerName;
478                 displayStats.stats[layerKey].gameMode = gameMode;
479             }
480             if (frameRateVote.frameRate > 0.0f) {
481                 displayStats.stats[layerKey].setFrameRateVote = frameRateVote;
482             }
483             TimeStatsHelper::TimeStatsLayer& timeStatsLayer = displayStats.stats[layerKey];
484             timeStatsLayer.totalFrames++;
485             timeStatsLayer.droppedFrames += layerRecord.droppedFrames;
486             timeStatsLayer.lateAcquireFrames += layerRecord.lateAcquireFrames;
487             timeStatsLayer.badDesiredPresentFrames += layerRecord.badDesiredPresentFrames;
488 
489             layerRecord.droppedFrames = 0;
490             layerRecord.lateAcquireFrames = 0;
491             layerRecord.badDesiredPresentFrames = 0;
492 
493             const int32_t postToAcquireMs = msBetween(timeRecords[0].frameTime.postTime,
494                                                       timeRecords[0].frameTime.acquireTime);
495             ALOGV("[%d]-[%" PRIu64 "]-post2acquire[%d]", layerId,
496                   timeRecords[0].frameTime.frameNumber, postToAcquireMs);
497             timeStatsLayer.deltas["post2acquire"].insert(postToAcquireMs);
498 
499             const int32_t postToPresentMs = msBetween(timeRecords[0].frameTime.postTime,
500                                                       timeRecords[0].frameTime.presentTime);
501             ALOGV("[%d]-[%" PRIu64 "]-post2present[%d]", layerId,
502                   timeRecords[0].frameTime.frameNumber, postToPresentMs);
503             timeStatsLayer.deltas["post2present"].insert(postToPresentMs);
504 
505             const int32_t acquireToPresentMs = msBetween(timeRecords[0].frameTime.acquireTime,
506                                                          timeRecords[0].frameTime.presentTime);
507             ALOGV("[%d]-[%" PRIu64 "]-acquire2present[%d]", layerId,
508                   timeRecords[0].frameTime.frameNumber, acquireToPresentMs);
509             timeStatsLayer.deltas["acquire2present"].insert(acquireToPresentMs);
510 
511             const int32_t latchToPresentMs = msBetween(timeRecords[0].frameTime.latchTime,
512                                                        timeRecords[0].frameTime.presentTime);
513             ALOGV("[%d]-[%" PRIu64 "]-latch2present[%d]", layerId,
514                   timeRecords[0].frameTime.frameNumber, latchToPresentMs);
515             timeStatsLayer.deltas["latch2present"].insert(latchToPresentMs);
516 
517             const int32_t desiredToPresentMs = msBetween(timeRecords[0].frameTime.desiredTime,
518                                                          timeRecords[0].frameTime.presentTime);
519             ALOGV("[%d]-[%" PRIu64 "]-desired2present[%d]", layerId,
520                   timeRecords[0].frameTime.frameNumber, desiredToPresentMs);
521             timeStatsLayer.deltas["desired2present"].insert(desiredToPresentMs);
522 
523             const int32_t presentToPresentMs = msBetween(prevTimeRecord.frameTime.presentTime,
524                                                          timeRecords[0].frameTime.presentTime);
525             ALOGV("[%d]-[%" PRIu64 "]-present2present[%d]", layerId,
526                   timeRecords[0].frameTime.frameNumber, presentToPresentMs);
527             timeStatsLayer.deltas["present2present"].insert(presentToPresentMs);
528         }
529         prevTimeRecord = timeRecords[0];
530         timeRecords.pop_front();
531         layerRecord.waitData--;
532     }
533 }
534 
535 static constexpr const char* kPopupWindowPrefix = "PopupWindow";
536 static const size_t kMinLenLayerName = std::strlen(kPopupWindowPrefix);
537 
538 // Avoid tracking the "PopupWindow:<random hash>#<number>" layers
layerNameIsValid(const std::string & layerName)539 static bool layerNameIsValid(const std::string& layerName) {
540     return layerName.length() >= kMinLenLayerName &&
541             layerName.compare(0, kMinLenLayerName, kPopupWindowPrefix) != 0;
542 }
543 
canAddNewAggregatedStats(uid_t uid,const std::string & layerName,GameMode gameMode)544 bool TimeStats::canAddNewAggregatedStats(uid_t uid, const std::string& layerName,
545                                          GameMode gameMode) {
546     uint32_t layerRecords = 0;
547     for (const auto& record : mTimeStats.stats) {
548         if (record.second.stats.count({uid, layerName, gameMode}) > 0) {
549             return true;
550         }
551 
552         layerRecords += record.second.stats.size();
553     }
554 
555     return layerRecords < MAX_NUM_LAYER_STATS;
556 }
557 
setPostTime(int32_t layerId,uint64_t frameNumber,const std::string & layerName,uid_t uid,nsecs_t postTime,GameMode gameMode)558 void TimeStats::setPostTime(int32_t layerId, uint64_t frameNumber, const std::string& layerName,
559                             uid_t uid, nsecs_t postTime, GameMode gameMode) {
560     if (!mEnabled.load()) return;
561 
562     ATRACE_CALL();
563     ALOGV("[%d]-[%" PRIu64 "]-[%s]-PostTime[%" PRId64 "]", layerId, frameNumber, layerName.c_str(),
564           postTime);
565 
566     std::lock_guard<std::mutex> lock(mMutex);
567     if (!canAddNewAggregatedStats(uid, layerName, gameMode)) {
568         return;
569     }
570     if (!mTimeStatsTracker.count(layerId) && mTimeStatsTracker.size() < MAX_NUM_LAYER_RECORDS &&
571         layerNameIsValid(layerName)) {
572         mTimeStatsTracker[layerId].uid = uid;
573         mTimeStatsTracker[layerId].layerName = layerName;
574         mTimeStatsTracker[layerId].gameMode = gameMode;
575     }
576     if (!mTimeStatsTracker.count(layerId)) return;
577     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
578     if (layerRecord.timeRecords.size() == MAX_NUM_TIME_RECORDS) {
579         ALOGE("[%d]-[%s]-timeRecords is at its maximum size[%zu]. Ignore this when unittesting.",
580               layerId, layerRecord.layerName.c_str(), MAX_NUM_TIME_RECORDS);
581         mTimeStatsTracker.erase(layerId);
582         return;
583     }
584     // For most media content, the acquireFence is invalid because the buffer is
585     // ready at the queueBuffer stage. In this case, acquireTime should be given
586     // a default value as postTime.
587     TimeRecord timeRecord = {
588             .frameTime =
589                     {
590                             .frameNumber = frameNumber,
591                             .postTime = postTime,
592                             .latchTime = postTime,
593                             .acquireTime = postTime,
594                             .desiredTime = postTime,
595                     },
596     };
597     layerRecord.timeRecords.push_back(timeRecord);
598     if (layerRecord.waitData < 0 ||
599         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
600         layerRecord.waitData = layerRecord.timeRecords.size() - 1;
601 }
602 
setLatchTime(int32_t layerId,uint64_t frameNumber,nsecs_t latchTime)603 void TimeStats::setLatchTime(int32_t layerId, uint64_t frameNumber, nsecs_t latchTime) {
604     if (!mEnabled.load()) return;
605 
606     ATRACE_CALL();
607     ALOGV("[%d]-[%" PRIu64 "]-LatchTime[%" PRId64 "]", layerId, frameNumber, latchTime);
608 
609     std::lock_guard<std::mutex> lock(mMutex);
610     if (!mTimeStatsTracker.count(layerId)) return;
611     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
612     if (layerRecord.waitData < 0 ||
613         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
614         return;
615     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
616     if (timeRecord.frameTime.frameNumber == frameNumber) {
617         timeRecord.frameTime.latchTime = latchTime;
618     }
619 }
620 
incrementLatchSkipped(int32_t layerId,LatchSkipReason reason)621 void TimeStats::incrementLatchSkipped(int32_t layerId, LatchSkipReason reason) {
622     if (!mEnabled.load()) return;
623 
624     ATRACE_CALL();
625     ALOGV("[%d]-LatchSkipped-Reason[%d]", layerId,
626           static_cast<std::underlying_type<LatchSkipReason>::type>(reason));
627 
628     std::lock_guard<std::mutex> lock(mMutex);
629     if (!mTimeStatsTracker.count(layerId)) return;
630     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
631 
632     switch (reason) {
633         case LatchSkipReason::LateAcquire:
634             layerRecord.lateAcquireFrames++;
635             break;
636     }
637 }
638 
incrementBadDesiredPresent(int32_t layerId)639 void TimeStats::incrementBadDesiredPresent(int32_t layerId) {
640     if (!mEnabled.load()) return;
641 
642     ATRACE_CALL();
643     ALOGV("[%d]-BadDesiredPresent", layerId);
644 
645     std::lock_guard<std::mutex> lock(mMutex);
646     if (!mTimeStatsTracker.count(layerId)) return;
647     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
648     layerRecord.badDesiredPresentFrames++;
649 }
650 
setDesiredTime(int32_t layerId,uint64_t frameNumber,nsecs_t desiredTime)651 void TimeStats::setDesiredTime(int32_t layerId, uint64_t frameNumber, nsecs_t desiredTime) {
652     if (!mEnabled.load()) return;
653 
654     ATRACE_CALL();
655     ALOGV("[%d]-[%" PRIu64 "]-DesiredTime[%" PRId64 "]", layerId, frameNumber, desiredTime);
656 
657     std::lock_guard<std::mutex> lock(mMutex);
658     if (!mTimeStatsTracker.count(layerId)) return;
659     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
660     if (layerRecord.waitData < 0 ||
661         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
662         return;
663     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
664     if (timeRecord.frameTime.frameNumber == frameNumber) {
665         timeRecord.frameTime.desiredTime = desiredTime;
666     }
667 }
668 
setAcquireTime(int32_t layerId,uint64_t frameNumber,nsecs_t acquireTime)669 void TimeStats::setAcquireTime(int32_t layerId, uint64_t frameNumber, nsecs_t acquireTime) {
670     if (!mEnabled.load()) return;
671 
672     ATRACE_CALL();
673     ALOGV("[%d]-[%" PRIu64 "]-AcquireTime[%" PRId64 "]", layerId, frameNumber, acquireTime);
674 
675     std::lock_guard<std::mutex> lock(mMutex);
676     if (!mTimeStatsTracker.count(layerId)) return;
677     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
678     if (layerRecord.waitData < 0 ||
679         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
680         return;
681     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
682     if (timeRecord.frameTime.frameNumber == frameNumber) {
683         timeRecord.frameTime.acquireTime = acquireTime;
684     }
685 }
686 
setAcquireFence(int32_t layerId,uint64_t frameNumber,const std::shared_ptr<FenceTime> & acquireFence)687 void TimeStats::setAcquireFence(int32_t layerId, uint64_t frameNumber,
688                                 const std::shared_ptr<FenceTime>& acquireFence) {
689     if (!mEnabled.load()) return;
690 
691     ATRACE_CALL();
692     ALOGV("[%d]-[%" PRIu64 "]-AcquireFenceTime[%" PRId64 "]", layerId, frameNumber,
693           acquireFence->getSignalTime());
694 
695     std::lock_guard<std::mutex> lock(mMutex);
696     if (!mTimeStatsTracker.count(layerId)) return;
697     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
698     if (layerRecord.waitData < 0 ||
699         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
700         return;
701     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
702     if (timeRecord.frameTime.frameNumber == frameNumber) {
703         timeRecord.acquireFence = acquireFence;
704     }
705 }
706 
setPresentTime(int32_t layerId,uint64_t frameNumber,nsecs_t presentTime,Fps displayRefreshRate,std::optional<Fps> renderRate,SetFrameRateVote frameRateVote,GameMode gameMode)707 void TimeStats::setPresentTime(int32_t layerId, uint64_t frameNumber, nsecs_t presentTime,
708                                Fps displayRefreshRate, std::optional<Fps> renderRate,
709                                SetFrameRateVote frameRateVote, GameMode gameMode) {
710     if (!mEnabled.load()) return;
711 
712     ATRACE_CALL();
713     ALOGV("[%d]-[%" PRIu64 "]-PresentTime[%" PRId64 "]", layerId, frameNumber, presentTime);
714 
715     std::lock_guard<std::mutex> lock(mMutex);
716     if (!mTimeStatsTracker.count(layerId)) return;
717     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
718     if (layerRecord.waitData < 0 ||
719         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
720         return;
721     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
722     if (timeRecord.frameTime.frameNumber == frameNumber) {
723         timeRecord.frameTime.presentTime = presentTime;
724         timeRecord.ready = true;
725         layerRecord.waitData++;
726     }
727 
728     flushAvailableRecordsToStatsLocked(layerId, displayRefreshRate, renderRate, frameRateVote,
729                                        gameMode);
730 }
731 
setPresentFence(int32_t layerId,uint64_t frameNumber,const std::shared_ptr<FenceTime> & presentFence,Fps displayRefreshRate,std::optional<Fps> renderRate,SetFrameRateVote frameRateVote,GameMode gameMode)732 void TimeStats::setPresentFence(int32_t layerId, uint64_t frameNumber,
733                                 const std::shared_ptr<FenceTime>& presentFence,
734                                 Fps displayRefreshRate, std::optional<Fps> renderRate,
735                                 SetFrameRateVote frameRateVote, GameMode gameMode) {
736     if (!mEnabled.load()) return;
737 
738     ATRACE_CALL();
739     ALOGV("[%d]-[%" PRIu64 "]-PresentFenceTime[%" PRId64 "]", layerId, frameNumber,
740           presentFence->getSignalTime());
741 
742     std::lock_guard<std::mutex> lock(mMutex);
743     if (!mTimeStatsTracker.count(layerId)) return;
744     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
745     if (layerRecord.waitData < 0 ||
746         layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
747         return;
748     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
749     if (timeRecord.frameTime.frameNumber == frameNumber) {
750         timeRecord.presentFence = presentFence;
751         timeRecord.ready = true;
752         layerRecord.waitData++;
753     }
754 
755     flushAvailableRecordsToStatsLocked(layerId, displayRefreshRate, renderRate, frameRateVote,
756                                        gameMode);
757 }
758 
759 static const constexpr int32_t kValidJankyReason = JankType::DisplayHAL |
760         JankType::SurfaceFlingerCpuDeadlineMissed | JankType::SurfaceFlingerGpuDeadlineMissed |
761         JankType::AppDeadlineMissed | JankType::PredictionError |
762         JankType::SurfaceFlingerScheduling;
763 
764 template <class T>
updateJankPayload(T & t,int32_t reasons)765 static void updateJankPayload(T& t, int32_t reasons) {
766     t.jankPayload.totalFrames++;
767 
768     if (reasons & kValidJankyReason) {
769         t.jankPayload.totalJankyFrames++;
770         if ((reasons & JankType::SurfaceFlingerCpuDeadlineMissed) != 0) {
771             t.jankPayload.totalSFLongCpu++;
772         }
773         if ((reasons & JankType::SurfaceFlingerGpuDeadlineMissed) != 0) {
774             t.jankPayload.totalSFLongGpu++;
775         }
776         if ((reasons & JankType::DisplayHAL) != 0) {
777             t.jankPayload.totalSFUnattributed++;
778         }
779         if ((reasons & JankType::AppDeadlineMissed) != 0) {
780             t.jankPayload.totalAppUnattributed++;
781         }
782         if ((reasons & JankType::PredictionError) != 0) {
783             t.jankPayload.totalSFPredictionError++;
784         }
785         if ((reasons & JankType::SurfaceFlingerScheduling) != 0) {
786             t.jankPayload.totalSFScheduling++;
787         }
788     }
789 
790     // We want to track BufferStuffing separately as it can provide info on latency issues
791     if (reasons & JankType::BufferStuffing) {
792         t.jankPayload.totalAppBufferStuffing++;
793     }
794 }
795 
incrementJankyFrames(const JankyFramesInfo & info)796 void TimeStats::incrementJankyFrames(const JankyFramesInfo& info) {
797     if (!mEnabled.load()) return;
798 
799     ATRACE_CALL();
800     std::lock_guard<std::mutex> lock(mMutex);
801 
802     // Only update layer stats if we're already tracking the layer in TimeStats.
803     // Otherwise, continue tracking the statistic but use a default layer name instead.
804     // As an implementation detail, we do this because this method is expected to be
805     // called from FrameTimeline, whose jank classification includes transaction jank
806     // that occurs without a buffer. But, in general those layer names are not suitable as
807     // aggregation keys: e.g., it's normal and expected for Window Manager to include the hash code
808     // for an animation leash. So while we can show that jank in dumpsys, aggregating based on the
809     // layer blows up the stats size, so as a workaround drop those stats. This assumes that
810     // TimeStats will flush the first present fence for a layer *before* FrameTimeline does so that
811     // the first jank record is not dropped.
812 
813     static const std::string kDefaultLayerName = "none";
814     constexpr GameMode kDefaultGameMode = GameMode::Unsupported;
815 
816     const int32_t refreshRateBucket =
817             clampToNearestBucket(info.refreshRate, REFRESH_RATE_BUCKET_WIDTH);
818     const int32_t renderRateBucket =
819             clampToNearestBucket(info.renderRate ? *info.renderRate : info.refreshRate,
820                                  RENDER_RATE_BUCKET_WIDTH);
821     const TimeStatsHelper::TimelineStatsKey timelineKey = {refreshRateBucket, renderRateBucket};
822 
823     if (!mTimeStats.stats.count(timelineKey)) {
824         mTimeStats.stats[timelineKey].key = timelineKey;
825     }
826 
827     TimeStatsHelper::TimelineStats& timelineStats = mTimeStats.stats[timelineKey];
828 
829     updateJankPayload<TimeStatsHelper::TimelineStats>(timelineStats, info.reasons);
830 
831     TimeStatsHelper::LayerStatsKey layerKey = {info.uid, info.layerName, info.gameMode};
832     if (!timelineStats.stats.count(layerKey)) {
833         layerKey = {info.uid, kDefaultLayerName, kDefaultGameMode};
834         timelineStats.stats[layerKey].displayRefreshRateBucket = refreshRateBucket;
835         timelineStats.stats[layerKey].renderRateBucket = renderRateBucket;
836         timelineStats.stats[layerKey].uid = info.uid;
837         timelineStats.stats[layerKey].layerName = kDefaultLayerName;
838         timelineStats.stats[layerKey].gameMode = kDefaultGameMode;
839     }
840 
841     TimeStatsHelper::TimeStatsLayer& timeStatsLayer = timelineStats.stats[layerKey];
842     updateJankPayload<TimeStatsHelper::TimeStatsLayer>(timeStatsLayer, info.reasons);
843 
844     if (info.reasons & kValidJankyReason) {
845         // TimeStats Histograms only retain positive values, so we don't need to check if these
846         // deadlines were really missed if we know that the frame had jank, since deadlines
847         // that were met will be dropped.
848         timelineStats.displayDeadlineDeltas.insert(toMs(info.displayDeadlineDelta));
849         timelineStats.displayPresentDeltas.insert(toMs(info.displayPresentJitter));
850         timeStatsLayer.deltas["appDeadlineDeltas"].insert(toMs(info.appDeadlineDelta));
851     }
852 }
853 
onDestroy(int32_t layerId)854 void TimeStats::onDestroy(int32_t layerId) {
855     ATRACE_CALL();
856     ALOGV("[%d]-onDestroy", layerId);
857     std::lock_guard<std::mutex> lock(mMutex);
858     mTimeStatsTracker.erase(layerId);
859 }
860 
removeTimeRecord(int32_t layerId,uint64_t frameNumber)861 void TimeStats::removeTimeRecord(int32_t layerId, uint64_t frameNumber) {
862     if (!mEnabled.load()) return;
863 
864     ATRACE_CALL();
865     ALOGV("[%d]-[%" PRIu64 "]-removeTimeRecord", layerId, frameNumber);
866 
867     std::lock_guard<std::mutex> lock(mMutex);
868     if (!mTimeStatsTracker.count(layerId)) return;
869     LayerRecord& layerRecord = mTimeStatsTracker[layerId];
870     size_t removeAt = 0;
871     for (const TimeRecord& record : layerRecord.timeRecords) {
872         if (record.frameTime.frameNumber == frameNumber) break;
873         removeAt++;
874     }
875     if (removeAt == layerRecord.timeRecords.size()) return;
876     layerRecord.timeRecords.erase(layerRecord.timeRecords.begin() + removeAt);
877     if (layerRecord.waitData > static_cast<int32_t>(removeAt)) {
878         layerRecord.waitData--;
879     }
880     layerRecord.droppedFrames++;
881 }
882 
flushPowerTimeLocked()883 void TimeStats::flushPowerTimeLocked() {
884     if (!mEnabled.load()) return;
885 
886     nsecs_t curTime = systemTime();
887     // elapsedTime is in milliseconds.
888     int64_t elapsedTime = (curTime - mPowerTime.prevTime) / 1000000;
889 
890     switch (mPowerTime.powerMode) {
891         case PowerMode::ON:
892             mTimeStats.displayOnTimeLegacy += elapsedTime;
893             break;
894         case PowerMode::OFF:
895         case PowerMode::DOZE:
896         case PowerMode::DOZE_SUSPEND:
897         case PowerMode::ON_SUSPEND:
898         default:
899             break;
900     }
901 
902     mPowerTime.prevTime = curTime;
903 }
904 
setPowerMode(PowerMode powerMode)905 void TimeStats::setPowerMode(PowerMode powerMode) {
906     if (!mEnabled.load()) {
907         std::lock_guard<std::mutex> lock(mMutex);
908         mPowerTime.powerMode = powerMode;
909         return;
910     }
911 
912     std::lock_guard<std::mutex> lock(mMutex);
913     if (powerMode == mPowerTime.powerMode) return;
914 
915     flushPowerTimeLocked();
916     mPowerTime.powerMode = powerMode;
917 }
918 
recordRefreshRate(uint32_t fps,nsecs_t duration)919 void TimeStats::recordRefreshRate(uint32_t fps, nsecs_t duration) {
920     std::lock_guard<std::mutex> lock(mMutex);
921     if (mTimeStats.refreshRateStatsLegacy.count(fps)) {
922         mTimeStats.refreshRateStatsLegacy[fps] += duration;
923     } else {
924         mTimeStats.refreshRateStatsLegacy.insert({fps, duration});
925     }
926 }
927 
flushAvailableGlobalRecordsToStatsLocked()928 void TimeStats::flushAvailableGlobalRecordsToStatsLocked() {
929     ATRACE_CALL();
930 
931     while (!mGlobalRecord.presentFences.empty()) {
932         const nsecs_t curPresentTime = mGlobalRecord.presentFences.front()->getSignalTime();
933         if (curPresentTime == Fence::SIGNAL_TIME_PENDING) break;
934 
935         if (curPresentTime == Fence::SIGNAL_TIME_INVALID) {
936             ALOGE("GlobalPresentFence is invalid!");
937             mGlobalRecord.prevPresentTime = 0;
938             mGlobalRecord.presentFences.pop_front();
939             continue;
940         }
941 
942         ALOGV("GlobalPresentFenceTime[%" PRId64 "]",
943               mGlobalRecord.presentFences.front()->getSignalTime());
944 
945         if (mGlobalRecord.prevPresentTime != 0) {
946             const int32_t presentToPresentMs =
947                     msBetween(mGlobalRecord.prevPresentTime, curPresentTime);
948             ALOGV("Global present2present[%d] prev[%" PRId64 "] curr[%" PRId64 "]",
949                   presentToPresentMs, mGlobalRecord.prevPresentTime, curPresentTime);
950             mTimeStats.presentToPresentLegacy.insert(presentToPresentMs);
951         }
952 
953         mGlobalRecord.prevPresentTime = curPresentTime;
954         mGlobalRecord.presentFences.pop_front();
955     }
956     while (!mGlobalRecord.renderEngineDurations.empty()) {
957         const auto duration = mGlobalRecord.renderEngineDurations.front();
958         const auto& endTime = duration.endTime;
959 
960         nsecs_t endNs = -1;
961 
962         if (auto val = std::get_if<nsecs_t>(&endTime)) {
963             endNs = *val;
964         } else {
965             endNs = std::get<std::shared_ptr<FenceTime>>(endTime)->getSignalTime();
966         }
967 
968         if (endNs == Fence::SIGNAL_TIME_PENDING) break;
969 
970         if (endNs < 0) {
971             ALOGE("RenderEngineTiming is invalid!");
972             mGlobalRecord.renderEngineDurations.pop_front();
973             continue;
974         }
975 
976         const int32_t renderEngineMs = msBetween(duration.startTime, endNs);
977         mTimeStats.renderEngineTimingLegacy.insert(renderEngineMs);
978 
979         mGlobalRecord.renderEngineDurations.pop_front();
980     }
981 }
982 
setPresentFenceGlobal(const std::shared_ptr<FenceTime> & presentFence)983 void TimeStats::setPresentFenceGlobal(const std::shared_ptr<FenceTime>& presentFence) {
984     if (!mEnabled.load()) return;
985 
986     ATRACE_CALL();
987     std::lock_guard<std::mutex> lock(mMutex);
988     if (presentFence == nullptr || !presentFence->isValid()) {
989         mGlobalRecord.prevPresentTime = 0;
990         return;
991     }
992 
993     if (mPowerTime.powerMode != PowerMode::ON) {
994         // Try flushing the last present fence on PowerMode::ON.
995         flushAvailableGlobalRecordsToStatsLocked();
996         mGlobalRecord.presentFences.clear();
997         mGlobalRecord.prevPresentTime = 0;
998         return;
999     }
1000 
1001     if (mGlobalRecord.presentFences.size() == MAX_NUM_TIME_RECORDS) {
1002         // The front presentFence must be trapped in pending status in this
1003         // case. Try dequeuing the front one to recover.
1004         ALOGE("GlobalPresentFences is already at its maximum size[%zu]", MAX_NUM_TIME_RECORDS);
1005         mGlobalRecord.prevPresentTime = 0;
1006         mGlobalRecord.presentFences.pop_front();
1007     }
1008 
1009     mGlobalRecord.presentFences.emplace_back(presentFence);
1010     flushAvailableGlobalRecordsToStatsLocked();
1011 }
1012 
enable()1013 void TimeStats::enable() {
1014     if (mEnabled.load()) return;
1015 
1016     ATRACE_CALL();
1017 
1018     std::lock_guard<std::mutex> lock(mMutex);
1019     mEnabled.store(true);
1020     mTimeStats.statsStartLegacy = static_cast<int64_t>(std::time(0));
1021     mPowerTime.prevTime = systemTime();
1022     ALOGD("Enabled");
1023 }
1024 
disable()1025 void TimeStats::disable() {
1026     if (!mEnabled.load()) return;
1027 
1028     ATRACE_CALL();
1029 
1030     std::lock_guard<std::mutex> lock(mMutex);
1031     flushPowerTimeLocked();
1032     mEnabled.store(false);
1033     mTimeStats.statsEndLegacy = static_cast<int64_t>(std::time(0));
1034     ALOGD("Disabled");
1035 }
1036 
clearAll()1037 void TimeStats::clearAll() {
1038     std::lock_guard<std::mutex> lock(mMutex);
1039     mTimeStats.stats.clear();
1040     clearGlobalLocked();
1041     clearLayersLocked();
1042 }
1043 
clearGlobalLocked()1044 void TimeStats::clearGlobalLocked() {
1045     ATRACE_CALL();
1046 
1047     mTimeStats.statsStartLegacy = (mEnabled.load() ? static_cast<int64_t>(std::time(0)) : 0);
1048     mTimeStats.statsEndLegacy = 0;
1049     mTimeStats.totalFramesLegacy = 0;
1050     mTimeStats.missedFramesLegacy = 0;
1051     mTimeStats.clientCompositionFramesLegacy = 0;
1052     mTimeStats.clientCompositionReusedFramesLegacy = 0;
1053     mTimeStats.compositionStrategyChangesLegacy = 0;
1054     mTimeStats.compositionStrategyPredictedLegacy = 0;
1055     mTimeStats.compositionStrategyPredictionSucceededLegacy = 0;
1056     mTimeStats.refreshRateSwitchesLegacy = 0;
1057     mTimeStats.displayEventConnectionsCountLegacy = 0;
1058     mTimeStats.displayOnTimeLegacy = 0;
1059     mTimeStats.presentToPresentLegacy.hist.clear();
1060     mTimeStats.frameDurationLegacy.hist.clear();
1061     mTimeStats.renderEngineTimingLegacy.hist.clear();
1062     mTimeStats.refreshRateStatsLegacy.clear();
1063     mPowerTime.prevTime = systemTime();
1064     for (auto& globalRecord : mTimeStats.stats) {
1065         globalRecord.second.clearGlobals();
1066     }
1067     mGlobalRecord.prevPresentTime = 0;
1068     mGlobalRecord.presentFences.clear();
1069     ALOGD("Cleared global stats");
1070 }
1071 
clearLayersLocked()1072 void TimeStats::clearLayersLocked() {
1073     ATRACE_CALL();
1074 
1075     mTimeStatsTracker.clear();
1076 
1077     for (auto& globalRecord : mTimeStats.stats) {
1078         globalRecord.second.stats.clear();
1079     }
1080     ALOGD("Cleared layer stats");
1081 }
1082 
isEnabled()1083 bool TimeStats::isEnabled() {
1084     return mEnabled.load();
1085 }
1086 
dump(bool asProto,std::optional<uint32_t> maxLayers,std::string & result)1087 void TimeStats::dump(bool asProto, std::optional<uint32_t> maxLayers, std::string& result) {
1088     ATRACE_CALL();
1089 
1090     std::lock_guard<std::mutex> lock(mMutex);
1091     if (mTimeStats.statsStartLegacy == 0) {
1092         return;
1093     }
1094 
1095     mTimeStats.statsEndLegacy = static_cast<int64_t>(std::time(0));
1096 
1097     flushPowerTimeLocked();
1098 
1099     if (asProto) {
1100         ALOGD("Dumping TimeStats as proto");
1101         SFTimeStatsGlobalProto timeStatsProto = mTimeStats.toProto(maxLayers);
1102         result.append(timeStatsProto.SerializeAsString());
1103     } else {
1104         ALOGD("Dumping TimeStats as text");
1105         result.append(mTimeStats.toString(maxLayers));
1106         result.append("\n");
1107     }
1108 }
1109 
1110 } // namespace impl
1111 
1112 } // namespace android
1113