1 /*
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
18 #include "gmock/gmock-spec-builders.h"
19 #include "mock/MockTimeStats.h"
20 #undef LOG_TAG
21 #define LOG_TAG "LibSurfaceFlingerUnittests"
22
23 #include <FrameTimeline/FrameTimeline.h>
24 #include <gtest/gtest.h>
25 #include <log/log.h>
26 #include <perfetto/trace/trace.pb.h>
27 #include <cinttypes>
28
29 using namespace std::chrono_literals;
30 using testing::_;
31 using testing::AtLeast;
32 using testing::Contains;
33 using FrameTimelineEvent = perfetto::protos::FrameTimelineEvent;
34 using ProtoExpectedDisplayFrameStart =
35 perfetto::protos::FrameTimelineEvent_ExpectedDisplayFrameStart;
36 using ProtoExpectedSurfaceFrameStart =
37 perfetto::protos::FrameTimelineEvent_ExpectedSurfaceFrameStart;
38 using ProtoActualDisplayFrameStart = perfetto::protos::FrameTimelineEvent_ActualDisplayFrameStart;
39 using ProtoActualSurfaceFrameStart = perfetto::protos::FrameTimelineEvent_ActualSurfaceFrameStart;
40 using ProtoFrameEnd = perfetto::protos::FrameTimelineEvent_FrameEnd;
41 using ProtoPresentType = perfetto::protos::FrameTimelineEvent_PresentType;
42 using ProtoJankType = perfetto::protos::FrameTimelineEvent_JankType;
43 using ProtoPredictionType = perfetto::protos::FrameTimelineEvent_PredictionType;
44
45 namespace android::frametimeline {
46
47 class FrameTimelineTest : public testing::Test {
48 public:
FrameTimelineTest()49 FrameTimelineTest() {
50 const ::testing::TestInfo* const test_info =
51 ::testing::UnitTest::GetInstance()->current_test_info();
52 ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
53 }
54
~FrameTimelineTest()55 ~FrameTimelineTest() {
56 const ::testing::TestInfo* const test_info =
57 ::testing::UnitTest::GetInstance()->current_test_info();
58 ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
59 }
60
SetUpTestSuite()61 static void SetUpTestSuite() {
62 // Need to initialize tracing in process for testing, and only once per test suite.
63 perfetto::TracingInitArgs args;
64 args.backends = perfetto::kInProcessBackend;
65 perfetto::Tracing::Initialize(args);
66 }
67
SetUp()68 void SetUp() override {
69 mTimeStats = std::make_shared<mock::TimeStats>();
70 mFrameTimeline = std::make_unique<impl::FrameTimeline>(mTimeStats, kSurfaceFlingerPid,
71 kTestThresholds);
72 mFrameTimeline->registerDataSource();
73 mTokenManager = &mFrameTimeline->mTokenManager;
74 mTraceCookieCounter = &mFrameTimeline->mTraceCookieCounter;
75 maxDisplayFrames = &mFrameTimeline->mMaxDisplayFrames;
76 maxTokens = mTokenManager->kMaxTokens;
77 }
78
79 // Each tracing session can be used for a single block of Start -> Stop.
getTracingSessionForTest()80 static std::unique_ptr<perfetto::TracingSession> getTracingSessionForTest() {
81 perfetto::TraceConfig cfg;
82 cfg.set_duration_ms(500);
83 cfg.add_buffers()->set_size_kb(1024);
84 auto* ds_cfg = cfg.add_data_sources()->mutable_config();
85 ds_cfg->set_name(impl::FrameTimeline::kFrameTimelineDataSource);
86
87 auto tracingSession = perfetto::Tracing::NewTrace(perfetto::kInProcessBackend);
88 tracingSession->Setup(cfg);
89 return tracingSession;
90 }
91
readFrameTimelinePacketsBlocking(perfetto::TracingSession * tracingSession)92 std::vector<perfetto::protos::TracePacket> readFrameTimelinePacketsBlocking(
93 perfetto::TracingSession* tracingSession) {
94 std::vector<char> raw_trace = tracingSession->ReadTraceBlocking();
95 perfetto::protos::Trace trace;
96 EXPECT_TRUE(trace.ParseFromArray(raw_trace.data(), int(raw_trace.size())));
97
98 std::vector<perfetto::protos::TracePacket> packets;
99 for (const auto& packet : trace.packet()) {
100 if (!packet.has_frame_timeline_event()) {
101 continue;
102 }
103 packets.emplace_back(packet);
104 }
105 return packets;
106 }
107
addEmptyDisplayFrame()108 void addEmptyDisplayFrame() {
109 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
110 // Trigger a flushPresentFence by calling setSfPresent for the next frame
111 mFrameTimeline->setSfPresent(2500, presentFence1);
112 }
113
flushTokens()114 void flushTokens() {
115 for (size_t i = 0; i < maxTokens; i++) {
116 mTokenManager->generateTokenForPredictions({});
117 }
118 EXPECT_EQ(getPredictions().size(), maxTokens);
119 }
120
getSurfaceFrame(size_t displayFrameIdx,size_t surfaceFrameIdx)121 SurfaceFrame& getSurfaceFrame(size_t displayFrameIdx, size_t surfaceFrameIdx) {
122 std::lock_guard<std::mutex> lock(mFrameTimeline->mMutex);
123 return *(mFrameTimeline->mDisplayFrames[displayFrameIdx]
124 ->getSurfaceFrames()[surfaceFrameIdx]);
125 }
126
getDisplayFrame(size_t idx)127 std::shared_ptr<impl::FrameTimeline::DisplayFrame> getDisplayFrame(size_t idx) {
128 std::lock_guard<std::mutex> lock(mFrameTimeline->mMutex);
129 return mFrameTimeline->mDisplayFrames[idx];
130 }
131
compareTimelineItems(const TimelineItem & a,const TimelineItem & b)132 static bool compareTimelineItems(const TimelineItem& a, const TimelineItem& b) {
133 return a.startTime == b.startTime && a.endTime == b.endTime &&
134 a.presentTime == b.presentTime;
135 }
136
getPredictions() const137 const std::map<int64_t, TimelineItem>& getPredictions() const {
138 return mTokenManager->mPredictions;
139 }
140
getNumberOfDisplayFrames() const141 uint32_t getNumberOfDisplayFrames() const {
142 std::lock_guard<std::mutex> lock(mFrameTimeline->mMutex);
143 return static_cast<uint32_t>(mFrameTimeline->mDisplayFrames.size());
144 }
145
snoopCurrentTraceCookie() const146 int64_t snoopCurrentTraceCookie() const { return mTraceCookieCounter->mTraceCookie; }
147
flushTrace()148 void flushTrace() {
149 using FrameTimelineDataSource = impl::FrameTimeline::FrameTimelineDataSource;
150 FrameTimelineDataSource::Trace(
151 [&](FrameTimelineDataSource::TraceContext ctx) { ctx.Flush(); });
152 }
153
154 std::shared_ptr<mock::TimeStats> mTimeStats;
155 std::unique_ptr<impl::FrameTimeline> mFrameTimeline;
156 impl::TokenManager* mTokenManager;
157 TraceCookieCounter* mTraceCookieCounter;
158 FenceToFenceTimeMap fenceFactory;
159 uint32_t* maxDisplayFrames;
160 size_t maxTokens;
161 static constexpr pid_t kSurfaceFlingerPid = 666;
162 static constexpr nsecs_t kPresentThreshold = std::chrono::nanoseconds(2ns).count();
163 static constexpr nsecs_t kDeadlineThreshold = std::chrono::nanoseconds(0ns).count();
164 static constexpr nsecs_t kStartThreshold = std::chrono::nanoseconds(2ns).count();
165 static constexpr JankClassificationThresholds kTestThresholds{kPresentThreshold,
166 kDeadlineThreshold,
167 kStartThreshold};
168 };
169
170 static const std::string sLayerNameOne = "layer1";
171 static const std::string sLayerNameTwo = "layer2";
172 static constexpr const uid_t sUidOne = 0;
173 static constexpr pid_t sPidOne = 10;
174 static constexpr pid_t sPidTwo = 20;
175 static constexpr int32_t sInputEventId = 5;
176 static constexpr int32_t sLayerIdOne = 1;
177 static constexpr int32_t sLayerIdTwo = 2;
178 static constexpr int32_t sGameMode = 0;
179
TEST_F(FrameTimelineTest,tokenManagerRemovesStalePredictions)180 TEST_F(FrameTimelineTest, tokenManagerRemovesStalePredictions) {
181 int64_t token1 = mTokenManager->generateTokenForPredictions({0, 0, 0});
182 EXPECT_EQ(getPredictions().size(), 1u);
183 flushTokens();
184 int64_t token2 = mTokenManager->generateTokenForPredictions({10, 20, 30});
185 std::optional<TimelineItem> predictions = mTokenManager->getPredictionsForToken(token1);
186
187 // token1 should have expired
188 EXPECT_EQ(predictions.has_value(), false);
189
190 predictions = mTokenManager->getPredictionsForToken(token2);
191 EXPECT_EQ(compareTimelineItems(*predictions, TimelineItem(10, 20, 30)), true);
192 }
193
TEST_F(FrameTimelineTest,createSurfaceFrameForToken_getOwnerPidReturnsCorrectPid)194 TEST_F(FrameTimelineTest, createSurfaceFrameForToken_getOwnerPidReturnsCorrectPid) {
195 auto surfaceFrame1 =
196 mFrameTimeline->createSurfaceFrameForToken({}, sPidOne, sUidOne, sLayerIdOne,
197 sLayerNameOne, sLayerNameOne,
198 /*isBuffer*/ true, sGameMode);
199 auto surfaceFrame2 =
200 mFrameTimeline->createSurfaceFrameForToken({}, sPidTwo, sUidOne, sLayerIdOne,
201 sLayerNameOne, sLayerNameOne,
202 /*isBuffer*/ true, sGameMode);
203 EXPECT_EQ(surfaceFrame1->getOwnerPid(), sPidOne);
204 EXPECT_EQ(surfaceFrame2->getOwnerPid(), sPidTwo);
205 }
206
TEST_F(FrameTimelineTest,createSurfaceFrameForToken_noToken)207 TEST_F(FrameTimelineTest, createSurfaceFrameForToken_noToken) {
208 auto surfaceFrame =
209 mFrameTimeline->createSurfaceFrameForToken({}, sPidOne, sUidOne, sLayerIdOne,
210 sLayerNameOne, sLayerNameOne,
211 /*isBuffer*/ true, sGameMode);
212 EXPECT_EQ(surfaceFrame->getPredictionState(), PredictionState::None);
213 }
214
TEST_F(FrameTimelineTest,createSurfaceFrameForToken_expiredToken)215 TEST_F(FrameTimelineTest, createSurfaceFrameForToken_expiredToken) {
216 int64_t token1 = mTokenManager->generateTokenForPredictions({0, 0, 0});
217 flushTokens();
218 auto surfaceFrame =
219 mFrameTimeline->createSurfaceFrameForToken({token1, sInputEventId}, sPidOne, sUidOne,
220 sLayerIdOne, sLayerNameOne, sLayerNameOne,
221 /*isBuffer*/ true, sGameMode);
222
223 EXPECT_EQ(surfaceFrame->getPredictionState(), PredictionState::Expired);
224 }
225
TEST_F(FrameTimelineTest,createSurfaceFrameForToken_validToken)226 TEST_F(FrameTimelineTest, createSurfaceFrameForToken_validToken) {
227 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
228 auto surfaceFrame =
229 mFrameTimeline->createSurfaceFrameForToken({token1, sInputEventId}, sPidOne, sUidOne,
230 sLayerIdOne, sLayerNameOne, sLayerNameOne,
231 /*isBuffer*/ true, sGameMode);
232
233 EXPECT_EQ(surfaceFrame->getPredictionState(), PredictionState::Valid);
234 EXPECT_EQ(compareTimelineItems(surfaceFrame->getPredictions(), TimelineItem(10, 20, 30)), true);
235 }
236
TEST_F(FrameTimelineTest,createSurfaceFrameForToken_validInputEventId)237 TEST_F(FrameTimelineTest, createSurfaceFrameForToken_validInputEventId) {
238 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
239 constexpr int32_t inputEventId = 1;
240 auto surfaceFrame =
241 mFrameTimeline->createSurfaceFrameForToken({token1, inputEventId}, sPidOne, sUidOne,
242 sLayerIdOne, sLayerNameOne, sLayerNameOne,
243 /*isBuffer*/ true, sGameMode);
244
245 EXPECT_EQ(inputEventId, surfaceFrame->getInputEventId());
246 }
247
TEST_F(FrameTimelineTest,presentFenceSignaled_droppedFramesNotUpdated)248 TEST_F(FrameTimelineTest, presentFenceSignaled_droppedFramesNotUpdated) {
249 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
250 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
251 auto surfaceFrame1 =
252 mFrameTimeline->createSurfaceFrameForToken({token1, sInputEventId}, sPidOne, sUidOne,
253 sLayerIdOne, sLayerNameOne, sLayerNameOne,
254 /*isBuffer*/ true, sGameMode);
255
256 // Set up the display frame
257 mFrameTimeline->setSfWakeUp(token1, 20, Fps::fromPeriodNsecs(11));
258 surfaceFrame1->setDropTime(12);
259 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Dropped);
260 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
261 mFrameTimeline->setSfPresent(25, presentFence1);
262 presentFence1->signalForTest(30);
263
264 addEmptyDisplayFrame();
265
266 auto& droppedSurfaceFrame = getSurfaceFrame(0, 0);
267 EXPECT_EQ(droppedSurfaceFrame.getPresentState(), SurfaceFrame::PresentState::Dropped);
268 EXPECT_EQ(0u, droppedSurfaceFrame.getActuals().endTime);
269 EXPECT_EQ(12u, droppedSurfaceFrame.getDropTime());
270 EXPECT_EQ(droppedSurfaceFrame.getActuals().presentTime, 0);
271 }
272
TEST_F(FrameTimelineTest,presentFenceSignaled_presentedFramesUpdated)273 TEST_F(FrameTimelineTest, presentFenceSignaled_presentedFramesUpdated) {
274 // Layer specific increment
275 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_)).Times(2);
276 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
277 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
278 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 30});
279 auto surfaceFrame1 =
280 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
281 sUidOne, sLayerIdOne, sLayerNameOne,
282 sLayerNameOne, /*isBuffer*/ true, sGameMode);
283 auto surfaceFrame2 =
284 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
285 sUidOne, sLayerIdTwo, sLayerNameTwo,
286 sLayerNameTwo, /*isBuffer*/ true, sGameMode);
287 mFrameTimeline->setSfWakeUp(sfToken1, 22, Fps::fromPeriodNsecs(11));
288 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
289 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
290 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
291 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
292 mFrameTimeline->setSfPresent(26, presentFence1);
293 auto displayFrame = getDisplayFrame(0);
294 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
295 auto& presentedSurfaceFrame2 = getSurfaceFrame(0, 1);
296 presentFence1->signalForTest(42);
297
298 // Fences haven't been flushed yet, so it should be 0
299 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
300 EXPECT_EQ(presentedSurfaceFrame1.getActuals().presentTime, 0);
301 EXPECT_EQ(presentedSurfaceFrame2.getActuals().presentTime, 0);
302
303 addEmptyDisplayFrame();
304
305 // Fences have flushed, so the present timestamps should be updated
306 EXPECT_EQ(displayFrame->getActuals().presentTime, 42);
307 EXPECT_EQ(presentedSurfaceFrame1.getActuals().presentTime, 42);
308 EXPECT_EQ(presentedSurfaceFrame2.getActuals().presentTime, 42);
309 EXPECT_NE(surfaceFrame1->getJankType(), std::nullopt);
310 EXPECT_NE(surfaceFrame2->getJankType(), std::nullopt);
311 }
312
TEST_F(FrameTimelineTest,displayFramesSlidingWindowMovesAfterLimit)313 TEST_F(FrameTimelineTest, displayFramesSlidingWindowMovesAfterLimit) {
314 // Insert kMaxDisplayFrames' count of DisplayFrames to fill the deque
315 int frameTimeFactor = 0;
316 // Layer specific increment
317 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_))
318 .Times(static_cast<int32_t>(*maxDisplayFrames));
319 for (size_t i = 0; i < *maxDisplayFrames; i++) {
320 auto presentFence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
321 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions(
322 {10 + frameTimeFactor, 20 + frameTimeFactor, 30 + frameTimeFactor});
323 int64_t sfToken = mTokenManager->generateTokenForPredictions(
324 {22 + frameTimeFactor, 26 + frameTimeFactor, 30 + frameTimeFactor});
325 auto surfaceFrame =
326 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken, sInputEventId},
327 sPidOne, sUidOne, sLayerIdOne,
328 sLayerNameOne, sLayerNameOne,
329 /*isBuffer*/ true, sGameMode);
330 mFrameTimeline->setSfWakeUp(sfToken, 22 + frameTimeFactor, Fps::fromPeriodNsecs(11));
331 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
332 mFrameTimeline->addSurfaceFrame(surfaceFrame);
333 mFrameTimeline->setSfPresent(27 + frameTimeFactor, presentFence);
334 presentFence->signalForTest(32 + frameTimeFactor);
335 frameTimeFactor += 30;
336 }
337 auto displayFrame0 = getDisplayFrame(0);
338
339 // The 0th Display Frame should have actuals 22, 27, 32
340 EXPECT_EQ(compareTimelineItems(displayFrame0->getActuals(), TimelineItem(22, 27, 32)), true);
341
342 // Add one more display frame
343 auto presentFence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
344 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions(
345 {10 + frameTimeFactor, 20 + frameTimeFactor, 30 + frameTimeFactor});
346 int64_t sfToken = mTokenManager->generateTokenForPredictions(
347 {22 + frameTimeFactor, 26 + frameTimeFactor, 30 + frameTimeFactor});
348 auto surfaceFrame =
349 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken, sInputEventId}, sPidOne,
350 sUidOne, sLayerIdOne, sLayerNameOne,
351 sLayerNameOne, /*isBuffer*/ true, sGameMode);
352 mFrameTimeline->setSfWakeUp(sfToken, 22 + frameTimeFactor, Fps::fromPeriodNsecs(11));
353 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
354 mFrameTimeline->addSurfaceFrame(surfaceFrame);
355 mFrameTimeline->setSfPresent(27 + frameTimeFactor, presentFence);
356 presentFence->signalForTest(32 + frameTimeFactor);
357 displayFrame0 = getDisplayFrame(0);
358
359 // The window should have slided by 1 now and the previous 0th display frame
360 // should have been removed from the deque
361 EXPECT_EQ(compareTimelineItems(displayFrame0->getActuals(), TimelineItem(52, 57, 62)), true);
362 }
363
TEST_F(FrameTimelineTest,surfaceFrameEndTimeAcquireFenceAfterQueue)364 TEST_F(FrameTimelineTest, surfaceFrameEndTimeAcquireFenceAfterQueue) {
365 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken({}, sPidOne, 0, sLayerIdOne,
366 "acquireFenceAfterQueue",
367 "acquireFenceAfterQueue",
368 /*isBuffer*/ true, sGameMode);
369 surfaceFrame->setActualQueueTime(123);
370 surfaceFrame->setAcquireFenceTime(456);
371 EXPECT_EQ(surfaceFrame->getActuals().endTime, 456);
372 }
373
TEST_F(FrameTimelineTest,surfaceFrameEndTimeAcquireFenceBeforeQueue)374 TEST_F(FrameTimelineTest, surfaceFrameEndTimeAcquireFenceBeforeQueue) {
375 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken({}, sPidOne, 0, sLayerIdOne,
376 "acquireFenceAfterQueue",
377 "acquireFenceAfterQueue",
378 /*isBuffer*/ true, sGameMode);
379 surfaceFrame->setActualQueueTime(456);
380 surfaceFrame->setAcquireFenceTime(123);
381 EXPECT_EQ(surfaceFrame->getActuals().endTime, 456);
382 }
383
TEST_F(FrameTimelineTest,setMaxDisplayFramesSetsSizeProperly)384 TEST_F(FrameTimelineTest, setMaxDisplayFramesSetsSizeProperly) {
385 auto presentFence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
386 presentFence->signalForTest(2);
387
388 // Size shouldn't exceed maxDisplayFrames - 64
389 for (size_t i = 0; i < *maxDisplayFrames + 10; i++) {
390 auto surfaceFrame =
391 mFrameTimeline->createSurfaceFrameForToken({}, sPidOne, sUidOne, sLayerIdOne,
392 sLayerNameOne, sLayerNameOne,
393 /*isBuffer*/ true, sGameMode);
394 int64_t sfToken = mTokenManager->generateTokenForPredictions({22, 26, 30});
395 mFrameTimeline->setSfWakeUp(sfToken, 22, Fps::fromPeriodNsecs(11));
396 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
397 mFrameTimeline->addSurfaceFrame(surfaceFrame);
398 mFrameTimeline->setSfPresent(27, presentFence);
399 }
400 EXPECT_EQ(getNumberOfDisplayFrames(), *maxDisplayFrames);
401
402 // Increase the size to 256
403 mFrameTimeline->setMaxDisplayFrames(256);
404 EXPECT_EQ(*maxDisplayFrames, 256u);
405
406 for (size_t i = 0; i < *maxDisplayFrames + 10; i++) {
407 auto surfaceFrame =
408 mFrameTimeline->createSurfaceFrameForToken({}, sPidOne, sUidOne, sLayerIdOne,
409 sLayerNameOne, sLayerNameOne,
410 /*isBuffer*/ true, sGameMode);
411 int64_t sfToken = mTokenManager->generateTokenForPredictions({22, 26, 30});
412 mFrameTimeline->setSfWakeUp(sfToken, 22, Fps::fromPeriodNsecs(11));
413 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
414 mFrameTimeline->addSurfaceFrame(surfaceFrame);
415 mFrameTimeline->setSfPresent(27, presentFence);
416 }
417 EXPECT_EQ(getNumberOfDisplayFrames(), *maxDisplayFrames);
418
419 // Shrink the size to 128
420 mFrameTimeline->setMaxDisplayFrames(128);
421 EXPECT_EQ(*maxDisplayFrames, 128u);
422
423 for (size_t i = 0; i < *maxDisplayFrames + 10; i++) {
424 auto surfaceFrame =
425 mFrameTimeline->createSurfaceFrameForToken({}, sPidOne, sUidOne, sLayerIdOne,
426 sLayerNameOne, sLayerNameOne,
427 /*isBuffer*/ true, sGameMode);
428 int64_t sfToken = mTokenManager->generateTokenForPredictions({22, 26, 30});
429 mFrameTimeline->setSfWakeUp(sfToken, 22, Fps::fromPeriodNsecs(11));
430 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
431 mFrameTimeline->addSurfaceFrame(surfaceFrame);
432 mFrameTimeline->setSfPresent(27, presentFence);
433 }
434 EXPECT_EQ(getNumberOfDisplayFrames(), *maxDisplayFrames);
435 }
436
TEST_F(FrameTimelineTest,presentFenceSignaled_invalidSignalTime)437 TEST_F(FrameTimelineTest, presentFenceSignaled_invalidSignalTime) {
438 Fps refreshRate = Fps::fromPeriodNsecs(11);
439
440 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
441 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 60});
442 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({52, 60, 60});
443
444 auto surfaceFrame1 =
445 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
446 sUidOne, sLayerIdOne, sLayerNameOne,
447 sLayerNameOne, /*isBuffer*/ true, sGameMode);
448 mFrameTimeline->setSfWakeUp(sfToken1, 52, refreshRate);
449 surfaceFrame1->setAcquireFenceTime(20);
450 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
451 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
452
453 mFrameTimeline->setSfPresent(59, presentFence1);
454 presentFence1->signalForTest(-1);
455 addEmptyDisplayFrame();
456
457 auto displayFrame0 = getDisplayFrame(0);
458 EXPECT_EQ(displayFrame0->getActuals().presentTime, -1);
459 EXPECT_EQ(displayFrame0->getJankType(), JankType::Unknown);
460 EXPECT_EQ(surfaceFrame1->getActuals().presentTime, -1);
461 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::Unknown);
462 }
463
464 // Tests related to TimeStats
TEST_F(FrameTimelineTest,presentFenceSignaled_doesNotReportForInvalidTokens)465 TEST_F(FrameTimelineTest, presentFenceSignaled_doesNotReportForInvalidTokens) {
466 Fps refreshRate = Fps::fromPeriodNsecs(11);
467 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_)).Times(0);
468 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
469 int64_t surfaceFrameToken1 = -1;
470 int64_t sfToken1 = -1;
471
472 auto surfaceFrame1 =
473 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
474 sUidOne, sLayerIdOne, sLayerNameOne,
475 sLayerNameOne, /*isBuffer*/ true, sGameMode);
476 mFrameTimeline->setSfWakeUp(sfToken1, 52, refreshRate);
477 surfaceFrame1->setAcquireFenceTime(20);
478 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
479 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
480 presentFence1->signalForTest(70);
481
482 mFrameTimeline->setSfPresent(59, presentFence1);
483 }
484
TEST_F(FrameTimelineTest,presentFenceSignaled_reportsLongSfCpu)485 TEST_F(FrameTimelineTest, presentFenceSignaled_reportsLongSfCpu) {
486 Fps refreshRate = Fps::fromPeriodNsecs(11);
487 EXPECT_CALL(*mTimeStats,
488 incrementJankyFrames(
489 TimeStats::JankyFramesInfo{refreshRate, std::nullopt, sUidOne,
490 sLayerNameOne, sGameMode,
491 JankType::SurfaceFlingerCpuDeadlineMissed, 2, 10,
492 0}));
493 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
494 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 60});
495 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({52, 60, 60});
496
497 auto surfaceFrame1 =
498 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
499 sUidOne, sLayerIdOne, sLayerNameOne,
500 sLayerNameOne, /*isBuffer*/ true, sGameMode);
501 mFrameTimeline->setSfWakeUp(sfToken1, 52, refreshRate);
502 surfaceFrame1->setAcquireFenceTime(20);
503 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
504 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
505 presentFence1->signalForTest(70);
506
507 mFrameTimeline->setSfPresent(62, presentFence1);
508 }
509
TEST_F(FrameTimelineTest,presentFenceSignaled_reportsLongSfGpu)510 TEST_F(FrameTimelineTest, presentFenceSignaled_reportsLongSfGpu) {
511 Fps refreshRate = Fps::fromPeriodNsecs(11);
512 EXPECT_CALL(*mTimeStats,
513 incrementJankyFrames(
514 TimeStats::JankyFramesInfo{refreshRate, std::nullopt, sUidOne,
515 sLayerNameOne, sGameMode,
516 JankType::SurfaceFlingerGpuDeadlineMissed, 4, 10,
517 0}));
518 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
519 auto gpuFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
520 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 60});
521 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({52, 60, 60});
522
523 auto surfaceFrame1 =
524 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
525 sUidOne, sLayerIdOne, sLayerNameOne,
526 sLayerNameOne, /*isBuffer*/ true, sGameMode);
527 mFrameTimeline->setSfWakeUp(sfToken1, 52, refreshRate);
528 surfaceFrame1->setAcquireFenceTime(20);
529 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
530 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
531 gpuFence1->signalForTest(64);
532 presentFence1->signalForTest(70);
533
534 mFrameTimeline->setSfPresent(59, presentFence1, gpuFence1);
535 }
536
TEST_F(FrameTimelineTest,presentFenceSignaled_reportsDisplayMiss)537 TEST_F(FrameTimelineTest, presentFenceSignaled_reportsDisplayMiss) {
538 Fps refreshRate = Fps::fromPeriodNsecs(30);
539 EXPECT_CALL(*mTimeStats,
540 incrementJankyFrames(TimeStats::JankyFramesInfo{refreshRate, std::nullopt, sUidOne,
541 sLayerNameOne, sGameMode,
542 JankType::DisplayHAL, -4, 0, 0}));
543
544 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
545 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 60});
546 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({52, 60, 60});
547
548 auto surfaceFrame1 =
549 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
550 sUidOne, sLayerIdOne, sLayerNameOne,
551 sLayerNameOne, /*isBuffer*/ true, sGameMode);
552 mFrameTimeline->setSfWakeUp(sfToken1, 52, refreshRate);
553 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
554 surfaceFrame1->setAcquireFenceTime(20);
555 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
556 presentFence1->signalForTest(90);
557 mFrameTimeline->setSfPresent(56, presentFence1);
558 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::DisplayHAL);
559 }
560
TEST_F(FrameTimelineTest,presentFenceSignaled_reportsAppMiss)561 TEST_F(FrameTimelineTest, presentFenceSignaled_reportsAppMiss) {
562 Fps refreshRate = Fps(11.0);
563 EXPECT_CALL(*mTimeStats,
564 incrementJankyFrames(TimeStats::JankyFramesInfo{refreshRate, std::nullopt, sUidOne,
565 sLayerNameOne, sGameMode,
566 JankType::AppDeadlineMissed, -4, 0,
567 25}));
568 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
569 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 60});
570 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({82, 90, 90});
571
572 auto surfaceFrame1 =
573 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
574 sUidOne, sLayerIdOne, sLayerNameOne,
575 sLayerNameOne, /*isBuffer*/ true, sGameMode);
576 surfaceFrame1->setAcquireFenceTime(45);
577 mFrameTimeline->setSfWakeUp(sfToken1, 52, refreshRate);
578
579 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
580 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
581 presentFence1->signalForTest(90);
582 mFrameTimeline->setSfPresent(86, presentFence1);
583
584 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::AppDeadlineMissed);
585 }
586
TEST_F(FrameTimelineTest,presentFenceSignaled_reportsSfScheduling)587 TEST_F(FrameTimelineTest, presentFenceSignaled_reportsSfScheduling) {
588 Fps refreshRate = Fps::fromPeriodNsecs(32);
589 EXPECT_CALL(*mTimeStats,
590 incrementJankyFrames(TimeStats::JankyFramesInfo{refreshRate, std::nullopt, sUidOne,
591 sLayerNameOne, sGameMode,
592 JankType::SurfaceFlingerScheduling,
593 -4, 0, -10}));
594 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
595 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({40, 60, 92});
596 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({52, 60, 60});
597
598 auto surfaceFrame1 =
599 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
600 sUidOne, sLayerIdOne, sLayerNameOne,
601 sLayerNameOne, /*isBuffer*/ true, sGameMode);
602 surfaceFrame1->setAcquireFenceTime(50);
603 mFrameTimeline->setSfWakeUp(sfToken1, 52, refreshRate);
604
605 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
606 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
607 presentFence1->signalForTest(60);
608 mFrameTimeline->setSfPresent(56, presentFence1);
609
610 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::SurfaceFlingerScheduling);
611 }
612
TEST_F(FrameTimelineTest,presentFenceSignaled_reportsSfPredictionError)613 TEST_F(FrameTimelineTest, presentFenceSignaled_reportsSfPredictionError) {
614 Fps refreshRate = Fps::fromPeriodNsecs(16);
615 EXPECT_CALL(*mTimeStats,
616 incrementJankyFrames(TimeStats::JankyFramesInfo{refreshRate, std::nullopt, sUidOne,
617 sLayerNameOne, sGameMode,
618 JankType::PredictionError, -4, 5,
619 0}));
620 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
621 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({30, 40, 60});
622 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({52, 60, 60});
623
624 auto surfaceFrame1 =
625 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
626 sUidOne, sLayerIdOne, sLayerNameOne,
627 sLayerNameOne, /*isBuffer*/ true, sGameMode);
628 surfaceFrame1->setAcquireFenceTime(40);
629 mFrameTimeline->setSfWakeUp(sfToken1, 52, refreshRate);
630
631 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
632 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
633 presentFence1->signalForTest(65);
634 mFrameTimeline->setSfPresent(56, presentFence1);
635
636 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::PredictionError);
637 }
638
TEST_F(FrameTimelineTest,presentFenceSignaled_reportsAppBufferStuffing)639 TEST_F(FrameTimelineTest, presentFenceSignaled_reportsAppBufferStuffing) {
640 Fps refreshRate = Fps::fromPeriodNsecs(32);
641 EXPECT_CALL(*mTimeStats,
642 incrementJankyFrames(TimeStats::JankyFramesInfo{refreshRate, std::nullopt, sUidOne,
643 sLayerNameOne, sGameMode,
644 JankType::BufferStuffing, -4, 0,
645 0}));
646 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
647 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({30, 40, 58});
648 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({82, 90, 90});
649
650 auto surfaceFrame1 =
651 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
652 sUidOne, sLayerIdOne, sLayerNameOne,
653 sLayerNameOne, /*isBuffer*/ true, sGameMode);
654 surfaceFrame1->setAcquireFenceTime(40);
655 mFrameTimeline->setSfWakeUp(sfToken1, 82, refreshRate);
656
657 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented,
658 /*previousLatchTime*/ 56);
659 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
660 presentFence1->signalForTest(90);
661 mFrameTimeline->setSfPresent(86, presentFence1);
662
663 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::BufferStuffing);
664 }
665
TEST_F(FrameTimelineTest,presentFenceSignaled_reportsAppMissWithRenderRate)666 TEST_F(FrameTimelineTest, presentFenceSignaled_reportsAppMissWithRenderRate) {
667 Fps refreshRate = Fps::fromPeriodNsecs(11);
668 Fps renderRate = Fps::fromPeriodNsecs(30);
669 EXPECT_CALL(*mTimeStats,
670 incrementJankyFrames(TimeStats::JankyFramesInfo{refreshRate, renderRate, sUidOne,
671 sLayerNameOne, sGameMode,
672 JankType::AppDeadlineMissed, -4, 0,
673 25}));
674 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
675 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 60});
676 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({82, 90, 90});
677
678 auto surfaceFrame1 =
679 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
680 sUidOne, sLayerIdOne, sLayerNameOne,
681 sLayerNameOne, /*isBuffer*/ true, sGameMode);
682 surfaceFrame1->setAcquireFenceTime(45);
683 mFrameTimeline->setSfWakeUp(sfToken1, 52, refreshRate);
684
685 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
686 surfaceFrame1->setRenderRate(renderRate);
687 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
688 presentFence1->signalForTest(90);
689 mFrameTimeline->setSfPresent(86, presentFence1);
690
691 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::AppDeadlineMissed);
692 }
693
TEST_F(FrameTimelineTest,presentFenceSignaled_displayFramePredictionExpiredPresentsSurfaceFrame)694 TEST_F(FrameTimelineTest, presentFenceSignaled_displayFramePredictionExpiredPresentsSurfaceFrame) {
695 Fps refreshRate = Fps::fromPeriodNsecs(11);
696 Fps renderRate = Fps::fromPeriodNsecs(30);
697
698 EXPECT_CALL(*mTimeStats,
699 incrementJankyFrames(
700 TimeStats::JankyFramesInfo{refreshRate, renderRate, sUidOne, sLayerNameOne,
701 sGameMode,
702 JankType::Unknown | JankType::AppDeadlineMissed,
703 0, 0, 25}));
704 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
705 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 60});
706 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({82, 90, 90});
707
708 auto surfaceFrame1 =
709 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
710 sUidOne, sLayerIdOne, sLayerNameOne,
711 sLayerNameOne, /*isBuffer*/ true, sGameMode);
712 surfaceFrame1->setAcquireFenceTime(45);
713 // Trigger a prediction expiry
714 flushTokens();
715 mFrameTimeline->setSfWakeUp(sfToken1, 52, refreshRate);
716
717 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
718 surfaceFrame1->setRenderRate(renderRate);
719 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
720 presentFence1->signalForTest(90);
721 mFrameTimeline->setSfPresent(86, presentFence1);
722
723 auto displayFrame = getDisplayFrame(0);
724 EXPECT_EQ(displayFrame->getJankType(), JankType::Unknown);
725 EXPECT_EQ(displayFrame->getFrameStartMetadata(), FrameStartMetadata::UnknownStart);
726 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::UnknownFinish);
727 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::UnknownPresent);
728
729 EXPECT_EQ(surfaceFrame1->getActuals().presentTime, 90);
730 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::Unknown | JankType::AppDeadlineMissed);
731 }
732
733 /*
734 * Tracing Tests
735 *
736 * Trace packets are flushed all the way only when the next packet is traced.
737 * For example: trace<Display/Surface>Frame() will create a TracePacket but not flush it. Only when
738 * another TracePacket is created, the previous one is guaranteed to be flushed. The following tests
739 * will have additional empty frames created for this reason.
740 */
TEST_F(FrameTimelineTest,tracing_noPacketsSentWithoutTraceStart)741 TEST_F(FrameTimelineTest, tracing_noPacketsSentWithoutTraceStart) {
742 auto tracingSession = getTracingSessionForTest();
743 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
744 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
745 auto surfaceFrame1 =
746 mFrameTimeline->createSurfaceFrameForToken({token1, sInputEventId}, sPidOne, sUidOne,
747 sLayerIdOne, sLayerNameOne, sLayerNameOne,
748 /*isBuffer*/ true, sGameMode);
749
750 // Set up the display frame
751 mFrameTimeline->setSfWakeUp(token1, 20, Fps::fromPeriodNsecs(11));
752 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Dropped);
753 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
754 mFrameTimeline->setSfPresent(25, presentFence1);
755 presentFence1->signalForTest(30);
756
757 addEmptyDisplayFrame();
758
759 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
760 EXPECT_EQ(packets.size(), 0u);
761 }
762
TEST_F(FrameTimelineTest,tracing_sanityTest)763 TEST_F(FrameTimelineTest, tracing_sanityTest) {
764 auto tracingSession = getTracingSessionForTest();
765 // Layer specific increment
766 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_));
767 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
768
769 tracingSession->StartBlocking();
770 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
771 int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
772 auto surfaceFrame1 =
773 mFrameTimeline->createSurfaceFrameForToken({token1, sInputEventId}, sPidOne, sUidOne,
774 sLayerIdOne, sLayerNameOne, sLayerNameOne,
775 /*isBuffer*/ true, sGameMode);
776
777 // Set up the display frame
778 mFrameTimeline->setSfWakeUp(token2, 20, Fps::fromPeriodNsecs(11));
779 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
780 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
781 mFrameTimeline->setSfPresent(25, presentFence1);
782 presentFence1->signalForTest(30);
783
784 addEmptyDisplayFrame();
785 flushTrace();
786 tracingSession->StopBlocking();
787
788 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
789 // Display Frame 1 has 8 packets - 4 from DisplayFrame and 4 from SurfaceFrame.
790 EXPECT_EQ(packets.size(), 8u);
791 }
792
TEST_F(FrameTimelineTest,traceDisplayFrame_invalidTokenDoesNotEmitTracePacket)793 TEST_F(FrameTimelineTest, traceDisplayFrame_invalidTokenDoesNotEmitTracePacket) {
794 auto tracingSession = getTracingSessionForTest();
795 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
796
797 tracingSession->StartBlocking();
798
799 // Set up the display frame
800 mFrameTimeline->setSfWakeUp(-1, 20, Fps::fromPeriodNsecs(11));
801 mFrameTimeline->setSfPresent(25, presentFence1);
802 presentFence1->signalForTest(30);
803
804 addEmptyDisplayFrame();
805 flushTrace();
806 tracingSession->StopBlocking();
807
808 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
809 EXPECT_EQ(packets.size(), 0u);
810 }
811
TEST_F(FrameTimelineTest,traceSurfaceFrame_invalidTokenDoesNotEmitTracePacket)812 TEST_F(FrameTimelineTest, traceSurfaceFrame_invalidTokenDoesNotEmitTracePacket) {
813 auto tracingSession = getTracingSessionForTest();
814 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
815
816 tracingSession->StartBlocking();
817 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
818 auto surfaceFrame1 =
819 mFrameTimeline->createSurfaceFrameForToken({}, sPidOne, sUidOne, sLayerIdOne,
820 sLayerNameOne, sLayerNameOne,
821 /*isBuffer*/ true, sGameMode);
822
823 // Set up the display frame
824 mFrameTimeline->setSfWakeUp(token1, 20, Fps::fromPeriodNsecs(11));
825 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Dropped);
826 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
827 mFrameTimeline->setSfPresent(25, presentFence1);
828 presentFence1->signalForTest(30);
829
830 addEmptyDisplayFrame();
831 flushTrace();
832 tracingSession->StopBlocking();
833
834 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
835 // Display Frame 1 has 4 packets (SurfaceFrame shouldn't be traced since it has an invalid
836 // token).
837 EXPECT_EQ(packets.size(), 4u);
838 }
839
createProtoExpectedDisplayFrameStart(int64_t cookie,int64_t token,pid_t pid)840 ProtoExpectedDisplayFrameStart createProtoExpectedDisplayFrameStart(int64_t cookie, int64_t token,
841 pid_t pid) {
842 ProtoExpectedDisplayFrameStart proto;
843 proto.set_cookie(cookie);
844 proto.set_token(token);
845 proto.set_pid(pid);
846 return proto;
847 }
848
createProtoActualDisplayFrameStart(int64_t cookie,int64_t token,pid_t pid,ProtoPresentType presentType,bool onTimeFinish,bool gpuComposition,ProtoJankType jankType,ProtoPredictionType predictionType)849 ProtoActualDisplayFrameStart createProtoActualDisplayFrameStart(
850 int64_t cookie, int64_t token, pid_t pid, ProtoPresentType presentType, bool onTimeFinish,
851 bool gpuComposition, ProtoJankType jankType, ProtoPredictionType predictionType) {
852 ProtoActualDisplayFrameStart proto;
853 proto.set_cookie(cookie);
854 proto.set_token(token);
855 proto.set_pid(pid);
856 proto.set_present_type(presentType);
857 proto.set_on_time_finish(onTimeFinish);
858 proto.set_gpu_composition(gpuComposition);
859 proto.set_jank_type(jankType);
860 proto.set_prediction_type(predictionType);
861 return proto;
862 }
863
createProtoExpectedSurfaceFrameStart(int64_t cookie,int64_t token,int64_t displayFrameToken,pid_t pid,std::string layerName)864 ProtoExpectedSurfaceFrameStart createProtoExpectedSurfaceFrameStart(int64_t cookie, int64_t token,
865 int64_t displayFrameToken,
866 pid_t pid,
867 std::string layerName) {
868 ProtoExpectedSurfaceFrameStart proto;
869 proto.set_cookie(cookie);
870 proto.set_token(token);
871 proto.set_display_frame_token(displayFrameToken);
872 proto.set_pid(pid);
873 proto.set_layer_name(layerName);
874 return proto;
875 }
876
createProtoActualSurfaceFrameStart(int64_t cookie,int64_t token,int64_t displayFrameToken,pid_t pid,std::string layerName,ProtoPresentType presentType,bool onTimeFinish,bool gpuComposition,ProtoJankType jankType,ProtoPredictionType predictionType,bool isBuffer)877 ProtoActualSurfaceFrameStart createProtoActualSurfaceFrameStart(
878 int64_t cookie, int64_t token, int64_t displayFrameToken, pid_t pid, std::string layerName,
879 ProtoPresentType presentType, bool onTimeFinish, bool gpuComposition,
880 ProtoJankType jankType, ProtoPredictionType predictionType, bool isBuffer) {
881 ProtoActualSurfaceFrameStart proto;
882 proto.set_cookie(cookie);
883 proto.set_token(token);
884 proto.set_display_frame_token(displayFrameToken);
885 proto.set_pid(pid);
886 proto.set_layer_name(layerName);
887 proto.set_present_type(presentType);
888 proto.set_on_time_finish(onTimeFinish);
889 proto.set_gpu_composition(gpuComposition);
890 proto.set_jank_type(jankType);
891 proto.set_prediction_type(predictionType);
892 proto.set_is_buffer(isBuffer);
893 return proto;
894 }
895
createProtoFrameEnd(int64_t cookie)896 ProtoFrameEnd createProtoFrameEnd(int64_t cookie) {
897 ProtoFrameEnd proto;
898 proto.set_cookie(cookie);
899 return proto;
900 }
901
validateTraceEvent(const ProtoExpectedDisplayFrameStart & received,const ProtoExpectedDisplayFrameStart & source)902 void validateTraceEvent(const ProtoExpectedDisplayFrameStart& received,
903 const ProtoExpectedDisplayFrameStart& source) {
904 ASSERT_TRUE(received.has_cookie());
905 EXPECT_EQ(received.cookie(), source.cookie());
906
907 ASSERT_TRUE(received.has_token());
908 EXPECT_EQ(received.token(), source.token());
909
910 ASSERT_TRUE(received.has_pid());
911 EXPECT_EQ(received.pid(), source.pid());
912 }
913
validateTraceEvent(const ProtoActualDisplayFrameStart & received,const ProtoActualDisplayFrameStart & source)914 void validateTraceEvent(const ProtoActualDisplayFrameStart& received,
915 const ProtoActualDisplayFrameStart& source) {
916 ASSERT_TRUE(received.has_cookie());
917 EXPECT_EQ(received.cookie(), source.cookie());
918
919 ASSERT_TRUE(received.has_token());
920 EXPECT_EQ(received.token(), source.token());
921
922 ASSERT_TRUE(received.has_pid());
923 EXPECT_EQ(received.pid(), source.pid());
924
925 ASSERT_TRUE(received.has_present_type());
926 EXPECT_EQ(received.present_type(), source.present_type());
927 ASSERT_TRUE(received.has_on_time_finish());
928 EXPECT_EQ(received.on_time_finish(), source.on_time_finish());
929 ASSERT_TRUE(received.has_gpu_composition());
930 EXPECT_EQ(received.gpu_composition(), source.gpu_composition());
931 ASSERT_TRUE(received.has_jank_type());
932 EXPECT_EQ(received.jank_type(), source.jank_type());
933 ASSERT_TRUE(received.has_prediction_type());
934 EXPECT_EQ(received.prediction_type(), source.prediction_type());
935 }
936
validateTraceEvent(const ProtoExpectedSurfaceFrameStart & received,const ProtoExpectedSurfaceFrameStart & source)937 void validateTraceEvent(const ProtoExpectedSurfaceFrameStart& received,
938 const ProtoExpectedSurfaceFrameStart& source) {
939 ASSERT_TRUE(received.has_cookie());
940 EXPECT_EQ(received.cookie(), source.cookie());
941
942 ASSERT_TRUE(received.has_token());
943 EXPECT_EQ(received.token(), source.token());
944
945 ASSERT_TRUE(received.has_display_frame_token());
946 EXPECT_EQ(received.display_frame_token(), source.display_frame_token());
947
948 ASSERT_TRUE(received.has_pid());
949 EXPECT_EQ(received.pid(), source.pid());
950
951 ASSERT_TRUE(received.has_layer_name());
952 EXPECT_EQ(received.layer_name(), source.layer_name());
953 }
954
validateTraceEvent(const ProtoActualSurfaceFrameStart & received,const ProtoActualSurfaceFrameStart & source)955 void validateTraceEvent(const ProtoActualSurfaceFrameStart& received,
956 const ProtoActualSurfaceFrameStart& source) {
957 ASSERT_TRUE(received.has_cookie());
958 EXPECT_EQ(received.cookie(), source.cookie());
959
960 ASSERT_TRUE(received.has_token());
961 EXPECT_EQ(received.token(), source.token());
962
963 ASSERT_TRUE(received.has_display_frame_token());
964 EXPECT_EQ(received.display_frame_token(), source.display_frame_token());
965
966 ASSERT_TRUE(received.has_pid());
967 EXPECT_EQ(received.pid(), source.pid());
968
969 ASSERT_TRUE(received.has_layer_name());
970 EXPECT_EQ(received.layer_name(), source.layer_name());
971
972 ASSERT_TRUE(received.has_present_type());
973 EXPECT_EQ(received.present_type(), source.present_type());
974 ASSERT_TRUE(received.has_on_time_finish());
975 EXPECT_EQ(received.on_time_finish(), source.on_time_finish());
976 ASSERT_TRUE(received.has_gpu_composition());
977 EXPECT_EQ(received.gpu_composition(), source.gpu_composition());
978 ASSERT_TRUE(received.has_jank_type());
979 EXPECT_EQ(received.jank_type(), source.jank_type());
980 ASSERT_TRUE(received.has_prediction_type());
981 EXPECT_EQ(received.prediction_type(), source.prediction_type());
982 ASSERT_TRUE(received.has_is_buffer());
983 EXPECT_EQ(received.is_buffer(), source.is_buffer());
984 }
985
validateTraceEvent(const ProtoFrameEnd & received,const ProtoFrameEnd & source)986 void validateTraceEvent(const ProtoFrameEnd& received, const ProtoFrameEnd& source) {
987 ASSERT_TRUE(received.has_cookie());
988 EXPECT_EQ(received.cookie(), source.cookie());
989 }
990
TEST_F(FrameTimelineTest,traceDisplayFrame_emitsValidTracePacket)991 TEST_F(FrameTimelineTest, traceDisplayFrame_emitsValidTracePacket) {
992 auto tracingSession = getTracingSessionForTest();
993 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
994
995 tracingSession->StartBlocking();
996 int64_t displayFrameToken1 = mTokenManager->generateTokenForPredictions({10, 30, 30});
997
998 // Set up the display frame
999 mFrameTimeline->setSfWakeUp(displayFrameToken1, 20, Fps::fromPeriodNsecs(11));
1000 mFrameTimeline->setSfPresent(26, presentFence1);
1001 presentFence1->signalForTest(31);
1002
1003 int64_t traceCookie = snoopCurrentTraceCookie();
1004 auto protoExpectedDisplayFrameStart =
1005 createProtoExpectedDisplayFrameStart(traceCookie + 1, displayFrameToken1,
1006 kSurfaceFlingerPid);
1007 auto protoExpectedDisplayFrameEnd = createProtoFrameEnd(traceCookie + 1);
1008 auto protoActualDisplayFrameStart =
1009 createProtoActualDisplayFrameStart(traceCookie + 2, displayFrameToken1,
1010 kSurfaceFlingerPid,
1011 FrameTimelineEvent::PRESENT_ON_TIME, true, false,
1012 FrameTimelineEvent::JANK_NONE,
1013 FrameTimelineEvent::PREDICTION_VALID);
1014 auto protoActualDisplayFrameEnd = createProtoFrameEnd(traceCookie + 2);
1015
1016 addEmptyDisplayFrame();
1017 flushTrace();
1018 tracingSession->StopBlocking();
1019
1020 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
1021 EXPECT_EQ(packets.size(), 4u);
1022
1023 // Packet - 0 : ExpectedDisplayFrameStart
1024 const auto& packet0 = packets[0];
1025 ASSERT_TRUE(packet0.has_timestamp());
1026 EXPECT_EQ(packet0.timestamp(), 10u);
1027 ASSERT_TRUE(packet0.has_frame_timeline_event());
1028
1029 const auto& event0 = packet0.frame_timeline_event();
1030 ASSERT_TRUE(event0.has_expected_display_frame_start());
1031 const auto& expectedDisplayFrameStart = event0.expected_display_frame_start();
1032 validateTraceEvent(expectedDisplayFrameStart, protoExpectedDisplayFrameStart);
1033
1034 // Packet - 1 : FrameEnd (ExpectedDisplayFrame)
1035 const auto& packet1 = packets[1];
1036 ASSERT_TRUE(packet1.has_timestamp());
1037 EXPECT_EQ(packet1.timestamp(), 30u);
1038 ASSERT_TRUE(packet1.has_frame_timeline_event());
1039
1040 const auto& event1 = packet1.frame_timeline_event();
1041 ASSERT_TRUE(event1.has_frame_end());
1042 const auto& expectedDisplayFrameEnd = event1.frame_end();
1043 validateTraceEvent(expectedDisplayFrameEnd, protoExpectedDisplayFrameEnd);
1044
1045 // Packet - 2 : ActualDisplayFrameStart
1046 const auto& packet2 = packets[2];
1047 ASSERT_TRUE(packet2.has_timestamp());
1048 EXPECT_EQ(packet2.timestamp(), 20u);
1049 ASSERT_TRUE(packet2.has_frame_timeline_event());
1050
1051 const auto& event2 = packet2.frame_timeline_event();
1052 ASSERT_TRUE(event2.has_actual_display_frame_start());
1053 const auto& actualDisplayFrameStart = event2.actual_display_frame_start();
1054 validateTraceEvent(actualDisplayFrameStart, protoActualDisplayFrameStart);
1055
1056 // Packet - 3 : FrameEnd (ActualDisplayFrame)
1057 const auto& packet3 = packets[3];
1058 ASSERT_TRUE(packet3.has_timestamp());
1059 EXPECT_EQ(packet3.timestamp(), 31u);
1060 ASSERT_TRUE(packet3.has_frame_timeline_event());
1061
1062 const auto& event3 = packet3.frame_timeline_event();
1063 ASSERT_TRUE(event3.has_frame_end());
1064 const auto& actualDisplayFrameEnd = event3.frame_end();
1065 validateTraceEvent(actualDisplayFrameEnd, protoActualDisplayFrameEnd);
1066 }
1067
TEST_F(FrameTimelineTest,traceDisplayFrame_predictionExpiredDoesNotTraceExpectedTimeline)1068 TEST_F(FrameTimelineTest, traceDisplayFrame_predictionExpiredDoesNotTraceExpectedTimeline) {
1069 auto tracingSession = getTracingSessionForTest();
1070 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1071
1072 tracingSession->StartBlocking();
1073 int64_t displayFrameToken1 = mTokenManager->generateTokenForPredictions({10, 25, 30});
1074 // Flush the token so that it would expire
1075 flushTokens();
1076
1077 // Set up the display frame
1078 mFrameTimeline->setSfWakeUp(displayFrameToken1, 20, Fps::fromPeriodNsecs(11));
1079 mFrameTimeline->setSfPresent(26, presentFence1);
1080 presentFence1->signalForTest(31);
1081
1082 int64_t traceCookie = snoopCurrentTraceCookie();
1083
1084 auto protoActualDisplayFrameStart =
1085 createProtoActualDisplayFrameStart(traceCookie + 1, displayFrameToken1,
1086 kSurfaceFlingerPid,
1087 FrameTimelineEvent::PRESENT_UNSPECIFIED, false,
1088 false, FrameTimelineEvent::JANK_UNKNOWN,
1089 FrameTimelineEvent::PREDICTION_EXPIRED);
1090 auto protoActualDisplayFrameEnd = createProtoFrameEnd(traceCookie + 1);
1091
1092 addEmptyDisplayFrame();
1093 flushTrace();
1094 tracingSession->StopBlocking();
1095
1096 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
1097 // Only actual timeline packets should be in the trace
1098 EXPECT_EQ(packets.size(), 2u);
1099
1100 // Packet - 0 : ActualDisplayFrameStart
1101 const auto& packet0 = packets[0];
1102 ASSERT_TRUE(packet0.has_timestamp());
1103 EXPECT_EQ(packet0.timestamp(), 20u);
1104 ASSERT_TRUE(packet0.has_frame_timeline_event());
1105
1106 const auto& event0 = packet0.frame_timeline_event();
1107 ASSERT_TRUE(event0.has_actual_display_frame_start());
1108 const auto& actualDisplayFrameStart = event0.actual_display_frame_start();
1109 validateTraceEvent(actualDisplayFrameStart, protoActualDisplayFrameStart);
1110
1111 // Packet - 1 : FrameEnd (ActualDisplayFrame)
1112 const auto& packet1 = packets[1];
1113 ASSERT_TRUE(packet1.has_timestamp());
1114 EXPECT_EQ(packet1.timestamp(), 31u);
1115 ASSERT_TRUE(packet1.has_frame_timeline_event());
1116
1117 const auto& event1 = packet1.frame_timeline_event();
1118 ASSERT_TRUE(event1.has_frame_end());
1119 const auto& actualDisplayFrameEnd = event1.frame_end();
1120 validateTraceEvent(actualDisplayFrameEnd, protoActualDisplayFrameEnd);
1121 }
1122
TEST_F(FrameTimelineTest,traceSurfaceFrame_emitsValidTracePacket)1123 TEST_F(FrameTimelineTest, traceSurfaceFrame_emitsValidTracePacket) {
1124 auto tracingSession = getTracingSessionForTest();
1125 // Layer specific increment
1126 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_));
1127 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1128 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1129
1130 tracingSession->StartBlocking();
1131 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions({10, 25, 40});
1132 int64_t displayFrameToken1 = mTokenManager->generateTokenForPredictions({30, 35, 40});
1133
1134 auto surfaceFrame1 =
1135 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken, sInputEventId}, sPidOne,
1136 sUidOne, sLayerIdOne, sLayerNameOne,
1137 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1138 auto surfaceFrame2 =
1139 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken, sInputEventId}, sPidOne,
1140 sUidOne, sLayerIdOne, sLayerNameOne,
1141 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1142 surfaceFrame1->setActualQueueTime(10);
1143 surfaceFrame1->setDropTime(15);
1144
1145 surfaceFrame2->setActualQueueTime(15);
1146 surfaceFrame2->setAcquireFenceTime(20);
1147
1148 // First 2 cookies will be used by the DisplayFrame
1149 int64_t traceCookie = snoopCurrentTraceCookie() + 2;
1150
1151 auto protoDroppedSurfaceFrameExpectedStart =
1152 createProtoExpectedSurfaceFrameStart(traceCookie + 1, surfaceFrameToken,
1153 displayFrameToken1, sPidOne, sLayerNameOne);
1154 auto protoDroppedSurfaceFrameExpectedEnd = createProtoFrameEnd(traceCookie + 1);
1155 auto protoDroppedSurfaceFrameActualStart =
1156 createProtoActualSurfaceFrameStart(traceCookie + 2, surfaceFrameToken,
1157 displayFrameToken1, sPidOne, sLayerNameOne,
1158 FrameTimelineEvent::PRESENT_DROPPED, false, false,
1159 FrameTimelineEvent::JANK_NONE,
1160 FrameTimelineEvent::PREDICTION_VALID, true);
1161 auto protoDroppedSurfaceFrameActualEnd = createProtoFrameEnd(traceCookie + 2);
1162
1163 auto protoPresentedSurfaceFrameExpectedStart =
1164 createProtoExpectedSurfaceFrameStart(traceCookie + 3, surfaceFrameToken,
1165 displayFrameToken1, sPidOne, sLayerNameOne);
1166 auto protoPresentedSurfaceFrameExpectedEnd = createProtoFrameEnd(traceCookie + 3);
1167 auto protoPresentedSurfaceFrameActualStart =
1168 createProtoActualSurfaceFrameStart(traceCookie + 4, surfaceFrameToken,
1169 displayFrameToken1, sPidOne, sLayerNameOne,
1170 FrameTimelineEvent::PRESENT_ON_TIME, true, false,
1171 FrameTimelineEvent::JANK_NONE,
1172 FrameTimelineEvent::PREDICTION_VALID, true);
1173 auto protoPresentedSurfaceFrameActualEnd = createProtoFrameEnd(traceCookie + 4);
1174
1175 // Set up the display frame
1176 mFrameTimeline->setSfWakeUp(displayFrameToken1, 20, Fps::fromPeriodNsecs(11));
1177 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Dropped);
1178 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
1179 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1180 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1181 mFrameTimeline->setSfPresent(26, presentFence1);
1182 presentFence1->signalForTest(40);
1183
1184 addEmptyDisplayFrame();
1185 flushTrace();
1186 tracingSession->StopBlocking();
1187
1188 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
1189 // 4 DisplayFrame + 4 DroppedSurfaceFrame + 4 PresentedSurfaceFrame
1190 EXPECT_EQ(packets.size(), 12u);
1191
1192 // Packet - 4 : ExpectedSurfaceFrameStart1
1193 const auto& packet4 = packets[4];
1194 ASSERT_TRUE(packet4.has_timestamp());
1195 EXPECT_EQ(packet4.timestamp(), 10u);
1196 ASSERT_TRUE(packet4.has_frame_timeline_event());
1197
1198 const auto& event4 = packet4.frame_timeline_event();
1199 ASSERT_TRUE(event4.has_expected_surface_frame_start());
1200 const auto& expectedSurfaceFrameStart1 = event4.expected_surface_frame_start();
1201 validateTraceEvent(expectedSurfaceFrameStart1, protoDroppedSurfaceFrameExpectedStart);
1202
1203 // Packet - 5 : FrameEnd (ExpectedSurfaceFrame1)
1204 const auto& packet5 = packets[5];
1205 ASSERT_TRUE(packet5.has_timestamp());
1206 EXPECT_EQ(packet5.timestamp(), 25u);
1207 ASSERT_TRUE(packet5.has_frame_timeline_event());
1208
1209 const auto& event5 = packet5.frame_timeline_event();
1210 ASSERT_TRUE(event5.has_frame_end());
1211 const auto& expectedSurfaceFrameEnd1 = event5.frame_end();
1212 validateTraceEvent(expectedSurfaceFrameEnd1, protoDroppedSurfaceFrameExpectedEnd);
1213
1214 // Packet - 6 : ActualSurfaceFrameStart1
1215 const auto& packet6 = packets[6];
1216 ASSERT_TRUE(packet6.has_timestamp());
1217 EXPECT_EQ(packet6.timestamp(), 10u);
1218 ASSERT_TRUE(packet6.has_frame_timeline_event());
1219
1220 const auto& event6 = packet6.frame_timeline_event();
1221 ASSERT_TRUE(event6.has_actual_surface_frame_start());
1222 const auto& actualSurfaceFrameStart1 = event6.actual_surface_frame_start();
1223 validateTraceEvent(actualSurfaceFrameStart1, protoDroppedSurfaceFrameActualStart);
1224
1225 // Packet - 7 : FrameEnd (ActualSurfaceFrame1)
1226 const auto& packet7 = packets[7];
1227 ASSERT_TRUE(packet7.has_timestamp());
1228 EXPECT_EQ(packet7.timestamp(), 15u);
1229 ASSERT_TRUE(packet7.has_frame_timeline_event());
1230
1231 const auto& event7 = packet7.frame_timeline_event();
1232 ASSERT_TRUE(event7.has_frame_end());
1233 const auto& actualSurfaceFrameEnd1 = event7.frame_end();
1234 validateTraceEvent(actualSurfaceFrameEnd1, protoDroppedSurfaceFrameActualEnd);
1235
1236 // Packet - 8 : ExpectedSurfaceFrameStart2
1237 const auto& packet8 = packets[8];
1238 ASSERT_TRUE(packet8.has_timestamp());
1239 EXPECT_EQ(packet8.timestamp(), 10u);
1240 ASSERT_TRUE(packet8.has_frame_timeline_event());
1241
1242 const auto& event8 = packet8.frame_timeline_event();
1243 ASSERT_TRUE(event8.has_expected_surface_frame_start());
1244 const auto& expectedSurfaceFrameStart2 = event8.expected_surface_frame_start();
1245 validateTraceEvent(expectedSurfaceFrameStart2, protoPresentedSurfaceFrameExpectedStart);
1246
1247 // Packet - 9 : FrameEnd (ExpectedSurfaceFrame2)
1248 const auto& packet9 = packets[9];
1249 ASSERT_TRUE(packet9.has_timestamp());
1250 EXPECT_EQ(packet9.timestamp(), 25u);
1251 ASSERT_TRUE(packet9.has_frame_timeline_event());
1252
1253 const auto& event9 = packet9.frame_timeline_event();
1254 ASSERT_TRUE(event9.has_frame_end());
1255 const auto& expectedSurfaceFrameEnd2 = event9.frame_end();
1256 validateTraceEvent(expectedSurfaceFrameEnd2, protoPresentedSurfaceFrameExpectedEnd);
1257
1258 // Packet - 10 : ActualSurfaceFrameStart2
1259 const auto& packet10 = packets[10];
1260 ASSERT_TRUE(packet10.has_timestamp());
1261 EXPECT_EQ(packet10.timestamp(), 10u);
1262 ASSERT_TRUE(packet10.has_frame_timeline_event());
1263
1264 const auto& event10 = packet10.frame_timeline_event();
1265 ASSERT_TRUE(event10.has_actual_surface_frame_start());
1266 const auto& actualSurfaceFrameStart2 = event10.actual_surface_frame_start();
1267 validateTraceEvent(actualSurfaceFrameStart2, protoPresentedSurfaceFrameActualStart);
1268
1269 // Packet - 11 : FrameEnd (ActualSurfaceFrame2)
1270 const auto& packet11 = packets[11];
1271 ASSERT_TRUE(packet11.has_timestamp());
1272 EXPECT_EQ(packet11.timestamp(), 20u);
1273 ASSERT_TRUE(packet11.has_frame_timeline_event());
1274
1275 const auto& event11 = packet11.frame_timeline_event();
1276 ASSERT_TRUE(event11.has_frame_end());
1277 const auto& actualSurfaceFrameEnd2 = event11.frame_end();
1278 validateTraceEvent(actualSurfaceFrameEnd2, protoPresentedSurfaceFrameActualEnd);
1279 }
1280
TEST_F(FrameTimelineTest,traceSurfaceFrame_predictionExpiredDoesNotTraceExpectedTimeline)1281 TEST_F(FrameTimelineTest, traceSurfaceFrame_predictionExpiredDoesNotTraceExpectedTimeline) {
1282 auto tracingSession = getTracingSessionForTest();
1283 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1284
1285 tracingSession->StartBlocking();
1286 constexpr nsecs_t appStartTime = std::chrono::nanoseconds(10ms).count();
1287 constexpr nsecs_t appEndTime = std::chrono::nanoseconds(20ms).count();
1288 constexpr nsecs_t appPresentTime = std::chrono::nanoseconds(30ms).count();
1289 int64_t surfaceFrameToken =
1290 mTokenManager->generateTokenForPredictions({appStartTime, appEndTime, appPresentTime});
1291
1292 // Flush the token so that it would expire
1293 flushTokens();
1294 auto surfaceFrame1 =
1295 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken, /*inputEventId*/ 0},
1296 sPidOne, sUidOne, sLayerIdOne, sLayerNameOne,
1297 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1298 surfaceFrame1->setActualQueueTime(appEndTime);
1299 surfaceFrame1->setAcquireFenceTime(appEndTime);
1300
1301 constexpr nsecs_t sfStartTime = std::chrono::nanoseconds(20ms).count();
1302 constexpr nsecs_t sfEndTime = std::chrono::nanoseconds(30ms).count();
1303 constexpr nsecs_t sfPresentTime = std::chrono::nanoseconds(30ms).count();
1304 int64_t displayFrameToken =
1305 mTokenManager->generateTokenForPredictions({sfStartTime, sfEndTime, sfPresentTime});
1306
1307 // First 2 cookies will be used by the DisplayFrame
1308 int64_t traceCookie = snoopCurrentTraceCookie() + 2;
1309
1310 auto protoActualSurfaceFrameStart =
1311 createProtoActualSurfaceFrameStart(traceCookie + 1, surfaceFrameToken,
1312 displayFrameToken, sPidOne, sLayerNameOne,
1313 FrameTimelineEvent::PRESENT_UNSPECIFIED, false,
1314 false, FrameTimelineEvent::JANK_UNKNOWN,
1315 FrameTimelineEvent::PREDICTION_EXPIRED, true);
1316 auto protoActualSurfaceFrameEnd = createProtoFrameEnd(traceCookie + 1);
1317
1318 // Set up the display frame
1319 mFrameTimeline->setSfWakeUp(displayFrameToken, sfStartTime, Fps::fromPeriodNsecs(11));
1320 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1321 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1322 mFrameTimeline->setSfPresent(sfEndTime, presentFence1);
1323 presentFence1->signalForTest(sfPresentTime);
1324
1325 addEmptyDisplayFrame();
1326 flushTrace();
1327 tracingSession->StopBlocking();
1328
1329 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
1330 // Display Frame 4 packets + SurfaceFrame 2 packets
1331 ASSERT_EQ(packets.size(), 6u);
1332
1333 // Packet - 4 : ActualSurfaceFrameStart
1334 const auto& packet4 = packets[4];
1335 ASSERT_TRUE(packet4.has_timestamp());
1336 EXPECT_EQ(packet4.timestamp(),
1337 static_cast<uint64_t>(appEndTime - SurfaceFrame::kPredictionExpiredStartTimeDelta));
1338 ASSERT_TRUE(packet4.has_frame_timeline_event());
1339
1340 const auto& event4 = packet4.frame_timeline_event();
1341 ASSERT_TRUE(event4.has_actual_surface_frame_start());
1342 const auto& actualSurfaceFrameStart = event4.actual_surface_frame_start();
1343 validateTraceEvent(actualSurfaceFrameStart, protoActualSurfaceFrameStart);
1344
1345 // Packet - 5 : FrameEnd (ActualSurfaceFrame)
1346 const auto& packet5 = packets[5];
1347 ASSERT_TRUE(packet5.has_timestamp());
1348 EXPECT_EQ(packet5.timestamp(), static_cast<uint64_t>(appEndTime));
1349 ASSERT_TRUE(packet5.has_frame_timeline_event());
1350
1351 const auto& event5 = packet5.frame_timeline_event();
1352 ASSERT_TRUE(event5.has_frame_end());
1353 const auto& actualSurfaceFrameEnd = event5.frame_end();
1354 validateTraceEvent(actualSurfaceFrameEnd, protoActualSurfaceFrameEnd);
1355 }
1356
TEST_F(FrameTimelineTest,traceSurfaceFrame_predictionExpiredDroppedFramesTracedProperly)1357 TEST_F(FrameTimelineTest, traceSurfaceFrame_predictionExpiredDroppedFramesTracedProperly) {
1358 auto tracingSession = getTracingSessionForTest();
1359 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1360
1361 tracingSession->StartBlocking();
1362 constexpr nsecs_t appStartTime = std::chrono::nanoseconds(10ms).count();
1363 constexpr nsecs_t appEndTime = std::chrono::nanoseconds(20ms).count();
1364 constexpr nsecs_t appPresentTime = std::chrono::nanoseconds(30ms).count();
1365 int64_t surfaceFrameToken =
1366 mTokenManager->generateTokenForPredictions({appStartTime, appEndTime, appPresentTime});
1367
1368 // Flush the token so that it would expire
1369 flushTokens();
1370 auto surfaceFrame1 =
1371 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken, /*inputEventId*/ 0},
1372 sPidOne, sUidOne, sLayerIdOne, sLayerNameOne,
1373 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1374
1375 constexpr nsecs_t sfStartTime = std::chrono::nanoseconds(22ms).count();
1376 constexpr nsecs_t sfEndTime = std::chrono::nanoseconds(30ms).count();
1377 constexpr nsecs_t sfPresentTime = std::chrono::nanoseconds(30ms).count();
1378 int64_t displayFrameToken =
1379 mTokenManager->generateTokenForPredictions({sfStartTime, sfEndTime, sfPresentTime});
1380
1381 // First 2 cookies will be used by the DisplayFrame
1382 int64_t traceCookie = snoopCurrentTraceCookie() + 2;
1383
1384 auto protoActualSurfaceFrameStart =
1385 createProtoActualSurfaceFrameStart(traceCookie + 1, surfaceFrameToken,
1386 displayFrameToken, sPidOne, sLayerNameOne,
1387 FrameTimelineEvent::PRESENT_DROPPED, false, false,
1388 FrameTimelineEvent::JANK_NONE,
1389 FrameTimelineEvent::PREDICTION_EXPIRED, true);
1390 auto protoActualSurfaceFrameEnd = createProtoFrameEnd(traceCookie + 1);
1391
1392 // Set up the display frame
1393 mFrameTimeline->setSfWakeUp(displayFrameToken, sfStartTime, Fps::fromPeriodNsecs(11));
1394 surfaceFrame1->setDropTime(sfStartTime);
1395 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Dropped);
1396 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1397 mFrameTimeline->setSfPresent(sfEndTime, presentFence1);
1398 presentFence1->signalForTest(sfPresentTime);
1399
1400 addEmptyDisplayFrame();
1401 flushTrace();
1402 tracingSession->StopBlocking();
1403
1404 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
1405 // Display Frame 4 packets + SurfaceFrame 2 packets
1406 ASSERT_EQ(packets.size(), 6u);
1407
1408 // Packet - 4 : ActualSurfaceFrameStart
1409 const auto& packet4 = packets[4];
1410 ASSERT_TRUE(packet4.has_timestamp());
1411 EXPECT_EQ(packet4.timestamp(),
1412 static_cast<uint64_t>(sfStartTime - SurfaceFrame::kPredictionExpiredStartTimeDelta));
1413 ASSERT_TRUE(packet4.has_frame_timeline_event());
1414
1415 const auto& event4 = packet4.frame_timeline_event();
1416 ASSERT_TRUE(event4.has_actual_surface_frame_start());
1417 const auto& actualSurfaceFrameStart = event4.actual_surface_frame_start();
1418 validateTraceEvent(actualSurfaceFrameStart, protoActualSurfaceFrameStart);
1419
1420 // Packet - 5 : FrameEnd (ActualSurfaceFrame)
1421 const auto& packet5 = packets[5];
1422 ASSERT_TRUE(packet5.has_timestamp());
1423 EXPECT_EQ(packet5.timestamp(), static_cast<uint64_t>(sfStartTime));
1424 ASSERT_TRUE(packet5.has_frame_timeline_event());
1425
1426 const auto& event5 = packet5.frame_timeline_event();
1427 ASSERT_TRUE(event5.has_frame_end());
1428 const auto& actualSurfaceFrameEnd = event5.frame_end();
1429 validateTraceEvent(actualSurfaceFrameEnd, protoActualSurfaceFrameEnd);
1430 }
1431
1432 // Tests for Jank classification
TEST_F(FrameTimelineTest,jankClassification_presentOnTimeDoesNotClassify)1433 TEST_F(FrameTimelineTest, jankClassification_presentOnTimeDoesNotClassify) {
1434 // Layer specific increment
1435 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_));
1436 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1437 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions({10, 20, 30});
1438 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 30, 30});
1439 auto surfaceFrame =
1440 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken, sInputEventId}, sPidOne,
1441 sUidOne, sLayerIdOne, sLayerNameOne,
1442 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1443 mFrameTimeline->setSfWakeUp(sfToken1, 22, Fps::fromPeriodNsecs(11));
1444 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
1445 mFrameTimeline->addSurfaceFrame(surfaceFrame);
1446 mFrameTimeline->setSfPresent(26, presentFence1);
1447 auto displayFrame = getDisplayFrame(0);
1448 auto& presentedSurfaceFrame = getSurfaceFrame(0, 0);
1449 presentFence1->signalForTest(29);
1450
1451 // Fences haven't been flushed yet, so it should be 0
1452 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
1453 EXPECT_EQ(presentedSurfaceFrame.getActuals().presentTime, 0);
1454
1455 addEmptyDisplayFrame();
1456 displayFrame = getDisplayFrame(0);
1457
1458 // Fences have flushed, so the present timestamps should be updated
1459 EXPECT_EQ(displayFrame->getActuals().presentTime, 29);
1460 EXPECT_EQ(presentedSurfaceFrame.getActuals().presentTime, 29);
1461 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1462 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1463 EXPECT_EQ(displayFrame->getJankType(), JankType::None);
1464 }
1465
TEST_F(FrameTimelineTest,jankClassification_displayFrameOnTimeFinishEarlyPresent)1466 TEST_F(FrameTimelineTest, jankClassification_displayFrameOnTimeFinishEarlyPresent) {
1467 Fps vsyncRate = Fps::fromPeriodNsecs(11);
1468 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1469 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 30, 40});
1470 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 60, 70});
1471 mFrameTimeline->setSfWakeUp(sfToken1, 22, vsyncRate);
1472 mFrameTimeline->setSfPresent(26, presentFence1);
1473 auto displayFrame = getDisplayFrame(0);
1474 presentFence1->signalForTest(30);
1475
1476 // Fences for the first frame haven't been flushed yet, so it should be 0
1477 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
1478
1479 // Trigger a flush by finalizing the next DisplayFrame
1480 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1481 mFrameTimeline->setSfWakeUp(sfToken2, 52, vsyncRate);
1482 mFrameTimeline->setSfPresent(56, presentFence2);
1483 displayFrame = getDisplayFrame(0);
1484
1485 // Fences for the first frame have flushed, so the present timestamps should be updated
1486 EXPECT_EQ(displayFrame->getActuals().presentTime, 30);
1487 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1488 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1489 EXPECT_EQ(displayFrame->getJankType(), JankType::SurfaceFlingerScheduling);
1490
1491 // Fences for the second frame haven't been flushed yet, so it should be 0
1492 auto displayFrame2 = getDisplayFrame(1);
1493 presentFence2->signalForTest(65);
1494 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1495 addEmptyDisplayFrame();
1496 displayFrame2 = getDisplayFrame(1);
1497
1498 // Fences for the second frame have flushed, so the present timestamps should be updated
1499 EXPECT_EQ(displayFrame2->getActuals().presentTime, 65);
1500 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1501 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1502 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
1503 }
1504
TEST_F(FrameTimelineTest,jankClassification_displayFrameOnTimeFinishLatePresent)1505 TEST_F(FrameTimelineTest, jankClassification_displayFrameOnTimeFinishLatePresent) {
1506 Fps vsyncRate = Fps::fromPeriodNsecs(11);
1507 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1508 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 30, 40});
1509 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 60, 70});
1510 mFrameTimeline->setSfWakeUp(sfToken1, 22, vsyncRate);
1511 mFrameTimeline->setSfPresent(26, presentFence1);
1512 auto displayFrame = getDisplayFrame(0);
1513 presentFence1->signalForTest(50);
1514
1515 // Fences for the first frame haven't been flushed yet, so it should be 0
1516 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
1517
1518 // Trigger a flush by finalizing the next DisplayFrame
1519 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1520 mFrameTimeline->setSfWakeUp(sfToken2, 52, vsyncRate);
1521 mFrameTimeline->setSfPresent(56, presentFence2);
1522 displayFrame = getDisplayFrame(0);
1523
1524 // Fences for the first frame have flushed, so the present timestamps should be updated
1525 EXPECT_EQ(displayFrame->getActuals().presentTime, 50);
1526 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1527 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1528 EXPECT_EQ(displayFrame->getJankType(), JankType::DisplayHAL);
1529
1530 // Fences for the second frame haven't been flushed yet, so it should be 0
1531 auto displayFrame2 = getDisplayFrame(1);
1532 presentFence2->signalForTest(75);
1533 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1534
1535 addEmptyDisplayFrame();
1536 displayFrame2 = getDisplayFrame(1);
1537
1538 // Fences for the second frame have flushed, so the present timestamps should be updated
1539 EXPECT_EQ(displayFrame2->getActuals().presentTime, 75);
1540 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1541 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1542 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
1543 }
1544
TEST_F(FrameTimelineTest,jankClassification_displayFrameLateFinishEarlyPresent)1545 TEST_F(FrameTimelineTest, jankClassification_displayFrameLateFinishEarlyPresent) {
1546 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1547 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({12, 18, 40});
1548 mFrameTimeline->setSfWakeUp(sfToken1, 12, Fps::fromPeriodNsecs(11));
1549
1550 mFrameTimeline->setSfPresent(22, presentFence1);
1551 auto displayFrame = getDisplayFrame(0);
1552 presentFence1->signalForTest(28);
1553
1554 // Fences haven't been flushed yet, so it should be 0
1555 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
1556
1557 addEmptyDisplayFrame();
1558 displayFrame = getDisplayFrame(0);
1559
1560 // Fences have flushed, so the present timestamps should be updated
1561 EXPECT_EQ(displayFrame->getActuals().presentTime, 28);
1562 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1563 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1564 EXPECT_EQ(displayFrame->getJankType(), JankType::SurfaceFlingerScheduling);
1565 }
1566
TEST_F(FrameTimelineTest,jankClassification_displayFrameLateFinishLatePresent)1567 TEST_F(FrameTimelineTest, jankClassification_displayFrameLateFinishLatePresent) {
1568 /*
1569 * Case 1 - cpu time > vsync period but combined time > deadline > deadline -> cpudeadlinemissed
1570 * Case 2 - cpu time < vsync period but combined time > deadline -> gpudeadlinemissed
1571 * Case 3 - previous frame ran longer -> sf_stuffing
1572 * Case 4 - Long cpu under SF stuffing -> cpudeadlinemissed
1573 */
1574 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1575 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1576 auto presentFence3 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1577 auto presentFence4 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1578 auto gpuFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1579 auto gpuFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1580 auto gpuFence3 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1581 auto gpuFence4 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1582 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
1583 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 60, 60});
1584 int64_t sfToken3 = mTokenManager->generateTokenForPredictions({82, 90, 90});
1585 int64_t sfToken4 = mTokenManager->generateTokenForPredictions({112, 120, 120});
1586
1587 // case 1 - cpu time = 33 - 12 = 21, vsync period = 11
1588 mFrameTimeline->setSfWakeUp(sfToken1, 12, Fps::fromPeriodNsecs(11));
1589 mFrameTimeline->setSfPresent(33, presentFence1, gpuFence1);
1590 auto displayFrame0 = getDisplayFrame(0);
1591 gpuFence1->signalForTest(36);
1592 presentFence1->signalForTest(52);
1593
1594 // Fences haven't been flushed yet, so it should be 0
1595 EXPECT_EQ(displayFrame0->getActuals().presentTime, 0);
1596
1597 // case 2 - cpu time = 56 - 52 = 4, vsync period = 30
1598 mFrameTimeline->setSfWakeUp(sfToken2, 52, Fps::fromPeriodNsecs(30));
1599 mFrameTimeline->setSfPresent(56, presentFence2, gpuFence2);
1600 auto displayFrame1 = getDisplayFrame(1);
1601 gpuFence2->signalForTest(76);
1602 presentFence2->signalForTest(90);
1603
1604 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1605 // Fences have flushed for first displayFrame, so the present timestamps should be updated
1606 EXPECT_EQ(displayFrame0->getActuals().presentTime, 52);
1607 EXPECT_EQ(displayFrame0->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1608 EXPECT_EQ(displayFrame0->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1609 EXPECT_EQ(displayFrame0->getJankType(), JankType::SurfaceFlingerCpuDeadlineMissed);
1610
1611 // case 3 - cpu time = 86 - 82 = 4, vsync period = 30
1612 mFrameTimeline->setSfWakeUp(sfToken3, 106, Fps::fromPeriodNsecs(30));
1613 mFrameTimeline->setSfPresent(112, presentFence3, gpuFence3);
1614 auto displayFrame2 = getDisplayFrame(2);
1615 gpuFence3->signalForTest(116);
1616 presentFence3->signalForTest(120);
1617
1618 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1619 // Fences have flushed for second displayFrame, so the present timestamps should be updated
1620 EXPECT_EQ(displayFrame1->getActuals().presentTime, 90);
1621 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1622 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1623 EXPECT_EQ(displayFrame1->getJankType(), JankType::SurfaceFlingerGpuDeadlineMissed);
1624
1625 // case 4 - cpu time = 86 - 82 = 4, vsync period = 30
1626 mFrameTimeline->setSfWakeUp(sfToken4, 120, Fps::fromPeriodNsecs(30));
1627 mFrameTimeline->setSfPresent(140, presentFence4, gpuFence4);
1628 auto displayFrame3 = getDisplayFrame(3);
1629 gpuFence4->signalForTest(156);
1630 presentFence4->signalForTest(180);
1631
1632 EXPECT_EQ(displayFrame3->getActuals().presentTime, 0);
1633 // Fences have flushed for third displayFrame, so the present timestamps should be updated
1634 EXPECT_EQ(displayFrame2->getActuals().presentTime, 120);
1635 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1636 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1637 EXPECT_EQ(displayFrame2->getJankType(), JankType::SurfaceFlingerStuffing);
1638
1639 addEmptyDisplayFrame();
1640
1641 // Fences have flushed for third displayFrame, so the present timestamps should be updated
1642 EXPECT_EQ(displayFrame3->getActuals().presentTime, 180);
1643 EXPECT_EQ(displayFrame3->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1644 EXPECT_EQ(displayFrame3->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1645 EXPECT_EQ(displayFrame3->getJankType(), JankType::SurfaceFlingerGpuDeadlineMissed);
1646 }
1647
TEST_F(FrameTimelineTest,jankClassification_surfaceFrameOnTimeFinishEarlyPresent)1648 TEST_F(FrameTimelineTest, jankClassification_surfaceFrameOnTimeFinishEarlyPresent) {
1649 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_));
1650 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1651 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 30, 40});
1652 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 60, 70});
1653 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 16, 40});
1654 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({25, 36, 70});
1655 auto surfaceFrame1 =
1656 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
1657 sUidOne, sLayerIdOne, sLayerNameOne,
1658 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1659 surfaceFrame1->setAcquireFenceTime(16);
1660 mFrameTimeline->setSfWakeUp(sfToken1, 22, Fps::fromPeriodNsecs(11));
1661 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1662 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1663 mFrameTimeline->setSfPresent(27, presentFence1);
1664 auto displayFrame1 = getDisplayFrame(0);
1665 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1666 presentFence1->signalForTest(30);
1667
1668 // Fences for the first frame haven't been flushed yet, so it should be 0
1669 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1670 auto actuals1 = presentedSurfaceFrame1.getActuals();
1671 EXPECT_EQ(actuals1.presentTime, 0);
1672
1673 // Trigger a flush by finalizing the next DisplayFrame
1674 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1675 auto surfaceFrame2 =
1676 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken2, sInputEventId}, sPidOne,
1677 sUidOne, sLayerIdOne, sLayerNameOne,
1678 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1679 surfaceFrame2->setAcquireFenceTime(36);
1680 mFrameTimeline->setSfWakeUp(sfToken2, 52, Fps::fromPeriodNsecs(11));
1681 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
1682 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1683 mFrameTimeline->setSfPresent(57, presentFence2);
1684 auto displayFrame2 = getDisplayFrame(1);
1685 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1686
1687 // Fences for the first frame have flushed, so the present timestamps should be updated
1688 EXPECT_EQ(displayFrame1->getActuals().presentTime, 30);
1689 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1690 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1691 EXPECT_EQ(displayFrame1->getJankType(), JankType::SurfaceFlingerScheduling);
1692
1693 actuals1 = presentedSurfaceFrame1.getActuals();
1694 EXPECT_EQ(actuals1.presentTime, 30);
1695 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1696 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1697 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::SurfaceFlingerScheduling);
1698
1699 // Fences for the second frame haven't been flushed yet, so it should be 0
1700 presentFence2->signalForTest(65);
1701 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1702 auto actuals2 = presentedSurfaceFrame2.getActuals();
1703 EXPECT_EQ(actuals2.presentTime, 0);
1704
1705 ::testing::Mock::VerifyAndClearExpectations(mTimeStats.get());
1706
1707 EXPECT_CALL(*mTimeStats,
1708 incrementJankyFrames(
1709 TimeStats::JankyFramesInfo{Fps::fromPeriodNsecs(11), std::nullopt, sUidOne,
1710 sLayerNameOne, sGameMode,
1711 JankType::PredictionError, -3, 5, 0}));
1712
1713 addEmptyDisplayFrame();
1714
1715 // Fences for the second frame have flushed, so the present timestamps should be updated
1716 EXPECT_EQ(displayFrame2->getActuals().presentTime, 65);
1717 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1718 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1719 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
1720
1721 actuals2 = presentedSurfaceFrame2.getActuals();
1722 EXPECT_EQ(actuals2.presentTime, 65);
1723 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1724 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1725 EXPECT_EQ(presentedSurfaceFrame2.getJankType(), JankType::PredictionError);
1726 }
1727
TEST_F(FrameTimelineTest,jankClassification_surfaceFrameOnTimeFinishLatePresent)1728 TEST_F(FrameTimelineTest, jankClassification_surfaceFrameOnTimeFinishLatePresent) {
1729 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_));
1730 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1731 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 30, 40});
1732 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 60, 70});
1733 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 16, 40});
1734 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({25, 36, 70});
1735 auto surfaceFrame1 =
1736 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
1737 sUidOne, sLayerIdOne, sLayerNameOne,
1738 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1739 surfaceFrame1->setAcquireFenceTime(16);
1740 mFrameTimeline->setSfWakeUp(sfToken1, 22, Fps::fromPeriodNsecs(11));
1741 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1742 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1743 mFrameTimeline->setSfPresent(26, presentFence1);
1744 auto displayFrame1 = getDisplayFrame(0);
1745 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1746 presentFence1->signalForTest(50);
1747
1748 // Fences for the first frame haven't been flushed yet, so it should be 0
1749 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1750 auto actuals1 = presentedSurfaceFrame1.getActuals();
1751 EXPECT_EQ(actuals1.presentTime, 0);
1752
1753 // Trigger a flush by finalizing the next DisplayFrame
1754 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1755 auto surfaceFrame2 =
1756 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken2, sInputEventId}, sPidOne,
1757 sUidOne, sLayerIdOne, sLayerNameOne,
1758 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1759 surfaceFrame2->setAcquireFenceTime(36);
1760 mFrameTimeline->setSfWakeUp(sfToken2, 52, Fps::fromPeriodNsecs(11));
1761 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
1762 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1763 mFrameTimeline->setSfPresent(57, presentFence2);
1764 auto displayFrame2 = getDisplayFrame(1);
1765 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1766
1767 // Fences for the first frame have flushed, so the present timestamps should be updated
1768 EXPECT_EQ(displayFrame1->getActuals().presentTime, 50);
1769 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1770 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1771 EXPECT_EQ(displayFrame1->getJankType(), JankType::DisplayHAL);
1772
1773 actuals1 = presentedSurfaceFrame1.getActuals();
1774 EXPECT_EQ(actuals1.presentTime, 50);
1775 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1776 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1777 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::DisplayHAL);
1778
1779 // Fences for the second frame haven't been flushed yet, so it should be 0
1780 presentFence2->signalForTest(86);
1781 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1782 auto actuals2 = presentedSurfaceFrame2.getActuals();
1783 EXPECT_EQ(actuals2.presentTime, 0);
1784
1785 ::testing::Mock::VerifyAndClearExpectations(mTimeStats.get());
1786
1787 EXPECT_CALL(*mTimeStats,
1788 incrementJankyFrames(
1789 TimeStats::JankyFramesInfo{Fps::fromPeriodNsecs(11), std::nullopt, sUidOne,
1790 sLayerNameOne, sGameMode,
1791 JankType::PredictionError, -3, 5, 0}));
1792
1793 addEmptyDisplayFrame();
1794
1795 // Fences for the second frame have flushed, so the present timestamps should be updated
1796 EXPECT_EQ(displayFrame2->getActuals().presentTime, 86);
1797 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1798 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1799 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
1800
1801 actuals2 = presentedSurfaceFrame2.getActuals();
1802 EXPECT_EQ(actuals2.presentTime, 86);
1803 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1804 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1805 EXPECT_EQ(presentedSurfaceFrame2.getJankType(), JankType::PredictionError);
1806 }
1807
TEST_F(FrameTimelineTest,jankClassification_surfaceFrameLateFinishEarlyPresent)1808 TEST_F(FrameTimelineTest, jankClassification_surfaceFrameLateFinishEarlyPresent) {
1809 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_));
1810
1811 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1812 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({42, 50, 50});
1813 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 26, 60});
1814 auto surfaceFrame1 =
1815 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
1816 sUidOne, sLayerIdOne, sLayerNameOne,
1817 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1818 surfaceFrame1->setAcquireFenceTime(40);
1819 mFrameTimeline->setSfWakeUp(sfToken1, 42, Fps::fromPeriodNsecs(11));
1820 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1821 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1822 mFrameTimeline->setSfPresent(46, presentFence1);
1823 auto displayFrame1 = getDisplayFrame(0);
1824 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1825 presentFence1->signalForTest(50);
1826
1827 // Fences for the first frame haven't been flushed yet, so it should be 0
1828 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1829 auto actuals1 = presentedSurfaceFrame1.getActuals();
1830 EXPECT_EQ(actuals1.presentTime, 0);
1831
1832 addEmptyDisplayFrame();
1833
1834 // Fences for the first frame have flushed, so the present timestamps should be updated
1835 EXPECT_EQ(displayFrame1->getActuals().presentTime, 50);
1836 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1837 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1838 EXPECT_EQ(displayFrame1->getJankType(), JankType::None);
1839
1840 actuals1 = presentedSurfaceFrame1.getActuals();
1841 EXPECT_EQ(actuals1.presentTime, 50);
1842 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1843 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1844 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::Unknown);
1845 }
1846
TEST_F(FrameTimelineTest,jankClassification_surfaceFrameLateFinishLatePresent)1847 TEST_F(FrameTimelineTest, jankClassification_surfaceFrameLateFinishLatePresent) {
1848 // First frame - DisplayFrame is not janky. This should classify the SurfaceFrame as only
1849 // AppDeadlineMissed. Second frame - DisplayFrame is janky. This should propagate DisplayFrame's
1850 // jank to the SurfaceFrame along with AppDeadlineMissed.
1851
1852 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_)).Times(2);
1853 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1854 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({32, 40, 40});
1855 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({42, 50, 50});
1856 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 16, 30});
1857 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({25, 36, 50});
1858 auto surfaceFrame1 =
1859 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
1860 sUidOne, sLayerIdOne, sLayerNameOne,
1861 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1862 surfaceFrame1->setAcquireFenceTime(26);
1863 mFrameTimeline->setSfWakeUp(sfToken1, 32, Fps::fromPeriodNsecs(11));
1864 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1865 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1866 mFrameTimeline->setSfPresent(36, presentFence1);
1867 auto displayFrame1 = getDisplayFrame(0);
1868 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1869 presentFence1->signalForTest(40);
1870
1871 // Fences for the first frame haven't been flushed yet, so it should be 0
1872 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1873 auto actuals1 = presentedSurfaceFrame1.getActuals();
1874 EXPECT_EQ(actuals1.presentTime, 0);
1875
1876 // Trigger a flush by finalizing the next DisplayFrame
1877 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1878 auto surfaceFrame2 =
1879 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken2, sInputEventId}, sPidOne,
1880 sUidOne, sLayerIdOne, sLayerNameOne,
1881 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1882 surfaceFrame2->setAcquireFenceTime(40);
1883 mFrameTimeline->setSfWakeUp(sfToken2, 43, Fps::fromPeriodNsecs(11));
1884 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
1885 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1886 mFrameTimeline->setSfPresent(56, presentFence2);
1887 auto displayFrame2 = getDisplayFrame(1);
1888 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1889
1890 // Fences for the first frame have flushed, so the present timestamps should be updated
1891 EXPECT_EQ(displayFrame1->getActuals().presentTime, 40);
1892 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1893 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1894 EXPECT_EQ(displayFrame1->getJankType(), JankType::None);
1895
1896 actuals1 = presentedSurfaceFrame1.getActuals();
1897 EXPECT_EQ(actuals1.presentTime, 40);
1898 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1899 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1900 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::AppDeadlineMissed);
1901
1902 // Fences for the second frame haven't been flushed yet, so it should be 0
1903 presentFence2->signalForTest(60);
1904 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1905 auto actuals2 = presentedSurfaceFrame2.getActuals();
1906 EXPECT_EQ(actuals2.presentTime, 0);
1907
1908 addEmptyDisplayFrame();
1909
1910 // Fences for the second frame have flushed, so the present timestamps should be updated
1911 EXPECT_EQ(displayFrame2->getActuals().presentTime, 60);
1912 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1913 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1914 EXPECT_EQ(displayFrame2->getJankType(), JankType::SurfaceFlingerCpuDeadlineMissed);
1915
1916 actuals2 = presentedSurfaceFrame2.getActuals();
1917 EXPECT_EQ(actuals2.presentTime, 60);
1918 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1919 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1920 EXPECT_EQ(presentedSurfaceFrame2.getJankType(),
1921 JankType::SurfaceFlingerCpuDeadlineMissed | JankType::AppDeadlineMissed);
1922 }
1923
TEST_F(FrameTimelineTest,jankClassification_multiJankBufferStuffingAndAppDeadlineMissed)1924 TEST_F(FrameTimelineTest, jankClassification_multiJankBufferStuffingAndAppDeadlineMissed) {
1925 // Layer specific increment
1926 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_)).Times(2);
1927 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1928 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
1929 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
1930
1931 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({52, 60, 60});
1932 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({112, 120, 120});
1933 auto surfaceFrame1 =
1934 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
1935 sUidOne, sLayerIdOne, sLayerNameOne,
1936 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1937 surfaceFrame1->setAcquireFenceTime(50);
1938 mFrameTimeline->setSfWakeUp(sfToken1, 52, Fps::fromPeriodNsecs(30));
1939 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1940 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1941 mFrameTimeline->setSfPresent(56, presentFence1);
1942 auto displayFrame1 = getDisplayFrame(0);
1943 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1944 presentFence1->signalForTest(60);
1945
1946 // Fences for the first frame haven't been flushed yet, so it should be 0
1947 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1948 auto actuals1 = presentedSurfaceFrame1.getActuals();
1949 EXPECT_EQ(actuals1.presentTime, 0);
1950
1951 // Trigger a flush by finalizing the next DisplayFrame
1952 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1953 auto surfaceFrame2 =
1954 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken2, sInputEventId}, sPidOne,
1955 sUidOne, sLayerIdOne, sLayerNameOne,
1956 sLayerNameOne, /*isBuffer*/ true, sGameMode);
1957 surfaceFrame2->setAcquireFenceTime(84);
1958 mFrameTimeline->setSfWakeUp(sfToken2, 112, Fps::fromPeriodNsecs(30));
1959 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented, 54);
1960 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1961 mFrameTimeline->setSfPresent(116, presentFence2);
1962 auto displayFrame2 = getDisplayFrame(1);
1963 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1964 presentFence2->signalForTest(120);
1965
1966 // Fences for the first frame have flushed, so the present timestamps should be updated
1967 EXPECT_EQ(displayFrame1->getActuals().presentTime, 60);
1968 actuals1 = presentedSurfaceFrame1.getActuals();
1969 EXPECT_EQ(actuals1.endTime, 50);
1970 EXPECT_EQ(actuals1.presentTime, 60);
1971
1972 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1973 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1974 EXPECT_EQ(displayFrame1->getJankType(), JankType::None);
1975
1976 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1977 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1978 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::AppDeadlineMissed);
1979
1980 // Fences for the second frame haven't been flushed yet, so it should be 0
1981 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1982 auto actuals2 = presentedSurfaceFrame2.getActuals();
1983 EXPECT_EQ(actuals2.presentTime, 0);
1984
1985 addEmptyDisplayFrame();
1986
1987 // Fences for the second frame have flushed, so the present timestamps should be updated
1988 EXPECT_EQ(displayFrame2->getActuals().presentTime, 120);
1989 actuals2 = presentedSurfaceFrame2.getActuals();
1990 EXPECT_EQ(actuals2.presentTime, 120);
1991
1992 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1993 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1994 EXPECT_EQ(displayFrame2->getJankType(), JankType::None);
1995
1996 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1997 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1998 EXPECT_EQ(presentedSurfaceFrame2.getJankType(),
1999 JankType::AppDeadlineMissed | JankType::BufferStuffing);
2000 }
2001
TEST_F(FrameTimelineTest,jankClassification_appDeadlineAdjustedForBufferStuffing)2002 TEST_F(FrameTimelineTest, jankClassification_appDeadlineAdjustedForBufferStuffing) {
2003 // Layer specific increment
2004 EXPECT_CALL(*mTimeStats, incrementJankyFrames(_)).Times(2);
2005 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2006 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
2007 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
2008
2009 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({52, 60, 60});
2010 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({82, 90, 90});
2011 auto surfaceFrame1 =
2012 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken1, sInputEventId}, sPidOne,
2013 sUidOne, sLayerIdOne, sLayerNameOne,
2014 sLayerNameOne, /*isBuffer*/ true, sGameMode);
2015 surfaceFrame1->setAcquireFenceTime(50);
2016 mFrameTimeline->setSfWakeUp(sfToken1, 52, Fps::fromPeriodNsecs(30));
2017 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
2018 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
2019 mFrameTimeline->setSfPresent(56, presentFence1);
2020 auto displayFrame1 = getDisplayFrame(0);
2021 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
2022 presentFence1->signalForTest(60);
2023
2024 // Fences for the first frame haven't been flushed yet, so it should be 0
2025 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
2026 auto actuals1 = presentedSurfaceFrame1.getActuals();
2027 EXPECT_EQ(actuals1.presentTime, 0);
2028
2029 // Trigger a flush by finalizing the next DisplayFrame
2030 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2031 auto surfaceFrame2 =
2032 mFrameTimeline->createSurfaceFrameForToken({surfaceFrameToken2, sInputEventId}, sPidOne,
2033 sUidOne, sLayerIdOne, sLayerNameOne,
2034 sLayerNameOne, /*isBuffer*/ true, sGameMode);
2035 surfaceFrame2->setAcquireFenceTime(80);
2036 mFrameTimeline->setSfWakeUp(sfToken2, 82, Fps::fromPeriodNsecs(30));
2037 // Setting previous latch time to 54, adjusted deadline will be 54 + vsyncTime(30) = 84
2038 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented, 54);
2039 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
2040 mFrameTimeline->setSfPresent(86, presentFence2);
2041 auto displayFrame2 = getDisplayFrame(1);
2042 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
2043 presentFence2->signalForTest(90);
2044
2045 // Fences for the first frame have flushed, so the present timestamps should be updated
2046 EXPECT_EQ(displayFrame1->getActuals().presentTime, 60);
2047 actuals1 = presentedSurfaceFrame1.getActuals();
2048 EXPECT_EQ(actuals1.endTime, 50);
2049 EXPECT_EQ(actuals1.presentTime, 60);
2050
2051 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
2052 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
2053 EXPECT_EQ(displayFrame1->getJankType(), JankType::None);
2054
2055 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
2056 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
2057 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::AppDeadlineMissed);
2058
2059 // Fences for the second frame haven't been flushed yet, so it should be 0
2060 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
2061 auto actuals2 = presentedSurfaceFrame2.getActuals();
2062 EXPECT_EQ(actuals2.presentTime, 0);
2063
2064 addEmptyDisplayFrame();
2065
2066 // Fences for the second frame have flushed, so the present timestamps should be updated
2067 EXPECT_EQ(displayFrame2->getActuals().presentTime, 90);
2068 actuals2 = presentedSurfaceFrame2.getActuals();
2069 EXPECT_EQ(actuals2.presentTime, 90);
2070
2071 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
2072 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
2073 EXPECT_EQ(displayFrame2->getJankType(), JankType::None);
2074
2075 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
2076 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
2077 EXPECT_EQ(presentedSurfaceFrame2.getJankType(), JankType::BufferStuffing);
2078 }
2079
TEST_F(FrameTimelineTest,computeFps_noLayerIds_returnsZero)2080 TEST_F(FrameTimelineTest, computeFps_noLayerIds_returnsZero) {
2081 EXPECT_EQ(mFrameTimeline->computeFps({}), 0.0f);
2082 }
2083
TEST_F(FrameTimelineTest,computeFps_singleDisplayFrame_returnsZero)2084 TEST_F(FrameTimelineTest, computeFps_singleDisplayFrame_returnsZero) {
2085 const auto oneHundredMs = std::chrono::nanoseconds(100ms).count();
2086
2087 auto surfaceFrame1 =
2088 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2089 sLayerIdOne, sLayerNameOne, sLayerNameOne,
2090 /*isBuffer*/ true, sGameMode);
2091 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2092 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
2093 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
2094 presentFence1->signalForTest(oneHundredMs);
2095 mFrameTimeline->setSfPresent(oneHundredMs, presentFence1);
2096
2097 EXPECT_EQ(mFrameTimeline->computeFps({sLayerIdOne}), 0.0f);
2098 }
2099
TEST_F(FrameTimelineTest,computeFps_twoDisplayFrames_oneLayer)2100 TEST_F(FrameTimelineTest, computeFps_twoDisplayFrames_oneLayer) {
2101 const auto oneHundredMs = std::chrono::nanoseconds(100ms).count();
2102 const auto twoHundredMs = std::chrono::nanoseconds(200ms).count();
2103 auto surfaceFrame1 =
2104 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2105 sLayerIdOne, sLayerNameOne, sLayerNameOne,
2106 /*isBuffer*/ true, sGameMode);
2107 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2108 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
2109 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
2110 presentFence1->signalForTest(oneHundredMs);
2111 mFrameTimeline->setSfPresent(oneHundredMs, presentFence1);
2112
2113 auto surfaceFrame2 =
2114 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2115 sLayerIdOne, sLayerNameOne, sLayerNameOne,
2116 /*isBuffer*/ true, sGameMode);
2117 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2118 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
2119 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
2120 presentFence2->signalForTest(twoHundredMs);
2121 mFrameTimeline->setSfPresent(twoHundredMs, presentFence2);
2122
2123 EXPECT_EQ(mFrameTimeline->computeFps({sLayerIdOne}), 10.0);
2124 }
2125
TEST_F(FrameTimelineTest,computeFps_twoDisplayFrames_twoLayers)2126 TEST_F(FrameTimelineTest, computeFps_twoDisplayFrames_twoLayers) {
2127 const auto oneHundredMs = std::chrono::nanoseconds(100ms).count();
2128 const auto twoHundredMs = std::chrono::nanoseconds(200ms).count();
2129 auto surfaceFrame1 =
2130 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2131 sLayerIdOne, sLayerNameOne, sLayerNameOne,
2132 /*isBuffer*/ true, sGameMode);
2133 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2134 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
2135 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
2136 presentFence1->signalForTest(oneHundredMs);
2137 mFrameTimeline->setSfPresent(oneHundredMs, presentFence1);
2138
2139 auto surfaceFrame2 =
2140 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2141 sLayerIdTwo, sLayerNameTwo, sLayerNameTwo,
2142 /*isBuffer*/ true, sGameMode);
2143 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2144 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
2145 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
2146 presentFence2->signalForTest(twoHundredMs);
2147 mFrameTimeline->setSfPresent(twoHundredMs, presentFence2);
2148
2149 EXPECT_EQ(mFrameTimeline->computeFps({sLayerIdOne, sLayerIdTwo}), 10.0f);
2150 }
2151
TEST_F(FrameTimelineTest,computeFps_filtersOutLayers)2152 TEST_F(FrameTimelineTest, computeFps_filtersOutLayers) {
2153 const auto oneHundredMs = std::chrono::nanoseconds(100ms).count();
2154 const auto twoHundredMs = std::chrono::nanoseconds(200ms).count();
2155 auto surfaceFrame1 =
2156 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2157 sLayerIdOne, sLayerNameOne, sLayerNameOne,
2158 /*isBuffer*/ true, sGameMode);
2159 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2160 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
2161 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
2162 presentFence1->signalForTest(oneHundredMs);
2163 mFrameTimeline->setSfPresent(oneHundredMs, presentFence1);
2164
2165 auto surfaceFrame2 =
2166 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2167 sLayerIdTwo, sLayerNameTwo, sLayerNameTwo,
2168 /*isBuffer*/ true, sGameMode);
2169 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2170 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
2171 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
2172 presentFence2->signalForTest(twoHundredMs);
2173 mFrameTimeline->setSfPresent(twoHundredMs, presentFence2);
2174
2175 EXPECT_EQ(mFrameTimeline->computeFps({sLayerIdOne}), 0.0f);
2176 }
2177
TEST_F(FrameTimelineTest,computeFps_averagesOverMultipleFrames)2178 TEST_F(FrameTimelineTest, computeFps_averagesOverMultipleFrames) {
2179 const auto oneHundredMs = std::chrono::nanoseconds(100ms).count();
2180 const auto twoHundredMs = std::chrono::nanoseconds(200ms).count();
2181 const auto threeHundredMs = std::chrono::nanoseconds(300ms).count();
2182 const auto fiveHundredMs = std::chrono::nanoseconds(500ms).count();
2183 const auto sixHundredMs = std::chrono::nanoseconds(600ms).count();
2184 auto surfaceFrame1 =
2185 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2186 sLayerIdOne, sLayerNameOne, sLayerNameOne,
2187 /*isBuffer*/ true, sGameMode);
2188 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2189 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
2190 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
2191 presentFence1->signalForTest(oneHundredMs);
2192 mFrameTimeline->setSfPresent(oneHundredMs, presentFence1);
2193
2194 auto surfaceFrame2 =
2195 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2196 sLayerIdOne, sLayerNameOne, sLayerNameOne,
2197 /*isBuffer*/ true, sGameMode);
2198 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2199 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
2200 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
2201 presentFence2->signalForTest(twoHundredMs);
2202 mFrameTimeline->setSfPresent(twoHundredMs, presentFence2);
2203
2204 auto surfaceFrame3 =
2205 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2206 sLayerIdTwo, sLayerNameTwo, sLayerNameTwo,
2207 /*isBuffer*/ true, sGameMode);
2208 auto presentFence3 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2209 surfaceFrame3->setPresentState(SurfaceFrame::PresentState::Presented);
2210 mFrameTimeline->addSurfaceFrame(surfaceFrame3);
2211 presentFence3->signalForTest(threeHundredMs);
2212 mFrameTimeline->setSfPresent(threeHundredMs, presentFence3);
2213
2214 auto surfaceFrame4 =
2215 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2216 sLayerIdOne, sLayerNameOne, sLayerNameOne,
2217 /*isBuffer*/ true, sGameMode);
2218 auto presentFence4 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2219 surfaceFrame4->setPresentState(SurfaceFrame::PresentState::Presented);
2220 mFrameTimeline->addSurfaceFrame(surfaceFrame4);
2221 presentFence4->signalForTest(fiveHundredMs);
2222 mFrameTimeline->setSfPresent(fiveHundredMs, presentFence4);
2223
2224 auto surfaceFrame5 =
2225 mFrameTimeline->createSurfaceFrameForToken(FrameTimelineInfo(), sPidOne, sUidOne,
2226 sLayerIdOne, sLayerNameOne, sLayerNameOne,
2227 /*isBuffer*/ true, sGameMode);
2228 auto presentFence5 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
2229 // Dropped frames will be excluded from fps computation
2230 surfaceFrame5->setPresentState(SurfaceFrame::PresentState::Dropped);
2231 mFrameTimeline->addSurfaceFrame(surfaceFrame5);
2232 presentFence5->signalForTest(sixHundredMs);
2233 mFrameTimeline->setSfPresent(sixHundredMs, presentFence5);
2234
2235 EXPECT_EQ(mFrameTimeline->computeFps({sLayerIdOne}), 5.0f);
2236 }
2237
2238 } // namespace android::frametimeline
2239