blob: 03e38f30de87829523cc1fe081203ad893fd2c00 [file] [log] [blame]
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001/*
2 * Copyright 2020 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17#undef LOG_TAG
18#define LOG_TAG "FrameTimeline"
19#define ATRACE_TAG ATRACE_TAG_GRAPHICS
20
21#include "FrameTimeline.h"
Alec Mouriadebf5c2021-01-05 12:57:36 -080022
Adithya Srinivasanf279e042020-08-17 14:56:27 -070023#include <android-base/stringprintf.h>
Ady Abraham7f8a1e62020-09-28 16:09:35 -070024#include <utils/Log.h>
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -070025#include <utils/Trace.h>
Alec Mouriadebf5c2021-01-05 12:57:36 -080026
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070027#include <chrono>
Adithya Srinivasanf279e042020-08-17 14:56:27 -070028#include <cinttypes>
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070029#include <numeric>
Alec Mouriadebf5c2021-01-05 12:57:36 -080030#include <unordered_set>
Adithya Srinivasanf279e042020-08-17 14:56:27 -070031
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080032namespace android::frametimeline {
Adithya Srinivasanf279e042020-08-17 14:56:27 -070033
34using base::StringAppendF;
Adithya Srinivasan01189672020-10-20 14:23:05 -070035using FrameTimelineEvent = perfetto::protos::pbzero::FrameTimelineEvent;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +000036using FrameTimelineDataSource = impl::FrameTimeline::FrameTimelineDataSource;
Adithya Srinivasanf279e042020-08-17 14:56:27 -070037
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070038void dumpTable(std::string& result, TimelineItem predictions, TimelineItem actuals,
39 const std::string& indent, PredictionState predictionState, nsecs_t baseTime) {
40 StringAppendF(&result, "%s", indent.c_str());
41 StringAppendF(&result, "\t\t");
42 StringAppendF(&result, " Start time\t\t|");
43 StringAppendF(&result, " End time\t\t|");
44 StringAppendF(&result, " Present time\n");
45 if (predictionState == PredictionState::Valid) {
46 // Dump the Predictions only if they are valid
47 StringAppendF(&result, "%s", indent.c_str());
48 StringAppendF(&result, "Expected\t|");
49 std::chrono::nanoseconds startTime(predictions.startTime - baseTime);
50 std::chrono::nanoseconds endTime(predictions.endTime - baseTime);
51 std::chrono::nanoseconds presentTime(predictions.presentTime - baseTime);
52 StringAppendF(&result, "\t%10.2f\t|\t%10.2f\t|\t%10.2f\n",
53 std::chrono::duration<double, std::milli>(startTime).count(),
54 std::chrono::duration<double, std::milli>(endTime).count(),
55 std::chrono::duration<double, std::milli>(presentTime).count());
56 }
57 StringAppendF(&result, "%s", indent.c_str());
58 StringAppendF(&result, "Actual \t|");
59
60 if (actuals.startTime == 0) {
61 StringAppendF(&result, "\t\tN/A\t|");
62 } else {
63 std::chrono::nanoseconds startTime(std::max<nsecs_t>(0, actuals.startTime - baseTime));
64 StringAppendF(&result, "\t%10.2f\t|",
65 std::chrono::duration<double, std::milli>(startTime).count());
66 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080067 if (actuals.endTime <= 0) {
68 // Animation leashes can send the endTime as -1
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070069 StringAppendF(&result, "\t\tN/A\t|");
70 } else {
71 std::chrono::nanoseconds endTime(actuals.endTime - baseTime);
72 StringAppendF(&result, "\t%10.2f\t|",
73 std::chrono::duration<double, std::milli>(endTime).count());
74 }
75 if (actuals.presentTime == 0) {
76 StringAppendF(&result, "\t\tN/A\n");
77 } else {
78 std::chrono::nanoseconds presentTime(std::max<nsecs_t>(0, actuals.presentTime - baseTime));
79 StringAppendF(&result, "\t%10.2f\n",
80 std::chrono::duration<double, std::milli>(presentTime).count());
81 }
82
83 StringAppendF(&result, "%s", indent.c_str());
84 StringAppendF(&result, "----------------------");
85 StringAppendF(&result, "----------------------");
86 StringAppendF(&result, "----------------------");
87 StringAppendF(&result, "----------------------\n");
88}
89
90std::string toString(PredictionState predictionState) {
91 switch (predictionState) {
92 case PredictionState::Valid:
93 return "Valid";
94 case PredictionState::Expired:
95 return "Expired";
96 case PredictionState::None:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070097 return "None";
98 }
99}
100
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800101std::string jankTypeBitmaskToString(int32_t jankType) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800102 if (jankType == JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700103 return "None";
104 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000105
106 std::vector<std::string> janks;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800107 if (jankType & JankType::DisplayHAL) {
108 janks.emplace_back("Display HAL");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000109 jankType &= ~JankType::DisplayHAL;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800110 }
111 if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) {
112 janks.emplace_back("SurfaceFlinger CPU Deadline Missed");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000113 jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800114 }
115 if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) {
116 janks.emplace_back("SurfaceFlinger GPU Deadline Missed");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000117 jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800118 }
119 if (jankType & JankType::AppDeadlineMissed) {
120 janks.emplace_back("App Deadline Missed");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000121 jankType &= ~JankType::AppDeadlineMissed;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800122 }
123 if (jankType & JankType::PredictionError) {
124 janks.emplace_back("Prediction Error");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000125 jankType &= ~JankType::PredictionError;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800126 }
127 if (jankType & JankType::SurfaceFlingerScheduling) {
128 janks.emplace_back("SurfaceFlinger Scheduling");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000129 jankType &= ~JankType::SurfaceFlingerScheduling;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800130 }
131 if (jankType & JankType::BufferStuffing) {
132 janks.emplace_back("Buffer Stuffing");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000133 jankType &= ~JankType::BufferStuffing;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800134 }
135 if (jankType & JankType::Unknown) {
136 janks.emplace_back("Unknown jank");
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000137 jankType &= ~JankType::Unknown;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800138 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000139
140 // jankType should be 0 if all types of jank were checked for.
141 LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800142 return std::accumulate(janks.begin(), janks.end(), std::string(),
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700143 [](const std::string& l, const std::string& r) {
144 return l.empty() ? r : l + ", " + r;
145 });
146}
147
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800148std::string toString(FramePresentMetadata presentMetadata) {
149 switch (presentMetadata) {
150 case FramePresentMetadata::OnTimePresent:
151 return "On Time Present";
152 case FramePresentMetadata::LatePresent:
153 return "Late Present";
154 case FramePresentMetadata::EarlyPresent:
155 return "Early Present";
156 case FramePresentMetadata::UnknownPresent:
157 return "Unknown Present";
Adithya Srinivasan01189672020-10-20 14:23:05 -0700158 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700159}
160
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800161std::string toString(FrameReadyMetadata finishMetadata) {
162 switch (finishMetadata) {
163 case FrameReadyMetadata::OnTimeFinish:
164 return "On Time Finish";
165 case FrameReadyMetadata::LateFinish:
166 return "Late Finish";
167 case FrameReadyMetadata::UnknownFinish:
168 return "Unknown Finish";
169 }
170}
171
172std::string toString(FrameStartMetadata startMetadata) {
173 switch (startMetadata) {
174 case FrameStartMetadata::OnTimeStart:
175 return "On Time Start";
176 case FrameStartMetadata::LateStart:
177 return "Late Start";
178 case FrameStartMetadata::EarlyStart:
179 return "Early Start";
180 case FrameStartMetadata::UnknownStart:
181 return "Unknown Start";
182 }
183}
184
185std::string toString(SurfaceFrame::PresentState presentState) {
186 using PresentState = SurfaceFrame::PresentState;
187 switch (presentState) {
188 case PresentState::Presented:
189 return "Presented";
190 case PresentState::Dropped:
191 return "Dropped";
192 case PresentState::Unknown:
193 return "Unknown";
194 }
195}
196
197FrameTimelineEvent::PresentType toProto(FramePresentMetadata presentMetadata) {
198 switch (presentMetadata) {
199 case FramePresentMetadata::EarlyPresent:
200 return FrameTimelineEvent::PRESENT_EARLY;
201 case FramePresentMetadata::LatePresent:
202 return FrameTimelineEvent::PRESENT_LATE;
203 case FramePresentMetadata::OnTimePresent:
204 return FrameTimelineEvent::PRESENT_ON_TIME;
205 case FramePresentMetadata::UnknownPresent:
206 return FrameTimelineEvent::PRESENT_UNSPECIFIED;
207 }
208}
209
Adithya Srinivasan78e58af2021-02-25 00:08:08 +0000210FrameTimelineEvent::PredictionType toProto(PredictionState predictionState) {
211 switch (predictionState) {
212 case PredictionState::Valid:
213 return FrameTimelineEvent::PREDICTION_VALID;
214 case PredictionState::Expired:
215 return FrameTimelineEvent::PREDICTION_EXPIRED;
216 case PredictionState::None:
217 return FrameTimelineEvent::PREDICTION_UNKNOWN;
218 }
219}
220
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000221int32_t jankTypeBitmaskToProto(int32_t jankType) {
222 if (jankType == JankType::None) {
223 return FrameTimelineEvent::JANK_NONE;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700224 }
Adithya Srinivasan552e2a72021-01-15 03:21:53 +0000225
226 int32_t protoJank = 0;
227 if (jankType & JankType::DisplayHAL) {
228 protoJank |= FrameTimelineEvent::JANK_DISPLAY_HAL;
229 jankType &= ~JankType::DisplayHAL;
230 }
231 if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) {
232 protoJank |= FrameTimelineEvent::JANK_SF_CPU_DEADLINE_MISSED;
233 jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed;
234 }
235 if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) {
236 protoJank |= FrameTimelineEvent::JANK_SF_GPU_DEADLINE_MISSED;
237 jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed;
238 }
239 if (jankType & JankType::AppDeadlineMissed) {
240 protoJank |= FrameTimelineEvent::JANK_APP_DEADLINE_MISSED;
241 jankType &= ~JankType::AppDeadlineMissed;
242 }
243 if (jankType & JankType::PredictionError) {
244 protoJank |= FrameTimelineEvent::JANK_PREDICTION_ERROR;
245 jankType &= ~JankType::PredictionError;
246 }
247 if (jankType & JankType::SurfaceFlingerScheduling) {
248 protoJank |= FrameTimelineEvent::JANK_SF_SCHEDULING;
249 jankType &= ~JankType::SurfaceFlingerScheduling;
250 }
251 if (jankType & JankType::BufferStuffing) {
252 protoJank |= FrameTimelineEvent::JANK_BUFFER_STUFFING;
253 jankType &= ~JankType::BufferStuffing;
254 }
255 if (jankType & JankType::Unknown) {
256 protoJank |= FrameTimelineEvent::JANK_UNKNOWN;
257 jankType &= ~JankType::Unknown;
258 }
259
260 // jankType should be 0 if all types of jank were checked for.
261 LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType);
262 return protoJank;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700263}
264
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800265// Returns the smallest timestamp from the set of predictions and actuals.
266nsecs_t getMinTime(PredictionState predictionState, TimelineItem predictions,
267 TimelineItem actuals) {
268 nsecs_t minTime = std::numeric_limits<nsecs_t>::max();
269 if (predictionState == PredictionState::Valid) {
270 // Checking start time for predictions is enough because start time is always lesser than
271 // endTime and presentTime.
272 minTime = std::min(minTime, predictions.startTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700273 }
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700274
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800275 // Need to check startTime, endTime and presentTime for actuals because some frames might not
276 // have them set.
277 if (actuals.startTime != 0) {
278 minTime = std::min(minTime, actuals.startTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700279 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800280 if (actuals.endTime != 0) {
281 minTime = std::min(minTime, actuals.endTime);
282 }
283 if (actuals.presentTime != 0) {
284 minTime = std::min(minTime, actuals.endTime);
285 }
286 return minTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700287}
288
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000289int64_t TraceCookieCounter::getCookieForTracing() {
290 return ++mTraceCookie;
291}
292
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000293SurfaceFrame::SurfaceFrame(const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid,
Alec Mouriadebf5c2021-01-05 12:57:36 -0800294 uid_t ownerUid, int32_t layerId, std::string layerName,
295 std::string debugName, PredictionState predictionState,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800296 frametimeline::TimelineItem&& predictions,
297 std::shared_ptr<TimeStats> timeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000298 JankClassificationThresholds thresholds,
299 TraceCookieCounter* traceCookieCounter)
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000300 : mToken(frameTimelineInfo.vsyncId),
301 mInputEventId(frameTimelineInfo.inputEventId),
Adithya Srinivasan01189672020-10-20 14:23:05 -0700302 mOwnerPid(ownerPid),
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700303 mOwnerUid(ownerUid),
Alec Mouri9a29e672020-09-14 12:39:14 -0700304 mLayerName(std::move(layerName)),
305 mDebugName(std::move(debugName)),
Alec Mouriadebf5c2021-01-05 12:57:36 -0800306 mLayerId(layerId),
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700307 mPresentState(PresentState::Unknown),
308 mPredictionState(predictionState),
309 mPredictions(predictions),
310 mActuals({0, 0, 0}),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800311 mTimeStats(timeStats),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000312 mJankClassificationThresholds(thresholds),
313 mTraceCookieCounter(*traceCookieCounter) {}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700314
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700315void SurfaceFrame::setActualStartTime(nsecs_t actualStartTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000316 std::scoped_lock lock(mMutex);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700317 mActuals.startTime = actualStartTime;
318}
319
320void SurfaceFrame::setActualQueueTime(nsecs_t actualQueueTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000321 std::scoped_lock lock(mMutex);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700322 mActualQueueTime = actualQueueTime;
323}
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000324
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700325void SurfaceFrame::setAcquireFenceTime(nsecs_t acquireFenceTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000326 std::scoped_lock lock(mMutex);
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700327 mActuals.endTime = std::max(acquireFenceTime, mActualQueueTime);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700328}
329
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000330void SurfaceFrame::setDropTime(nsecs_t dropTime) {
331 std::scoped_lock lock(mMutex);
332 mDropTime = dropTime;
333}
334
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800335void SurfaceFrame::setPresentState(PresentState presentState, nsecs_t lastLatchTime) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000336 std::scoped_lock lock(mMutex);
Adithya Srinivasanb9a7dab2021-01-14 23:49:46 +0000337 LOG_ALWAYS_FATAL_IF(mPresentState != PresentState::Unknown,
338 "setPresentState called on a SurfaceFrame from Layer - %s, that has a "
339 "PresentState - %s set already.",
340 mDebugName.c_str(), toString(mPresentState).c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800341 mPresentState = presentState;
342 mLastLatchTime = lastLatchTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700343}
344
Alec Mouri7d436ec2021-01-27 20:40:50 -0800345void SurfaceFrame::setRenderRate(Fps renderRate) {
346 std::lock_guard<std::mutex> lock(mMutex);
347 mRenderRate = renderRate;
348}
349
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800350std::optional<int32_t> SurfaceFrame::getJankType() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000351 std::scoped_lock lock(mMutex);
Adithya Srinivasan95619432021-02-08 21:52:51 +0000352 if (mPresentState == PresentState::Dropped) {
353 // Return no jank if it's a dropped frame since we cannot attribute a jank to a it.
354 return JankType::None;
355 }
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100356 if (mActuals.presentTime == 0) {
Adithya Srinivasan95619432021-02-08 21:52:51 +0000357 // Frame hasn't been presented yet.
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100358 return std::nullopt;
359 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700360 return mJankType;
361}
362
363nsecs_t SurfaceFrame::getBaseTime() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000364 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800365 return getMinTime(mPredictionState, mPredictions, mActuals);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700366}
367
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800368TimelineItem SurfaceFrame::getActuals() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000369 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800370 return mActuals;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700371}
372
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000373PredictionState SurfaceFrame::getPredictionState() const {
374 std::scoped_lock lock(mMutex);
375 return mPredictionState;
376}
377
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800378SurfaceFrame::PresentState SurfaceFrame::getPresentState() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000379 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800380 return mPresentState;
381}
382
383FramePresentMetadata SurfaceFrame::getFramePresentMetadata() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000384 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800385 return mFramePresentMetadata;
386}
387
388FrameReadyMetadata SurfaceFrame::getFrameReadyMetadata() const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000389 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800390 return mFrameReadyMetadata;
391}
392
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000393nsecs_t SurfaceFrame::getDropTime() const {
394 std::scoped_lock lock(mMutex);
395 return mDropTime;
396}
397
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800398void SurfaceFrame::dump(std::string& result, const std::string& indent, nsecs_t baseTime) const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000399 std::scoped_lock lock(mMutex);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700400 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri9a29e672020-09-14 12:39:14 -0700401 StringAppendF(&result, "Layer - %s", mDebugName.c_str());
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100402 if (mJankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700403 // Easily identify a janky Surface Frame in the dump
404 StringAppendF(&result, " [*] ");
405 }
406 StringAppendF(&result, "\n");
407 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800408 StringAppendF(&result, "Token: %" PRId64 "\n", mToken);
409 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700410 StringAppendF(&result, "Owner Pid : %d\n", mOwnerPid);
411 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri7d436ec2021-01-27 20:40:50 -0800412 StringAppendF(&result, "Scheduled rendering rate: %d fps\n",
413 mRenderRate ? mRenderRate->getIntValue() : 0);
414 StringAppendF(&result, "%s", indent.c_str());
Alec Mouriadebf5c2021-01-05 12:57:36 -0800415 StringAppendF(&result, "Layer ID : %d\n", mLayerId);
416 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800417 StringAppendF(&result, "Present State : %s\n", toString(mPresentState).c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700418 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000419 if (mPresentState == PresentState::Dropped) {
420 std::chrono::nanoseconds dropTime(mDropTime - baseTime);
421 StringAppendF(&result, "Drop time : %10f\n",
422 std::chrono::duration<double, std::milli>(dropTime).count());
423 StringAppendF(&result, "%s", indent.c_str());
424 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700425 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
426 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800427 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700428 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800429 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
430 StringAppendF(&result, "%s", indent.c_str());
431 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
432 std::chrono::nanoseconds latchTime(
433 std::max(static_cast<int64_t>(0), mLastLatchTime - baseTime));
434 StringAppendF(&result, "%s", indent.c_str());
435 StringAppendF(&result, "Last latch time: %10f\n",
436 std::chrono::duration<double, std::milli>(latchTime).count());
437 if (mPredictionState == PredictionState::Valid) {
438 nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime;
439 std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta));
440 StringAppendF(&result, "%s", indent.c_str());
441 StringAppendF(&result, "Present delta: %10f\n",
442 std::chrono::duration<double, std::milli>(presentDeltaNs).count());
443 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700444 dumpTable(result, mPredictions, mActuals, indent, mPredictionState, baseTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700445}
446
Alec Mouri363faf02021-01-29 16:34:55 -0800447void SurfaceFrame::onPresent(nsecs_t presentTime, int32_t displayFrameJankType, Fps refreshRate,
448 nsecs_t displayDeadlineDelta, nsecs_t displayPresentDelta) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000449 std::scoped_lock lock(mMutex);
Alec Mouri7d436ec2021-01-27 20:40:50 -0800450
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800451 if (mPresentState != PresentState::Presented) {
452 // No need to update dropped buffers
453 return;
454 }
455
456 mActuals.presentTime = presentTime;
457 // Jank Analysis for SurfaceFrame
458 if (mPredictionState == PredictionState::None) {
459 // Cannot do jank classification on frames that don't have a token.
460 return;
461 }
462 if (mPredictionState == PredictionState::Expired) {
463 // We do not know what happened here to classify this correctly. This could
464 // potentially be AppDeadlineMissed but that's assuming no app will request frames
465 // 120ms apart.
466 mJankType = JankType::Unknown;
467 mFramePresentMetadata = FramePresentMetadata::UnknownPresent;
468 mFrameReadyMetadata = FrameReadyMetadata::UnknownFinish;
Alec Mouri363faf02021-01-29 16:34:55 -0800469 const constexpr nsecs_t kAppDeadlineDelta = -1;
470 mTimeStats->incrementJankyFrames({refreshRate, mRenderRate, mOwnerUid, mLayerName,
471 mJankType, displayDeadlineDelta, displayPresentDelta,
472 kAppDeadlineDelta});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800473 return;
474 }
475
476 const nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime;
477 const nsecs_t deadlineDelta = mActuals.endTime - mPredictions.endTime;
Alec Mouriadebf5c2021-01-05 12:57:36 -0800478 const nsecs_t deltaToVsync = refreshRate.getPeriodNsecs() > 0
479 ? std::abs(presentDelta) % refreshRate.getPeriodNsecs()
480 : 0;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800481
482 if (deadlineDelta > mJankClassificationThresholds.deadlineThreshold) {
483 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
484 } else {
485 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
486 }
487
488 if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) {
489 mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent
490 : FramePresentMetadata::EarlyPresent;
491 } else {
492 mFramePresentMetadata = FramePresentMetadata::OnTimePresent;
493 }
494
495 if (mFramePresentMetadata == FramePresentMetadata::OnTimePresent) {
496 // Frames presented on time are not janky.
497 mJankType = JankType::None;
498 } else if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) {
499 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
500 // Finish on time, Present early
501 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -0800502 deltaToVsync >= refreshRate.getPeriodNsecs() -
503 mJankClassificationThresholds.presentThreshold) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800504 // Delta factor of vsync
505 mJankType = JankType::SurfaceFlingerScheduling;
506 } else {
507 // Delta not a factor of vsync
508 mJankType = JankType::PredictionError;
509 }
510 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
511 // Finish late, Present early
512 mJankType = JankType::Unknown;
513 }
514 } else {
515 if (mLastLatchTime != 0 && mPredictions.endTime <= mLastLatchTime) {
516 // Buffer Stuffing.
517 mJankType |= JankType::BufferStuffing;
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000518 // In a stuffed state, the frame could be stuck on a dequeue wait for quite some time.
519 // Because of this dequeue wait, it can be hard to tell if a frame was genuinely late.
520 // We try to do this by moving the deadline. Since the queue could be stuffed by more
521 // than one buffer, we take the last latch time as reference and give one vsync
522 // worth of time for the frame to be ready.
523 nsecs_t adjustedDeadline = mLastLatchTime + refreshRate.getPeriodNsecs();
524 if (adjustedDeadline > mActuals.endTime) {
525 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
526 } else {
527 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
528 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800529 }
530 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
531 // Finish on time, Present late
532 if (displayFrameJankType != JankType::None) {
533 // Propagate displayFrame's jank if it exists
534 mJankType |= displayFrameJankType;
535 } else {
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000536 if (!(mJankType & JankType::BufferStuffing)) {
537 // In a stuffed state, if the app finishes on time and there is no display frame
538 // jank, only buffer stuffing is the root cause of the jank.
539 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
540 deltaToVsync >= refreshRate.getPeriodNsecs() -
541 mJankClassificationThresholds.presentThreshold) {
542 // Delta factor of vsync
543 mJankType |= JankType::SurfaceFlingerScheduling;
544 } else {
545 // Delta not a factor of vsync
546 mJankType |= JankType::PredictionError;
547 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800548 }
549 }
550 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
551 // Finish late, Present late
552 if (displayFrameJankType == JankType::None) {
553 // Display frame is not janky, so purely app's fault
554 mJankType |= JankType::AppDeadlineMissed;
555 } else {
556 // Propagate DisplayFrame's jankType if it is janky
557 mJankType |= displayFrameJankType;
558 }
559 }
560 }
Alec Mouri363faf02021-01-29 16:34:55 -0800561 mTimeStats->incrementJankyFrames({refreshRate, mRenderRate, mOwnerUid, mLayerName, mJankType,
562 displayDeadlineDelta, displayPresentDelta, deadlineDelta});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800563}
564
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000565void SurfaceFrame::tracePredictions(int64_t displayFrameToken) const {
Adithya Srinivasan86678502021-01-19 21:50:38 +0000566 int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000567
Adithya Srinivasan86678502021-01-19 21:50:38 +0000568 // Expected timeline start
569 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000570 std::scoped_lock lock(mMutex);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700571 auto packet = ctx.NewTracePacket();
572 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000573 packet->set_timestamp(static_cast<uint64_t>(mPredictions.startTime));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700574
575 auto* event = packet->set_frame_timeline_event();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000576 auto* expectedSurfaceFrameStartEvent = event->set_expected_surface_frame_start();
Adithya Srinivasan01189672020-10-20 14:23:05 -0700577
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000578 expectedSurfaceFrameStartEvent->set_cookie(expectedTimelineCookie);
579
580 expectedSurfaceFrameStartEvent->set_token(mToken);
581 expectedSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken);
582
583 expectedSurfaceFrameStartEvent->set_pid(mOwnerPid);
584 expectedSurfaceFrameStartEvent->set_layer_name(mDebugName);
585 });
Adithya Srinivasan86678502021-01-19 21:50:38 +0000586
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000587 // Expected timeline end
588 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000589 std::scoped_lock lock(mMutex);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000590 auto packet = ctx.NewTracePacket();
591 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
592 packet->set_timestamp(static_cast<uint64_t>(mPredictions.endTime));
593
594 auto* event = packet->set_frame_timeline_event();
595 auto* expectedSurfaceFrameEndEvent = event->set_frame_end();
596
597 expectedSurfaceFrameEndEvent->set_cookie(expectedTimelineCookie);
598 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000599}
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000600
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000601void SurfaceFrame::traceActuals(int64_t displayFrameToken) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000602 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000603
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000604 // Actual timeline start
605 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000606 std::scoped_lock lock(mMutex);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000607 auto packet = ctx.NewTracePacket();
608 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
609 // Actual start time is not yet available, so use expected start instead
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000610 if (mPredictionState == PredictionState::Expired) {
611 // If prediction is expired, we can't use the predicted start time. Instead, just use a
612 // start time a little earlier than the end time so that we have some info about this
613 // frame in the trace.
614 packet->set_timestamp(
615 static_cast<uint64_t>(mActuals.endTime - kPredictionExpiredStartTimeDelta));
616 } else {
617 packet->set_timestamp(static_cast<uint64_t>(mPredictions.startTime));
618 }
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000619
620 auto* event = packet->set_frame_timeline_event();
621 auto* actualSurfaceFrameStartEvent = event->set_actual_surface_frame_start();
622
623 actualSurfaceFrameStartEvent->set_cookie(actualTimelineCookie);
624
625 actualSurfaceFrameStartEvent->set_token(mToken);
626 actualSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken);
627
628 actualSurfaceFrameStartEvent->set_pid(mOwnerPid);
629 actualSurfaceFrameStartEvent->set_layer_name(mDebugName);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700630
631 if (mPresentState == PresentState::Dropped) {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000632 actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700633 } else if (mPresentState == PresentState::Unknown) {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000634 actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_UNSPECIFIED);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700635 } else {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000636 actualSurfaceFrameStartEvent->set_present_type(toProto(mFramePresentMetadata));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700637 }
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000638 actualSurfaceFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
639 FrameReadyMetadata::OnTimeFinish);
640 actualSurfaceFrameStartEvent->set_gpu_composition(mGpuComposition);
641 actualSurfaceFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType));
Adithya Srinivasan78e58af2021-02-25 00:08:08 +0000642 actualSurfaceFrameStartEvent->set_prediction_type(toProto(mPredictionState));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000643 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000644
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000645 // Actual timeline end
646 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000647 std::scoped_lock lock(mMutex);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000648 auto packet = ctx.NewTracePacket();
649 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000650 if (mPresentState == PresentState::Dropped) {
651 packet->set_timestamp(static_cast<uint64_t>(mDropTime));
652 } else {
653 packet->set_timestamp(static_cast<uint64_t>(mActuals.endTime));
654 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700655
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000656 auto* event = packet->set_frame_timeline_event();
657 auto* actualSurfaceFrameEndEvent = event->set_frame_end();
Adithya Srinivasan01189672020-10-20 14:23:05 -0700658
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000659 actualSurfaceFrameEndEvent->set_cookie(actualTimelineCookie);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700660 });
661}
662
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000663/**
664 * TODO(b/178637512): add inputEventId to the perfetto trace.
665 */
666void SurfaceFrame::trace(int64_t displayFrameToken) const {
667 if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID ||
668 displayFrameToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
669 // No packets can be traced with a missing token.
670 return;
671 }
672 if (getPredictionState() != PredictionState::Expired) {
673 // Expired predictions have zeroed timestamps. This cannot be used in any meaningful way in
674 // a trace.
675 tracePredictions(displayFrameToken);
676 }
677 traceActuals(displayFrameToken);
678}
679
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800680namespace impl {
681
682int64_t TokenManager::generateTokenForPredictions(TimelineItem&& predictions) {
683 ATRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000684 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800685 const int64_t assignedToken = mCurrentToken++;
686 mPredictions[assignedToken] = {systemTime(), predictions};
687 flushTokens(systemTime());
688 return assignedToken;
689}
690
691std::optional<TimelineItem> TokenManager::getPredictionsForToken(int64_t token) const {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000692 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800693 auto predictionsIterator = mPredictions.find(token);
694 if (predictionsIterator != mPredictions.end()) {
695 return predictionsIterator->second.predictions;
696 }
697 return {};
698}
699
700void TokenManager::flushTokens(nsecs_t flushTime) {
701 for (auto it = mPredictions.begin(); it != mPredictions.end();) {
702 if (flushTime - it->second.timestamp >= kMaxRetentionTime) {
703 it = mPredictions.erase(it);
704 } else {
705 // Tokens are ordered by time. If i'th token is within the retention time, then the
706 // i+1'th token will also be within retention time.
707 break;
708 }
709 }
710}
711
712FrameTimeline::FrameTimeline(std::shared_ptr<TimeStats> timeStats, pid_t surfaceFlingerPid,
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000713 JankClassificationThresholds thresholds, nsecs_t hwcDuration)
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000714 : mMaxDisplayFrames(kDefaultMaxDisplayFrames),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800715 mTimeStats(std::move(timeStats)),
716 mSurfaceFlingerPid(surfaceFlingerPid),
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000717 mJankClassificationThresholds(thresholds),
718 mHwcDuration(hwcDuration) {
719 mCurrentDisplayFrame = std::make_shared<DisplayFrame>(mTimeStats, thresholds, hwcDuration,
720 &mTraceCookieCounter);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000721}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700722
Adithya Srinivasan01189672020-10-20 14:23:05 -0700723void FrameTimeline::onBootFinished() {
724 perfetto::TracingInitArgs args;
725 args.backends = perfetto::kSystemBackend;
726 perfetto::Tracing::Initialize(args);
727 registerDataSource();
728}
729
730void FrameTimeline::registerDataSource() {
731 perfetto::DataSourceDescriptor dsd;
732 dsd.set_name(kFrameTimelineDataSource);
733 FrameTimelineDataSource::Register(dsd);
734}
735
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800736std::shared_ptr<SurfaceFrame> FrameTimeline::createSurfaceFrameForToken(
Alec Mouriadebf5c2021-01-05 12:57:36 -0800737 const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid, uid_t ownerUid, int32_t layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000738 std::string layerName, std::string debugName) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700739 ATRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000740 if (frameTimelineInfo.vsyncId == FrameTimelineInfo::INVALID_VSYNC_ID) {
Alec Mouriadebf5c2021-01-05 12:57:36 -0800741 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000742 std::move(layerName), std::move(debugName),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800743 PredictionState::None, TimelineItem(), mTimeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000744 mJankClassificationThresholds, &mTraceCookieCounter);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700745 }
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000746 std::optional<TimelineItem> predictions =
747 mTokenManager.getPredictionsForToken(frameTimelineInfo.vsyncId);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700748 if (predictions) {
Alec Mouriadebf5c2021-01-05 12:57:36 -0800749 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000750 std::move(layerName), std::move(debugName),
751 PredictionState::Valid, std::move(*predictions),
752 mTimeStats, mJankClassificationThresholds,
753 &mTraceCookieCounter);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700754 }
Alec Mouriadebf5c2021-01-05 12:57:36 -0800755 return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId,
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000756 std::move(layerName), std::move(debugName),
757 PredictionState::Expired, TimelineItem(), mTimeStats,
758 mJankClassificationThresholds, &mTraceCookieCounter);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700759}
760
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800761FrameTimeline::DisplayFrame::DisplayFrame(std::shared_ptr<TimeStats> timeStats,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000762 JankClassificationThresholds thresholds,
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000763 nsecs_t hwcDuration,
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000764 TraceCookieCounter* traceCookieCounter)
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800765 : mSurfaceFlingerPredictions(TimelineItem()),
766 mSurfaceFlingerActuals(TimelineItem()),
767 mTimeStats(timeStats),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000768 mJankClassificationThresholds(thresholds),
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000769 mHwcDuration(hwcDuration),
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000770 mTraceCookieCounter(*traceCookieCounter) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800771 mSurfaceFrames.reserve(kNumSurfaceFramesInitial);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700772}
773
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800774void FrameTimeline::addSurfaceFrame(std::shared_ptr<SurfaceFrame> surfaceFrame) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700775 ATRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000776 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800777 mCurrentDisplayFrame->addSurfaceFrame(surfaceFrame);
778}
779
Alec Mouri7d436ec2021-01-27 20:40:50 -0800780void FrameTimeline::setSfWakeUp(int64_t token, nsecs_t wakeUpTime, Fps refreshRate) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800781 ATRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000782 std::scoped_lock lock(mMutex);
Alec Mouri7d436ec2021-01-27 20:40:50 -0800783 mCurrentDisplayFrame->onSfWakeUp(token, refreshRate,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800784 mTokenManager.getPredictionsForToken(token), wakeUpTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700785}
786
787void FrameTimeline::setSfPresent(nsecs_t sfPresentTime,
788 const std::shared_ptr<FenceTime>& presentFence) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700789 ATRACE_CALL();
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -1000790 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800791 mCurrentDisplayFrame->setActualEndTime(sfPresentTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700792 mPendingPresentFences.emplace_back(std::make_pair(presentFence, mCurrentDisplayFrame));
793 flushPendingPresentFences();
794 finalizeCurrentDisplayFrame();
795}
796
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800797void FrameTimeline::DisplayFrame::addSurfaceFrame(std::shared_ptr<SurfaceFrame> surfaceFrame) {
798 mSurfaceFrames.push_back(surfaceFrame);
799}
800
Alec Mouri7d436ec2021-01-27 20:40:50 -0800801void FrameTimeline::DisplayFrame::onSfWakeUp(int64_t token, Fps refreshRate,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800802 std::optional<TimelineItem> predictions,
803 nsecs_t wakeUpTime) {
804 mToken = token;
Alec Mouri7d436ec2021-01-27 20:40:50 -0800805 mRefreshRate = refreshRate;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800806 if (!predictions) {
807 mPredictionState = PredictionState::Expired;
808 } else {
809 mPredictionState = PredictionState::Valid;
810 mSurfaceFlingerPredictions = *predictions;
811 }
812 mSurfaceFlingerActuals.startTime = wakeUpTime;
813}
814
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800815void FrameTimeline::DisplayFrame::setPredictions(PredictionState predictionState,
816 TimelineItem predictions) {
817 mPredictionState = predictionState;
818 mSurfaceFlingerPredictions = predictions;
819}
820
821void FrameTimeline::DisplayFrame::setActualStartTime(nsecs_t actualStartTime) {
822 mSurfaceFlingerActuals.startTime = actualStartTime;
823}
824
825void FrameTimeline::DisplayFrame::setActualEndTime(nsecs_t actualEndTime) {
826 mSurfaceFlingerActuals.endTime = actualEndTime;
827}
828
829void FrameTimeline::DisplayFrame::onPresent(nsecs_t signalTime) {
830 mSurfaceFlingerActuals.presentTime = signalTime;
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000831 if (mPredictionState == PredictionState::Expired) {
832 // Cannot do jank classification with expired predictions
833 mJankType = JankType::Unknown;
834 return;
835 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800836
837 // Delta between the expected present and the actual present
838 const nsecs_t presentDelta =
839 mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime;
Alec Mouri363faf02021-01-29 16:34:55 -0800840 const nsecs_t deadlineDelta =
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000841 mSurfaceFlingerActuals.endTime - (mSurfaceFlingerPredictions.endTime - mHwcDuration);
Alec Mouri363faf02021-01-29 16:34:55 -0800842
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800843 // How far off was the presentDelta when compared to the vsyncPeriod. Used in checking if there
844 // was a prediction error or not.
Alec Mouriadebf5c2021-01-05 12:57:36 -0800845 nsecs_t deltaToVsync = mRefreshRate.getPeriodNsecs() > 0
846 ? std::abs(presentDelta) % mRefreshRate.getPeriodNsecs()
847 : 0;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800848 if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) {
849 mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent
850 : FramePresentMetadata::EarlyPresent;
851 } else {
852 mFramePresentMetadata = FramePresentMetadata::OnTimePresent;
853 }
854
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000855 if (mSurfaceFlingerActuals.endTime > mSurfaceFlingerPredictions.endTime - mHwcDuration) {
856 // SF needs to have finished at least mHwcDuration ahead of the deadline for it to be
857 // on time.
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800858 mFrameReadyMetadata = FrameReadyMetadata::LateFinish;
859 } else {
860 mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish;
861 }
862
863 if (std::abs(mSurfaceFlingerActuals.startTime - mSurfaceFlingerPredictions.startTime) >
864 mJankClassificationThresholds.startThreshold) {
865 mFrameStartMetadata =
866 mSurfaceFlingerActuals.startTime > mSurfaceFlingerPredictions.startTime
867 ? FrameStartMetadata::LateStart
868 : FrameStartMetadata::EarlyStart;
869 }
870
871 if (mFramePresentMetadata != FramePresentMetadata::OnTimePresent) {
872 // Do jank classification only if present is not on time
873 if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) {
874 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
875 // Finish on time, Present early
876 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -0800877 deltaToVsync >= (mRefreshRate.getPeriodNsecs() -
878 mJankClassificationThresholds.presentThreshold)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800879 // Delta is a factor of vsync if its within the presentTheshold on either side
880 // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold
881 // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms.
882 mJankType = JankType::SurfaceFlingerScheduling;
883 } else {
884 // Delta is not a factor of vsync,
885 mJankType = JankType::PredictionError;
886 }
887 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
888 // Finish late, Present early
889 mJankType = JankType::SurfaceFlingerScheduling;
890 } else {
891 // Finish time unknown
892 mJankType = JankType::Unknown;
893 }
894 } else if (mFramePresentMetadata == FramePresentMetadata::LatePresent) {
895 if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) {
896 // Finish on time, Present late
897 if (deltaToVsync < mJankClassificationThresholds.presentThreshold ||
Alec Mouri7d436ec2021-01-27 20:40:50 -0800898 deltaToVsync >= (mRefreshRate.getPeriodNsecs() -
899 mJankClassificationThresholds.presentThreshold)) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800900 // Delta is a factor of vsync if its within the presentTheshold on either side
901 // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold
902 // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms.
903 mJankType = JankType::DisplayHAL;
904 } else {
905 // Delta is not a factor of vsync
906 mJankType = JankType::PredictionError;
907 }
908 } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) {
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +0000909 if (mFrameStartMetadata == FrameStartMetadata::LateStart) {
910 // Late start, Late finish, Late Present
911 mJankType = JankType::SurfaceFlingerScheduling;
912 } else {
913 // OnTime start, Finish late, Present late
914 mJankType = JankType::SurfaceFlingerCpuDeadlineMissed;
915 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800916 } else {
917 // Finish time unknown
918 mJankType = JankType::Unknown;
919 }
920 } else {
921 // Present unknown
922 mJankType = JankType::Unknown;
923 }
924 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800925 for (auto& surfaceFrame : mSurfaceFrames) {
Alec Mouri363faf02021-01-29 16:34:55 -0800926 surfaceFrame->onPresent(signalTime, mJankType, mRefreshRate, deadlineDelta, deltaToVsync);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800927 }
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800928}
929
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000930void FrameTimeline::DisplayFrame::tracePredictions(pid_t surfaceFlingerPid) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000931 int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000932
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000933 // Expected timeline start
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800934 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800935 auto packet = ctx.NewTracePacket();
936 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000937 packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerPredictions.startTime));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800938
939 auto* event = packet->set_frame_timeline_event();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000940 auto* expectedDisplayFrameStartEvent = event->set_expected_display_frame_start();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800941
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000942 expectedDisplayFrameStartEvent->set_cookie(expectedTimelineCookie);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800943
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000944 expectedDisplayFrameStartEvent->set_token(mToken);
945 expectedDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
946 });
Adithya Srinivasan86678502021-01-19 21:50:38 +0000947
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000948 // Expected timeline end
949 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
950 auto packet = ctx.NewTracePacket();
951 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
952 packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerPredictions.endTime));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800953
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000954 auto* event = packet->set_frame_timeline_event();
955 auto* expectedDisplayFrameEndEvent = event->set_frame_end();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800956
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000957 expectedDisplayFrameEndEvent->set_cookie(expectedTimelineCookie);
958 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000959}
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000960
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000961void FrameTimeline::DisplayFrame::traceActuals(pid_t surfaceFlingerPid) const {
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000962 int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000963
964 // Actual timeline start
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000965 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
966 auto packet = ctx.NewTracePacket();
967 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
968 packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerActuals.startTime));
969
970 auto* event = packet->set_frame_timeline_event();
971 auto* actualDisplayFrameStartEvent = event->set_actual_display_frame_start();
972
973 actualDisplayFrameStartEvent->set_cookie(actualTimelineCookie);
974
975 actualDisplayFrameStartEvent->set_token(mToken);
976 actualDisplayFrameStartEvent->set_pid(surfaceFlingerPid);
977
978 actualDisplayFrameStartEvent->set_present_type(toProto(mFramePresentMetadata));
979 actualDisplayFrameStartEvent->set_on_time_finish(mFrameReadyMetadata ==
980 FrameReadyMetadata::OnTimeFinish);
981 actualDisplayFrameStartEvent->set_gpu_composition(mGpuComposition);
982 actualDisplayFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType));
Adithya Srinivasan78e58af2021-02-25 00:08:08 +0000983 actualDisplayFrameStartEvent->set_prediction_type(toProto(mPredictionState));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000984 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000985
986 // Actual timeline end
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000987 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
988 auto packet = ctx.NewTracePacket();
989 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
Adithya Srinivasan1a971632021-02-26 23:10:29 +0000990 packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerActuals.presentTime));
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +0000991
992 auto* event = packet->set_frame_timeline_event();
993 auto* actualDisplayFrameEndEvent = event->set_frame_end();
994
995 actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800996 });
Adithya Srinivasan061c14c2021-02-11 01:19:47 +0000997}
998
999void FrameTimeline::DisplayFrame::trace(pid_t surfaceFlingerPid) const {
1000 if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
1001 // DisplayFrame should not have an invalid token.
1002 ALOGE("Cannot trace DisplayFrame with invalid token");
1003 return;
1004 }
1005
1006 if (mPredictionState == PredictionState::Valid) {
1007 // Expired and unknown predictions have zeroed timestamps. This cannot be used in any
1008 // meaningful way in a trace.
1009 tracePredictions(surfaceFlingerPid);
1010 }
1011 traceActuals(surfaceFlingerPid);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001012
1013 for (auto& surfaceFrame : mSurfaceFrames) {
1014 surfaceFrame->trace(mToken);
1015 }
1016}
1017
Alec Mouriadebf5c2021-01-05 12:57:36 -08001018float FrameTimeline::computeFps(const std::unordered_set<int32_t>& layerIds) {
1019 if (layerIds.empty()) {
1020 return 0.0f;
1021 }
1022
1023 std::vector<nsecs_t> presentTimes;
1024 {
1025 std::scoped_lock lock(mMutex);
1026 presentTimes.reserve(mDisplayFrames.size());
1027 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
1028 const auto& displayFrame = mDisplayFrames[i];
1029 if (displayFrame->getActuals().presentTime <= 0) {
1030 continue;
1031 }
1032 for (const auto& surfaceFrame : displayFrame->getSurfaceFrames()) {
1033 if (surfaceFrame->getPresentState() == SurfaceFrame::PresentState::Presented &&
1034 layerIds.count(surfaceFrame->getLayerId()) > 0) {
1035 // We're looking for DisplayFrames that presents at least one layer from
1036 // layerIds, so push the present time and skip looking through the rest of the
1037 // SurfaceFrames.
1038 presentTimes.push_back(displayFrame->getActuals().presentTime);
1039 break;
1040 }
1041 }
1042 }
1043 }
1044
1045 // FPS can't be computed when there's fewer than 2 presented frames.
1046 if (presentTimes.size() <= 1) {
1047 return 0.0f;
1048 }
1049
1050 nsecs_t priorPresentTime = -1;
1051 nsecs_t totalPresentToPresentWalls = 0;
1052
1053 for (const nsecs_t presentTime : presentTimes) {
1054 if (priorPresentTime == -1) {
1055 priorPresentTime = presentTime;
1056 continue;
1057 }
1058
1059 totalPresentToPresentWalls += (presentTime - priorPresentTime);
1060 priorPresentTime = presentTime;
1061 }
1062
1063 if (CC_UNLIKELY(totalPresentToPresentWalls <= 0)) {
1064 ALOGW("Invalid total present-to-present duration when computing fps: %" PRId64,
1065 totalPresentToPresentWalls);
1066 return 0.0f;
1067 }
1068
1069 const constexpr nsecs_t kOneSecond =
1070 std::chrono::duration_cast<std::chrono::nanoseconds>(1s).count();
1071 // (10^9 nanoseconds / second) * (N present deltas) / (total nanoseconds in N present deltas) =
1072 // M frames / second
1073 return kOneSecond * static_cast<nsecs_t>((presentTimes.size() - 1)) /
1074 static_cast<float>(totalPresentToPresentWalls);
1075}
1076
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001077void FrameTimeline::flushPendingPresentFences() {
1078 for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
1079 const auto& pendingPresentFence = mPendingPresentFences[i];
1080 nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
1081 if (pendingPresentFence.first && pendingPresentFence.first->isValid()) {
1082 signalTime = pendingPresentFence.first->getSignalTime();
1083 if (signalTime == Fence::SIGNAL_TIME_PENDING) {
1084 continue;
1085 }
1086 }
1087 if (signalTime != Fence::SIGNAL_TIME_INVALID) {
1088 auto& displayFrame = pendingPresentFence.second;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001089 displayFrame->onPresent(signalTime);
1090 displayFrame->trace(mSurfaceFlingerPid);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001091 }
1092
1093 mPendingPresentFences.erase(mPendingPresentFences.begin() + static_cast<int>(i));
1094 --i;
1095 }
1096}
1097
1098void FrameTimeline::finalizeCurrentDisplayFrame() {
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001099 while (mDisplayFrames.size() >= mMaxDisplayFrames) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001100 // We maintain only a fixed number of frames' data. Pop older frames
1101 mDisplayFrames.pop_front();
1102 }
1103 mDisplayFrames.push_back(mCurrentDisplayFrame);
1104 mCurrentDisplayFrame.reset();
Adithya Srinivasan05bd2d12021-01-11 18:49:58 +00001105 mCurrentDisplayFrame = std::make_shared<DisplayFrame>(mTimeStats, mJankClassificationThresholds,
Adithya Srinivasan939cd4d2021-02-23 06:18:13 +00001106 mHwcDuration, &mTraceCookieCounter);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001107}
1108
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001109nsecs_t FrameTimeline::DisplayFrame::getBaseTime() const {
1110 nsecs_t baseTime =
1111 getMinTime(mPredictionState, mSurfaceFlingerPredictions, mSurfaceFlingerActuals);
1112 for (const auto& surfaceFrame : mSurfaceFrames) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001113 nsecs_t surfaceFrameBaseTime = surfaceFrame->getBaseTime();
1114 if (surfaceFrameBaseTime != 0) {
1115 baseTime = std::min(baseTime, surfaceFrameBaseTime);
1116 }
1117 }
1118 return baseTime;
1119}
1120
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001121void FrameTimeline::DisplayFrame::dumpJank(std::string& result, nsecs_t baseTime,
1122 int displayFrameCount) const {
1123 if (mJankType == JankType::None) {
1124 // Check if any Surface Frame has been janky
1125 bool isJanky = false;
1126 for (const auto& surfaceFrame : mSurfaceFrames) {
1127 if (surfaceFrame->getJankType() != JankType::None) {
1128 isJanky = true;
1129 break;
1130 }
1131 }
1132 if (!isJanky) {
1133 return;
1134 }
1135 }
1136 StringAppendF(&result, "Display Frame %d", displayFrameCount);
1137 dump(result, baseTime);
1138}
1139
1140void FrameTimeline::DisplayFrame::dumpAll(std::string& result, nsecs_t baseTime) const {
1141 dump(result, baseTime);
1142}
1143
1144void FrameTimeline::DisplayFrame::dump(std::string& result, nsecs_t baseTime) const {
1145 if (mJankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001146 // Easily identify a janky Display Frame in the dump
1147 StringAppendF(&result, " [*] ");
1148 }
1149 StringAppendF(&result, "\n");
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001150 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
1151 StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str());
1152 StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str());
1153 StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str());
1154 StringAppendF(&result, "Start Metadata: %s\n", toString(mFrameStartMetadata).c_str());
Alec Mouri7d436ec2021-01-27 20:40:50 -08001155 std::chrono::nanoseconds vsyncPeriod(mRefreshRate.getPeriodNsecs());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001156 StringAppendF(&result, "Vsync Period: %10f\n",
1157 std::chrono::duration<double, std::milli>(vsyncPeriod).count());
1158 nsecs_t presentDelta =
1159 mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime;
1160 std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta));
1161 StringAppendF(&result, "Present delta: %10f\n",
1162 std::chrono::duration<double, std::milli>(presentDeltaNs).count());
Alec Mouri7d436ec2021-01-27 20:40:50 -08001163 std::chrono::nanoseconds deltaToVsync(std::abs(presentDelta) % mRefreshRate.getPeriodNsecs());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001164 StringAppendF(&result, "Present delta %% refreshrate: %10f\n",
1165 std::chrono::duration<double, std::milli>(deltaToVsync).count());
1166 dumpTable(result, mSurfaceFlingerPredictions, mSurfaceFlingerActuals, "", mPredictionState,
1167 baseTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001168 StringAppendF(&result, "\n");
1169 std::string indent = " "; // 4 spaces
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001170 for (const auto& surfaceFrame : mSurfaceFrames) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001171 surfaceFrame->dump(result, indent, baseTime);
1172 }
1173 StringAppendF(&result, "\n");
1174}
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001175
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001176void FrameTimeline::dumpAll(std::string& result) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001177 std::scoped_lock lock(mMutex);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001178 StringAppendF(&result, "Number of display frames : %d\n", (int)mDisplayFrames.size());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001179 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001180 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
1181 StringAppendF(&result, "Display Frame %d", static_cast<int>(i));
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001182 mDisplayFrames[i]->dumpAll(result, baseTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001183 }
1184}
1185
1186void FrameTimeline::dumpJank(std::string& result) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001187 std::scoped_lock lock(mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001188 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime();
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001189 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001190 mDisplayFrames[i]->dumpJank(result, baseTime, static_cast<int>(i));
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001191 }
1192}
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001193
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -07001194void FrameTimeline::parseArgs(const Vector<String16>& args, std::string& result) {
1195 ATRACE_CALL();
1196 std::unordered_map<std::string, bool> argsMap;
1197 for (size_t i = 0; i < args.size(); i++) {
1198 argsMap[std::string(String8(args[i]).c_str())] = true;
1199 }
1200 if (argsMap.count("-jank")) {
1201 dumpJank(result);
1202 }
1203 if (argsMap.count("-all")) {
1204 dumpAll(result);
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001205 }
1206}
1207
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001208void FrameTimeline::setMaxDisplayFrames(uint32_t size) {
Siarhei Vishniakoufc434ac2021-01-13 10:28:00 -10001209 std::scoped_lock lock(mMutex);
Adithya Srinivasan2d736322020-10-01 16:53:48 -07001210
1211 // The size can either increase or decrease, clear everything, to be consistent
1212 mDisplayFrames.clear();
1213 mPendingPresentFences.clear();
1214 mMaxDisplayFrames = size;
1215}
1216
1217void FrameTimeline::reset() {
1218 setMaxDisplayFrames(kDefaultMaxDisplayFrames);
1219}
1220
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001221} // namespace impl
1222} // namespace android::frametimeline