blob: ff000c9721bfcde40e5306a7a4c183cffc5b9c62 [file] [log] [blame]
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001/*
2 * Copyright 2020 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 "FrameTimeline"
19#define ATRACE_TAG ATRACE_TAG_GRAPHICS
20
21#include "FrameTimeline.h"
Alec Mouriadebf5c2021-01-05 12:57:36 -080022
Adithya Srinivasanf279e042020-08-17 14:56:27 -070023#include <android-base/stringprintf.h>
Ady Abraham7f8a1e62020-09-28 16:09:35 -070024#include <utils/Log.h>
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -070025#include <utils/Trace.h>
Alec Mouriadebf5c2021-01-05 12:57:36 -080026
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070027#include <chrono>
Adithya Srinivasanf279e042020-08-17 14:56:27 -070028#include <cinttypes>
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070029#include <numeric>
Alec Mouriadebf5c2021-01-05 12:57:36 -080030#include <unordered_set>
Adithya Srinivasanf279e042020-08-17 14:56:27 -070031
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080032namespace android::frametimeline {
Adithya Srinivasanf279e042020-08-17 14:56:27 -070033
34using base::StringAppendF;
Adithya Srinivasan01189672020-10-20 14:23:05 -070035using FrameTimelineEvent = perfetto::protos::pbzero::FrameTimelineEvent;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +000036using FrameTimelineDataSource = impl::FrameTimeline::FrameTimelineDataSource;
Adithya Srinivasanf279e042020-08-17 14:56:27 -070037
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070038void dumpTable(std::string& result, TimelineItem predictions, TimelineItem actuals,
39 const std::string& indent, PredictionState predictionState, nsecs_t baseTime) {
40 StringAppendF(&result, "%s", indent.c_str());
41 StringAppendF(&result, "\t\t");
42 StringAppendF(&result, " Start time\t\t|");
43 StringAppendF(&result, " End time\t\t|");
44 StringAppendF(&result, " Present time\n");
45 if (predictionState == PredictionState::Valid) {
46 // Dump the Predictions only if they are valid
47 StringAppendF(&result, "%s", indent.c_str());
48 StringAppendF(&result, "Expected\t|");
49 std::chrono::nanoseconds startTime(predictions.startTime - baseTime);
50 std::chrono::nanoseconds endTime(predictions.endTime - baseTime);
51 std::chrono::nanoseconds presentTime(predictions.presentTime - baseTime);
52 StringAppendF(&result, "\t%10.2f\t|\t%10.2f\t|\t%10.2f\n",
53 std::chrono::duration<double, std::milli>(startTime).count(),
54 std::chrono::duration<double, std::milli>(endTime).count(),
55 std::chrono::duration<double, std::milli>(presentTime).count());
56 }
57 StringAppendF(&result, "%s", indent.c_str());
58 StringAppendF(&result, "Actual \t|");
59
60 if (actuals.startTime == 0) {
61 StringAppendF(&result, "\t\tN/A\t|");
62 } else {
63 std::chrono::nanoseconds startTime(std::max<nsecs_t>(0, actuals.startTime - baseTime));
64 StringAppendF(&result, "\t%10.2f\t|",
65 std::chrono::duration<double, std::milli>(startTime).count());
66 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080067 if (actuals.endTime <= 0) {
68 // Animation leashes can send the endTime as -1
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070069 StringAppendF(&result, "\t\tN/A\t|");
70 } else {
71 std::chrono::nanoseconds endTime(actuals.endTime - baseTime);
72 StringAppendF(&result, "\t%10.2f\t|",
73 std::chrono::duration<double, std::milli>(endTime).count());
74 }
75 if (actuals.presentTime == 0) {
76 StringAppendF(&result, "\t\tN/A\n");
77 } else {
78 std::chrono::nanoseconds presentTime(std::max<nsecs_t>(0, actuals.presentTime - baseTime));
79 StringAppendF(&result, "\t%10.2f\n",
80 std::chrono::duration<double, std::milli>(presentTime).count());
81 }
82
83 StringAppendF(&result, "%s", indent.c_str());
84 StringAppendF(&result, "----------------------");
85 StringAppendF(&result, "----------------------");
86 StringAppendF(&result, "----------------------");
87 StringAppendF(&result, "----------------------\n");
88}
89
90std::string toString(PredictionState predictionState) {
91 switch (predictionState) {
92 case PredictionState::Valid:
93 return "Valid";
94 case PredictionState::Expired:
95 return "Expired";
96 case PredictionState::None:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070097 return "None";
98 }
99}
100
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800101std::string jankTypeBitmaskToString(int32_t jankType) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800102 if (jankType == JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700103 return "None";
104 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000105
106 std::vector<std::string> janks;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800107 if (jankType & JankType::DisplayHAL) {
108 janks.emplace_back("Display HAL");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000109 jankType &= ~JankType::DisplayHAL;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800110 }
111 if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) {
112 janks.emplace_back("SurfaceFlinger CPU Deadline Missed");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000113 jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800114 }
115 if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) {
116 janks.emplace_back("SurfaceFlinger GPU Deadline Missed");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000117 jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800118 }
119 if (jankType & JankType::AppDeadlineMissed) {
120 janks.emplace_back("App Deadline Missed");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000121 jankType &= ~JankType::AppDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800122 }
123 if (jankType & JankType::PredictionError) {
124 janks.emplace_back("Prediction Error");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000125 jankType &= ~JankType::PredictionError;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800126 }
127 if (jankType & JankType::SurfaceFlingerScheduling) {
128 janks.emplace_back("SurfaceFlinger Scheduling");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000129 jankType &= ~JankType::SurfaceFlingerScheduling;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800130 }
131 if (jankType & JankType::BufferStuffing) {
132 janks.emplace_back("Buffer Stuffing");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000133 jankType &= ~JankType::BufferStuffing;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800134 }
135 if (jankType & JankType::Unknown) {
136 janks.emplace_back("Unknown jank");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000137 jankType &= ~JankType::Unknown;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800138 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000139
140 // jankType should be 0 if all types of jank were checked for.
141 LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800142 return std::accumulate(janks.begin(), janks.end(), std::string(),
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700143 [](const std::string& l, const std::string& r) {
144 return l.empty() ? r : l + ", " + r;
145 });
146}
147
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800148std::string toString(FramePresentMetadata presentMetadata) {
149 switch (presentMetadata) {
150 case FramePresentMetadata::OnTimePresent:
151 return "On Time Present";
152 case FramePresentMetadata::LatePresent:
153 return "Late Present";
154 case FramePresentMetadata::EarlyPresent:
155 return "Early Present";
156 case FramePresentMetadata::UnknownPresent:
157 return "Unknown Present";
Adithya Srinivasan01189672020-10-20 14:23:05 -0700158 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700159}
160
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800161std::string toString(FrameReadyMetadata finishMetadata) {
162 switch (finishMetadata) {
163 case FrameReadyMetadata::OnTimeFinish:
164 return "On Time Finish";
165 case FrameReadyMetadata::LateFinish:
166 return "Late Finish";
167 case FrameReadyMetadata::UnknownFinish:
168 return "Unknown Finish";
169 }
170}
171
172std::string toString(FrameStartMetadata startMetadata) {
173 switch (startMetadata) {
174 case FrameStartMetadata::OnTimeStart:
175 return "On Time Start";
176 case FrameStartMetadata::LateStart:
177 return "Late Start";
178 case FrameStartMetadata::EarlyStart:
179 return "Early Start";
180 case FrameStartMetadata::UnknownStart:
181 return "Unknown Start";
182 }
183}
184
185std::string toString(SurfaceFrame::PresentState presentState) {
186 using PresentState = SurfaceFrame::PresentState;
187 switch (presentState) {
188 case PresentState::Presented:
189 return "Presented";
190 case PresentState::Dropped:
191 return "Dropped";
192 case PresentState::Unknown:
193 return "Unknown";
194 }
195}
196
197FrameTimelineEvent::PresentType toProto(FramePresentMetadata presentMetadata) {
198 switch (presentMetadata) {
199 case FramePresentMetadata::EarlyPresent:
200 return FrameTimelineEvent::PRESENT_EARLY;
201 case FramePresentMetadata::LatePresent:
202 return FrameTimelineEvent::PRESENT_LATE;
203 case FramePresentMetadata::OnTimePresent:
204 return FrameTimelineEvent::PRESENT_ON_TIME;
205 case FramePresentMetadata::UnknownPresent:
206 return FrameTimelineEvent::PRESENT_UNSPECIFIED;
207 }
208}
209
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000210int32_t jankTypeBitmaskToProto(int32_t jankType) {
211 if (jankType == JankType::None) {
212 return FrameTimelineEvent::JANK_NONE;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700213 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000214
215 int32_t protoJank = 0;
216 if (jankType & JankType::DisplayHAL) {
217 protoJank |= FrameTimelineEvent::JANK_DISPLAY_HAL;
218 jankType &= ~JankType::DisplayHAL;
219 }
220 if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) {
221 protoJank |= FrameTimelineEvent::JANK_SF_CPU_DEADLINE_MISSED;
222 jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed;
223 }
224 if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) {
225 protoJank |= FrameTimelineEvent::JANK_SF_GPU_DEADLINE_MISSED;
226 jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed;
227 }
228 if (jankType & JankType::AppDeadlineMissed) {
229 protoJank |= FrameTimelineEvent::JANK_APP_DEADLINE_MISSED;
230 jankType &= ~JankType::AppDeadlineMissed;
231 }
232 if (jankType & JankType::PredictionError) {
233 protoJank |= FrameTimelineEvent::JANK_PREDICTION_ERROR;
234 jankType &= ~JankType::PredictionError;
235 }
236 if (jankType & JankType::SurfaceFlingerScheduling) {
237 protoJank |= FrameTimelineEvent::JANK_SF_SCHEDULING;
238 jankType &= ~JankType::SurfaceFlingerScheduling;
239 }
240 if (jankType & JankType::BufferStuffing) {
241 protoJank |= FrameTimelineEvent::JANK_BUFFER_STUFFING;
242 jankType &= ~JankType::BufferStuffing;
243 }
244 if (jankType & JankType::Unknown) {
245 protoJank |= FrameTimelineEvent::JANK_UNKNOWN;
246 jankType &= ~JankType::Unknown;
247 }
248
249 // jankType should be 0 if all types of jank were checked for.
250 LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType);
251 return protoJank;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700252}
253
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800254// Returns the smallest timestamp from the set of predictions and actuals.
255nsecs_t getMinTime(PredictionState predictionState, TimelineItem predictions,
256 TimelineItem actuals) {
257 nsecs_t minTime = std::numeric_limits<nsecs_t>::max();
258 if (predictionState == PredictionState::Valid) {
259 // Checking start time for predictions is enough because start time is always lesser than
260 // endTime and presentTime.
261 minTime = std::min(minTime, predictions.startTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700262 }
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700263
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800264 // Need to check startTime, endTime and presentTime for actuals because some frames might not
265 // have them set.
266 if (actuals.startTime != 0) {
267 minTime = std::min(minTime, actuals.startTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700268 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800269 if (actuals.endTime != 0) {
270 minTime = std::min(minTime, actuals.endTime);
271 }
272 if (actuals.presentTime != 0) {
273 minTime = std::min(minTime, actuals.endTime);
274 }
275 return minTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700276}
277
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000278int64_t TraceCookieCounter::getCookieForTracing() {
279 return ++mTraceCookie;
280}
281
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000282SurfaceFrame::SurfaceFrame(const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid,
Alec Mouriadebf5c2021-01-05 12:57:36 -0800283 uid_t ownerUid, int32_t layerId, std::string layerName,
284 std::string debugName, PredictionState predictionState,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800285 frametimeline::TimelineItem&& predictions,
286 std::shared_ptr<TimeStats> timeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000287 JankClassificationThresholds thresholds,
288 TraceCookieCounter* traceCookieCounter)
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000289 : mToken(frameTimelineInfo.vsyncId),
290 mInputEventId(frameTimelineInfo.inputEventId),
Adithya Srinivasan01189672020-10-20 14:23:05 -0700291 mOwnerPid(ownerPid),
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700292 mOwnerUid(ownerUid),
Alec Mouri9a29e672020-09-14 12:39:14 -0700293 mLayerName(std::move(layerName)),
294 mDebugName(std::move(debugName)),
Alec Mouriadebf5c2021-01-05 12:57:36 -0800295 mLayerId(layerId),
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700296 mPresentState(PresentState::Unknown),
297 mPredictionState(predictionState),
298 mPredictions(predictions),
299 mActuals({0, 0, 0}),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800300 mTimeStats(timeStats),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000301 mJankClassificationThresholds(thresholds),
302 mTraceCookieCounter(*traceCookieCounter) {}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700303
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700304void SurfaceFrame::setActualStartTime(nsecs_t actualStartTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000305 std::scoped_lock lock(mMutex);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700306 mActuals.startTime = actualStartTime;
307}
308
309void SurfaceFrame::setActualQueueTime(nsecs_t actualQueueTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000310 std::scoped_lock lock(mMutex);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700311 mActualQueueTime = actualQueueTime;
312}
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000313
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700314void SurfaceFrame::setAcquireFenceTime(nsecs_t acquireFenceTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000315 std::scoped_lock lock(mMutex);
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700316 mActuals.endTime = std::max(acquireFenceTime, mActualQueueTime);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700317}
318
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000319void SurfaceFrame::setDropTime(nsecs_t dropTime) {
320 std::scoped_lock lock(mMutex);
321 mDropTime = dropTime;
322}
323
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800324void SurfaceFrame::setPresentState(PresentState presentState, nsecs_t lastLatchTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000325 std::scoped_lock lock(mMutex);
Adithya Srinivasanb9a7dab2021-01-14 23:49:46 +0000326 LOG_ALWAYS_FATAL_IF(mPresentState != PresentState::Unknown,
327 "setPresentState called on a SurfaceFrame from Layer - %s, that has a "
328 "PresentState - %s set already.",
329 mDebugName.c_str(), toString(mPresentState).c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800330 mPresentState = presentState;
331 mLastLatchTime = lastLatchTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700332}
333
Alec Mouri7d436ec2021-01-27 20:40:50 -0800334void SurfaceFrame::setRenderRate(Fps renderRate) {
335 std::lock_guard<std::mutex> lock(mMutex);
336 mRenderRate = renderRate;
337}
338
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800339std::optional<int32_t> SurfaceFrame::getJankType() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000340 std::scoped_lock lock(mMutex);
Adithya Srinivasan95619432021-02-08 21:52:51 +0000341 if (mPresentState == PresentState::Dropped) {
342 // Return no jank if it's a dropped frame since we cannot attribute a jank to a it.
343 return JankType::None;
344 }
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100345 if (mActuals.presentTime == 0) {
Adithya Srinivasan95619432021-02-08 21:52:51 +0000346 // Frame hasn't been presented yet.
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100347 return std::nullopt;
348 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700349 return mJankType;
350}
351
352nsecs_t SurfaceFrame::getBaseTime() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000353 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800354 return getMinTime(mPredictionState, mPredictions, mActuals);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700355}
356
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800357TimelineItem SurfaceFrame::getActuals() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000358 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800359 return mActuals;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700360}
361
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000362PredictionState SurfaceFrame::getPredictionState() const {
363 std::scoped_lock lock(mMutex);
364 return mPredictionState;
365}
366
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800367SurfaceFrame::PresentState SurfaceFrame::getPresentState() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000368 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800369 return mPresentState;
370}
371
372FramePresentMetadata SurfaceFrame::getFramePresentMetadata() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000373 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800374 return mFramePresentMetadata;
375}
376
377FrameReadyMetadata SurfaceFrame::getFrameReadyMetadata() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000378 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800379 return mFrameReadyMetadata;
380}
381
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000382nsecs_t SurfaceFrame::getDropTime() const {
383 std::scoped_lock lock(mMutex);
384 return mDropTime;
385}
386
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800387void SurfaceFrame::dump(std::string& result, const std::string& indent, nsecs_t baseTime) const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000388 std::scoped_lock lock(mMutex);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700389 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri9a29e672020-09-14 12:39:14 -0700390 StringAppendF(&result, "Layer - %s", mDebugName.c_str());
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100391 if (mJankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700392 // Easily identify a janky Surface Frame in the dump
393 StringAppendF(&result, " [*] ");
394 }
395 StringAppendF(&result, "\n");
396 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800397 StringAppendF(&result, "Token: %" PRId64 "\n", mToken);
398 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700399 StringAppendF(&result, "Owner Pid : %d\n", mOwnerPid);
400 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri7d436ec2021-01-27 20:40:50 -0800401 StringAppendF(&result, "Scheduled rendering rate: %d fps\n",
402 mRenderRate ? mRenderRate->getIntValue() : 0);
403 StringAppendF(&result, "%s", indent.c_str());
Alec Mouriadebf5c2021-01-05 12:57:36 -0800404 StringAppendF(&result, "Layer ID : %d\n", mLayerId);
405 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800406 StringAppendF(&result, "Present State : %s\n", toString(mPresentState).c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700407 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000408 if (mPresentState == PresentState::Dropped) {
409 std::chrono::nanoseconds dropTime(mDropTime - baseTime);
410 StringAppendF(&result, "Drop time : %10f\n",
411 std::chrono::duration<double, std::milli>(dropTime).count());
412 StringAppendF(&result, "%s", indent.c_str());
413 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700414 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
415 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800416 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700417 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800418 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
419 StringAppendF(&result, "%s", indent.c_str());
420 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
421 std::chrono::nanoseconds latchTime(
422 std::max(static_cast<int64_t>(0), mLastLatchTime - baseTime));
423 StringAppendF(&result, "%s", indent.c_str());
424 StringAppendF(&result, "Last latch time: %10f\n",
425 std::chrono::duration<double, std::milli>(latchTime).count());
426 if (mPredictionState == PredictionState::Valid) {
427 nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime;
428 std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta));
429 StringAppendF(&result, "%s", indent.c_str());
430 StringAppendF(&result, "Present delta: %10f\n",
431 std::chrono::duration<double, std::milli>(presentDeltaNs).count());
432 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700433 dumpTable(result, mPredictions, mActuals, indent, mPredictionState, baseTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700434}
435
Alec Mouri363faf02021-01-29 16:34:55 -0800436void SurfaceFrame::onPresent(nsecs_t presentTime, int32_t displayFrameJankType, Fps refreshRate,
437 nsecs_t displayDeadlineDelta, nsecs_t displayPresentDelta) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000438 std::scoped_lock lock(mMutex);
Alec Mouri7d436ec2021-01-27 20:40:50 -0800439
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800440 if (mPresentState != PresentState::Presented) {
441 // No need to update dropped buffers
442 return;
443 }
444
445 mActuals.presentTime = presentTime;
446 // Jank Analysis for SurfaceFrame
447 if (mPredictionState == PredictionState::None) {
448 // Cannot do jank classification on frames that don't have a token.
449 return;
450 }
451 if (mPredictionState == PredictionState::Expired) {
452 // We do not know what happened here to classify this correctly. This could
453 // potentially be AppDeadlineMissed but that's assuming no app will request frames
454 // 120ms apart.
455 mJankType = JankType::Unknown;
456 mFramePresentMetadata = FramePresentMetadata::UnknownPresent;
457 mFrameReadyMetadata = FrameReadyMetadata::UnknownFinish;
Alec Mouri363faf02021-01-29 16:34:55 -0800458 const constexpr nsecs_t kAppDeadlineDelta = -1;
459 mTimeStats->incrementJankyFrames({refreshRate, mRenderRate, mOwnerUid, mLayerName,
460 mJankType, displayDeadlineDelta, displayPresentDelta,
461 kAppDeadlineDelta});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800462 return;
463 }
464
465 const nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime;
466 const nsecs_t deadlineDelta = mActuals.endTime - mPredictions.endTime;
Alec Mouriadebf5c2021-01-05 12:57:36 -0800467 const nsecs_t deltaToVsync = refreshRate.getPeriodNsecs() > 0
468 ? std::abs(presentDelta) % refreshRate.getPeriodNsecs()
469 : 0;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800470
471 if (deadlineDelta > mJankClassificationThresholds.deadlineThreshold) {
472 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
473 } else {
474 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
475 }
476
477 if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) {
478 mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent
479 : FramePresentMetadata::EarlyPresent;
480 } else {
481 mFramePresentMetadata = FramePresentMetadata::OnTimePresent;
482 }
483
484 if (mFramePresentMetadata == FramePresentMetadata::OnTimePresent) {
485 // Frames presented on time are not janky.
486 mJankType = JankType::None;
487 } else if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) {
488 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
489 // Finish on time, Present early
490 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -0800491 deltaToVsync >= refreshRate.getPeriodNsecs() -
492 mJankClassificationThresholds.presentThreshold) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800493 // Delta factor of vsync
494 mJankType = JankType::SurfaceFlingerScheduling;
495 } else {
496 // Delta not a factor of vsync
497 mJankType = JankType::PredictionError;
498 }
499 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
500 // Finish late, Present early
501 mJankType = JankType::Unknown;
502 }
503 } else {
504 if (mLastLatchTime != 0 && mPredictions.endTime <= mLastLatchTime) {
505 // Buffer Stuffing.
506 mJankType |= JankType::BufferStuffing;
507 }
508 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
509 // Finish on time, Present late
510 if (displayFrameJankType != JankType::None) {
511 // Propagate displayFrame's jank if it exists
512 mJankType |= displayFrameJankType;
513 } else {
514 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -0800515 deltaToVsync >= refreshRate.getPeriodNsecs() -
516 mJankClassificationThresholds.presentThreshold) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800517 // Delta factor of vsync
518 mJankType |= JankType::SurfaceFlingerScheduling;
519 } else {
520 // Delta not a factor of vsync
521 mJankType |= JankType::PredictionError;
522 }
523 }
524 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
525 // Finish late, Present late
526 if (displayFrameJankType == JankType::None) {
527 // Display frame is not janky, so purely app's fault
528 mJankType |= JankType::AppDeadlineMissed;
529 } else {
530 // Propagate DisplayFrame's jankType if it is janky
531 mJankType |= displayFrameJankType;
532 }
533 }
534 }
Alec Mouri363faf02021-01-29 16:34:55 -0800535 mTimeStats->incrementJankyFrames({refreshRate, mRenderRate, mOwnerUid, mLayerName, mJankType,
536 displayDeadlineDelta, displayPresentDelta, deadlineDelta});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800537}
538
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000539void SurfaceFrame::tracePredictions(int64_t displayFrameToken) const {
Adithya Srinivasan86678502021-01-19 21:50:38 +0000540 int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000541
Adithya Srinivasan86678502021-01-19 21:50:38 +0000542 // Expected timeline start
543 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000544 std::scoped_lock lock(mMutex);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700545 auto packet = ctx.NewTracePacket();
546 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000547 packet->set_timestamp(static_cast<uint64_t>(mPredictions.startTime));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700548
549 auto* event = packet->set_frame_timeline_event();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000550 auto* expectedSurfaceFrameStartEvent = event->set_expected_surface_frame_start();
Adithya Srinivasan01189672020-10-20 14:23:05 -0700551
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000552 expectedSurfaceFrameStartEvent->set_cookie(expectedTimelineCookie);
553
554 expectedSurfaceFrameStartEvent->set_token(mToken);
555 expectedSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken);
556
557 expectedSurfaceFrameStartEvent->set_pid(mOwnerPid);
558 expectedSurfaceFrameStartEvent->set_layer_name(mDebugName);
559 });
Adithya Srinivasan86678502021-01-19 21:50:38 +0000560
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000561 // Expected timeline end
562 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000563 std::scoped_lock lock(mMutex);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000564 auto packet = ctx.NewTracePacket();
565 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
566 packet->set_timestamp(static_cast<uint64_t>(mPredictions.endTime));
567
568 auto* event = packet->set_frame_timeline_event();
569 auto* expectedSurfaceFrameEndEvent = event->set_frame_end();
570
571 expectedSurfaceFrameEndEvent->set_cookie(expectedTimelineCookie);
572 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000573}
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000574
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000575void SurfaceFrame::traceActuals(int64_t displayFrameToken) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000576 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000577
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000578 // Actual timeline start
579 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000580 std::scoped_lock lock(mMutex);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000581 auto packet = ctx.NewTracePacket();
582 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
583 // Actual start time is not yet available, so use expected start instead
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000584 if (mPredictionState == PredictionState::Expired) {
585 // If prediction is expired, we can't use the predicted start time. Instead, just use a
586 // start time a little earlier than the end time so that we have some info about this
587 // frame in the trace.
588 packet->set_timestamp(
589 static_cast<uint64_t>(mActuals.endTime - kPredictionExpiredStartTimeDelta));
590 } else {
591 packet->set_timestamp(static_cast<uint64_t>(mPredictions.startTime));
592 }
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000593
594 auto* event = packet->set_frame_timeline_event();
595 auto* actualSurfaceFrameStartEvent = event->set_actual_surface_frame_start();
596
597 actualSurfaceFrameStartEvent->set_cookie(actualTimelineCookie);
598
599 actualSurfaceFrameStartEvent->set_token(mToken);
600 actualSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken);
601
602 actualSurfaceFrameStartEvent->set_pid(mOwnerPid);
603 actualSurfaceFrameStartEvent->set_layer_name(mDebugName);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700604
605 if (mPresentState == PresentState::Dropped) {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000606 actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700607 } else if (mPresentState == PresentState::Unknown) {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000608 actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_UNSPECIFIED);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700609 } else {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000610 actualSurfaceFrameStartEvent->set_present_type(toProto(mFramePresentMetadata));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700611 }
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000612 actualSurfaceFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
613 FrameReadyMetadata::OnTimeFinish);
614 actualSurfaceFrameStartEvent->set_gpu_composition(mGpuComposition);
615 actualSurfaceFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType));
616 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000617
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000618 // Actual timeline end
619 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000620 std::scoped_lock lock(mMutex);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000621 auto packet = ctx.NewTracePacket();
622 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000623 if (mPresentState == PresentState::Dropped) {
624 packet->set_timestamp(static_cast<uint64_t>(mDropTime));
625 } else {
626 packet->set_timestamp(static_cast<uint64_t>(mActuals.endTime));
627 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700628
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000629 auto* event = packet->set_frame_timeline_event();
630 auto* actualSurfaceFrameEndEvent = event->set_frame_end();
Adithya Srinivasan01189672020-10-20 14:23:05 -0700631
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000632 actualSurfaceFrameEndEvent->set_cookie(actualTimelineCookie);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700633 });
634}
635
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000636/**
637 * TODO(b/178637512): add inputEventId to the perfetto trace.
638 */
639void SurfaceFrame::trace(int64_t displayFrameToken) const {
640 if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID ||
641 displayFrameToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
642 // No packets can be traced with a missing token.
643 return;
644 }
645 if (getPredictionState() != PredictionState::Expired) {
646 // Expired predictions have zeroed timestamps. This cannot be used in any meaningful way in
647 // a trace.
648 tracePredictions(displayFrameToken);
649 }
650 traceActuals(displayFrameToken);
651}
652
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800653namespace impl {
654
655int64_t TokenManager::generateTokenForPredictions(TimelineItem&& predictions) {
656 ATRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000657 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800658 const int64_t assignedToken = mCurrentToken++;
659 mPredictions[assignedToken] = {systemTime(), predictions};
660 flushTokens(systemTime());
661 return assignedToken;
662}
663
664std::optional<TimelineItem> TokenManager::getPredictionsForToken(int64_t token) const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000665 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800666 auto predictionsIterator = mPredictions.find(token);
667 if (predictionsIterator != mPredictions.end()) {
668 return predictionsIterator->second.predictions;
669 }
670 return {};
671}
672
673void TokenManager::flushTokens(nsecs_t flushTime) {
674 for (auto it = mPredictions.begin(); it != mPredictions.end();) {
675 if (flushTime - it->second.timestamp >= kMaxRetentionTime) {
676 it = mPredictions.erase(it);
677 } else {
678 // Tokens are ordered by time. If i'th token is within the retention time, then the
679 // i+1'th token will also be within retention time.
680 break;
681 }
682 }
683}
684
685FrameTimeline::FrameTimeline(std::shared_ptr<TimeStats> timeStats, pid_t surfaceFlingerPid,
686 JankClassificationThresholds thresholds)
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000687 : mMaxDisplayFrames(kDefaultMaxDisplayFrames),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800688 mTimeStats(std::move(timeStats)),
689 mSurfaceFlingerPid(surfaceFlingerPid),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000690 mJankClassificationThresholds(thresholds) {
691 mCurrentDisplayFrame =
692 std::make_shared<DisplayFrame>(mTimeStats, thresholds, &mTraceCookieCounter);
693}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700694
Adithya Srinivasan01189672020-10-20 14:23:05 -0700695void FrameTimeline::onBootFinished() {
696 perfetto::TracingInitArgs args;
697 args.backends = perfetto::kSystemBackend;
698 perfetto::Tracing::Initialize(args);
699 registerDataSource();
700}
701
702void FrameTimeline::registerDataSource() {
703 perfetto::DataSourceDescriptor dsd;
704 dsd.set_name(kFrameTimelineDataSource);
705 FrameTimelineDataSource::Register(dsd);
706}
707
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800708std::shared_ptr<SurfaceFrame> FrameTimeline::createSurfaceFrameForToken(
Alec Mouriadebf5c2021-01-05 12:57:36 -0800709 const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid, uid_t ownerUid, int32_t layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000710 std::string layerName, std::string debugName) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700711 ATRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000712 if (frameTimelineInfo.vsyncId == FrameTimelineInfo::INVALID_VSYNC_ID) {
Alec Mouriadebf5c2021-01-05 12:57:36 -0800713 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000714 std::move(layerName), std::move(debugName),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800715 PredictionState::None, TimelineItem(), mTimeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000716 mJankClassificationThresholds, &mTraceCookieCounter);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700717 }
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000718 std::optional<TimelineItem> predictions =
719 mTokenManager.getPredictionsForToken(frameTimelineInfo.vsyncId);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700720 if (predictions) {
Alec Mouriadebf5c2021-01-05 12:57:36 -0800721 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000722 std::move(layerName), std::move(debugName),
723 PredictionState::Valid, std::move(*predictions),
724 mTimeStats, mJankClassificationThresholds,
725 &mTraceCookieCounter);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700726 }
Alec Mouriadebf5c2021-01-05 12:57:36 -0800727 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000728 std::move(layerName), std::move(debugName),
729 PredictionState::Expired, TimelineItem(), mTimeStats,
730 mJankClassificationThresholds, &mTraceCookieCounter);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700731}
732
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800733FrameTimeline::DisplayFrame::DisplayFrame(std::shared_ptr<TimeStats> timeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000734 JankClassificationThresholds thresholds,
735 TraceCookieCounter* traceCookieCounter)
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800736 : mSurfaceFlingerPredictions(TimelineItem()),
737 mSurfaceFlingerActuals(TimelineItem()),
738 mTimeStats(timeStats),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000739 mJankClassificationThresholds(thresholds),
740 mTraceCookieCounter(*traceCookieCounter) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800741 mSurfaceFrames.reserve(kNumSurfaceFramesInitial);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700742}
743
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800744void FrameTimeline::addSurfaceFrame(std::shared_ptr<SurfaceFrame> surfaceFrame) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700745 ATRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000746 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800747 mCurrentDisplayFrame->addSurfaceFrame(surfaceFrame);
748}
749
Alec Mouri7d436ec2021-01-27 20:40:50 -0800750void FrameTimeline::setSfWakeUp(int64_t token, nsecs_t wakeUpTime, Fps refreshRate) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800751 ATRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000752 std::scoped_lock lock(mMutex);
Alec Mouri7d436ec2021-01-27 20:40:50 -0800753 mCurrentDisplayFrame->onSfWakeUp(token, refreshRate,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800754 mTokenManager.getPredictionsForToken(token), wakeUpTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700755}
756
757void FrameTimeline::setSfPresent(nsecs_t sfPresentTime,
758 const std::shared_ptr<FenceTime>& presentFence) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700759 ATRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000760 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800761 mCurrentDisplayFrame->setActualEndTime(sfPresentTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700762 mPendingPresentFences.emplace_back(std::make_pair(presentFence, mCurrentDisplayFrame));
763 flushPendingPresentFences();
764 finalizeCurrentDisplayFrame();
765}
766
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800767void FrameTimeline::DisplayFrame::addSurfaceFrame(std::shared_ptr<SurfaceFrame> surfaceFrame) {
768 mSurfaceFrames.push_back(surfaceFrame);
769}
770
Alec Mouri7d436ec2021-01-27 20:40:50 -0800771void FrameTimeline::DisplayFrame::onSfWakeUp(int64_t token, Fps refreshRate,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800772 std::optional<TimelineItem> predictions,
773 nsecs_t wakeUpTime) {
774 mToken = token;
Alec Mouri7d436ec2021-01-27 20:40:50 -0800775 mRefreshRate = refreshRate;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800776 if (!predictions) {
777 mPredictionState = PredictionState::Expired;
778 } else {
779 mPredictionState = PredictionState::Valid;
780 mSurfaceFlingerPredictions = *predictions;
781 }
782 mSurfaceFlingerActuals.startTime = wakeUpTime;
783}
784
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800785void FrameTimeline::DisplayFrame::setPredictions(PredictionState predictionState,
786 TimelineItem predictions) {
787 mPredictionState = predictionState;
788 mSurfaceFlingerPredictions = predictions;
789}
790
791void FrameTimeline::DisplayFrame::setActualStartTime(nsecs_t actualStartTime) {
792 mSurfaceFlingerActuals.startTime = actualStartTime;
793}
794
795void FrameTimeline::DisplayFrame::setActualEndTime(nsecs_t actualEndTime) {
796 mSurfaceFlingerActuals.endTime = actualEndTime;
797}
798
799void FrameTimeline::DisplayFrame::onPresent(nsecs_t signalTime) {
800 mSurfaceFlingerActuals.presentTime = signalTime;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000801 if (mPredictionState == PredictionState::Expired) {
802 // Cannot do jank classification with expired predictions
803 mJankType = JankType::Unknown;
804 return;
805 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800806
807 // Delta between the expected present and the actual present
808 const nsecs_t presentDelta =
809 mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime;
Alec Mouri363faf02021-01-29 16:34:55 -0800810 const nsecs_t deadlineDelta =
811 mSurfaceFlingerActuals.endTime - mSurfaceFlingerPredictions.endTime;
812
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800813 // How far off was the presentDelta when compared to the vsyncPeriod. Used in checking if there
814 // was a prediction error or not.
Alec Mouriadebf5c2021-01-05 12:57:36 -0800815 nsecs_t deltaToVsync = mRefreshRate.getPeriodNsecs() > 0
816 ? std::abs(presentDelta) % mRefreshRate.getPeriodNsecs()
817 : 0;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800818 if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) {
819 mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent
820 : FramePresentMetadata::EarlyPresent;
821 } else {
822 mFramePresentMetadata = FramePresentMetadata::OnTimePresent;
823 }
824
825 if (mSurfaceFlingerActuals.endTime - mSurfaceFlingerPredictions.endTime >
826 mJankClassificationThresholds.deadlineThreshold) {
827 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
828 } else {
829 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
830 }
831
832 if (std::abs(mSurfaceFlingerActuals.startTime - mSurfaceFlingerPredictions.startTime) >
833 mJankClassificationThresholds.startThreshold) {
834 mFrameStartMetadata =
835 mSurfaceFlingerActuals.startTime > mSurfaceFlingerPredictions.startTime
836 ? FrameStartMetadata::LateStart
837 : FrameStartMetadata::EarlyStart;
838 }
839
840 if (mFramePresentMetadata != FramePresentMetadata::OnTimePresent) {
841 // Do jank classification only if present is not on time
842 if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) {
843 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
844 // Finish on time, Present early
845 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -0800846 deltaToVsync >= (mRefreshRate.getPeriodNsecs() -
847 mJankClassificationThresholds.presentThreshold)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800848 // Delta is a factor of vsync if its within the presentTheshold on either side
849 // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold
850 // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms.
851 mJankType = JankType::SurfaceFlingerScheduling;
852 } else {
853 // Delta is not a factor of vsync,
854 mJankType = JankType::PredictionError;
855 }
856 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
857 // Finish late, Present early
858 mJankType = JankType::SurfaceFlingerScheduling;
859 } else {
860 // Finish time unknown
861 mJankType = JankType::Unknown;
862 }
863 } else if (mFramePresentMetadata == FramePresentMetadata::LatePresent) {
864 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
865 // Finish on time, Present late
866 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -0800867 deltaToVsync >= (mRefreshRate.getPeriodNsecs() -
868 mJankClassificationThresholds.presentThreshold)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800869 // Delta is a factor of vsync if its within the presentTheshold on either side
870 // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold
871 // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms.
872 mJankType = JankType::DisplayHAL;
873 } else {
874 // Delta is not a factor of vsync
875 mJankType = JankType::PredictionError;
876 }
877 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
878 // Finish late, Present late
879 mJankType = JankType::SurfaceFlingerCpuDeadlineMissed;
880 } else {
881 // Finish time unknown
882 mJankType = JankType::Unknown;
883 }
884 } else {
885 // Present unknown
886 mJankType = JankType::Unknown;
887 }
888 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800889 for (auto& surfaceFrame : mSurfaceFrames) {
Alec Mouri363faf02021-01-29 16:34:55 -0800890 surfaceFrame->onPresent(signalTime, mJankType, mRefreshRate, deadlineDelta, deltaToVsync);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800891 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800892}
893
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000894void FrameTimeline::DisplayFrame::tracePredictions(pid_t surfaceFlingerPid) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000895 int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000896
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000897 // Expected timeline start
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800898 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800899 auto packet = ctx.NewTracePacket();
900 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000901 packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerPredictions.startTime));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800902
903 auto* event = packet->set_frame_timeline_event();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000904 auto* expectedDisplayFrameStartEvent = event->set_expected_display_frame_start();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800905
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000906 expectedDisplayFrameStartEvent->set_cookie(expectedTimelineCookie);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800907
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000908 expectedDisplayFrameStartEvent->set_token(mToken);
909 expectedDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
910 });
Adithya Srinivasan86678502021-01-19 21:50:38 +0000911
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000912 // Expected timeline end
913 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
914 auto packet = ctx.NewTracePacket();
915 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
916 packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerPredictions.endTime));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800917
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000918 auto* event = packet->set_frame_timeline_event();
919 auto* expectedDisplayFrameEndEvent = event->set_frame_end();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800920
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000921 expectedDisplayFrameEndEvent->set_cookie(expectedTimelineCookie);
922 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000923}
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000924
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000925void FrameTimeline::DisplayFrame::traceActuals(pid_t surfaceFlingerPid) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000926 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000927
928 // Actual timeline start
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000929 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
930 auto packet = ctx.NewTracePacket();
931 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
932 packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerActuals.startTime));
933
934 auto* event = packet->set_frame_timeline_event();
935 auto* actualDisplayFrameStartEvent = event->set_actual_display_frame_start();
936
937 actualDisplayFrameStartEvent->set_cookie(actualTimelineCookie);
938
939 actualDisplayFrameStartEvent->set_token(mToken);
940 actualDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
941
942 actualDisplayFrameStartEvent->set_present_type(toProto(mFramePresentMetadata));
943 actualDisplayFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
944 FrameReadyMetadata::OnTimeFinish);
945 actualDisplayFrameStartEvent->set_gpu_composition(mGpuComposition);
946 actualDisplayFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType));
947 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000948
949 // Actual timeline end
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000950 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
951 auto packet = ctx.NewTracePacket();
952 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
953 packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerActuals.endTime));
954
955 auto* event = packet->set_frame_timeline_event();
956 auto* actualDisplayFrameEndEvent = event->set_frame_end();
957
958 actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800959 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000960}
961
962void FrameTimeline::DisplayFrame::trace(pid_t surfaceFlingerPid) const {
963 if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
964 // DisplayFrame should not have an invalid token.
965 ALOGE("Cannot trace DisplayFrame with invalid token");
966 return;
967 }
968
969 if (mPredictionState == PredictionState::Valid) {
970 // Expired and unknown predictions have zeroed timestamps. This cannot be used in any
971 // meaningful way in a trace.
972 tracePredictions(surfaceFlingerPid);
973 }
974 traceActuals(surfaceFlingerPid);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800975
976 for (auto& surfaceFrame : mSurfaceFrames) {
977 surfaceFrame->trace(mToken);
978 }
979}
980
Alec Mouriadebf5c2021-01-05 12:57:36 -0800981float FrameTimeline::computeFps(const std::unordered_set<int32_t>& layerIds) {
982 if (layerIds.empty()) {
983 return 0.0f;
984 }
985
986 std::vector<nsecs_t> presentTimes;
987 {
988 std::scoped_lock lock(mMutex);
989 presentTimes.reserve(mDisplayFrames.size());
990 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
991 const auto& displayFrame = mDisplayFrames[i];
992 if (displayFrame->getActuals().presentTime <= 0) {
993 continue;
994 }
995 for (const auto& surfaceFrame : displayFrame->getSurfaceFrames()) {
996 if (surfaceFrame->getPresentState() == SurfaceFrame::PresentState::Presented &&
997 layerIds.count(surfaceFrame->getLayerId()) > 0) {
998 // We're looking for DisplayFrames that presents at least one layer from
999 // layerIds, so push the present time and skip looking through the rest of the
1000 // SurfaceFrames.
1001 presentTimes.push_back(displayFrame->getActuals().presentTime);
1002 break;
1003 }
1004 }
1005 }
1006 }
1007
1008 // FPS can't be computed when there's fewer than 2 presented frames.
1009 if (presentTimes.size() <= 1) {
1010 return 0.0f;
1011 }
1012
1013 nsecs_t priorPresentTime = -1;
1014 nsecs_t totalPresentToPresentWalls = 0;
1015
1016 for (const nsecs_t presentTime : presentTimes) {
1017 if (priorPresentTime == -1) {
1018 priorPresentTime = presentTime;
1019 continue;
1020 }
1021
1022 totalPresentToPresentWalls += (presentTime - priorPresentTime);
1023 priorPresentTime = presentTime;
1024 }
1025
1026 if (CC_UNLIKELY(totalPresentToPresentWalls <= 0)) {
1027 ALOGW("Invalid total present-to-present duration when computing fps: %" PRId64,
1028 totalPresentToPresentWalls);
1029 return 0.0f;
1030 }
1031
1032 const constexpr nsecs_t kOneSecond =
1033 std::chrono::duration_cast<std::chrono::nanoseconds>(1s).count();
1034 // (10^9 nanoseconds / second) * (N present deltas) / (total nanoseconds in N present deltas) =
1035 // M frames / second
1036 return kOneSecond * static_cast<nsecs_t>((presentTimes.size() - 1)) /
1037 static_cast<float>(totalPresentToPresentWalls);
1038}
1039
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001040void FrameTimeline::flushPendingPresentFences() {
1041 for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
1042 const auto& pendingPresentFence = mPendingPresentFences[i];
1043 nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
1044 if (pendingPresentFence.first && pendingPresentFence.first->isValid()) {
1045 signalTime = pendingPresentFence.first->getSignalTime();
1046 if (signalTime == Fence::SIGNAL_TIME_PENDING) {
1047 continue;
1048 }
1049 }
1050 if (signalTime != Fence::SIGNAL_TIME_INVALID) {
1051 auto& displayFrame = pendingPresentFence.second;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001052 displayFrame->onPresent(signalTime);
1053 displayFrame->trace(mSurfaceFlingerPid);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001054 }
1055
1056 mPendingPresentFences.erase(mPendingPresentFences.begin() + static_cast<int>(i));
1057 --i;
1058 }
1059}
1060
1061void FrameTimeline::finalizeCurrentDisplayFrame() {
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001062 while (mDisplayFrames.size() >= mMaxDisplayFrames) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001063 // We maintain only a fixed number of frames' data. Pop older frames
1064 mDisplayFrames.pop_front();
1065 }
1066 mDisplayFrames.push_back(mCurrentDisplayFrame);
1067 mCurrentDisplayFrame.reset();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001068 mCurrentDisplayFrame = std::make_shared<DisplayFrame>(mTimeStats, mJankClassificationThresholds,
1069 &mTraceCookieCounter);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001070}
1071
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001072nsecs_t FrameTimeline::DisplayFrame::getBaseTime() const {
1073 nsecs_t baseTime =
1074 getMinTime(mPredictionState, mSurfaceFlingerPredictions, mSurfaceFlingerActuals);
1075 for (const auto& surfaceFrame : mSurfaceFrames) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001076 nsecs_t surfaceFrameBaseTime = surfaceFrame->getBaseTime();
1077 if (surfaceFrameBaseTime != 0) {
1078 baseTime = std::min(baseTime, surfaceFrameBaseTime);
1079 }
1080 }
1081 return baseTime;
1082}
1083
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001084void FrameTimeline::DisplayFrame::dumpJank(std::string& result, nsecs_t baseTime,
1085 int displayFrameCount) const {
1086 if (mJankType == JankType::None) {
1087 // Check if any Surface Frame has been janky
1088 bool isJanky = false;
1089 for (const auto& surfaceFrame : mSurfaceFrames) {
1090 if (surfaceFrame->getJankType() != JankType::None) {
1091 isJanky = true;
1092 break;
1093 }
1094 }
1095 if (!isJanky) {
1096 return;
1097 }
1098 }
1099 StringAppendF(&result, "Display Frame %d", displayFrameCount);
1100 dump(result, baseTime);
1101}
1102
1103void FrameTimeline::DisplayFrame::dumpAll(std::string& result, nsecs_t baseTime) const {
1104 dump(result, baseTime);
1105}
1106
1107void FrameTimeline::DisplayFrame::dump(std::string& result, nsecs_t baseTime) const {
1108 if (mJankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001109 // Easily identify a janky Display Frame in the dump
1110 StringAppendF(&result, " [*] ");
1111 }
1112 StringAppendF(&result, "\n");
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001113 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
1114 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
1115 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
1116 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
1117 StringAppendF(&result, "Start Metadata: %s\n", toString(mFrameStartMetadata).c_str());
Alec Mouri7d436ec2021-01-27 20:40:50 -08001118 std::chrono::nanoseconds vsyncPeriod(mRefreshRate.getPeriodNsecs());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001119 StringAppendF(&result, "Vsync Period: %10f\n",
1120 std::chrono::duration<double, std::milli>(vsyncPeriod).count());
1121 nsecs_t presentDelta =
1122 mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime;
1123 std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta));
1124 StringAppendF(&result, "Present delta: %10f\n",
1125 std::chrono::duration<double, std::milli>(presentDeltaNs).count());
Alec Mouri7d436ec2021-01-27 20:40:50 -08001126 std::chrono::nanoseconds deltaToVsync(std::abs(presentDelta) % mRefreshRate.getPeriodNsecs());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001127 StringAppendF(&result, "Present delta %% refreshrate: %10f\n",
1128 std::chrono::duration<double, std::milli>(deltaToVsync).count());
1129 dumpTable(result, mSurfaceFlingerPredictions, mSurfaceFlingerActuals, "", mPredictionState,
1130 baseTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001131 StringAppendF(&result, "\n");
1132 std::string indent = " "; // 4 spaces
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001133 for (const auto& surfaceFrame : mSurfaceFrames) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001134 surfaceFrame->dump(result, indent, baseTime);
1135 }
1136 StringAppendF(&result, "\n");
1137}
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001138
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001139void FrameTimeline::dumpAll(std::string& result) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001140 std::scoped_lock lock(mMutex);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001141 StringAppendF(&result, "Number of display frames : %d\n", (int)mDisplayFrames.size());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001142 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001143 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
1144 StringAppendF(&result, "Display Frame %d", static_cast<int>(i));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001145 mDisplayFrames[i]->dumpAll(result, baseTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001146 }
1147}
1148
1149void FrameTimeline::dumpJank(std::string& result) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001150 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001151 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001152 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001153 mDisplayFrames[i]->dumpJank(result, baseTime, static_cast<int>(i));
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001154 }
1155}
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001156
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001157void FrameTimeline::parseArgs(const Vector<String16>& args, std::string& result) {
1158 ATRACE_CALL();
1159 std::unordered_map<std::string, bool> argsMap;
1160 for (size_t i = 0; i < args.size(); i++) {
1161 argsMap[std::string(String8(args[i]).c_str())] = true;
1162 }
1163 if (argsMap.count("-jank")) {
1164 dumpJank(result);
1165 }
1166 if (argsMap.count("-all")) {
1167 dumpAll(result);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001168 }
1169}
1170
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001171void FrameTimeline::setMaxDisplayFrames(uint32_t size) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001172 std::scoped_lock lock(mMutex);
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001173
1174 // The size can either increase or decrease, clear everything, to be consistent
1175 mDisplayFrames.clear();
1176 mPendingPresentFences.clear();
1177 mMaxDisplayFrames = size;
1178}
1179
1180void FrameTimeline::reset() {
1181 setMaxDisplayFrames(kDefaultMaxDisplayFrames);
1182}
1183
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001184} // namespace impl
1185} // namespace android::frametimeline