1 /*
2  * Copyright (C) 2017 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 #include "timestatsproto/TimeStatsHelper.h"
17 
18 #include <android-base/stringprintf.h>
19 #include <ftl/enum.h>
20 
21 #include <array>
22 #include <cinttypes>
23 
24 #define HISTOGRAM_SIZE 85
25 
26 using android::base::StringAppendF;
27 using android::base::StringPrintf;
28 
29 namespace android {
30 namespace surfaceflinger {
31 
32 // Time buckets for histogram, the calculated time deltas will be lower bounded
33 // to the buckets in this array.
34 static const std::array<int32_t, HISTOGRAM_SIZE> histogramConfig =
35         {0,   1,   2,   3,   4,   5,   6,   7,   8,   9,   10,  11,  12,  13,  14,  15,  16,
36          17,  18,  19,  20,  21,  22,  23,  24,  25,  26,  27,  28,  29,  30,  31,  32,  33,
37          34,  36,  38,  40,  42,  44,  46,  48,  50,  54,  58,  62,  66,  70,  74,  78,  82,
38          86,  90,  94,  98,  102, 106, 110, 114, 118, 122, 126, 130, 134, 138, 142, 146, 150,
39          200, 250, 300, 350, 400, 450, 500, 550, 600, 650, 700, 750, 800, 850, 900, 950, 1000};
40 
insert(int32_t delta)41 void TimeStatsHelper::Histogram::insert(int32_t delta) {
42     if (delta < 0) return;
43     // std::lower_bound won't work on out of range values
44     if (delta > histogramConfig[HISTOGRAM_SIZE - 1]) {
45         hist[histogramConfig[HISTOGRAM_SIZE - 1]]++;
46         return;
47     }
48     auto iter = std::lower_bound(histogramConfig.begin(), histogramConfig.end(), delta);
49     hist[*iter]++;
50 }
51 
totalTime() const52 int64_t TimeStatsHelper::Histogram::totalTime() const {
53     int64_t ret = 0;
54     for (const auto& ele : hist) {
55         ret += ele.first * ele.second;
56     }
57     return ret;
58 }
59 
averageTime() const60 float TimeStatsHelper::Histogram::averageTime() const {
61     int64_t ret = 0;
62     int64_t count = 0;
63     for (const auto& ele : hist) {
64         count += ele.second;
65         ret += ele.first * ele.second;
66     }
67     return static_cast<float>(ret) / count;
68 }
69 
toString() const70 std::string TimeStatsHelper::Histogram::toString() const {
71     std::string result;
72     for (int32_t i = 0; i < HISTOGRAM_SIZE; ++i) {
73         int32_t bucket = histogramConfig[i];
74         int32_t count = (hist.count(bucket) == 0) ? 0 : hist.at(bucket);
75         StringAppendF(&result, "%dms=%d ", bucket, count);
76     }
77     result.back() = '\n';
78     return result;
79 }
80 
toString() const81 std::string TimeStatsHelper::JankPayload::toString() const {
82     std::string result;
83     StringAppendF(&result, "totalTimelineFrames = %d\n", totalFrames);
84     StringAppendF(&result, "jankyFrames = %d\n", totalJankyFrames);
85     StringAppendF(&result, "sfLongCpuJankyFrames = %d\n", totalSFLongCpu);
86     StringAppendF(&result, "sfLongGpuJankyFrames = %d\n", totalSFLongGpu);
87     StringAppendF(&result, "sfUnattributedJankyFrames = %d\n", totalSFUnattributed);
88     StringAppendF(&result, "appUnattributedJankyFrames = %d\n", totalAppUnattributed);
89     StringAppendF(&result, "sfSchedulingJankyFrames = %d\n", totalSFScheduling);
90     StringAppendF(&result, "sfPredictionErrorJankyFrames = %d\n", totalSFPredictionError);
91     StringAppendF(&result, "appBufferStuffingJankyFrames = %d\n", totalAppBufferStuffing);
92     return result;
93 }
94 
toString() const95 std::string TimeStatsHelper::SetFrameRateVote::toString() const {
96     std::string result;
97     StringAppendF(&result, "frameRate = %.2f\n", frameRate);
98     StringAppendF(&result, "frameRateCompatibility = %s\n",
99                   ftl::enum_string(frameRateCompatibility).c_str());
100     StringAppendF(&result, "seamlessness = %s\n", ftl::enum_string(seamlessness).c_str());
101     return result;
102 }
103 
toString() const104 std::string TimeStatsHelper::TimeStatsLayer::toString() const {
105     std::string result = "\n";
106     StringAppendF(&result, "displayRefreshRate = %d fps\n", displayRefreshRateBucket);
107     StringAppendF(&result, "renderRate = %d fps\n", renderRateBucket);
108     StringAppendF(&result, "uid = %d\n", uid);
109     StringAppendF(&result, "layerName = %s\n", layerName.c_str());
110     StringAppendF(&result, "packageName = %s\n", packageName.c_str());
111     StringAppendF(&result, "gameMode = %s\n", ftl::enum_string(gameMode).c_str());
112     StringAppendF(&result, "totalFrames = %d\n", totalFrames);
113     StringAppendF(&result, "droppedFrames = %d\n", droppedFrames);
114     StringAppendF(&result, "lateAcquireFrames = %d\n", lateAcquireFrames);
115     StringAppendF(&result, "badDesiredPresentFrames = %d\n", badDesiredPresentFrames);
116     result.append("Jank payload for this layer:\n");
117     result.append(jankPayload.toString());
118     result.append("SetFrameRate vote for this layer:\n");
119     result.append(setFrameRateVote.toString());
120     const auto iter = deltas.find("present2present");
121     if (iter != deltas.end()) {
122         const float averageTime = iter->second.averageTime();
123         const float averageFPS = averageTime < 1.0f ? 0.0f : 1000.0f / averageTime;
124         StringAppendF(&result, "averageFPS = %.3f\n", averageFPS);
125     }
126     for (const auto& ele : deltas) {
127         StringAppendF(&result, "%s histogram is as below:\n", ele.first.c_str());
128         result.append(ele.second.toString());
129     }
130 
131     return result;
132 }
133 
toString(std::optional<uint32_t> maxLayers) const134 std::string TimeStatsHelper::TimeStatsGlobal::toString(std::optional<uint32_t> maxLayers) const {
135     std::string result = "SurfaceFlinger TimeStats:\n";
136     result.append("Legacy stats are as follows:\n");
137     StringAppendF(&result, "statsStart = %" PRId64 "\n", statsStartLegacy);
138     StringAppendF(&result, "statsEnd = %" PRId64 "\n", statsEndLegacy);
139     StringAppendF(&result, "totalFrames = %d\n", totalFramesLegacy);
140     StringAppendF(&result, "missedFrames = %d\n", missedFramesLegacy);
141     StringAppendF(&result, "clientCompositionFrames = %d\n", clientCompositionFramesLegacy);
142     StringAppendF(&result, "clientCompositionReusedFrames = %d\n",
143                   clientCompositionReusedFramesLegacy);
144     StringAppendF(&result, "refreshRateSwitches = %d\n", refreshRateSwitchesLegacy);
145     StringAppendF(&result, "compositionStrategyChanges = %d\n", compositionStrategyChangesLegacy);
146     StringAppendF(&result, "compositionStrategyPredicted = %d\n",
147                   compositionStrategyPredictedLegacy);
148     StringAppendF(&result, "compositionStrategyPredictionSucceeded = %d\n",
149                   compositionStrategyPredictionSucceededLegacy);
150     StringAppendF(&result, "compositionStrategyPredictionFailed = %d\n",
151                   compositionStrategyPredictedLegacy -
152                           compositionStrategyPredictionSucceededLegacy);
153 
154     StringAppendF(&result, "displayOnTime = %" PRId64 " ms\n", displayOnTimeLegacy);
155     StringAppendF(&result, "displayConfigStats is as below:\n");
156     for (const auto& [fps, duration] : refreshRateStatsLegacy) {
157         StringAppendF(&result, "%dfps = %ldms\n", fps, ns2ms(duration));
158     }
159     result.back() = '\n';
160     StringAppendF(&result, "totalP2PTime = %" PRId64 " ms\n", presentToPresentLegacy.totalTime());
161     StringAppendF(&result, "presentToPresent histogram is as below:\n");
162     result.append(presentToPresentLegacy.toString());
163     const float averageFrameDuration = frameDurationLegacy.averageTime();
164     StringAppendF(&result, "averageFrameDuration = %.3f ms\n",
165                   std::isnan(averageFrameDuration) ? 0.0f : averageFrameDuration);
166     StringAppendF(&result, "frameDuration histogram is as below:\n");
167     result.append(frameDurationLegacy.toString());
168     const float averageRenderEngineTiming = renderEngineTimingLegacy.averageTime();
169     StringAppendF(&result, "averageRenderEngineTiming = %.3f ms\n",
170                   std::isnan(averageRenderEngineTiming) ? 0.0f : averageRenderEngineTiming);
171     StringAppendF(&result, "renderEngineTiming histogram is as below:\n");
172     result.append(renderEngineTimingLegacy.toString());
173 
174     result.append("\nGlobal aggregated jank payload (Timeline stats):");
175     for (const auto& ele : stats) {
176         result.append("\n");
177         StringAppendF(&result, "displayRefreshRate = %d fps\n",
178                       ele.second.key.displayRefreshRateBucket);
179         StringAppendF(&result, "renderRate = %d fps\n", ele.second.key.renderRateBucket);
180         result.append(ele.second.jankPayload.toString());
181         StringAppendF(&result, "sfDeadlineMisses histogram is as below:\n");
182         result.append(ele.second.displayDeadlineDeltas.toString());
183         StringAppendF(&result, "sfPredictionErrors histogram is as below:\n");
184         result.append(ele.second.displayPresentDeltas.toString());
185     }
186 
187     const auto dumpStats = generateDumpStats(maxLayers);
188     for (const auto& ele : dumpStats) {
189         result.append(ele->toString());
190     }
191 
192     return result;
193 }
194 
toProto() const195 SFTimeStatsLayerProto TimeStatsHelper::TimeStatsLayer::toProto() const {
196     SFTimeStatsLayerProto layerProto;
197     layerProto.set_layer_name(layerName);
198     layerProto.set_package_name(packageName);
199     layerProto.set_total_frames(totalFrames);
200     layerProto.set_dropped_frames(droppedFrames);
201     for (const auto& ele : deltas) {
202         SFTimeStatsDeltaProto* deltaProto = layerProto.add_deltas();
203         deltaProto->set_delta_name(ele.first);
204         for (const auto& histEle : ele.second.hist) {
205             SFTimeStatsHistogramBucketProto* histProto = deltaProto->add_histograms();
206             histProto->set_time_millis(histEle.first);
207             histProto->set_frame_count(histEle.second);
208         }
209     }
210     return layerProto;
211 }
212 
toProto(std::optional<uint32_t> maxLayers) const213 SFTimeStatsGlobalProto TimeStatsHelper::TimeStatsGlobal::toProto(
214         std::optional<uint32_t> maxLayers) const {
215     SFTimeStatsGlobalProto globalProto;
216     globalProto.set_stats_start(statsStartLegacy);
217     globalProto.set_stats_end(statsEndLegacy);
218     globalProto.set_total_frames(totalFramesLegacy);
219     globalProto.set_missed_frames(missedFramesLegacy);
220     globalProto.set_client_composition_frames(clientCompositionFramesLegacy);
221     globalProto.set_display_on_time(displayOnTimeLegacy);
222     for (const auto& ele : refreshRateStatsLegacy) {
223         SFTimeStatsDisplayConfigBucketProto* configBucketProto =
224                 globalProto.add_display_config_stats();
225         SFTimeStatsDisplayConfigProto* configProto = configBucketProto->mutable_config();
226         configProto->set_fps(ele.first);
227         configBucketProto->set_duration_millis(ns2ms(ele.second));
228     }
229     for (const auto& histEle : presentToPresentLegacy.hist) {
230         SFTimeStatsHistogramBucketProto* histProto = globalProto.add_present_to_present();
231         histProto->set_time_millis(histEle.first);
232         histProto->set_frame_count(histEle.second);
233     }
234     for (const auto& histEle : frameDurationLegacy.hist) {
235         SFTimeStatsHistogramBucketProto* histProto = globalProto.add_frame_duration();
236         histProto->set_time_millis(histEle.first);
237         histProto->set_frame_count(histEle.second);
238     }
239     for (const auto& histEle : renderEngineTimingLegacy.hist) {
240         SFTimeStatsHistogramBucketProto* histProto = globalProto.add_render_engine_timing();
241         histProto->set_time_millis(histEle.first);
242         histProto->set_frame_count(histEle.second);
243     }
244     const auto dumpStats = generateDumpStats(maxLayers);
245     for (const auto& ele : dumpStats) {
246         SFTimeStatsLayerProto* layerProto = globalProto.add_stats();
247         layerProto->CopyFrom(ele->toProto());
248     }
249     return globalProto;
250 }
251 
252 std::vector<TimeStatsHelper::TimeStatsLayer const*>
generateDumpStats(std::optional<uint32_t> maxLayers) const253 TimeStatsHelper::TimeStatsGlobal::generateDumpStats(std::optional<uint32_t> maxLayers) const {
254     std::vector<TimeStatsLayer const*> dumpStats;
255 
256     int numLayers = 0;
257     for (const auto& ele : stats) {
258         numLayers += ele.second.stats.size();
259     }
260 
261     dumpStats.reserve(numLayers);
262 
263     for (const auto& ele : stats) {
264         for (const auto& layerEle : ele.second.stats) {
265             dumpStats.push_back(&layerEle.second);
266         }
267     }
268 
269     std::sort(dumpStats.begin(), dumpStats.end(),
270               [](TimeStatsHelper::TimeStatsLayer const* l,
271                  TimeStatsHelper::TimeStatsLayer const* r) {
272                   return l->totalFrames > r->totalFrames;
273               });
274 
275     if (maxLayers && (*maxLayers < dumpStats.size())) {
276         dumpStats.resize(*maxLayers);
277     }
278     return dumpStats;
279 }
280 
281 } // namespace surfaceflinger
282 } // namespace android
283