blob: ef5f5ad41469cb51f09f57d22031268302f4246f [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
Alec Mouri9a29e672020-09-14 12:39:14 -070097std::string toString(TimeStats::JankType jankType) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -070098 switch (jankType) {
Alec Mouri9a29e672020-09-14 12:39:14 -070099 case TimeStats::JankType::None:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700100 return "None";
Alec Mouri9a29e672020-09-14 12:39:14 -0700101 case TimeStats::JankType::Display:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700102 return "Composer/Display - outside SF and App";
Alec Mouri9a29e672020-09-14 12:39:14 -0700103 case TimeStats::JankType::SurfaceFlingerDeadlineMissed:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700104 return "SurfaceFlinger Deadline Missed";
Alec Mouri9a29e672020-09-14 12:39:14 -0700105 case TimeStats::JankType::AppDeadlineMissed:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700106 return "App Deadline Missed";
Alec Mouri9a29e672020-09-14 12:39:14 -0700107 case TimeStats::JankType::PredictionExpired:
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700108 return "Prediction Expired";
Alec Mouri9a29e672020-09-14 12:39:14 -0700109 case TimeStats::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
157FrameTimelineEvent::JankType JankTypeToProto(TimeStats::JankType jankType) {
158 switch (jankType) {
159 case TimeStats::None:
160 return FrameTimelineEvent::JANK_NONE;
161 case TimeStats::Display:
162 return FrameTimelineEvent::JANK_DISPLAY_HAL;
163 case TimeStats::SurfaceFlingerDeadlineMissed:
164 return FrameTimelineEvent::JANK_SF_DEADLINE_MISSED;
165 case TimeStats::AppDeadlineMissed:
166 case TimeStats::PredictionExpired:
167 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),
Alec Mouri9a29e672020-09-14 12:39:14 -0700220 mJankType(TimeStats::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
Alec Mouri9a29e672020-09-14 12:39:14 -0700262void SurfaceFrame::setJankInfo(TimeStats::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
Alec Mouri9a29e672020-09-14 12:39:14 -0700268TimeStats::JankType SurfaceFrame::getJankType() const {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700269 std::lock_guard<std::mutex> lock(mMutex);
270 return mJankType;
271}
272
273nsecs_t SurfaceFrame::getBaseTime() const {
274 std::lock_guard<std::mutex> lock(mMutex);
275 nsecs_t baseTime = std::numeric_limits<nsecs_t>::max();
276 if (mPredictionState == PredictionState::Valid) {
277 baseTime = std::min(baseTime, mPredictions.startTime);
278 }
279 if (mActuals.startTime != 0) {
280 baseTime = std::min(baseTime, mActuals.startTime);
281 }
282 baseTime = std::min(baseTime, mActuals.endTime);
283 return baseTime;
284}
285
286std::string presentStateToString(SurfaceFrame::PresentState presentState) {
287 using PresentState = SurfaceFrame::PresentState;
288 switch (presentState) {
289 case PresentState::Presented:
290 return "Presented";
291 case PresentState::Dropped:
292 return "Dropped";
293 case PresentState::Unknown:
294 default:
295 return "Unknown";
296 }
297}
298
299void SurfaceFrame::dump(std::string& result, const std::string& indent, nsecs_t baseTime) {
300 std::lock_guard<std::mutex> lock(mMutex);
301 StringAppendF(&result, "%s", indent.c_str());
Alec Mouri9a29e672020-09-14 12:39:14 -0700302 StringAppendF(&result, "Layer - %s", mDebugName.c_str());
303 if (mJankType != TimeStats::JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700304 // Easily identify a janky Surface Frame in the dump
305 StringAppendF(&result, " [*] ");
306 }
307 StringAppendF(&result, "\n");
308 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700309 StringAppendF(&result, "Owner Pid : %d\n", mOwnerPid);
310 StringAppendF(&result, "%s", indent.c_str());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700311 StringAppendF(&result, "Present State : %s\n", presentStateToString(mPresentState).c_str());
312 StringAppendF(&result, "%s", indent.c_str());
313 StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str());
314 StringAppendF(&result, "%s", indent.c_str());
315 StringAppendF(&result, "Jank Type : %s\n", toString(mJankType).c_str());
316 StringAppendF(&result, "%s", indent.c_str());
317 StringAppendF(&result, "Jank Metadata: %s\n",
318 jankMetadataBitmaskToString(mJankMetadata).c_str());
319 dumpTable(result, mPredictions, mActuals, indent, mPredictionState, baseTime);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700320}
321
Adithya Srinivasan01189672020-10-20 14:23:05 -0700322void SurfaceFrame::traceSurfaceFrame(int64_t displayFrameToken) {
323 using FrameTimelineDataSource = FrameTimeline::FrameTimelineDataSource;
324 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
325 std::lock_guard<std::mutex> lock(mMutex);
326 if (mToken == ISurfaceComposer::INVALID_VSYNC_ID) {
327 ALOGD("Cannot trace SurfaceFrame - %s with invalid token", mLayerName.c_str());
328 return;
329 } else if (displayFrameToken == ISurfaceComposer::INVALID_VSYNC_ID) {
330 ALOGD("Cannot trace SurfaceFrame - %s with invalid displayFrameToken",
331 mLayerName.c_str());
332 return;
333 }
334 auto packet = ctx.NewTracePacket();
335 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
336 packet->set_timestamp(static_cast<uint64_t>(systemTime()));
337
338 auto* event = packet->set_frame_timeline_event();
339 auto* surfaceFrameEvent = event->set_surface_frame();
340
341 surfaceFrameEvent->set_token(mToken);
342 surfaceFrameEvent->set_display_frame_token(displayFrameToken);
343
344 if (mPresentState == PresentState::Dropped) {
345 surfaceFrameEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED);
346 } else if (mPresentState == PresentState::Unknown) {
347 surfaceFrameEvent->set_present_type(FrameTimelineEvent::PRESENT_UNSPECIFIED);
348 } else {
349 surfaceFrameEvent->set_present_type(presentTypeToProto(mJankMetadata));
350 }
351 surfaceFrameEvent->set_on_time_finish(!(mJankMetadata & LateFinish));
352 surfaceFrameEvent->set_gpu_composition(mJankMetadata & GpuComposition);
353 surfaceFrameEvent->set_jank_type(JankTypeToProto(mJankType));
354
355 surfaceFrameEvent->set_expected_start_ns(mPredictions.startTime);
356 surfaceFrameEvent->set_expected_end_ns(mPredictions.endTime);
357
358 surfaceFrameEvent->set_actual_start_ns(mActuals.startTime);
359 surfaceFrameEvent->set_actual_end_ns(mActuals.endTime);
360
361 surfaceFrameEvent->set_layer_name(mDebugName);
362 surfaceFrameEvent->set_pid(mOwnerPid);
363 });
364}
365
Alec Mouri9a29e672020-09-14 12:39:14 -0700366FrameTimeline::FrameTimeline(std::shared_ptr<TimeStats> timeStats)
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700367 : mCurrentDisplayFrame(std::make_shared<DisplayFrame>()),
Alec Mouri9a29e672020-09-14 12:39:14 -0700368 mMaxDisplayFrames(kDefaultMaxDisplayFrames),
369 mTimeStats(std::move(timeStats)) {}
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700370
Adithya Srinivasan01189672020-10-20 14:23:05 -0700371void FrameTimeline::onBootFinished() {
372 perfetto::TracingInitArgs args;
373 args.backends = perfetto::kSystemBackend;
374 perfetto::Tracing::Initialize(args);
375 registerDataSource();
376}
377
378void FrameTimeline::registerDataSource() {
379 perfetto::DataSourceDescriptor dsd;
380 dsd.set_name(kFrameTimelineDataSource);
381 FrameTimelineDataSource::Register(dsd);
382}
383
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700384FrameTimeline::DisplayFrame::DisplayFrame()
Adithya Srinivasan01189672020-10-20 14:23:05 -0700385 : surfaceFlingerPredictions(TimelineItem()), surfaceFlingerActuals(TimelineItem()) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700386 this->surfaceFrames.reserve(kNumSurfaceFramesInitial);
387}
388
389std::unique_ptr<android::frametimeline::SurfaceFrame> FrameTimeline::createSurfaceFrameForToken(
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700390 pid_t ownerPid, uid_t ownerUid, std::string layerName, std::string debugName,
391 std::optional<int64_t> token) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700392 ATRACE_CALL();
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700393 if (!token) {
Adithya Srinivasan01189672020-10-20 14:23:05 -0700394 return std::make_unique<impl::SurfaceFrame>(ISurfaceComposer::INVALID_VSYNC_ID, ownerPid,
395 ownerUid, std::move(layerName),
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700396 std::move(debugName), PredictionState::None,
397 TimelineItem());
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700398 }
399 std::optional<TimelineItem> predictions = mTokenManager.getPredictionsForToken(*token);
400 if (predictions) {
Adithya Srinivasan01189672020-10-20 14:23:05 -0700401 return std::make_unique<impl::SurfaceFrame>(*token, ownerPid, ownerUid,
402 std::move(layerName), std::move(debugName),
403 PredictionState::Valid,
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700404 std::move(*predictions));
405 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700406 return std::make_unique<impl::SurfaceFrame>(*token, ownerPid, ownerUid, std::move(layerName),
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700407 std::move(debugName), PredictionState::Expired,
408 TimelineItem());
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700409}
410
411void FrameTimeline::addSurfaceFrame(
412 std::unique_ptr<android::frametimeline::SurfaceFrame> surfaceFrame,
413 SurfaceFrame::PresentState state) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700414 ATRACE_CALL();
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700415 surfaceFrame->setPresentState(state);
416 std::unique_ptr<impl::SurfaceFrame> implSurfaceFrame(
417 static_cast<impl::SurfaceFrame*>(surfaceFrame.release()));
418 std::lock_guard<std::mutex> lock(mMutex);
419 mCurrentDisplayFrame->surfaceFrames.push_back(std::move(implSurfaceFrame));
420}
421
422void FrameTimeline::setSfWakeUp(int64_t token, nsecs_t wakeUpTime) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700423 ATRACE_CALL();
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700424 const std::optional<TimelineItem> prediction = mTokenManager.getPredictionsForToken(token);
425 std::lock_guard<std::mutex> lock(mMutex);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700426 mCurrentDisplayFrame->token = token;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700427 if (!prediction) {
428 mCurrentDisplayFrame->predictionState = PredictionState::Expired;
429 } else {
430 mCurrentDisplayFrame->surfaceFlingerPredictions = *prediction;
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700431 mCurrentDisplayFrame->predictionState = PredictionState::Valid;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700432 }
433 mCurrentDisplayFrame->surfaceFlingerActuals.startTime = wakeUpTime;
434}
435
436void FrameTimeline::setSfPresent(nsecs_t sfPresentTime,
437 const std::shared_ptr<FenceTime>& presentFence) {
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700438 ATRACE_CALL();
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700439 std::lock_guard<std::mutex> lock(mMutex);
440 mCurrentDisplayFrame->surfaceFlingerActuals.endTime = sfPresentTime;
441 mPendingPresentFences.emplace_back(std::make_pair(presentFence, mCurrentDisplayFrame));
442 flushPendingPresentFences();
443 finalizeCurrentDisplayFrame();
444}
445
446void FrameTimeline::flushPendingPresentFences() {
447 for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
448 const auto& pendingPresentFence = mPendingPresentFences[i];
449 nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
450 if (pendingPresentFence.first && pendingPresentFence.first->isValid()) {
451 signalTime = pendingPresentFence.first->getSignalTime();
452 if (signalTime == Fence::SIGNAL_TIME_PENDING) {
453 continue;
454 }
455 }
456 if (signalTime != Fence::SIGNAL_TIME_INVALID) {
Alec Mouri9a29e672020-09-14 12:39:14 -0700457 int32_t totalJankReasons = TimeStats::JankType::None;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700458 auto& displayFrame = pendingPresentFence.second;
459 displayFrame->surfaceFlingerActuals.presentTime = signalTime;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700460
461 // Jank Analysis for DisplayFrame
462 const auto& sfActuals = displayFrame->surfaceFlingerActuals;
463 const auto& sfPredictions = displayFrame->surfaceFlingerPredictions;
464 if (std::abs(sfActuals.presentTime - sfPredictions.presentTime) > kPresentThreshold) {
465 displayFrame->jankMetadata |= sfActuals.presentTime > sfPredictions.presentTime
466 ? LatePresent
467 : EarlyPresent;
468 }
469 if (std::abs(sfActuals.endTime - sfPredictions.endTime) > kDeadlineThreshold) {
470 if (sfActuals.endTime > sfPredictions.endTime) {
471 displayFrame->jankMetadata |= LateFinish;
472 } else {
473 displayFrame->jankMetadata |= EarlyFinish;
474 }
475
Alec Mouri9a29e672020-09-14 12:39:14 -0700476 if ((displayFrame->jankMetadata & EarlyFinish) &&
477 (displayFrame->jankMetadata & EarlyPresent)) {
478 displayFrame->jankType = TimeStats::JankType::SurfaceFlingerEarlyLatch;
479 } else if ((displayFrame->jankMetadata & LateFinish) &&
480 (displayFrame->jankMetadata & LatePresent)) {
481 displayFrame->jankType = TimeStats::JankType::SurfaceFlingerDeadlineMissed;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700482 } else if (displayFrame->jankMetadata & EarlyPresent ||
483 displayFrame->jankMetadata & LatePresent) {
484 // Cases where SF finished early but frame was presented late and vice versa
Alec Mouri9a29e672020-09-14 12:39:14 -0700485 displayFrame->jankType = TimeStats::JankType::Display;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700486 }
487 }
Alec Mouri9a29e672020-09-14 12:39:14 -0700488
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700489 if (std::abs(sfActuals.startTime - sfPredictions.startTime) > kSFStartThreshold) {
490 displayFrame->jankMetadata |=
491 sfActuals.startTime > sfPredictions.startTime ? LateStart : EarlyStart;
492 }
493
Alec Mouri9a29e672020-09-14 12:39:14 -0700494 totalJankReasons |= displayFrame->jankType;
Adithya Srinivasan01189672020-10-20 14:23:05 -0700495 traceDisplayFrame(*displayFrame);
Alec Mouri9a29e672020-09-14 12:39:14 -0700496
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700497 for (auto& surfaceFrame : displayFrame->surfaceFrames) {
498 if (surfaceFrame->getPresentState() == SurfaceFrame::PresentState::Presented) {
499 // Only presented SurfaceFrames need to be updated
Adithya Srinivasan5f683cf2020-09-15 14:21:04 -0700500 surfaceFrame->setActualPresentTime(signalTime);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700501
502 // Jank Analysis for SurfaceFrame
503 const auto& predictionState = surfaceFrame->getPredictionState();
504 if (predictionState == PredictionState::Expired) {
505 // Jank analysis cannot be done on apps that don't use predictions
Alec Mouri9a29e672020-09-14 12:39:14 -0700506 surfaceFrame->setJankInfo(TimeStats::JankType::PredictionExpired, 0);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700507 } else if (predictionState == PredictionState::Valid) {
508 const auto& actuals = surfaceFrame->getActuals();
509 const auto& predictions = surfaceFrame->getPredictions();
510 int32_t jankMetadata = 0;
Alec Mouri9a29e672020-09-14 12:39:14 -0700511 TimeStats::JankType jankType = TimeStats::JankType::None;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700512 if (std::abs(actuals.endTime - predictions.endTime) > kDeadlineThreshold) {
513 jankMetadata |= actuals.endTime > predictions.endTime ? LateFinish
514 : EarlyFinish;
515 }
516 if (std::abs(actuals.presentTime - predictions.presentTime) >
517 kPresentThreshold) {
518 jankMetadata |= actuals.presentTime > predictions.presentTime
519 ? LatePresent
520 : EarlyPresent;
521 }
522 if (jankMetadata & EarlyPresent) {
Alec Mouri9a29e672020-09-14 12:39:14 -0700523 jankType = TimeStats::JankType::SurfaceFlingerEarlyLatch;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700524 } else if (jankMetadata & LatePresent) {
525 if (jankMetadata & EarlyFinish) {
526 // TODO(b/169890654): Classify this properly
Alec Mouri9a29e672020-09-14 12:39:14 -0700527 jankType = TimeStats::JankType::Display;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700528 } else {
Alec Mouri9a29e672020-09-14 12:39:14 -0700529 jankType = TimeStats::JankType::AppDeadlineMissed;
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700530 }
531 }
Alec Mouri9a29e672020-09-14 12:39:14 -0700532
533 totalJankReasons |= jankType;
534 mTimeStats->incrementJankyFrames(surfaceFrame->getOwnerUid(),
535 surfaceFrame->getName(),
536 jankType | displayFrame->jankType);
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700537 surfaceFrame->setJankInfo(jankType, jankMetadata);
538 }
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700539 }
Adithya Srinivasan01189672020-10-20 14:23:05 -0700540 surfaceFrame->traceSurfaceFrame(displayFrame->token);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700541 }
Alec Mouri9a29e672020-09-14 12:39:14 -0700542
543 mTimeStats->incrementJankyFrames(totalJankReasons);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700544 }
545
546 mPendingPresentFences.erase(mPendingPresentFences.begin() + static_cast<int>(i));
547 --i;
548 }
549}
550
551void FrameTimeline::finalizeCurrentDisplayFrame() {
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700552 while (mDisplayFrames.size() >= mMaxDisplayFrames) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700553 // We maintain only a fixed number of frames' data. Pop older frames
554 mDisplayFrames.pop_front();
555 }
556 mDisplayFrames.push_back(mCurrentDisplayFrame);
557 mCurrentDisplayFrame.reset();
558 mCurrentDisplayFrame = std::make_shared<DisplayFrame>();
559}
560
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700561nsecs_t FrameTimeline::findBaseTime(const std::shared_ptr<DisplayFrame>& displayFrame) {
562 nsecs_t baseTime = std::numeric_limits<nsecs_t>::max();
563 if (displayFrame->predictionState == PredictionState::Valid) {
564 baseTime = std::min(baseTime, displayFrame->surfaceFlingerPredictions.startTime);
565 }
566 baseTime = std::min(baseTime, displayFrame->surfaceFlingerActuals.startTime);
567 for (const auto& surfaceFrame : displayFrame->surfaceFrames) {
568 nsecs_t surfaceFrameBaseTime = surfaceFrame->getBaseTime();
569 if (surfaceFrameBaseTime != 0) {
570 baseTime = std::min(baseTime, surfaceFrameBaseTime);
571 }
572 }
573 return baseTime;
574}
575
576void FrameTimeline::dumpDisplayFrame(std::string& result,
577 const std::shared_ptr<DisplayFrame>& displayFrame,
578 nsecs_t baseTime) {
Alec Mouri9a29e672020-09-14 12:39:14 -0700579 if (displayFrame->jankType != TimeStats::JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700580 // Easily identify a janky Display Frame in the dump
581 StringAppendF(&result, " [*] ");
582 }
583 StringAppendF(&result, "\n");
584 StringAppendF(&result, "Prediction State : %s\n",
585 toString(displayFrame->predictionState).c_str());
586 StringAppendF(&result, "Jank Type : %s\n", toString(displayFrame->jankType).c_str());
587 StringAppendF(&result, "Jank Metadata: %s\n",
588 jankMetadataBitmaskToString(displayFrame->jankMetadata).c_str());
589 dumpTable(result, displayFrame->surfaceFlingerPredictions, displayFrame->surfaceFlingerActuals,
590 "", displayFrame->predictionState, baseTime);
591 StringAppendF(&result, "\n");
592 std::string indent = " "; // 4 spaces
593 for (const auto& surfaceFrame : displayFrame->surfaceFrames) {
594 surfaceFrame->dump(result, indent, baseTime);
595 }
596 StringAppendF(&result, "\n");
597}
598void FrameTimeline::dumpAll(std::string& result) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700599 std::lock_guard<std::mutex> lock(mMutex);
600 StringAppendF(&result, "Number of display frames : %d\n", (int)mDisplayFrames.size());
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700601 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : findBaseTime(mDisplayFrames[0]);
602 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
603 StringAppendF(&result, "Display Frame %d", static_cast<int>(i));
604 dumpDisplayFrame(result, mDisplayFrames[i], baseTime);
605 }
606}
607
608void FrameTimeline::dumpJank(std::string& result) {
609 std::lock_guard<std::mutex> lock(mMutex);
610 nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : findBaseTime(mDisplayFrames[0]);
611 for (size_t i = 0; i < mDisplayFrames.size(); i++) {
612 const auto& displayFrame = mDisplayFrames[i];
Alec Mouri9a29e672020-09-14 12:39:14 -0700613 if (displayFrame->jankType == TimeStats::JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700614 // Check if any Surface Frame has been janky
615 bool isJanky = false;
616 for (const auto& surfaceFrame : displayFrame->surfaceFrames) {
Alec Mouri9a29e672020-09-14 12:39:14 -0700617 if (surfaceFrame->getJankType() != TimeStats::JankType::None) {
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700618 isJanky = true;
619 break;
620 }
621 }
622 if (!isJanky) {
623 continue;
624 }
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700625 }
Adithya Srinivasan8fc601d2020-09-25 13:51:09 -0700626 StringAppendF(&result, "Display Frame %d", static_cast<int>(i));
627 dumpDisplayFrame(result, displayFrame, baseTime);
628 }
629}
630void FrameTimeline::parseArgs(const Vector<String16>& args, std::string& result) {
631 ATRACE_CALL();
632 std::unordered_map<std::string, bool> argsMap;
633 for (size_t i = 0; i < args.size(); i++) {
634 argsMap[std::string(String8(args[i]).c_str())] = true;
635 }
636 if (argsMap.count("-jank")) {
637 dumpJank(result);
638 }
639 if (argsMap.count("-all")) {
640 dumpAll(result);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700641 }
642}
643
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700644void FrameTimeline::setMaxDisplayFrames(uint32_t size) {
645 std::lock_guard<std::mutex> lock(mMutex);
646
647 // The size can either increase or decrease, clear everything, to be consistent
648 mDisplayFrames.clear();
649 mPendingPresentFences.clear();
650 mMaxDisplayFrames = size;
651}
652
653void FrameTimeline::reset() {
654 setMaxDisplayFrames(kDefaultMaxDisplayFrames);
655}
656
Adithya Srinivasan01189672020-10-20 14:23:05 -0700657void FrameTimeline::traceDisplayFrame(const DisplayFrame& displayFrame) {
658 FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
659 if (displayFrame.token == ISurfaceComposer::INVALID_VSYNC_ID) {
660 ALOGD("Cannot trace DisplayFrame with invalid token");
661 return;
662 }
663 auto packet = ctx.NewTracePacket();
664 packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
665 packet->set_timestamp(static_cast<uint64_t>(systemTime()));
666
667 auto* event = packet->set_frame_timeline_event();
668 auto* displayFrameEvent = event->set_display_frame();
669
670 displayFrameEvent->set_token(displayFrame.token);
671 displayFrameEvent->set_present_type(presentTypeToProto(displayFrame.jankMetadata));
672 displayFrameEvent->set_on_time_finish(!(displayFrame.jankMetadata & LateFinish));
673 displayFrameEvent->set_gpu_composition(displayFrame.jankMetadata & GpuComposition);
674 displayFrameEvent->set_jank_type(JankTypeToProto(displayFrame.jankType));
675
676 displayFrameEvent->set_expected_start_ns(displayFrame.surfaceFlingerPredictions.startTime);
677 displayFrameEvent->set_expected_end_ns(displayFrame.surfaceFlingerPredictions.endTime);
678
679 displayFrameEvent->set_actual_start_ns(displayFrame.surfaceFlingerActuals.startTime);
680 displayFrameEvent->set_actual_end_ns(displayFrame.surfaceFlingerActuals.endTime);
681 });
682}
683
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700684} // namespace android::frametimeline::impl