blob: 4b897fa17cccd4c9064d3a3d873ee7311c816308 [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
Alec Mouri9a29e672020-09-14 12:39:14 -070017#include "gmock/gmock-spec-builders.h"
18#include "mock/MockTimeStats.h"
Adithya Srinivasanf279e042020-08-17 14:56:27 -070019#undef LOG_TAG
20#define LOG_TAG "LibSurfaceFlingerUnittests"
21
22#include <FrameTimeline/FrameTimeline.h>
23#include <gtest/gtest.h>
24#include <log/log.h>
Adithya Srinivasan01189672020-10-20 14:23:05 -070025#include <perfetto/trace/trace.pb.h>
Adithya Srinivasanf279e042020-08-17 14:56:27 -070026#include <cinttypes>
27
28using namespace std::chrono_literals;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080029using testing::AtLeast;
Alec Mouri9a29e672020-09-14 12:39:14 -070030using testing::Contains;
Adithya Srinivasan01189672020-10-20 14:23:05 -070031using FrameTimelineEvent = perfetto::protos::FrameTimelineEvent;
32using ProtoDisplayFrame = perfetto::protos::FrameTimelineEvent_DisplayFrame;
33using ProtoSurfaceFrame = perfetto::protos::FrameTimelineEvent_SurfaceFrame;
34using ProtoPresentType = perfetto::protos::FrameTimelineEvent_PresentType;
35using ProtoJankType = perfetto::protos::FrameTimelineEvent_JankType;
Alec Mouri9a29e672020-09-14 12:39:14 -070036
37MATCHER_P(HasBit, bit, "") {
38 return (arg & bit) != 0;
39}
Adithya Srinivasanf279e042020-08-17 14:56:27 -070040
41namespace android::frametimeline {
42
43class FrameTimelineTest : public testing::Test {
44public:
45 FrameTimelineTest() {
46 const ::testing::TestInfo* const test_info =
47 ::testing::UnitTest::GetInstance()->current_test_info();
48 ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
49 }
50
51 ~FrameTimelineTest() {
52 const ::testing::TestInfo* const test_info =
53 ::testing::UnitTest::GetInstance()->current_test_info();
54 ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
55 }
56
Adithya Srinivasan01189672020-10-20 14:23:05 -070057 static void SetUpTestSuite() {
58 // Need to initialize tracing in process for testing, and only once per test suite.
59 perfetto::TracingInitArgs args;
60 args.backends = perfetto::kInProcessBackend;
61 perfetto::Tracing::Initialize(args);
62 }
63
Adithya Srinivasanf279e042020-08-17 14:56:27 -070064 void SetUp() override {
Alec Mouri9a29e672020-09-14 12:39:14 -070065 mTimeStats = std::make_shared<mock::TimeStats>();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -080066 mFrameTimeline = std::make_unique<impl::FrameTimeline>(mTimeStats, mSurfaceFlingerPid,
67 kTestThresholds);
Adithya Srinivasan01189672020-10-20 14:23:05 -070068 mFrameTimeline->registerDataSource();
Adithya Srinivasanf279e042020-08-17 14:56:27 -070069 mTokenManager = &mFrameTimeline->mTokenManager;
Adithya Srinivasan2d736322020-10-01 16:53:48 -070070 maxDisplayFrames = &mFrameTimeline->mMaxDisplayFrames;
Adithya Srinivasanf279e042020-08-17 14:56:27 -070071 maxTokenRetentionTime = mTokenManager->kMaxRetentionTime;
72 }
73
Adithya Srinivasan01189672020-10-20 14:23:05 -070074 // Each tracing session can be used for a single block of Start -> Stop.
75 static std::unique_ptr<perfetto::TracingSession> getTracingSessionForTest() {
76 perfetto::TraceConfig cfg;
77 cfg.set_duration_ms(500);
78 cfg.add_buffers()->set_size_kb(1024);
79 auto* ds_cfg = cfg.add_data_sources()->mutable_config();
80 ds_cfg->set_name(impl::FrameTimeline::kFrameTimelineDataSource);
81
82 auto tracingSession = perfetto::Tracing::NewTrace(perfetto::kInProcessBackend);
83 tracingSession->Setup(cfg);
84 return tracingSession;
85 }
86
87 std::vector<perfetto::protos::TracePacket> readFrameTimelinePacketsBlocking(
88 perfetto::TracingSession* tracingSession) {
89 std::vector<char> raw_trace = tracingSession->ReadTraceBlocking();
90 perfetto::protos::Trace trace;
91 EXPECT_TRUE(trace.ParseFromArray(raw_trace.data(), int(raw_trace.size())));
92
93 std::vector<perfetto::protos::TracePacket> packets;
94 for (const auto& packet : trace.packet()) {
95 if (!packet.has_frame_timeline_event()) {
96 continue;
97 }
98 packets.emplace_back(packet);
99 }
100 return packets;
101 }
102
103 void addEmptyDisplayFrame() {
104 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
105 mFrameTimeline->setSfPresent(2500, presentFence1);
106 }
107
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700108 void flushTokens(nsecs_t flushTime) {
109 std::lock_guard<std::mutex> lock(mTokenManager->mMutex);
110 mTokenManager->flushTokens(flushTime);
111 }
112
113 SurfaceFrame& getSurfaceFrame(size_t displayFrameIdx, size_t surfaceFrameIdx) {
114 std::lock_guard<std::mutex> lock(mFrameTimeline->mMutex);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800115 return *(mFrameTimeline->mDisplayFrames[displayFrameIdx]
116 ->getSurfaceFrames()[surfaceFrameIdx]);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700117 }
118
119 std::shared_ptr<impl::FrameTimeline::DisplayFrame> getDisplayFrame(size_t idx) {
120 std::lock_guard<std::mutex> lock(mFrameTimeline->mMutex);
121 return mFrameTimeline->mDisplayFrames[idx];
122 }
123
124 static bool compareTimelineItems(const TimelineItem& a, const TimelineItem& b) {
125 return a.startTime == b.startTime && a.endTime == b.endTime &&
126 a.presentTime == b.presentTime;
127 }
128
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800129 const std::map<int64_t, TokenManagerPrediction>& getPredictions() {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700130 return mTokenManager->mPredictions;
131 }
132
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700133 uint32_t getNumberOfDisplayFrames() {
134 std::lock_guard<std::mutex> lock(mFrameTimeline->mMutex);
135 return static_cast<uint32_t>(mFrameTimeline->mDisplayFrames.size());
136 }
137
Alec Mouri9a29e672020-09-14 12:39:14 -0700138 std::shared_ptr<mock::TimeStats> mTimeStats;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700139 std::unique_ptr<impl::FrameTimeline> mFrameTimeline;
140 impl::TokenManager* mTokenManager;
141 FenceToFenceTimeMap fenceFactory;
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700142 uint32_t* maxDisplayFrames;
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700143 nsecs_t maxTokenRetentionTime;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800144 pid_t mSurfaceFlingerPid = 666;
145 static constexpr nsecs_t kPresentThreshold =
146 std::chrono::duration_cast<std::chrono::nanoseconds>(2ns).count();
147 static constexpr nsecs_t kDeadlineThreshold =
148 std::chrono::duration_cast<std::chrono::nanoseconds>(2ns).count();
149 static constexpr nsecs_t kStartThreshold =
150 std::chrono::duration_cast<std::chrono::nanoseconds>(2ns).count();
151 static constexpr JankClassificationThresholds kTestThresholds{kPresentThreshold,
152 kDeadlineThreshold,
153 kStartThreshold};
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700154};
155
Alec Mouri9a29e672020-09-14 12:39:14 -0700156static const std::string sLayerNameOne = "layer1";
157static const std::string sLayerNameTwo = "layer2";
158static constexpr const uid_t sUidOne = 0;
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700159static constexpr pid_t sPidOne = 10;
160static constexpr pid_t sPidTwo = 20;
Alec Mouri9a29e672020-09-14 12:39:14 -0700161
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700162TEST_F(FrameTimelineTest, tokenManagerRemovesStalePredictions) {
163 int64_t token1 = mTokenManager->generateTokenForPredictions({0, 0, 0});
164 EXPECT_EQ(getPredictions().size(), 1);
165 flushTokens(systemTime() + maxTokenRetentionTime);
166 int64_t token2 = mTokenManager->generateTokenForPredictions({10, 20, 30});
167 std::optional<TimelineItem> predictions = mTokenManager->getPredictionsForToken(token1);
168
169 // token1 should have expired
170 EXPECT_EQ(getPredictions().size(), 1);
171 EXPECT_EQ(predictions.has_value(), false);
172
173 predictions = mTokenManager->getPredictionsForToken(token2);
174 EXPECT_EQ(compareTimelineItems(*predictions, TimelineItem(10, 20, 30)), true);
175}
176
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700177TEST_F(FrameTimelineTest, createSurfaceFrameForToken_getOwnerPidReturnsCorrectPid) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800178 auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
179 sLayerNameOne, sLayerNameOne);
180 auto surfaceFrame2 = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidTwo, sUidOne,
181 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700182 EXPECT_EQ(surfaceFrame1->getOwnerPid(), sPidOne);
183 EXPECT_EQ(surfaceFrame2->getOwnerPid(), sPidTwo);
184}
185
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700186TEST_F(FrameTimelineTest, createSurfaceFrameForToken_noToken) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800187 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
188 sLayerNameOne, sLayerNameOne);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700189 EXPECT_EQ(surfaceFrame->getPredictionState(), PredictionState::None);
190}
191
192TEST_F(FrameTimelineTest, createSurfaceFrameForToken_expiredToken) {
193 int64_t token1 = mTokenManager->generateTokenForPredictions({0, 0, 0});
194 flushTokens(systemTime() + maxTokenRetentionTime);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800195 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken(token1, sPidOne, sUidOne,
196 sLayerNameOne, sLayerNameOne);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700197
198 EXPECT_EQ(surfaceFrame->getPredictionState(), PredictionState::Expired);
199}
200
201TEST_F(FrameTimelineTest, createSurfaceFrameForToken_validToken) {
202 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800203 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken(token1, sPidOne, sUidOne,
204 sLayerNameOne, sLayerNameOne);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700205
206 EXPECT_EQ(surfaceFrame->getPredictionState(), PredictionState::Valid);
207 EXPECT_EQ(compareTimelineItems(surfaceFrame->getPredictions(), TimelineItem(10, 20, 30)), true);
208}
209
210TEST_F(FrameTimelineTest, presentFenceSignaled_droppedFramesNotUpdated) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800211 // Global increment
212 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700213 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
214 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
215
216 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
217 int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800218 auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(token1, sPidOne, sUidOne,
219 sLayerNameOne, sLayerNameOne);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700220
221 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800222 mFrameTimeline->setSfWakeUp(token1, 20, 11);
223 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Dropped);
224 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700225 mFrameTimeline->setSfPresent(25, presentFence1);
226 presentFence1->signalForTest(30);
227
228 // Trigger a flush by calling setSfPresent for the next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800229 mFrameTimeline->setSfWakeUp(token2, 50, 11);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700230 mFrameTimeline->setSfPresent(55, presentFence2);
231
232 auto& droppedSurfaceFrame = getSurfaceFrame(0, 0);
233 EXPECT_EQ(droppedSurfaceFrame.getPresentState(), SurfaceFrame::PresentState::Dropped);
234 EXPECT_EQ(droppedSurfaceFrame.getActuals().presentTime, 0);
235}
236
237TEST_F(FrameTimelineTest, presentFenceSignaled_presentedFramesUpdated) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800238 // Global increment
239 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
240 // Layer specific increment
241 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_)).Times(2);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700242 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
243 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
244 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
245 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 30});
246 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 56, 60});
Alec Mouri9a29e672020-09-14 12:39:14 -0700247 auto surfaceFrame1 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800248 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
249 sLayerNameOne, sLayerNameOne);
Alec Mouri9a29e672020-09-14 12:39:14 -0700250 auto surfaceFrame2 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800251 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
252 sLayerNameTwo, sLayerNameTwo);
253 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
254 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
255 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
256 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
257 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700258 mFrameTimeline->setSfPresent(26, presentFence1);
259 auto displayFrame = getDisplayFrame(0);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800260 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
261 auto& presentedSurfaceFrame2 = getSurfaceFrame(0, 1);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700262 presentFence1->signalForTest(42);
263
264 // Fences haven't been flushed yet, so it should be 0
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800265 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700266 EXPECT_EQ(presentedSurfaceFrame1.getActuals().presentTime, 0);
267 EXPECT_EQ(presentedSurfaceFrame2.getActuals().presentTime, 0);
268
269 // Trigger a flush by finalizing the next DisplayFrame
270 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
Alec Mouri9a29e672020-09-14 12:39:14 -0700271 auto surfaceFrame3 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800272 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken2, sPidOne, sUidOne,
273 sLayerNameOne, sLayerNameOne);
274 mFrameTimeline->setSfWakeUp(sfToken2, 52, 11);
275 surfaceFrame3->setPresentState(SurfaceFrame::PresentState::Dropped);
276 mFrameTimeline->addSurfaceFrame(surfaceFrame3);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700277 mFrameTimeline->setSfPresent(56, presentFence2);
278 displayFrame = getDisplayFrame(0);
279
280 // Fences have flushed, so the present timestamps should be updated
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800281 EXPECT_EQ(displayFrame->getActuals().presentTime, 42);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700282 EXPECT_EQ(presentedSurfaceFrame1.getActuals().presentTime, 42);
283 EXPECT_EQ(presentedSurfaceFrame2.getActuals().presentTime, 42);
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100284 EXPECT_NE(surfaceFrame1->getJankType(), std::nullopt);
285 EXPECT_NE(surfaceFrame2->getJankType(), std::nullopt);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700286}
287
288TEST_F(FrameTimelineTest, displayFramesSlidingWindowMovesAfterLimit) {
289 // Insert kMaxDisplayFrames' count of DisplayFrames to fill the deque
290 int frameTimeFactor = 0;
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800291 // Global increment
292 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_))
293 .Times(static_cast<int32_t>(*maxDisplayFrames));
294 // Layer specific increment
295 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_))
296 .Times(static_cast<int32_t>(*maxDisplayFrames));
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700297 for (size_t i = 0; i < *maxDisplayFrames; i++) {
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700298 auto presentFence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
299 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions(
300 {10 + frameTimeFactor, 20 + frameTimeFactor, 30 + frameTimeFactor});
301 int64_t sfToken = mTokenManager->generateTokenForPredictions(
302 {22 + frameTimeFactor, 26 + frameTimeFactor, 30 + frameTimeFactor});
Alec Mouri9a29e672020-09-14 12:39:14 -0700303 auto surfaceFrame =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800304 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken, sPidOne, sUidOne,
305 sLayerNameOne, sLayerNameOne);
306 mFrameTimeline->setSfWakeUp(sfToken, 22 + frameTimeFactor, 11);
307 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
308 mFrameTimeline->addSurfaceFrame(surfaceFrame);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700309 mFrameTimeline->setSfPresent(27 + frameTimeFactor, presentFence);
310 presentFence->signalForTest(32 + frameTimeFactor);
311 frameTimeFactor += 30;
312 }
313 auto displayFrame0 = getDisplayFrame(0);
314
315 // The 0th Display Frame should have actuals 22, 27, 32
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800316 EXPECT_EQ(compareTimelineItems(displayFrame0->getActuals(), TimelineItem(22, 27, 32)), true);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700317
318 // Add one more display frame
319 auto presentFence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
320 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions(
321 {10 + frameTimeFactor, 20 + frameTimeFactor, 30 + frameTimeFactor});
322 int64_t sfToken = mTokenManager->generateTokenForPredictions(
323 {22 + frameTimeFactor, 26 + frameTimeFactor, 30 + frameTimeFactor});
Alec Mouri9a29e672020-09-14 12:39:14 -0700324 auto surfaceFrame =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800325 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken, sPidOne, sUidOne,
326 sLayerNameOne, sLayerNameOne);
327 mFrameTimeline->setSfWakeUp(sfToken, 22 + frameTimeFactor, 11);
328 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
329 mFrameTimeline->addSurfaceFrame(surfaceFrame);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700330 mFrameTimeline->setSfPresent(27 + frameTimeFactor, presentFence);
331 presentFence->signalForTest(32 + frameTimeFactor);
332 displayFrame0 = getDisplayFrame(0);
333
334 // The window should have slided by 1 now and the previous 0th display frame
335 // should have been removed from the deque
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800336 EXPECT_EQ(compareTimelineItems(displayFrame0->getActuals(), TimelineItem(52, 57, 62)), true);
Adithya Srinivasanf279e042020-08-17 14:56:27 -0700337}
338
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700339TEST_F(FrameTimelineTest, surfaceFrameEndTimeAcquireFenceAfterQueue) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800340 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, 0,
341 "acquireFenceAfterQueue",
342 "acquireFenceAfterQueue");
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700343 surfaceFrame->setActualQueueTime(123);
344 surfaceFrame->setAcquireFenceTime(456);
345 EXPECT_EQ(surfaceFrame->getActuals().endTime, 456);
346}
347
348TEST_F(FrameTimelineTest, surfaceFrameEndTimeAcquireFenceBeforeQueue) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800349 auto surfaceFrame = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, 0,
350 "acquireFenceAfterQueue",
351 "acquireFenceAfterQueue");
Ady Abraham7f8a1e62020-09-28 16:09:35 -0700352 surfaceFrame->setActualQueueTime(456);
353 surfaceFrame->setAcquireFenceTime(123);
354 EXPECT_EQ(surfaceFrame->getActuals().endTime, 456);
355}
356
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700357TEST_F(FrameTimelineTest, setMaxDisplayFramesSetsSizeProperly) {
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800358 // Global increment
359 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_))
360 .Times(static_cast<int32_t>(*maxDisplayFrames + 10));
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700361 auto presentFence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
362 presentFence->signalForTest(2);
363
364 // Size shouldn't exceed maxDisplayFrames - 64
365 for (size_t i = 0; i < *maxDisplayFrames + 10; i++) {
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700366 auto surfaceFrame =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800367 mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
368 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700369 int64_t sfToken = mTokenManager->generateTokenForPredictions({22, 26, 30});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800370 mFrameTimeline->setSfWakeUp(sfToken, 22, 11);
371 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
372 mFrameTimeline->addSurfaceFrame(surfaceFrame);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700373 mFrameTimeline->setSfPresent(27, presentFence);
374 }
375 EXPECT_EQ(getNumberOfDisplayFrames(), *maxDisplayFrames);
376
377 // Increase the size to 256
378 mFrameTimeline->setMaxDisplayFrames(256);
379 EXPECT_EQ(*maxDisplayFrames, 256);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800380 // Global increment
381 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_))
382 .Times(static_cast<int32_t>(*maxDisplayFrames + 10));
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700383
384 for (size_t i = 0; i < *maxDisplayFrames + 10; i++) {
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700385 auto surfaceFrame =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800386 mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
387 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700388 int64_t sfToken = mTokenManager->generateTokenForPredictions({22, 26, 30});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800389 mFrameTimeline->setSfWakeUp(sfToken, 22, 11);
390 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
391 mFrameTimeline->addSurfaceFrame(surfaceFrame);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700392 mFrameTimeline->setSfPresent(27, presentFence);
393 }
394 EXPECT_EQ(getNumberOfDisplayFrames(), *maxDisplayFrames);
395
396 // Shrink the size to 128
397 mFrameTimeline->setMaxDisplayFrames(128);
398 EXPECT_EQ(*maxDisplayFrames, 128);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800399 // Global increment
400 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_))
401 .Times(static_cast<int32_t>(*maxDisplayFrames + 10));
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700402
403 for (size_t i = 0; i < *maxDisplayFrames + 10; i++) {
Adithya Srinivasan9febda82020-10-19 10:49:41 -0700404 auto surfaceFrame =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800405 mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
406 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700407 int64_t sfToken = mTokenManager->generateTokenForPredictions({22, 26, 30});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800408 mFrameTimeline->setSfWakeUp(sfToken, 22, 11);
409 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
410 mFrameTimeline->addSurfaceFrame(surfaceFrame);
Adithya Srinivasan2d736322020-10-01 16:53:48 -0700411 mFrameTimeline->setSfPresent(27, presentFence);
412 }
413 EXPECT_EQ(getNumberOfDisplayFrames(), *maxDisplayFrames);
414}
Alec Mouri9a29e672020-09-14 12:39:14 -0700415
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800416// Tests related to TimeStats
Alec Mouri9a29e672020-09-14 12:39:14 -0700417TEST_F(FrameTimelineTest, presentFenceSignaled_reportsLongSfCpu) {
418 EXPECT_CALL(*mTimeStats,
419 incrementJankyFrames(sUidOne, sLayerNameOne,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800420 HasBit(JankType::SurfaceFlingerCpuDeadlineMissed)));
Alec Mouri9a29e672020-09-14 12:39:14 -0700421 EXPECT_CALL(*mTimeStats,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800422 incrementJankyFrames(HasBit(JankType::SurfaceFlingerCpuDeadlineMissed)));
Alec Mouri9a29e672020-09-14 12:39:14 -0700423 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
424 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions(
425 {std::chrono::duration_cast<std::chrono::nanoseconds>(10ms).count(),
426 std::chrono::duration_cast<std::chrono::nanoseconds>(20ms).count(),
427 std::chrono::duration_cast<std::chrono::nanoseconds>(60ms).count()});
428 int64_t sfToken1 = mTokenManager->generateTokenForPredictions(
429 {std::chrono::duration_cast<std::chrono::nanoseconds>(52ms).count(),
430 std::chrono::duration_cast<std::chrono::nanoseconds>(56ms).count(),
431 std::chrono::duration_cast<std::chrono::nanoseconds>(60ms).count()});
432 auto surfaceFrame1 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800433 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
434 sLayerNameOne, sLayerNameOne);
Alec Mouri9a29e672020-09-14 12:39:14 -0700435 mFrameTimeline->setSfWakeUp(sfToken1,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800436 std::chrono::duration_cast<std::chrono::nanoseconds>(52ms).count(),
437 11);
438 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
439 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Alec Mouri9a29e672020-09-14 12:39:14 -0700440 presentFence1->signalForTest(
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100441 std::chrono::duration_cast<std::chrono::nanoseconds>(70ms).count());
Alec Mouri9a29e672020-09-14 12:39:14 -0700442
443 mFrameTimeline->setSfPresent(std::chrono::duration_cast<std::chrono::nanoseconds>(59ms).count(),
444 presentFence1);
445}
446
447TEST_F(FrameTimelineTest, presentFenceSignaled_reportsDisplayMiss) {
448 EXPECT_CALL(*mTimeStats,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800449 incrementJankyFrames(sUidOne, sLayerNameOne, HasBit(JankType::DisplayHAL)));
450 EXPECT_CALL(*mTimeStats, incrementJankyFrames(HasBit(JankType::DisplayHAL)));
451
Alec Mouri9a29e672020-09-14 12:39:14 -0700452 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
453 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions(
454 {std::chrono::duration_cast<std::chrono::nanoseconds>(10ms).count(),
455 std::chrono::duration_cast<std::chrono::nanoseconds>(20ms).count(),
456 std::chrono::duration_cast<std::chrono::nanoseconds>(60ms).count()});
457 int64_t sfToken1 = mTokenManager->generateTokenForPredictions(
458 {std::chrono::duration_cast<std::chrono::nanoseconds>(52ms).count(),
459 std::chrono::duration_cast<std::chrono::nanoseconds>(56ms).count(),
460 std::chrono::duration_cast<std::chrono::nanoseconds>(60ms).count()});
461 auto surfaceFrame1 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800462 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
463 sLayerNameOne, sLayerNameOne);
Alec Mouri9a29e672020-09-14 12:39:14 -0700464 mFrameTimeline->setSfWakeUp(sfToken1,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800465 std::chrono::duration_cast<std::chrono::nanoseconds>(52ms).count(),
466 30);
467 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
468 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Alec Mouri9a29e672020-09-14 12:39:14 -0700469 presentFence1->signalForTest(
470 std::chrono::duration_cast<std::chrono::nanoseconds>(90ms).count());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800471 mFrameTimeline->setSfPresent(std::chrono::duration_cast<std::chrono::nanoseconds>(56ms).count(),
Alec Mouri9a29e672020-09-14 12:39:14 -0700472 presentFence1);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800473 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::DisplayHAL);
Alec Mouri9a29e672020-09-14 12:39:14 -0700474}
475
476TEST_F(FrameTimelineTest, presentFenceSignaled_reportsAppMiss) {
477 EXPECT_CALL(*mTimeStats,
478 incrementJankyFrames(sUidOne, sLayerNameOne,
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100479 HasBit(JankType::AppDeadlineMissed)));
480 EXPECT_CALL(*mTimeStats, incrementJankyFrames(HasBit(JankType::AppDeadlineMissed)));
Alec Mouri9a29e672020-09-14 12:39:14 -0700481 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
482 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions(
483 {std::chrono::duration_cast<std::chrono::nanoseconds>(10ms).count(),
484 std::chrono::duration_cast<std::chrono::nanoseconds>(20ms).count(),
485 std::chrono::duration_cast<std::chrono::nanoseconds>(60ms).count()});
486 int64_t sfToken1 = mTokenManager->generateTokenForPredictions(
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800487 {std::chrono::duration_cast<std::chrono::nanoseconds>(82ms).count(),
488 std::chrono::duration_cast<std::chrono::nanoseconds>(86ms).count(),
489 std::chrono::duration_cast<std::chrono::nanoseconds>(90ms).count()});
Alec Mouri9a29e672020-09-14 12:39:14 -0700490 auto surfaceFrame1 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800491 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
492 sLayerNameOne, sLayerNameOne);
Alec Mouri9a29e672020-09-14 12:39:14 -0700493 surfaceFrame1->setAcquireFenceTime(
494 std::chrono::duration_cast<std::chrono::nanoseconds>(45ms).count());
495 mFrameTimeline->setSfWakeUp(sfToken1,
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800496 std::chrono::duration_cast<std::chrono::nanoseconds>(52ms).count(),
497 11);
Alec Mouri9a29e672020-09-14 12:39:14 -0700498
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800499 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
500 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Alec Mouri9a29e672020-09-14 12:39:14 -0700501 presentFence1->signalForTest(
502 std::chrono::duration_cast<std::chrono::nanoseconds>(90ms).count());
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800503 mFrameTimeline->setSfPresent(std::chrono::duration_cast<std::chrono::nanoseconds>(86ms).count(),
Alec Mouri9a29e672020-09-14 12:39:14 -0700504 presentFence1);
Jorim Jaggi9c03b502020-11-24 23:51:31 +0100505
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800506 EXPECT_EQ(surfaceFrame1->getJankType(), JankType::AppDeadlineMissed);
Alec Mouri9a29e672020-09-14 12:39:14 -0700507}
508
Adithya Srinivasan01189672020-10-20 14:23:05 -0700509/*
510 * Tracing Tests
511 *
512 * Trace packets are flushed all the way only when the next packet is traced.
513 * For example: trace<Display/Surface>Frame() will create a TracePacket but not flush it. Only when
514 * another TracePacket is created, the previous one is guaranteed to be flushed. The following tests
515 * will have additional empty frames created for this reason.
516 */
517TEST_F(FrameTimelineTest, tracing_noPacketsSentWithoutTraceStart) {
518 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800519 // Global increment
520 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700521 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
522 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
523
524 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
525 int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800526 auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(token1, sPidOne, sUidOne,
527 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700528
529 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800530 mFrameTimeline->setSfWakeUp(token1, 20, 11);
531 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Dropped);
532 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700533 mFrameTimeline->setSfPresent(25, presentFence1);
534 presentFence1->signalForTest(30);
535
536 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
537 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800538 mFrameTimeline->setSfWakeUp(token2, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700539 mFrameTimeline->setSfPresent(55, presentFence2);
540
541 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
542 EXPECT_EQ(packets.size(), 0);
543}
544
545TEST_F(FrameTimelineTest, tracing_sanityTest) {
546 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800547 // Global increment
548 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
549 // Layer specific increment
550 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700551 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
552 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
553
554 tracingSession->StartBlocking();
555 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
556 int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800557 auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(token1, sPidOne, sUidOne,
558 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700559
560 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800561 mFrameTimeline->setSfWakeUp(token2, 20, 11);
562 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
563 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700564 mFrameTimeline->setSfPresent(25, presentFence1);
565 presentFence1->signalForTest(30);
566
567 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
568 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800569 mFrameTimeline->setSfWakeUp(token2, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700570 mFrameTimeline->setSfPresent(55, presentFence2);
571 presentFence2->signalForTest(55);
572
573 // The SurfaceFrame packet from the first frame is emitted, but not flushed yet. Emitting a new
574 // packet will flush it. To emit a new packet, we'll need to call flushPendingPresentFences()
575 // again, which is done by setSfPresent().
576 addEmptyDisplayFrame();
577 tracingSession->StopBlocking();
578
579 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
580 // Display Frame 1 has two packets - DisplayFrame and a SurfaceFrame.
581 // Display Frame 2 has one packet - DisplayFrame. However, this packet has been emitted but not
582 // flushed through traced, so this is not counted.
583 EXPECT_EQ(packets.size(), 2);
584}
585
586TEST_F(FrameTimelineTest, traceDisplayFrame_invalidTokenDoesNotEmitTracePacket) {
587 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800588 // Global increment
589 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700590 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
591 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
592
593 tracingSession->StartBlocking();
594 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
595
596 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800597 mFrameTimeline->setSfWakeUp(-1, 20, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700598 mFrameTimeline->setSfPresent(25, presentFence1);
599 presentFence1->signalForTest(30);
600
601 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
602 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800603 mFrameTimeline->setSfWakeUp(token1, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700604 mFrameTimeline->setSfPresent(55, presentFence2);
605 presentFence2->signalForTest(60);
606
607 addEmptyDisplayFrame();
608 tracingSession->StopBlocking();
609
610 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
611 // Display Frame 1 has no packets.
612 // Display Frame 2 has one packet - DisplayFrame. However, this packet has
613 // been emitted but not flushed through traced, so this is not counted.
614 EXPECT_EQ(packets.size(), 0);
615}
616
617TEST_F(FrameTimelineTest, traceSurfaceFrame_invalidTokenDoesNotEmitTracePacket) {
618 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800619 // Global increment
620 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700621 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
622 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
623
624 tracingSession->StartBlocking();
625 int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
626 int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800627 auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(std::nullopt, sPidOne, sUidOne,
628 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700629
630 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800631 mFrameTimeline->setSfWakeUp(token1, 20, 11);
632 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Dropped);
633 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700634 mFrameTimeline->setSfPresent(25, presentFence1);
635 presentFence1->signalForTest(30);
636
637 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
638 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800639 mFrameTimeline->setSfWakeUp(token2, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700640 mFrameTimeline->setSfPresent(55, presentFence2);
641 presentFence2->signalForTest(60);
642
643 addEmptyDisplayFrame();
644 tracingSession->StopBlocking();
645
646 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
647 // Display Frame 1 has one packet - DisplayFrame (SurfaceFrame shouldn't be traced since it has
648 // an invalid token).
649 // Display Frame 2 has one packet - DisplayFrame. However, this packet has
650 // been emitted but not flushed through traced, so this is not counted.
651 EXPECT_EQ(packets.size(), 1);
652}
653
654void validateDisplayFrameEvent(const ProtoDisplayFrame& received, const ProtoDisplayFrame& source) {
655 ASSERT_TRUE(received.has_token());
656 EXPECT_EQ(received.token(), source.token());
657
658 ASSERT_TRUE(received.has_present_type());
659 EXPECT_EQ(received.present_type(), source.present_type());
660 ASSERT_TRUE(received.has_on_time_finish());
661 EXPECT_EQ(received.on_time_finish(), source.on_time_finish());
662 ASSERT_TRUE(received.has_gpu_composition());
663 EXPECT_EQ(received.gpu_composition(), source.gpu_composition());
664 ASSERT_TRUE(received.has_jank_type());
665 EXPECT_EQ(received.jank_type(), source.jank_type());
666
667 ASSERT_TRUE(received.has_expected_start_ns());
668 EXPECT_EQ(received.expected_start_ns(), source.expected_start_ns());
669 ASSERT_TRUE(received.has_expected_end_ns());
670 EXPECT_EQ(received.expected_end_ns(), source.expected_end_ns());
671
672 ASSERT_TRUE(received.has_actual_start_ns());
673 EXPECT_EQ(received.actual_start_ns(), source.actual_start_ns());
674 ASSERT_TRUE(received.has_actual_end_ns());
675 EXPECT_EQ(received.actual_end_ns(), source.actual_end_ns());
676}
677
678void validateSurfaceFrameEvent(const ProtoSurfaceFrame& received, const ProtoSurfaceFrame& source) {
679 ASSERT_TRUE(received.has_token());
680 EXPECT_EQ(received.token(), source.token());
681
682 ASSERT_TRUE(received.has_display_frame_token());
683 EXPECT_EQ(received.display_frame_token(), source.display_frame_token());
684
685 ASSERT_TRUE(received.has_present_type());
686 EXPECT_EQ(received.present_type(), source.present_type());
687 ASSERT_TRUE(received.has_on_time_finish());
688 EXPECT_EQ(received.on_time_finish(), source.on_time_finish());
689 ASSERT_TRUE(received.has_gpu_composition());
690 EXPECT_EQ(received.gpu_composition(), source.gpu_composition());
691 ASSERT_TRUE(received.has_jank_type());
692 EXPECT_EQ(received.jank_type(), source.jank_type());
693
694 ASSERT_TRUE(received.has_expected_start_ns());
695 EXPECT_EQ(received.expected_start_ns(), source.expected_start_ns());
696 ASSERT_TRUE(received.has_expected_end_ns());
697 EXPECT_EQ(received.expected_end_ns(), source.expected_end_ns());
698
699 ASSERT_TRUE(received.has_actual_start_ns());
700 EXPECT_EQ(received.actual_start_ns(), source.actual_start_ns());
701 ASSERT_TRUE(received.has_actual_end_ns());
702 EXPECT_EQ(received.actual_end_ns(), source.actual_end_ns());
703
704 ASSERT_TRUE(received.has_layer_name());
705 EXPECT_EQ(received.layer_name(), source.layer_name());
706 ASSERT_TRUE(received.has_pid());
707 EXPECT_EQ(received.pid(), source.pid());
708}
709
710TEST_F(FrameTimelineTest, traceDisplayFrame_emitsValidTracePacket) {
711 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800712 // Global increment
713 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700714 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
715 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
716
717 tracingSession->StartBlocking();
718 int64_t displayFrameToken1 = mTokenManager->generateTokenForPredictions({10, 25, 30});
719 int64_t displayFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
720
721 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800722 mFrameTimeline->setSfWakeUp(displayFrameToken1, 20, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700723 mFrameTimeline->setSfPresent(26, presentFence1);
724 presentFence1->signalForTest(31);
725
726 ProtoDisplayFrame protoDisplayFrame;
727 protoDisplayFrame.set_token(displayFrameToken1);
728 protoDisplayFrame.set_present_type(ProtoPresentType(FrameTimelineEvent::PRESENT_ON_TIME));
729 protoDisplayFrame.set_on_time_finish(true);
730 protoDisplayFrame.set_gpu_composition(false);
731 protoDisplayFrame.set_jank_type(ProtoJankType(FrameTimelineEvent::JANK_NONE));
732 protoDisplayFrame.set_expected_start_ns(10);
733 protoDisplayFrame.set_expected_end_ns(25);
734 protoDisplayFrame.set_actual_start_ns(20);
735 protoDisplayFrame.set_actual_end_ns(26);
736
737 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
738 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800739 mFrameTimeline->setSfWakeUp(displayFrameToken2, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700740 mFrameTimeline->setSfPresent(55, presentFence2);
741 presentFence2->signalForTest(55);
742
743 addEmptyDisplayFrame();
744 tracingSession->StopBlocking();
745
746 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
747 // Display Frame 1 has one packet - DisplayFrame.
748 // Display Frame 2 has one packet - DisplayFrame. However, this packet has been emitted but not
749 // flushed through traced, so this is not counted.
750 EXPECT_EQ(packets.size(), 1);
751
752 const auto& packet = packets[0];
753 ASSERT_TRUE(packet.has_timestamp());
754 ASSERT_TRUE(packet.has_frame_timeline_event());
755
756 const auto& event = packet.frame_timeline_event();
757 ASSERT_TRUE(event.has_display_frame());
758 ASSERT_FALSE(event.has_surface_frame());
759 const auto& displayFrameEvent = event.display_frame();
760 validateDisplayFrameEvent(displayFrameEvent, protoDisplayFrame);
761}
762
763TEST_F(FrameTimelineTest, traceSurfaceFrame_emitsValidTracePacket) {
764 auto tracingSession = getTracingSessionForTest();
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800765 // Global increment
766 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
767 // Layer specific increment
768 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_));
Adithya Srinivasan01189672020-10-20 14:23:05 -0700769 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
770 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
771
772 tracingSession->StartBlocking();
773 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions({10, 25, 40});
774 int64_t displayFrameToken1 = mTokenManager->generateTokenForPredictions({30, 35, 40});
775 int64_t displayFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
776
777 auto surfaceFrame1 =
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800778 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken, sPidOne, sUidOne,
779 sLayerNameOne, sLayerNameOne);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700780 surfaceFrame1->setActualStartTime(0);
781 surfaceFrame1->setActualQueueTime(15);
782 surfaceFrame1->setAcquireFenceTime(20);
783
784 ProtoSurfaceFrame protoSurfaceFrame;
785 protoSurfaceFrame.set_token(surfaceFrameToken);
786 protoSurfaceFrame.set_display_frame_token(displayFrameToken1);
787 protoSurfaceFrame.set_present_type(ProtoPresentType(FrameTimelineEvent::PRESENT_ON_TIME));
788 protoSurfaceFrame.set_on_time_finish(true);
789 protoSurfaceFrame.set_gpu_composition(false);
790 protoSurfaceFrame.set_jank_type(ProtoJankType(FrameTimelineEvent::JANK_NONE));
791 protoSurfaceFrame.set_expected_start_ns(10);
792 protoSurfaceFrame.set_expected_end_ns(25);
793 protoSurfaceFrame.set_actual_start_ns(0);
794 protoSurfaceFrame.set_actual_end_ns(20);
795 protoSurfaceFrame.set_layer_name(sLayerNameOne);
796 protoSurfaceFrame.set_pid(sPidOne);
797
798 // Set up the display frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800799 mFrameTimeline->setSfWakeUp(displayFrameToken1, 20, 11);
800 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
801 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700802 mFrameTimeline->setSfPresent(26, presentFence1);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800803 presentFence1->signalForTest(40);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700804
805 // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the
806 // next frame
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800807 mFrameTimeline->setSfWakeUp(displayFrameToken2, 50, 11);
Adithya Srinivasan01189672020-10-20 14:23:05 -0700808 mFrameTimeline->setSfPresent(55, presentFence2);
809 presentFence2->signalForTest(55);
810
811 addEmptyDisplayFrame();
812 tracingSession->StopBlocking();
813
814 auto packets = readFrameTimelinePacketsBlocking(tracingSession.get());
815 // Display Frame 1 has one packet - DisplayFrame and a SurfaceFrame.
816 // Display Frame 2 has one packet - DisplayFrame. However, this packet has been emitted but not
817 // flushed through traced, so this is not counted.
818 EXPECT_EQ(packets.size(), 2);
819
820 const auto& packet = packets[1];
821 ASSERT_TRUE(packet.has_timestamp());
822 ASSERT_TRUE(packet.has_frame_timeline_event());
823
824 const auto& event = packet.frame_timeline_event();
825 ASSERT_TRUE(!event.has_display_frame());
826 ASSERT_TRUE(event.has_surface_frame());
827 const auto& surfaceFrameEvent = event.surface_frame();
828 validateSurfaceFrameEvent(surfaceFrameEvent, protoSurfaceFrame);
829}
830
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800831// Tests for Jank classification
832TEST_F(FrameTimelineTest, jankClassification_presentOnTimeDoesNotClassify) {
833 // Global increment
834 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
835 // Layer specific increment
836 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_));
837 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
838 int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions({10, 20, 30});
839 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 30});
840 auto surfaceFrame =
841 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken, sPidOne, sUidOne,
842 sLayerNameOne, sLayerNameOne);
843 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
844 surfaceFrame->setPresentState(SurfaceFrame::PresentState::Presented);
845 mFrameTimeline->addSurfaceFrame(surfaceFrame);
846 mFrameTimeline->setSfPresent(26, presentFence1);
847 auto displayFrame = getDisplayFrame(0);
848 auto& presentedSurfaceFrame = getSurfaceFrame(0, 0);
849 presentFence1->signalForTest(29);
850
851 // Fences haven't been flushed yet, so it should be 0
852 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
853 EXPECT_EQ(presentedSurfaceFrame.getActuals().presentTime, 0);
854
855 addEmptyDisplayFrame();
856 displayFrame = getDisplayFrame(0);
857
858 // Fences have flushed, so the present timestamps should be updated
859 EXPECT_EQ(displayFrame->getActuals().presentTime, 29);
860 EXPECT_EQ(presentedSurfaceFrame.getActuals().presentTime, 29);
861 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
862 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
863 EXPECT_EQ(displayFrame->getJankType(), JankType::None);
864}
865
866TEST_F(FrameTimelineTest, jankClassification_displayFrameOnTimeFinishEarlyPresent) {
867 // Global increment
868 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
869 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
870 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
871 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 56, 70});
872 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
873 mFrameTimeline->setSfPresent(26, presentFence1);
874 auto displayFrame = getDisplayFrame(0);
875 presentFence1->signalForTest(30);
876
877 // Fences for the first frame haven't been flushed yet, so it should be 0
878 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
879
880 // Trigger a flush by finalizing the next DisplayFrame
881 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
882 mFrameTimeline->setSfWakeUp(sfToken2, 52, 11);
883 mFrameTimeline->setSfPresent(56, presentFence2);
884 displayFrame = getDisplayFrame(0);
885
886 // Fences for the first frame have flushed, so the present timestamps should be updated
887 EXPECT_EQ(displayFrame->getActuals().presentTime, 30);
888 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
889 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
890 EXPECT_EQ(displayFrame->getJankType(), JankType::SurfaceFlingerScheduling);
891
892 // Fences for the second frame haven't been flushed yet, so it should be 0
893 auto displayFrame2 = getDisplayFrame(1);
894 presentFence2->signalForTest(65);
895 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
896
897 addEmptyDisplayFrame();
898 displayFrame2 = getDisplayFrame(1);
899
900 // Fences for the second frame have flushed, so the present timestamps should be updated
901 EXPECT_EQ(displayFrame2->getActuals().presentTime, 65);
902 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
903 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
904 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
905}
906
907TEST_F(FrameTimelineTest, jankClassification_displayFrameOnTimeFinishLatePresent) {
908 // Global increment
909 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
910 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
911 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
912 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 56, 70});
913 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
914 mFrameTimeline->setSfPresent(26, presentFence1);
915 auto displayFrame = getDisplayFrame(0);
916 presentFence1->signalForTest(50);
917
918 // Fences for the first frame haven't been flushed yet, so it should be 0
919 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
920
921 // Trigger a flush by finalizing the next DisplayFrame
922 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
923 mFrameTimeline->setSfWakeUp(sfToken2, 52, 11);
924 mFrameTimeline->setSfPresent(56, presentFence2);
925 displayFrame = getDisplayFrame(0);
926
927 // Fences for the first frame have flushed, so the present timestamps should be updated
928 EXPECT_EQ(displayFrame->getActuals().presentTime, 50);
929 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
930 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
931 EXPECT_EQ(displayFrame->getJankType(), JankType::DisplayHAL);
932
933 // Fences for the second frame haven't been flushed yet, so it should be 0
934 auto displayFrame2 = getDisplayFrame(1);
935 presentFence2->signalForTest(75);
936 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
937
938 addEmptyDisplayFrame();
939 displayFrame2 = getDisplayFrame(1);
940
941 // Fences for the second frame have flushed, so the present timestamps should be updated
942 EXPECT_EQ(displayFrame2->getActuals().presentTime, 75);
943 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
944 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
945 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
946}
947
948TEST_F(FrameTimelineTest, jankClassification_displayFrameLateFinishEarlyPresent) {
949 // Global increment
950 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
951 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
952 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({12, 18, 40});
953 mFrameTimeline->setSfWakeUp(sfToken1, 12, 11);
954
955 mFrameTimeline->setSfPresent(22, presentFence1);
956 auto displayFrame = getDisplayFrame(0);
957 presentFence1->signalForTest(28);
958
959 // Fences haven't been flushed yet, so it should be 0
960 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
961
962 addEmptyDisplayFrame();
963 displayFrame = getDisplayFrame(0);
964
965 // Fences have flushed, so the present timestamps should be updated
966 EXPECT_EQ(displayFrame->getActuals().presentTime, 28);
967 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
968 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
969 EXPECT_EQ(displayFrame->getJankType(), JankType::SurfaceFlingerScheduling);
970}
971
972TEST_F(FrameTimelineTest, jankClassification_displayFrameLateFinishLatePresent) {
973 // Global increment
974 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
975 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
976 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
977 mFrameTimeline->setSfWakeUp(sfToken1, 12, 11);
978 mFrameTimeline->setSfPresent(36, presentFence1);
979 auto displayFrame = getDisplayFrame(0);
980 presentFence1->signalForTest(52);
981
982 // Fences haven't been flushed yet, so it should be 0
983 EXPECT_EQ(displayFrame->getActuals().presentTime, 0);
984
985 addEmptyDisplayFrame();
986 displayFrame = getDisplayFrame(0);
987
988 // Fences have flushed, so the present timestamps should be updated
989 EXPECT_EQ(displayFrame->getActuals().presentTime, 52);
990 EXPECT_EQ(displayFrame->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
991 EXPECT_EQ(displayFrame->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
992 EXPECT_EQ(displayFrame->getJankType(), JankType::SurfaceFlingerCpuDeadlineMissed);
993}
994
995TEST_F(FrameTimelineTest, jankClassification_surfaceFrameOnTimeFinishEarlyPresent) {
996 // Global increment
997 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
998 // Layer specific increment
999 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_)).Times(2);
1000 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1001 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
1002 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 56, 70});
1003 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 16, 40});
1004 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({25, 36, 70});
1005 auto surfaceFrame1 =
1006 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
1007 sLayerNameOne, sLayerNameOne);
1008 surfaceFrame1->setAcquireFenceTime(16);
1009 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
1010 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1011 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1012 mFrameTimeline->setSfPresent(26, presentFence1);
1013 auto displayFrame1 = getDisplayFrame(0);
1014 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1015 presentFence1->signalForTest(30);
1016
1017 // Fences for the first frame haven't been flushed yet, so it should be 0
1018 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1019 auto actuals1 = presentedSurfaceFrame1.getActuals();
1020 EXPECT_EQ(actuals1.presentTime, 0);
1021
1022 // Trigger a flush by finalizing the next DisplayFrame
1023 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1024 auto surfaceFrame2 =
1025 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken2, sPidOne, sUidOne,
1026 sLayerNameOne, sLayerNameOne);
1027 surfaceFrame2->setAcquireFenceTime(36);
1028 mFrameTimeline->setSfWakeUp(sfToken2, 52, 11);
1029 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
1030 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1031 mFrameTimeline->setSfPresent(56, presentFence2);
1032 auto displayFrame2 = getDisplayFrame(1);
1033 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1034
1035 // Fences for the first frame have flushed, so the present timestamps should be updated
1036 EXPECT_EQ(displayFrame1->getActuals().presentTime, 30);
1037 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1038 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1039 EXPECT_EQ(displayFrame1->getJankType(), JankType::SurfaceFlingerScheduling);
1040
1041 actuals1 = presentedSurfaceFrame1.getActuals();
1042 EXPECT_EQ(actuals1.presentTime, 30);
1043 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1044 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1045 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::SurfaceFlingerScheduling);
1046
1047 // Fences for the second frame haven't been flushed yet, so it should be 0
1048 presentFence2->signalForTest(65);
1049 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1050 auto actuals2 = presentedSurfaceFrame2.getActuals();
1051 EXPECT_EQ(actuals2.presentTime, 0);
1052
1053 addEmptyDisplayFrame();
1054
1055 // Fences for the second frame have flushed, so the present timestamps should be updated
1056 EXPECT_EQ(displayFrame2->getActuals().presentTime, 65);
1057 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1058 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1059 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
1060
1061 actuals2 = presentedSurfaceFrame2.getActuals();
1062 EXPECT_EQ(actuals2.presentTime, 65);
1063 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1064 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1065 EXPECT_EQ(presentedSurfaceFrame2.getJankType(), JankType::PredictionError);
1066}
1067
1068TEST_F(FrameTimelineTest, jankClassification_surfaceFrameOnTimeFinishLatePresent) {
1069 // Global increment
1070 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
1071 // Layer specific increment
1072 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_)).Times(2);
1073 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1074 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({22, 26, 40});
1075 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({52, 56, 70});
1076 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 16, 40});
1077 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({25, 36, 70});
1078 auto surfaceFrame1 =
1079 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
1080 sLayerNameOne, sLayerNameOne);
1081 surfaceFrame1->setAcquireFenceTime(16);
1082 mFrameTimeline->setSfWakeUp(sfToken1, 22, 11);
1083 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1084 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1085 mFrameTimeline->setSfPresent(26, presentFence1);
1086 auto displayFrame1 = getDisplayFrame(0);
1087 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1088 presentFence1->signalForTest(50);
1089
1090 // Fences for the first frame haven't been flushed yet, so it should be 0
1091 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1092 auto actuals1 = presentedSurfaceFrame1.getActuals();
1093 EXPECT_EQ(actuals1.presentTime, 0);
1094
1095 // Trigger a flush by finalizing the next DisplayFrame
1096 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1097 auto surfaceFrame2 =
1098 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken2, sPidOne, sUidOne,
1099 sLayerNameOne, sLayerNameOne);
1100 surfaceFrame2->setAcquireFenceTime(36);
1101 mFrameTimeline->setSfWakeUp(sfToken2, 52, 11);
1102 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
1103 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1104 mFrameTimeline->setSfPresent(56, presentFence2);
1105 auto displayFrame2 = getDisplayFrame(1);
1106 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1107
1108 // Fences for the first frame have flushed, so the present timestamps should be updated
1109 EXPECT_EQ(displayFrame1->getActuals().presentTime, 50);
1110 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1111 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1112 EXPECT_EQ(displayFrame1->getJankType(), JankType::DisplayHAL);
1113
1114 actuals1 = presentedSurfaceFrame1.getActuals();
1115 EXPECT_EQ(actuals1.presentTime, 50);
1116 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1117 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1118 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::DisplayHAL);
1119
1120 // Fences for the second frame haven't been flushed yet, so it should be 0
1121 presentFence2->signalForTest(86);
1122 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1123 auto actuals2 = presentedSurfaceFrame2.getActuals();
1124 EXPECT_EQ(actuals2.presentTime, 0);
1125
1126 addEmptyDisplayFrame();
1127
1128 // Fences for the second frame have flushed, so the present timestamps should be updated
1129 EXPECT_EQ(displayFrame2->getActuals().presentTime, 86);
1130 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1131 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1132 EXPECT_EQ(displayFrame2->getJankType(), JankType::PredictionError);
1133
1134 actuals2 = presentedSurfaceFrame2.getActuals();
1135 EXPECT_EQ(actuals2.presentTime, 86);
1136 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1137 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1138 EXPECT_EQ(presentedSurfaceFrame2.getJankType(), JankType::PredictionError);
1139}
1140
1141TEST_F(FrameTimelineTest, jankClassification_surfaceFrameLateFinishEarlyPresent) {
1142 // Global increment
1143 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_));
1144 // Layer specific increment
1145 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_));
1146 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1147 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({42, 46, 50});
1148 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 26, 60});
1149 auto surfaceFrame1 =
1150 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
1151 sLayerNameOne, sLayerNameOne);
1152 surfaceFrame1->setAcquireFenceTime(40);
1153 mFrameTimeline->setSfWakeUp(sfToken1, 42, 11);
1154 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1155 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1156 mFrameTimeline->setSfPresent(46, presentFence1);
1157 auto displayFrame1 = getDisplayFrame(0);
1158 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1159 presentFence1->signalForTest(50);
1160
1161 // Fences for the first frame haven't been flushed yet, so it should be 0
1162 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1163 auto actuals1 = presentedSurfaceFrame1.getActuals();
1164 EXPECT_EQ(actuals1.presentTime, 0);
1165
1166 addEmptyDisplayFrame();
1167
1168 // Fences for the first frame have flushed, so the present timestamps should be updated
1169 EXPECT_EQ(displayFrame1->getActuals().presentTime, 50);
1170 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1171 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1172 EXPECT_EQ(displayFrame1->getJankType(), JankType::None);
1173
1174 actuals1 = presentedSurfaceFrame1.getActuals();
1175 EXPECT_EQ(actuals1.presentTime, 50);
1176 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::EarlyPresent);
1177 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1178 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::Unknown);
1179}
1180
1181TEST_F(FrameTimelineTest, jankClassification_surfaceFrameLateFinishLatePresent) {
1182 // First frame - DisplayFrame is not janky. This should classify the SurfaceFrame as
1183 // AppDeadlineMissed. Second frame - DisplayFrame is janky. This should propagate DisplayFrame's
1184 // jank to the SurfaceFrame.
1185
1186 // Global increment
1187 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
1188 // Layer specific increment
1189 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_)).Times(2);
1190 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1191 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({32, 36, 40});
1192 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({42, 46, 50});
1193 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({5, 16, 30});
1194 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({25, 36, 50});
1195 auto surfaceFrame1 =
1196 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
1197 sLayerNameOne, sLayerNameOne);
1198 surfaceFrame1->setAcquireFenceTime(26);
1199 mFrameTimeline->setSfWakeUp(sfToken1, 32, 11);
1200 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1201 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1202 mFrameTimeline->setSfPresent(36, presentFence1);
1203 auto displayFrame1 = getDisplayFrame(0);
1204 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1205 presentFence1->signalForTest(40);
1206
1207 // Fences for the first frame haven't been flushed yet, so it should be 0
1208 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1209 auto actuals1 = presentedSurfaceFrame1.getActuals();
1210 EXPECT_EQ(actuals1.presentTime, 0);
1211
1212 // Trigger a flush by finalizing the next DisplayFrame
1213 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1214 auto surfaceFrame2 =
1215 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken2, sPidOne, sUidOne,
1216 sLayerNameOne, sLayerNameOne);
1217 surfaceFrame2->setAcquireFenceTime(40);
1218 mFrameTimeline->setSfWakeUp(sfToken2, 43, 11);
1219 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented);
1220 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1221 mFrameTimeline->setSfPresent(56, presentFence2);
1222 auto displayFrame2 = getDisplayFrame(1);
1223 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1224
1225 // Fences for the first frame have flushed, so the present timestamps should be updated
1226 EXPECT_EQ(displayFrame1->getActuals().presentTime, 40);
1227 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1228 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1229 EXPECT_EQ(displayFrame1->getJankType(), JankType::None);
1230
1231 actuals1 = presentedSurfaceFrame1.getActuals();
1232 EXPECT_EQ(actuals1.presentTime, 40);
1233 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1234 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1235 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::AppDeadlineMissed);
1236
1237 // Fences for the second frame haven't been flushed yet, so it should be 0
1238 presentFence2->signalForTest(60);
1239 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1240 auto actuals2 = presentedSurfaceFrame2.getActuals();
1241 EXPECT_EQ(actuals2.presentTime, 0);
1242
1243 addEmptyDisplayFrame();
1244
1245 // Fences for the second frame have flushed, so the present timestamps should be updated
1246 EXPECT_EQ(displayFrame2->getActuals().presentTime, 60);
1247 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1248 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1249 EXPECT_EQ(displayFrame2->getJankType(), JankType::SurfaceFlingerCpuDeadlineMissed);
1250
1251 actuals2 = presentedSurfaceFrame2.getActuals();
1252 EXPECT_EQ(actuals2.presentTime, 60);
1253 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1254 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1255 EXPECT_EQ(presentedSurfaceFrame2.getJankType(), JankType::SurfaceFlingerCpuDeadlineMissed);
1256}
1257
1258TEST_F(FrameTimelineTest, jankClassification_multiJankBufferStuffingAndAppDeadlineMissed) {
1259 // Global increment
1260 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_)).Times(2);
1261 // Layer specific increment
1262 EXPECT_CALL(*mTimeStats, incrementJankyFrames(testing::_, testing::_, testing::_)).Times(2);
1263 auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1264 int64_t surfaceFrameToken1 = mTokenManager->generateTokenForPredictions({10, 20, 30});
1265 int64_t surfaceFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60});
1266
1267 int64_t sfToken1 = mTokenManager->generateTokenForPredictions({52, 56, 60});
1268 int64_t sfToken2 = mTokenManager->generateTokenForPredictions({112, 116, 120});
1269 auto surfaceFrame1 =
1270 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken1, sPidOne, sUidOne,
1271 sLayerNameOne, sLayerNameOne);
1272 surfaceFrame1->setAcquireFenceTime(50);
1273 mFrameTimeline->setSfWakeUp(sfToken1, 52, 30);
1274 surfaceFrame1->setPresentState(SurfaceFrame::PresentState::Presented);
1275 mFrameTimeline->addSurfaceFrame(surfaceFrame1);
1276 mFrameTimeline->setSfPresent(56, presentFence1);
1277 auto displayFrame1 = getDisplayFrame(0);
1278 auto& presentedSurfaceFrame1 = getSurfaceFrame(0, 0);
1279 presentFence1->signalForTest(60);
1280
1281 // Fences for the first frame haven't been flushed yet, so it should be 0
1282 EXPECT_EQ(displayFrame1->getActuals().presentTime, 0);
1283 auto actuals1 = presentedSurfaceFrame1.getActuals();
1284 EXPECT_EQ(actuals1.presentTime, 0);
1285
1286 // Trigger a flush by finalizing the next DisplayFrame
1287 auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
1288 auto surfaceFrame2 =
1289 mFrameTimeline->createSurfaceFrameForToken(surfaceFrameToken2, sPidOne, sUidOne,
1290 sLayerNameOne, sLayerNameOne);
1291 surfaceFrame2->setAcquireFenceTime(84);
1292 mFrameTimeline->setSfWakeUp(sfToken2, 112, 30);
1293 surfaceFrame2->setPresentState(SurfaceFrame::PresentState::Presented, 54);
1294 mFrameTimeline->addSurfaceFrame(surfaceFrame2);
1295 mFrameTimeline->setSfPresent(116, presentFence2);
1296 auto displayFrame2 = getDisplayFrame(1);
1297 auto& presentedSurfaceFrame2 = getSurfaceFrame(1, 0);
1298 presentFence2->signalForTest(120);
1299
1300 // Fences for the first frame have flushed, so the present timestamps should be updated
1301 EXPECT_EQ(displayFrame1->getActuals().presentTime, 60);
1302 actuals1 = presentedSurfaceFrame1.getActuals();
1303 EXPECT_EQ(actuals1.endTime, 50);
1304 EXPECT_EQ(actuals1.presentTime, 60);
1305
1306 EXPECT_EQ(displayFrame1->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1307 EXPECT_EQ(displayFrame1->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1308 EXPECT_EQ(displayFrame1->getJankType(), JankType::None);
1309
1310 EXPECT_EQ(presentedSurfaceFrame1.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1311 EXPECT_EQ(presentedSurfaceFrame1.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1312 EXPECT_EQ(presentedSurfaceFrame1.getJankType(), JankType::AppDeadlineMissed);
1313
1314 // Fences for the second frame haven't been flushed yet, so it should be 0
1315 EXPECT_EQ(displayFrame2->getActuals().presentTime, 0);
1316 auto actuals2 = presentedSurfaceFrame2.getActuals();
1317 EXPECT_EQ(actuals2.presentTime, 0);
1318
1319 addEmptyDisplayFrame();
1320
1321 // Fences for the second frame have flushed, so the present timestamps should be updated
1322 EXPECT_EQ(displayFrame2->getActuals().presentTime, 120);
1323 actuals2 = presentedSurfaceFrame2.getActuals();
1324 EXPECT_EQ(actuals2.presentTime, 120);
1325
1326 EXPECT_EQ(displayFrame2->getFramePresentMetadata(), FramePresentMetadata::OnTimePresent);
1327 EXPECT_EQ(displayFrame2->getFrameReadyMetadata(), FrameReadyMetadata::OnTimeFinish);
1328 EXPECT_EQ(displayFrame2->getJankType(), JankType::None);
1329
1330 EXPECT_EQ(presentedSurfaceFrame2.getFramePresentMetadata(), FramePresentMetadata::LatePresent);
1331 EXPECT_EQ(presentedSurfaceFrame2.getFrameReadyMetadata(), FrameReadyMetadata::LateFinish);
1332 EXPECT_EQ(presentedSurfaceFrame2.getJankType(),
1333 JankType::AppDeadlineMissed | JankType::BufferStuffing);
1334}
Adithya Srinivasanf279e042020-08-17 14:56:27 -07001335} // namespace android::frametimeline