blob: b09f07a2bb644c0c83fa4918ca23a8adc4fb881d [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"
22#include <android-base/stringprintf.h>
Ady Abraham7f8a1e62020-09-28 16:09:35 -070023#include <utils/Log.h>
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -070024#include <utils/Trace.h>
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070025#include <chrono>
Adithya Srinivasanf279e042020-08-17 14:56:27 -070026#include <cinttypes>
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070027#include <numeric>
Adithya Srinivasanf279e042020-08-17 14:56:27 -070028
29namespace android::frametimeline::impl {
30
31using base::StringAppendF;
Adithya Srinivasan01189672020-10-20 14:23:05 -070032using FrameTimelineEvent = perfetto::protos::pbzero::FrameTimelineEvent;
Adithya Srinivasanf279e042020-08-17 14:56:27 -070033
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070034void dumpTable(std::string& result, TimelineItem predictions, TimelineItem actuals,
35 const std::string& indent, PredictionState predictionState, nsecs_t baseTime) {
36 StringAppendF(&result, "%s", indent.c_str());
37 StringAppendF(&result, "\t\t");
38 StringAppendF(&result, " Start time\t\t|");
39 StringAppendF(&result, " End time\t\t|");
40 StringAppendF(&result, " Present time\n");
41 if (predictionState == PredictionState::Valid) {
42 // Dump the Predictions only if they are valid
43 StringAppendF(&result, "%s", indent.c_str());
44 StringAppendF(&result, "Expected\t|");
45 std::chrono::nanoseconds startTime(predictions.startTime - baseTime);
46 std::chrono::nanoseconds endTime(predictions.endTime - baseTime);
47 std::chrono::nanoseconds presentTime(predictions.presentTime - baseTime);
48 StringAppendF(&result, "\t%10.2f\t|\t%10.2f\t|\t%10.2f\n",
49 std::chrono::duration<double, std::milli>(startTime).count(),
50 std::chrono::duration<double, std::milli>(endTime).count(),
51 std::chrono::duration<double, std::milli>(presentTime).count());
52 }
53 StringAppendF(&result, "%s", indent.c_str());
54 StringAppendF(&result, "Actual \t|");
55
56 if (actuals.startTime == 0) {
57 StringAppendF(&result, "\t\tN/A\t|");
58 } else {
59 std::chrono::nanoseconds startTime(std::max<nsecs_t>(0, actuals.startTime - baseTime));
60 StringAppendF(&result, "\t%10.2f\t|",
61 std::chrono::duration<double, std::milli>(startTime).count());
62 }
63 if (actuals.endTime == 0) {
64 StringAppendF(&result, "\t\tN/A\t|");
65 } else {
66 std::chrono::nanoseconds endTime(actuals.endTime - baseTime);
67 StringAppendF(&result, "\t%10.2f\t|",
68 std::chrono::duration<double, std::milli>(endTime).count());
69 }
70 if (actuals.presentTime == 0) {
71 StringAppendF(&result, "\t\tN/A\n");
72 } else {
73 std::chrono::nanoseconds presentTime(std::max<nsecs_t>(0, actuals.presentTime - baseTime));
74 StringAppendF(&result, "\t%10.2f\n",
75 std::chrono::duration<double, std::milli>(presentTime).count());
76 }
77
78 StringAppendF(&result, "%s", indent.c_str());
79 StringAppendF(&result, "----------------------");
80 StringAppendF(&result, "----------------------");
81 StringAppendF(&result, "----------------------");
82 StringAppendF(&result, "----------------------\n");
83}
84
85std::string toString(PredictionState predictionState) {
86 switch (predictionState) {
87 case PredictionState::Valid:
88 return "Valid";
89 case PredictionState::Expired:
90 return "Expired";
91 case PredictionState::None:
92 default:
93 return "None";
94 }
95}
96
Jorim Jaggi5814ab82020-12-03 20:45:58 +010097std::string toString(JankType jankType) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070098 switch (jankType) {
Jorim Jaggi5814ab82020-12-03 20:45:58 +010099 case JankType::None:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700100 return "None";
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100101 case JankType::Display:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700102 return "Composer/Display - outside SF and App";
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100103 case JankType::SurfaceFlingerDeadlineMissed:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700104 return "SurfaceFlinger Deadline Missed";
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100105 case JankType::AppDeadlineMissed:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700106 return "App Deadline Missed";
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100107 case JankType::PredictionExpired:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700108 return "Prediction Expired";
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100109 case JankType::SurfaceFlingerEarlyLatch:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700110 return "SurfaceFlinger Early Latch";
111 default:
112 return "Unclassified";
113 }
114}
115
116std::string jankMetadataBitmaskToString(int32_t jankMetadata) {
117 std::vector<std::string> jankInfo;
118
119 if (jankMetadata & EarlyStart) {
120 jankInfo.emplace_back("Early Start");
121 } else if (jankMetadata & LateStart) {
122 jankInfo.emplace_back("Late Start");
123 }
124
125 if (jankMetadata & EarlyFinish) {
126 jankInfo.emplace_back("Early Finish");
127 } else if (jankMetadata & LateFinish) {
128 jankInfo.emplace_back("Late Finish");
129 }
130
131 if (jankMetadata & EarlyPresent) {
132 jankInfo.emplace_back("Early Present");
133 } else if (jankMetadata & LatePresent) {
134 jankInfo.emplace_back("Late Present");
135 }
136 // TODO(b/169876734): add GPU composition metadata here
137
138 if (jankInfo.empty()) {
139 return "None";
140 }
141 return std::accumulate(jankInfo.begin(), jankInfo.end(), std::string(),
142 [](const std::string& l, const std::string& r) {
143 return l.empty() ? r : l + ", " + r;
144 });
145}
146
Adithya Srinivasan01189672020-10-20 14:23:05 -0700147FrameTimelineEvent::PresentType presentTypeToProto(int32_t jankMetadata) {
148 if (jankMetadata & EarlyPresent) {
149 return FrameTimelineEvent::PRESENT_EARLY;
150 }
151 if (jankMetadata & LatePresent) {
152 return FrameTimelineEvent::PRESENT_LATE;
153 }
154 return FrameTimelineEvent::PRESENT_ON_TIME;
155}
156
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100157FrameTimelineEvent::JankType JankTypeToProto(JankType jankType) {
Adithya Srinivasan01189672020-10-20 14:23:05 -0700158 switch (jankType) {
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100159 case JankType::None:
Adithya Srinivasan01189672020-10-20 14:23:05 -0700160 return FrameTimelineEvent::JANK_NONE;
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100161 case JankType::Display:
Adithya Srinivasan01189672020-10-20 14:23:05 -0700162 return FrameTimelineEvent::JANK_DISPLAY_HAL;
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100163 case JankType::SurfaceFlingerDeadlineMissed:
Adithya Srinivasan01189672020-10-20 14:23:05 -0700164 return FrameTimelineEvent::JANK_SF_DEADLINE_MISSED;
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100165 case JankType::AppDeadlineMissed:
166 case JankType::PredictionExpired:
Adithya Srinivasan01189672020-10-20 14:23:05 -0700167 return FrameTimelineEvent::JANK_APP_DEADLINE_MISSED;
168 default:
169 return FrameTimelineEvent::JANK_UNKNOWN;
170 }
171}
172
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700173int64_t TokenManager::generateTokenForPredictions(TimelineItem&& predictions) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700174 ATRACE_CALL();
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700175 std::lock_guard<std::mutex> lock(mMutex);
176 const int64_t assignedToken = mCurrentToken++;
177 mPredictions[assignedToken] = predictions;
178 mTokens.emplace_back(std::make_pair(assignedToken, systemTime()));
179 flushTokens(systemTime());
180 return assignedToken;
181}
182
183std::optional<TimelineItem> TokenManager::getPredictionsForToken(int64_t token) {
184 std::lock_guard<std::mutex> lock(mMutex);
185 flushTokens(systemTime());
186 auto predictionsIterator = mPredictions.find(token);
187 if (predictionsIterator != mPredictions.end()) {
188 return predictionsIterator->second;
189 }
190 return {};
191}
192
193void TokenManager::flushTokens(nsecs_t flushTime) {
194 for (size_t i = 0; i < mTokens.size(); i++) {
195 if (flushTime - mTokens[i].second >= kMaxRetentionTime) {
196 mPredictions.erase(mTokens[i].first);
197 mTokens.erase(mTokens.begin() + static_cast<int>(i));
198 --i;
199 } else {
200 // Tokens are ordered by time. If i'th token is within the retention time, then the
201 // i+1'th token will also be within retention time.
202 break;
203 }
204 }
205}
206
Adithya Srinivasan01189672020-10-20 14:23:05 -0700207SurfaceFrame::SurfaceFrame(int64_t token, pid_t ownerPid, uid_t ownerUid, std::string layerName,
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700208 std::string debugName, PredictionState predictionState,
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700209 frametimeline::TimelineItem&& predictions)
Adithya Srinivasan01189672020-10-20 14:23:05 -0700210 : mToken(token),
211 mOwnerPid(ownerPid),
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700212 mOwnerUid(ownerUid),
Alec Mouri9a29e672020-09-14 12:39:14 -0700213 mLayerName(std::move(layerName)),
214 mDebugName(std::move(debugName)),
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700215 mPresentState(PresentState::Unknown),
216 mPredictionState(predictionState),
217 mPredictions(predictions),
218 mActuals({0, 0, 0}),
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700219 mActualQueueTime(0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100220 mJankType(JankType::None),
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700221 mJankMetadata(0) {}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700222
223void SurfaceFrame::setPresentState(PresentState state) {
224 std::lock_guard<std::mutex> lock(mMutex);
225 mPresentState = state;
226}
227
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700228SurfaceFrame::PresentState SurfaceFrame::getPresentState() const {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700229 std::lock_guard<std::mutex> lock(mMutex);
230 return mPresentState;
231}
232
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700233TimelineItem SurfaceFrame::getActuals() const {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700234 std::lock_guard<std::mutex> lock(mMutex);
235 return mActuals;
236}
237
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700238nsecs_t SurfaceFrame::getActualQueueTime() const {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700239 std::lock_guard<std::mutex> lock(mMutex);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700240 return mActualQueueTime;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700241}
242
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700243void SurfaceFrame::setActualStartTime(nsecs_t actualStartTime) {
244 std::lock_guard<std::mutex> lock(mMutex);
245 mActuals.startTime = actualStartTime;
246}
247
248void SurfaceFrame::setActualQueueTime(nsecs_t actualQueueTime) {
249 std::lock_guard<std::mutex> lock(mMutex);
250 mActualQueueTime = actualQueueTime;
251}
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700252void SurfaceFrame::setAcquireFenceTime(nsecs_t acquireFenceTime) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700253 std::lock_guard<std::mutex> lock(mMutex);
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700254 mActuals.endTime = std::max(acquireFenceTime, mActualQueueTime);
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700255}
256
257void SurfaceFrame::setActualPresentTime(nsecs_t presentTime) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700258 std::lock_guard<std::mutex> lock(mMutex);
259 mActuals.presentTime = presentTime;
260}
261
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100262void SurfaceFrame::setJankInfo(JankType jankType, int32_t jankMetadata) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700263 std::lock_guard<std::mutex> lock(mMutex);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700264 mJankType = jankType;
265 mJankMetadata = jankMetadata;
266}
267
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100268std::optional<JankType> SurfaceFrame::getJankType() const {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700269 std::lock_guard<std::mutex> lock(mMutex);
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100270 if (mActuals.presentTime == 0) {
271 return std::nullopt;
272 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700273 return mJankType;
274}
275
276nsecs_t SurfaceFrame::getBaseTime() const {
277 std::lock_guard<std::mutex> lock(mMutex);
278 nsecs_t baseTime = std::numeric_limits<nsecs_t>::max();
279 if (mPredictionState == PredictionState::Valid) {
280 baseTime = std::min(baseTime, mPredictions.startTime);
281 }
282 if (mActuals.startTime != 0) {
283 baseTime = std::min(baseTime, mActuals.startTime);
284 }
285 baseTime = std::min(baseTime, mActuals.endTime);
286 return baseTime;
287}
288
289std::string presentStateToString(SurfaceFrame::PresentState presentState) {
290 using PresentState = SurfaceFrame::PresentState;
291 switch (presentState) {
292 case PresentState::Presented:
293 return "Presented";
294 case PresentState::Dropped:
295 return "Dropped";
296 case PresentState::Unknown:
297 default:
298 return "Unknown";
299 }
300}
301
302void SurfaceFrame::dump(std::string& result, const std::string& indent, nsecs_t baseTime) {
303 std::lock_guard<std::mutex> lock(mMutex);
304 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri9a29e672020-09-14 12:39:14 -0700305 StringAppendF(&result, "Layer - %s", mDebugName.c_str());
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100306 if (mJankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700307 // Easily identify a janky Surface Frame in the dump
308 StringAppendF(&result, " [*] ");
309 }
310 StringAppendF(&result, "\n");
311 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700312 StringAppendF(&result, "Owner Pid : %d\n", mOwnerPid);
313 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700314 StringAppendF(&result, "Present State : %s\n", presentStateToString(mPresentState).c_str());
315 StringAppendF(&result, "%s", indent.c_str());
316 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
317 StringAppendF(&result, "%s", indent.c_str());
318 StringAppendF(&result, "Jank Type : %s\n", toString(mJankType).c_str());
319 StringAppendF(&result, "%s", indent.c_str());
320 StringAppendF(&result, "Jank Metadata: %s\n",
321 jankMetadataBitmaskToString(mJankMetadata).c_str());
322 dumpTable(result, mPredictions, mActuals, indent, mPredictionState, baseTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700323}
324
Adithya Srinivasan01189672020-10-20 14:23:05 -0700325void SurfaceFrame::traceSurfaceFrame(int64_t displayFrameToken) {
326 using FrameTimelineDataSource = FrameTimeline::FrameTimelineDataSource;
327 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
328 std::lock_guard<std::mutex> lock(mMutex);
329 if (mToken == ISurfaceComposer::INVALID_VSYNC_ID) {
330 ALOGD("Cannot trace SurfaceFrame - %s with invalid token", mLayerName.c_str());
331 return;
332 } else if (displayFrameToken == ISurfaceComposer::INVALID_VSYNC_ID) {
333 ALOGD("Cannot trace SurfaceFrame - %s with invalid displayFrameToken",
334 mLayerName.c_str());
335 return;
336 }
337 auto packet = ctx.NewTracePacket();
338 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
339 packet->set_timestamp(static_cast<uint64_t>(systemTime()));
340
341 auto* event = packet->set_frame_timeline_event();
342 auto* surfaceFrameEvent = event->set_surface_frame();
343
344 surfaceFrameEvent->set_token(mToken);
345 surfaceFrameEvent->set_display_frame_token(displayFrameToken);
346
347 if (mPresentState == PresentState::Dropped) {
348 surfaceFrameEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED);
349 } else if (mPresentState == PresentState::Unknown) {
350 surfaceFrameEvent->set_present_type(FrameTimelineEvent::PRESENT_UNSPECIFIED);
351 } else {
352 surfaceFrameEvent->set_present_type(presentTypeToProto(mJankMetadata));
353 }
354 surfaceFrameEvent->set_on_time_finish(!(mJankMetadata & LateFinish));
355 surfaceFrameEvent->set_gpu_composition(mJankMetadata & GpuComposition);
356 surfaceFrameEvent->set_jank_type(JankTypeToProto(mJankType));
357
358 surfaceFrameEvent->set_expected_start_ns(mPredictions.startTime);
359 surfaceFrameEvent->set_expected_end_ns(mPredictions.endTime);
360
361 surfaceFrameEvent->set_actual_start_ns(mActuals.startTime);
362 surfaceFrameEvent->set_actual_end_ns(mActuals.endTime);
363
364 surfaceFrameEvent->set_layer_name(mDebugName);
365 surfaceFrameEvent->set_pid(mOwnerPid);
366 });
367}
368
Alec Mouri9a29e672020-09-14 12:39:14 -0700369FrameTimeline::FrameTimeline(std::shared_ptr<TimeStats> timeStats)
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700370 : mCurrentDisplayFrame(std::make_shared<DisplayFrame>()),
Alec Mouri9a29e672020-09-14 12:39:14 -0700371 mMaxDisplayFrames(kDefaultMaxDisplayFrames),
372 mTimeStats(std::move(timeStats)) {}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700373
Adithya Srinivasan01189672020-10-20 14:23:05 -0700374void FrameTimeline::onBootFinished() {
375 perfetto::TracingInitArgs args;
376 args.backends = perfetto::kSystemBackend;
377 perfetto::Tracing::Initialize(args);
378 registerDataSource();
379}
380
381void FrameTimeline::registerDataSource() {
382 perfetto::DataSourceDescriptor dsd;
383 dsd.set_name(kFrameTimelineDataSource);
384 FrameTimelineDataSource::Register(dsd);
385}
386
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700387FrameTimeline::DisplayFrame::DisplayFrame()
Adithya Srinivasan01189672020-10-20 14:23:05 -0700388 : surfaceFlingerPredictions(TimelineItem()), surfaceFlingerActuals(TimelineItem()) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700389 this->surfaceFrames.reserve(kNumSurfaceFramesInitial);
390}
391
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100392std::shared_ptr<android::frametimeline::SurfaceFrame> FrameTimeline::createSurfaceFrameForToken(
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700393 pid_t ownerPid, uid_t ownerUid, std::string layerName, std::string debugName,
394 std::optional<int64_t> token) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700395 ATRACE_CALL();
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700396 if (!token) {
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100397 return std::make_shared<impl::SurfaceFrame>(ISurfaceComposer::INVALID_VSYNC_ID,ownerPid,
Adithya Srinivasan01189672020-10-20 14:23:05 -0700398 ownerUid, std::move(layerName),
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700399 std::move(debugName), PredictionState::None,
400 TimelineItem());
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700401 }
402 std::optional<TimelineItem> predictions = mTokenManager.getPredictionsForToken(*token);
403 if (predictions) {
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100404 return std::make_shared<impl::SurfaceFrame>(*token, ownerPid, ownerUid,
Adithya Srinivasan01189672020-10-20 14:23:05 -0700405 std::move(layerName), std::move(debugName),
406 PredictionState::Valid,
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700407 std::move(*predictions));
408 }
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100409 return std::make_shared<impl::SurfaceFrame>(*token, ownerPid, ownerUid, std::move(layerName),
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700410 std::move(debugName), PredictionState::Expired,
411 TimelineItem());
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700412}
413
414void FrameTimeline::addSurfaceFrame(
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100415 std::shared_ptr<android::frametimeline::SurfaceFrame> surfaceFrame,
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700416 SurfaceFrame::PresentState state) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700417 ATRACE_CALL();
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700418 surfaceFrame->setPresentState(state);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700419 std::lock_guard<std::mutex> lock(mMutex);
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100420 mCurrentDisplayFrame->surfaceFrames.push_back(
421 std::static_pointer_cast<impl::SurfaceFrame>(surfaceFrame));
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700422}
423
424void FrameTimeline::setSfWakeUp(int64_t token, nsecs_t wakeUpTime) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700425 ATRACE_CALL();
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700426 const std::optional<TimelineItem> prediction = mTokenManager.getPredictionsForToken(token);
427 std::lock_guard<std::mutex> lock(mMutex);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700428 mCurrentDisplayFrame->token = token;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700429 if (!prediction) {
430 mCurrentDisplayFrame->predictionState = PredictionState::Expired;
431 } else {
432 mCurrentDisplayFrame->surfaceFlingerPredictions = *prediction;
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700433 mCurrentDisplayFrame->predictionState = PredictionState::Valid;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700434 }
435 mCurrentDisplayFrame->surfaceFlingerActuals.startTime = wakeUpTime;
436}
437
438void FrameTimeline::setSfPresent(nsecs_t sfPresentTime,
439 const std::shared_ptr<FenceTime>& presentFence) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700440 ATRACE_CALL();
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700441 std::lock_guard<std::mutex> lock(mMutex);
442 mCurrentDisplayFrame->surfaceFlingerActuals.endTime = sfPresentTime;
443 mPendingPresentFences.emplace_back(std::make_pair(presentFence, mCurrentDisplayFrame));
444 flushPendingPresentFences();
445 finalizeCurrentDisplayFrame();
446}
447
448void FrameTimeline::flushPendingPresentFences() {
449 for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
450 const auto& pendingPresentFence = mPendingPresentFences[i];
451 nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
452 if (pendingPresentFence.first && pendingPresentFence.first->isValid()) {
453 signalTime = pendingPresentFence.first->getSignalTime();
454 if (signalTime == Fence::SIGNAL_TIME_PENDING) {
455 continue;
456 }
457 }
458 if (signalTime != Fence::SIGNAL_TIME_INVALID) {
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100459 int32_t totalJankReasons = JankType::None;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700460 auto& displayFrame = pendingPresentFence.second;
461 displayFrame->surfaceFlingerActuals.presentTime = signalTime;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700462
463 // Jank Analysis for DisplayFrame
464 const auto& sfActuals = displayFrame->surfaceFlingerActuals;
465 const auto& sfPredictions = displayFrame->surfaceFlingerPredictions;
466 if (std::abs(sfActuals.presentTime - sfPredictions.presentTime) > kPresentThreshold) {
467 displayFrame->jankMetadata |= sfActuals.presentTime > sfPredictions.presentTime
468 ? LatePresent
469 : EarlyPresent;
470 }
471 if (std::abs(sfActuals.endTime - sfPredictions.endTime) > kDeadlineThreshold) {
472 if (sfActuals.endTime > sfPredictions.endTime) {
473 displayFrame->jankMetadata |= LateFinish;
474 } else {
475 displayFrame->jankMetadata |= EarlyFinish;
476 }
477
Alec Mouri9a29e672020-09-14 12:39:14 -0700478 if ((displayFrame->jankMetadata & EarlyFinish) &&
479 (displayFrame->jankMetadata & EarlyPresent)) {
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100480 displayFrame->jankType = JankType::SurfaceFlingerEarlyLatch;
Alec Mouri9a29e672020-09-14 12:39:14 -0700481 } else if ((displayFrame->jankMetadata & LateFinish) &&
482 (displayFrame->jankMetadata & LatePresent)) {
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100483 displayFrame->jankType = JankType::SurfaceFlingerDeadlineMissed;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700484 } else if (displayFrame->jankMetadata & EarlyPresent ||
485 displayFrame->jankMetadata & LatePresent) {
486 // Cases where SF finished early but frame was presented late and vice versa
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100487 displayFrame->jankType = JankType::Display;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700488 }
489 }
Alec Mouri9a29e672020-09-14 12:39:14 -0700490
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700491 if (std::abs(sfActuals.startTime - sfPredictions.startTime) > kSFStartThreshold) {
492 displayFrame->jankMetadata |=
493 sfActuals.startTime > sfPredictions.startTime ? LateStart : EarlyStart;
494 }
495
Alec Mouri9a29e672020-09-14 12:39:14 -0700496 totalJankReasons |= displayFrame->jankType;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700497 traceDisplayFrame(*displayFrame);
Alec Mouri9a29e672020-09-14 12:39:14 -0700498
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700499 for (auto& surfaceFrame : displayFrame->surfaceFrames) {
500 if (surfaceFrame->getPresentState() == SurfaceFrame::PresentState::Presented) {
501 // Only presented SurfaceFrames need to be updated
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700502 surfaceFrame->setActualPresentTime(signalTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700503
504 // Jank Analysis for SurfaceFrame
505 const auto& predictionState = surfaceFrame->getPredictionState();
506 if (predictionState == PredictionState::Expired) {
507 // Jank analysis cannot be done on apps that don't use predictions
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100508 surfaceFrame->setJankInfo(JankType::PredictionExpired, 0);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700509 } else if (predictionState == PredictionState::Valid) {
510 const auto& actuals = surfaceFrame->getActuals();
511 const auto& predictions = surfaceFrame->getPredictions();
512 int32_t jankMetadata = 0;
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100513 JankType jankType = JankType::None;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700514 if (std::abs(actuals.endTime - predictions.endTime) > kDeadlineThreshold) {
515 jankMetadata |= actuals.endTime > predictions.endTime ? LateFinish
516 : EarlyFinish;
517 }
518 if (std::abs(actuals.presentTime - predictions.presentTime) >
519 kPresentThreshold) {
520 jankMetadata |= actuals.presentTime > predictions.presentTime
521 ? LatePresent
522 : EarlyPresent;
523 }
524 if (jankMetadata & EarlyPresent) {
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100525 jankType = JankType::SurfaceFlingerEarlyLatch;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700526 } else if (jankMetadata & LatePresent) {
527 if (jankMetadata & EarlyFinish) {
528 // TODO(b/169890654): Classify this properly
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100529 jankType = JankType::Display;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700530 } else {
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100531 jankType = JankType::AppDeadlineMissed;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700532 }
533 }
Alec Mouri9a29e672020-09-14 12:39:14 -0700534
535 totalJankReasons |= jankType;
536 mTimeStats->incrementJankyFrames(surfaceFrame->getOwnerUid(),
537 surfaceFrame->getName(),
538 jankType | displayFrame->jankType);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700539 surfaceFrame->setJankInfo(jankType, jankMetadata);
540 }
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700541 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700542 surfaceFrame->traceSurfaceFrame(displayFrame->token);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700543 }
Alec Mouri9a29e672020-09-14 12:39:14 -0700544
545 mTimeStats->incrementJankyFrames(totalJankReasons);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700546 }
547
548 mPendingPresentFences.erase(mPendingPresentFences.begin() + static_cast<int>(i));
549 --i;
550 }
551}
552
553void FrameTimeline::finalizeCurrentDisplayFrame() {
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700554 while (mDisplayFrames.size() >= mMaxDisplayFrames) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700555 // We maintain only a fixed number of frames' data. Pop older frames
556 mDisplayFrames.pop_front();
557 }
558 mDisplayFrames.push_back(mCurrentDisplayFrame);
559 mCurrentDisplayFrame.reset();
560 mCurrentDisplayFrame = std::make_shared<DisplayFrame>();
561}
562
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700563nsecs_t FrameTimeline::findBaseTime(const std::shared_ptr<DisplayFrame>& displayFrame) {
564 nsecs_t baseTime = std::numeric_limits<nsecs_t>::max();
565 if (displayFrame->predictionState == PredictionState::Valid) {
566 baseTime = std::min(baseTime, displayFrame->surfaceFlingerPredictions.startTime);
567 }
568 baseTime = std::min(baseTime, displayFrame->surfaceFlingerActuals.startTime);
569 for (const auto& surfaceFrame : displayFrame->surfaceFrames) {
570 nsecs_t surfaceFrameBaseTime = surfaceFrame->getBaseTime();
571 if (surfaceFrameBaseTime != 0) {
572 baseTime = std::min(baseTime, surfaceFrameBaseTime);
573 }
574 }
575 return baseTime;
576}
577
578void FrameTimeline::dumpDisplayFrame(std::string& result,
579 const std::shared_ptr<DisplayFrame>& displayFrame,
580 nsecs_t baseTime) {
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100581 if (displayFrame->jankType != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700582 // Easily identify a janky Display Frame in the dump
583 StringAppendF(&result, " [*] ");
584 }
585 StringAppendF(&result, "\n");
586 StringAppendF(&result, "Prediction State : %s\n",
587 toString(displayFrame->predictionState).c_str());
588 StringAppendF(&result, "Jank Type : %s\n", toString(displayFrame->jankType).c_str());
589 StringAppendF(&result, "Jank Metadata: %s\n",
590 jankMetadataBitmaskToString(displayFrame->jankMetadata).c_str());
591 dumpTable(result, displayFrame->surfaceFlingerPredictions, displayFrame->surfaceFlingerActuals,
592 "", displayFrame->predictionState, baseTime);
593 StringAppendF(&result, "\n");
594 std::string indent = " "; // 4 spaces
595 for (const auto& surfaceFrame : displayFrame->surfaceFrames) {
596 surfaceFrame->dump(result, indent, baseTime);
597 }
598 StringAppendF(&result, "\n");
599}
600void FrameTimeline::dumpAll(std::string& result) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700601 std::lock_guard<std::mutex> lock(mMutex);
602 StringAppendF(&result, "Number of display frames : %d\n", (int)mDisplayFrames.size());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700603 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : findBaseTime(mDisplayFrames[0]);
604 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
605 StringAppendF(&result, "Display Frame %d", static_cast<int>(i));
606 dumpDisplayFrame(result, mDisplayFrames[i], baseTime);
607 }
608}
609
610void FrameTimeline::dumpJank(std::string& result) {
611 std::lock_guard<std::mutex> lock(mMutex);
612 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : findBaseTime(mDisplayFrames[0]);
613 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
614 const auto& displayFrame = mDisplayFrames[i];
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100615 if (displayFrame->jankType == JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700616 // Check if any Surface Frame has been janky
617 bool isJanky = false;
618 for (const auto& surfaceFrame : displayFrame->surfaceFrames) {
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100619 if (surfaceFrame->getJankType() != JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700620 isJanky = true;
621 break;
622 }
623 }
624 if (!isJanky) {
625 continue;
626 }
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700627 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700628 StringAppendF(&result, "Display Frame %d", static_cast<int>(i));
629 dumpDisplayFrame(result, displayFrame, baseTime);
630 }
631}
632void FrameTimeline::parseArgs(const Vector<String16>& args, std::string& result) {
633 ATRACE_CALL();
634 std::unordered_map<std::string, bool> argsMap;
635 for (size_t i = 0; i < args.size(); i++) {
636 argsMap[std::string(String8(args[i]).c_str())] = true;
637 }
638 if (argsMap.count("-jank")) {
639 dumpJank(result);
640 }
641 if (argsMap.count("-all")) {
642 dumpAll(result);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700643 }
644}
645
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700646void FrameTimeline::setMaxDisplayFrames(uint32_t size) {
647 std::lock_guard<std::mutex> lock(mMutex);
648
649 // The size can either increase or decrease, clear everything, to be consistent
650 mDisplayFrames.clear();
651 mPendingPresentFences.clear();
652 mMaxDisplayFrames = size;
653}
654
655void FrameTimeline::reset() {
656 setMaxDisplayFrames(kDefaultMaxDisplayFrames);
657}
658
Adithya Srinivasan01189672020-10-20 14:23:05 -0700659void FrameTimeline::traceDisplayFrame(const DisplayFrame& displayFrame) {
660 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
661 if (displayFrame.token == ISurfaceComposer::INVALID_VSYNC_ID) {
662 ALOGD("Cannot trace DisplayFrame with invalid token");
663 return;
664 }
665 auto packet = ctx.NewTracePacket();
666 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
667 packet->set_timestamp(static_cast<uint64_t>(systemTime()));
668
669 auto* event = packet->set_frame_timeline_event();
670 auto* displayFrameEvent = event->set_display_frame();
671
672 displayFrameEvent->set_token(displayFrame.token);
673 displayFrameEvent->set_present_type(presentTypeToProto(displayFrame.jankMetadata));
674 displayFrameEvent->set_on_time_finish(!(displayFrame.jankMetadata & LateFinish));
675 displayFrameEvent->set_gpu_composition(displayFrame.jankMetadata & GpuComposition);
676 displayFrameEvent->set_jank_type(JankTypeToProto(displayFrame.jankType));
677
678 displayFrameEvent->set_expected_start_ns(displayFrame.surfaceFlingerPredictions.startTime);
679 displayFrameEvent->set_expected_end_ns(displayFrame.surfaceFlingerPredictions.endTime);
680
681 displayFrameEvent->set_actual_start_ns(displayFrame.surfaceFlingerActuals.startTime);
682 displayFrameEvent->set_actual_end_ns(displayFrame.surfaceFlingerActuals.endTime);
683 });
684}
685
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700686} // namespace android::frametimeline::impl