blob: e78bd9ace9bd8dbd8904568995d303a1b5192ec9 [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>
Melody Hsue524dd92024-08-27 22:27:29 +000032#include <vector>
Adithya Srinivasanf279e042020-08-17 14:56:27 -070033
Pascal Mütschardd56514e2024-05-24 17:37:13 +020034#include "../Jank/JankTracker.h"
35
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080036namespace android::frametimeline {
Adithya Srinivasanf279e042020-08-17 14:56:27 -070037
38using base::StringAppendF;
Adithya Srinivasan01189672020-10-20 14:23:05 -070039using FrameTimelineEvent = perfetto::protos::pbzero::FrameTimelineEvent;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +000040using FrameTimelineDataSource = impl::FrameTimeline::FrameTimelineDataSource;
Adithya Srinivasanf279e042020-08-17 14:56:27 -070041
Ady Abraham43a68c32024-09-04 19:21:20 -070042namespace {
43
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070044void dumpTable(std::string& result, TimelineItem predictions, TimelineItem actuals,
45 const std::string& indent, PredictionState predictionState, nsecs_t baseTime) {
46 StringAppendF(&result, "%s", indent.c_str());
47 StringAppendF(&result, "\t\t");
48 StringAppendF(&result, " Start time\t\t|");
49 StringAppendF(&result, " End time\t\t|");
50 StringAppendF(&result, " Present time\n");
51 if (predictionState == PredictionState::Valid) {
52 // Dump the Predictions only if they are valid
53 StringAppendF(&result, "%s", indent.c_str());
54 StringAppendF(&result, "Expected\t|");
55 std::chrono::nanoseconds startTime(predictions.startTime - baseTime);
56 std::chrono::nanoseconds endTime(predictions.endTime - baseTime);
57 std::chrono::nanoseconds presentTime(predictions.presentTime - baseTime);
58 StringAppendF(&result, "\t%10.2f\t|\t%10.2f\t|\t%10.2f\n",
59 std::chrono::duration<double, std::milli>(startTime).count(),
60 std::chrono::duration<double, std::milli>(endTime).count(),
61 std::chrono::duration<double, std::milli>(presentTime).count());
62 }
63 StringAppendF(&result, "%s", indent.c_str());
64 StringAppendF(&result, "Actual \t|");
65
66 if (actuals.startTime == 0) {
67 StringAppendF(&result, "\t\tN/A\t|");
68 } else {
69 std::chrono::nanoseconds startTime(std::max<nsecs_t>(0, actuals.startTime - baseTime));
70 StringAppendF(&result, "\t%10.2f\t|",
71 std::chrono::duration<double, std::milli>(startTime).count());
72 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080073 if (actuals.endTime <= 0) {
74 // Animation leashes can send the endTime as -1
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070075 StringAppendF(&result, "\t\tN/A\t|");
76 } else {
77 std::chrono::nanoseconds endTime(actuals.endTime - baseTime);
78 StringAppendF(&result, "\t%10.2f\t|",
79 std::chrono::duration<double, std::milli>(endTime).count());
80 }
81 if (actuals.presentTime == 0) {
82 StringAppendF(&result, "\t\tN/A\n");
83 } else {
84 std::chrono::nanoseconds presentTime(std::max<nsecs_t>(0, actuals.presentTime - baseTime));
85 StringAppendF(&result, "\t%10.2f\n",
86 std::chrono::duration<double, std::milli>(presentTime).count());
87 }
88
89 StringAppendF(&result, "%s", indent.c_str());
90 StringAppendF(&result, "----------------------");
91 StringAppendF(&result, "----------------------");
92 StringAppendF(&result, "----------------------");
93 StringAppendF(&result, "----------------------\n");
94}
95
96std::string toString(PredictionState predictionState) {
97 switch (predictionState) {
98 case PredictionState::Valid:
99 return "Valid";
100 case PredictionState::Expired:
101 return "Expired";
102 case PredictionState::None:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700103 return "None";
104 }
105}
106
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800107std::string jankTypeBitmaskToString(int32_t jankType) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800108 if (jankType == JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700109 return "None";
110 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000111
112 std::vector<std::string> janks;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800113 if (jankType & JankType::DisplayHAL) {
114 janks.emplace_back("Display HAL");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000115 jankType &= ~JankType::DisplayHAL;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800116 }
117 if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) {
Rachel Lee94917b32022-03-18 17:52:09 -0700118 janks.emplace_back("SurfaceFlinger deadline missed (while in HWC)");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000119 jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800120 }
121 if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) {
Rachel Lee94917b32022-03-18 17:52:09 -0700122 janks.emplace_back("SurfaceFlinger deadline missed (while in GPU comp)");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000123 jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800124 }
125 if (jankType & JankType::AppDeadlineMissed) {
126 janks.emplace_back("App Deadline Missed");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000127 jankType &= ~JankType::AppDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800128 }
129 if (jankType & JankType::PredictionError) {
130 janks.emplace_back("Prediction Error");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000131 jankType &= ~JankType::PredictionError;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800132 }
133 if (jankType & JankType::SurfaceFlingerScheduling) {
134 janks.emplace_back("SurfaceFlinger Scheduling");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000135 jankType &= ~JankType::SurfaceFlingerScheduling;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800136 }
137 if (jankType & JankType::BufferStuffing) {
138 janks.emplace_back("Buffer Stuffing");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000139 jankType &= ~JankType::BufferStuffing;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800140 }
141 if (jankType & JankType::Unknown) {
142 janks.emplace_back("Unknown jank");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000143 jankType &= ~JankType::Unknown;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800144 }
Adithya Srinivasan2045ddf2021-05-27 17:38:10 +0000145 if (jankType & JankType::SurfaceFlingerStuffing) {
146 janks.emplace_back("SurfaceFlinger Stuffing");
147 jankType &= ~JankType::SurfaceFlingerStuffing;
148 }
Edgar Arriaga631e4252023-03-02 02:11:24 +0000149 if (jankType & JankType::Dropped) {
150 janks.emplace_back("Dropped Frame");
151 jankType &= ~JankType::Dropped;
152 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000153
154 // jankType should be 0 if all types of jank were checked for.
155 LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800156 return std::accumulate(janks.begin(), janks.end(), std::string(),
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700157 [](const std::string& l, const std::string& r) {
158 return l.empty() ? r : l + ", " + r;
159 });
160}
161
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800162std::string toString(FramePresentMetadata presentMetadata) {
163 switch (presentMetadata) {
164 case FramePresentMetadata::OnTimePresent:
165 return "On Time Present";
166 case FramePresentMetadata::LatePresent:
167 return "Late Present";
168 case FramePresentMetadata::EarlyPresent:
169 return "Early Present";
170 case FramePresentMetadata::UnknownPresent:
171 return "Unknown Present";
Adithya Srinivasan01189672020-10-20 14:23:05 -0700172 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700173}
174
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800175std::string toString(FrameReadyMetadata finishMetadata) {
176 switch (finishMetadata) {
177 case FrameReadyMetadata::OnTimeFinish:
178 return "On Time Finish";
179 case FrameReadyMetadata::LateFinish:
180 return "Late Finish";
181 case FrameReadyMetadata::UnknownFinish:
182 return "Unknown Finish";
183 }
184}
185
186std::string toString(FrameStartMetadata startMetadata) {
187 switch (startMetadata) {
188 case FrameStartMetadata::OnTimeStart:
189 return "On Time Start";
190 case FrameStartMetadata::LateStart:
191 return "Late Start";
192 case FrameStartMetadata::EarlyStart:
193 return "Early Start";
194 case FrameStartMetadata::UnknownStart:
195 return "Unknown Start";
196 }
197}
198
199std::string toString(SurfaceFrame::PresentState presentState) {
200 using PresentState = SurfaceFrame::PresentState;
201 switch (presentState) {
202 case PresentState::Presented:
203 return "Presented";
204 case PresentState::Dropped:
205 return "Dropped";
206 case PresentState::Unknown:
207 return "Unknown";
208 }
209}
210
211FrameTimelineEvent::PresentType toProto(FramePresentMetadata presentMetadata) {
212 switch (presentMetadata) {
213 case FramePresentMetadata::EarlyPresent:
214 return FrameTimelineEvent::PRESENT_EARLY;
215 case FramePresentMetadata::LatePresent:
216 return FrameTimelineEvent::PRESENT_LATE;
217 case FramePresentMetadata::OnTimePresent:
218 return FrameTimelineEvent::PRESENT_ON_TIME;
219 case FramePresentMetadata::UnknownPresent:
220 return FrameTimelineEvent::PRESENT_UNSPECIFIED;
221 }
222}
223
Adithya Srinivasan78e58af2021-02-25 00:08:08 +0000224FrameTimelineEvent::PredictionType toProto(PredictionState predictionState) {
225 switch (predictionState) {
226 case PredictionState::Valid:
227 return FrameTimelineEvent::PREDICTION_VALID;
228 case PredictionState::Expired:
229 return FrameTimelineEvent::PREDICTION_EXPIRED;
230 case PredictionState::None:
231 return FrameTimelineEvent::PREDICTION_UNKNOWN;
232 }
233}
234
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000235int32_t jankTypeBitmaskToProto(int32_t jankType) {
236 if (jankType == JankType::None) {
237 return FrameTimelineEvent::JANK_NONE;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700238 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000239
240 int32_t protoJank = 0;
241 if (jankType & JankType::DisplayHAL) {
242 protoJank |= FrameTimelineEvent::JANK_DISPLAY_HAL;
243 jankType &= ~JankType::DisplayHAL;
244 }
245 if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) {
246 protoJank |= FrameTimelineEvent::JANK_SF_CPU_DEADLINE_MISSED;
247 jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed;
248 }
249 if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) {
250 protoJank |= FrameTimelineEvent::JANK_SF_GPU_DEADLINE_MISSED;
251 jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed;
252 }
253 if (jankType & JankType::AppDeadlineMissed) {
254 protoJank |= FrameTimelineEvent::JANK_APP_DEADLINE_MISSED;
255 jankType &= ~JankType::AppDeadlineMissed;
256 }
257 if (jankType & JankType::PredictionError) {
258 protoJank |= FrameTimelineEvent::JANK_PREDICTION_ERROR;
259 jankType &= ~JankType::PredictionError;
260 }
261 if (jankType & JankType::SurfaceFlingerScheduling) {
262 protoJank |= FrameTimelineEvent::JANK_SF_SCHEDULING;
263 jankType &= ~JankType::SurfaceFlingerScheduling;
264 }
265 if (jankType & JankType::BufferStuffing) {
266 protoJank |= FrameTimelineEvent::JANK_BUFFER_STUFFING;
267 jankType &= ~JankType::BufferStuffing;
268 }
269 if (jankType & JankType::Unknown) {
270 protoJank |= FrameTimelineEvent::JANK_UNKNOWN;
271 jankType &= ~JankType::Unknown;
272 }
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +0000273 if (jankType & JankType::SurfaceFlingerStuffing) {
274 protoJank |= FrameTimelineEvent::JANK_SF_STUFFING;
275 jankType &= ~JankType::SurfaceFlingerStuffing;
276 }
Edgar Arriaga631e4252023-03-02 02:11:24 +0000277 if (jankType & JankType::Dropped) {
278 // Jank dropped does not append to other janks, it fully overrides.
279 protoJank |= FrameTimelineEvent::JANK_DROPPED;
280 jankType &= ~JankType::Dropped;
281 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000282
283 // jankType should be 0 if all types of jank were checked for.
284 LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType);
285 return protoJank;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700286}
287
Ying Wei96eb5352023-11-21 17:37:21 +0000288FrameTimelineEvent::JankSeverityType toProto(JankSeverityType jankSeverityType) {
289 switch (jankSeverityType) {
290 case JankSeverityType::Unknown:
291 return FrameTimelineEvent::SEVERITY_UNKNOWN;
292 case JankSeverityType::None:
293 return FrameTimelineEvent::SEVERITY_NONE;
294 case JankSeverityType::Partial:
295 return FrameTimelineEvent::SEVERITY_PARTIAL;
296 case JankSeverityType::Full:
297 return FrameTimelineEvent::SEVERITY_FULL;
298 }
299}
300
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800301// Returns the smallest timestamp from the set of predictions and actuals.
302nsecs_t getMinTime(PredictionState predictionState, TimelineItem predictions,
303 TimelineItem actuals) {
304 nsecs_t minTime = std::numeric_limits<nsecs_t>::max();
305 if (predictionState == PredictionState::Valid) {
306 // Checking start time for predictions is enough because start time is always lesser than
307 // endTime and presentTime.
308 minTime = std::min(minTime, predictions.startTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700309 }
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700310
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800311 // Need to check startTime, endTime and presentTime for actuals because some frames might not
312 // have them set.
313 if (actuals.startTime != 0) {
314 minTime = std::min(minTime, actuals.startTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700315 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800316 if (actuals.endTime != 0) {
317 minTime = std::min(minTime, actuals.endTime);
318 }
319 if (actuals.presentTime != 0) {
ramindaniea2bb822022-06-27 19:52:10 +0000320 minTime = std::min(minTime, actuals.presentTime);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800321 }
322 return minTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700323}
324
Ady Abraham43a68c32024-09-04 19:21:20 -0700325bool shouldTraceForDataSource(const FrameTimelineDataSource::TraceContext& ctx, nsecs_t timestamp) {
326 if (auto ds = ctx.GetDataSourceLocked(); ds && ds->getStartTime() > timestamp) {
327 return false;
328 }
329
330 return true;
331}
332
333} // namespace
334
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000335int64_t TraceCookieCounter::getCookieForTracing() {
336 return ++mTraceCookie;
337}
338
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000339SurfaceFrame::SurfaceFrame(const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid,
Alec Mouriadebf5c2021-01-05 12:57:36 -0800340 uid_t ownerUid, int32_t layerId, std::string layerName,
341 std::string debugName, PredictionState predictionState,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800342 frametimeline::TimelineItem&& predictions,
343 std::shared_ptr<TimeStats> timeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000344 JankClassificationThresholds thresholds,
Dominik Laskowskif5d0ea52021-09-26 17:27:01 -0700345 TraceCookieCounter* traceCookieCounter, bool isBuffer, GameMode gameMode)
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000346 : mToken(frameTimelineInfo.vsyncId),
347 mInputEventId(frameTimelineInfo.inputEventId),
Adithya Srinivasan01189672020-10-20 14:23:05 -0700348 mOwnerPid(ownerPid),
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700349 mOwnerUid(ownerUid),
Alec Mouri9a29e672020-09-14 12:39:14 -0700350 mLayerName(std::move(layerName)),
351 mDebugName(std::move(debugName)),
Alec Mouriadebf5c2021-01-05 12:57:36 -0800352 mLayerId(layerId),
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700353 mPresentState(PresentState::Unknown),
354 mPredictionState(predictionState),
355 mPredictions(predictions),
356 mActuals({0, 0, 0}),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800357 mTimeStats(timeStats),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000358 mJankClassificationThresholds(thresholds),
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000359 mTraceCookieCounter(*traceCookieCounter),
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000360 mIsBuffer(isBuffer),
361 mGameMode(gameMode) {}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700362
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700363void SurfaceFrame::setActualStartTime(nsecs_t actualStartTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000364 std::scoped_lock lock(mMutex);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700365 mActuals.startTime = actualStartTime;
366}
367
368void SurfaceFrame::setActualQueueTime(nsecs_t actualQueueTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000369 std::scoped_lock lock(mMutex);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700370 mActualQueueTime = actualQueueTime;
371}
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000372
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700373void SurfaceFrame::setAcquireFenceTime(nsecs_t acquireFenceTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000374 std::scoped_lock lock(mMutex);
Vishnu Nairbd7d07e2024-07-08 13:37:11 -0700375 if (CC_UNLIKELY(acquireFenceTime == Fence::SIGNAL_TIME_PENDING)) {
376 mActuals.endTime = mActualQueueTime;
377 } else {
378 mActuals.endTime = std::max(acquireFenceTime, mActualQueueTime);
379 }
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700380}
381
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000382void SurfaceFrame::setDropTime(nsecs_t dropTime) {
383 std::scoped_lock lock(mMutex);
384 mDropTime = dropTime;
385}
386
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800387void SurfaceFrame::setPresentState(PresentState presentState, nsecs_t lastLatchTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000388 std::scoped_lock lock(mMutex);
Adithya Srinivasanb9a7dab2021-01-14 23:49:46 +0000389 LOG_ALWAYS_FATAL_IF(mPresentState != PresentState::Unknown,
390 "setPresentState called on a SurfaceFrame from Layer - %s, that has a "
391 "PresentState - %s set already.",
392 mDebugName.c_str(), toString(mPresentState).c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800393 mPresentState = presentState;
394 mLastLatchTime = lastLatchTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700395}
396
Alec Mouri7d436ec2021-01-27 20:40:50 -0800397void SurfaceFrame::setRenderRate(Fps renderRate) {
398 std::lock_guard<std::mutex> lock(mMutex);
399 mRenderRate = renderRate;
400}
401
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200402Fps SurfaceFrame::getRenderRate() const {
403 std::lock_guard<std::mutex> lock(mMutex);
404 return mRenderRate ? *mRenderRate : mDisplayFrameRenderRate;
405}
406
Adithya Srinivasanb6a2fa12021-03-13 00:23:09 +0000407void SurfaceFrame::setGpuComposition() {
408 std::scoped_lock lock(mMutex);
409 mGpuComposition = true;
410}
411
Sally Qi438eb7d2023-12-05 18:59:32 -0800412// TODO(b/316171339): migrate from perfetto side
413bool SurfaceFrame::isSelfJanky() const {
414 int32_t jankType = getJankType().value_or(JankType::None);
415
416 if (jankType == JankType::None) {
417 return false;
418 }
419
420 int32_t jankBitmask = JankType::AppDeadlineMissed | JankType::Unknown;
421 if (jankType & jankBitmask) {
422 return true;
423 }
424
425 return false;
426}
427
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800428std::optional<int32_t> SurfaceFrame::getJankType() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000429 std::scoped_lock lock(mMutex);
Adithya Srinivasan95619432021-02-08 21:52:51 +0000430 if (mPresentState == PresentState::Dropped) {
Edgar Arriaga631e4252023-03-02 02:11:24 +0000431 return JankType::Dropped;
Adithya Srinivasan95619432021-02-08 21:52:51 +0000432 }
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100433 if (mActuals.presentTime == 0) {
Adithya Srinivasan95619432021-02-08 21:52:51 +0000434 // Frame hasn't been presented yet.
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100435 return std::nullopt;
436 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700437 return mJankType;
438}
439
Ying Wei96eb5352023-11-21 17:37:21 +0000440std::optional<JankSeverityType> SurfaceFrame::getJankSeverityType() const {
441 std::scoped_lock lock(mMutex);
442 if (mActuals.presentTime == 0) {
443 // Frame hasn't been presented yet.
444 return std::nullopt;
445 }
446 return mJankSeverityType;
447}
448
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700449nsecs_t SurfaceFrame::getBaseTime() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000450 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800451 return getMinTime(mPredictionState, mPredictions, mActuals);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700452}
453
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800454TimelineItem SurfaceFrame::getActuals() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000455 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800456 return mActuals;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700457}
458
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000459PredictionState SurfaceFrame::getPredictionState() const {
460 std::scoped_lock lock(mMutex);
461 return mPredictionState;
462}
463
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800464SurfaceFrame::PresentState SurfaceFrame::getPresentState() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000465 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800466 return mPresentState;
467}
468
469FramePresentMetadata SurfaceFrame::getFramePresentMetadata() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000470 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800471 return mFramePresentMetadata;
472}
473
474FrameReadyMetadata SurfaceFrame::getFrameReadyMetadata() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000475 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800476 return mFrameReadyMetadata;
477}
478
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000479nsecs_t SurfaceFrame::getDropTime() const {
480 std::scoped_lock lock(mMutex);
481 return mDropTime;
482}
483
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000484void SurfaceFrame::promoteToBuffer() {
485 std::scoped_lock lock(mMutex);
486 LOG_ALWAYS_FATAL_IF(mIsBuffer == true,
487 "Trying to promote an already promoted BufferSurfaceFrame from layer %s "
488 "with token %" PRId64 "",
489 mDebugName.c_str(), mToken);
490 mIsBuffer = true;
491}
492
493bool SurfaceFrame::getIsBuffer() const {
494 std::scoped_lock lock(mMutex);
495 return mIsBuffer;
496}
497
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800498void SurfaceFrame::dump(std::string& result, const std::string& indent, nsecs_t baseTime) const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000499 std::scoped_lock lock(mMutex);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700500 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri9a29e672020-09-14 12:39:14 -0700501 StringAppendF(&result, "Layer - %s", mDebugName.c_str());
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100502 if (mJankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700503 // Easily identify a janky Surface Frame in the dump
504 StringAppendF(&result, " [*] ");
505 }
506 StringAppendF(&result, "\n");
507 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800508 StringAppendF(&result, "Token: %" PRId64 "\n", mToken);
509 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000510 StringAppendF(&result, "Is Buffer?: %d\n", mIsBuffer);
511 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700512 StringAppendF(&result, "Owner Pid : %d\n", mOwnerPid);
513 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri7d436ec2021-01-27 20:40:50 -0800514 StringAppendF(&result, "Scheduled rendering rate: %d fps\n",
515 mRenderRate ? mRenderRate->getIntValue() : 0);
516 StringAppendF(&result, "%s", indent.c_str());
Alec Mouriadebf5c2021-01-05 12:57:36 -0800517 StringAppendF(&result, "Layer ID : %d\n", mLayerId);
518 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800519 StringAppendF(&result, "Present State : %s\n", toString(mPresentState).c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700520 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000521 if (mPresentState == PresentState::Dropped) {
522 std::chrono::nanoseconds dropTime(mDropTime - baseTime);
523 StringAppendF(&result, "Drop time : %10f\n",
524 std::chrono::duration<double, std::milli>(dropTime).count());
525 StringAppendF(&result, "%s", indent.c_str());
526 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700527 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
528 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800529 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700530 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800531 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
532 StringAppendF(&result, "%s", indent.c_str());
533 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
534 std::chrono::nanoseconds latchTime(
535 std::max(static_cast<int64_t>(0), mLastLatchTime - baseTime));
536 StringAppendF(&result, "%s", indent.c_str());
537 StringAppendF(&result, "Last latch time: %10f\n",
538 std::chrono::duration<double, std::milli>(latchTime).count());
539 if (mPredictionState == PredictionState::Valid) {
540 nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime;
541 std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta));
542 StringAppendF(&result, "%s", indent.c_str());
543 StringAppendF(&result, "Present delta: %10f\n",
544 std::chrono::duration<double, std::milli>(presentDeltaNs).count());
545 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700546 dumpTable(result, mPredictions, mActuals, indent, mPredictionState, baseTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700547}
548
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000549std::string SurfaceFrame::miniDump() const {
550 std::scoped_lock lock(mMutex);
551 std::string result;
552 StringAppendF(&result, "Layer - %s\n", mDebugName.c_str());
553 StringAppendF(&result, "Token: %" PRId64 "\n", mToken);
554 StringAppendF(&result, "Is Buffer?: %d\n", mIsBuffer);
555 StringAppendF(&result, "Present State : %s\n", toString(mPresentState).c_str());
556 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
557 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
558 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
559 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
560 StringAppendF(&result, "Present time: %" PRId64 "", mActuals.presentTime);
561 return result;
562}
563
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000564void SurfaceFrame::classifyJankLocked(int32_t displayFrameJankType, const Fps& refreshRate,
Ady Abrahame96e79f2024-05-20 18:00:39 +0000565 Fps displayFrameRenderRate, nsecs_t* outDeadlineDelta) {
Ady Abrahame43ff722022-02-15 14:44:25 -0800566 if (mActuals.presentTime == Fence::SIGNAL_TIME_INVALID) {
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000567 // Cannot do any classification for invalid present time.
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000568 mJankType = JankType::Unknown;
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 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800573 return;
574 }
575
Ady Abrahame43ff722022-02-15 14:44:25 -0800576 if (mPredictionState == PredictionState::Expired) {
577 // We classify prediction expired as AppDeadlineMissed as the
578 // TokenManager::kMaxTokens we store is large enough to account for a
579 // reasonable app, so prediction expire would mean a huge scheduling delay.
Edgar Arriaga631e4252023-03-02 02:11:24 +0000580 mJankType = mPresentState != PresentState::Presented ? JankType::Dropped
581 : JankType::AppDeadlineMissed;
Ying Wei96eb5352023-11-21 17:37:21 +0000582 mJankSeverityType = JankSeverityType::Unknown;
Ady Abrahame96e79f2024-05-20 18:00:39 +0000583 if (outDeadlineDelta) {
584 *outDeadlineDelta = -1;
585 }
Ady Abrahame43ff722022-02-15 14:44:25 -0800586 return;
587 }
588
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800589 if (mPredictionState == PredictionState::None) {
590 // Cannot do jank classification on frames that don't have a token.
591 return;
592 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800593
594 const nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime;
Alec Mouriadebf5c2021-01-05 12:57:36 -0800595 const nsecs_t deltaToVsync = refreshRate.getPeriodNsecs() > 0
596 ? std::abs(presentDelta) % refreshRate.getPeriodNsecs()
597 : 0;
Ady Abrahame96e79f2024-05-20 18:00:39 +0000598 const nsecs_t deadlineDelta = mActuals.endTime - mPredictions.endTime;
599 if (outDeadlineDelta) {
600 *outDeadlineDelta = deadlineDelta;
601 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800602
603 if (deadlineDelta > mJankClassificationThresholds.deadlineThreshold) {
604 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
605 } else {
606 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
607 }
608
609 if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) {
610 mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent
611 : FramePresentMetadata::EarlyPresent;
Ying Wei96eb5352023-11-21 17:37:21 +0000612 // Jank that is missing by less than the render rate period is classified as partial jank,
613 // otherwise it is a full jank.
614 mJankSeverityType = std::abs(presentDelta) < displayFrameRenderRate.getPeriodNsecs()
615 ? JankSeverityType::Partial
616 : JankSeverityType::Full;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800617 } else {
618 mFramePresentMetadata = FramePresentMetadata::OnTimePresent;
619 }
620
621 if (mFramePresentMetadata == FramePresentMetadata::OnTimePresent) {
622 // Frames presented on time are not janky.
623 mJankType = JankType::None;
624 } else if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) {
625 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
626 // Finish on time, Present early
627 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -0800628 deltaToVsync >= refreshRate.getPeriodNsecs() -
629 mJankClassificationThresholds.presentThreshold) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800630 // Delta factor of vsync
631 mJankType = JankType::SurfaceFlingerScheduling;
632 } else {
633 // Delta not a factor of vsync
634 mJankType = JankType::PredictionError;
635 }
636 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
637 // Finish late, Present early
638 mJankType = JankType::Unknown;
639 }
640 } else {
641 if (mLastLatchTime != 0 && mPredictions.endTime <= mLastLatchTime) {
642 // Buffer Stuffing.
643 mJankType |= JankType::BufferStuffing;
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000644 // In a stuffed state, the frame could be stuck on a dequeue wait for quite some time.
645 // Because of this dequeue wait, it can be hard to tell if a frame was genuinely late.
646 // We try to do this by moving the deadline. Since the queue could be stuffed by more
647 // than one buffer, we take the last latch time as reference and give one vsync
648 // worth of time for the frame to be ready.
649 nsecs_t adjustedDeadline = mLastLatchTime + refreshRate.getPeriodNsecs();
650 if (adjustedDeadline > mActuals.endTime) {
651 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
652 } else {
653 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
654 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800655 }
656 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
657 // Finish on time, Present late
658 if (displayFrameJankType != JankType::None) {
659 // Propagate displayFrame's jank if it exists
660 mJankType |= displayFrameJankType;
661 } else {
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000662 if (!(mJankType & JankType::BufferStuffing)) {
663 // In a stuffed state, if the app finishes on time and there is no display frame
664 // jank, only buffer stuffing is the root cause of the jank.
665 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
666 deltaToVsync >= refreshRate.getPeriodNsecs() -
667 mJankClassificationThresholds.presentThreshold) {
668 // Delta factor of vsync
669 mJankType |= JankType::SurfaceFlingerScheduling;
670 } else {
671 // Delta not a factor of vsync
672 mJankType |= JankType::PredictionError;
673 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800674 }
675 }
676 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
677 // Finish late, Present late
Adithya Srinivasan8a945502021-03-19 19:12:32 +0000678 mJankType |= JankType::AppDeadlineMissed;
679 // Propagate DisplayFrame's jankType if it is janky
680 mJankType |= displayFrameJankType;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800681 }
682 }
Edgar Arriaga631e4252023-03-02 02:11:24 +0000683 if (mPresentState != PresentState::Presented) {
684 mJankType = JankType::Dropped;
685 // Since frame was not presented, lets drop any present value
686 mActuals.presentTime = 0;
Ying Wei96eb5352023-11-21 17:37:21 +0000687 mJankSeverityType = JankSeverityType::Unknown;
Edgar Arriaga631e4252023-03-02 02:11:24 +0000688 }
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000689}
690
691void SurfaceFrame::onPresent(nsecs_t presentTime, int32_t displayFrameJankType, Fps refreshRate,
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200692 Fps displayFrameRenderRate, nsecs_t displayDeadlineDelta,
693 nsecs_t displayPresentDelta) {
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000694 std::scoped_lock lock(mMutex);
695
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200696 mDisplayFrameRenderRate = displayFrameRenderRate;
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000697 mActuals.presentTime = presentTime;
698 nsecs_t deadlineDelta = 0;
699
Ady Abrahame96e79f2024-05-20 18:00:39 +0000700 classifyJankLocked(displayFrameJankType, refreshRate, displayFrameRenderRate, &deadlineDelta);
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000701
702 if (mPredictionState != PredictionState::None) {
703 // Only update janky frames if the app used vsync predictions
704 mTimeStats->incrementJankyFrames({refreshRate, mRenderRate, mOwnerUid, mLayerName,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000705 mGameMode, mJankType, displayDeadlineDelta,
706 displayPresentDelta, deadlineDelta});
Pascal Mütschardd56514e2024-05-24 17:37:13 +0200707
708 gui::JankData jd;
709 jd.frameVsyncId = mToken;
710 jd.jankType = mJankType;
711 jd.frameIntervalNs =
712 (mRenderRate ? *mRenderRate : mDisplayFrameRenderRate).getPeriodNsecs();
Pascal Mütschard0e8452b2024-09-03 11:02:11 +0200713
714 if (mPredictionState == PredictionState::Valid) {
715 jd.scheduledAppFrameTimeNs = mPredictions.endTime - mPredictions.startTime;
716
717 // Using expected start, rather than actual, to measure the entire frame time. That is
718 // if the application starts the frame later than scheduled, include that delay in the
719 // frame time, as it usually means main thread being busy with non-rendering work.
720 if (mPresentState == PresentState::Dropped) {
721 jd.actualAppFrameTimeNs = mDropTime - mPredictions.startTime;
722 } else {
723 jd.actualAppFrameTimeNs = mActuals.endTime - mPredictions.startTime;
724 }
725 } else {
726 jd.scheduledAppFrameTimeNs = 0;
727 jd.actualAppFrameTimeNs = 0;
728 }
729
Pascal Mütschardd56514e2024-05-24 17:37:13 +0200730 JankTracker::onJankData(mLayerId, jd);
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000731 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800732}
733
Ady Abraham14beed72024-05-15 17:16:45 -0700734void SurfaceFrame::onCommitNotComposited(Fps refreshRate, Fps displayFrameRenderRate) {
735 std::scoped_lock lock(mMutex);
736
737 mDisplayFrameRenderRate = displayFrameRenderRate;
738 mActuals.presentTime = mPredictions.presentTime;
Ady Abrahame96e79f2024-05-20 18:00:39 +0000739 classifyJankLocked(JankType::None, refreshRate, displayFrameRenderRate, nullptr);
Ady Abraham14beed72024-05-15 17:16:45 -0700740}
741
Ady Abraham43a68c32024-09-04 19:21:20 -0700742void SurfaceFrame::tracePredictions(int64_t displayFrameToken, nsecs_t monoBootOffset,
743 bool filterFramesBeforeTraceStarts) const {
Adithya Srinivasan86678502021-01-19 21:50:38 +0000744 int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Ady Abraham43a68c32024-09-04 19:21:20 -0700745 bool traced = false;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000746
Adithya Srinivasan86678502021-01-19 21:50:38 +0000747 // Expected timeline start
748 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Ady Abraham43a68c32024-09-04 19:21:20 -0700749 const auto timestamp = mPredictions.startTime;
750 if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) {
751 // Do not trace packets started before tracing starts.
752 return;
753 }
754 traced = true;
755
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000756 std::scoped_lock lock(mMutex);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700757 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -0800758 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
Ady Abraham43a68c32024-09-04 19:21:20 -0700759 packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700760
761 auto* event = packet->set_frame_timeline_event();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000762 auto* expectedSurfaceFrameStartEvent = event->set_expected_surface_frame_start();
Adithya Srinivasan01189672020-10-20 14:23:05 -0700763
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000764 expectedSurfaceFrameStartEvent->set_cookie(expectedTimelineCookie);
765
766 expectedSurfaceFrameStartEvent->set_token(mToken);
767 expectedSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken);
768
769 expectedSurfaceFrameStartEvent->set_pid(mOwnerPid);
770 expectedSurfaceFrameStartEvent->set_layer_name(mDebugName);
771 });
Adithya Srinivasan86678502021-01-19 21:50:38 +0000772
Ady Abraham43a68c32024-09-04 19:21:20 -0700773 if (traced) {
774 // Expected timeline end
775 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
776 std::scoped_lock lock(mMutex);
777 auto packet = ctx.NewTracePacket();
778 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
779 packet->set_timestamp(static_cast<uint64_t>(mPredictions.endTime + monoBootOffset));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000780
Ady Abraham43a68c32024-09-04 19:21:20 -0700781 auto* event = packet->set_frame_timeline_event();
782 auto* expectedSurfaceFrameEndEvent = event->set_frame_end();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000783
Ady Abraham43a68c32024-09-04 19:21:20 -0700784 expectedSurfaceFrameEndEvent->set_cookie(expectedTimelineCookie);
785 });
786 }
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000787}
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000788
Ady Abraham43a68c32024-09-04 19:21:20 -0700789void SurfaceFrame::traceActuals(int64_t displayFrameToken, nsecs_t monoBootOffset,
790 bool filterFramesBeforeTraceStarts) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000791 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Ady Abraham43a68c32024-09-04 19:21:20 -0700792 bool traced = false;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000793
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000794 // Actual timeline start
795 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Ady Abraham43a68c32024-09-04 19:21:20 -0700796 const auto timestamp = [&]() {
797 std::scoped_lock lock(mMutex);
798 // Actual start time is not yet available, so use expected start instead
799 if (mPredictionState == PredictionState::Expired) {
800 // If prediction is expired, we can't use the predicted start time. Instead, just
801 // use a start time a little earlier than the end time so that we have some info
802 // about this frame in the trace.
803 nsecs_t endTime =
804 (mPresentState == PresentState::Dropped ? mDropTime : mActuals.endTime);
805 return endTime - kPredictionExpiredStartTimeDelta;
806 }
807
808 return mActuals.startTime == 0 ? mPredictions.startTime : mActuals.startTime;
809 }();
810
811 if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) {
812 // Do not trace packets started before tracing starts.
813 return;
814 }
815 traced = true;
816
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);
Ady Abraham43a68c32024-09-04 19:21:20 -0700820 packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000821
822 auto* event = packet->set_frame_timeline_event();
823 auto* actualSurfaceFrameStartEvent = event->set_actual_surface_frame_start();
824
825 actualSurfaceFrameStartEvent->set_cookie(actualTimelineCookie);
826
827 actualSurfaceFrameStartEvent->set_token(mToken);
828 actualSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken);
829
830 actualSurfaceFrameStartEvent->set_pid(mOwnerPid);
831 actualSurfaceFrameStartEvent->set_layer_name(mDebugName);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700832
833 if (mPresentState == PresentState::Dropped) {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000834 actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700835 } else if (mPresentState == PresentState::Unknown) {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000836 actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_UNSPECIFIED);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700837 } else {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000838 actualSurfaceFrameStartEvent->set_present_type(toProto(mFramePresentMetadata));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700839 }
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000840 actualSurfaceFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
841 FrameReadyMetadata::OnTimeFinish);
842 actualSurfaceFrameStartEvent->set_gpu_composition(mGpuComposition);
843 actualSurfaceFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType));
Adithya Srinivasan78e58af2021-02-25 00:08:08 +0000844 actualSurfaceFrameStartEvent->set_prediction_type(toProto(mPredictionState));
Adithya Srinivasan1f9450c2021-06-10 22:39:19 +0000845 actualSurfaceFrameStartEvent->set_is_buffer(mIsBuffer);
Ying Wei96eb5352023-11-21 17:37:21 +0000846 actualSurfaceFrameStartEvent->set_jank_severity_type(toProto(mJankSeverityType));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000847 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000848
Ady Abraham43a68c32024-09-04 19:21:20 -0700849 if (traced) {
850 // Actual timeline end
851 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
852 std::scoped_lock lock(mMutex);
853 auto packet = ctx.NewTracePacket();
854 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
855 if (mPresentState == PresentState::Dropped) {
856 packet->set_timestamp(static_cast<uint64_t>(mDropTime + monoBootOffset));
857 } else {
858 packet->set_timestamp(static_cast<uint64_t>(mActuals.endTime + monoBootOffset));
859 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700860
Ady Abraham43a68c32024-09-04 19:21:20 -0700861 auto* event = packet->set_frame_timeline_event();
862 auto* actualSurfaceFrameEndEvent = event->set_frame_end();
Adithya Srinivasan01189672020-10-20 14:23:05 -0700863
Ady Abraham43a68c32024-09-04 19:21:20 -0700864 actualSurfaceFrameEndEvent->set_cookie(actualTimelineCookie);
865 });
866 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700867}
868
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000869/**
870 * TODO(b/178637512): add inputEventId to the perfetto trace.
871 */
Ady Abraham43a68c32024-09-04 19:21:20 -0700872void SurfaceFrame::trace(int64_t displayFrameToken, nsecs_t monoBootOffset,
873 bool filterFramesBeforeTraceStarts) const {
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000874 if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID ||
875 displayFrameToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
876 // No packets can be traced with a missing token.
877 return;
878 }
879 if (getPredictionState() != PredictionState::Expired) {
880 // Expired predictions have zeroed timestamps. This cannot be used in any meaningful way in
881 // a trace.
Ady Abraham43a68c32024-09-04 19:21:20 -0700882 tracePredictions(displayFrameToken, monoBootOffset, filterFramesBeforeTraceStarts);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000883 }
Ady Abraham43a68c32024-09-04 19:21:20 -0700884 traceActuals(displayFrameToken, monoBootOffset, filterFramesBeforeTraceStarts);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000885}
886
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800887namespace impl {
888
889int64_t TokenManager::generateTokenForPredictions(TimelineItem&& predictions) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000890 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000891 std::scoped_lock lock(mMutex);
Adithya Srinivasanbed4c4f2021-05-03 20:24:46 +0000892 while (mPredictions.size() >= kMaxTokens) {
893 mPredictions.erase(mPredictions.begin());
894 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800895 const int64_t assignedToken = mCurrentToken++;
Adithya Srinivasanbed4c4f2021-05-03 20:24:46 +0000896 mPredictions[assignedToken] = predictions;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800897 return assignedToken;
898}
899
900std::optional<TimelineItem> TokenManager::getPredictionsForToken(int64_t token) const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000901 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800902 auto predictionsIterator = mPredictions.find(token);
903 if (predictionsIterator != mPredictions.end()) {
Adithya Srinivasanbed4c4f2021-05-03 20:24:46 +0000904 return predictionsIterator->second;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800905 }
906 return {};
907}
908
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800909FrameTimeline::FrameTimeline(std::shared_ptr<TimeStats> timeStats, pid_t surfaceFlingerPid,
Ady Abraham43a68c32024-09-04 19:21:20 -0700910 JankClassificationThresholds thresholds, bool useBootTimeClock,
911 bool filterFramesBeforeTraceStarts)
Ady Abraham57f8e182022-03-08 15:54:33 -0800912 : mUseBootTimeClock(useBootTimeClock),
Ady Abraham43a68c32024-09-04 19:21:20 -0700913 mFilterFramesBeforeTraceStarts(
914 FlagManager::getInstance().filter_frames_before_trace_starts() &&
915 filterFramesBeforeTraceStarts),
Ady Abraham57f8e182022-03-08 15:54:33 -0800916 mMaxDisplayFrames(kDefaultMaxDisplayFrames),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800917 mTimeStats(std::move(timeStats)),
918 mSurfaceFlingerPid(surfaceFlingerPid),
Adithya Srinivasan82eef322021-04-10 00:06:04 +0000919 mJankClassificationThresholds(thresholds) {
920 mCurrentDisplayFrame =
921 std::make_shared<DisplayFrame>(mTimeStats, thresholds, &mTraceCookieCounter);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000922}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700923
Adithya Srinivasan01189672020-10-20 14:23:05 -0700924void FrameTimeline::onBootFinished() {
925 perfetto::TracingInitArgs args;
926 args.backends = perfetto::kSystemBackend;
927 perfetto::Tracing::Initialize(args);
928 registerDataSource();
929}
930
931void FrameTimeline::registerDataSource() {
932 perfetto::DataSourceDescriptor dsd;
933 dsd.set_name(kFrameTimelineDataSource);
934 FrameTimelineDataSource::Register(dsd);
935}
936
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800937std::shared_ptr<SurfaceFrame> FrameTimeline::createSurfaceFrameForToken(
Alec Mouriadebf5c2021-01-05 12:57:36 -0800938 const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid, uid_t ownerUid, int32_t layerId,
Dominik Laskowskif5d0ea52021-09-26 17:27:01 -0700939 std::string layerName, std::string debugName, bool isBuffer, GameMode gameMode) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000940 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000941 if (frameTimelineInfo.vsyncId == FrameTimelineInfo::INVALID_VSYNC_ID) {
Alec Mouriadebf5c2021-01-05 12:57:36 -0800942 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000943 std::move(layerName), std::move(debugName),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800944 PredictionState::None, TimelineItem(), mTimeStats,
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000945 mJankClassificationThresholds, &mTraceCookieCounter,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000946 isBuffer, gameMode);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700947 }
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000948 std::optional<TimelineItem> predictions =
949 mTokenManager.getPredictionsForToken(frameTimelineInfo.vsyncId);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700950 if (predictions) {
Alec Mouriadebf5c2021-01-05 12:57:36 -0800951 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000952 std::move(layerName), std::move(debugName),
953 PredictionState::Valid, std::move(*predictions),
954 mTimeStats, mJankClassificationThresholds,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000955 &mTraceCookieCounter, isBuffer, gameMode);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700956 }
Alec Mouriadebf5c2021-01-05 12:57:36 -0800957 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000958 std::move(layerName), std::move(debugName),
959 PredictionState::Expired, TimelineItem(), mTimeStats,
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000960 mJankClassificationThresholds, &mTraceCookieCounter,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000961 isBuffer, gameMode);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700962}
963
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800964FrameTimeline::DisplayFrame::DisplayFrame(std::shared_ptr<TimeStats> timeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000965 JankClassificationThresholds thresholds,
966 TraceCookieCounter* traceCookieCounter)
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800967 : mSurfaceFlingerPredictions(TimelineItem()),
968 mSurfaceFlingerActuals(TimelineItem()),
969 mTimeStats(timeStats),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000970 mJankClassificationThresholds(thresholds),
971 mTraceCookieCounter(*traceCookieCounter) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800972 mSurfaceFrames.reserve(kNumSurfaceFramesInitial);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700973}
974
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800975void FrameTimeline::addSurfaceFrame(std::shared_ptr<SurfaceFrame> surfaceFrame) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000976 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000977 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800978 mCurrentDisplayFrame->addSurfaceFrame(surfaceFrame);
979}
980
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200981void FrameTimeline::setSfWakeUp(int64_t token, nsecs_t wakeUpTime, Fps refreshRate,
982 Fps renderRate) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000983 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000984 std::scoped_lock lock(mMutex);
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200985 mCurrentDisplayFrame->onSfWakeUp(token, refreshRate, renderRate,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800986 mTokenManager.getPredictionsForToken(token), wakeUpTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700987}
988
989void FrameTimeline::setSfPresent(nsecs_t sfPresentTime,
Adithya Srinivasanb6a2fa12021-03-13 00:23:09 +0000990 const std::shared_ptr<FenceTime>& presentFence,
Adithya Srinivasan36b01af2021-04-07 22:29:47 +0000991 const std::shared_ptr<FenceTime>& gpuFence) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000992 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000993 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800994 mCurrentDisplayFrame->setActualEndTime(sfPresentTime);
Adithya Srinivasan36b01af2021-04-07 22:29:47 +0000995 mCurrentDisplayFrame->setGpuFence(gpuFence);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700996 mPendingPresentFences.emplace_back(std::make_pair(presentFence, mCurrentDisplayFrame));
997 flushPendingPresentFences();
998 finalizeCurrentDisplayFrame();
999}
1000
Melody Hsue524dd92024-08-27 22:27:29 +00001001const std::vector<std::shared_ptr<frametimeline::SurfaceFrame>>& FrameTimeline::getPresentFrames()
1002 const {
1003 return mPresentFrames;
1004}
1005
Ady Abraham14beed72024-05-15 17:16:45 -07001006void FrameTimeline::onCommitNotComposited() {
Vishnu Nairbe0ad902024-06-27 23:38:43 +00001007 SFTRACE_CALL();
Ady Abraham14beed72024-05-15 17:16:45 -07001008 std::scoped_lock lock(mMutex);
1009 mCurrentDisplayFrame->onCommitNotComposited();
1010 mCurrentDisplayFrame.reset();
1011 mCurrentDisplayFrame = std::make_shared<DisplayFrame>(mTimeStats, mJankClassificationThresholds,
1012 &mTraceCookieCounter);
1013}
1014
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001015void FrameTimeline::DisplayFrame::addSurfaceFrame(std::shared_ptr<SurfaceFrame> surfaceFrame) {
1016 mSurfaceFrames.push_back(surfaceFrame);
1017}
1018
Pascal Muetschardac7bcd92023-10-03 15:05:36 +02001019void FrameTimeline::DisplayFrame::onSfWakeUp(int64_t token, Fps refreshRate, Fps renderRate,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001020 std::optional<TimelineItem> predictions,
1021 nsecs_t wakeUpTime) {
1022 mToken = token;
Alec Mouri7d436ec2021-01-27 20:40:50 -08001023 mRefreshRate = refreshRate;
Pascal Muetschardac7bcd92023-10-03 15:05:36 +02001024 mRenderRate = renderRate;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001025 if (!predictions) {
1026 mPredictionState = PredictionState::Expired;
1027 } else {
1028 mPredictionState = PredictionState::Valid;
1029 mSurfaceFlingerPredictions = *predictions;
1030 }
1031 mSurfaceFlingerActuals.startTime = wakeUpTime;
1032}
1033
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001034void FrameTimeline::DisplayFrame::setPredictions(PredictionState predictionState,
1035 TimelineItem predictions) {
1036 mPredictionState = predictionState;
1037 mSurfaceFlingerPredictions = predictions;
1038}
1039
1040void FrameTimeline::DisplayFrame::setActualStartTime(nsecs_t actualStartTime) {
1041 mSurfaceFlingerActuals.startTime = actualStartTime;
1042}
1043
1044void FrameTimeline::DisplayFrame::setActualEndTime(nsecs_t actualEndTime) {
1045 mSurfaceFlingerActuals.endTime = actualEndTime;
1046}
1047
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001048void FrameTimeline::DisplayFrame::setGpuFence(const std::shared_ptr<FenceTime>& gpuFence) {
1049 mGpuFence = gpuFence;
Adithya Srinivasanb6a2fa12021-03-13 00:23:09 +00001050}
1051
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001052void FrameTimeline::DisplayFrame::classifyJank(nsecs_t& deadlineDelta, nsecs_t& deltaToVsync,
1053 nsecs_t previousPresentTime) {
Ady Abrahamb1e10d12023-03-13 15:23:54 -07001054 const bool presentTimeValid =
1055 mSurfaceFlingerActuals.presentTime >= mSurfaceFlingerActuals.startTime;
1056 if (mPredictionState == PredictionState::Expired || !presentTimeValid) {
Adithya Srinivasande272452021-04-10 00:21:00 +00001057 // Cannot do jank classification with expired predictions or invalid signal times. Set the
1058 // deltas to 0 as both negative and positive deltas are used as real values.
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001059 mJankType = JankType::Unknown;
Ying Wei96eb5352023-11-21 17:37:21 +00001060 mJankSeverityType = JankSeverityType::Unknown;
Adithya Srinivasande272452021-04-10 00:21:00 +00001061 deadlineDelta = 0;
1062 deltaToVsync = 0;
Ady Abrahamb1e10d12023-03-13 15:23:54 -07001063 if (!presentTimeValid) {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001064 mSurfaceFlingerActuals.presentTime = mSurfaceFlingerActuals.endTime;
Ady Abrahamb1e10d12023-03-13 15:23:54 -07001065 mJankType |= JankType::DisplayHAL;
Ady Abrahamfcb16862022-10-10 14:35:21 -07001066 }
1067
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001068 return;
1069 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001070
1071 // Delta between the expected present and the actual present
1072 const nsecs_t presentDelta =
1073 mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime;
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001074 // Sf actual end time represents the CPU end time. In case of HWC, SF's end time would have
1075 // included the time for composition. However, for GPU composition, the final end time is max(sf
1076 // end time, gpu fence time).
1077 nsecs_t combinedEndTime = mSurfaceFlingerActuals.endTime;
1078 if (mGpuFence != FenceTime::NO_FENCE) {
1079 combinedEndTime = std::max(combinedEndTime, mGpuFence->getSignalTime());
1080 }
1081 deadlineDelta = combinedEndTime - mSurfaceFlingerPredictions.endTime;
Alec Mouri363faf02021-01-29 16:34:55 -08001082
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001083 // How far off was the presentDelta when compared to the vsyncPeriod. Used in checking if there
1084 // was a prediction error or not.
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001085 deltaToVsync = mRefreshRate.getPeriodNsecs() > 0
Alec Mouriadebf5c2021-01-05 12:57:36 -08001086 ? std::abs(presentDelta) % mRefreshRate.getPeriodNsecs()
1087 : 0;
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001088
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001089 if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) {
1090 mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent
1091 : FramePresentMetadata::EarlyPresent;
Ying Wei96eb5352023-11-21 17:37:21 +00001092 // Jank that is missing by less than the render rate period is classified as partial jank,
1093 // otherwise it is a full jank.
1094 mJankSeverityType = std::abs(presentDelta) < mRenderRate.getPeriodNsecs()
1095 ? JankSeverityType::Partial
1096 : JankSeverityType::Full;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001097 } else {
1098 mFramePresentMetadata = FramePresentMetadata::OnTimePresent;
1099 }
1100
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001101 if (combinedEndTime > mSurfaceFlingerPredictions.endTime) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001102 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
1103 } else {
1104 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
1105 }
1106
1107 if (std::abs(mSurfaceFlingerActuals.startTime - mSurfaceFlingerPredictions.startTime) >
1108 mJankClassificationThresholds.startThreshold) {
1109 mFrameStartMetadata =
1110 mSurfaceFlingerActuals.startTime > mSurfaceFlingerPredictions.startTime
1111 ? FrameStartMetadata::LateStart
1112 : FrameStartMetadata::EarlyStart;
1113 }
1114
1115 if (mFramePresentMetadata != FramePresentMetadata::OnTimePresent) {
1116 // Do jank classification only if present is not on time
1117 if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) {
1118 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
1119 // Finish on time, Present early
1120 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -08001121 deltaToVsync >= (mRefreshRate.getPeriodNsecs() -
1122 mJankClassificationThresholds.presentThreshold)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001123 // Delta is a factor of vsync if its within the presentTheshold on either side
1124 // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold
1125 // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms.
1126 mJankType = JankType::SurfaceFlingerScheduling;
1127 } else {
1128 // Delta is not a factor of vsync,
1129 mJankType = JankType::PredictionError;
1130 }
1131 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
1132 // Finish late, Present early
1133 mJankType = JankType::SurfaceFlingerScheduling;
1134 } else {
1135 // Finish time unknown
1136 mJankType = JankType::Unknown;
1137 }
1138 } else if (mFramePresentMetadata == FramePresentMetadata::LatePresent) {
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001139 if (std::abs(mSurfaceFlingerPredictions.presentTime - previousPresentTime) <=
1140 mJankClassificationThresholds.presentThreshold ||
1141 previousPresentTime > mSurfaceFlingerPredictions.presentTime) {
1142 // The previous frame was either presented in the current frame's expected vsync or
1143 // it was presented even later than the current frame's expected vsync.
1144 mJankType = JankType::SurfaceFlingerStuffing;
1145 }
1146 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish &&
1147 !(mJankType & JankType::SurfaceFlingerStuffing)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001148 // Finish on time, Present late
1149 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -08001150 deltaToVsync >= (mRefreshRate.getPeriodNsecs() -
1151 mJankClassificationThresholds.presentThreshold)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001152 // Delta is a factor of vsync if its within the presentTheshold on either side
1153 // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold
1154 // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms.
1155 mJankType = JankType::DisplayHAL;
1156 } else {
1157 // Delta is not a factor of vsync
1158 mJankType = JankType::PredictionError;
1159 }
1160 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001161 if (!(mJankType & JankType::SurfaceFlingerStuffing) ||
1162 mSurfaceFlingerActuals.presentTime - previousPresentTime >
1163 mRefreshRate.getPeriodNsecs() +
1164 mJankClassificationThresholds.presentThreshold) {
1165 // Classify CPU vs GPU if SF wasn't stuffed or if SF was stuffed but this frame
1166 // was presented more than a vsync late.
Rachel Lee94917b32022-03-18 17:52:09 -07001167 if (mGpuFence != FenceTime::NO_FENCE) {
1168 // If SF was in GPU composition, classify it as GPU deadline missed.
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001169 mJankType = JankType::SurfaceFlingerGpuDeadlineMissed;
1170 } else {
1171 mJankType = JankType::SurfaceFlingerCpuDeadlineMissed;
1172 }
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +00001173 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001174 } else {
1175 // Finish time unknown
1176 mJankType = JankType::Unknown;
1177 }
1178 } else {
1179 // Present unknown
1180 mJankType = JankType::Unknown;
1181 }
1182 }
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001183}
1184
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001185void FrameTimeline::DisplayFrame::onPresent(nsecs_t signalTime, nsecs_t previousPresentTime) {
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001186 mSurfaceFlingerActuals.presentTime = signalTime;
1187 nsecs_t deadlineDelta = 0;
1188 nsecs_t deltaToVsync = 0;
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001189 classifyJank(deadlineDelta, deltaToVsync, previousPresentTime);
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001190
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001191 for (auto& surfaceFrame : mSurfaceFrames) {
Pascal Muetschardac7bcd92023-10-03 15:05:36 +02001192 surfaceFrame->onPresent(signalTime, mJankType, mRefreshRate, mRenderRate, deadlineDelta,
1193 deltaToVsync);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001194 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001195}
1196
Ady Abraham14beed72024-05-15 17:16:45 -07001197void FrameTimeline::DisplayFrame::onCommitNotComposited() {
1198 for (auto& surfaceFrame : mSurfaceFrames) {
1199 surfaceFrame->onCommitNotComposited(mRefreshRate, mRenderRate);
1200 }
1201}
1202
Ady Abraham43a68c32024-09-04 19:21:20 -07001203void FrameTimeline::DisplayFrame::tracePredictions(pid_t surfaceFlingerPid, nsecs_t monoBootOffset,
1204 bool filterFramesBeforeTraceStarts) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001205 int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Ady Abraham43a68c32024-09-04 19:21:20 -07001206 bool traced = false;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001207
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001208 // Expected timeline start
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001209 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Ady Abraham43a68c32024-09-04 19:21:20 -07001210 const auto timestamp = mSurfaceFlingerPredictions.startTime;
1211 if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) {
1212 // Do not trace packets started before tracing starts.
1213 return;
1214 }
1215 traced = true;
1216
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001217 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -08001218 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
Ady Abraham43a68c32024-09-04 19:21:20 -07001219 packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001220
1221 auto* event = packet->set_frame_timeline_event();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001222 auto* expectedDisplayFrameStartEvent = event->set_expected_display_frame_start();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001223
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001224 expectedDisplayFrameStartEvent->set_cookie(expectedTimelineCookie);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001225
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001226 expectedDisplayFrameStartEvent->set_token(mToken);
1227 expectedDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
1228 });
Adithya Srinivasan86678502021-01-19 21:50:38 +00001229
Ady Abraham43a68c32024-09-04 19:21:20 -07001230 if (traced) {
1231 // Expected timeline end
1232 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
1233 auto packet = ctx.NewTracePacket();
1234 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1235 packet->set_timestamp(
1236 static_cast<uint64_t>(mSurfaceFlingerPredictions.endTime + monoBootOffset));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001237
Ady Abraham43a68c32024-09-04 19:21:20 -07001238 auto* event = packet->set_frame_timeline_event();
1239 auto* expectedDisplayFrameEndEvent = event->set_frame_end();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001240
Ady Abraham43a68c32024-09-04 19:21:20 -07001241 expectedDisplayFrameEndEvent->set_cookie(expectedTimelineCookie);
1242 });
1243 }
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001244}
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001245
Sally Qiaa107742023-09-29 14:53:14 -07001246void FrameTimeline::DisplayFrame::addSkippedFrame(pid_t surfaceFlingerPid, nsecs_t monoBootOffset,
Ady Abraham43a68c32024-09-04 19:21:20 -07001247 nsecs_t previousPredictionPresentTime,
1248 bool filterFramesBeforeTraceStarts) const {
Sally Qiaa107742023-09-29 14:53:14 -07001249 nsecs_t skippedFrameStartTime = 0, skippedFramePresentTime = 0;
1250 const constexpr float kThresh = 0.5f;
1251 const constexpr float kRange = 1.5f;
1252 for (auto& surfaceFrame : mSurfaceFrames) {
Sally Qi438eb7d2023-12-05 18:59:32 -08001253 if (previousPredictionPresentTime != 0 &&
1254 static_cast<float>(mSurfaceFlingerPredictions.presentTime -
1255 previousPredictionPresentTime) >=
Sally Qiaa107742023-09-29 14:53:14 -07001256 static_cast<float>(mRenderRate.getPeriodNsecs()) * kRange &&
1257 static_cast<float>(surfaceFrame->getPredictions().presentTime) <=
Sally Qi438eb7d2023-12-05 18:59:32 -08001258 (static_cast<float>(mSurfaceFlingerPredictions.presentTime) -
Sally Qiaa107742023-09-29 14:53:14 -07001259 kThresh * static_cast<float>(mRenderRate.getPeriodNsecs())) &&
1260 static_cast<float>(surfaceFrame->getPredictions().presentTime) >=
Sally Qi2269a692024-05-17 18:02:28 -07001261 (static_cast<float>(previousPredictionPresentTime) +
Sally Qi438eb7d2023-12-05 18:59:32 -08001262 kThresh * static_cast<float>(mRenderRate.getPeriodNsecs())) &&
1263 // sf skipped frame is not considered if app is self janked
Sally Qi093477c2024-09-11 00:58:22 +00001264 surfaceFrame->getJankType() != JankType::None && !surfaceFrame->isSelfJanky()) {
Sally Qiaa107742023-09-29 14:53:14 -07001265 skippedFrameStartTime = surfaceFrame->getPredictions().endTime;
1266 skippedFramePresentTime = surfaceFrame->getPredictions().presentTime;
1267 break;
1268 }
1269 }
1270
1271 // add slice
1272 if (skippedFrameStartTime != 0 && skippedFramePresentTime != 0) {
1273 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Ady Abraham43a68c32024-09-04 19:21:20 -07001274 bool traced = false;
Sally Qiaa107742023-09-29 14:53:14 -07001275
1276 // Actual timeline start
1277 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Ady Abraham43a68c32024-09-04 19:21:20 -07001278 if (filterFramesBeforeTraceStarts &&
1279 !shouldTraceForDataSource(ctx, skippedFrameStartTime)) {
1280 // Do not trace packets started before tracing starts.
1281 return;
1282 }
1283 traced = true;
1284
Sally Qiaa107742023-09-29 14:53:14 -07001285 auto packet = ctx.NewTracePacket();
1286 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1287 packet->set_timestamp(static_cast<uint64_t>(skippedFrameStartTime + monoBootOffset));
1288
1289 auto* event = packet->set_frame_timeline_event();
1290 auto* actualDisplayFrameStartEvent = event->set_actual_display_frame_start();
1291
1292 actualDisplayFrameStartEvent->set_cookie(actualTimelineCookie);
1293
1294 actualDisplayFrameStartEvent->set_token(0);
1295 actualDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
1296 actualDisplayFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
1297 FrameReadyMetadata::OnTimeFinish);
1298 actualDisplayFrameStartEvent->set_gpu_composition(false);
1299 actualDisplayFrameStartEvent->set_prediction_type(toProto(PredictionState::Valid));
1300 actualDisplayFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED);
1301 actualDisplayFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(JankType::Dropped));
Ying Wei96eb5352023-11-21 17:37:21 +00001302 actualDisplayFrameStartEvent->set_jank_severity_type(toProto(JankSeverityType::None));
Sally Qiaa107742023-09-29 14:53:14 -07001303 });
1304
Ady Abraham43a68c32024-09-04 19:21:20 -07001305 if (traced) {
1306 // Actual timeline end
1307 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
1308 auto packet = ctx.NewTracePacket();
1309 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1310 packet->set_timestamp(
1311 static_cast<uint64_t>(skippedFramePresentTime + monoBootOffset));
Sally Qiaa107742023-09-29 14:53:14 -07001312
Ady Abraham43a68c32024-09-04 19:21:20 -07001313 auto* event = packet->set_frame_timeline_event();
1314 auto* actualDisplayFrameEndEvent = event->set_frame_end();
Sally Qiaa107742023-09-29 14:53:14 -07001315
Ady Abraham43a68c32024-09-04 19:21:20 -07001316 actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie);
1317 });
1318 }
Sally Qiaa107742023-09-29 14:53:14 -07001319 }
1320}
1321
Ady Abraham43a68c32024-09-04 19:21:20 -07001322void FrameTimeline::DisplayFrame::traceActuals(pid_t surfaceFlingerPid, nsecs_t monoBootOffset,
1323 bool filterFramesBeforeTraceStarts) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001324 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Ady Abraham43a68c32024-09-04 19:21:20 -07001325 bool traced = false;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001326
1327 // Actual timeline start
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001328 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Ady Abraham43a68c32024-09-04 19:21:20 -07001329 const auto timestamp = mSurfaceFlingerActuals.startTime;
1330 if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) {
1331 // Do not trace packets started before tracing starts.
1332 return;
1333 }
1334 traced = true;
1335
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001336 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -08001337 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
Ady Abraham43a68c32024-09-04 19:21:20 -07001338 packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001339
1340 auto* event = packet->set_frame_timeline_event();
1341 auto* actualDisplayFrameStartEvent = event->set_actual_display_frame_start();
1342
1343 actualDisplayFrameStartEvent->set_cookie(actualTimelineCookie);
1344
1345 actualDisplayFrameStartEvent->set_token(mToken);
1346 actualDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
1347
1348 actualDisplayFrameStartEvent->set_present_type(toProto(mFramePresentMetadata));
1349 actualDisplayFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
1350 FrameReadyMetadata::OnTimeFinish);
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001351 actualDisplayFrameStartEvent->set_gpu_composition(mGpuFence != FenceTime::NO_FENCE);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001352 actualDisplayFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType));
Adithya Srinivasan78e58af2021-02-25 00:08:08 +00001353 actualDisplayFrameStartEvent->set_prediction_type(toProto(mPredictionState));
Ying Wei96eb5352023-11-21 17:37:21 +00001354 actualDisplayFrameStartEvent->set_jank_severity_type(toProto(mJankSeverityType));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001355 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001356
Ady Abraham43a68c32024-09-04 19:21:20 -07001357 if (traced) {
1358 // Actual timeline end
1359 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
1360 auto packet = ctx.NewTracePacket();
1361 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1362 packet->set_timestamp(
1363 static_cast<uint64_t>(mSurfaceFlingerActuals.presentTime + monoBootOffset));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001364
Ady Abraham43a68c32024-09-04 19:21:20 -07001365 auto* event = packet->set_frame_timeline_event();
1366 auto* actualDisplayFrameEndEvent = event->set_frame_end();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001367
Ady Abraham43a68c32024-09-04 19:21:20 -07001368 actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie);
1369 });
1370 }
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001371}
1372
Sally Qi438eb7d2023-12-05 18:59:32 -08001373nsecs_t FrameTimeline::DisplayFrame::trace(pid_t surfaceFlingerPid, nsecs_t monoBootOffset,
Ady Abraham43a68c32024-09-04 19:21:20 -07001374 nsecs_t previousPredictionPresentTime,
1375 bool filterFramesBeforeTraceStarts) const {
Ady Abraham57a8ab42023-01-26 15:28:19 -08001376 if (mSurfaceFrames.empty()) {
1377 // We don't want to trace display frames without any surface frames updates as this cannot
1378 // be janky
Sally Qi438eb7d2023-12-05 18:59:32 -08001379 return previousPredictionPresentTime;
Ady Abraham57a8ab42023-01-26 15:28:19 -08001380 }
1381
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001382 if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
1383 // DisplayFrame should not have an invalid token.
1384 ALOGE("Cannot trace DisplayFrame with invalid token");
Sally Qi438eb7d2023-12-05 18:59:32 -08001385 return previousPredictionPresentTime;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001386 }
1387
1388 if (mPredictionState == PredictionState::Valid) {
1389 // Expired and unknown predictions have zeroed timestamps. This cannot be used in any
1390 // meaningful way in a trace.
Ady Abraham43a68c32024-09-04 19:21:20 -07001391 tracePredictions(surfaceFlingerPid, monoBootOffset, filterFramesBeforeTraceStarts);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001392 }
Ady Abraham43a68c32024-09-04 19:21:20 -07001393 traceActuals(surfaceFlingerPid, monoBootOffset, filterFramesBeforeTraceStarts);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001394
1395 for (auto& surfaceFrame : mSurfaceFrames) {
Ady Abraham43a68c32024-09-04 19:21:20 -07001396 surfaceFrame->trace(mToken, monoBootOffset, filterFramesBeforeTraceStarts);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001397 }
Sally Qiaa107742023-09-29 14:53:14 -07001398
Sally Qif5721252023-11-17 11:14:53 -08001399 if (FlagManager::getInstance().add_sf_skipped_frames_to_trace()) {
Ady Abraham43a68c32024-09-04 19:21:20 -07001400 addSkippedFrame(surfaceFlingerPid, monoBootOffset, previousPredictionPresentTime,
1401 filterFramesBeforeTraceStarts);
Sally Qif5721252023-11-17 11:14:53 -08001402 }
Sally Qi438eb7d2023-12-05 18:59:32 -08001403 return mSurfaceFlingerPredictions.presentTime;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001404}
1405
Alec Mouriadebf5c2021-01-05 12:57:36 -08001406float FrameTimeline::computeFps(const std::unordered_set<int32_t>& layerIds) {
1407 if (layerIds.empty()) {
1408 return 0.0f;
1409 }
1410
1411 std::vector<nsecs_t> presentTimes;
1412 {
1413 std::scoped_lock lock(mMutex);
1414 presentTimes.reserve(mDisplayFrames.size());
1415 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
1416 const auto& displayFrame = mDisplayFrames[i];
1417 if (displayFrame->getActuals().presentTime <= 0) {
1418 continue;
1419 }
1420 for (const auto& surfaceFrame : displayFrame->getSurfaceFrames()) {
1421 if (surfaceFrame->getPresentState() == SurfaceFrame::PresentState::Presented &&
1422 layerIds.count(surfaceFrame->getLayerId()) > 0) {
1423 // We're looking for DisplayFrames that presents at least one layer from
1424 // layerIds, so push the present time and skip looking through the rest of the
1425 // SurfaceFrames.
1426 presentTimes.push_back(displayFrame->getActuals().presentTime);
1427 break;
1428 }
1429 }
1430 }
1431 }
1432
1433 // FPS can't be computed when there's fewer than 2 presented frames.
1434 if (presentTimes.size() <= 1) {
1435 return 0.0f;
1436 }
1437
1438 nsecs_t priorPresentTime = -1;
1439 nsecs_t totalPresentToPresentWalls = 0;
1440
1441 for (const nsecs_t presentTime : presentTimes) {
1442 if (priorPresentTime == -1) {
1443 priorPresentTime = presentTime;
1444 continue;
1445 }
1446
1447 totalPresentToPresentWalls += (presentTime - priorPresentTime);
1448 priorPresentTime = presentTime;
1449 }
1450
1451 if (CC_UNLIKELY(totalPresentToPresentWalls <= 0)) {
1452 ALOGW("Invalid total present-to-present duration when computing fps: %" PRId64,
1453 totalPresentToPresentWalls);
1454 return 0.0f;
1455 }
1456
1457 const constexpr nsecs_t kOneSecond =
1458 std::chrono::duration_cast<std::chrono::nanoseconds>(1s).count();
1459 // (10^9 nanoseconds / second) * (N present deltas) / (total nanoseconds in N present deltas) =
1460 // M frames / second
1461 return kOneSecond * static_cast<nsecs_t>((presentTimes.size() - 1)) /
1462 static_cast<float>(totalPresentToPresentWalls);
1463}
1464
Ady Abrahamfcb16862022-10-10 14:35:21 -07001465std::optional<size_t> FrameTimeline::getFirstSignalFenceIndex() const {
1466 for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
1467 const auto& [fence, _] = mPendingPresentFences[i];
Theodore Dubois205c6dd2022-11-23 15:06:33 -08001468 if (fence && fence->getSignalTime() != Fence::SIGNAL_TIME_PENDING) {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001469 return i;
1470 }
1471 }
1472
1473 return {};
1474}
1475
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001476void FrameTimeline::flushPendingPresentFences() {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001477 const auto firstSignaledFence = getFirstSignalFenceIndex();
1478 if (!firstSignaledFence.has_value()) {
1479 return;
1480 }
1481
Ady Abraham57f8e182022-03-08 15:54:33 -08001482 // Perfetto is using boottime clock to void drifts when the device goes
1483 // to suspend.
1484 const auto monoBootOffset = mUseBootTimeClock
1485 ? (systemTime(SYSTEM_TIME_BOOTTIME) - systemTime(SYSTEM_TIME_MONOTONIC))
1486 : 0;
1487
Ady Abrahamfcb16862022-10-10 14:35:21 -07001488 // Present fences are expected to be signaled in order. Mark all the previous
1489 // pending fences as errors.
1490 for (size_t i = 0; i < firstSignaledFence.value(); i++) {
1491 const auto& pendingPresentFence = *mPendingPresentFences.begin();
1492 const nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
1493 auto& displayFrame = pendingPresentFence.second;
Sally Qi438eb7d2023-12-05 18:59:32 -08001494 displayFrame->onPresent(signalTime, mPreviousActualPresentTime);
Ady Abraham43a68c32024-09-04 19:21:20 -07001495 mPreviousPredictionPresentTime =
1496 displayFrame->trace(mSurfaceFlingerPid, monoBootOffset,
1497 mPreviousPredictionPresentTime, mFilterFramesBeforeTraceStarts);
Ady Abrahamfcb16862022-10-10 14:35:21 -07001498 mPendingPresentFences.erase(mPendingPresentFences.begin());
1499 }
1500
Melody Hsue524dd92024-08-27 22:27:29 +00001501 mPresentFrames.clear();
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001502 for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
1503 const auto& pendingPresentFence = mPendingPresentFences[i];
1504 nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
1505 if (pendingPresentFence.first && pendingPresentFence.first->isValid()) {
1506 signalTime = pendingPresentFence.first->getSignalTime();
1507 if (signalTime == Fence::SIGNAL_TIME_PENDING) {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001508 break;
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001509 }
1510 }
Ady Abrahamfcb16862022-10-10 14:35:21 -07001511
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +00001512 auto& displayFrame = pendingPresentFence.second;
Sally Qi438eb7d2023-12-05 18:59:32 -08001513 displayFrame->onPresent(signalTime, mPreviousActualPresentTime);
Melody Hsue524dd92024-08-27 22:27:29 +00001514
1515 // Surface frames have been jank classified and can be provided to caller
1516 // to detect if buffer stuffing is occurring.
1517 for (const auto& frame : displayFrame->getSurfaceFrames()) {
1518 mPresentFrames.push_back(frame);
1519 }
1520
Ady Abraham43a68c32024-09-04 19:21:20 -07001521 mPreviousPredictionPresentTime =
1522 displayFrame->trace(mSurfaceFlingerPid, monoBootOffset,
1523 mPreviousPredictionPresentTime, mFilterFramesBeforeTraceStarts);
Sally Qi438eb7d2023-12-05 18:59:32 -08001524 mPreviousActualPresentTime = signalTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001525
1526 mPendingPresentFences.erase(mPendingPresentFences.begin() + static_cast<int>(i));
1527 --i;
1528 }
1529}
1530
1531void FrameTimeline::finalizeCurrentDisplayFrame() {
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001532 while (mDisplayFrames.size() >= mMaxDisplayFrames) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001533 // We maintain only a fixed number of frames' data. Pop older frames
1534 mDisplayFrames.pop_front();
1535 }
1536 mDisplayFrames.push_back(mCurrentDisplayFrame);
1537 mCurrentDisplayFrame.reset();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001538 mCurrentDisplayFrame = std::make_shared<DisplayFrame>(mTimeStats, mJankClassificationThresholds,
Adithya Srinivasan82eef322021-04-10 00:06:04 +00001539 &mTraceCookieCounter);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001540}
1541
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001542nsecs_t FrameTimeline::DisplayFrame::getBaseTime() const {
1543 nsecs_t baseTime =
1544 getMinTime(mPredictionState, mSurfaceFlingerPredictions, mSurfaceFlingerActuals);
1545 for (const auto& surfaceFrame : mSurfaceFrames) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001546 nsecs_t surfaceFrameBaseTime = surfaceFrame->getBaseTime();
1547 if (surfaceFrameBaseTime != 0) {
1548 baseTime = std::min(baseTime, surfaceFrameBaseTime);
1549 }
1550 }
1551 return baseTime;
1552}
1553
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001554void FrameTimeline::DisplayFrame::dumpJank(std::string& result, nsecs_t baseTime,
1555 int displayFrameCount) const {
1556 if (mJankType == JankType::None) {
1557 // Check if any Surface Frame has been janky
1558 bool isJanky = false;
1559 for (const auto& surfaceFrame : mSurfaceFrames) {
1560 if (surfaceFrame->getJankType() != JankType::None) {
1561 isJanky = true;
1562 break;
1563 }
1564 }
1565 if (!isJanky) {
1566 return;
1567 }
1568 }
1569 StringAppendF(&result, "Display Frame %d", displayFrameCount);
1570 dump(result, baseTime);
1571}
1572
1573void FrameTimeline::DisplayFrame::dumpAll(std::string& result, nsecs_t baseTime) const {
1574 dump(result, baseTime);
1575}
1576
1577void FrameTimeline::DisplayFrame::dump(std::string& result, nsecs_t baseTime) const {
1578 if (mJankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001579 // Easily identify a janky Display Frame in the dump
1580 StringAppendF(&result, " [*] ");
1581 }
1582 StringAppendF(&result, "\n");
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001583 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
1584 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
1585 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
1586 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
1587 StringAppendF(&result, "Start Metadata: %s\n", toString(mFrameStartMetadata).c_str());
Alec Mouri7d436ec2021-01-27 20:40:50 -08001588 std::chrono::nanoseconds vsyncPeriod(mRefreshRate.getPeriodNsecs());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001589 StringAppendF(&result, "Vsync Period: %10f\n",
1590 std::chrono::duration<double, std::milli>(vsyncPeriod).count());
1591 nsecs_t presentDelta =
1592 mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime;
1593 std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta));
1594 StringAppendF(&result, "Present delta: %10f\n",
1595 std::chrono::duration<double, std::milli>(presentDeltaNs).count());
Alec Mouri7d436ec2021-01-27 20:40:50 -08001596 std::chrono::nanoseconds deltaToVsync(std::abs(presentDelta) % mRefreshRate.getPeriodNsecs());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001597 StringAppendF(&result, "Present delta %% refreshrate: %10f\n",
1598 std::chrono::duration<double, std::milli>(deltaToVsync).count());
1599 dumpTable(result, mSurfaceFlingerPredictions, mSurfaceFlingerActuals, "", mPredictionState,
1600 baseTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001601 StringAppendF(&result, "\n");
1602 std::string indent = " "; // 4 spaces
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001603 for (const auto& surfaceFrame : mSurfaceFrames) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001604 surfaceFrame->dump(result, indent, baseTime);
1605 }
1606 StringAppendF(&result, "\n");
1607}
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001608
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001609void FrameTimeline::dumpAll(std::string& result) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001610 std::scoped_lock lock(mMutex);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001611 StringAppendF(&result, "Number of display frames : %d\n", (int)mDisplayFrames.size());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001612 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001613 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
1614 StringAppendF(&result, "Display Frame %d", static_cast<int>(i));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001615 mDisplayFrames[i]->dumpAll(result, baseTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001616 }
1617}
1618
1619void FrameTimeline::dumpJank(std::string& result) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001620 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001621 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001622 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001623 mDisplayFrames[i]->dumpJank(result, baseTime, static_cast<int>(i));
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001624 }
1625}
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001626
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001627void FrameTimeline::parseArgs(const Vector<String16>& args, std::string& result) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +00001628 SFTRACE_CALL();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001629 std::unordered_map<std::string, bool> argsMap;
1630 for (size_t i = 0; i < args.size(); i++) {
1631 argsMap[std::string(String8(args[i]).c_str())] = true;
1632 }
1633 if (argsMap.count("-jank")) {
1634 dumpJank(result);
1635 }
1636 if (argsMap.count("-all")) {
1637 dumpAll(result);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001638 }
1639}
1640
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001641void FrameTimeline::setMaxDisplayFrames(uint32_t size) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001642 std::scoped_lock lock(mMutex);
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001643
1644 // The size can either increase or decrease, clear everything, to be consistent
1645 mDisplayFrames.clear();
1646 mPendingPresentFences.clear();
1647 mMaxDisplayFrames = size;
1648}
1649
1650void FrameTimeline::reset() {
1651 setMaxDisplayFrames(kDefaultMaxDisplayFrames);
1652}
1653
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001654} // namespace impl
1655} // namespace android::frametimeline