blob: c13e444a99dfedfd8eab5dc1f6b3ae093a89f4c7 [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
Ady Abraham43a68c32024-09-04 19:21:20 -070041namespace {
42
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070043void dumpTable(std::string& result, TimelineItem predictions, TimelineItem actuals,
44 const std::string& indent, PredictionState predictionState, nsecs_t baseTime) {
45 StringAppendF(&result, "%s", indent.c_str());
46 StringAppendF(&result, "\t\t");
47 StringAppendF(&result, " Start time\t\t|");
48 StringAppendF(&result, " End time\t\t|");
49 StringAppendF(&result, " Present time\n");
50 if (predictionState == PredictionState::Valid) {
51 // Dump the Predictions only if they are valid
52 StringAppendF(&result, "%s", indent.c_str());
53 StringAppendF(&result, "Expected\t|");
54 std::chrono::nanoseconds startTime(predictions.startTime - baseTime);
55 std::chrono::nanoseconds endTime(predictions.endTime - baseTime);
56 std::chrono::nanoseconds presentTime(predictions.presentTime - baseTime);
57 StringAppendF(&result, "\t%10.2f\t|\t%10.2f\t|\t%10.2f\n",
58 std::chrono::duration<double, std::milli>(startTime).count(),
59 std::chrono::duration<double, std::milli>(endTime).count(),
60 std::chrono::duration<double, std::milli>(presentTime).count());
61 }
62 StringAppendF(&result, "%s", indent.c_str());
63 StringAppendF(&result, "Actual \t|");
64
65 if (actuals.startTime == 0) {
66 StringAppendF(&result, "\t\tN/A\t|");
67 } else {
68 std::chrono::nanoseconds startTime(std::max<nsecs_t>(0, actuals.startTime - baseTime));
69 StringAppendF(&result, "\t%10.2f\t|",
70 std::chrono::duration<double, std::milli>(startTime).count());
71 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080072 if (actuals.endTime <= 0) {
73 // Animation leashes can send the endTime as -1
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070074 StringAppendF(&result, "\t\tN/A\t|");
75 } else {
76 std::chrono::nanoseconds endTime(actuals.endTime - baseTime);
77 StringAppendF(&result, "\t%10.2f\t|",
78 std::chrono::duration<double, std::milli>(endTime).count());
79 }
80 if (actuals.presentTime == 0) {
81 StringAppendF(&result, "\t\tN/A\n");
82 } else {
83 std::chrono::nanoseconds presentTime(std::max<nsecs_t>(0, actuals.presentTime - baseTime));
84 StringAppendF(&result, "\t%10.2f\n",
85 std::chrono::duration<double, std::milli>(presentTime).count());
86 }
87
88 StringAppendF(&result, "%s", indent.c_str());
89 StringAppendF(&result, "----------------------");
90 StringAppendF(&result, "----------------------");
91 StringAppendF(&result, "----------------------");
92 StringAppendF(&result, "----------------------\n");
93}
94
95std::string toString(PredictionState predictionState) {
96 switch (predictionState) {
97 case PredictionState::Valid:
98 return "Valid";
99 case PredictionState::Expired:
100 return "Expired";
101 case PredictionState::None:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700102 return "None";
103 }
104}
105
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800106std::string jankTypeBitmaskToString(int32_t jankType) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800107 if (jankType == JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700108 return "None";
109 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000110
111 std::vector<std::string> janks;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800112 if (jankType & JankType::DisplayHAL) {
113 janks.emplace_back("Display HAL");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000114 jankType &= ~JankType::DisplayHAL;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800115 }
116 if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) {
Rachel Lee94917b32022-03-18 17:52:09 -0700117 janks.emplace_back("SurfaceFlinger deadline missed (while in HWC)");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000118 jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800119 }
120 if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) {
Rachel Lee94917b32022-03-18 17:52:09 -0700121 janks.emplace_back("SurfaceFlinger deadline missed (while in GPU comp)");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000122 jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800123 }
124 if (jankType & JankType::AppDeadlineMissed) {
125 janks.emplace_back("App Deadline Missed");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000126 jankType &= ~JankType::AppDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800127 }
128 if (jankType & JankType::PredictionError) {
129 janks.emplace_back("Prediction Error");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000130 jankType &= ~JankType::PredictionError;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800131 }
132 if (jankType & JankType::SurfaceFlingerScheduling) {
133 janks.emplace_back("SurfaceFlinger Scheduling");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000134 jankType &= ~JankType::SurfaceFlingerScheduling;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800135 }
136 if (jankType & JankType::BufferStuffing) {
137 janks.emplace_back("Buffer Stuffing");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000138 jankType &= ~JankType::BufferStuffing;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800139 }
140 if (jankType & JankType::Unknown) {
141 janks.emplace_back("Unknown jank");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000142 jankType &= ~JankType::Unknown;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800143 }
Adithya Srinivasan2045ddf2021-05-27 17:38:10 +0000144 if (jankType & JankType::SurfaceFlingerStuffing) {
145 janks.emplace_back("SurfaceFlinger Stuffing");
146 jankType &= ~JankType::SurfaceFlingerStuffing;
147 }
Edgar Arriaga631e4252023-03-02 02:11:24 +0000148 if (jankType & JankType::Dropped) {
149 janks.emplace_back("Dropped Frame");
150 jankType &= ~JankType::Dropped;
151 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000152
153 // jankType should be 0 if all types of jank were checked for.
154 LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800155 return std::accumulate(janks.begin(), janks.end(), std::string(),
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700156 [](const std::string& l, const std::string& r) {
157 return l.empty() ? r : l + ", " + r;
158 });
159}
160
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800161std::string toString(FramePresentMetadata presentMetadata) {
162 switch (presentMetadata) {
163 case FramePresentMetadata::OnTimePresent:
164 return "On Time Present";
165 case FramePresentMetadata::LatePresent:
166 return "Late Present";
167 case FramePresentMetadata::EarlyPresent:
168 return "Early Present";
169 case FramePresentMetadata::UnknownPresent:
170 return "Unknown Present";
Adithya Srinivasan01189672020-10-20 14:23:05 -0700171 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700172}
173
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800174std::string toString(FrameReadyMetadata finishMetadata) {
175 switch (finishMetadata) {
176 case FrameReadyMetadata::OnTimeFinish:
177 return "On Time Finish";
178 case FrameReadyMetadata::LateFinish:
179 return "Late Finish";
180 case FrameReadyMetadata::UnknownFinish:
181 return "Unknown Finish";
182 }
183}
184
185std::string toString(FrameStartMetadata startMetadata) {
186 switch (startMetadata) {
187 case FrameStartMetadata::OnTimeStart:
188 return "On Time Start";
189 case FrameStartMetadata::LateStart:
190 return "Late Start";
191 case FrameStartMetadata::EarlyStart:
192 return "Early Start";
193 case FrameStartMetadata::UnknownStart:
194 return "Unknown Start";
195 }
196}
197
198std::string toString(SurfaceFrame::PresentState presentState) {
199 using PresentState = SurfaceFrame::PresentState;
200 switch (presentState) {
201 case PresentState::Presented:
202 return "Presented";
203 case PresentState::Dropped:
204 return "Dropped";
205 case PresentState::Unknown:
206 return "Unknown";
207 }
208}
209
210FrameTimelineEvent::PresentType toProto(FramePresentMetadata presentMetadata) {
211 switch (presentMetadata) {
212 case FramePresentMetadata::EarlyPresent:
213 return FrameTimelineEvent::PRESENT_EARLY;
214 case FramePresentMetadata::LatePresent:
215 return FrameTimelineEvent::PRESENT_LATE;
216 case FramePresentMetadata::OnTimePresent:
217 return FrameTimelineEvent::PRESENT_ON_TIME;
218 case FramePresentMetadata::UnknownPresent:
219 return FrameTimelineEvent::PRESENT_UNSPECIFIED;
220 }
221}
222
Adithya Srinivasan78e58af2021-02-25 00:08:08 +0000223FrameTimelineEvent::PredictionType toProto(PredictionState predictionState) {
224 switch (predictionState) {
225 case PredictionState::Valid:
226 return FrameTimelineEvent::PREDICTION_VALID;
227 case PredictionState::Expired:
228 return FrameTimelineEvent::PREDICTION_EXPIRED;
229 case PredictionState::None:
230 return FrameTimelineEvent::PREDICTION_UNKNOWN;
231 }
232}
233
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000234int32_t jankTypeBitmaskToProto(int32_t jankType) {
235 if (jankType == JankType::None) {
236 return FrameTimelineEvent::JANK_NONE;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700237 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000238
239 int32_t protoJank = 0;
240 if (jankType & JankType::DisplayHAL) {
241 protoJank |= FrameTimelineEvent::JANK_DISPLAY_HAL;
242 jankType &= ~JankType::DisplayHAL;
243 }
244 if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) {
245 protoJank |= FrameTimelineEvent::JANK_SF_CPU_DEADLINE_MISSED;
246 jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed;
247 }
248 if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) {
249 protoJank |= FrameTimelineEvent::JANK_SF_GPU_DEADLINE_MISSED;
250 jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed;
251 }
252 if (jankType & JankType::AppDeadlineMissed) {
253 protoJank |= FrameTimelineEvent::JANK_APP_DEADLINE_MISSED;
254 jankType &= ~JankType::AppDeadlineMissed;
255 }
256 if (jankType & JankType::PredictionError) {
257 protoJank |= FrameTimelineEvent::JANK_PREDICTION_ERROR;
258 jankType &= ~JankType::PredictionError;
259 }
260 if (jankType & JankType::SurfaceFlingerScheduling) {
261 protoJank |= FrameTimelineEvent::JANK_SF_SCHEDULING;
262 jankType &= ~JankType::SurfaceFlingerScheduling;
263 }
264 if (jankType & JankType::BufferStuffing) {
265 protoJank |= FrameTimelineEvent::JANK_BUFFER_STUFFING;
266 jankType &= ~JankType::BufferStuffing;
267 }
268 if (jankType & JankType::Unknown) {
269 protoJank |= FrameTimelineEvent::JANK_UNKNOWN;
270 jankType &= ~JankType::Unknown;
271 }
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +0000272 if (jankType & JankType::SurfaceFlingerStuffing) {
273 protoJank |= FrameTimelineEvent::JANK_SF_STUFFING;
274 jankType &= ~JankType::SurfaceFlingerStuffing;
275 }
Edgar Arriaga631e4252023-03-02 02:11:24 +0000276 if (jankType & JankType::Dropped) {
277 // Jank dropped does not append to other janks, it fully overrides.
278 protoJank |= FrameTimelineEvent::JANK_DROPPED;
279 jankType &= ~JankType::Dropped;
280 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000281
282 // jankType should be 0 if all types of jank were checked for.
283 LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType);
284 return protoJank;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700285}
286
Ying Wei96eb5352023-11-21 17:37:21 +0000287FrameTimelineEvent::JankSeverityType toProto(JankSeverityType jankSeverityType) {
288 switch (jankSeverityType) {
289 case JankSeverityType::Unknown:
290 return FrameTimelineEvent::SEVERITY_UNKNOWN;
291 case JankSeverityType::None:
292 return FrameTimelineEvent::SEVERITY_NONE;
293 case JankSeverityType::Partial:
294 return FrameTimelineEvent::SEVERITY_PARTIAL;
295 case JankSeverityType::Full:
296 return FrameTimelineEvent::SEVERITY_FULL;
297 }
298}
299
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800300// Returns the smallest timestamp from the set of predictions and actuals.
301nsecs_t getMinTime(PredictionState predictionState, TimelineItem predictions,
302 TimelineItem actuals) {
303 nsecs_t minTime = std::numeric_limits<nsecs_t>::max();
304 if (predictionState == PredictionState::Valid) {
305 // Checking start time for predictions is enough because start time is always lesser than
306 // endTime and presentTime.
307 minTime = std::min(minTime, predictions.startTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700308 }
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700309
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800310 // Need to check startTime, endTime and presentTime for actuals because some frames might not
311 // have them set.
312 if (actuals.startTime != 0) {
313 minTime = std::min(minTime, actuals.startTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700314 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800315 if (actuals.endTime != 0) {
316 minTime = std::min(minTime, actuals.endTime);
317 }
318 if (actuals.presentTime != 0) {
ramindaniea2bb822022-06-27 19:52:10 +0000319 minTime = std::min(minTime, actuals.presentTime);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800320 }
321 return minTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700322}
323
Ady Abraham43a68c32024-09-04 19:21:20 -0700324bool shouldTraceForDataSource(const FrameTimelineDataSource::TraceContext& ctx, nsecs_t timestamp) {
325 if (auto ds = ctx.GetDataSourceLocked(); ds && ds->getStartTime() > timestamp) {
326 return false;
327 }
328
329 return true;
330}
331
332} // namespace
333
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000334int64_t TraceCookieCounter::getCookieForTracing() {
335 return ++mTraceCookie;
336}
337
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000338SurfaceFrame::SurfaceFrame(const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid,
Alec Mouriadebf5c2021-01-05 12:57:36 -0800339 uid_t ownerUid, int32_t layerId, std::string layerName,
340 std::string debugName, PredictionState predictionState,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800341 frametimeline::TimelineItem&& predictions,
342 std::shared_ptr<TimeStats> timeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000343 JankClassificationThresholds thresholds,
Dominik Laskowskif5d0ea52021-09-26 17:27:01 -0700344 TraceCookieCounter* traceCookieCounter, bool isBuffer, GameMode gameMode)
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000345 : mToken(frameTimelineInfo.vsyncId),
346 mInputEventId(frameTimelineInfo.inputEventId),
Adithya Srinivasan01189672020-10-20 14:23:05 -0700347 mOwnerPid(ownerPid),
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700348 mOwnerUid(ownerUid),
Alec Mouri9a29e672020-09-14 12:39:14 -0700349 mLayerName(std::move(layerName)),
350 mDebugName(std::move(debugName)),
Alec Mouriadebf5c2021-01-05 12:57:36 -0800351 mLayerId(layerId),
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700352 mPresentState(PresentState::Unknown),
353 mPredictionState(predictionState),
354 mPredictions(predictions),
355 mActuals({0, 0, 0}),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800356 mTimeStats(timeStats),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000357 mJankClassificationThresholds(thresholds),
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000358 mTraceCookieCounter(*traceCookieCounter),
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000359 mIsBuffer(isBuffer),
360 mGameMode(gameMode) {}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700361
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700362void SurfaceFrame::setActualStartTime(nsecs_t actualStartTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000363 std::scoped_lock lock(mMutex);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700364 mActuals.startTime = actualStartTime;
365}
366
367void SurfaceFrame::setActualQueueTime(nsecs_t actualQueueTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000368 std::scoped_lock lock(mMutex);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700369 mActualQueueTime = actualQueueTime;
370}
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000371
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700372void SurfaceFrame::setAcquireFenceTime(nsecs_t acquireFenceTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000373 std::scoped_lock lock(mMutex);
Vishnu Nairbd7d07e2024-07-08 13:37:11 -0700374 if (CC_UNLIKELY(acquireFenceTime == Fence::SIGNAL_TIME_PENDING)) {
375 mActuals.endTime = mActualQueueTime;
376 } else {
377 mActuals.endTime = std::max(acquireFenceTime, mActualQueueTime);
378 }
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700379}
380
Ben Widawskyebdbead2024-10-24 11:47:50 -0700381void SurfaceFrame::setDesiredPresentTime(nsecs_t desiredPresentTime) {
382 std::scoped_lock lock(mMutex);
383 mActuals.desiredPresentTime = desiredPresentTime;
384}
385
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000386void SurfaceFrame::setDropTime(nsecs_t dropTime) {
387 std::scoped_lock lock(mMutex);
388 mDropTime = dropTime;
389}
390
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800391void SurfaceFrame::setPresentState(PresentState presentState, nsecs_t lastLatchTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000392 std::scoped_lock lock(mMutex);
Adithya Srinivasanb9a7dab2021-01-14 23:49:46 +0000393 LOG_ALWAYS_FATAL_IF(mPresentState != PresentState::Unknown,
394 "setPresentState called on a SurfaceFrame from Layer - %s, that has a "
395 "PresentState - %s set already.",
396 mDebugName.c_str(), toString(mPresentState).c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800397 mPresentState = presentState;
398 mLastLatchTime = lastLatchTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700399}
400
Alec Mouri7d436ec2021-01-27 20:40:50 -0800401void SurfaceFrame::setRenderRate(Fps renderRate) {
402 std::lock_guard<std::mutex> lock(mMutex);
403 mRenderRate = renderRate;
404}
405
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200406Fps SurfaceFrame::getRenderRate() const {
407 std::lock_guard<std::mutex> lock(mMutex);
408 return mRenderRate ? *mRenderRate : mDisplayFrameRenderRate;
409}
410
Adithya Srinivasanb6a2fa12021-03-13 00:23:09 +0000411void SurfaceFrame::setGpuComposition() {
412 std::scoped_lock lock(mMutex);
413 mGpuComposition = true;
414}
415
Sally Qi438eb7d2023-12-05 18:59:32 -0800416// TODO(b/316171339): migrate from perfetto side
417bool SurfaceFrame::isSelfJanky() const {
418 int32_t jankType = getJankType().value_or(JankType::None);
419
420 if (jankType == JankType::None) {
421 return false;
422 }
423
424 int32_t jankBitmask = JankType::AppDeadlineMissed | JankType::Unknown;
425 if (jankType & jankBitmask) {
426 return true;
427 }
428
429 return false;
430}
431
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800432std::optional<int32_t> SurfaceFrame::getJankType() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000433 std::scoped_lock lock(mMutex);
Adithya Srinivasan95619432021-02-08 21:52:51 +0000434 if (mPresentState == PresentState::Dropped) {
Edgar Arriaga631e4252023-03-02 02:11:24 +0000435 return JankType::Dropped;
Adithya Srinivasan95619432021-02-08 21:52:51 +0000436 }
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100437 if (mActuals.presentTime == 0) {
Adithya Srinivasan95619432021-02-08 21:52:51 +0000438 // Frame hasn't been presented yet.
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100439 return std::nullopt;
440 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700441 return mJankType;
442}
443
Ying Wei96eb5352023-11-21 17:37:21 +0000444std::optional<JankSeverityType> SurfaceFrame::getJankSeverityType() const {
445 std::scoped_lock lock(mMutex);
446 if (mActuals.presentTime == 0) {
447 // Frame hasn't been presented yet.
448 return std::nullopt;
449 }
450 return mJankSeverityType;
451}
452
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700453nsecs_t SurfaceFrame::getBaseTime() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000454 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800455 return getMinTime(mPredictionState, mPredictions, mActuals);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700456}
457
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800458TimelineItem SurfaceFrame::getActuals() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000459 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800460 return mActuals;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700461}
462
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000463PredictionState SurfaceFrame::getPredictionState() const {
464 std::scoped_lock lock(mMutex);
465 return mPredictionState;
466}
467
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800468SurfaceFrame::PresentState SurfaceFrame::getPresentState() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000469 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800470 return mPresentState;
471}
472
473FramePresentMetadata SurfaceFrame::getFramePresentMetadata() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000474 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800475 return mFramePresentMetadata;
476}
477
478FrameReadyMetadata SurfaceFrame::getFrameReadyMetadata() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000479 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800480 return mFrameReadyMetadata;
481}
482
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000483nsecs_t SurfaceFrame::getDropTime() const {
484 std::scoped_lock lock(mMutex);
485 return mDropTime;
486}
487
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000488void SurfaceFrame::promoteToBuffer() {
489 std::scoped_lock lock(mMutex);
490 LOG_ALWAYS_FATAL_IF(mIsBuffer == true,
491 "Trying to promote an already promoted BufferSurfaceFrame from layer %s "
492 "with token %" PRId64 "",
493 mDebugName.c_str(), mToken);
494 mIsBuffer = true;
495}
496
497bool SurfaceFrame::getIsBuffer() const {
498 std::scoped_lock lock(mMutex);
499 return mIsBuffer;
500}
501
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800502void SurfaceFrame::dump(std::string& result, const std::string& indent, nsecs_t baseTime) const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000503 std::scoped_lock lock(mMutex);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700504 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri9a29e672020-09-14 12:39:14 -0700505 StringAppendF(&result, "Layer - %s", mDebugName.c_str());
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100506 if (mJankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700507 // Easily identify a janky Surface Frame in the dump
508 StringAppendF(&result, " [*] ");
509 }
510 StringAppendF(&result, "\n");
511 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800512 StringAppendF(&result, "Token: %" PRId64 "\n", mToken);
513 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000514 StringAppendF(&result, "Is Buffer?: %d\n", mIsBuffer);
515 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700516 StringAppendF(&result, "Owner Pid : %d\n", mOwnerPid);
517 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri7d436ec2021-01-27 20:40:50 -0800518 StringAppendF(&result, "Scheduled rendering rate: %d fps\n",
519 mRenderRate ? mRenderRate->getIntValue() : 0);
520 StringAppendF(&result, "%s", indent.c_str());
Alec Mouriadebf5c2021-01-05 12:57:36 -0800521 StringAppendF(&result, "Layer ID : %d\n", mLayerId);
522 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800523 StringAppendF(&result, "Present State : %s\n", toString(mPresentState).c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700524 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000525 if (mPresentState == PresentState::Dropped) {
526 std::chrono::nanoseconds dropTime(mDropTime - baseTime);
527 StringAppendF(&result, "Drop time : %10f\n",
528 std::chrono::duration<double, std::milli>(dropTime).count());
529 StringAppendF(&result, "%s", indent.c_str());
530 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700531 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
532 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800533 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700534 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800535 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
536 StringAppendF(&result, "%s", indent.c_str());
537 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
538 std::chrono::nanoseconds latchTime(
539 std::max(static_cast<int64_t>(0), mLastLatchTime - baseTime));
540 StringAppendF(&result, "%s", indent.c_str());
541 StringAppendF(&result, "Last latch time: %10f\n",
542 std::chrono::duration<double, std::milli>(latchTime).count());
543 if (mPredictionState == PredictionState::Valid) {
544 nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime;
545 std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta));
546 StringAppendF(&result, "%s", indent.c_str());
547 StringAppendF(&result, "Present delta: %10f\n",
548 std::chrono::duration<double, std::milli>(presentDeltaNs).count());
549 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700550 dumpTable(result, mPredictions, mActuals, indent, mPredictionState, baseTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700551}
552
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000553std::string SurfaceFrame::miniDump() const {
554 std::scoped_lock lock(mMutex);
555 std::string result;
556 StringAppendF(&result, "Layer - %s\n", mDebugName.c_str());
557 StringAppendF(&result, "Token: %" PRId64 "\n", mToken);
558 StringAppendF(&result, "Is Buffer?: %d\n", mIsBuffer);
559 StringAppendF(&result, "Present State : %s\n", toString(mPresentState).c_str());
560 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
561 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
562 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
563 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
564 StringAppendF(&result, "Present time: %" PRId64 "", mActuals.presentTime);
565 return result;
566}
567
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000568void SurfaceFrame::classifyJankLocked(int32_t displayFrameJankType, const Fps& refreshRate,
Ady Abrahame96e79f2024-05-20 18:00:39 +0000569 Fps displayFrameRenderRate, nsecs_t* outDeadlineDelta) {
Ady Abrahame43ff722022-02-15 14:44:25 -0800570 if (mActuals.presentTime == Fence::SIGNAL_TIME_INVALID) {
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000571 // Cannot do any classification for invalid present time.
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000572 mJankType = JankType::Unknown;
Ying Wei96eb5352023-11-21 17:37:21 +0000573 mJankSeverityType = JankSeverityType::Unknown;
Ady Abrahame96e79f2024-05-20 18:00:39 +0000574 if (outDeadlineDelta) {
575 *outDeadlineDelta = -1;
576 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800577 return;
578 }
579
Ady Abrahame43ff722022-02-15 14:44:25 -0800580 if (mPredictionState == PredictionState::Expired) {
581 // We classify prediction expired as AppDeadlineMissed as the
582 // TokenManager::kMaxTokens we store is large enough to account for a
583 // reasonable app, so prediction expire would mean a huge scheduling delay.
Edgar Arriaga631e4252023-03-02 02:11:24 +0000584 mJankType = mPresentState != PresentState::Presented ? JankType::Dropped
585 : JankType::AppDeadlineMissed;
Ying Wei96eb5352023-11-21 17:37:21 +0000586 mJankSeverityType = JankSeverityType::Unknown;
Ady Abrahame96e79f2024-05-20 18:00:39 +0000587 if (outDeadlineDelta) {
588 *outDeadlineDelta = -1;
589 }
Ady Abrahame43ff722022-02-15 14:44:25 -0800590 return;
591 }
592
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800593 if (mPredictionState == PredictionState::None) {
594 // Cannot do jank classification on frames that don't have a token.
595 return;
596 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800597
598 const nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime;
Alec Mouriadebf5c2021-01-05 12:57:36 -0800599 const nsecs_t deltaToVsync = refreshRate.getPeriodNsecs() > 0
600 ? std::abs(presentDelta) % refreshRate.getPeriodNsecs()
601 : 0;
Ady Abrahame96e79f2024-05-20 18:00:39 +0000602 const nsecs_t deadlineDelta = mActuals.endTime - mPredictions.endTime;
603 if (outDeadlineDelta) {
604 *outDeadlineDelta = deadlineDelta;
605 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800606
607 if (deadlineDelta > mJankClassificationThresholds.deadlineThreshold) {
608 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
609 } else {
610 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
611 }
612
613 if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) {
614 mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent
615 : FramePresentMetadata::EarlyPresent;
Ying Wei96eb5352023-11-21 17:37:21 +0000616 // Jank that is missing by less than the render rate period is classified as partial jank,
617 // otherwise it is a full jank.
618 mJankSeverityType = std::abs(presentDelta) < displayFrameRenderRate.getPeriodNsecs()
619 ? JankSeverityType::Partial
620 : JankSeverityType::Full;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800621 } else {
622 mFramePresentMetadata = FramePresentMetadata::OnTimePresent;
623 }
624
625 if (mFramePresentMetadata == FramePresentMetadata::OnTimePresent) {
626 // Frames presented on time are not janky.
627 mJankType = JankType::None;
628 } else if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) {
629 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
630 // Finish on time, Present early
631 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -0800632 deltaToVsync >= refreshRate.getPeriodNsecs() -
633 mJankClassificationThresholds.presentThreshold) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800634 // Delta factor of vsync
635 mJankType = JankType::SurfaceFlingerScheduling;
636 } else {
637 // Delta not a factor of vsync
638 mJankType = JankType::PredictionError;
639 }
640 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
641 // Finish late, Present early
642 mJankType = JankType::Unknown;
643 }
644 } else {
645 if (mLastLatchTime != 0 && mPredictions.endTime <= mLastLatchTime) {
646 // Buffer Stuffing.
647 mJankType |= JankType::BufferStuffing;
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000648 // In a stuffed state, the frame could be stuck on a dequeue wait for quite some time.
649 // Because of this dequeue wait, it can be hard to tell if a frame was genuinely late.
650 // We try to do this by moving the deadline. Since the queue could be stuffed by more
651 // than one buffer, we take the last latch time as reference and give one vsync
652 // worth of time for the frame to be ready.
653 nsecs_t adjustedDeadline = mLastLatchTime + refreshRate.getPeriodNsecs();
654 if (adjustedDeadline > mActuals.endTime) {
655 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
656 } else {
657 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
658 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800659 }
660 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
661 // Finish on time, Present late
662 if (displayFrameJankType != JankType::None) {
663 // Propagate displayFrame's jank if it exists
664 mJankType |= displayFrameJankType;
665 } else {
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000666 if (!(mJankType & JankType::BufferStuffing)) {
667 // In a stuffed state, if the app finishes on time and there is no display frame
668 // jank, only buffer stuffing is the root cause of the jank.
669 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
670 deltaToVsync >= refreshRate.getPeriodNsecs() -
671 mJankClassificationThresholds.presentThreshold) {
672 // Delta factor of vsync
673 mJankType |= JankType::SurfaceFlingerScheduling;
674 } else {
675 // Delta not a factor of vsync
676 mJankType |= JankType::PredictionError;
677 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800678 }
679 }
680 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
681 // Finish late, Present late
Adithya Srinivasan8a945502021-03-19 19:12:32 +0000682 mJankType |= JankType::AppDeadlineMissed;
683 // Propagate DisplayFrame's jankType if it is janky
684 mJankType |= displayFrameJankType;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800685 }
686 }
Edgar Arriaga631e4252023-03-02 02:11:24 +0000687 if (mPresentState != PresentState::Presented) {
688 mJankType = JankType::Dropped;
689 // Since frame was not presented, lets drop any present value
690 mActuals.presentTime = 0;
Ying Wei96eb5352023-11-21 17:37:21 +0000691 mJankSeverityType = JankSeverityType::Unknown;
Edgar Arriaga631e4252023-03-02 02:11:24 +0000692 }
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000693}
694
695void SurfaceFrame::onPresent(nsecs_t presentTime, int32_t displayFrameJankType, Fps refreshRate,
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200696 Fps displayFrameRenderRate, nsecs_t displayDeadlineDelta,
697 nsecs_t displayPresentDelta) {
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000698 std::scoped_lock lock(mMutex);
699
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200700 mDisplayFrameRenderRate = displayFrameRenderRate;
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000701 mActuals.presentTime = presentTime;
702 nsecs_t deadlineDelta = 0;
703
Ady Abrahame96e79f2024-05-20 18:00:39 +0000704 classifyJankLocked(displayFrameJankType, refreshRate, displayFrameRenderRate, &deadlineDelta);
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000705
706 if (mPredictionState != PredictionState::None) {
707 // Only update janky frames if the app used vsync predictions
708 mTimeStats->incrementJankyFrames({refreshRate, mRenderRate, mOwnerUid, mLayerName,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000709 mGameMode, mJankType, displayDeadlineDelta,
710 displayPresentDelta, deadlineDelta});
Pascal Mütschardd56514e2024-05-24 17:37:13 +0200711
712 gui::JankData jd;
713 jd.frameVsyncId = mToken;
714 jd.jankType = mJankType;
715 jd.frameIntervalNs =
716 (mRenderRate ? *mRenderRate : mDisplayFrameRenderRate).getPeriodNsecs();
Pascal Mütschard0e8452b2024-09-03 11:02:11 +0200717
718 if (mPredictionState == PredictionState::Valid) {
719 jd.scheduledAppFrameTimeNs = mPredictions.endTime - mPredictions.startTime;
720
721 // Using expected start, rather than actual, to measure the entire frame time. That is
722 // if the application starts the frame later than scheduled, include that delay in the
723 // frame time, as it usually means main thread being busy with non-rendering work.
724 if (mPresentState == PresentState::Dropped) {
725 jd.actualAppFrameTimeNs = mDropTime - mPredictions.startTime;
726 } else {
727 jd.actualAppFrameTimeNs = mActuals.endTime - mPredictions.startTime;
728 }
729 } else {
730 jd.scheduledAppFrameTimeNs = 0;
731 jd.actualAppFrameTimeNs = 0;
732 }
733
Pascal Mütschardd56514e2024-05-24 17:37:13 +0200734 JankTracker::onJankData(mLayerId, jd);
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +0000735 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800736}
737
Ady Abraham14beed72024-05-15 17:16:45 -0700738void SurfaceFrame::onCommitNotComposited(Fps refreshRate, Fps displayFrameRenderRate) {
739 std::scoped_lock lock(mMutex);
740
741 mDisplayFrameRenderRate = displayFrameRenderRate;
742 mActuals.presentTime = mPredictions.presentTime;
Ady Abrahame96e79f2024-05-20 18:00:39 +0000743 classifyJankLocked(JankType::None, refreshRate, displayFrameRenderRate, nullptr);
Ady Abraham14beed72024-05-15 17:16:45 -0700744}
745
Ady Abraham43a68c32024-09-04 19:21:20 -0700746void SurfaceFrame::tracePredictions(int64_t displayFrameToken, nsecs_t monoBootOffset,
747 bool filterFramesBeforeTraceStarts) const {
Adithya Srinivasan86678502021-01-19 21:50:38 +0000748 int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Ady Abraham43a68c32024-09-04 19:21:20 -0700749 bool traced = false;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000750
Adithya Srinivasan86678502021-01-19 21:50:38 +0000751 // Expected timeline start
752 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Ady Abraham43a68c32024-09-04 19:21:20 -0700753 const auto timestamp = mPredictions.startTime;
754 if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) {
755 // Do not trace packets started before tracing starts.
756 return;
757 }
758 traced = true;
759
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000760 std::scoped_lock lock(mMutex);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700761 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -0800762 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
Ady Abraham43a68c32024-09-04 19:21:20 -0700763 packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700764
765 auto* event = packet->set_frame_timeline_event();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000766 auto* expectedSurfaceFrameStartEvent = event->set_expected_surface_frame_start();
Adithya Srinivasan01189672020-10-20 14:23:05 -0700767
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000768 expectedSurfaceFrameStartEvent->set_cookie(expectedTimelineCookie);
769
770 expectedSurfaceFrameStartEvent->set_token(mToken);
771 expectedSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken);
772
773 expectedSurfaceFrameStartEvent->set_pid(mOwnerPid);
774 expectedSurfaceFrameStartEvent->set_layer_name(mDebugName);
775 });
Adithya Srinivasan86678502021-01-19 21:50:38 +0000776
Ady Abraham43a68c32024-09-04 19:21:20 -0700777 if (traced) {
778 // Expected timeline end
779 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
780 std::scoped_lock lock(mMutex);
781 auto packet = ctx.NewTracePacket();
782 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
783 packet->set_timestamp(static_cast<uint64_t>(mPredictions.endTime + monoBootOffset));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000784
Ady Abraham43a68c32024-09-04 19:21:20 -0700785 auto* event = packet->set_frame_timeline_event();
786 auto* expectedSurfaceFrameEndEvent = event->set_frame_end();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000787
Ady Abraham43a68c32024-09-04 19:21:20 -0700788 expectedSurfaceFrameEndEvent->set_cookie(expectedTimelineCookie);
789 });
790 }
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000791}
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000792
Ady Abraham43a68c32024-09-04 19:21:20 -0700793void SurfaceFrame::traceActuals(int64_t displayFrameToken, nsecs_t monoBootOffset,
794 bool filterFramesBeforeTraceStarts) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000795 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Ady Abraham43a68c32024-09-04 19:21:20 -0700796 bool traced = false;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000797
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000798 // Actual timeline start
799 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Ady Abraham43a68c32024-09-04 19:21:20 -0700800 const auto timestamp = [&]() {
801 std::scoped_lock lock(mMutex);
802 // Actual start time is not yet available, so use expected start instead
803 if (mPredictionState == PredictionState::Expired) {
804 // If prediction is expired, we can't use the predicted start time. Instead, just
805 // use a start time a little earlier than the end time so that we have some info
806 // about this frame in the trace.
807 nsecs_t endTime =
808 (mPresentState == PresentState::Dropped ? mDropTime : mActuals.endTime);
809 return endTime - kPredictionExpiredStartTimeDelta;
810 }
811
812 return mActuals.startTime == 0 ? mPredictions.startTime : mActuals.startTime;
813 }();
814
815 if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) {
816 // Do not trace packets started before tracing starts.
817 return;
818 }
819 traced = true;
820
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000821 std::scoped_lock lock(mMutex);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000822 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -0800823 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
Ady Abraham43a68c32024-09-04 19:21:20 -0700824 packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000825
826 auto* event = packet->set_frame_timeline_event();
827 auto* actualSurfaceFrameStartEvent = event->set_actual_surface_frame_start();
828
829 actualSurfaceFrameStartEvent->set_cookie(actualTimelineCookie);
830
831 actualSurfaceFrameStartEvent->set_token(mToken);
832 actualSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken);
833
834 actualSurfaceFrameStartEvent->set_pid(mOwnerPid);
835 actualSurfaceFrameStartEvent->set_layer_name(mDebugName);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700836
837 if (mPresentState == PresentState::Dropped) {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000838 actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700839 } else if (mPresentState == PresentState::Unknown) {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000840 actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_UNSPECIFIED);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700841 } else {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000842 actualSurfaceFrameStartEvent->set_present_type(toProto(mFramePresentMetadata));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700843 }
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000844 actualSurfaceFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
845 FrameReadyMetadata::OnTimeFinish);
846 actualSurfaceFrameStartEvent->set_gpu_composition(mGpuComposition);
847 actualSurfaceFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType));
Adithya Srinivasan78e58af2021-02-25 00:08:08 +0000848 actualSurfaceFrameStartEvent->set_prediction_type(toProto(mPredictionState));
Adithya Srinivasan1f9450c2021-06-10 22:39:19 +0000849 actualSurfaceFrameStartEvent->set_is_buffer(mIsBuffer);
Ying Wei96eb5352023-11-21 17:37:21 +0000850 actualSurfaceFrameStartEvent->set_jank_severity_type(toProto(mJankSeverityType));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000851 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000852
Ady Abraham43a68c32024-09-04 19:21:20 -0700853 if (traced) {
854 // Actual timeline end
855 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
856 std::scoped_lock lock(mMutex);
857 auto packet = ctx.NewTracePacket();
858 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
859 if (mPresentState == PresentState::Dropped) {
860 packet->set_timestamp(static_cast<uint64_t>(mDropTime + monoBootOffset));
861 } else {
862 packet->set_timestamp(static_cast<uint64_t>(mActuals.endTime + monoBootOffset));
863 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700864
Ady Abraham43a68c32024-09-04 19:21:20 -0700865 auto* event = packet->set_frame_timeline_event();
866 auto* actualSurfaceFrameEndEvent = event->set_frame_end();
Adithya Srinivasan01189672020-10-20 14:23:05 -0700867
Ady Abraham43a68c32024-09-04 19:21:20 -0700868 actualSurfaceFrameEndEvent->set_cookie(actualTimelineCookie);
869 });
870 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700871}
872
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000873/**
874 * TODO(b/178637512): add inputEventId to the perfetto trace.
875 */
Ady Abraham43a68c32024-09-04 19:21:20 -0700876void SurfaceFrame::trace(int64_t displayFrameToken, nsecs_t monoBootOffset,
877 bool filterFramesBeforeTraceStarts) const {
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000878 if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID ||
879 displayFrameToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
880 // No packets can be traced with a missing token.
881 return;
882 }
883 if (getPredictionState() != PredictionState::Expired) {
884 // Expired predictions have zeroed timestamps. This cannot be used in any meaningful way in
885 // a trace.
Ady Abraham43a68c32024-09-04 19:21:20 -0700886 tracePredictions(displayFrameToken, monoBootOffset, filterFramesBeforeTraceStarts);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000887 }
Ady Abraham43a68c32024-09-04 19:21:20 -0700888 traceActuals(displayFrameToken, monoBootOffset, filterFramesBeforeTraceStarts);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000889}
890
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800891namespace impl {
892
893int64_t TokenManager::generateTokenForPredictions(TimelineItem&& predictions) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000894 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000895 std::scoped_lock lock(mMutex);
Adithya Srinivasanbed4c4f2021-05-03 20:24:46 +0000896 while (mPredictions.size() >= kMaxTokens) {
897 mPredictions.erase(mPredictions.begin());
898 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800899 const int64_t assignedToken = mCurrentToken++;
Adithya Srinivasanbed4c4f2021-05-03 20:24:46 +0000900 mPredictions[assignedToken] = predictions;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800901 return assignedToken;
902}
903
904std::optional<TimelineItem> TokenManager::getPredictionsForToken(int64_t token) const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000905 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800906 auto predictionsIterator = mPredictions.find(token);
907 if (predictionsIterator != mPredictions.end()) {
Adithya Srinivasanbed4c4f2021-05-03 20:24:46 +0000908 return predictionsIterator->second;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800909 }
910 return {};
911}
912
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800913FrameTimeline::FrameTimeline(std::shared_ptr<TimeStats> timeStats, pid_t surfaceFlingerPid,
Ady Abraham43a68c32024-09-04 19:21:20 -0700914 JankClassificationThresholds thresholds, bool useBootTimeClock,
915 bool filterFramesBeforeTraceStarts)
Ady Abraham57f8e182022-03-08 15:54:33 -0800916 : mUseBootTimeClock(useBootTimeClock),
Ady Abraham43a68c32024-09-04 19:21:20 -0700917 mFilterFramesBeforeTraceStarts(
918 FlagManager::getInstance().filter_frames_before_trace_starts() &&
919 filterFramesBeforeTraceStarts),
Ady Abraham57f8e182022-03-08 15:54:33 -0800920 mMaxDisplayFrames(kDefaultMaxDisplayFrames),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800921 mTimeStats(std::move(timeStats)),
922 mSurfaceFlingerPid(surfaceFlingerPid),
Adithya Srinivasan82eef322021-04-10 00:06:04 +0000923 mJankClassificationThresholds(thresholds) {
924 mCurrentDisplayFrame =
925 std::make_shared<DisplayFrame>(mTimeStats, thresholds, &mTraceCookieCounter);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000926}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700927
Adithya Srinivasan01189672020-10-20 14:23:05 -0700928void FrameTimeline::onBootFinished() {
929 perfetto::TracingInitArgs args;
930 args.backends = perfetto::kSystemBackend;
931 perfetto::Tracing::Initialize(args);
932 registerDataSource();
933}
934
935void FrameTimeline::registerDataSource() {
936 perfetto::DataSourceDescriptor dsd;
937 dsd.set_name(kFrameTimelineDataSource);
938 FrameTimelineDataSource::Register(dsd);
939}
940
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800941std::shared_ptr<SurfaceFrame> FrameTimeline::createSurfaceFrameForToken(
Alec Mouriadebf5c2021-01-05 12:57:36 -0800942 const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid, uid_t ownerUid, int32_t layerId,
Dominik Laskowskif5d0ea52021-09-26 17:27:01 -0700943 std::string layerName, std::string debugName, bool isBuffer, GameMode gameMode) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000944 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000945 if (frameTimelineInfo.vsyncId == FrameTimelineInfo::INVALID_VSYNC_ID) {
Alec Mouriadebf5c2021-01-05 12:57:36 -0800946 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000947 std::move(layerName), std::move(debugName),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800948 PredictionState::None, TimelineItem(), mTimeStats,
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000949 mJankClassificationThresholds, &mTraceCookieCounter,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000950 isBuffer, gameMode);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700951 }
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000952 std::optional<TimelineItem> predictions =
953 mTokenManager.getPredictionsForToken(frameTimelineInfo.vsyncId);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700954 if (predictions) {
Alec Mouriadebf5c2021-01-05 12:57:36 -0800955 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000956 std::move(layerName), std::move(debugName),
957 PredictionState::Valid, std::move(*predictions),
958 mTimeStats, mJankClassificationThresholds,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000959 &mTraceCookieCounter, isBuffer, gameMode);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700960 }
Alec Mouriadebf5c2021-01-05 12:57:36 -0800961 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000962 std::move(layerName), std::move(debugName),
963 PredictionState::Expired, TimelineItem(), mTimeStats,
Adithya Srinivasan785addd2021-03-09 00:38:00 +0000964 mJankClassificationThresholds, &mTraceCookieCounter,
Adithya Srinivasan58069dc2021-06-04 20:37:02 +0000965 isBuffer, gameMode);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700966}
967
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800968FrameTimeline::DisplayFrame::DisplayFrame(std::shared_ptr<TimeStats> timeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000969 JankClassificationThresholds thresholds,
970 TraceCookieCounter* traceCookieCounter)
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800971 : mSurfaceFlingerPredictions(TimelineItem()),
972 mSurfaceFlingerActuals(TimelineItem()),
973 mTimeStats(timeStats),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000974 mJankClassificationThresholds(thresholds),
975 mTraceCookieCounter(*traceCookieCounter) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800976 mSurfaceFrames.reserve(kNumSurfaceFramesInitial);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700977}
978
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800979void FrameTimeline::addSurfaceFrame(std::shared_ptr<SurfaceFrame> surfaceFrame) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000980 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000981 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800982 mCurrentDisplayFrame->addSurfaceFrame(surfaceFrame);
983}
984
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200985void FrameTimeline::setSfWakeUp(int64_t token, nsecs_t wakeUpTime, Fps refreshRate,
986 Fps renderRate) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000987 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000988 std::scoped_lock lock(mMutex);
Pascal Muetschardac7bcd92023-10-03 15:05:36 +0200989 mCurrentDisplayFrame->onSfWakeUp(token, refreshRate, renderRate,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800990 mTokenManager.getPredictionsForToken(token), wakeUpTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700991}
992
993void FrameTimeline::setSfPresent(nsecs_t sfPresentTime,
Adithya Srinivasanb6a2fa12021-03-13 00:23:09 +0000994 const std::shared_ptr<FenceTime>& presentFence,
Adithya Srinivasan36b01af2021-04-07 22:29:47 +0000995 const std::shared_ptr<FenceTime>& gpuFence) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +0000996 SFTRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000997 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800998 mCurrentDisplayFrame->setActualEndTime(sfPresentTime);
Adithya Srinivasan36b01af2021-04-07 22:29:47 +0000999 mCurrentDisplayFrame->setGpuFence(gpuFence);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001000 mPendingPresentFences.emplace_back(std::make_pair(presentFence, mCurrentDisplayFrame));
1001 flushPendingPresentFences();
1002 finalizeCurrentDisplayFrame();
1003}
1004
Ady Abraham14beed72024-05-15 17:16:45 -07001005void FrameTimeline::onCommitNotComposited() {
Vishnu Nairbe0ad902024-06-27 23:38:43 +00001006 SFTRACE_CALL();
Ady Abraham14beed72024-05-15 17:16:45 -07001007 std::scoped_lock lock(mMutex);
1008 mCurrentDisplayFrame->onCommitNotComposited();
1009 mCurrentDisplayFrame.reset();
1010 mCurrentDisplayFrame = std::make_shared<DisplayFrame>(mTimeStats, mJankClassificationThresholds,
1011 &mTraceCookieCounter);
1012}
1013
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001014void FrameTimeline::DisplayFrame::addSurfaceFrame(std::shared_ptr<SurfaceFrame> surfaceFrame) {
1015 mSurfaceFrames.push_back(surfaceFrame);
1016}
1017
Pascal Muetschardac7bcd92023-10-03 15:05:36 +02001018void FrameTimeline::DisplayFrame::onSfWakeUp(int64_t token, Fps refreshRate, Fps renderRate,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001019 std::optional<TimelineItem> predictions,
1020 nsecs_t wakeUpTime) {
1021 mToken = token;
Alec Mouri7d436ec2021-01-27 20:40:50 -08001022 mRefreshRate = refreshRate;
Pascal Muetschardac7bcd92023-10-03 15:05:36 +02001023 mRenderRate = renderRate;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001024 if (!predictions) {
1025 mPredictionState = PredictionState::Expired;
1026 } else {
1027 mPredictionState = PredictionState::Valid;
1028 mSurfaceFlingerPredictions = *predictions;
1029 }
1030 mSurfaceFlingerActuals.startTime = wakeUpTime;
1031}
1032
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001033void FrameTimeline::DisplayFrame::setPredictions(PredictionState predictionState,
1034 TimelineItem predictions) {
1035 mPredictionState = predictionState;
1036 mSurfaceFlingerPredictions = predictions;
1037}
1038
1039void FrameTimeline::DisplayFrame::setActualStartTime(nsecs_t actualStartTime) {
1040 mSurfaceFlingerActuals.startTime = actualStartTime;
1041}
1042
1043void FrameTimeline::DisplayFrame::setActualEndTime(nsecs_t actualEndTime) {
1044 mSurfaceFlingerActuals.endTime = actualEndTime;
1045}
1046
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001047void FrameTimeline::DisplayFrame::setGpuFence(const std::shared_ptr<FenceTime>& gpuFence) {
1048 mGpuFence = gpuFence;
Adithya Srinivasanb6a2fa12021-03-13 00:23:09 +00001049}
1050
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001051void FrameTimeline::DisplayFrame::classifyJank(nsecs_t& deadlineDelta, nsecs_t& deltaToVsync,
1052 nsecs_t previousPresentTime) {
Ady Abrahamb1e10d12023-03-13 15:23:54 -07001053 const bool presentTimeValid =
1054 mSurfaceFlingerActuals.presentTime >= mSurfaceFlingerActuals.startTime;
1055 if (mPredictionState == PredictionState::Expired || !presentTimeValid) {
Adithya Srinivasande272452021-04-10 00:21:00 +00001056 // Cannot do jank classification with expired predictions or invalid signal times. Set the
1057 // deltas to 0 as both negative and positive deltas are used as real values.
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001058 mJankType = JankType::Unknown;
Ying Wei96eb5352023-11-21 17:37:21 +00001059 mJankSeverityType = JankSeverityType::Unknown;
Adithya Srinivasande272452021-04-10 00:21:00 +00001060 deadlineDelta = 0;
1061 deltaToVsync = 0;
Ady Abrahamb1e10d12023-03-13 15:23:54 -07001062 if (!presentTimeValid) {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001063 mSurfaceFlingerActuals.presentTime = mSurfaceFlingerActuals.endTime;
Ady Abrahamb1e10d12023-03-13 15:23:54 -07001064 mJankType |= JankType::DisplayHAL;
Ady Abrahamfcb16862022-10-10 14:35:21 -07001065 }
1066
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001067 return;
1068 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001069
1070 // Delta between the expected present and the actual present
1071 const nsecs_t presentDelta =
1072 mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime;
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001073 // Sf actual end time represents the CPU end time. In case of HWC, SF's end time would have
1074 // included the time for composition. However, for GPU composition, the final end time is max(sf
1075 // end time, gpu fence time).
1076 nsecs_t combinedEndTime = mSurfaceFlingerActuals.endTime;
1077 if (mGpuFence != FenceTime::NO_FENCE) {
1078 combinedEndTime = std::max(combinedEndTime, mGpuFence->getSignalTime());
1079 }
1080 deadlineDelta = combinedEndTime - mSurfaceFlingerPredictions.endTime;
Alec Mouri363faf02021-01-29 16:34:55 -08001081
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001082 // How far off was the presentDelta when compared to the vsyncPeriod. Used in checking if there
1083 // was a prediction error or not.
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001084 deltaToVsync = mRefreshRate.getPeriodNsecs() > 0
Alec Mouriadebf5c2021-01-05 12:57:36 -08001085 ? std::abs(presentDelta) % mRefreshRate.getPeriodNsecs()
1086 : 0;
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001087
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001088 if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) {
1089 mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent
1090 : FramePresentMetadata::EarlyPresent;
Ying Wei96eb5352023-11-21 17:37:21 +00001091 // Jank that is missing by less than the render rate period is classified as partial jank,
1092 // otherwise it is a full jank.
1093 mJankSeverityType = std::abs(presentDelta) < mRenderRate.getPeriodNsecs()
1094 ? JankSeverityType::Partial
1095 : JankSeverityType::Full;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001096 } else {
1097 mFramePresentMetadata = FramePresentMetadata::OnTimePresent;
1098 }
1099
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001100 if (combinedEndTime > mSurfaceFlingerPredictions.endTime) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001101 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
1102 } else {
1103 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
1104 }
1105
1106 if (std::abs(mSurfaceFlingerActuals.startTime - mSurfaceFlingerPredictions.startTime) >
1107 mJankClassificationThresholds.startThreshold) {
1108 mFrameStartMetadata =
1109 mSurfaceFlingerActuals.startTime > mSurfaceFlingerPredictions.startTime
1110 ? FrameStartMetadata::LateStart
1111 : FrameStartMetadata::EarlyStart;
1112 }
1113
1114 if (mFramePresentMetadata != FramePresentMetadata::OnTimePresent) {
1115 // Do jank classification only if present is not on time
1116 if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) {
1117 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
1118 // Finish on time, Present early
1119 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -08001120 deltaToVsync >= (mRefreshRate.getPeriodNsecs() -
1121 mJankClassificationThresholds.presentThreshold)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001122 // Delta is a factor of vsync if its within the presentTheshold on either side
1123 // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold
1124 // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms.
1125 mJankType = JankType::SurfaceFlingerScheduling;
1126 } else {
1127 // Delta is not a factor of vsync,
1128 mJankType = JankType::PredictionError;
1129 }
1130 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
1131 // Finish late, Present early
1132 mJankType = JankType::SurfaceFlingerScheduling;
1133 } else {
1134 // Finish time unknown
1135 mJankType = JankType::Unknown;
1136 }
1137 } else if (mFramePresentMetadata == FramePresentMetadata::LatePresent) {
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001138 if (std::abs(mSurfaceFlingerPredictions.presentTime - previousPresentTime) <=
1139 mJankClassificationThresholds.presentThreshold ||
1140 previousPresentTime > mSurfaceFlingerPredictions.presentTime) {
1141 // The previous frame was either presented in the current frame's expected vsync or
1142 // it was presented even later than the current frame's expected vsync.
1143 mJankType = JankType::SurfaceFlingerStuffing;
1144 }
1145 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish &&
1146 !(mJankType & JankType::SurfaceFlingerStuffing)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001147 // Finish on time, Present late
1148 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -08001149 deltaToVsync >= (mRefreshRate.getPeriodNsecs() -
1150 mJankClassificationThresholds.presentThreshold)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001151 // Delta is a factor of vsync if its within the presentTheshold on either side
1152 // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold
1153 // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms.
1154 mJankType = JankType::DisplayHAL;
1155 } else {
1156 // Delta is not a factor of vsync
1157 mJankType = JankType::PredictionError;
1158 }
1159 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001160 if (!(mJankType & JankType::SurfaceFlingerStuffing) ||
1161 mSurfaceFlingerActuals.presentTime - previousPresentTime >
1162 mRefreshRate.getPeriodNsecs() +
1163 mJankClassificationThresholds.presentThreshold) {
1164 // Classify CPU vs GPU if SF wasn't stuffed or if SF was stuffed but this frame
1165 // was presented more than a vsync late.
Rachel Lee94917b32022-03-18 17:52:09 -07001166 if (mGpuFence != FenceTime::NO_FENCE) {
1167 // If SF was in GPU composition, classify it as GPU deadline missed.
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001168 mJankType = JankType::SurfaceFlingerGpuDeadlineMissed;
1169 } else {
1170 mJankType = JankType::SurfaceFlingerCpuDeadlineMissed;
1171 }
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +00001172 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001173 } else {
1174 // Finish time unknown
1175 mJankType = JankType::Unknown;
1176 }
1177 } else {
1178 // Present unknown
1179 mJankType = JankType::Unknown;
1180 }
1181 }
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001182}
1183
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001184void FrameTimeline::DisplayFrame::onPresent(nsecs_t signalTime, nsecs_t previousPresentTime) {
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001185 mSurfaceFlingerActuals.presentTime = signalTime;
1186 nsecs_t deadlineDelta = 0;
1187 nsecs_t deltaToVsync = 0;
Adithya Srinivasan57dc81d2021-04-14 17:31:41 +00001188 classifyJank(deadlineDelta, deltaToVsync, previousPresentTime);
Adithya Srinivasan115ac692021-03-06 01:21:30 +00001189
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001190 for (auto& surfaceFrame : mSurfaceFrames) {
Pascal Muetschardac7bcd92023-10-03 15:05:36 +02001191 surfaceFrame->onPresent(signalTime, mJankType, mRefreshRate, mRenderRate, deadlineDelta,
1192 deltaToVsync);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001193 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001194}
1195
Ady Abraham14beed72024-05-15 17:16:45 -07001196void FrameTimeline::DisplayFrame::onCommitNotComposited() {
1197 for (auto& surfaceFrame : mSurfaceFrames) {
1198 surfaceFrame->onCommitNotComposited(mRefreshRate, mRenderRate);
1199 }
1200}
1201
Ady Abraham43a68c32024-09-04 19:21:20 -07001202void FrameTimeline::DisplayFrame::tracePredictions(pid_t surfaceFlingerPid, nsecs_t monoBootOffset,
1203 bool filterFramesBeforeTraceStarts) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001204 int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Ady Abraham43a68c32024-09-04 19:21:20 -07001205 bool traced = false;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001206
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001207 // Expected timeline start
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001208 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Ady Abraham43a68c32024-09-04 19:21:20 -07001209 const auto timestamp = mSurfaceFlingerPredictions.startTime;
1210 if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) {
1211 // Do not trace packets started before tracing starts.
1212 return;
1213 }
1214 traced = true;
1215
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001216 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -08001217 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
Ady Abraham43a68c32024-09-04 19:21:20 -07001218 packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001219
1220 auto* event = packet->set_frame_timeline_event();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001221 auto* expectedDisplayFrameStartEvent = event->set_expected_display_frame_start();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001222
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001223 expectedDisplayFrameStartEvent->set_cookie(expectedTimelineCookie);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001224
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001225 expectedDisplayFrameStartEvent->set_token(mToken);
1226 expectedDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
1227 });
Adithya Srinivasan86678502021-01-19 21:50:38 +00001228
Ady Abraham43a68c32024-09-04 19:21:20 -07001229 if (traced) {
1230 // Expected timeline end
1231 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
1232 auto packet = ctx.NewTracePacket();
1233 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1234 packet->set_timestamp(
1235 static_cast<uint64_t>(mSurfaceFlingerPredictions.endTime + monoBootOffset));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001236
Ady Abraham43a68c32024-09-04 19:21:20 -07001237 auto* event = packet->set_frame_timeline_event();
1238 auto* expectedDisplayFrameEndEvent = event->set_frame_end();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001239
Ady Abraham43a68c32024-09-04 19:21:20 -07001240 expectedDisplayFrameEndEvent->set_cookie(expectedTimelineCookie);
1241 });
1242 }
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001243}
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001244
Sally Qiaa107742023-09-29 14:53:14 -07001245void FrameTimeline::DisplayFrame::addSkippedFrame(pid_t surfaceFlingerPid, nsecs_t monoBootOffset,
Ady Abraham43a68c32024-09-04 19:21:20 -07001246 nsecs_t previousPredictionPresentTime,
1247 bool filterFramesBeforeTraceStarts) const {
Sally Qiaa107742023-09-29 14:53:14 -07001248 nsecs_t skippedFrameStartTime = 0, skippedFramePresentTime = 0;
1249 const constexpr float kThresh = 0.5f;
1250 const constexpr float kRange = 1.5f;
1251 for (auto& surfaceFrame : mSurfaceFrames) {
Sally Qi438eb7d2023-12-05 18:59:32 -08001252 if (previousPredictionPresentTime != 0 &&
1253 static_cast<float>(mSurfaceFlingerPredictions.presentTime -
1254 previousPredictionPresentTime) >=
Sally Qiaa107742023-09-29 14:53:14 -07001255 static_cast<float>(mRenderRate.getPeriodNsecs()) * kRange &&
1256 static_cast<float>(surfaceFrame->getPredictions().presentTime) <=
Sally Qi438eb7d2023-12-05 18:59:32 -08001257 (static_cast<float>(mSurfaceFlingerPredictions.presentTime) -
Sally Qiaa107742023-09-29 14:53:14 -07001258 kThresh * static_cast<float>(mRenderRate.getPeriodNsecs())) &&
1259 static_cast<float>(surfaceFrame->getPredictions().presentTime) >=
Sally Qi2269a692024-05-17 18:02:28 -07001260 (static_cast<float>(previousPredictionPresentTime) +
Sally Qi438eb7d2023-12-05 18:59:32 -08001261 kThresh * static_cast<float>(mRenderRate.getPeriodNsecs())) &&
1262 // sf skipped frame is not considered if app is self janked
Sally Qi093477c2024-09-11 00:58:22 +00001263 surfaceFrame->getJankType() != JankType::None && !surfaceFrame->isSelfJanky()) {
Sally Qiaa107742023-09-29 14:53:14 -07001264 skippedFrameStartTime = surfaceFrame->getPredictions().endTime;
1265 skippedFramePresentTime = surfaceFrame->getPredictions().presentTime;
1266 break;
1267 }
1268 }
1269
1270 // add slice
1271 if (skippedFrameStartTime != 0 && skippedFramePresentTime != 0) {
1272 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Ady Abraham43a68c32024-09-04 19:21:20 -07001273 bool traced = false;
Sally Qiaa107742023-09-29 14:53:14 -07001274
1275 // Actual timeline start
1276 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Ady Abraham43a68c32024-09-04 19:21:20 -07001277 if (filterFramesBeforeTraceStarts &&
1278 !shouldTraceForDataSource(ctx, skippedFrameStartTime)) {
1279 // Do not trace packets started before tracing starts.
1280 return;
1281 }
1282 traced = true;
1283
Sally Qiaa107742023-09-29 14:53:14 -07001284 auto packet = ctx.NewTracePacket();
1285 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1286 packet->set_timestamp(static_cast<uint64_t>(skippedFrameStartTime + monoBootOffset));
1287
1288 auto* event = packet->set_frame_timeline_event();
1289 auto* actualDisplayFrameStartEvent = event->set_actual_display_frame_start();
1290
1291 actualDisplayFrameStartEvent->set_cookie(actualTimelineCookie);
1292
1293 actualDisplayFrameStartEvent->set_token(0);
1294 actualDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
1295 actualDisplayFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
1296 FrameReadyMetadata::OnTimeFinish);
1297 actualDisplayFrameStartEvent->set_gpu_composition(false);
1298 actualDisplayFrameStartEvent->set_prediction_type(toProto(PredictionState::Valid));
1299 actualDisplayFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED);
1300 actualDisplayFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(JankType::Dropped));
Ying Wei96eb5352023-11-21 17:37:21 +00001301 actualDisplayFrameStartEvent->set_jank_severity_type(toProto(JankSeverityType::None));
Sally Qiaa107742023-09-29 14:53:14 -07001302 });
1303
Ady Abraham43a68c32024-09-04 19:21:20 -07001304 if (traced) {
1305 // Actual timeline end
1306 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
1307 auto packet = ctx.NewTracePacket();
1308 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1309 packet->set_timestamp(
1310 static_cast<uint64_t>(skippedFramePresentTime + monoBootOffset));
Sally Qiaa107742023-09-29 14:53:14 -07001311
Ady Abraham43a68c32024-09-04 19:21:20 -07001312 auto* event = packet->set_frame_timeline_event();
1313 auto* actualDisplayFrameEndEvent = event->set_frame_end();
Sally Qiaa107742023-09-29 14:53:14 -07001314
Ady Abraham43a68c32024-09-04 19:21:20 -07001315 actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie);
1316 });
1317 }
Sally Qiaa107742023-09-29 14:53:14 -07001318 }
1319}
1320
Ady Abraham43a68c32024-09-04 19:21:20 -07001321void FrameTimeline::DisplayFrame::traceActuals(pid_t surfaceFlingerPid, nsecs_t monoBootOffset,
1322 bool filterFramesBeforeTraceStarts) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001323 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Ady Abraham43a68c32024-09-04 19:21:20 -07001324 bool traced = false;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001325
1326 // Actual timeline start
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001327 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Ady Abraham43a68c32024-09-04 19:21:20 -07001328 const auto timestamp = mSurfaceFlingerActuals.startTime;
1329 if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) {
1330 // Do not trace packets started before tracing starts.
1331 return;
1332 }
1333 traced = true;
1334
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001335 auto packet = ctx.NewTracePacket();
Ady Abraham57f8e182022-03-08 15:54:33 -08001336 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
Ady Abraham43a68c32024-09-04 19:21:20 -07001337 packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001338
1339 auto* event = packet->set_frame_timeline_event();
1340 auto* actualDisplayFrameStartEvent = event->set_actual_display_frame_start();
1341
1342 actualDisplayFrameStartEvent->set_cookie(actualTimelineCookie);
1343
1344 actualDisplayFrameStartEvent->set_token(mToken);
1345 actualDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
1346
1347 actualDisplayFrameStartEvent->set_present_type(toProto(mFramePresentMetadata));
1348 actualDisplayFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
1349 FrameReadyMetadata::OnTimeFinish);
Adithya Srinivasan36b01af2021-04-07 22:29:47 +00001350 actualDisplayFrameStartEvent->set_gpu_composition(mGpuFence != FenceTime::NO_FENCE);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001351 actualDisplayFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType));
Adithya Srinivasan78e58af2021-02-25 00:08:08 +00001352 actualDisplayFrameStartEvent->set_prediction_type(toProto(mPredictionState));
Ying Wei96eb5352023-11-21 17:37:21 +00001353 actualDisplayFrameStartEvent->set_jank_severity_type(toProto(mJankSeverityType));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001354 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001355
Ady Abraham43a68c32024-09-04 19:21:20 -07001356 if (traced) {
1357 // Actual timeline end
1358 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
1359 auto packet = ctx.NewTracePacket();
1360 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
1361 packet->set_timestamp(
1362 static_cast<uint64_t>(mSurfaceFlingerActuals.presentTime + monoBootOffset));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001363
Ady Abraham43a68c32024-09-04 19:21:20 -07001364 auto* event = packet->set_frame_timeline_event();
1365 auto* actualDisplayFrameEndEvent = event->set_frame_end();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001366
Ady Abraham43a68c32024-09-04 19:21:20 -07001367 actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie);
1368 });
1369 }
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001370}
1371
Sally Qi438eb7d2023-12-05 18:59:32 -08001372nsecs_t FrameTimeline::DisplayFrame::trace(pid_t surfaceFlingerPid, nsecs_t monoBootOffset,
Ady Abraham43a68c32024-09-04 19:21:20 -07001373 nsecs_t previousPredictionPresentTime,
1374 bool filterFramesBeforeTraceStarts) const {
Ady Abraham57a8ab42023-01-26 15:28:19 -08001375 if (mSurfaceFrames.empty()) {
1376 // We don't want to trace display frames without any surface frames updates as this cannot
1377 // be janky
Sally Qi438eb7d2023-12-05 18:59:32 -08001378 return previousPredictionPresentTime;
Ady Abraham57a8ab42023-01-26 15:28:19 -08001379 }
1380
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001381 if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
1382 // DisplayFrame should not have an invalid token.
1383 ALOGE("Cannot trace DisplayFrame with invalid token");
Sally Qi438eb7d2023-12-05 18:59:32 -08001384 return previousPredictionPresentTime;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001385 }
1386
1387 if (mPredictionState == PredictionState::Valid) {
1388 // Expired and unknown predictions have zeroed timestamps. This cannot be used in any
1389 // meaningful way in a trace.
Ady Abraham43a68c32024-09-04 19:21:20 -07001390 tracePredictions(surfaceFlingerPid, monoBootOffset, filterFramesBeforeTraceStarts);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +00001391 }
Ady Abraham43a68c32024-09-04 19:21:20 -07001392 traceActuals(surfaceFlingerPid, monoBootOffset, filterFramesBeforeTraceStarts);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001393
1394 for (auto& surfaceFrame : mSurfaceFrames) {
Ady Abraham43a68c32024-09-04 19:21:20 -07001395 surfaceFrame->trace(mToken, monoBootOffset, filterFramesBeforeTraceStarts);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001396 }
Sally Qiaa107742023-09-29 14:53:14 -07001397
Sally Qif5721252023-11-17 11:14:53 -08001398 if (FlagManager::getInstance().add_sf_skipped_frames_to_trace()) {
Ady Abraham43a68c32024-09-04 19:21:20 -07001399 addSkippedFrame(surfaceFlingerPid, monoBootOffset, previousPredictionPresentTime,
1400 filterFramesBeforeTraceStarts);
Sally Qif5721252023-11-17 11:14:53 -08001401 }
Sally Qi438eb7d2023-12-05 18:59:32 -08001402 return mSurfaceFlingerPredictions.presentTime;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001403}
1404
Alec Mouriadebf5c2021-01-05 12:57:36 -08001405float FrameTimeline::computeFps(const std::unordered_set<int32_t>& layerIds) {
1406 if (layerIds.empty()) {
1407 return 0.0f;
1408 }
1409
1410 std::vector<nsecs_t> presentTimes;
1411 {
1412 std::scoped_lock lock(mMutex);
1413 presentTimes.reserve(mDisplayFrames.size());
1414 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
1415 const auto& displayFrame = mDisplayFrames[i];
1416 if (displayFrame->getActuals().presentTime <= 0) {
1417 continue;
1418 }
1419 for (const auto& surfaceFrame : displayFrame->getSurfaceFrames()) {
1420 if (surfaceFrame->getPresentState() == SurfaceFrame::PresentState::Presented &&
1421 layerIds.count(surfaceFrame->getLayerId()) > 0) {
1422 // We're looking for DisplayFrames that presents at least one layer from
1423 // layerIds, so push the present time and skip looking through the rest of the
1424 // SurfaceFrames.
1425 presentTimes.push_back(displayFrame->getActuals().presentTime);
1426 break;
1427 }
1428 }
1429 }
1430 }
1431
1432 // FPS can't be computed when there's fewer than 2 presented frames.
1433 if (presentTimes.size() <= 1) {
1434 return 0.0f;
1435 }
1436
1437 nsecs_t priorPresentTime = -1;
1438 nsecs_t totalPresentToPresentWalls = 0;
1439
1440 for (const nsecs_t presentTime : presentTimes) {
1441 if (priorPresentTime == -1) {
1442 priorPresentTime = presentTime;
1443 continue;
1444 }
1445
1446 totalPresentToPresentWalls += (presentTime - priorPresentTime);
1447 priorPresentTime = presentTime;
1448 }
1449
1450 if (CC_UNLIKELY(totalPresentToPresentWalls <= 0)) {
1451 ALOGW("Invalid total present-to-present duration when computing fps: %" PRId64,
1452 totalPresentToPresentWalls);
1453 return 0.0f;
1454 }
1455
1456 const constexpr nsecs_t kOneSecond =
1457 std::chrono::duration_cast<std::chrono::nanoseconds>(1s).count();
1458 // (10^9 nanoseconds / second) * (N present deltas) / (total nanoseconds in N present deltas) =
1459 // M frames / second
1460 return kOneSecond * static_cast<nsecs_t>((presentTimes.size() - 1)) /
1461 static_cast<float>(totalPresentToPresentWalls);
1462}
1463
Ben Widawskyebdbead2024-10-24 11:47:50 -07001464void FrameTimeline::generateFrameStats(int32_t layer, size_t count, FrameStats* outStats) const {
1465 std::scoped_lock lock(mMutex);
1466
1467 // TODO: Include FPS calculation here
1468 for (auto displayFrame : mDisplayFrames) {
1469 if (!count--) {
1470 break;
1471 }
1472
1473 if (displayFrame->getActuals().presentTime <= 0) {
1474 continue;
1475 }
1476
1477 for (const auto& surfaceFrame : displayFrame->getSurfaceFrames()) {
1478 if (surfaceFrame->getLayerId() == layer) {
1479 outStats->actualPresentTimesNano.push_back(surfaceFrame->getActuals().presentTime);
1480 outStats->desiredPresentTimesNano.push_back(
1481 surfaceFrame->getActuals().desiredPresentTime);
1482 outStats->frameReadyTimesNano.push_back(surfaceFrame->getActuals().endTime);
1483 }
1484 }
1485 }
1486}
1487
Ady Abrahamfcb16862022-10-10 14:35:21 -07001488std::optional<size_t> FrameTimeline::getFirstSignalFenceIndex() const {
1489 for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
1490 const auto& [fence, _] = mPendingPresentFences[i];
Theodore Dubois205c6dd2022-11-23 15:06:33 -08001491 if (fence && fence->getSignalTime() != Fence::SIGNAL_TIME_PENDING) {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001492 return i;
1493 }
1494 }
1495
1496 return {};
1497}
1498
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001499void FrameTimeline::flushPendingPresentFences() {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001500 const auto firstSignaledFence = getFirstSignalFenceIndex();
1501 if (!firstSignaledFence.has_value()) {
1502 return;
1503 }
1504
Ady Abraham57f8e182022-03-08 15:54:33 -08001505 // Perfetto is using boottime clock to void drifts when the device goes
1506 // to suspend.
1507 const auto monoBootOffset = mUseBootTimeClock
1508 ? (systemTime(SYSTEM_TIME_BOOTTIME) - systemTime(SYSTEM_TIME_MONOTONIC))
1509 : 0;
1510
Ady Abrahamfcb16862022-10-10 14:35:21 -07001511 // Present fences are expected to be signaled in order. Mark all the previous
1512 // pending fences as errors.
1513 for (size_t i = 0; i < firstSignaledFence.value(); i++) {
1514 const auto& pendingPresentFence = *mPendingPresentFences.begin();
1515 const nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
1516 auto& displayFrame = pendingPresentFence.second;
Sally Qi438eb7d2023-12-05 18:59:32 -08001517 displayFrame->onPresent(signalTime, mPreviousActualPresentTime);
Ady Abraham43a68c32024-09-04 19:21:20 -07001518 mPreviousPredictionPresentTime =
1519 displayFrame->trace(mSurfaceFlingerPid, monoBootOffset,
1520 mPreviousPredictionPresentTime, mFilterFramesBeforeTraceStarts);
Ady Abrahamfcb16862022-10-10 14:35:21 -07001521 mPendingPresentFences.erase(mPendingPresentFences.begin());
1522 }
1523
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001524 for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
1525 const auto& pendingPresentFence = mPendingPresentFences[i];
1526 nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
1527 if (pendingPresentFence.first && pendingPresentFence.first->isValid()) {
1528 signalTime = pendingPresentFence.first->getSignalTime();
1529 if (signalTime == Fence::SIGNAL_TIME_PENDING) {
Ady Abrahamfcb16862022-10-10 14:35:21 -07001530 break;
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001531 }
1532 }
Ady Abrahamfcb16862022-10-10 14:35:21 -07001533
Adithya Srinivasan7c4ac7a2021-03-08 23:48:03 +00001534 auto& displayFrame = pendingPresentFence.second;
Sally Qi438eb7d2023-12-05 18:59:32 -08001535 displayFrame->onPresent(signalTime, mPreviousActualPresentTime);
Ady Abraham43a68c32024-09-04 19:21:20 -07001536 mPreviousPredictionPresentTime =
1537 displayFrame->trace(mSurfaceFlingerPid, monoBootOffset,
1538 mPreviousPredictionPresentTime, mFilterFramesBeforeTraceStarts);
Sally Qi438eb7d2023-12-05 18:59:32 -08001539 mPreviousActualPresentTime = signalTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001540
1541 mPendingPresentFences.erase(mPendingPresentFences.begin() + static_cast<int>(i));
1542 --i;
1543 }
1544}
1545
1546void FrameTimeline::finalizeCurrentDisplayFrame() {
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001547 while (mDisplayFrames.size() >= mMaxDisplayFrames) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001548 // We maintain only a fixed number of frames' data. Pop older frames
1549 mDisplayFrames.pop_front();
1550 }
1551 mDisplayFrames.push_back(mCurrentDisplayFrame);
1552 mCurrentDisplayFrame.reset();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001553 mCurrentDisplayFrame = std::make_shared<DisplayFrame>(mTimeStats, mJankClassificationThresholds,
Adithya Srinivasan82eef322021-04-10 00:06:04 +00001554 &mTraceCookieCounter);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001555}
1556
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001557nsecs_t FrameTimeline::DisplayFrame::getBaseTime() const {
1558 nsecs_t baseTime =
1559 getMinTime(mPredictionState, mSurfaceFlingerPredictions, mSurfaceFlingerActuals);
1560 for (const auto& surfaceFrame : mSurfaceFrames) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001561 nsecs_t surfaceFrameBaseTime = surfaceFrame->getBaseTime();
1562 if (surfaceFrameBaseTime != 0) {
1563 baseTime = std::min(baseTime, surfaceFrameBaseTime);
1564 }
1565 }
1566 return baseTime;
1567}
1568
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001569void FrameTimeline::DisplayFrame::dumpJank(std::string& result, nsecs_t baseTime,
1570 int displayFrameCount) const {
1571 if (mJankType == JankType::None) {
1572 // Check if any Surface Frame has been janky
1573 bool isJanky = false;
1574 for (const auto& surfaceFrame : mSurfaceFrames) {
1575 if (surfaceFrame->getJankType() != JankType::None) {
1576 isJanky = true;
1577 break;
1578 }
1579 }
1580 if (!isJanky) {
1581 return;
1582 }
1583 }
1584 StringAppendF(&result, "Display Frame %d", displayFrameCount);
1585 dump(result, baseTime);
1586}
1587
1588void FrameTimeline::DisplayFrame::dumpAll(std::string& result, nsecs_t baseTime) const {
1589 dump(result, baseTime);
1590}
1591
1592void FrameTimeline::DisplayFrame::dump(std::string& result, nsecs_t baseTime) const {
1593 if (mJankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001594 // Easily identify a janky Display Frame in the dump
1595 StringAppendF(&result, " [*] ");
1596 }
1597 StringAppendF(&result, "\n");
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001598 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
1599 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
1600 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
1601 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
1602 StringAppendF(&result, "Start Metadata: %s\n", toString(mFrameStartMetadata).c_str());
Alec Mouri7d436ec2021-01-27 20:40:50 -08001603 std::chrono::nanoseconds vsyncPeriod(mRefreshRate.getPeriodNsecs());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001604 StringAppendF(&result, "Vsync Period: %10f\n",
1605 std::chrono::duration<double, std::milli>(vsyncPeriod).count());
1606 nsecs_t presentDelta =
1607 mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime;
1608 std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta));
1609 StringAppendF(&result, "Present delta: %10f\n",
1610 std::chrono::duration<double, std::milli>(presentDeltaNs).count());
Alec Mouri7d436ec2021-01-27 20:40:50 -08001611 std::chrono::nanoseconds deltaToVsync(std::abs(presentDelta) % mRefreshRate.getPeriodNsecs());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001612 StringAppendF(&result, "Present delta %% refreshrate: %10f\n",
1613 std::chrono::duration<double, std::milli>(deltaToVsync).count());
1614 dumpTable(result, mSurfaceFlingerPredictions, mSurfaceFlingerActuals, "", mPredictionState,
1615 baseTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001616 StringAppendF(&result, "\n");
1617 std::string indent = " "; // 4 spaces
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001618 for (const auto& surfaceFrame : mSurfaceFrames) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001619 surfaceFrame->dump(result, indent, baseTime);
1620 }
1621 StringAppendF(&result, "\n");
1622}
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001623
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001624void FrameTimeline::dumpAll(std::string& result) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001625 std::scoped_lock lock(mMutex);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001626 StringAppendF(&result, "Number of display frames : %d\n", (int)mDisplayFrames.size());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001627 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001628 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
1629 StringAppendF(&result, "Display Frame %d", static_cast<int>(i));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001630 mDisplayFrames[i]->dumpAll(result, baseTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001631 }
1632}
1633
1634void FrameTimeline::dumpJank(std::string& result) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001635 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001636 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001637 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001638 mDisplayFrames[i]->dumpJank(result, baseTime, static_cast<int>(i));
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001639 }
1640}
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001641
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001642void FrameTimeline::parseArgs(const Vector<String16>& args, std::string& result) {
Vishnu Nairbe0ad902024-06-27 23:38:43 +00001643 SFTRACE_CALL();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001644 std::unordered_map<std::string, bool> argsMap;
1645 for (size_t i = 0; i < args.size(); i++) {
1646 argsMap[std::string(String8(args[i]).c_str())] = true;
1647 }
1648 if (argsMap.count("-jank")) {
1649 dumpJank(result);
1650 }
1651 if (argsMap.count("-all")) {
1652 dumpAll(result);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001653 }
1654}
1655
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001656void FrameTimeline::setMaxDisplayFrames(uint32_t size) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001657 std::scoped_lock lock(mMutex);
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001658
1659 // The size can either increase or decrease, clear everything, to be consistent
1660 mDisplayFrames.clear();
1661 mPendingPresentFences.clear();
1662 mMaxDisplayFrames = size;
1663}
1664
1665void FrameTimeline::reset() {
1666 setMaxDisplayFrames(kDefaultMaxDisplayFrames);
1667}
1668
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001669} // namespace impl
1670} // namespace android::frametimeline