blob: 3736abc79f2bac665921745e5651d618c8c18b6d [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>
Sally Qif5721252023-11-17 11:14:53 -080024#include <common/FlagManager.h>
Vishnu Nairbe0ad902024-06-27 23:38:43 +000025#include <common/trace.h>
Ady Abraham7f8a1e62020-09-28 16:09:35 -070026#include <utils/Log.h>
Alec Mouriadebf5c2021-01-05 12:57:36 -080027
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070028#include <chrono>
Adithya Srinivasanf279e042020-08-17 14:56:27 -070029#include <cinttypes>
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070030#include <numeric>
Alec Mouriadebf5c2021-01-05 12:57:36 -080031#include <unordered_set>
Adithya Srinivasanf279e042020-08-17 14:56:27 -070032
Pascal Mütschardd56514e2024-05-24 17:37:13 +020033#include "../Jank/JankTracker.h"
34
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080035namespace android::frametimeline {
Adithya Srinivasanf279e042020-08-17 14:56:27 -070036
37using base::StringAppendF;
Adithya Srinivasan01189672020-10-20 14:23:05 -070038using FrameTimelineEvent = perfetto::protos::pbzero::FrameTimelineEvent;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +000039using FrameTimelineDataSource = impl::FrameTimeline::FrameTimelineDataSource;
Adithya Srinivasanf279e042020-08-17 14:56:27 -070040
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070041void dumpTable(std::string& result, TimelineItem predictions, TimelineItem actuals,
42 const std::string& indent, PredictionState predictionState, nsecs_t baseTime) {
43 StringAppendF(&result, "%s", indent.c_str());
44 StringAppendF(&result, "\t\t");
45 StringAppendF(&result, " Start time\t\t|");
46 StringAppendF(&result, " End time\t\t|");
47 StringAppendF(&result, " Present time\n");
48 if (predictionState == PredictionState::Valid) {
49 // Dump the Predictions only if they are valid
50 StringAppendF(&result, "%s", indent.c_str());
51 StringAppendF(&result, "Expected\t|");
52 std::chrono::nanoseconds startTime(predictions.startTime - baseTime);
53 std::chrono::nanoseconds endTime(predictions.endTime - baseTime);
54 std::chrono::nanoseconds presentTime(predictions.presentTime - baseTime);
55 StringAppendF(&result, "\t%10.2f\t|\t%10.2f\t|\t%10.2f\n",
56 std::chrono::duration<double, std::milli>(startTime).count(),
57 std::chrono::duration<double, std::milli>(endTime).count(),
58 std::chrono::duration<double, std::milli>(presentTime).count());
59 }
60 StringAppendF(&result, "%s", indent.c_str());
61 StringAppendF(&result, "Actual \t|");
62
63 if (actuals.startTime == 0) {
64 StringAppendF(&result, "\t\tN/A\t|");
65 } else {
66 std::chrono::nanoseconds startTime(std::max<nsecs_t>(0, actuals.startTime - baseTime));
67 StringAppendF(&result, "\t%10.2f\t|",
68 std::chrono::duration<double, std::milli>(startTime).count());
69 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080070 if (actuals.endTime <= 0) {
71 // Animation leashes can send the endTime as -1
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070072 StringAppendF(&result, "\t\tN/A\t|");
73 } else {
74 std::chrono::nanoseconds endTime(actuals.endTime - baseTime);
75 StringAppendF(&result, "\t%10.2f\t|",
76 std::chrono::duration<double, std::milli>(endTime).count());
77 }
78 if (actuals.presentTime == 0) {
79 StringAppendF(&result, "\t\tN/A\n");
80 } else {
81 std::chrono::nanoseconds presentTime(std::max<nsecs_t>(0, actuals.presentTime - baseTime));
82 StringAppendF(&result, "\t%10.2f\n",
83 std::chrono::duration<double, std::milli>(presentTime).count());
84 }
85
86 StringAppendF(&result, "%s", indent.c_str());
87 StringAppendF(&result, "----------------------");
88 StringAppendF(&result, "----------------------");
89 StringAppendF(&result, "----------------------");
90 StringAppendF(&result, "----------------------\n");
91}
92
93std::string toString(PredictionState predictionState) {
94 switch (predictionState) {
95 case PredictionState::Valid:
96 return "Valid";
97 case PredictionState::Expired:
98 return "Expired";
99 case PredictionState::None:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700100 return "None";
101 }
102}
103
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800104std::string jankTypeBitmaskToString(int32_t jankType) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800105 if (jankType == JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700106 return "None";
107 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000108
109 std::vector<std::string> janks;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800110 if (jankType & JankType::DisplayHAL) {
111 janks.emplace_back("Display HAL");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000112 jankType &= ~JankType::DisplayHAL;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800113 }
114 if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) {
Rachel Lee94917b32022-03-18 17:52:09 -0700115 janks.emplace_back("SurfaceFlinger deadline missed (while in HWC)");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000116 jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800117 }
118 if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) {
Rachel Lee94917b32022-03-18 17:52:09 -0700119 janks.emplace_back("SurfaceFlinger deadline missed (while in GPU comp)");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000120 jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800121 }
122 if (jankType & JankType::AppDeadlineMissed) {
123 janks.emplace_back("App Deadline Missed");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000124 jankType &= ~JankType::AppDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800125 }
126 if (jankType & JankType::PredictionError) {
127 janks.emplace_back("Prediction Error");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000128 jankType &= ~JankType::PredictionError;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800129 }
130 if (jankType & JankType::SurfaceFlingerScheduling) {
131 janks.emplace_back("SurfaceFlinger Scheduling");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000132 jankType &= ~JankType::SurfaceFlingerScheduling;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800133 }
134 if (jankType & JankType::BufferStuffing) {
135 janks.emplace_back("Buffer Stuffing");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000136 jankType &= ~JankType::BufferStuffing;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800137 }
138 if (jankType & JankType::Unknown) {
139 janks.emplace_back("Unknown jank");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000140 jankType &= ~JankType::Unknown;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800141 }
Adithya Srinivasan2045ddf2021-05-27 17:38:10 +0000142 if (jankType & JankType::SurfaceFlingerStuffing) {
143 janks.emplace_back("SurfaceFlinger Stuffing");
144 jankType &= ~JankType::SurfaceFlingerStuffing;
145 }
Edgar Arriaga631e4252023-03-02 02:11:24 +0000146 if (jankType & JankType::Dropped) {
147 janks.emplace_back("Dropped Frame");
148 jankType &= ~JankType::Dropped;
149 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000150
151 // jankType should be 0 if all types of jank were checked for.
152 LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800153 return std::accumulate(janks.begin(), janks.end(), std::string(),
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700154 [](const std::string& l, const std::string& r) {
155 return l.empty() ? r : l + ", " + r;
156 });
157}
158
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800159std::string toString(FramePresentMetadata presentMetadata) {
160 switch (presentMetadata) {
161 case FramePresentMetadata::OnTimePresent:
162 return "On Time Present";
163 case FramePresentMetadata::LatePresent:
164 return "Late Present";
165 case FramePresentMetadata::EarlyPresent:
166 return "Early Present";
167 case FramePresentMetadata::UnknownPresent:
168 return "Unknown Present";
Adithya Srinivasan01189672020-10-20 14:23:05 -0700169 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700170}
171
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800172std::string toString(FrameReadyMetadata finishMetadata) {
173 switch (finishMetadata) {
174 case FrameReadyMetadata::OnTimeFinish:
175 return "On Time Finish";
176 case FrameReadyMetadata::LateFinish:
177 return "Late Finish";
178 case FrameReadyMetadata::UnknownFinish:
179 return "Unknown Finish";
180 }
181}
182
183std::string toString(FrameStartMetadata startMetadata) {
184 switch (startMetadata) {
185 case FrameStartMetadata::OnTimeStart:
186 return "On Time Start";
187 case FrameStartMetadata::LateStart:
188 return "Late Start";
189 case FrameStartMetadata::EarlyStart:
190 return "Early Start";
191 case FrameStartMetadata::UnknownStart:
192 return "Unknown Start";
193 }
194}
195
196std::string toString(SurfaceFrame::PresentState presentState) {
197 using PresentState = SurfaceFrame::PresentState;
198 switch (presentState) {
199 case PresentState::Presented:
200 return "Presented";
201 case PresentState::Dropped:
202 return "Dropped";
203 case PresentState::Unknown:
204 return "Unknown";
205 }
206}
207
208FrameTimelineEvent::PresentType toProto(FramePresentMetadata presentMetadata) {
209 switch (presentMetadata) {
210 case FramePresentMetadata::EarlyPresent:
211 return FrameTimelineEvent::PRESENT_EARLY;
212 case FramePresentMetadata::LatePresent:
213 return FrameTimelineEvent::PRESENT_LATE;
214 case FramePresentMetadata::OnTimePresent:
215 return FrameTimelineEvent::PRESENT_ON_TIME;
216 case FramePresentMetadata::UnknownPresent:
217 return FrameTimelineEvent::PRESENT_UNSPECIFIED;
218 }
219}
220
Adithya Srinivasan78e58af2021-02-25 00:08:08 +0000221FrameTimelineEvent::PredictionType toProto(PredictionState predictionState) {
222 switch (predictionState) {
223 case PredictionState::Valid:
224 return FrameTimelineEvent::PREDICTION_VALID;
225 case PredictionState::Expired:
226 return FrameTimelineEvent::PREDICTION_EXPIRED;
227 case PredictionState::None:
228 return FrameTimelineEvent::PREDICTION_UNKNOWN;
229 }
230}
231
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000232int32_t jankTypeBitmaskToProto(int32_t jankType) {
233 if (jankType == JankType::None) {
234 return FrameTimelineEvent::JANK_NONE;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700235 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000236
237 int32_t protoJank = 0;
238 if (jankType & JankType::DisplayHAL) {
239 protoJank |= FrameTimelineEvent::JANK_DISPLAY_HAL;
240 jankType &= ~JankType::DisplayHAL;
241 }
242 if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) {
243 protoJank |= FrameTimelineEvent::JANK_SF_CPU_DEADLINE_MISSED;
244 jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed;
245 }
246 if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) {
247 protoJank |= FrameTimelineEvent::JANK_SF_GPU_DEADLINE_MISSED;
248 jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed;
249 }
250 if (jankType & JankType::AppDeadlineMissed) {
251 protoJank |= FrameTimelineEvent::JANK_APP_DEADLINE_MISSED;
252 jankType &= ~JankType::AppDeadlineMissed;
253 }
254 if (jankType & JankType::PredictionError) {
255 protoJank |= FrameTimelineEvent::JANK_PREDICTION_ERROR;
256 jankType &= ~JankType::PredictionError;
257 }
258 if (jankType & JankType::SurfaceFlingerScheduling) {
259 protoJank |= FrameTimelineEvent::JANK_SF_SCHEDULING;
260 jankType &= ~JankType::SurfaceFlingerScheduling;
261 }
262 if (jankType & JankType::BufferStuffing) {
263 protoJank |= FrameTimelineEvent::JANK_BUFFER_STUFFING;
264 jankType &= ~JankType::BufferStuffing;
265 }
266 if (jankType & JankType::Unknown) {
267 protoJank |= FrameTimelineEvent::JANK_UNKNOWN;
268 jankType &= ~JankType::Unknown;
269 }
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +0000270 if (jankType & JankType::SurfaceFlingerStuffing) {
271 protoJank |= FrameTimelineEvent::JANK_SF_STUFFING;
272 jankType &= ~JankType::SurfaceFlingerStuffing;
273 }
Edgar Arriaga631e4252023-03-02 02:11:24 +0000274 if (jankType & JankType::Dropped) {
275 // Jank dropped does not append to other janks, it fully overrides.
276 protoJank |= FrameTimelineEvent::JANK_DROPPED;
277 jankType &= ~JankType::Dropped;
278 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000279
280 // jankType should be 0 if all types of jank were checked for.
281 LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType);
282 return protoJank;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700283}
284
Ying Wei96eb5352023-11-21 17:37:21 +0000285FrameTimelineEvent::JankSeverityType toProto(JankSeverityType jankSeverityType) {
286 switch (jankSeverityType) {
287 case JankSeverityType::Unknown:
288 return FrameTimelineEvent::SEVERITY_UNKNOWN;
289 case JankSeverityType::None:
290 return FrameTimelineEvent::SEVERITY_NONE;
291 case JankSeverityType::Partial:
292 return FrameTimelineEvent::SEVERITY_PARTIAL;
293 case JankSeverityType::Full:
294 return FrameTimelineEvent::SEVERITY_FULL;
295 }
296}
297
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800298// Returns the smallest timestamp from the set of predictions and actuals.
299nsecs_t getMinTime(PredictionState predictionState, TimelineItem predictions,
300 TimelineItem actuals) {
301 nsecs_t minTime = std::numeric_limits<nsecs_t>::max();
302 if (predictionState == PredictionState::Valid) {
303 // Checking start time for predictions is enough because start time is always lesser than
304 // endTime and presentTime.
305 minTime = std::min(minTime, predictions.startTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700306 }
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700307
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800308 // Need to check startTime, endTime and presentTime for actuals because some frames might not
309 // have them set.
310 if (actuals.startTime != 0) {
311 minTime = std::min(minTime, actuals.startTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700312 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800313 if (actuals.endTime != 0) {
314 minTime = std::min(minTime, actuals.endTime);
315 }
316 if (actuals.presentTime != 0) {
ramindaniea2bb822022-06-27 19:52:10 +0000317 minTime = std::min(minTime, actuals.presentTime);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800318 }
319 return minTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700320}
321
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000322int64_t TraceCookieCounter::getCookieForTracing() {
323 return ++mTraceCookie;
324}
325
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000326SurfaceFrame::SurfaceFrame(const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid,
Alec Mouriadebf5c2021-01-05 12:57:36 -0800327 uid_t ownerUid, int32_t layerId, std::string layerName,
328 std::string debugName, PredictionState predictionState,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800329 frametimeline::TimelineItem&& predictions,
330 std::shared_ptr<TimeStats> timeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000331 JankClassificationThresholds thresholds,
Dominik Laskowskif5d0ea52021-09-26 17:27:01 -0700332 TraceCookieCounter* traceCookieCounter, bool isBuffer, GameMode gameMode)
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000333 : mToken(frameTimelineInfo.vsyncId),
334 mInputEventId(frameTimelineInfo.inputEventId),
Adithya Srinivasan01189672020-10-20 14:23:05 -0700335 mOwnerPid(ownerPid),
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700336 mOwnerUid(ownerUid),
Alec Mouri9a29e672020-09-14 12:39:14 -0700337 mLayerName(std::move(layerName)),
338 mDebugName(std::move(debugName)),
Alec Mouriadebf5c2021-01-05 12:57:36 -0800339 mLayerId(layerId),
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700340 mPresentState(PresentState::Unknown),
341 mPredictionState(predictionState),
342 mPredictions(predictions),
343 mActuals({0, 0, 0}),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800344 mTimeStats(timeStats),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000345 mJankClassificationThresholds(thresholds),
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000346 mTraceCookieCounter(*traceCookieCounter),
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000347 mIsBuffer(isBuffer),
348 mGameMode(gameMode) {}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700349
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700350void SurfaceFrame::setActualStartTime(nsecs_t actualStartTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000351 std::scoped_lock lock(mMutex);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700352 mActuals.startTime = actualStartTime;
353}
354
355void SurfaceFrame::setActualQueueTime(nsecs_t actualQueueTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000356 std::scoped_lock lock(mMutex);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700357 mActualQueueTime = actualQueueTime;
358}
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000359
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700360void SurfaceFrame::setAcquireFenceTime(nsecs_t acquireFenceTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000361 std::scoped_lock lock(mMutex);
Vishnu Nairbd7d07e2024-07-08 13:37:11 -0700362 if (CC_UNLIKELY(acquireFenceTime == Fence::SIGNAL_TIME_PENDING)) {
363 mActuals.endTime = mActualQueueTime;
364 } else {
365 mActuals.endTime = std::max(acquireFenceTime, mActualQueueTime);
366 }
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700367}
368
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000369void SurfaceFrame::setDropTime(nsecs_t dropTime) {
370 std::scoped_lock lock(mMutex);
371 mDropTime = dropTime;
372}
373
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800374void SurfaceFrame::setPresentState(PresentState presentState, nsecs_t lastLatchTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000375 std::scoped_lock lock(mMutex);
Adithya Srinivasanb9a7dab2021-01-14 23:49:46 +0000376 LOG_ALWAYS_FATAL_IF(mPresentState != PresentState::Unknown,
377 "setPresentState called on a SurfaceFrame from Layer - %s, that has a "
378 "PresentState - %s set already.",
379 mDebugName.c_str(), toString(mPresentState).c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800380 mPresentState = presentState;
381 mLastLatchTime = lastLatchTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700382}
383
Alec Mouri7d436ec2021-01-27 20:40:50 -0800384void SurfaceFrame::setRenderRate(Fps renderRate) {
385 std::lock_guard<std::mutex> lock(mMutex);
386 mRenderRate = renderRate;
387}
388
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200389Fps SurfaceFrame::getRenderRate() const {
390 std::lock_guard<std::mutex> lock(mMutex);
391 return mRenderRate ? *mRenderRate : mDisplayFrameRenderRate;
392}
393
Adithya Srinivasanb6a2fa12021-03-13 00:23:09 +0000394void SurfaceFrame::setGpuComposition() {
395 std::scoped_lock lock(mMutex);
396 mGpuComposition = true;
397}
398
Sally Qi438eb7d2023-12-05 18:59:32 -0800399// TODO(b/316171339): migrate from perfetto side
400bool SurfaceFrame::isSelfJanky() const {
401 int32_t jankType = getJankType().value_or(JankType::None);
402
403 if (jankType == JankType::None) {
404 return false;
405 }
406
407 int32_t jankBitmask = JankType::AppDeadlineMissed | JankType::Unknown;
408 if (jankType & jankBitmask) {
409 return true;
410 }
411
412 return false;
413}
414
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800415std::optional<int32_t> SurfaceFrame::getJankType() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000416 std::scoped_lock lock(mMutex);
Adithya Srinivasan95619432021-02-08 21:52:51 +0000417 if (mPresentState == PresentState::Dropped) {
Edgar Arriaga631e4252023-03-02 02:11:24 +0000418 return JankType::Dropped;
Adithya Srinivasan95619432021-02-08 21:52:51 +0000419 }
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100420 if (mActuals.presentTime == 0) {
Adithya Srinivasan95619432021-02-08 21:52:51 +0000421 // Frame hasn't been presented yet.
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100422 return std::nullopt;
423 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700424 return mJankType;
425}
426
Ying Wei96eb5352023-11-21 17:37:21 +0000427std::optional<JankSeverityType> SurfaceFrame::getJankSeverityType() const {
428 std::scoped_lock lock(mMutex);
429 if (mActuals.presentTime == 0) {
430 // Frame hasn't been presented yet.
431 return std::nullopt;
432 }
433 return mJankSeverityType;
434}
435
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700436nsecs_t SurfaceFrame::getBaseTime() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000437 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800438 return getMinTime(mPredictionState, mPredictions, mActuals);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700439}
440
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800441TimelineItem SurfaceFrame::getActuals() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000442 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800443 return mActuals;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700444}
445
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000446PredictionState SurfaceFrame::getPredictionState() const {
447 std::scoped_lock lock(mMutex);
448 return mPredictionState;
449}
450
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800451SurfaceFrame::PresentState SurfaceFrame::getPresentState() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000452 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800453 return mPresentState;
454}
455
456FramePresentMetadata SurfaceFrame::getFramePresentMetadata() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000457 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800458 return mFramePresentMetadata;
459}
460
461FrameReadyMetadata SurfaceFrame::getFrameReadyMetadata() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000462 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800463 return mFrameReadyMetadata;
464}
465
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000466nsecs_t SurfaceFrame::getDropTime() const {
467 std::scoped_lock lock(mMutex);
468 return mDropTime;
469}
470
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000471void SurfaceFrame::promoteToBuffer() {
472 std::scoped_lock lock(mMutex);
473 LOG_ALWAYS_FATAL_IF(mIsBuffer == true,
474 "Trying to promote an already promoted BufferSurfaceFrame from layer %s "
475 "with token %" PRId64 "",
476 mDebugName.c_str(), mToken);
477 mIsBuffer = true;
478}
479
480bool SurfaceFrame::getIsBuffer() const {
481 std::scoped_lock lock(mMutex);
482 return mIsBuffer;
483}
484
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800485void SurfaceFrame::dump(std::string& result, const std::string& indent, nsecs_t baseTime) const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000486 std::scoped_lock lock(mMutex);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700487 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri9a29e672020-09-14 12:39:14 -0700488 StringAppendF(&result, "Layer - %s", mDebugName.c_str());
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100489 if (mJankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700490 // Easily identify a janky Surface Frame in the dump
491 StringAppendF(&result, " [*] ");
492 }
493 StringAppendF(&result, "\n");
494 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800495 StringAppendF(&result, "Token: %" PRId64 "\n", mToken);
496 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000497 StringAppendF(&result, "Is Buffer?: %d\n", mIsBuffer);
498 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700499 StringAppendF(&result, "Owner Pid : %d\n", mOwnerPid);
500 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri7d436ec2021-01-27 20:40:50 -0800501 StringAppendF(&result, "Scheduled rendering rate: %d fps\n",
502 mRenderRate ? mRenderRate->getIntValue() : 0);
503 StringAppendF(&result, "%s", indent.c_str());
Alec Mouriadebf5c2021-01-05 12:57:36 -0800504 StringAppendF(&result, "Layer ID : %d\n", mLayerId);
505 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800506 StringAppendF(&result, "Present State : %s\n", toString(mPresentState).c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700507 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000508 if (mPresentState == PresentState::Dropped) {
509 std::chrono::nanoseconds dropTime(mDropTime - baseTime);
510 StringAppendF(&result, "Drop time : %10f\n",
511 std::chrono::duration<double, std::milli>(dropTime).count());
512 StringAppendF(&result, "%s", indent.c_str());
513 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700514 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
515 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800516 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700517 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800518 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
519 StringAppendF(&result, "%s", indent.c_str());
520 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
521 std::chrono::nanoseconds latchTime(
522 std::max(static_cast<int64_t>(0), mLastLatchTime - baseTime));
523 StringAppendF(&result, "%s", indent.c_str());
524 StringAppendF(&result, "Last latch time: %10f\n",
525 std::chrono::duration<double, std::milli>(latchTime).count());
526 if (mPredictionState == PredictionState::Valid) {
527 nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime;
528 std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta));
529 StringAppendF(&result, "%s", indent.c_str());
530 StringAppendF(&result, "Present delta: %10f\n",
531 std::chrono::duration<double, std::milli>(presentDeltaNs).count());
532 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700533 dumpTable(result, mPredictions, mActuals, indent, mPredictionState, baseTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700534}
535
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000536std::string SurfaceFrame::miniDump() const {
537 std::scoped_lock lock(mMutex);
538 std::string result;
539 StringAppendF(&result, "Layer - %s\n", mDebugName.c_str());
540 StringAppendF(&result, "Token: %" PRId64 "\n", mToken);
541 StringAppendF(&result, "Is Buffer?: %d\n", mIsBuffer);
542 StringAppendF(&result, "Present State : %s\n", toString(mPresentState).c_str());
543 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
544 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
545 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
546 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
547 StringAppendF(&result, "Present time: %" PRId64 "", mActuals.presentTime);
548 return result;
549}
550
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000551void SurfaceFrame::classifyJankLocked(int32_t displayFrameJankType, const Fps& refreshRate,
Ady Abrahame96e79f2024-05-20 18:00:39 +0000552 Fps displayFrameRenderRate, nsecs_t* outDeadlineDelta) {
Ady Abrahame43ff722022-02-15 14:44:25 -0800553 if (mActuals.presentTime == Fence::SIGNAL_TIME_INVALID) {
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000554 // Cannot do any classification for invalid present time.
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000555 mJankType = JankType::Unknown;
Ying Wei96eb5352023-11-21 17:37:21 +0000556 mJankSeverityType = JankSeverityType::Unknown;
Ady Abrahame96e79f2024-05-20 18:00:39 +0000557 if (outDeadlineDelta) {
558 *outDeadlineDelta = -1;
559 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800560 return;
561 }
562
Ady Abrahame43ff722022-02-15 14:44:25 -0800563 if (mPredictionState == PredictionState::Expired) {
564 // We classify prediction expired as AppDeadlineMissed as the
565 // TokenManager::kMaxTokens we store is large enough to account for a
566 // reasonable app, so prediction expire would mean a huge scheduling delay.
Edgar Arriaga631e4252023-03-02 02:11:24 +0000567 mJankType = mPresentState != PresentState::Presented ? JankType::Dropped
568 : JankType::AppDeadlineMissed;
Ying Wei96eb5352023-11-21 17:37:21 +0000569 mJankSeverityType = JankSeverityType::Unknown;
Ady Abrahame96e79f2024-05-20 18:00:39 +0000570 if (outDeadlineDelta) {
571 *outDeadlineDelta = -1;
572 }
Ady Abrahame43ff722022-02-15 14:44:25 -0800573 return;
574 }
575
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800576 if (mPredictionState == PredictionState::None) {
577 // Cannot do jank classification on frames that don't have a token.
578 return;
579 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800580
581 const nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime;
Alec Mouriadebf5c2021-01-05 12:57:36 -0800582 const nsecs_t deltaToVsync = refreshRate.getPeriodNsecs() > 0
583 ? std::abs(presentDelta) % refreshRate.getPeriodNsecs()
584 : 0;
Ady Abrahame96e79f2024-05-20 18:00:39 +0000585 const nsecs_t deadlineDelta = mActuals.endTime - mPredictions.endTime;
586 if (outDeadlineDelta) {
587 *outDeadlineDelta = deadlineDelta;
588 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800589
590 if (deadlineDelta > mJankClassificationThresholds.deadlineThreshold) {
591 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
592 } else {
593 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
594 }
595
596 if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) {
597 mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent
598 : FramePresentMetadata::EarlyPresent;
Ying Wei96eb5352023-11-21 17:37:21 +0000599 // Jank that is missing by less than the render rate period is classified as partial jank,
600 // otherwise it is a full jank.
601 mJankSeverityType = std::abs(presentDelta) < displayFrameRenderRate.getPeriodNsecs()
602 ? JankSeverityType::Partial
603 : JankSeverityType::Full;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800604 } else {
605 mFramePresentMetadata = FramePresentMetadata::OnTimePresent;
606 }
607
608 if (mFramePresentMetadata == FramePresentMetadata::OnTimePresent) {
609 // Frames presented on time are not janky.
610 mJankType = JankType::None;
611 } else if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) {
612 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
613 // Finish on time, Present early
614 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -0800615 deltaToVsync >= refreshRate.getPeriodNsecs() -
616 mJankClassificationThresholds.presentThreshold) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800617 // Delta factor of vsync
618 mJankType = JankType::SurfaceFlingerScheduling;
619 } else {
620 // Delta not a factor of vsync
621 mJankType = JankType::PredictionError;
622 }
623 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
624 // Finish late, Present early
625 mJankType = JankType::Unknown;
626 }
627 } else {
628 if (mLastLatchTime != 0 && mPredictions.endTime <= mLastLatchTime) {
629 // Buffer Stuffing.
630 mJankType |= JankType::BufferStuffing;
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000631 // In a stuffed state, the frame could be stuck on a dequeue wait for quite some time.
632 // Because of this dequeue wait, it can be hard to tell if a frame was genuinely late.
633 // We try to do this by moving the deadline. Since the queue could be stuffed by more
634 // than one buffer, we take the last latch time as reference and give one vsync
635 // worth of time for the frame to be ready.
636 nsecs_t adjustedDeadline = mLastLatchTime + refreshRate.getPeriodNsecs();
637 if (adjustedDeadline > mActuals.endTime) {
638 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
639 } else {
640 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
641 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800642 }
643 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
644 // Finish on time, Present late
645 if (displayFrameJankType != JankType::None) {
646 // Propagate displayFrame's jank if it exists
647 mJankType |= displayFrameJankType;
648 } else {
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000649 if (!(mJankType & JankType::BufferStuffing)) {
650 // In a stuffed state, if the app finishes on time and there is no display frame
651 // jank, only buffer stuffing is the root cause of the jank.
652 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
653 deltaToVsync >= refreshRate.getPeriodNsecs() -
654 mJankClassificationThresholds.presentThreshold) {
655 // Delta factor of vsync
656 mJankType |= JankType::SurfaceFlingerScheduling;
657 } else {
658 // Delta not a factor of vsync
659 mJankType |= JankType::PredictionError;
660 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800661 }
662 }
663 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
664 // Finish late, Present late
Adithya Srinivasan8a945502021-03-19 19:12:32 +0000665 mJankType |= JankType::AppDeadlineMissed;
666 // Propagate DisplayFrame's jankType if it is janky
667 mJankType |= displayFrameJankType;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800668 }
669 }
Edgar Arriaga631e4252023-03-02 02:11:24 +0000670 if (mPresentState != PresentState::Presented) {
671 mJankType = JankType::Dropped;
672 // Since frame was not presented, lets drop any present value
673 mActuals.presentTime = 0;
Ying Wei96eb5352023-11-21 17:37:21 +0000674 mJankSeverityType = JankSeverityType::Unknown;
Edgar Arriaga631e4252023-03-02 02:11:24 +0000675 }
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000676}
677
678void SurfaceFrame::onPresent(nsecs_t presentTime, int32_t displayFrameJankType, Fps refreshRate,
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200679 Fps displayFrameRenderRate, nsecs_t displayDeadlineDelta,
680 nsecs_t displayPresentDelta) {
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000681 std::scoped_lock lock(mMutex);
682
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200683 mDisplayFrameRenderRate = displayFrameRenderRate;
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000684 mActuals.presentTime = presentTime;
685 nsecs_t deadlineDelta = 0;
686
Ady Abrahame96e79f2024-05-20 18:00:39 +0000687 classifyJankLocked(displayFrameJankType, refreshRate, displayFrameRenderRate, &deadlineDelta);
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000688
689 if (mPredictionState != PredictionState::None) {
690 // Only update janky frames if the app used vsync predictions
691 mTimeStats->incrementJankyFrames({refreshRate, mRenderRate, mOwnerUid, mLayerName,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000692 mGameMode, mJankType, displayDeadlineDelta,
693 displayPresentDelta, deadlineDelta});
Pascal Mütschardd56514e2024-05-24 17:37:13 +0200694
695 gui::JankData jd;
696 jd.frameVsyncId = mToken;
697 jd.jankType = mJankType;
698 jd.frameIntervalNs =
699 (mRenderRate ? *mRenderRate : mDisplayFrameRenderRate).getPeriodNsecs();
Pascal Mütschard0e8452b2024-09-03 11:02:11 +0200700
701 if (mPredictionState == PredictionState::Valid) {
702 jd.scheduledAppFrameTimeNs = mPredictions.endTime - mPredictions.startTime;
703
704 // Using expected start, rather than actual, to measure the entire frame time. That is
705 // if the application starts the frame later than scheduled, include that delay in the
706 // frame time, as it usually means main thread being busy with non-rendering work.
707 if (mPresentState == PresentState::Dropped) {
708 jd.actualAppFrameTimeNs = mDropTime - mPredictions.startTime;
709 } else {
710 jd.actualAppFrameTimeNs = mActuals.endTime - mPredictions.startTime;
711 }
712 } else {
713 jd.scheduledAppFrameTimeNs = 0;
714 jd.actualAppFrameTimeNs = 0;
715 }
716
Pascal Mütschardd56514e2024-05-24 17:37:13 +0200717 JankTracker::onJankData(mLayerId, jd);
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000718 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800719}
720
Ady Abraham14beed72024-05-15 17:16:45 -0700721void SurfaceFrame::onCommitNotComposited(Fps refreshRate, Fps displayFrameRenderRate) {
722 std::scoped_lock lock(mMutex);
723
724 mDisplayFrameRenderRate = displayFrameRenderRate;
725 mActuals.presentTime = mPredictions.presentTime;
Ady Abrahame96e79f2024-05-20 18:00:39 +0000726 classifyJankLocked(JankType::None, refreshRate, displayFrameRenderRate, nullptr);
Ady Abraham14beed72024-05-15 17:16:45 -0700727}
728
Ady Abraham57f8e182022-03-08 15:54:33 -0800729void SurfaceFrame::tracePredictions(int64_t displayFrameToken, nsecs_t monoBootOffset) const {
Adithya Srinivasan86678502021-01-19 21:50:38 +0000730 int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000731
Adithya Srinivasan86678502021-01-19 21:50:38 +0000732 // Expected timeline start
733 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000734 std::scoped_lock lock(mMutex);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700735 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -0800736 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
737 packet->set_timestamp(static_cast<uint64_t>(mPredictions.startTime + monoBootOffset));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700738
739 auto* event = packet->set_frame_timeline_event();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000740 auto* expectedSurfaceFrameStartEvent = event->set_expected_surface_frame_start();
Adithya Srinivasan01189672020-10-20 14:23:05 -0700741
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000742 expectedSurfaceFrameStartEvent->set_cookie(expectedTimelineCookie);
743
744 expectedSurfaceFrameStartEvent->set_token(mToken);
745 expectedSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken);
746
747 expectedSurfaceFrameStartEvent->set_pid(mOwnerPid);
748 expectedSurfaceFrameStartEvent->set_layer_name(mDebugName);
749 });
Adithya Srinivasan86678502021-01-19 21:50:38 +0000750
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000751 // Expected timeline end
752 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000753 std::scoped_lock lock(mMutex);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000754 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -0800755 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
756 packet->set_timestamp(static_cast<uint64_t>(mPredictions.endTime + monoBootOffset));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000757
758 auto* event = packet->set_frame_timeline_event();
759 auto* expectedSurfaceFrameEndEvent = event->set_frame_end();
760
761 expectedSurfaceFrameEndEvent->set_cookie(expectedTimelineCookie);
762 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000763}
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000764
Ady Abraham57f8e182022-03-08 15:54:33 -0800765void SurfaceFrame::traceActuals(int64_t displayFrameToken, nsecs_t monoBootOffset) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000766 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000767
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000768 // Actual timeline start
769 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000770 std::scoped_lock lock(mMutex);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000771 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -0800772 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000773 // Actual start time is not yet available, so use expected start instead
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000774 if (mPredictionState == PredictionState::Expired) {
775 // If prediction is expired, we can't use the predicted start time. Instead, just use a
776 // start time a little earlier than the end time so that we have some info about this
777 // frame in the trace.
Adithya Srinivasanb2283c32021-04-21 21:31:56 +0000778 nsecs_t endTime =
779 (mPresentState == PresentState::Dropped ? mDropTime : mActuals.endTime);
Ady Abrahamdee22322022-03-18 10:58:39 -0700780 const auto timestamp = endTime - kPredictionExpiredStartTimeDelta;
781 packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset));
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000782 } else {
Ady Abrahamdee22322022-03-18 10:58:39 -0700783 const auto timestamp =
784 mActuals.startTime == 0 ? mPredictions.startTime : mActuals.startTime;
785 packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset));
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000786 }
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000787
788 auto* event = packet->set_frame_timeline_event();
789 auto* actualSurfaceFrameStartEvent = event->set_actual_surface_frame_start();
790
791 actualSurfaceFrameStartEvent->set_cookie(actualTimelineCookie);
792
793 actualSurfaceFrameStartEvent->set_token(mToken);
794 actualSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken);
795
796 actualSurfaceFrameStartEvent->set_pid(mOwnerPid);
797 actualSurfaceFrameStartEvent->set_layer_name(mDebugName);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700798
799 if (mPresentState == PresentState::Dropped) {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000800 actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700801 } else if (mPresentState == PresentState::Unknown) {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000802 actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_UNSPECIFIED);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700803 } else {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000804 actualSurfaceFrameStartEvent->set_present_type(toProto(mFramePresentMetadata));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700805 }
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000806 actualSurfaceFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
807 FrameReadyMetadata::OnTimeFinish);
808 actualSurfaceFrameStartEvent->set_gpu_composition(mGpuComposition);
809 actualSurfaceFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType));
Adithya Srinivasan78e58af2021-02-25 00:08:08 +0000810 actualSurfaceFrameStartEvent->set_prediction_type(toProto(mPredictionState));
Adithya Srinivasan1f9450c2021-06-10 22:39:19 +0000811 actualSurfaceFrameStartEvent->set_is_buffer(mIsBuffer);
Ying Wei96eb5352023-11-21 17:37:21 +0000812 actualSurfaceFrameStartEvent->set_jank_severity_type(toProto(mJankSeverityType));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000813 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000814
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000815 // Actual timeline end
816 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000817 std::scoped_lock lock(mMutex);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000818 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -0800819 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000820 if (mPresentState == PresentState::Dropped) {
Ady Abraham57f8e182022-03-08 15:54:33 -0800821 packet->set_timestamp(static_cast<uint64_t>(mDropTime + monoBootOffset));
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000822 } else {
Ady Abraham57f8e182022-03-08 15:54:33 -0800823 packet->set_timestamp(static_cast<uint64_t>(mActuals.endTime + monoBootOffset));
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000824 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700825
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000826 auto* event = packet->set_frame_timeline_event();
827 auto* actualSurfaceFrameEndEvent = event->set_frame_end();
Adithya Srinivasan01189672020-10-20 14:23:05 -0700828
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000829 actualSurfaceFrameEndEvent->set_cookie(actualTimelineCookie);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700830 });
831}
832
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000833/**
834 * TODO(b/178637512): add inputEventId to the perfetto trace.
835 */
Ady Abraham57f8e182022-03-08 15:54:33 -0800836void SurfaceFrame::trace(int64_t displayFrameToken, nsecs_t monoBootOffset) const {
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000837 if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID ||
838 displayFrameToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
839 // No packets can be traced with a missing token.
840 return;
841 }
842 if (getPredictionState() != PredictionState::Expired) {
843 // Expired predictions have zeroed timestamps. This cannot be used in any meaningful way in
844 // a trace.
Ady Abraham57f8e182022-03-08 15:54:33 -0800845 tracePredictions(displayFrameToken, monoBootOffset);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000846 }
Ady Abraham57f8e182022-03-08 15:54:33 -0800847 traceActuals(displayFrameToken, monoBootOffset);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000848}
849
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800850namespace impl {
851
852int64_t TokenManager::generateTokenForPredictions(TimelineItem&& predictions) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000853 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000854 std::scoped_lock lock(mMutex);
Adithya Srinivasanbed4c4f2021-05-03 20:24:46 +0000855 while (mPredictions.size() >= kMaxTokens) {
856 mPredictions.erase(mPredictions.begin());
857 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800858 const int64_t assignedToken = mCurrentToken++;
Adithya Srinivasanbed4c4f2021-05-03 20:24:46 +0000859 mPredictions[assignedToken] = predictions;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800860 return assignedToken;
861}
862
863std::optional<TimelineItem> TokenManager::getPredictionsForToken(int64_t token) const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000864 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800865 auto predictionsIterator = mPredictions.find(token);
866 if (predictionsIterator != mPredictions.end()) {
Adithya Srinivasanbed4c4f2021-05-03 20:24:46 +0000867 return predictionsIterator->second;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800868 }
869 return {};
870}
871
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800872FrameTimeline::FrameTimeline(std::shared_ptr<TimeStats> timeStats, pid_t surfaceFlingerPid,
Ady Abraham57f8e182022-03-08 15:54:33 -0800873 JankClassificationThresholds thresholds, bool useBootTimeClock)
874 : mUseBootTimeClock(useBootTimeClock),
875 mMaxDisplayFrames(kDefaultMaxDisplayFrames),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800876 mTimeStats(std::move(timeStats)),
877 mSurfaceFlingerPid(surfaceFlingerPid),
Adithya Srinivasan82eef322021-04-10 00:06:04 +0000878 mJankClassificationThresholds(thresholds) {
879 mCurrentDisplayFrame =
880 std::make_shared<DisplayFrame>(mTimeStats, thresholds, &mTraceCookieCounter);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000881}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700882
Adithya Srinivasan01189672020-10-20 14:23:05 -0700883void FrameTimeline::onBootFinished() {
884 perfetto::TracingInitArgs args;
885 args.backends = perfetto::kSystemBackend;
886 perfetto::Tracing::Initialize(args);
887 registerDataSource();
888}
889
890void FrameTimeline::registerDataSource() {
891 perfetto::DataSourceDescriptor dsd;
892 dsd.set_name(kFrameTimelineDataSource);
893 FrameTimelineDataSource::Register(dsd);
894}
895
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800896std::shared_ptr<SurfaceFrame> FrameTimeline::createSurfaceFrameForToken(
Alec Mouriadebf5c2021-01-05 12:57:36 -0800897 const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid, uid_t ownerUid, int32_t layerId,
Dominik Laskowskif5d0ea52021-09-26 17:27:01 -0700898 std::string layerName, std::string debugName, bool isBuffer, GameMode gameMode) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000899 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000900 if (frameTimelineInfo.vsyncId == FrameTimelineInfo::INVALID_VSYNC_ID) {
Alec Mouriadebf5c2021-01-05 12:57:36 -0800901 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000902 std::move(layerName), std::move(debugName),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800903 PredictionState::None, TimelineItem(), mTimeStats,
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000904 mJankClassificationThresholds, &mTraceCookieCounter,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000905 isBuffer, gameMode);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700906 }
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000907 std::optional<TimelineItem> predictions =
908 mTokenManager.getPredictionsForToken(frameTimelineInfo.vsyncId);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700909 if (predictions) {
Alec Mouriadebf5c2021-01-05 12:57:36 -0800910 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000911 std::move(layerName), std::move(debugName),
912 PredictionState::Valid, std::move(*predictions),
913 mTimeStats, mJankClassificationThresholds,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000914 &mTraceCookieCounter, isBuffer, gameMode);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700915 }
Alec Mouriadebf5c2021-01-05 12:57:36 -0800916 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000917 std::move(layerName), std::move(debugName),
918 PredictionState::Expired, TimelineItem(), mTimeStats,
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000919 mJankClassificationThresholds, &mTraceCookieCounter,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000920 isBuffer, gameMode);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700921}
922
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800923FrameTimeline::DisplayFrame::DisplayFrame(std::shared_ptr<TimeStats> timeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000924 JankClassificationThresholds thresholds,
925 TraceCookieCounter* traceCookieCounter)
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800926 : mSurfaceFlingerPredictions(TimelineItem()),
927 mSurfaceFlingerActuals(TimelineItem()),
928 mTimeStats(timeStats),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000929 mJankClassificationThresholds(thresholds),
930 mTraceCookieCounter(*traceCookieCounter) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800931 mSurfaceFrames.reserve(kNumSurfaceFramesInitial);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700932}
933
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800934void FrameTimeline::addSurfaceFrame(std::shared_ptr<SurfaceFrame> surfaceFrame) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000935 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000936 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800937 mCurrentDisplayFrame->addSurfaceFrame(surfaceFrame);
938}
939
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200940void FrameTimeline::setSfWakeUp(int64_t token, nsecs_t wakeUpTime, Fps refreshRate,
941 Fps renderRate) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000942 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000943 std::scoped_lock lock(mMutex);
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200944 mCurrentDisplayFrame->onSfWakeUp(token, refreshRate, renderRate,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800945 mTokenManager.getPredictionsForToken(token), wakeUpTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700946}
947
948void FrameTimeline::setSfPresent(nsecs_t sfPresentTime,
Adithya Srinivasanb6a2fa12021-03-13 00:23:09 +0000949 const std::shared_ptr<FenceTime>& presentFence,
Adithya Srinivasan36b01af2021-04-07 22:29:47 +0000950 const std::shared_ptr<FenceTime>& gpuFence) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000951 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000952 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800953 mCurrentDisplayFrame->setActualEndTime(sfPresentTime);
Adithya Srinivasan36b01af2021-04-07 22:29:47 +0000954 mCurrentDisplayFrame->setGpuFence(gpuFence);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700955 mPendingPresentFences.emplace_back(std::make_pair(presentFence, mCurrentDisplayFrame));
956 flushPendingPresentFences();
957 finalizeCurrentDisplayFrame();
958}
959
Ady Abraham14beed72024-05-15 17:16:45 -0700960void FrameTimeline::onCommitNotComposited() {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000961 SFTRACE_CALL();
Ady Abraham14beed72024-05-15 17:16:45 -0700962 std::scoped_lock lock(mMutex);
963 mCurrentDisplayFrame->onCommitNotComposited();
964 mCurrentDisplayFrame.reset();
965 mCurrentDisplayFrame = std::make_shared<DisplayFrame>(mTimeStats, mJankClassificationThresholds,
966 &mTraceCookieCounter);
967}
968
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800969void FrameTimeline::DisplayFrame::addSurfaceFrame(std::shared_ptr<SurfaceFrame> surfaceFrame) {
970 mSurfaceFrames.push_back(surfaceFrame);
971}
972
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200973void FrameTimeline::DisplayFrame::onSfWakeUp(int64_t token, Fps refreshRate, Fps renderRate,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800974 std::optional<TimelineItem> predictions,
975 nsecs_t wakeUpTime) {
976 mToken = token;
Alec Mouri7d436ec2021-01-27 20:40:50 -0800977 mRefreshRate = refreshRate;
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200978 mRenderRate = renderRate;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800979 if (!predictions) {
980 mPredictionState = PredictionState::Expired;
981 } else {
982 mPredictionState = PredictionState::Valid;
983 mSurfaceFlingerPredictions = *predictions;
984 }
985 mSurfaceFlingerActuals.startTime = wakeUpTime;
986}
987
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800988void FrameTimeline::DisplayFrame::setPredictions(PredictionState predictionState,
989 TimelineItem predictions) {
990 mPredictionState = predictionState;
991 mSurfaceFlingerPredictions = predictions;
992}
993
994void FrameTimeline::DisplayFrame::setActualStartTime(nsecs_t actualStartTime) {
995 mSurfaceFlingerActuals.startTime = actualStartTime;
996}
997
998void FrameTimeline::DisplayFrame::setActualEndTime(nsecs_t actualEndTime) {
999 mSurfaceFlingerActuals.endTime = actualEndTime;
1000}
1001
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001002void FrameTimeline::DisplayFrame::setGpuFence(const std::shared_ptr<FenceTime>& gpuFence) {
1003 mGpuFence = gpuFence;
Adithya Srinivasanb6a2fa12021-03-13 00:23:09 +00001004}
1005
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001006void FrameTimeline::DisplayFrame::classifyJank(nsecs_t& deadlineDelta, nsecs_t& deltaToVsync,
1007 nsecs_t previousPresentTime) {
Ady Abrahamb1e10d12023-03-13 15:23:54 -07001008 const bool presentTimeValid =
1009 mSurfaceFlingerActuals.presentTime >= mSurfaceFlingerActuals.startTime;
1010 if (mPredictionState == PredictionState::Expired || !presentTimeValid) {
Adithya Srinivasande272452021-04-10 00:21:00 +00001011 // Cannot do jank classification with expired predictions or invalid signal times. Set the
1012 // deltas to 0 as both negative and positive deltas are used as real values.
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001013 mJankType = JankType::Unknown;
Ying Wei96eb5352023-11-21 17:37:21 +00001014 mJankSeverityType = JankSeverityType::Unknown;
Adithya Srinivasande272452021-04-10 00:21:00 +00001015 deadlineDelta = 0;
1016 deltaToVsync = 0;
Ady Abrahamb1e10d12023-03-13 15:23:54 -07001017 if (!presentTimeValid) {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001018 mSurfaceFlingerActuals.presentTime = mSurfaceFlingerActuals.endTime;
Ady Abrahamb1e10d12023-03-13 15:23:54 -07001019 mJankType |= JankType::DisplayHAL;
Ady Abrahamfcb16862022-10-10 14:35:21 -07001020 }
1021
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001022 return;
1023 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001024
1025 // Delta between the expected present and the actual present
1026 const nsecs_t presentDelta =
1027 mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime;
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001028 // Sf actual end time represents the CPU end time. In case of HWC, SF's end time would have
1029 // included the time for composition. However, for GPU composition, the final end time is max(sf
1030 // end time, gpu fence time).
1031 nsecs_t combinedEndTime = mSurfaceFlingerActuals.endTime;
1032 if (mGpuFence != FenceTime::NO_FENCE) {
1033 combinedEndTime = std::max(combinedEndTime, mGpuFence->getSignalTime());
1034 }
1035 deadlineDelta = combinedEndTime - mSurfaceFlingerPredictions.endTime;
Alec Mouri363faf02021-01-29 16:34:55 -08001036
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001037 // How far off was the presentDelta when compared to the vsyncPeriod. Used in checking if there
1038 // was a prediction error or not.
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001039 deltaToVsync = mRefreshRate.getPeriodNsecs() > 0
Alec Mouriadebf5c2021-01-05 12:57:36 -08001040 ? std::abs(presentDelta) % mRefreshRate.getPeriodNsecs()
1041 : 0;
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001042
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001043 if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) {
1044 mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent
1045 : FramePresentMetadata::EarlyPresent;
Ying Wei96eb5352023-11-21 17:37:21 +00001046 // Jank that is missing by less than the render rate period is classified as partial jank,
1047 // otherwise it is a full jank.
1048 mJankSeverityType = std::abs(presentDelta) < mRenderRate.getPeriodNsecs()
1049 ? JankSeverityType::Partial
1050 : JankSeverityType::Full;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001051 } else {
1052 mFramePresentMetadata = FramePresentMetadata::OnTimePresent;
1053 }
1054
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001055 if (combinedEndTime > mSurfaceFlingerPredictions.endTime) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001056 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
1057 } else {
1058 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
1059 }
1060
1061 if (std::abs(mSurfaceFlingerActuals.startTime - mSurfaceFlingerPredictions.startTime) >
1062 mJankClassificationThresholds.startThreshold) {
1063 mFrameStartMetadata =
1064 mSurfaceFlingerActuals.startTime > mSurfaceFlingerPredictions.startTime
1065 ? FrameStartMetadata::LateStart
1066 : FrameStartMetadata::EarlyStart;
1067 }
1068
1069 if (mFramePresentMetadata != FramePresentMetadata::OnTimePresent) {
1070 // Do jank classification only if present is not on time
1071 if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) {
1072 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
1073 // Finish on time, Present early
1074 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -08001075 deltaToVsync >= (mRefreshRate.getPeriodNsecs() -
1076 mJankClassificationThresholds.presentThreshold)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001077 // Delta is a factor of vsync if its within the presentTheshold on either side
1078 // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold
1079 // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms.
1080 mJankType = JankType::SurfaceFlingerScheduling;
1081 } else {
1082 // Delta is not a factor of vsync,
1083 mJankType = JankType::PredictionError;
1084 }
1085 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
1086 // Finish late, Present early
1087 mJankType = JankType::SurfaceFlingerScheduling;
1088 } else {
1089 // Finish time unknown
1090 mJankType = JankType::Unknown;
1091 }
1092 } else if (mFramePresentMetadata == FramePresentMetadata::LatePresent) {
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001093 if (std::abs(mSurfaceFlingerPredictions.presentTime - previousPresentTime) <=
1094 mJankClassificationThresholds.presentThreshold ||
1095 previousPresentTime > mSurfaceFlingerPredictions.presentTime) {
1096 // The previous frame was either presented in the current frame's expected vsync or
1097 // it was presented even later than the current frame's expected vsync.
1098 mJankType = JankType::SurfaceFlingerStuffing;
1099 }
1100 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish &&
1101 !(mJankType & JankType::SurfaceFlingerStuffing)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001102 // Finish on time, Present late
1103 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -08001104 deltaToVsync >= (mRefreshRate.getPeriodNsecs() -
1105 mJankClassificationThresholds.presentThreshold)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001106 // Delta is a factor of vsync if its within the presentTheshold on either side
1107 // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold
1108 // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms.
1109 mJankType = JankType::DisplayHAL;
1110 } else {
1111 // Delta is not a factor of vsync
1112 mJankType = JankType::PredictionError;
1113 }
1114 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001115 if (!(mJankType & JankType::SurfaceFlingerStuffing) ||
1116 mSurfaceFlingerActuals.presentTime - previousPresentTime >
1117 mRefreshRate.getPeriodNsecs() +
1118 mJankClassificationThresholds.presentThreshold) {
1119 // Classify CPU vs GPU if SF wasn't stuffed or if SF was stuffed but this frame
1120 // was presented more than a vsync late.
Rachel Lee94917b32022-03-18 17:52:09 -07001121 if (mGpuFence != FenceTime::NO_FENCE) {
1122 // If SF was in GPU composition, classify it as GPU deadline missed.
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001123 mJankType = JankType::SurfaceFlingerGpuDeadlineMissed;
1124 } else {
1125 mJankType = JankType::SurfaceFlingerCpuDeadlineMissed;
1126 }
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +00001127 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001128 } else {
1129 // Finish time unknown
1130 mJankType = JankType::Unknown;
1131 }
1132 } else {
1133 // Present unknown
1134 mJankType = JankType::Unknown;
1135 }
1136 }
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001137}
1138
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001139void FrameTimeline::DisplayFrame::onPresent(nsecs_t signalTime, nsecs_t previousPresentTime) {
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001140 mSurfaceFlingerActuals.presentTime = signalTime;
1141 nsecs_t deadlineDelta = 0;
1142 nsecs_t deltaToVsync = 0;
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001143 classifyJank(deadlineDelta, deltaToVsync, previousPresentTime);
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001144
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001145 for (auto& surfaceFrame : mSurfaceFrames) {
Pascal Muetschardac7bcd92023-10-03 15:05:36 +02001146 surfaceFrame->onPresent(signalTime, mJankType, mRefreshRate, mRenderRate, deadlineDelta,
1147 deltaToVsync);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001148 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001149}
1150
Ady Abraham14beed72024-05-15 17:16:45 -07001151void FrameTimeline::DisplayFrame::onCommitNotComposited() {
1152 for (auto& surfaceFrame : mSurfaceFrames) {
1153 surfaceFrame->onCommitNotComposited(mRefreshRate, mRenderRate);
1154 }
1155}
1156
Ady Abraham57f8e182022-03-08 15:54:33 -08001157void FrameTimeline::DisplayFrame::tracePredictions(pid_t surfaceFlingerPid,
1158 nsecs_t monoBootOffset) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001159 int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001160
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001161 // Expected timeline start
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001162 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001163 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -08001164 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1165 packet->set_timestamp(
1166 static_cast<uint64_t>(mSurfaceFlingerPredictions.startTime + monoBootOffset));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001167
1168 auto* event = packet->set_frame_timeline_event();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001169 auto* expectedDisplayFrameStartEvent = event->set_expected_display_frame_start();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001170
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001171 expectedDisplayFrameStartEvent->set_cookie(expectedTimelineCookie);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001172
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001173 expectedDisplayFrameStartEvent->set_token(mToken);
1174 expectedDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
1175 });
Adithya Srinivasan86678502021-01-19 21:50:38 +00001176
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001177 // Expected timeline end
1178 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
1179 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -08001180 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1181 packet->set_timestamp(
1182 static_cast<uint64_t>(mSurfaceFlingerPredictions.endTime + monoBootOffset));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001183
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001184 auto* event = packet->set_frame_timeline_event();
1185 auto* expectedDisplayFrameEndEvent = event->set_frame_end();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001186
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001187 expectedDisplayFrameEndEvent->set_cookie(expectedTimelineCookie);
1188 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001189}
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001190
Sally Qiaa107742023-09-29 14:53:14 -07001191void FrameTimeline::DisplayFrame::addSkippedFrame(pid_t surfaceFlingerPid, nsecs_t monoBootOffset,
Sally Qi438eb7d2023-12-05 18:59:32 -08001192 nsecs_t previousPredictionPresentTime) const {
Sally Qiaa107742023-09-29 14:53:14 -07001193 nsecs_t skippedFrameStartTime = 0, skippedFramePresentTime = 0;
1194 const constexpr float kThresh = 0.5f;
1195 const constexpr float kRange = 1.5f;
1196 for (auto& surfaceFrame : mSurfaceFrames) {
Sally Qi438eb7d2023-12-05 18:59:32 -08001197 if (previousPredictionPresentTime != 0 &&
1198 static_cast<float>(mSurfaceFlingerPredictions.presentTime -
1199 previousPredictionPresentTime) >=
Sally Qiaa107742023-09-29 14:53:14 -07001200 static_cast<float>(mRenderRate.getPeriodNsecs()) * kRange &&
1201 static_cast<float>(surfaceFrame->getPredictions().presentTime) <=
Sally Qi438eb7d2023-12-05 18:59:32 -08001202 (static_cast<float>(mSurfaceFlingerPredictions.presentTime) -
Sally Qiaa107742023-09-29 14:53:14 -07001203 kThresh * static_cast<float>(mRenderRate.getPeriodNsecs())) &&
1204 static_cast<float>(surfaceFrame->getPredictions().presentTime) >=
Sally Qi2269a692024-05-17 18:02:28 -07001205 (static_cast<float>(previousPredictionPresentTime) +
Sally Qi438eb7d2023-12-05 18:59:32 -08001206 kThresh * static_cast<float>(mRenderRate.getPeriodNsecs())) &&
1207 // sf skipped frame is not considered if app is self janked
1208 !surfaceFrame->isSelfJanky()) {
Sally Qiaa107742023-09-29 14:53:14 -07001209 skippedFrameStartTime = surfaceFrame->getPredictions().endTime;
1210 skippedFramePresentTime = surfaceFrame->getPredictions().presentTime;
1211 break;
1212 }
1213 }
1214
1215 // add slice
1216 if (skippedFrameStartTime != 0 && skippedFramePresentTime != 0) {
1217 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
1218
1219 // Actual timeline start
1220 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
1221 auto packet = ctx.NewTracePacket();
1222 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1223 packet->set_timestamp(static_cast<uint64_t>(skippedFrameStartTime + monoBootOffset));
1224
1225 auto* event = packet->set_frame_timeline_event();
1226 auto* actualDisplayFrameStartEvent = event->set_actual_display_frame_start();
1227
1228 actualDisplayFrameStartEvent->set_cookie(actualTimelineCookie);
1229
1230 actualDisplayFrameStartEvent->set_token(0);
1231 actualDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
1232 actualDisplayFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
1233 FrameReadyMetadata::OnTimeFinish);
1234 actualDisplayFrameStartEvent->set_gpu_composition(false);
1235 actualDisplayFrameStartEvent->set_prediction_type(toProto(PredictionState::Valid));
1236 actualDisplayFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED);
1237 actualDisplayFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(JankType::Dropped));
Ying Wei96eb5352023-11-21 17:37:21 +00001238 actualDisplayFrameStartEvent->set_jank_severity_type(toProto(JankSeverityType::None));
Sally Qiaa107742023-09-29 14:53:14 -07001239 });
1240
1241 // Actual timeline end
1242 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
1243 auto packet = ctx.NewTracePacket();
1244 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1245 packet->set_timestamp(static_cast<uint64_t>(skippedFramePresentTime + monoBootOffset));
1246
1247 auto* event = packet->set_frame_timeline_event();
1248 auto* actualDisplayFrameEndEvent = event->set_frame_end();
1249
1250 actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie);
1251 });
1252 }
1253}
1254
Ady Abraham57f8e182022-03-08 15:54:33 -08001255void FrameTimeline::DisplayFrame::traceActuals(pid_t surfaceFlingerPid,
1256 nsecs_t monoBootOffset) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001257 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001258
1259 // Actual timeline start
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001260 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
1261 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -08001262 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1263 packet->set_timestamp(
1264 static_cast<uint64_t>(mSurfaceFlingerActuals.startTime + monoBootOffset));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001265
1266 auto* event = packet->set_frame_timeline_event();
1267 auto* actualDisplayFrameStartEvent = event->set_actual_display_frame_start();
1268
1269 actualDisplayFrameStartEvent->set_cookie(actualTimelineCookie);
1270
1271 actualDisplayFrameStartEvent->set_token(mToken);
1272 actualDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
1273
1274 actualDisplayFrameStartEvent->set_present_type(toProto(mFramePresentMetadata));
1275 actualDisplayFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
1276 FrameReadyMetadata::OnTimeFinish);
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001277 actualDisplayFrameStartEvent->set_gpu_composition(mGpuFence != FenceTime::NO_FENCE);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001278 actualDisplayFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType));
Adithya Srinivasan78e58af2021-02-25 00:08:08 +00001279 actualDisplayFrameStartEvent->set_prediction_type(toProto(mPredictionState));
Ying Wei96eb5352023-11-21 17:37:21 +00001280 actualDisplayFrameStartEvent->set_jank_severity_type(toProto(mJankSeverityType));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001281 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001282
1283 // Actual timeline end
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001284 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
1285 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -08001286 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1287 packet->set_timestamp(
1288 static_cast<uint64_t>(mSurfaceFlingerActuals.presentTime + monoBootOffset));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001289
1290 auto* event = packet->set_frame_timeline_event();
1291 auto* actualDisplayFrameEndEvent = event->set_frame_end();
1292
1293 actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001294 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001295}
1296
Sally Qi438eb7d2023-12-05 18:59:32 -08001297nsecs_t FrameTimeline::DisplayFrame::trace(pid_t surfaceFlingerPid, nsecs_t monoBootOffset,
1298 nsecs_t previousPredictionPresentTime) const {
Ady Abraham57a8ab42023-01-26 15:28:19 -08001299 if (mSurfaceFrames.empty()) {
1300 // We don't want to trace display frames without any surface frames updates as this cannot
1301 // be janky
Sally Qi438eb7d2023-12-05 18:59:32 -08001302 return previousPredictionPresentTime;
Ady Abraham57a8ab42023-01-26 15:28:19 -08001303 }
1304
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001305 if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
1306 // DisplayFrame should not have an invalid token.
1307 ALOGE("Cannot trace DisplayFrame with invalid token");
Sally Qi438eb7d2023-12-05 18:59:32 -08001308 return previousPredictionPresentTime;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001309 }
1310
1311 if (mPredictionState == PredictionState::Valid) {
1312 // Expired and unknown predictions have zeroed timestamps. This cannot be used in any
1313 // meaningful way in a trace.
Ady Abraham57f8e182022-03-08 15:54:33 -08001314 tracePredictions(surfaceFlingerPid, monoBootOffset);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001315 }
Ady Abraham57f8e182022-03-08 15:54:33 -08001316 traceActuals(surfaceFlingerPid, monoBootOffset);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001317
1318 for (auto& surfaceFrame : mSurfaceFrames) {
Ady Abraham57f8e182022-03-08 15:54:33 -08001319 surfaceFrame->trace(mToken, monoBootOffset);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001320 }
Sally Qiaa107742023-09-29 14:53:14 -07001321
Sally Qif5721252023-11-17 11:14:53 -08001322 if (FlagManager::getInstance().add_sf_skipped_frames_to_trace()) {
Sally Qi438eb7d2023-12-05 18:59:32 -08001323 addSkippedFrame(surfaceFlingerPid, monoBootOffset, previousPredictionPresentTime);
Sally Qif5721252023-11-17 11:14:53 -08001324 }
Sally Qi438eb7d2023-12-05 18:59:32 -08001325 return mSurfaceFlingerPredictions.presentTime;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001326}
1327
Alec Mouriadebf5c2021-01-05 12:57:36 -08001328float FrameTimeline::computeFps(const std::unordered_set<int32_t>& layerIds) {
1329 if (layerIds.empty()) {
1330 return 0.0f;
1331 }
1332
1333 std::vector<nsecs_t> presentTimes;
1334 {
1335 std::scoped_lock lock(mMutex);
1336 presentTimes.reserve(mDisplayFrames.size());
1337 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
1338 const auto& displayFrame = mDisplayFrames[i];
1339 if (displayFrame->getActuals().presentTime <= 0) {
1340 continue;
1341 }
1342 for (const auto& surfaceFrame : displayFrame->getSurfaceFrames()) {
1343 if (surfaceFrame->getPresentState() == SurfaceFrame::PresentState::Presented &&
1344 layerIds.count(surfaceFrame->getLayerId()) > 0) {
1345 // We're looking for DisplayFrames that presents at least one layer from
1346 // layerIds, so push the present time and skip looking through the rest of the
1347 // SurfaceFrames.
1348 presentTimes.push_back(displayFrame->getActuals().presentTime);
1349 break;
1350 }
1351 }
1352 }
1353 }
1354
1355 // FPS can't be computed when there's fewer than 2 presented frames.
1356 if (presentTimes.size() <= 1) {
1357 return 0.0f;
1358 }
1359
1360 nsecs_t priorPresentTime = -1;
1361 nsecs_t totalPresentToPresentWalls = 0;
1362
1363 for (const nsecs_t presentTime : presentTimes) {
1364 if (priorPresentTime == -1) {
1365 priorPresentTime = presentTime;
1366 continue;
1367 }
1368
1369 totalPresentToPresentWalls += (presentTime - priorPresentTime);
1370 priorPresentTime = presentTime;
1371 }
1372
1373 if (CC_UNLIKELY(totalPresentToPresentWalls <= 0)) {
1374 ALOGW("Invalid total present-to-present duration when computing fps: %" PRId64,
1375 totalPresentToPresentWalls);
1376 return 0.0f;
1377 }
1378
1379 const constexpr nsecs_t kOneSecond =
1380 std::chrono::duration_cast<std::chrono::nanoseconds>(1s).count();
1381 // (10^9 nanoseconds / second) * (N present deltas) / (total nanoseconds in N present deltas) =
1382 // M frames / second
1383 return kOneSecond * static_cast<nsecs_t>((presentTimes.size() - 1)) /
1384 static_cast<float>(totalPresentToPresentWalls);
1385}
1386
Ady Abrahamfcb16862022-10-10 14:35:21 -07001387std::optional<size_t> FrameTimeline::getFirstSignalFenceIndex() const {
1388 for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
1389 const auto& [fence, _] = mPendingPresentFences[i];
Theodore Dubois205c6dd2022-11-23 15:06:33 -08001390 if (fence && fence->getSignalTime() != Fence::SIGNAL_TIME_PENDING) {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001391 return i;
1392 }
1393 }
1394
1395 return {};
1396}
1397
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001398void FrameTimeline::flushPendingPresentFences() {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001399 const auto firstSignaledFence = getFirstSignalFenceIndex();
1400 if (!firstSignaledFence.has_value()) {
1401 return;
1402 }
1403
Ady Abraham57f8e182022-03-08 15:54:33 -08001404 // Perfetto is using boottime clock to void drifts when the device goes
1405 // to suspend.
1406 const auto monoBootOffset = mUseBootTimeClock
1407 ? (systemTime(SYSTEM_TIME_BOOTTIME) - systemTime(SYSTEM_TIME_MONOTONIC))
1408 : 0;
1409
Ady Abrahamfcb16862022-10-10 14:35:21 -07001410 // Present fences are expected to be signaled in order. Mark all the previous
1411 // pending fences as errors.
1412 for (size_t i = 0; i < firstSignaledFence.value(); i++) {
1413 const auto& pendingPresentFence = *mPendingPresentFences.begin();
1414 const nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
1415 auto& displayFrame = pendingPresentFence.second;
Sally Qi438eb7d2023-12-05 18:59:32 -08001416 displayFrame->onPresent(signalTime, mPreviousActualPresentTime);
1417 mPreviousPredictionPresentTime = displayFrame->trace(mSurfaceFlingerPid, monoBootOffset,
1418 mPreviousPredictionPresentTime);
Ady Abrahamfcb16862022-10-10 14:35:21 -07001419 mPendingPresentFences.erase(mPendingPresentFences.begin());
1420 }
1421
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001422 for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
1423 const auto& pendingPresentFence = mPendingPresentFences[i];
1424 nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
1425 if (pendingPresentFence.first && pendingPresentFence.first->isValid()) {
1426 signalTime = pendingPresentFence.first->getSignalTime();
1427 if (signalTime == Fence::SIGNAL_TIME_PENDING) {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001428 break;
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001429 }
1430 }
Ady Abrahamfcb16862022-10-10 14:35:21 -07001431
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +00001432 auto& displayFrame = pendingPresentFence.second;
Sally Qi438eb7d2023-12-05 18:59:32 -08001433 displayFrame->onPresent(signalTime, mPreviousActualPresentTime);
1434 mPreviousPredictionPresentTime = displayFrame->trace(mSurfaceFlingerPid, monoBootOffset,
1435 mPreviousPredictionPresentTime);
1436 mPreviousActualPresentTime = signalTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001437
1438 mPendingPresentFences.erase(mPendingPresentFences.begin() + static_cast<int>(i));
1439 --i;
1440 }
1441}
1442
1443void FrameTimeline::finalizeCurrentDisplayFrame() {
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001444 while (mDisplayFrames.size() >= mMaxDisplayFrames) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001445 // We maintain only a fixed number of frames' data. Pop older frames
1446 mDisplayFrames.pop_front();
1447 }
1448 mDisplayFrames.push_back(mCurrentDisplayFrame);
1449 mCurrentDisplayFrame.reset();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001450 mCurrentDisplayFrame = std::make_shared<DisplayFrame>(mTimeStats, mJankClassificationThresholds,
Adithya Srinivasan82eef322021-04-10 00:06:04 +00001451 &mTraceCookieCounter);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001452}
1453
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001454nsecs_t FrameTimeline::DisplayFrame::getBaseTime() const {
1455 nsecs_t baseTime =
1456 getMinTime(mPredictionState, mSurfaceFlingerPredictions, mSurfaceFlingerActuals);
1457 for (const auto& surfaceFrame : mSurfaceFrames) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001458 nsecs_t surfaceFrameBaseTime = surfaceFrame->getBaseTime();
1459 if (surfaceFrameBaseTime != 0) {
1460 baseTime = std::min(baseTime, surfaceFrameBaseTime);
1461 }
1462 }
1463 return baseTime;
1464}
1465
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001466void FrameTimeline::DisplayFrame::dumpJank(std::string& result, nsecs_t baseTime,
1467 int displayFrameCount) const {
1468 if (mJankType == JankType::None) {
1469 // Check if any Surface Frame has been janky
1470 bool isJanky = false;
1471 for (const auto& surfaceFrame : mSurfaceFrames) {
1472 if (surfaceFrame->getJankType() != JankType::None) {
1473 isJanky = true;
1474 break;
1475 }
1476 }
1477 if (!isJanky) {
1478 return;
1479 }
1480 }
1481 StringAppendF(&result, "Display Frame %d", displayFrameCount);
1482 dump(result, baseTime);
1483}
1484
1485void FrameTimeline::DisplayFrame::dumpAll(std::string& result, nsecs_t baseTime) const {
1486 dump(result, baseTime);
1487}
1488
1489void FrameTimeline::DisplayFrame::dump(std::string& result, nsecs_t baseTime) const {
1490 if (mJankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001491 // Easily identify a janky Display Frame in the dump
1492 StringAppendF(&result, " [*] ");
1493 }
1494 StringAppendF(&result, "\n");
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001495 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
1496 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
1497 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
1498 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
1499 StringAppendF(&result, "Start Metadata: %s\n", toString(mFrameStartMetadata).c_str());
Alec Mouri7d436ec2021-01-27 20:40:50 -08001500 std::chrono::nanoseconds vsyncPeriod(mRefreshRate.getPeriodNsecs());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001501 StringAppendF(&result, "Vsync Period: %10f\n",
1502 std::chrono::duration<double, std::milli>(vsyncPeriod).count());
1503 nsecs_t presentDelta =
1504 mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime;
1505 std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta));
1506 StringAppendF(&result, "Present delta: %10f\n",
1507 std::chrono::duration<double, std::milli>(presentDeltaNs).count());
Alec Mouri7d436ec2021-01-27 20:40:50 -08001508 std::chrono::nanoseconds deltaToVsync(std::abs(presentDelta) % mRefreshRate.getPeriodNsecs());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001509 StringAppendF(&result, "Present delta %% refreshrate: %10f\n",
1510 std::chrono::duration<double, std::milli>(deltaToVsync).count());
1511 dumpTable(result, mSurfaceFlingerPredictions, mSurfaceFlingerActuals, "", mPredictionState,
1512 baseTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001513 StringAppendF(&result, "\n");
1514 std::string indent = " "; // 4 spaces
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001515 for (const auto& surfaceFrame : mSurfaceFrames) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001516 surfaceFrame->dump(result, indent, baseTime);
1517 }
1518 StringAppendF(&result, "\n");
1519}
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001520
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001521void FrameTimeline::dumpAll(std::string& result) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001522 std::scoped_lock lock(mMutex);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001523 StringAppendF(&result, "Number of display frames : %d\n", (int)mDisplayFrames.size());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001524 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001525 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
1526 StringAppendF(&result, "Display Frame %d", static_cast<int>(i));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001527 mDisplayFrames[i]->dumpAll(result, baseTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001528 }
1529}
1530
1531void FrameTimeline::dumpJank(std::string& result) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001532 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001533 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001534 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001535 mDisplayFrames[i]->dumpJank(result, baseTime, static_cast<int>(i));
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001536 }
1537}
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001538
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001539void FrameTimeline::parseArgs(const Vector<String16>& args, std::string& result) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +00001540 SFTRACE_CALL();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001541 std::unordered_map<std::string, bool> argsMap;
1542 for (size_t i = 0; i < args.size(); i++) {
1543 argsMap[std::string(String8(args[i]).c_str())] = true;
1544 }
1545 if (argsMap.count("-jank")) {
1546 dumpJank(result);
1547 }
1548 if (argsMap.count("-all")) {
1549 dumpAll(result);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001550 }
1551}
1552
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001553void FrameTimeline::setMaxDisplayFrames(uint32_t size) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001554 std::scoped_lock lock(mMutex);
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001555
1556 // The size can either increase or decrease, clear everything, to be consistent
1557 mDisplayFrames.clear();
1558 mPendingPresentFences.clear();
1559 mMaxDisplayFrames = size;
1560}
1561
1562void FrameTimeline::reset() {
1563 setMaxDisplayFrames(kDefaultMaxDisplayFrames);
1564}
1565
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001566} // namespace impl
1567} // namespace android::frametimeline