blob: 169698ba70ed97dfeab93f2ca9442c83ce857885 [file] [log] [blame]
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001/*
2 * Copyright 2020 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
Marin Shalamanovbed7fd32020-12-21 20:02:20 +010017// TODO(b/129481165): remove the #pragma below and fix conversion issues
18#pragma clang diagnostic push
19#pragma clang diagnostic ignored "-Wextra"
20
Alec Mouri9a29e672020-09-14 12:39:14 -070021#include "gmock/gmock-spec-builders.h"
22#include "mock/MockTimeStats.h"
Adithya Srinivasanf279e042020-08-17 14:56:27 -070023#undef LOG_TAG
24#define LOG_TAG "LibSurfaceFlingerUnittests"
25
26#include <FrameTimeline/FrameTimeline.h>
27#include <gtest/gtest.h>
28#include <log/log.h>
Adithya Srinivasan01189672020-10-20 14:23:05 -070029#include <perfetto/trace/trace.pb.h>
Adithya Srinivasanf279e042020-08-17 14:56:27 -070030#include <cinttypes>
31
32using namespace std::chrono_literals;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080033using testing::AtLeast;
Alec Mouri9a29e672020-09-14 12:39:14 -070034using testing::Contains;
Adithya Srinivasan01189672020-10-20 14:23:05 -070035using FrameTimelineEvent = perfetto::protos::FrameTimelineEvent;
36using ProtoDisplayFrame = perfetto::protos::FrameTimelineEvent_DisplayFrame;
37using ProtoSurfaceFrame = perfetto::protos::FrameTimelineEvent_SurfaceFrame;
38using ProtoPresentType = perfetto::protos::FrameTimelineEvent_PresentType;
39using ProtoJankType = perfetto::protos::FrameTimelineEvent_JankType;
Alec Mouri9a29e672020-09-14 12:39:14 -070040
41MATCHER_P(HasBit, bit, "") {
42 return (arg & bit) != 0;
43}
Adithya Srinivasanf279e042020-08-17 14:56:27 -070044
45namespace android::frametimeline {
46
47class FrameTimelineTest : public testing::Test {
48public:
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
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
Adithya Srinivasan01189672020-10-20 14:23:05 -070061 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
Adithya Srinivasanf279e042020-08-17 14:56:27 -070068 void SetUp() override {
Alec Mouri9a29e672020-09-14 12:39:14 -070069 mTimeStats = std::make_shared<mock::TimeStats>();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080070 mFrameTimeline = std::make_unique<impl::FrameTimeline>(mTimeStats, mSurfaceFlingerPid,
71 kTestThresholds);
Adithya Srinivasan01189672020-10-20 14:23:05 -070072 mFrameTimeline->registerDataSource();
Adithya Srinivasanf279e042020-08-17 14:56:27 -070073 mTokenManager = &mFrameTimeline->mTokenManager;
Adithya Srinivasan2d736322020-10-01 16:53:48 -070074 maxDisplayFrames = &mFrameTimeline->mMaxDisplayFrames;
Adithya Srinivasanf279e042020-08-17 14:56:27 -070075 maxTokenRetentionTime = mTokenManager->kMaxRetentionTime;
76 }
77
Adithya Srinivasan01189672020-10-20 14:23:05 -070078 // Each tracing session can be used for a single block of Start -> Stop.
79 static std::unique_ptr<perfetto::TracingSession> getTracingSessionForTest() {
80 perfetto::TraceConfig cfg;
81 cfg.set_duration_ms(500);
82 cfg.add_buffers()->set_size_kb(1024);
83 auto* ds_cfg = cfg.add_data_sources()->mutable_config();
84 ds_cfg->set_name(impl::FrameTimeline::kFrameTimelineDataSource);
85
86 auto tracingSession = perfetto::Tracing::NewTrace(perfetto::kInProcessBackend);
87 tracingSession->Setup(cfg);
88 return tracingSession;
89 }
90
91 std::vector<perfetto::protos::TracePacket> readFrameTimelinePacketsBlocking(
92 perfetto::TracingSession* tracingSession) {
93 std::vector<char> raw_trace = tracingSession->ReadTraceBlocking();
94 perfetto::protos::Trace trace;
95 EXPECT_TRUE(trace.ParseFromArray(raw_trace.data(), int(raw_trace.size())));
96
97 std::vector<perfetto::protos::TracePacket> packets;
98 for (const auto& packet : trace.packet()) {
99 if (!packet.has_frame_timeline_event()) {
100 continue;
101 }
102 packets.emplace_back(packet);
103 }
104 return packets;
105 }
106
107 void addEmptyDisplayFrame() {
108 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
109 mFrameTimeline->setSfPresent(2500, presentFence1);
110 }
111
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700112 void flushTokens(nsecs_t flushTime) {
113 std::lock_guard<std::mutex> lock(mTokenManager->mMutex);
114 mTokenManager->flushTokens(flushTime);
115 }
116
117 SurfaceFrame& getSurfaceFrame(size_t displayFrameIdx, size_t surfaceFrameIdx) {
118 std::lock_guard<std::mutex> lock(mFrameTimeline->mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800119 return *(mFrameTimeline->mDisplayFrames[displayFrameIdx]
120 ->getSurfaceFrames()[surfaceFrameIdx]);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700121 }
122
123 std::shared_ptr<impl::FrameTimeline::DisplayFrame> getDisplayFrame(size_t idx) {
124 std::lock_guard<std::mutex> lock(mFrameTimeline->mMutex);
125 return mFrameTimeline->mDisplayFrames[idx];
126 }
127
128 static bool compareTimelineItems(const TimelineItem& a, const TimelineItem& b) {
129 return a.startTime == b.startTime && a.endTime == b.endTime &&
130 a.presentTime == b.presentTime;
131 }
132
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800133 const std::map<int64_t, TokenManagerPrediction>& getPredictions() {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700134 return mTokenManager->mPredictions;
135 }
136
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700137 uint32_t getNumberOfDisplayFrames() {
138 std::lock_guard<std::mutex> lock(mFrameTimeline->mMutex);
139 return static_cast<uint32_t>(mFrameTimeline->mDisplayFrames.size());
140 }
141
Alec Mouri9a29e672020-09-14 12:39:14 -0700142 std::shared_ptr<mock::TimeStats> mTimeStats;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700143 std::unique_ptr<impl::FrameTimeline> mFrameTimeline;
144 impl::TokenManager* mTokenManager;
145 FenceToFenceTimeMap fenceFactory;
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700146 uint32_t* maxDisplayFrames;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700147 nsecs_t maxTokenRetentionTime;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800148 pid_t mSurfaceFlingerPid = 666;
149 static constexpr nsecs_t kPresentThreshold =
150 std::chrono::duration_cast<std::chrono::nanoseconds>(2ns).count();
151 static constexpr nsecs_t kDeadlineThreshold =
152 std::chrono::duration_cast<std::chrono::nanoseconds>(2ns).count();
153 static constexpr nsecs_t kStartThreshold =
154 std::chrono::duration_cast<std::chrono::nanoseconds>(2ns).count();
155 static constexpr JankClassificationThresholds kTestThresholds{kPresentThreshold,
156 kDeadlineThreshold,
157 kStartThreshold};
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700158};
159
Alec Mouri9a29e672020-09-14 12:39:14 -0700160static const std::string sLayerNameOne = "layer1";
161static const std::string sLayerNameTwo = "layer2";
162static constexpr const uid_t sUidOne = 0;
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700163static constexpr pid_t sPidOne = 10;
164static constexpr pid_t sPidTwo = 20;
Alec Mouri9a29e672020-09-14 12:39:14 -0700165
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700166TEST_F(FrameTimelineTest, tokenManagerRemovesStalePredictions) {
167 int64_t token1 = mTokenManager->generateTokenForPredictions({0, 0, 0});
168 EXPECT_EQ(getPredictions().size(), 1);
169 flushTokens(systemTime() + maxTokenRetentionTime);
170 int64_t token2 = mTokenManager->generateTokenForPredictions({10, 20, 30});
171 std::optional<TimelineItem> predictions = mTokenManager->getPredictionsForToken(token1);
172
173 // token1 should have expired
174 EXPECT_EQ(getPredictions().size(), 1);
175 EXPECT_EQ(predictions.has_value(), false);
176
177 predictions = mTokenManager->getPredictionsForToken(token2);
178 EXPECT_EQ(compareTimelineItems(*predictions, TimelineItem(10, 20, 30)), true);
179}
180
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700181TEST_F(FrameTimelineTest, createSurfaceFrameForToken_getOwnerPidReturnsCorrectPid) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800182 auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
183 sLayerNameOne, sLayerNameOne);
184 auto surfaceFrame2 = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidTwo, sUidOne,
185 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700186 EXPECT_EQ(surfaceFrame1->getOwnerPid(), sPidOne);
187 EXPECT_EQ(surfaceFrame2->getOwnerPid(), sPidTwo);
188}
189
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700190TEST_F(FrameTimelineTest, createSurfaceFrameForToken_noToken) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800191 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
192 sLayerNameOne, sLayerNameOne);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700193 EXPECT_EQ(surfaceFrame->getPredictionState(), PredictionState::None);
194}
195
196TEST_F(FrameTimelineTest, createSurfaceFrameForToken_expiredToken) {
197 int64_t token1 = mTokenManager->generateTokenForPredictions({0, 0, 0});
198 flushTokens(systemTime() + maxTokenRetentionTime);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800199 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken(token1, sPidOne, sUidOne,
200 sLayerNameOne, sLayerNameOne);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700201
202 EXPECT_EQ(surfaceFrame->getPredictionState(), PredictionState::Expired);
203}
204
205TEST_F(FrameTimelineTest, createSurfaceFrameForToken_validToken) {
206 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800207 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken(token1, sPidOne, sUidOne,
208 sLayerNameOne, sLayerNameOne);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700209
210 EXPECT_EQ(surfaceFrame->getPredictionState(), PredictionState::Valid);
211 EXPECT_EQ(compareTimelineItems(surfaceFrame->getPredictions(), TimelineItem(10, 20, 30)), true);
212}
213
214TEST_F(FrameTimelineTest, presentFenceSignaled_droppedFramesNotUpdated) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800215 // Global increment
216 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700217 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
218 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
219
220 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
221 int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800222 auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(token1, sPidOne, sUidOne,
223 sLayerNameOne, sLayerNameOne);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700224
225 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800226 mFrameTimeline->setSfWakeUp(token1, 20, 11);
227 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Dropped);
228 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700229 mFrameTimeline->setSfPresent(25, presentFence1);
230 presentFence1->signalForTest(30);
231
232 // Trigger a flush by calling setSfPresent for the next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800233 mFrameTimeline->setSfWakeUp(token2, 50, 11);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700234 mFrameTimeline->setSfPresent(55, presentFence2);
235
236 auto& droppedSurfaceFrame = getSurfaceFrame(0, 0);
237 EXPECT_EQ(droppedSurfaceFrame.getPresentState(), SurfaceFrame::PresentState::Dropped);
238 EXPECT_EQ(droppedSurfaceFrame.getActuals().presentTime, 0);
239}
240
241TEST_F(FrameTimelineTest, presentFenceSignaled_presentedFramesUpdated) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800242 // Global increment
243 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
244 // Layer specific increment
245 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_)).Times(2);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700246 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
247 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
248 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
249 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 30});
250 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 56, 60});
Alec Mouri9a29e672020-09-14 12:39:14 -0700251 auto surfaceFrame1 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800252 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
253 sLayerNameOne, sLayerNameOne);
Alec Mouri9a29e672020-09-14 12:39:14 -0700254 auto surfaceFrame2 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800255 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
256 sLayerNameTwo, sLayerNameTwo);
257 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
258 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
259 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
260 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
261 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700262 mFrameTimeline->setSfPresent(26, presentFence1);
263 auto displayFrame = getDisplayFrame(0);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800264 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
265 auto& presentedSurfaceFrame2 = getSurfaceFrame(0, 1);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700266 presentFence1->signalForTest(42);
267
268 // Fences haven't been flushed yet, so it should be 0
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800269 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700270 EXPECT_EQ(presentedSurfaceFrame1.getActuals().presentTime, 0);
271 EXPECT_EQ(presentedSurfaceFrame2.getActuals().presentTime, 0);
272
273 // Trigger a flush by finalizing the next DisplayFrame
274 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
Alec Mouri9a29e672020-09-14 12:39:14 -0700275 auto surfaceFrame3 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800276 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken2, sPidOne, sUidOne,
277 sLayerNameOne, sLayerNameOne);
278 mFrameTimeline->setSfWakeUp(sfToken2, 52, 11);
279 surfaceFrame3->setPresentState(SurfaceFrame::PresentState::Dropped);
280 mFrameTimeline->addSurfaceFrame(surfaceFrame3);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700281 mFrameTimeline->setSfPresent(56, presentFence2);
282 displayFrame = getDisplayFrame(0);
283
284 // Fences have flushed, so the present timestamps should be updated
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800285 EXPECT_EQ(displayFrame->getActuals().presentTime, 42);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700286 EXPECT_EQ(presentedSurfaceFrame1.getActuals().presentTime, 42);
287 EXPECT_EQ(presentedSurfaceFrame2.getActuals().presentTime, 42);
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100288 EXPECT_NE(surfaceFrame1->getJankType(), std::nullopt);
289 EXPECT_NE(surfaceFrame2->getJankType(), std::nullopt);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700290}
291
292TEST_F(FrameTimelineTest, displayFramesSlidingWindowMovesAfterLimit) {
293 // Insert kMaxDisplayFrames' count of DisplayFrames to fill the deque
294 int frameTimeFactor = 0;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800295 // Global increment
296 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_))
297 .Times(static_cast<int32_t>(*maxDisplayFrames));
298 // Layer specific increment
299 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_))
300 .Times(static_cast<int32_t>(*maxDisplayFrames));
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700301 for (size_t i = 0; i < *maxDisplayFrames; i++) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700302 auto presentFence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
303 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions(
304 {10 + frameTimeFactor, 20 + frameTimeFactor, 30 + frameTimeFactor});
305 int64_t sfToken = mTokenManager->generateTokenForPredictions(
306 {22 + frameTimeFactor, 26 + frameTimeFactor, 30 + frameTimeFactor});
Alec Mouri9a29e672020-09-14 12:39:14 -0700307 auto surfaceFrame =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800308 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken, sPidOne, sUidOne,
309 sLayerNameOne, sLayerNameOne);
310 mFrameTimeline->setSfWakeUp(sfToken, 22 + frameTimeFactor, 11);
311 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
312 mFrameTimeline->addSurfaceFrame(surfaceFrame);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700313 mFrameTimeline->setSfPresent(27 + frameTimeFactor, presentFence);
314 presentFence->signalForTest(32 + frameTimeFactor);
315 frameTimeFactor += 30;
316 }
317 auto displayFrame0 = getDisplayFrame(0);
318
319 // The 0th Display Frame should have actuals 22, 27, 32
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800320 EXPECT_EQ(compareTimelineItems(displayFrame0->getActuals(), TimelineItem(22, 27, 32)), true);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700321
322 // Add one more display frame
323 auto presentFence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
324 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions(
325 {10 + frameTimeFactor, 20 + frameTimeFactor, 30 + frameTimeFactor});
326 int64_t sfToken = mTokenManager->generateTokenForPredictions(
327 {22 + frameTimeFactor, 26 + frameTimeFactor, 30 + frameTimeFactor});
Alec Mouri9a29e672020-09-14 12:39:14 -0700328 auto surfaceFrame =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800329 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken, sPidOne, sUidOne,
330 sLayerNameOne, sLayerNameOne);
331 mFrameTimeline->setSfWakeUp(sfToken, 22 + frameTimeFactor, 11);
332 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
333 mFrameTimeline->addSurfaceFrame(surfaceFrame);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700334 mFrameTimeline->setSfPresent(27 + frameTimeFactor, presentFence);
335 presentFence->signalForTest(32 + frameTimeFactor);
336 displayFrame0 = getDisplayFrame(0);
337
338 // The window should have slided by 1 now and the previous 0th display frame
339 // should have been removed from the deque
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800340 EXPECT_EQ(compareTimelineItems(displayFrame0->getActuals(), TimelineItem(52, 57, 62)), true);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700341}
342
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700343TEST_F(FrameTimelineTest, surfaceFrameEndTimeAcquireFenceAfterQueue) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800344 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, 0,
345 "acquireFenceAfterQueue",
346 "acquireFenceAfterQueue");
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700347 surfaceFrame->setActualQueueTime(123);
348 surfaceFrame->setAcquireFenceTime(456);
349 EXPECT_EQ(surfaceFrame->getActuals().endTime, 456);
350}
351
352TEST_F(FrameTimelineTest, surfaceFrameEndTimeAcquireFenceBeforeQueue) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800353 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, 0,
354 "acquireFenceAfterQueue",
355 "acquireFenceAfterQueue");
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700356 surfaceFrame->setActualQueueTime(456);
357 surfaceFrame->setAcquireFenceTime(123);
358 EXPECT_EQ(surfaceFrame->getActuals().endTime, 456);
359}
360
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700361TEST_F(FrameTimelineTest, setMaxDisplayFramesSetsSizeProperly) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800362 // Global increment
363 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_))
364 .Times(static_cast<int32_t>(*maxDisplayFrames + 10));
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700365 auto presentFence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
366 presentFence->signalForTest(2);
367
368 // Size shouldn't exceed maxDisplayFrames - 64
369 for (size_t i = 0; i < *maxDisplayFrames + 10; i++) {
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700370 auto surfaceFrame =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800371 mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
372 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700373 int64_t sfToken = mTokenManager->generateTokenForPredictions({22, 26, 30});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800374 mFrameTimeline->setSfWakeUp(sfToken, 22, 11);
375 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
376 mFrameTimeline->addSurfaceFrame(surfaceFrame);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700377 mFrameTimeline->setSfPresent(27, presentFence);
378 }
379 EXPECT_EQ(getNumberOfDisplayFrames(), *maxDisplayFrames);
380
381 // Increase the size to 256
382 mFrameTimeline->setMaxDisplayFrames(256);
383 EXPECT_EQ(*maxDisplayFrames, 256);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800384 // Global increment
385 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_))
386 .Times(static_cast<int32_t>(*maxDisplayFrames + 10));
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700387
388 for (size_t i = 0; i < *maxDisplayFrames + 10; i++) {
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700389 auto surfaceFrame =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800390 mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
391 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700392 int64_t sfToken = mTokenManager->generateTokenForPredictions({22, 26, 30});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800393 mFrameTimeline->setSfWakeUp(sfToken, 22, 11);
394 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
395 mFrameTimeline->addSurfaceFrame(surfaceFrame);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700396 mFrameTimeline->setSfPresent(27, presentFence);
397 }
398 EXPECT_EQ(getNumberOfDisplayFrames(), *maxDisplayFrames);
399
400 // Shrink the size to 128
401 mFrameTimeline->setMaxDisplayFrames(128);
402 EXPECT_EQ(*maxDisplayFrames, 128);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800403 // Global increment
404 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_))
405 .Times(static_cast<int32_t>(*maxDisplayFrames + 10));
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700406
407 for (size_t i = 0; i < *maxDisplayFrames + 10; i++) {
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700408 auto surfaceFrame =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800409 mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
410 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700411 int64_t sfToken = mTokenManager->generateTokenForPredictions({22, 26, 30});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800412 mFrameTimeline->setSfWakeUp(sfToken, 22, 11);
413 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
414 mFrameTimeline->addSurfaceFrame(surfaceFrame);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700415 mFrameTimeline->setSfPresent(27, presentFence);
416 }
417 EXPECT_EQ(getNumberOfDisplayFrames(), *maxDisplayFrames);
418}
Alec Mouri9a29e672020-09-14 12:39:14 -0700419
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800420// Tests related to TimeStats
Alec Mouri9a29e672020-09-14 12:39:14 -0700421TEST_F(FrameTimelineTest, presentFenceSignaled_reportsLongSfCpu) {
422 EXPECT_CALL(*mTimeStats,
423 incrementJankyFrames(sUidOne, sLayerNameOne,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800424 HasBit(JankType::SurfaceFlingerCpuDeadlineMissed)));
Alec Mouri9a29e672020-09-14 12:39:14 -0700425 EXPECT_CALL(*mTimeStats,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800426 incrementJankyFrames(HasBit(JankType::SurfaceFlingerCpuDeadlineMissed)));
Alec Mouri9a29e672020-09-14 12:39:14 -0700427 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
428 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions(
429 {std::chrono::duration_cast<std::chrono::nanoseconds>(10ms).count(),
430 std::chrono::duration_cast<std::chrono::nanoseconds>(20ms).count(),
431 std::chrono::duration_cast<std::chrono::nanoseconds>(60ms).count()});
432 int64_t sfToken1 = mTokenManager->generateTokenForPredictions(
433 {std::chrono::duration_cast<std::chrono::nanoseconds>(52ms).count(),
434 std::chrono::duration_cast<std::chrono::nanoseconds>(56ms).count(),
435 std::chrono::duration_cast<std::chrono::nanoseconds>(60ms).count()});
436 auto surfaceFrame1 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800437 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
438 sLayerNameOne, sLayerNameOne);
Alec Mouri9a29e672020-09-14 12:39:14 -0700439 mFrameTimeline->setSfWakeUp(sfToken1,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800440 std::chrono::duration_cast<std::chrono::nanoseconds>(52ms).count(),
441 11);
442 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
443 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Alec Mouri9a29e672020-09-14 12:39:14 -0700444 presentFence1->signalForTest(
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100445 std::chrono::duration_cast<std::chrono::nanoseconds>(70ms).count());
Alec Mouri9a29e672020-09-14 12:39:14 -0700446
447 mFrameTimeline->setSfPresent(std::chrono::duration_cast<std::chrono::nanoseconds>(59ms).count(),
448 presentFence1);
449}
450
451TEST_F(FrameTimelineTest, presentFenceSignaled_reportsDisplayMiss) {
452 EXPECT_CALL(*mTimeStats,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800453 incrementJankyFrames(sUidOne, sLayerNameOne, HasBit(JankType::DisplayHAL)));
454 EXPECT_CALL(*mTimeStats, incrementJankyFrames(HasBit(JankType::DisplayHAL)));
455
Alec Mouri9a29e672020-09-14 12:39:14 -0700456 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
457 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions(
458 {std::chrono::duration_cast<std::chrono::nanoseconds>(10ms).count(),
459 std::chrono::duration_cast<std::chrono::nanoseconds>(20ms).count(),
460 std::chrono::duration_cast<std::chrono::nanoseconds>(60ms).count()});
461 int64_t sfToken1 = mTokenManager->generateTokenForPredictions(
462 {std::chrono::duration_cast<std::chrono::nanoseconds>(52ms).count(),
463 std::chrono::duration_cast<std::chrono::nanoseconds>(56ms).count(),
464 std::chrono::duration_cast<std::chrono::nanoseconds>(60ms).count()});
465 auto surfaceFrame1 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800466 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
467 sLayerNameOne, sLayerNameOne);
Alec Mouri9a29e672020-09-14 12:39:14 -0700468 mFrameTimeline->setSfWakeUp(sfToken1,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800469 std::chrono::duration_cast<std::chrono::nanoseconds>(52ms).count(),
470 30);
471 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
472 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Alec Mouri9a29e672020-09-14 12:39:14 -0700473 presentFence1->signalForTest(
474 std::chrono::duration_cast<std::chrono::nanoseconds>(90ms).count());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800475 mFrameTimeline->setSfPresent(std::chrono::duration_cast<std::chrono::nanoseconds>(56ms).count(),
Alec Mouri9a29e672020-09-14 12:39:14 -0700476 presentFence1);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800477 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::DisplayHAL);
Alec Mouri9a29e672020-09-14 12:39:14 -0700478}
479
480TEST_F(FrameTimelineTest, presentFenceSignaled_reportsAppMiss) {
481 EXPECT_CALL(*mTimeStats,
482 incrementJankyFrames(sUidOne, sLayerNameOne,
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100483 HasBit(JankType::AppDeadlineMissed)));
484 EXPECT_CALL(*mTimeStats, incrementJankyFrames(HasBit(JankType::AppDeadlineMissed)));
Alec Mouri9a29e672020-09-14 12:39:14 -0700485 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
486 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions(
487 {std::chrono::duration_cast<std::chrono::nanoseconds>(10ms).count(),
488 std::chrono::duration_cast<std::chrono::nanoseconds>(20ms).count(),
489 std::chrono::duration_cast<std::chrono::nanoseconds>(60ms).count()});
490 int64_t sfToken1 = mTokenManager->generateTokenForPredictions(
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800491 {std::chrono::duration_cast<std::chrono::nanoseconds>(82ms).count(),
492 std::chrono::duration_cast<std::chrono::nanoseconds>(86ms).count(),
493 std::chrono::duration_cast<std::chrono::nanoseconds>(90ms).count()});
Alec Mouri9a29e672020-09-14 12:39:14 -0700494 auto surfaceFrame1 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800495 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
496 sLayerNameOne, sLayerNameOne);
Alec Mouri9a29e672020-09-14 12:39:14 -0700497 surfaceFrame1->setAcquireFenceTime(
498 std::chrono::duration_cast<std::chrono::nanoseconds>(45ms).count());
499 mFrameTimeline->setSfWakeUp(sfToken1,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800500 std::chrono::duration_cast<std::chrono::nanoseconds>(52ms).count(),
501 11);
Alec Mouri9a29e672020-09-14 12:39:14 -0700502
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800503 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
504 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Alec Mouri9a29e672020-09-14 12:39:14 -0700505 presentFence1->signalForTest(
506 std::chrono::duration_cast<std::chrono::nanoseconds>(90ms).count());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800507 mFrameTimeline->setSfPresent(std::chrono::duration_cast<std::chrono::nanoseconds>(86ms).count(),
Alec Mouri9a29e672020-09-14 12:39:14 -0700508 presentFence1);
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100509
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800510 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::AppDeadlineMissed);
Alec Mouri9a29e672020-09-14 12:39:14 -0700511}
512
Adithya Srinivasan01189672020-10-20 14:23:05 -0700513/*
514 * Tracing Tests
515 *
516 * Trace packets are flushed all the way only when the next packet is traced.
517 * For example: trace<Display/Surface>Frame() will create a TracePacket but not flush it. Only when
518 * another TracePacket is created, the previous one is guaranteed to be flushed. The following tests
519 * will have additional empty frames created for this reason.
520 */
521TEST_F(FrameTimelineTest, tracing_noPacketsSentWithoutTraceStart) {
522 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800523 // Global increment
524 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700525 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
526 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
527
528 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
529 int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800530 auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(token1, sPidOne, sUidOne,
531 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700532
533 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800534 mFrameTimeline->setSfWakeUp(token1, 20, 11);
535 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Dropped);
536 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700537 mFrameTimeline->setSfPresent(25, presentFence1);
538 presentFence1->signalForTest(30);
539
540 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
541 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800542 mFrameTimeline->setSfWakeUp(token2, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700543 mFrameTimeline->setSfPresent(55, presentFence2);
544
545 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
546 EXPECT_EQ(packets.size(), 0);
547}
548
549TEST_F(FrameTimelineTest, tracing_sanityTest) {
550 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800551 // Global increment
552 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
553 // Layer specific increment
554 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700555 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
556 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
557
558 tracingSession->StartBlocking();
559 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
560 int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800561 auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(token1, sPidOne, sUidOne,
562 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700563
564 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800565 mFrameTimeline->setSfWakeUp(token2, 20, 11);
566 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
567 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700568 mFrameTimeline->setSfPresent(25, presentFence1);
569 presentFence1->signalForTest(30);
570
571 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
572 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800573 mFrameTimeline->setSfWakeUp(token2, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700574 mFrameTimeline->setSfPresent(55, presentFence2);
575 presentFence2->signalForTest(55);
576
577 // The SurfaceFrame packet from the first frame is emitted, but not flushed yet. Emitting a new
578 // packet will flush it. To emit a new packet, we'll need to call flushPendingPresentFences()
579 // again, which is done by setSfPresent().
580 addEmptyDisplayFrame();
581 tracingSession->StopBlocking();
582
583 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
584 // Display Frame 1 has two packets - DisplayFrame and a SurfaceFrame.
585 // Display Frame 2 has one packet - DisplayFrame. However, this packet has been emitted but not
586 // flushed through traced, so this is not counted.
587 EXPECT_EQ(packets.size(), 2);
588}
589
590TEST_F(FrameTimelineTest, traceDisplayFrame_invalidTokenDoesNotEmitTracePacket) {
591 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800592 // Global increment
593 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700594 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
595 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
596
597 tracingSession->StartBlocking();
598 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
599
600 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800601 mFrameTimeline->setSfWakeUp(-1, 20, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700602 mFrameTimeline->setSfPresent(25, presentFence1);
603 presentFence1->signalForTest(30);
604
605 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
606 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800607 mFrameTimeline->setSfWakeUp(token1, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700608 mFrameTimeline->setSfPresent(55, presentFence2);
609 presentFence2->signalForTest(60);
610
611 addEmptyDisplayFrame();
612 tracingSession->StopBlocking();
613
614 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
615 // Display Frame 1 has no packets.
616 // Display Frame 2 has one packet - DisplayFrame. However, this packet has
617 // been emitted but not flushed through traced, so this is not counted.
618 EXPECT_EQ(packets.size(), 0);
619}
620
621TEST_F(FrameTimelineTest, traceSurfaceFrame_invalidTokenDoesNotEmitTracePacket) {
622 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800623 // Global increment
624 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700625 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
626 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
627
628 tracingSession->StartBlocking();
629 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
630 int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800631 auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
632 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700633
634 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800635 mFrameTimeline->setSfWakeUp(token1, 20, 11);
636 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Dropped);
637 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700638 mFrameTimeline->setSfPresent(25, presentFence1);
639 presentFence1->signalForTest(30);
640
641 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
642 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800643 mFrameTimeline->setSfWakeUp(token2, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700644 mFrameTimeline->setSfPresent(55, presentFence2);
645 presentFence2->signalForTest(60);
646
647 addEmptyDisplayFrame();
648 tracingSession->StopBlocking();
649
650 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
651 // Display Frame 1 has one packet - DisplayFrame (SurfaceFrame shouldn't be traced since it has
652 // an invalid token).
653 // Display Frame 2 has one packet - DisplayFrame. However, this packet has
654 // been emitted but not flushed through traced, so this is not counted.
655 EXPECT_EQ(packets.size(), 1);
656}
657
658void validateDisplayFrameEvent(const ProtoDisplayFrame& received, const ProtoDisplayFrame& source) {
659 ASSERT_TRUE(received.has_token());
660 EXPECT_EQ(received.token(), source.token());
661
662 ASSERT_TRUE(received.has_present_type());
663 EXPECT_EQ(received.present_type(), source.present_type());
664 ASSERT_TRUE(received.has_on_time_finish());
665 EXPECT_EQ(received.on_time_finish(), source.on_time_finish());
666 ASSERT_TRUE(received.has_gpu_composition());
667 EXPECT_EQ(received.gpu_composition(), source.gpu_composition());
668 ASSERT_TRUE(received.has_jank_type());
669 EXPECT_EQ(received.jank_type(), source.jank_type());
670
671 ASSERT_TRUE(received.has_expected_start_ns());
672 EXPECT_EQ(received.expected_start_ns(), source.expected_start_ns());
673 ASSERT_TRUE(received.has_expected_end_ns());
674 EXPECT_EQ(received.expected_end_ns(), source.expected_end_ns());
675
676 ASSERT_TRUE(received.has_actual_start_ns());
677 EXPECT_EQ(received.actual_start_ns(), source.actual_start_ns());
678 ASSERT_TRUE(received.has_actual_end_ns());
679 EXPECT_EQ(received.actual_end_ns(), source.actual_end_ns());
680}
681
682void validateSurfaceFrameEvent(const ProtoSurfaceFrame& received, const ProtoSurfaceFrame& source) {
683 ASSERT_TRUE(received.has_token());
684 EXPECT_EQ(received.token(), source.token());
685
686 ASSERT_TRUE(received.has_display_frame_token());
687 EXPECT_EQ(received.display_frame_token(), source.display_frame_token());
688
689 ASSERT_TRUE(received.has_present_type());
690 EXPECT_EQ(received.present_type(), source.present_type());
691 ASSERT_TRUE(received.has_on_time_finish());
692 EXPECT_EQ(received.on_time_finish(), source.on_time_finish());
693 ASSERT_TRUE(received.has_gpu_composition());
694 EXPECT_EQ(received.gpu_composition(), source.gpu_composition());
695 ASSERT_TRUE(received.has_jank_type());
696 EXPECT_EQ(received.jank_type(), source.jank_type());
697
698 ASSERT_TRUE(received.has_expected_start_ns());
699 EXPECT_EQ(received.expected_start_ns(), source.expected_start_ns());
700 ASSERT_TRUE(received.has_expected_end_ns());
701 EXPECT_EQ(received.expected_end_ns(), source.expected_end_ns());
702
703 ASSERT_TRUE(received.has_actual_start_ns());
704 EXPECT_EQ(received.actual_start_ns(), source.actual_start_ns());
705 ASSERT_TRUE(received.has_actual_end_ns());
706 EXPECT_EQ(received.actual_end_ns(), source.actual_end_ns());
707
708 ASSERT_TRUE(received.has_layer_name());
709 EXPECT_EQ(received.layer_name(), source.layer_name());
710 ASSERT_TRUE(received.has_pid());
711 EXPECT_EQ(received.pid(), source.pid());
712}
713
714TEST_F(FrameTimelineTest, traceDisplayFrame_emitsValidTracePacket) {
715 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800716 // Global increment
717 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700718 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
719 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
720
721 tracingSession->StartBlocking();
722 int64_t displayFrameToken1 = mTokenManager->generateTokenForPredictions({10, 25, 30});
723 int64_t displayFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
724
725 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800726 mFrameTimeline->setSfWakeUp(displayFrameToken1, 20, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700727 mFrameTimeline->setSfPresent(26, presentFence1);
728 presentFence1->signalForTest(31);
729
730 ProtoDisplayFrame protoDisplayFrame;
731 protoDisplayFrame.set_token(displayFrameToken1);
732 protoDisplayFrame.set_present_type(ProtoPresentType(FrameTimelineEvent::PRESENT_ON_TIME));
733 protoDisplayFrame.set_on_time_finish(true);
734 protoDisplayFrame.set_gpu_composition(false);
735 protoDisplayFrame.set_jank_type(ProtoJankType(FrameTimelineEvent::JANK_NONE));
736 protoDisplayFrame.set_expected_start_ns(10);
737 protoDisplayFrame.set_expected_end_ns(25);
738 protoDisplayFrame.set_actual_start_ns(20);
739 protoDisplayFrame.set_actual_end_ns(26);
740
741 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
742 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800743 mFrameTimeline->setSfWakeUp(displayFrameToken2, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700744 mFrameTimeline->setSfPresent(55, presentFence2);
745 presentFence2->signalForTest(55);
746
747 addEmptyDisplayFrame();
748 tracingSession->StopBlocking();
749
750 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
751 // Display Frame 1 has one packet - DisplayFrame.
752 // Display Frame 2 has one packet - DisplayFrame. However, this packet has been emitted but not
753 // flushed through traced, so this is not counted.
754 EXPECT_EQ(packets.size(), 1);
755
756 const auto& packet = packets[0];
757 ASSERT_TRUE(packet.has_timestamp());
758 ASSERT_TRUE(packet.has_frame_timeline_event());
759
760 const auto& event = packet.frame_timeline_event();
761 ASSERT_TRUE(event.has_display_frame());
762 ASSERT_FALSE(event.has_surface_frame());
763 const auto& displayFrameEvent = event.display_frame();
764 validateDisplayFrameEvent(displayFrameEvent, protoDisplayFrame);
765}
766
767TEST_F(FrameTimelineTest, traceSurfaceFrame_emitsValidTracePacket) {
768 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800769 // Global increment
770 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
771 // Layer specific increment
772 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700773 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
774 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
775
776 tracingSession->StartBlocking();
777 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions({10, 25, 40});
778 int64_t displayFrameToken1 = mTokenManager->generateTokenForPredictions({30, 35, 40});
779 int64_t displayFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
780
781 auto surfaceFrame1 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800782 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken, sPidOne, sUidOne,
783 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700784 surfaceFrame1->setActualStartTime(0);
785 surfaceFrame1->setActualQueueTime(15);
786 surfaceFrame1->setAcquireFenceTime(20);
787
788 ProtoSurfaceFrame protoSurfaceFrame;
789 protoSurfaceFrame.set_token(surfaceFrameToken);
790 protoSurfaceFrame.set_display_frame_token(displayFrameToken1);
791 protoSurfaceFrame.set_present_type(ProtoPresentType(FrameTimelineEvent::PRESENT_ON_TIME));
792 protoSurfaceFrame.set_on_time_finish(true);
793 protoSurfaceFrame.set_gpu_composition(false);
794 protoSurfaceFrame.set_jank_type(ProtoJankType(FrameTimelineEvent::JANK_NONE));
795 protoSurfaceFrame.set_expected_start_ns(10);
796 protoSurfaceFrame.set_expected_end_ns(25);
797 protoSurfaceFrame.set_actual_start_ns(0);
798 protoSurfaceFrame.set_actual_end_ns(20);
799 protoSurfaceFrame.set_layer_name(sLayerNameOne);
800 protoSurfaceFrame.set_pid(sPidOne);
801
802 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800803 mFrameTimeline->setSfWakeUp(displayFrameToken1, 20, 11);
804 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
805 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700806 mFrameTimeline->setSfPresent(26, presentFence1);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800807 presentFence1->signalForTest(40);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700808
809 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
810 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800811 mFrameTimeline->setSfWakeUp(displayFrameToken2, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700812 mFrameTimeline->setSfPresent(55, presentFence2);
813 presentFence2->signalForTest(55);
814
815 addEmptyDisplayFrame();
816 tracingSession->StopBlocking();
817
818 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
819 // Display Frame 1 has one packet - DisplayFrame and a SurfaceFrame.
820 // Display Frame 2 has one packet - DisplayFrame. However, this packet has been emitted but not
821 // flushed through traced, so this is not counted.
822 EXPECT_EQ(packets.size(), 2);
823
824 const auto& packet = packets[1];
825 ASSERT_TRUE(packet.has_timestamp());
826 ASSERT_TRUE(packet.has_frame_timeline_event());
827
828 const auto& event = packet.frame_timeline_event();
829 ASSERT_TRUE(!event.has_display_frame());
830 ASSERT_TRUE(event.has_surface_frame());
831 const auto& surfaceFrameEvent = event.surface_frame();
832 validateSurfaceFrameEvent(surfaceFrameEvent, protoSurfaceFrame);
833}
834
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800835// Tests for Jank classification
836TEST_F(FrameTimelineTest, jankClassification_presentOnTimeDoesNotClassify) {
837 // Global increment
838 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
839 // Layer specific increment
840 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_));
841 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
842 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions({10, 20, 30});
843 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 30});
844 auto surfaceFrame =
845 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken, sPidOne, sUidOne,
846 sLayerNameOne, sLayerNameOne);
847 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
848 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
849 mFrameTimeline->addSurfaceFrame(surfaceFrame);
850 mFrameTimeline->setSfPresent(26, presentFence1);
851 auto displayFrame = getDisplayFrame(0);
852 auto& presentedSurfaceFrame = getSurfaceFrame(0, 0);
853 presentFence1->signalForTest(29);
854
855 // Fences haven't been flushed yet, so it should be 0
856 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
857 EXPECT_EQ(presentedSurfaceFrame.getActuals().presentTime, 0);
858
859 addEmptyDisplayFrame();
860 displayFrame = getDisplayFrame(0);
861
862 // Fences have flushed, so the present timestamps should be updated
863 EXPECT_EQ(displayFrame->getActuals().presentTime, 29);
864 EXPECT_EQ(presentedSurfaceFrame.getActuals().presentTime, 29);
865 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
866 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
867 EXPECT_EQ(displayFrame->getJankType(), JankType::None);
868}
869
870TEST_F(FrameTimelineTest, jankClassification_displayFrameOnTimeFinishEarlyPresent) {
871 // Global increment
872 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
873 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
874 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
875 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 56, 70});
876 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
877 mFrameTimeline->setSfPresent(26, presentFence1);
878 auto displayFrame = getDisplayFrame(0);
879 presentFence1->signalForTest(30);
880
881 // Fences for the first frame haven't been flushed yet, so it should be 0
882 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
883
884 // Trigger a flush by finalizing the next DisplayFrame
885 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
886 mFrameTimeline->setSfWakeUp(sfToken2, 52, 11);
887 mFrameTimeline->setSfPresent(56, presentFence2);
888 displayFrame = getDisplayFrame(0);
889
890 // Fences for the first frame have flushed, so the present timestamps should be updated
891 EXPECT_EQ(displayFrame->getActuals().presentTime, 30);
892 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
893 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
894 EXPECT_EQ(displayFrame->getJankType(), JankType::SurfaceFlingerScheduling);
895
896 // Fences for the second frame haven't been flushed yet, so it should be 0
897 auto displayFrame2 = getDisplayFrame(1);
898 presentFence2->signalForTest(65);
899 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
900
901 addEmptyDisplayFrame();
902 displayFrame2 = getDisplayFrame(1);
903
904 // Fences for the second frame have flushed, so the present timestamps should be updated
905 EXPECT_EQ(displayFrame2->getActuals().presentTime, 65);
906 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
907 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
908 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
909}
910
911TEST_F(FrameTimelineTest, jankClassification_displayFrameOnTimeFinishLatePresent) {
912 // Global increment
913 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
914 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
915 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
916 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 56, 70});
917 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
918 mFrameTimeline->setSfPresent(26, presentFence1);
919 auto displayFrame = getDisplayFrame(0);
920 presentFence1->signalForTest(50);
921
922 // Fences for the first frame haven't been flushed yet, so it should be 0
923 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
924
925 // Trigger a flush by finalizing the next DisplayFrame
926 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
927 mFrameTimeline->setSfWakeUp(sfToken2, 52, 11);
928 mFrameTimeline->setSfPresent(56, presentFence2);
929 displayFrame = getDisplayFrame(0);
930
931 // Fences for the first frame have flushed, so the present timestamps should be updated
932 EXPECT_EQ(displayFrame->getActuals().presentTime, 50);
933 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
934 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
935 EXPECT_EQ(displayFrame->getJankType(), JankType::DisplayHAL);
936
937 // Fences for the second frame haven't been flushed yet, so it should be 0
938 auto displayFrame2 = getDisplayFrame(1);
939 presentFence2->signalForTest(75);
940 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
941
942 addEmptyDisplayFrame();
943 displayFrame2 = getDisplayFrame(1);
944
945 // Fences for the second frame have flushed, so the present timestamps should be updated
946 EXPECT_EQ(displayFrame2->getActuals().presentTime, 75);
947 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
948 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
949 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
950}
951
952TEST_F(FrameTimelineTest, jankClassification_displayFrameLateFinishEarlyPresent) {
953 // Global increment
954 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
955 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
956 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({12, 18, 40});
957 mFrameTimeline->setSfWakeUp(sfToken1, 12, 11);
958
959 mFrameTimeline->setSfPresent(22, presentFence1);
960 auto displayFrame = getDisplayFrame(0);
961 presentFence1->signalForTest(28);
962
963 // Fences haven't been flushed yet, so it should be 0
964 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
965
966 addEmptyDisplayFrame();
967 displayFrame = getDisplayFrame(0);
968
969 // Fences have flushed, so the present timestamps should be updated
970 EXPECT_EQ(displayFrame->getActuals().presentTime, 28);
971 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
972 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
973 EXPECT_EQ(displayFrame->getJankType(), JankType::SurfaceFlingerScheduling);
974}
975
976TEST_F(FrameTimelineTest, jankClassification_displayFrameLateFinishLatePresent) {
977 // Global increment
978 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
979 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
980 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
981 mFrameTimeline->setSfWakeUp(sfToken1, 12, 11);
982 mFrameTimeline->setSfPresent(36, presentFence1);
983 auto displayFrame = getDisplayFrame(0);
984 presentFence1->signalForTest(52);
985
986 // Fences haven't been flushed yet, so it should be 0
987 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
988
989 addEmptyDisplayFrame();
990 displayFrame = getDisplayFrame(0);
991
992 // Fences have flushed, so the present timestamps should be updated
993 EXPECT_EQ(displayFrame->getActuals().presentTime, 52);
994 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
995 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
996 EXPECT_EQ(displayFrame->getJankType(), JankType::SurfaceFlingerCpuDeadlineMissed);
997}
998
999TEST_F(FrameTimelineTest, jankClassification_surfaceFrameOnTimeFinishEarlyPresent) {
1000 // Global increment
1001 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
1002 // Layer specific increment
1003 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_)).Times(2);
1004 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1005 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
1006 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 56, 70});
1007 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 16, 40});
1008 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({25, 36, 70});
1009 auto surfaceFrame1 =
1010 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
1011 sLayerNameOne, sLayerNameOne);
1012 surfaceFrame1->setAcquireFenceTime(16);
1013 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
1014 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1015 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1016 mFrameTimeline->setSfPresent(26, presentFence1);
1017 auto displayFrame1 = getDisplayFrame(0);
1018 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1019 presentFence1->signalForTest(30);
1020
1021 // Fences for the first frame haven't been flushed yet, so it should be 0
1022 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1023 auto actuals1 = presentedSurfaceFrame1.getActuals();
1024 EXPECT_EQ(actuals1.presentTime, 0);
1025
1026 // Trigger a flush by finalizing the next DisplayFrame
1027 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1028 auto surfaceFrame2 =
1029 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken2, sPidOne, sUidOne,
1030 sLayerNameOne, sLayerNameOne);
1031 surfaceFrame2->setAcquireFenceTime(36);
1032 mFrameTimeline->setSfWakeUp(sfToken2, 52, 11);
1033 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
1034 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1035 mFrameTimeline->setSfPresent(56, presentFence2);
1036 auto displayFrame2 = getDisplayFrame(1);
1037 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1038
1039 // Fences for the first frame have flushed, so the present timestamps should be updated
1040 EXPECT_EQ(displayFrame1->getActuals().presentTime, 30);
1041 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1042 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1043 EXPECT_EQ(displayFrame1->getJankType(), JankType::SurfaceFlingerScheduling);
1044
1045 actuals1 = presentedSurfaceFrame1.getActuals();
1046 EXPECT_EQ(actuals1.presentTime, 30);
1047 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1048 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1049 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::SurfaceFlingerScheduling);
1050
1051 // Fences for the second frame haven't been flushed yet, so it should be 0
1052 presentFence2->signalForTest(65);
1053 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1054 auto actuals2 = presentedSurfaceFrame2.getActuals();
1055 EXPECT_EQ(actuals2.presentTime, 0);
1056
1057 addEmptyDisplayFrame();
1058
1059 // Fences for the second frame have flushed, so the present timestamps should be updated
1060 EXPECT_EQ(displayFrame2->getActuals().presentTime, 65);
1061 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1062 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1063 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
1064
1065 actuals2 = presentedSurfaceFrame2.getActuals();
1066 EXPECT_EQ(actuals2.presentTime, 65);
1067 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1068 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1069 EXPECT_EQ(presentedSurfaceFrame2.getJankType(), JankType::PredictionError);
1070}
1071
1072TEST_F(FrameTimelineTest, jankClassification_surfaceFrameOnTimeFinishLatePresent) {
1073 // Global increment
1074 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
1075 // Layer specific increment
1076 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_)).Times(2);
1077 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1078 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
1079 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 56, 70});
1080 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 16, 40});
1081 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({25, 36, 70});
1082 auto surfaceFrame1 =
1083 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
1084 sLayerNameOne, sLayerNameOne);
1085 surfaceFrame1->setAcquireFenceTime(16);
1086 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
1087 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1088 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1089 mFrameTimeline->setSfPresent(26, presentFence1);
1090 auto displayFrame1 = getDisplayFrame(0);
1091 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1092 presentFence1->signalForTest(50);
1093
1094 // Fences for the first frame haven't been flushed yet, so it should be 0
1095 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1096 auto actuals1 = presentedSurfaceFrame1.getActuals();
1097 EXPECT_EQ(actuals1.presentTime, 0);
1098
1099 // Trigger a flush by finalizing the next DisplayFrame
1100 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1101 auto surfaceFrame2 =
1102 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken2, sPidOne, sUidOne,
1103 sLayerNameOne, sLayerNameOne);
1104 surfaceFrame2->setAcquireFenceTime(36);
1105 mFrameTimeline->setSfWakeUp(sfToken2, 52, 11);
1106 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
1107 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1108 mFrameTimeline->setSfPresent(56, presentFence2);
1109 auto displayFrame2 = getDisplayFrame(1);
1110 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1111
1112 // Fences for the first frame have flushed, so the present timestamps should be updated
1113 EXPECT_EQ(displayFrame1->getActuals().presentTime, 50);
1114 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1115 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1116 EXPECT_EQ(displayFrame1->getJankType(), JankType::DisplayHAL);
1117
1118 actuals1 = presentedSurfaceFrame1.getActuals();
1119 EXPECT_EQ(actuals1.presentTime, 50);
1120 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1121 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1122 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::DisplayHAL);
1123
1124 // Fences for the second frame haven't been flushed yet, so it should be 0
1125 presentFence2->signalForTest(86);
1126 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1127 auto actuals2 = presentedSurfaceFrame2.getActuals();
1128 EXPECT_EQ(actuals2.presentTime, 0);
1129
1130 addEmptyDisplayFrame();
1131
1132 // Fences for the second frame have flushed, so the present timestamps should be updated
1133 EXPECT_EQ(displayFrame2->getActuals().presentTime, 86);
1134 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1135 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1136 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
1137
1138 actuals2 = presentedSurfaceFrame2.getActuals();
1139 EXPECT_EQ(actuals2.presentTime, 86);
1140 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1141 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1142 EXPECT_EQ(presentedSurfaceFrame2.getJankType(), JankType::PredictionError);
1143}
1144
1145TEST_F(FrameTimelineTest, jankClassification_surfaceFrameLateFinishEarlyPresent) {
1146 // Global increment
1147 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
1148 // Layer specific increment
1149 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_));
1150 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1151 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({42, 46, 50});
1152 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 26, 60});
1153 auto surfaceFrame1 =
1154 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
1155 sLayerNameOne, sLayerNameOne);
1156 surfaceFrame1->setAcquireFenceTime(40);
1157 mFrameTimeline->setSfWakeUp(sfToken1, 42, 11);
1158 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1159 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1160 mFrameTimeline->setSfPresent(46, presentFence1);
1161 auto displayFrame1 = getDisplayFrame(0);
1162 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1163 presentFence1->signalForTest(50);
1164
1165 // Fences for the first frame haven't been flushed yet, so it should be 0
1166 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1167 auto actuals1 = presentedSurfaceFrame1.getActuals();
1168 EXPECT_EQ(actuals1.presentTime, 0);
1169
1170 addEmptyDisplayFrame();
1171
1172 // Fences for the first frame have flushed, so the present timestamps should be updated
1173 EXPECT_EQ(displayFrame1->getActuals().presentTime, 50);
1174 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1175 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1176 EXPECT_EQ(displayFrame1->getJankType(), JankType::None);
1177
1178 actuals1 = presentedSurfaceFrame1.getActuals();
1179 EXPECT_EQ(actuals1.presentTime, 50);
1180 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1181 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1182 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::Unknown);
1183}
1184
1185TEST_F(FrameTimelineTest, jankClassification_surfaceFrameLateFinishLatePresent) {
1186 // First frame - DisplayFrame is not janky. This should classify the SurfaceFrame as
1187 // AppDeadlineMissed. Second frame - DisplayFrame is janky. This should propagate DisplayFrame's
1188 // jank to the SurfaceFrame.
1189
1190 // Global increment
1191 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
1192 // Layer specific increment
1193 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_)).Times(2);
1194 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1195 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({32, 36, 40});
1196 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({42, 46, 50});
1197 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 16, 30});
1198 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({25, 36, 50});
1199 auto surfaceFrame1 =
1200 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
1201 sLayerNameOne, sLayerNameOne);
1202 surfaceFrame1->setAcquireFenceTime(26);
1203 mFrameTimeline->setSfWakeUp(sfToken1, 32, 11);
1204 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1205 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1206 mFrameTimeline->setSfPresent(36, presentFence1);
1207 auto displayFrame1 = getDisplayFrame(0);
1208 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1209 presentFence1->signalForTest(40);
1210
1211 // Fences for the first frame haven't been flushed yet, so it should be 0
1212 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1213 auto actuals1 = presentedSurfaceFrame1.getActuals();
1214 EXPECT_EQ(actuals1.presentTime, 0);
1215
1216 // Trigger a flush by finalizing the next DisplayFrame
1217 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1218 auto surfaceFrame2 =
1219 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken2, sPidOne, sUidOne,
1220 sLayerNameOne, sLayerNameOne);
1221 surfaceFrame2->setAcquireFenceTime(40);
1222 mFrameTimeline->setSfWakeUp(sfToken2, 43, 11);
1223 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
1224 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1225 mFrameTimeline->setSfPresent(56, presentFence2);
1226 auto displayFrame2 = getDisplayFrame(1);
1227 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1228
1229 // Fences for the first frame have flushed, so the present timestamps should be updated
1230 EXPECT_EQ(displayFrame1->getActuals().presentTime, 40);
1231 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1232 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1233 EXPECT_EQ(displayFrame1->getJankType(), JankType::None);
1234
1235 actuals1 = presentedSurfaceFrame1.getActuals();
1236 EXPECT_EQ(actuals1.presentTime, 40);
1237 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1238 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1239 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::AppDeadlineMissed);
1240
1241 // Fences for the second frame haven't been flushed yet, so it should be 0
1242 presentFence2->signalForTest(60);
1243 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1244 auto actuals2 = presentedSurfaceFrame2.getActuals();
1245 EXPECT_EQ(actuals2.presentTime, 0);
1246
1247 addEmptyDisplayFrame();
1248
1249 // Fences for the second frame have flushed, so the present timestamps should be updated
1250 EXPECT_EQ(displayFrame2->getActuals().presentTime, 60);
1251 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1252 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1253 EXPECT_EQ(displayFrame2->getJankType(), JankType::SurfaceFlingerCpuDeadlineMissed);
1254
1255 actuals2 = presentedSurfaceFrame2.getActuals();
1256 EXPECT_EQ(actuals2.presentTime, 60);
1257 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1258 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1259 EXPECT_EQ(presentedSurfaceFrame2.getJankType(), JankType::SurfaceFlingerCpuDeadlineMissed);
1260}
1261
1262TEST_F(FrameTimelineTest, jankClassification_multiJankBufferStuffingAndAppDeadlineMissed) {
1263 // Global increment
1264 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
1265 // Layer specific increment
1266 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_)).Times(2);
1267 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1268 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
1269 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
1270
1271 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({52, 56, 60});
1272 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({112, 116, 120});
1273 auto surfaceFrame1 =
1274 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
1275 sLayerNameOne, sLayerNameOne);
1276 surfaceFrame1->setAcquireFenceTime(50);
1277 mFrameTimeline->setSfWakeUp(sfToken1, 52, 30);
1278 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1279 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1280 mFrameTimeline->setSfPresent(56, presentFence1);
1281 auto displayFrame1 = getDisplayFrame(0);
1282 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1283 presentFence1->signalForTest(60);
1284
1285 // Fences for the first frame haven't been flushed yet, so it should be 0
1286 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1287 auto actuals1 = presentedSurfaceFrame1.getActuals();
1288 EXPECT_EQ(actuals1.presentTime, 0);
1289
1290 // Trigger a flush by finalizing the next DisplayFrame
1291 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1292 auto surfaceFrame2 =
1293 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken2, sPidOne, sUidOne,
1294 sLayerNameOne, sLayerNameOne);
1295 surfaceFrame2->setAcquireFenceTime(84);
1296 mFrameTimeline->setSfWakeUp(sfToken2, 112, 30);
1297 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented, 54);
1298 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1299 mFrameTimeline->setSfPresent(116, presentFence2);
1300 auto displayFrame2 = getDisplayFrame(1);
1301 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1302 presentFence2->signalForTest(120);
1303
1304 // Fences for the first frame have flushed, so the present timestamps should be updated
1305 EXPECT_EQ(displayFrame1->getActuals().presentTime, 60);
1306 actuals1 = presentedSurfaceFrame1.getActuals();
1307 EXPECT_EQ(actuals1.endTime, 50);
1308 EXPECT_EQ(actuals1.presentTime, 60);
1309
1310 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1311 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1312 EXPECT_EQ(displayFrame1->getJankType(), JankType::None);
1313
1314 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1315 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1316 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::AppDeadlineMissed);
1317
1318 // Fences for the second frame haven't been flushed yet, so it should be 0
1319 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1320 auto actuals2 = presentedSurfaceFrame2.getActuals();
1321 EXPECT_EQ(actuals2.presentTime, 0);
1322
1323 addEmptyDisplayFrame();
1324
1325 // Fences for the second frame have flushed, so the present timestamps should be updated
1326 EXPECT_EQ(displayFrame2->getActuals().presentTime, 120);
1327 actuals2 = presentedSurfaceFrame2.getActuals();
1328 EXPECT_EQ(actuals2.presentTime, 120);
1329
1330 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1331 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1332 EXPECT_EQ(displayFrame2->getJankType(), JankType::None);
1333
1334 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1335 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1336 EXPECT_EQ(presentedSurfaceFrame2.getJankType(),
1337 JankType::AppDeadlineMissed | JankType::BufferStuffing);
1338}
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001339} // namespace android::frametimeline
Marin Shalamanovbed7fd32020-12-21 20:02:20 +01001340
1341// TODO(b/129481165): remove the #pragma below and fix conversion issues
1342#pragma clang diagnostic pop // ignored "-Wextra"