blob: df4464ef526cecbada35b47346909dcf1a48ae12 [file] [log] [blame]
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001/*
2 * Copyright 2018 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
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -080017// TODO(b/129481165): remove the #pragma below and fix conversion issues
18#pragma clang diagnostic push
19#pragma clang diagnostic ignored "-Wconversion"
Marin Shalamanovbed7fd32020-12-21 20:02:20 +010020#pragma clang diagnostic ignored "-Wextra"
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -080021
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080022#undef LOG_TAG
23#define LOG_TAG "LibSurfaceFlingerUnittests"
24
Mikael Pessa2e1608f2019-07-19 11:25:35 -070025#include <TimeStats/TimeStats.h>
Alec Mouri37384342020-01-02 17:23:37 -080026#include <android/util/ProtoOutputStream.h>
Alec Mourifb571ea2019-01-24 18:42:10 -080027#include <gmock/gmock.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080028#include <gtest/gtest.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080029#include <log/log.h>
30#include <utils/String16.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080031#include <utils/Vector.h>
32
Alec Mouri9519bf12019-11-15 16:54:44 -080033#include <chrono>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080034#include <random>
Alec Mourifb571ea2019-01-24 18:42:10 -080035#include <unordered_set>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080036
Lloyd Pique067fe1e2018-12-06 19:44:13 -080037#include "libsurfaceflinger_unittest_main.h"
38
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080039using namespace android::surfaceflinger;
40using namespace google::protobuf;
Vishnu Nairabf97fd2020-02-03 13:51:16 -080041using namespace std::chrono_literals;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080042
43namespace android {
44namespace {
45
Alec Mouri8e2f31b2020-01-16 22:04:35 +000046using testing::_;
Alec Mouri37384342020-01-02 17:23:37 -080047using testing::AnyNumber;
Alec Mourifb571ea2019-01-24 18:42:10 -080048using testing::Contains;
Vishnu Nair9b079a22020-01-21 14:36:08 -080049using testing::HasSubstr;
Alec Mouri8e2f31b2020-01-16 22:04:35 +000050using testing::InSequence;
Alec Mourifb571ea2019-01-24 18:42:10 -080051using testing::SizeIs;
Alec Mouri37384342020-01-02 17:23:37 -080052using testing::StrEq;
Alec Mourifb571ea2019-01-24 18:42:10 -080053using testing::UnorderedElementsAre;
54
Peiyong Lin65248e02020-04-18 21:15:07 -070055using PowerMode = hardware::graphics::composer::V2_4::IComposerClient::PowerMode;
56
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080057// clang-format off
58#define FMT_PROTO true
59#define FMT_STRING false
60#define LAYER_ID_0 0
61#define LAYER_ID_1 1
Alec Mouri9a29e672020-09-14 12:39:14 -070062#define UID_0 123
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080063#define LAYER_ID_INVALID -1
64#define NUM_LAYERS 1
65#define NUM_LAYERS_INVALID "INVALID"
66
67enum InputCommand : int32_t {
68 ENABLE = 0,
69 DISABLE = 1,
70 CLEAR = 2,
71 DUMP_ALL = 3,
72 DUMP_MAXLAYERS_1 = 4,
73 DUMP_MAXLAYERS_INVALID = 5,
74 INPUT_COMMAND_BEGIN = ENABLE,
75 INPUT_COMMAND_END = DUMP_MAXLAYERS_INVALID,
76 INPUT_COMMAND_RANGE = INPUT_COMMAND_END - INPUT_COMMAND_BEGIN + 1,
77};
78
79enum TimeStamp : int32_t {
80 POST = 0,
81 ACQUIRE = 1,
82 ACQUIRE_FENCE = 2,
83 LATCH = 3,
84 DESIRED = 4,
85 PRESENT = 5,
86 PRESENT_FENCE = 6,
87 TIME_STAMP_BEGIN = POST,
88 TIME_STAMP_END = PRESENT,
89 TIME_STAMP_RANGE = TIME_STAMP_END - TIME_STAMP_BEGIN + 1,
90};
91
92static const TimeStamp NORMAL_SEQUENCE[] = {
93 TimeStamp::POST,
94 TimeStamp::ACQUIRE,
95 TimeStamp::LATCH,
96 TimeStamp::DESIRED,
97 TimeStamp::PRESENT,
98};
99
100static const TimeStamp NORMAL_SEQUENCE_2[] = {
101 TimeStamp::POST,
102 TimeStamp::ACQUIRE_FENCE,
103 TimeStamp::LATCH,
104 TimeStamp::DESIRED,
105 TimeStamp::PRESENT_FENCE,
106};
107
108static const TimeStamp UNORDERED_SEQUENCE[] = {
109 TimeStamp::ACQUIRE,
110 TimeStamp::LATCH,
111 TimeStamp::POST,
112 TimeStamp::DESIRED,
113 TimeStamp::PRESENT,
114};
115
116static const TimeStamp INCOMPLETE_SEQUENCE[] = {
117 TimeStamp::POST,
118};
119// clang-format on
120
121class TimeStatsTest : public testing::Test {
122public:
123 TimeStatsTest() {
124 const ::testing::TestInfo* const test_info =
125 ::testing::UnitTest::GetInstance()->current_test_info();
126 ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
127 }
128
129 ~TimeStatsTest() {
130 const ::testing::TestInfo* const test_info =
131 ::testing::UnitTest::GetInstance()->current_test_info();
132 ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
133 }
134
135 std::string inputCommand(InputCommand cmd, bool useProto);
136
137 void setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts);
138
139 int32_t genRandomInt32(int32_t begin, int32_t end);
140
141 template <size_t N>
142 void insertTimeRecord(const TimeStamp (&sequence)[N], int32_t id, uint64_t frameNumber,
143 nsecs_t ts) {
144 for (size_t i = 0; i < N; i++, ts += 1000000) {
145 setTimeStamp(sequence[i], id, frameNumber, ts);
146 }
147 }
148
149 std::mt19937 mRandomEngine = std::mt19937(std::random_device()());
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000150
151 class FakeStatsEventDelegate : public impl::TimeStats::StatsEventDelegate {
152 public:
153 FakeStatsEventDelegate() = default;
154 ~FakeStatsEventDelegate() override = default;
155
Tej Singh2a457b62020-01-31 16:16:10 -0800156 struct AStatsEvent* addStatsEventToPullData(AStatsEventList*) override {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000157 return mEvent;
158 }
Tej Singh38a4b212020-03-13 19:04:51 -0700159 void setStatsPullAtomCallback(int32_t atom_tag, AStatsManager_PullAtomMetadata*,
160 AStatsManager_PullAtomCallback callback,
161 void* cookie) override {
Alec Mouri37384342020-01-02 17:23:37 -0800162 mAtomTags.push_back(atom_tag);
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000163 mCallback = callback;
164 mCookie = cookie;
165 }
166
Tej Singh2a457b62020-01-31 16:16:10 -0800167 AStatsManager_PullAtomCallbackReturn makePullAtomCallback(int32_t atom_tag, void* cookie) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000168 return (*mCallback)(atom_tag, nullptr, cookie);
169 }
170
Tej Singh38a4b212020-03-13 19:04:51 -0700171 MOCK_METHOD1(clearStatsPullAtomCallback, void(int32_t));
Tej Singh2a457b62020-01-31 16:16:10 -0800172 MOCK_METHOD2(statsEventSetAtomId, void(AStatsEvent*, uint32_t));
Alec Mouri717bcb62020-02-10 17:07:19 -0800173 MOCK_METHOD2(statsEventWriteInt32, void(AStatsEvent*, int32_t));
Tej Singh2a457b62020-01-31 16:16:10 -0800174 MOCK_METHOD2(statsEventWriteInt64, void(AStatsEvent*, int64_t));
175 MOCK_METHOD2(statsEventWriteString8, void(AStatsEvent*, const char*));
176 MOCK_METHOD3(statsEventWriteByteArray, void(AStatsEvent*, const uint8_t*, size_t));
177 MOCK_METHOD1(statsEventBuild, void(AStatsEvent*));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000178
Tej Singh2a457b62020-01-31 16:16:10 -0800179 AStatsEvent* mEvent = AStatsEvent_obtain();
Alec Mouri37384342020-01-02 17:23:37 -0800180 std::vector<int32_t> mAtomTags;
Tej Singh2a457b62020-01-31 16:16:10 -0800181 AStatsManager_PullAtomCallback mCallback = nullptr;
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000182 void* mCookie = nullptr;
183 };
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000184 FakeStatsEventDelegate* mDelegate = new FakeStatsEventDelegate;
185 std::unique_ptr<TimeStats> mTimeStats =
Alec Mouri37384342020-01-02 17:23:37 -0800186 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
187 std::nullopt, std::nullopt);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800188};
189
190std::string TimeStatsTest::inputCommand(InputCommand cmd, bool useProto) {
Yiwei Zhang5434a782018-12-05 18:06:32 -0800191 std::string result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800192 Vector<String16> args;
193
194 switch (cmd) {
195 case InputCommand::ENABLE:
196 args.push_back(String16("-enable"));
197 break;
198 case InputCommand::DISABLE:
199 args.push_back(String16("-disable"));
200 break;
201 case InputCommand::CLEAR:
202 args.push_back(String16("-clear"));
203 break;
204 case InputCommand::DUMP_ALL:
205 args.push_back(String16("-dump"));
206 break;
207 case InputCommand::DUMP_MAXLAYERS_1:
208 args.push_back(String16("-dump"));
209 args.push_back(String16("-maxlayers"));
210 args.push_back(String16(std::to_string(NUM_LAYERS).c_str()));
211 break;
212 case InputCommand::DUMP_MAXLAYERS_INVALID:
213 args.push_back(String16("-dump"));
214 args.push_back(String16("-maxlayers"));
215 args.push_back(String16(NUM_LAYERS_INVALID));
216 break;
217 default:
218 ALOGD("Invalid control command");
219 }
220
Dominik Laskowskic2867142019-01-21 11:33:38 -0800221 EXPECT_NO_FATAL_FAILURE(mTimeStats->parseArgs(useProto, args, result));
Yiwei Zhang5434a782018-12-05 18:06:32 -0800222 return result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800223}
224
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800225static std::string genLayerName(int32_t layerId) {
Peiyong Lind8460c82020-07-28 16:04:22 -0700226 return (layerId < 0 ? "PopupWindow:b54fcd1#0" : "com.example.fake#") + std::to_string(layerId);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800227}
228
229void TimeStatsTest::setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts) {
230 switch (type) {
231 case TimeStamp::POST:
Alec Mouri9a29e672020-09-14 12:39:14 -0700232 ASSERT_NO_FATAL_FAILURE(
233 mTimeStats->setPostTime(id, frameNumber, genLayerName(id), UID_0, ts));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800234 break;
235 case TimeStamp::ACQUIRE:
236 ASSERT_NO_FATAL_FAILURE(mTimeStats->setAcquireTime(id, frameNumber, ts));
237 break;
238 case TimeStamp::ACQUIRE_FENCE:
239 ASSERT_NO_FATAL_FAILURE(
240 mTimeStats->setAcquireFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
241 break;
242 case TimeStamp::LATCH:
243 ASSERT_NO_FATAL_FAILURE(mTimeStats->setLatchTime(id, frameNumber, ts));
244 break;
245 case TimeStamp::DESIRED:
246 ASSERT_NO_FATAL_FAILURE(mTimeStats->setDesiredTime(id, frameNumber, ts));
247 break;
248 case TimeStamp::PRESENT:
249 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPresentTime(id, frameNumber, ts));
250 break;
251 case TimeStamp::PRESENT_FENCE:
252 ASSERT_NO_FATAL_FAILURE(
253 mTimeStats->setPresentFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
254 break;
255 default:
256 ALOGD("Invalid timestamp type");
257 }
258}
259
260int32_t TimeStatsTest::genRandomInt32(int32_t begin, int32_t end) {
261 std::uniform_int_distribution<int32_t> distr(begin, end);
262 return distr(mRandomEngine);
263}
264
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000265TEST_F(TimeStatsTest, disabledByDefault) {
266 ASSERT_FALSE(mTimeStats->isEnabled());
267}
268
Tej Singh38a4b212020-03-13 19:04:51 -0700269TEST_F(TimeStatsTest, setsCallbacksAfterBoot) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000270 mTimeStats->onBootFinished();
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800271 EXPECT_THAT(mDelegate->mAtomTags,
272 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
273 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
274}
275
Tej Singh38a4b212020-03-13 19:04:51 -0700276TEST_F(TimeStatsTest, clearsCallbacksOnDestruction) {
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800277 EXPECT_CALL(*mDelegate,
Tej Singh38a4b212020-03-13 19:04:51 -0700278 clearStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800279 EXPECT_CALL(*mDelegate,
Tej Singh38a4b212020-03-13 19:04:51 -0700280 clearStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO));
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800281 mTimeStats.reset();
Alec Mourib3885ad2019-09-06 17:08:55 -0700282}
283
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800284TEST_F(TimeStatsTest, canEnableAndDisableTimeStats) {
285 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
286 ASSERT_TRUE(mTimeStats->isEnabled());
287
288 EXPECT_TRUE(inputCommand(InputCommand::DISABLE, FMT_STRING).empty());
289 ASSERT_FALSE(mTimeStats->isEnabled());
290}
291
292TEST_F(TimeStatsTest, canIncreaseGlobalStats) {
293 constexpr size_t TOTAL_FRAMES = 5;
294 constexpr size_t MISSED_FRAMES = 4;
295 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
296
297 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
298
299 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
300 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
301 }
302 for (size_t i = 0; i < MISSED_FRAMES; i++) {
303 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
304 }
305 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
306 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
307 }
308
309 SFTimeStatsGlobalProto globalProto;
310 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
311
312 ASSERT_TRUE(globalProto.has_total_frames());
313 EXPECT_EQ(TOTAL_FRAMES, globalProto.total_frames());
314 ASSERT_TRUE(globalProto.has_missed_frames());
315 EXPECT_EQ(MISSED_FRAMES, globalProto.missed_frames());
316 ASSERT_TRUE(globalProto.has_client_composition_frames());
317 EXPECT_EQ(CLIENT_COMPOSITION_FRAMES, globalProto.client_composition_frames());
318}
319
Alec Mouri91f6df32020-01-30 08:48:58 -0800320TEST_F(TimeStatsTest, canIncreaseLateAcquireFrames) {
321 // this stat is not in the proto so verify by checking the string dump
322 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
323
324 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
325
326 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
327 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
328 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
329 }
330 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
331
332 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
333 const std::string expectedResult = "lateAcquireFrames = " + std::to_string(LATE_ACQUIRE_FRAMES);
334 EXPECT_THAT(result, HasSubstr(expectedResult));
335}
336
337TEST_F(TimeStatsTest, canIncreaseBadDesiredPresent) {
338 // this stat is not in the proto so verify by checking the string dump
339 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 2;
340
341 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
342
343 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
344 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
345 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
346 }
347 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
348
349 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
350 const std::string expectedResult =
351 "badDesiredPresentFrames = " + std::to_string(BAD_DESIRED_PRESENT_FRAMES);
352 EXPECT_THAT(result, HasSubstr(expectedResult));
353}
354
Alec Mouri9a29e672020-09-14 12:39:14 -0700355TEST_F(TimeStatsTest, canIncreaseJankyFrames) {
356 // this stat is not in the proto so verify by checking the string dump
357 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
358
359 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800360 mTimeStats->incrementJankyFrames(JankType::SurfaceFlingerCpuDeadlineMissed);
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100361 mTimeStats->incrementJankyFrames(JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800362 mTimeStats->incrementJankyFrames(JankType::DisplayHAL);
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100363 mTimeStats->incrementJankyFrames(JankType::AppDeadlineMissed);
364 mTimeStats->incrementJankyFrames(JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -0700365
366 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
367 std::string expectedResult = "totalTimelineFrames = " + std::to_string(5);
368 EXPECT_THAT(result, HasSubstr(expectedResult));
369 expectedResult = "jankyFrames = " + std::to_string(4);
370 EXPECT_THAT(result, HasSubstr(expectedResult));
371 expectedResult = "sfLongCpuJankyFrames = " + std::to_string(1);
372 EXPECT_THAT(result, HasSubstr(expectedResult));
373 expectedResult = "sfLongGpuJankyFrames = " + std::to_string(1);
374 EXPECT_THAT(result, HasSubstr(expectedResult));
375 expectedResult = "sfUnattributedJankyFrame = " + std::to_string(1);
376 EXPECT_THAT(result, HasSubstr(expectedResult));
377 expectedResult = "appUnattributedJankyFrame = " + std::to_string(1);
378 EXPECT_THAT(result, HasSubstr(expectedResult));
379}
380
381TEST_F(TimeStatsTest, canIncreaseJankyFramesForLayer) {
382 // this stat is not in the proto so verify by checking the string dump
383 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
384
385 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
386 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800387 JankType::SurfaceFlingerCpuDeadlineMissed);
Alec Mouri9a29e672020-09-14 12:39:14 -0700388 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100389 JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800390 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::DisplayHAL);
Alec Mouri9a29e672020-09-14 12:39:14 -0700391 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100392 JankType::AppDeadlineMissed);
393 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -0700394
395 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
396 std::string expectedResult = "totalTimelineFrames = " + std::to_string(5);
397 EXPECT_THAT(result, HasSubstr(expectedResult));
398 expectedResult = "jankyFrames = " + std::to_string(4);
399 EXPECT_THAT(result, HasSubstr(expectedResult));
400 expectedResult = "sfLongCpuJankyFrames = " + std::to_string(1);
401 EXPECT_THAT(result, HasSubstr(expectedResult));
402 expectedResult = "sfLongGpuJankyFrames = " + std::to_string(1);
403 EXPECT_THAT(result, HasSubstr(expectedResult));
404 expectedResult = "sfUnattributedJankyFrame = " + std::to_string(1);
405 EXPECT_THAT(result, HasSubstr(expectedResult));
406 expectedResult = "appUnattributedJankyFrame = " + std::to_string(1);
407 EXPECT_THAT(result, HasSubstr(expectedResult));
408}
409
Vishnu Nair9b079a22020-01-21 14:36:08 -0800410TEST_F(TimeStatsTest, canIncreaseClientCompositionReusedFrames) {
411 // this stat is not in the proto so verify by checking the string dump
412 constexpr size_t CLIENT_COMPOSITION_REUSED_FRAMES = 2;
413
414 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
415 for (size_t i = 0; i < CLIENT_COMPOSITION_REUSED_FRAMES; i++) {
416 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
417 }
418
419 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
420 const std::string expectedResult =
421 "clientCompositionReusedFrames = " + std::to_string(CLIENT_COMPOSITION_REUSED_FRAMES);
422 EXPECT_THAT(result, HasSubstr(expectedResult));
423}
424
Alec Mouri8de697e2020-03-19 10:52:01 -0700425TEST_F(TimeStatsTest, canIncreaseRefreshRateSwitches) {
426 // this stat is not in the proto so verify by checking the string dump
427 constexpr size_t REFRESH_RATE_SWITCHES = 2;
428
429 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
430 for (size_t i = 0; i < REFRESH_RATE_SWITCHES; i++) {
431 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementRefreshRateSwitches());
432 }
433
434 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
435 const std::string expectedResult =
436 "refreshRateSwitches = " + std::to_string(REFRESH_RATE_SWITCHES);
437 EXPECT_THAT(result, HasSubstr(expectedResult));
438}
439
Alec Mouri8f7a0102020-04-15 12:11:10 -0700440TEST_F(TimeStatsTest, canIncreaseCompositionStrategyChanges) {
441 // this stat is not in the proto so verify by checking the string dump
442 constexpr size_t COMPOSITION_STRATEGY_CHANGES = 2;
443
444 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
445 for (size_t i = 0; i < COMPOSITION_STRATEGY_CHANGES; i++) {
446 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementCompositionStrategyChanges());
447 }
448
449 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
450 const std::string expectedResult =
451 "compositionStrategyChanges = " + std::to_string(COMPOSITION_STRATEGY_CHANGES);
452 EXPECT_THAT(result, HasSubstr(expectedResult));
453}
454
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800455TEST_F(TimeStatsTest, canAverageFrameDuration) {
456 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
Peiyong Lin65248e02020-04-18 21:15:07 -0700457 mTimeStats->setPowerMode(PowerMode::ON);
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800458 mTimeStats
459 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
460 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
461 .count());
462 mTimeStats
463 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
464 std::chrono::duration_cast<std::chrono::nanoseconds>(16ms)
465 .count());
466
467 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
468 EXPECT_THAT(result, HasSubstr("averageFrameDuration = 10.000 ms"));
469}
470
471TEST_F(TimeStatsTest, canAverageRenderEngineTimings) {
472 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
473 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms)
474 .count(),
475 std::make_shared<FenceTime>(
476 std::chrono::duration_cast<
477 std::chrono::nanoseconds>(3ms)
478 .count()));
479
480 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
481 .count(),
482 std::chrono::duration_cast<std::chrono::nanoseconds>(8ms)
483 .count());
484
Peiyong Lind8460c82020-07-28 16:04:22 -0700485 // Push a fake present fence to trigger flushing the RenderEngine timings.
Peiyong Lin65248e02020-04-18 21:15:07 -0700486 mTimeStats->setPowerMode(PowerMode::ON);
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800487 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
488 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
489
490 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
491 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 3.000 ms"));
492}
493
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800494TEST_F(TimeStatsTest, canInsertGlobalPresentToPresent) {
495 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
496
497 ASSERT_NO_FATAL_FAILURE(
498 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
499 ASSERT_NO_FATAL_FAILURE(
500 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
501
Peiyong Lin65248e02020-04-18 21:15:07 -0700502 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::ON));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800503 ASSERT_NO_FATAL_FAILURE(
504 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000)));
505 ASSERT_NO_FATAL_FAILURE(
506 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000)));
507
Peiyong Lin65248e02020-04-18 21:15:07 -0700508 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::OFF));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800509 ASSERT_NO_FATAL_FAILURE(
510 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(6000000)));
511 ASSERT_NO_FATAL_FAILURE(
512 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(8000000)));
513
514 SFTimeStatsGlobalProto globalProto;
515 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
516
517 ASSERT_EQ(1, globalProto.present_to_present_size());
518 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.present_to_present().Get(0);
519 EXPECT_EQ(1, histogramProto.frame_count());
520 EXPECT_EQ(2, histogramProto.time_millis());
521}
522
Alec Mouri9519bf12019-11-15 16:54:44 -0800523TEST_F(TimeStatsTest, canInsertGlobalFrameDuration) {
524 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
525
Peiyong Lin65248e02020-04-18 21:15:07 -0700526 mTimeStats->setPowerMode(PowerMode::OFF);
Alec Mouri9519bf12019-11-15 16:54:44 -0800527 mTimeStats
528 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
529 std::chrono::duration_cast<std::chrono::nanoseconds>(5ms)
530 .count());
Peiyong Lin65248e02020-04-18 21:15:07 -0700531 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouri9519bf12019-11-15 16:54:44 -0800532 mTimeStats
533 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
534 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
535 .count());
536
537 SFTimeStatsGlobalProto globalProto;
538 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
539
540 ASSERT_EQ(1, globalProto.frame_duration_size());
541 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.frame_duration().Get(0);
542 EXPECT_EQ(1, histogramProto.frame_count());
543 EXPECT_EQ(3, histogramProto.time_millis());
544}
545
Alec Mourie4034bb2019-11-19 12:45:54 -0800546TEST_F(TimeStatsTest, canInsertGlobalRenderEngineTiming) {
547 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
548
Alec Mourie4034bb2019-11-19 12:45:54 -0800549 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms)
550 .count(),
551 std::make_shared<FenceTime>(
552 std::chrono::duration_cast<
553 std::chrono::nanoseconds>(3ms)
554 .count()));
555
556 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
557 .count(),
558 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
559 .count());
560
561 // First verify that flushing RenderEngine durations did not occur yet.
562 SFTimeStatsGlobalProto preFlushProto;
563 ASSERT_TRUE(preFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
564 ASSERT_EQ(0, preFlushProto.render_engine_timing_size());
565
Peiyong Lind8460c82020-07-28 16:04:22 -0700566 // Push a fake present fence to trigger flushing the RenderEngine timings.
Peiyong Lin65248e02020-04-18 21:15:07 -0700567 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mourie4034bb2019-11-19 12:45:54 -0800568 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
569 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
570
571 // Now we can verify that RenderEngine durations were flushed now.
572 SFTimeStatsGlobalProto postFlushProto;
573 ASSERT_TRUE(postFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
574
575 ASSERT_EQ(1, postFlushProto.render_engine_timing_size());
576 const SFTimeStatsHistogramBucketProto& histogramProto =
577 postFlushProto.render_engine_timing().Get(0);
578 EXPECT_EQ(2, histogramProto.frame_count());
579 EXPECT_EQ(2, histogramProto.time_millis());
580}
581
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800582TEST_F(TimeStatsTest, canInsertOneLayerTimeStats) {
583 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
584
585 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
586 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
587
588 SFTimeStatsGlobalProto globalProto;
589 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
590
591 ASSERT_EQ(1, globalProto.stats_size());
592 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
593 ASSERT_TRUE(layerProto.has_layer_name());
594 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
595 ASSERT_TRUE(layerProto.has_total_frames());
596 EXPECT_EQ(1, layerProto.total_frames());
597 ASSERT_EQ(6, layerProto.deltas_size());
598 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
599 ASSERT_EQ(1, deltaProto.histograms_size());
600 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
601 EXPECT_EQ(1, histogramProto.frame_count());
602 if ("post2acquire" == deltaProto.delta_name()) {
603 EXPECT_EQ(1, histogramProto.time_millis());
604 } else if ("post2present" == deltaProto.delta_name()) {
605 EXPECT_EQ(4, histogramProto.time_millis());
606 } else if ("acquire2present" == deltaProto.delta_name()) {
607 EXPECT_EQ(3, histogramProto.time_millis());
608 } else if ("latch2present" == deltaProto.delta_name()) {
609 EXPECT_EQ(2, histogramProto.time_millis());
610 } else if ("desired2present" == deltaProto.delta_name()) {
611 EXPECT_EQ(1, histogramProto.time_millis());
612 } else if ("present2present" == deltaProto.delta_name()) {
613 EXPECT_EQ(1, histogramProto.time_millis());
614 } else {
615 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
616 }
617 }
618}
619
620TEST_F(TimeStatsTest, canNotInsertInvalidLayerNameTimeStats) {
621 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
622
623 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_INVALID, 1, 1000000);
624 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_INVALID, 2, 2000000);
625
626 SFTimeStatsGlobalProto globalProto;
627 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
628
629 ASSERT_EQ(0, globalProto.stats_size());
630}
631
632TEST_F(TimeStatsTest, canInsertMultipleLayersTimeStats) {
633 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
634
635 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
636 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
637 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
638 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
639
640 SFTimeStatsGlobalProto globalProto;
641 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
642
643 EXPECT_EQ(2, globalProto.stats_size());
644}
645
646TEST_F(TimeStatsTest, canInsertUnorderedLayerTimeStats) {
647 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
648
649 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
650 insertTimeRecord(UNORDERED_SEQUENCE, LAYER_ID_0, 2, 2000000);
651
652 SFTimeStatsGlobalProto globalProto;
653 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
654
655 ASSERT_EQ(1, globalProto.stats_size());
656 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
657 ASSERT_TRUE(layerProto.has_layer_name());
658 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
659 ASSERT_TRUE(layerProto.has_total_frames());
660 EXPECT_EQ(1, layerProto.total_frames());
661 ASSERT_EQ(6, layerProto.deltas_size());
662 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
663 ASSERT_EQ(1, deltaProto.histograms_size());
664 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
665 EXPECT_EQ(1, histogramProto.frame_count());
666 if ("post2acquire" == deltaProto.delta_name()) {
667 EXPECT_EQ(0, histogramProto.time_millis());
668 } else if ("post2present" == deltaProto.delta_name()) {
669 EXPECT_EQ(2, histogramProto.time_millis());
670 } else if ("acquire2present" == deltaProto.delta_name()) {
671 EXPECT_EQ(2, histogramProto.time_millis());
672 } else if ("latch2present" == deltaProto.delta_name()) {
673 EXPECT_EQ(2, histogramProto.time_millis());
674 } else if ("desired2present" == deltaProto.delta_name()) {
675 EXPECT_EQ(1, histogramProto.time_millis());
676 } else if ("present2present" == deltaProto.delta_name()) {
677 EXPECT_EQ(1, histogramProto.time_millis());
678 } else {
679 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
680 }
681 }
682}
683
Alec Mourifb571ea2019-01-24 18:42:10 -0800684TEST_F(TimeStatsTest, recordRefreshRateNewConfigs) {
685 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
686
687 uint32_t fpsOne = 30;
688 uint32_t fpsTwo = 90;
689 uint64_t millisOne = 5000;
690 uint64_t millisTwo = 7000;
691
692 mTimeStats->recordRefreshRate(fpsOne, ms2ns(millisOne));
693 mTimeStats->recordRefreshRate(fpsTwo, ms2ns(millisTwo));
694
695 SFTimeStatsGlobalProto globalProto;
696 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
697
698 SFTimeStatsDisplayConfigBucketProto expectedBucketOne;
699 SFTimeStatsDisplayConfigProto* expectedConfigOne = expectedBucketOne.mutable_config();
700 expectedConfigOne->set_fps(fpsOne);
701 expectedBucketOne.set_duration_millis(millisOne);
702
703 SFTimeStatsDisplayConfigBucketProto expectedBucketTwo;
704 SFTimeStatsDisplayConfigProto* expectedConfigTwo = expectedBucketTwo.mutable_config();
705 expectedConfigTwo->set_fps(fpsTwo);
706 expectedBucketTwo.set_duration_millis(millisTwo);
707
708 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(2));
709
710 std::unordered_set<uint32_t> seen_fps;
711 for (const auto& bucket : globalProto.display_config_stats()) {
712 seen_fps.emplace(bucket.config().fps());
713 if (fpsOne == bucket.config().fps()) {
714 EXPECT_EQ(millisOne, bucket.duration_millis());
715 } else if (fpsTwo == bucket.config().fps()) {
716 EXPECT_EQ(millisTwo, bucket.duration_millis());
717 } else {
718 FAIL() << "Unknown fps: " << bucket.config().fps();
719 }
720 }
721 EXPECT_THAT(seen_fps, UnorderedElementsAre(fpsOne, fpsTwo));
722}
723
724TEST_F(TimeStatsTest, recordRefreshRateUpdatesConfig) {
725 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
726
727 uint32_t fps = 30;
728 uint64_t millisOne = 5000;
729 uint64_t millisTwo = 7000;
730
731 mTimeStats->recordRefreshRate(fps, ms2ns(millisOne));
732 mTimeStats->recordRefreshRate(fps, ms2ns(millisTwo));
733
734 SFTimeStatsGlobalProto globalProto;
735 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
736 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(1));
737 EXPECT_EQ(fps, globalProto.display_config_stats().Get(0).config().fps());
738 EXPECT_EQ(millisOne + millisTwo, globalProto.display_config_stats().Get(0).duration_millis());
739}
740
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800741TEST_F(TimeStatsTest, canRemoveTimeRecord) {
742 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
743
744 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
745 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 2, 2000000);
746 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(0, 2));
747 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
748
749 SFTimeStatsGlobalProto globalProto;
750 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
751
752 ASSERT_EQ(1, globalProto.stats_size());
753 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
754 ASSERT_TRUE(layerProto.has_total_frames());
755 EXPECT_EQ(1, layerProto.total_frames());
756}
757
758TEST_F(TimeStatsTest, canRecoverFromIncompleteTimeRecordError) {
759 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
760
761 uint64_t frameNumber = 1;
762 nsecs_t ts = 1000000;
763 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 1, 1000000);
Alec Mourifb571ea2019-01-24 18:42:10 -0800764 for (size_t i = 0; i < impl::TimeStats::MAX_NUM_TIME_RECORDS + 2; i++) {
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800765 frameNumber++;
766 ts += 1000000;
767 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, frameNumber, ts);
768 }
769
770 SFTimeStatsGlobalProto globalProto;
771 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
772
773 ASSERT_EQ(1, globalProto.stats_size());
774 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
775 ASSERT_TRUE(layerProto.has_total_frames());
776 EXPECT_EQ(1, layerProto.total_frames());
777}
778
779TEST_F(TimeStatsTest, layerTimeStatsOnDestroy) {
780 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
781
782 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
783 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
784 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(0));
785 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
786
787 SFTimeStatsGlobalProto globalProto;
788 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
789
790 ASSERT_EQ(1, globalProto.stats_size());
791 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
792 ASSERT_TRUE(layerProto.has_total_frames());
793 EXPECT_EQ(1, layerProto.total_frames());
794}
795
796TEST_F(TimeStatsTest, canClearTimeStats) {
797 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
798
799 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
800 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
801 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
Peiyong Lin65248e02020-04-18 21:15:07 -0700802 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::ON));
Alec Mouri31ac64a2020-01-09 09:26:22 -0800803
Alec Mouri31ac64a2020-01-09 09:26:22 -0800804 mTimeStats
805 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
806 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
807 .count());
808 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
809 .count(),
810 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
811 .count());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800812 ASSERT_NO_FATAL_FAILURE(
813 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
814 ASSERT_NO_FATAL_FAILURE(
815 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
816 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
817 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
818
819 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
820
821 SFTimeStatsGlobalProto globalProto;
822 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
823
824 EXPECT_EQ(0, globalProto.total_frames());
825 EXPECT_EQ(0, globalProto.missed_frames());
826 EXPECT_EQ(0, globalProto.client_composition_frames());
827 EXPECT_EQ(0, globalProto.present_to_present_size());
Alec Mouri31ac64a2020-01-09 09:26:22 -0800828 EXPECT_EQ(0, globalProto.frame_duration_size());
829 EXPECT_EQ(0, globalProto.render_engine_timing_size());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800830 EXPECT_EQ(0, globalProto.stats_size());
831}
832
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800833TEST_F(TimeStatsTest, canClearDumpOnlyTimeStats) {
834 // These stats are not in the proto so verify by checking the string dump.
Vishnu Nair9b079a22020-01-21 14:36:08 -0800835 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
836 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
Alec Mouri8de697e2020-03-19 10:52:01 -0700837 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementRefreshRateSwitches());
Alec Mouri8f7a0102020-04-15 12:11:10 -0700838 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementCompositionStrategyChanges());
Peiyong Lin65248e02020-04-18 21:15:07 -0700839 mTimeStats->setPowerMode(PowerMode::ON);
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800840 mTimeStats
841 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
842 std::chrono::duration_cast<std::chrono::nanoseconds>(5ms)
843 .count());
844 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
845 .count(),
846 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
847 .count());
848 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
849 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
Alec Mouri9a29e672020-09-14 12:39:14 -0700850
851 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800852 JankType::SurfaceFlingerCpuDeadlineMissed);
Alec Mouri9a29e672020-09-14 12:39:14 -0700853 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100854 JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800855 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::DisplayHAL);
Alec Mouri9a29e672020-09-14 12:39:14 -0700856 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100857 JankType::AppDeadlineMissed);
858 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -0700859
Vishnu Nair9b079a22020-01-21 14:36:08 -0800860 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
861
862 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
863 EXPECT_THAT(result, HasSubstr("clientCompositionReusedFrames = 0"));
Alec Mouri8de697e2020-03-19 10:52:01 -0700864 EXPECT_THAT(result, HasSubstr("refreshRateSwitches = 0"));
Alec Mouri8f7a0102020-04-15 12:11:10 -0700865 EXPECT_THAT(result, HasSubstr("compositionStrategyChanges = 0"));
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800866 EXPECT_THAT(result, HasSubstr("averageFrameDuration = 0.000 ms"));
867 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 0.000 ms"));
Alec Mouri9a29e672020-09-14 12:39:14 -0700868 EXPECT_THAT(result, HasSubstr("jankyFrames = 0"));
869 EXPECT_THAT(result, HasSubstr("sfLongCpuJankyFrames = 0"));
870 EXPECT_THAT(result, HasSubstr("sfLongGpuJankyFrames = 0"));
871 EXPECT_THAT(result, HasSubstr("sfUnattributedJankyFrame = 0"));
872 EXPECT_THAT(result, HasSubstr("appUnattributedJankyFrame = 0"));
Vishnu Nair9b079a22020-01-21 14:36:08 -0800873}
874
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800875TEST_F(TimeStatsTest, canDumpWithMaxLayers) {
876 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
877
878 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
879 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
880 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
881 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
882 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 3, 2000000);
883
884 SFTimeStatsGlobalProto globalProto;
885 ASSERT_TRUE(
886 globalProto.ParseFromString(inputCommand(InputCommand::DUMP_MAXLAYERS_1, FMT_PROTO)));
887
888 ASSERT_EQ(1, globalProto.stats_size());
889 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
890 ASSERT_TRUE(layerProto.has_layer_name());
891 EXPECT_EQ(genLayerName(LAYER_ID_1), layerProto.layer_name());
892 ASSERT_TRUE(layerProto.has_total_frames());
893 EXPECT_EQ(2, layerProto.total_frames());
894}
895
896TEST_F(TimeStatsTest, canDumpWithInvalidMaxLayers) {
897 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
898
899 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
900 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
901
902 SFTimeStatsGlobalProto globalProto;
903 ASSERT_TRUE(globalProto.ParseFromString(
904 inputCommand(InputCommand::DUMP_MAXLAYERS_INVALID, FMT_PROTO)));
905
906 ASSERT_EQ(0, globalProto.stats_size());
907}
908
Yiwei Zhangdd221b22020-06-12 11:06:19 -0700909TEST_F(TimeStatsTest, noInfInAverageFPS) {
910 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
911 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
912 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 1000000);
913
914 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
915 EXPECT_THAT(result, HasSubstr("averageFPS = 0.000"));
916}
917
Alec Mouri37384342020-01-02 17:23:37 -0800918namespace {
919std::string buildExpectedHistogramBytestring(const std::vector<int32_t>& times,
920 const std::vector<int32_t>& frameCounts) {
921 util::ProtoOutputStream proto;
922 for (int i = 0; i < times.size(); i++) {
923 ALOGE("Writing time: %d", times[i]);
924 proto.write(util::FIELD_TYPE_INT32 | util::FIELD_COUNT_REPEATED | 1 /* field id */,
925 (int32_t)times[i]);
926 ALOGE("Writing count: %d", frameCounts[i]);
927 proto.write(util::FIELD_TYPE_INT64 | util::FIELD_COUNT_REPEATED | 2 /* field id */,
928 (int64_t)frameCounts[i]);
929 }
930 std::string byteString;
931 proto.serializeToString(&byteString);
932 return byteString;
933}
934
Alec Mouri75de8f22021-01-20 14:53:44 -0800935std::string frameRateVoteToProtoByteString(float refreshRate, int frameRateCompatibility,
936 int seamlessness) {
937 util::ProtoOutputStream proto;
938 proto.write(android::util::FIELD_TYPE_FLOAT | 1 /* field id */, refreshRate);
939 proto.write(android::util::FIELD_TYPE_ENUM | 2 /* field id */, frameRateCompatibility);
940 proto.write(android::util::FIELD_TYPE_ENUM | 3 /* field id */, seamlessness);
941
942 std::string byteString;
943 proto.serializeToString(&byteString);
944 return byteString;
945}
946
Alec Mouri37384342020-01-02 17:23:37 -0800947std::string dumpByteStringHex(const std::string& str) {
948 std::stringstream ss;
949 ss << std::hex;
950 for (const char& c : str) {
951 ss << (int)c << " ";
952 }
953
954 return ss.str();
955}
956
957} // namespace
958
959MATCHER_P2(BytesEq, bytes, size, "") {
960 std::string expected;
961 expected.append((const char*)bytes, size);
962 std::string actual;
963 actual.append((const char*)arg, size);
964
965 *result_listener << "Bytes are not equal! \n";
966 *result_listener << "size: " << size << "\n";
967 *result_listener << "expected: " << dumpByteStringHex(expected).c_str() << "\n";
968 *result_listener << "actual: " << dumpByteStringHex(actual).c_str() << "\n";
969
970 return expected == actual;
971}
972
Alec Mouridfad9002020-02-12 17:49:09 -0800973TEST_F(TimeStatsTest, globalStatsCallback) {
974 constexpr size_t TOTAL_FRAMES = 5;
975 constexpr size_t MISSED_FRAMES = 4;
976 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
977 constexpr size_t DISPLAY_EVENT_CONNECTIONS = 14;
978
979 mTimeStats->onBootFinished();
980 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
981
982 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
983 mTimeStats->incrementTotalFrames();
984 }
985 for (size_t i = 0; i < MISSED_FRAMES; i++) {
986 mTimeStats->incrementMissedFrames();
987 }
988 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
989 mTimeStats->incrementClientCompositionFrames();
990 }
991
Alec Mouri9a29e672020-09-14 12:39:14 -0700992 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
993
Alec Mouridfad9002020-02-12 17:49:09 -0800994 mTimeStats->recordDisplayEventConnectionCount(DISPLAY_EVENT_CONNECTIONS);
Peiyong Lin65248e02020-04-18 21:15:07 -0700995 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouridfad9002020-02-12 17:49:09 -0800996 mTimeStats->recordFrameDuration(1000000, 3000000);
997 mTimeStats->recordRenderEngineDuration(2000000, 4000000);
998 mTimeStats->recordRenderEngineDuration(2000000, std::make_shared<FenceTime>(3000000));
999
1000 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
1001 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
1002
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001003 mTimeStats->incrementJankyFrames(JankType::SurfaceFlingerCpuDeadlineMissed);
Jorim Jaggi5814ab82020-12-03 20:45:58 +01001004 mTimeStats->incrementJankyFrames(JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001005 mTimeStats->incrementJankyFrames(JankType::DisplayHAL);
Jorim Jaggi5814ab82020-12-03 20:45:58 +01001006 mTimeStats->incrementJankyFrames(JankType::AppDeadlineMissed);
1007 mTimeStats->incrementJankyFrames(JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -07001008
Alec Mouridfad9002020-02-12 17:49:09 -08001009 EXPECT_THAT(mDelegate->mAtomTags,
1010 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1011 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1012 EXPECT_NE(nullptr, mDelegate->mCallback);
1013 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1014
1015 std::string expectedFrameDuration = buildExpectedHistogramBytestring({2}, {1});
1016 std::string expectedRenderEngineTiming = buildExpectedHistogramBytestring({1, 2}, {1, 1});
Alec Mouri75de8f22021-01-20 14:53:44 -08001017 std::string expectedEmptyHistogram = buildExpectedHistogramBytestring({}, {});
Alec Mouridfad9002020-02-12 17:49:09 -08001018
1019 {
1020 InSequence seq;
1021 EXPECT_CALL(*mDelegate,
1022 statsEventSetAtomId(mDelegate->mEvent,
1023 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
1024 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, TOTAL_FRAMES));
1025 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, MISSED_FRAMES));
1026 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, CLIENT_COMPOSITION_FRAMES));
1027 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, _));
1028 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 2));
1029 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, DISPLAY_EVENT_CONNECTIONS));
1030 EXPECT_CALL(*mDelegate,
1031 statsEventWriteByteArray(mDelegate->mEvent,
1032 BytesEq((const uint8_t*)expectedFrameDuration.c_str(),
1033 expectedFrameDuration.size()),
1034 expectedFrameDuration.size()));
1035 EXPECT_CALL(*mDelegate,
1036 statsEventWriteByteArray(mDelegate->mEvent,
1037 BytesEq((const uint8_t*)
1038 expectedRenderEngineTiming.c_str(),
1039 expectedRenderEngineTiming.size()),
1040 expectedRenderEngineTiming.size()));
Alec Mouri9a29e672020-09-14 12:39:14 -07001041 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 5));
1042 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 4));
1043 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1044 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1045 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1046 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
Alec Mouri75de8f22021-01-20 14:53:44 -08001047 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 0));
1048 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 0));
1049 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 0));
1050 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 0));
1051 EXPECT_CALL(*mDelegate,
1052 statsEventWriteByteArray(mDelegate->mEvent,
1053 BytesEq((const uint8_t*)expectedEmptyHistogram.c_str(),
1054 expectedEmptyHistogram.size()),
1055 expectedEmptyHistogram.size()));
1056 EXPECT_CALL(*mDelegate,
1057 statsEventWriteByteArray(mDelegate->mEvent,
1058 BytesEq((const uint8_t*)expectedEmptyHistogram.c_str(),
1059 expectedEmptyHistogram.size()),
1060 expectedEmptyHistogram.size()));
1061 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 0));
1062
Alec Mouridfad9002020-02-12 17:49:09 -08001063 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
1064 }
1065 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
1066 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1067 mDelegate->mCookie));
1068
1069 SFTimeStatsGlobalProto globalProto;
1070 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
1071
1072 EXPECT_EQ(0, globalProto.total_frames());
1073 EXPECT_EQ(0, globalProto.missed_frames());
1074 EXPECT_EQ(0, globalProto.client_composition_frames());
1075 EXPECT_EQ(0, globalProto.present_to_present_size());
1076}
1077
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001078TEST_F(TimeStatsTest, layerStatsCallback_pullsAllAndClears) {
1079 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
1080 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 3;
Alec Mouri37384342020-01-02 17:23:37 -08001081 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1082
1083 mTimeStats->onBootFinished();
1084
1085 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001086 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
1087 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
1088 }
1089 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
1090 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
1091 }
Alec Mouri37384342020-01-02 17:23:37 -08001092 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1093
Alec Mouri9a29e672020-09-14 12:39:14 -07001094 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001095 JankType::SurfaceFlingerCpuDeadlineMissed);
Alec Mouri9a29e672020-09-14 12:39:14 -07001096 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +01001097 JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001098 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::DisplayHAL);
Alec Mouri9a29e672020-09-14 12:39:14 -07001099 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +01001100 JankType::AppDeadlineMissed);
1101 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -07001102
Alec Mouri37384342020-01-02 17:23:37 -08001103 EXPECT_THAT(mDelegate->mAtomTags,
1104 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1105 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1106 EXPECT_NE(nullptr, mDelegate->mCallback);
1107 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1108
1109 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {1});
1110 std::string expectedPostToPresent = buildExpectedHistogramBytestring({4}, {1});
1111 std::string expectedAcquireToPresent = buildExpectedHistogramBytestring({3}, {1});
1112 std::string expectedLatchToPresent = buildExpectedHistogramBytestring({2}, {1});
1113 std::string expectedDesiredToPresent = buildExpectedHistogramBytestring({1}, {1});
1114 std::string expectedPostToAcquire = buildExpectedHistogramBytestring({1}, {1});
Alec Mouri75de8f22021-01-20 14:53:44 -08001115 std::string expectedFrameRateOverride = frameRateVoteToProtoByteString(0.0, 0, 0);
1116 std::string expectedEmptyHistogram = buildExpectedHistogramBytestring({}, {});
Alec Mouri37384342020-01-02 17:23:37 -08001117 {
1118 InSequence seq;
1119 EXPECT_CALL(*mDelegate,
1120 statsEventSetAtomId(mDelegate->mEvent,
1121 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1122 EXPECT_CALL(*mDelegate,
1123 statsEventWriteString8(mDelegate->mEvent,
1124 StrEq(genLayerName(LAYER_ID_0).c_str())));
1125 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 1));
1126 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 0));
1127 EXPECT_CALL(*mDelegate,
1128 statsEventWriteByteArray(mDelegate->mEvent,
1129 BytesEq((const uint8_t*)
1130 expectedPresentToPresent.c_str(),
1131 expectedPresentToPresent.size()),
1132 expectedPresentToPresent.size()));
1133 EXPECT_CALL(*mDelegate,
1134 statsEventWriteByteArray(mDelegate->mEvent,
1135 BytesEq((const uint8_t*)expectedPostToPresent.c_str(),
1136 expectedPostToPresent.size()),
1137 expectedPostToPresent.size()));
1138 EXPECT_CALL(*mDelegate,
1139 statsEventWriteByteArray(mDelegate->mEvent,
1140 BytesEq((const uint8_t*)
1141 expectedAcquireToPresent.c_str(),
1142 expectedAcquireToPresent.size()),
1143 expectedAcquireToPresent.size()));
1144 EXPECT_CALL(*mDelegate,
1145 statsEventWriteByteArray(mDelegate->mEvent,
1146 BytesEq((const uint8_t*)expectedLatchToPresent.c_str(),
1147 expectedLatchToPresent.size()),
1148 expectedLatchToPresent.size()));
1149 EXPECT_CALL(*mDelegate,
1150 statsEventWriteByteArray(mDelegate->mEvent,
1151 BytesEq((const uint8_t*)
1152 expectedDesiredToPresent.c_str(),
1153 expectedDesiredToPresent.size()),
1154 expectedDesiredToPresent.size()));
1155 EXPECT_CALL(*mDelegate,
1156 statsEventWriteByteArray(mDelegate->mEvent,
1157 BytesEq((const uint8_t*)expectedPostToAcquire.c_str(),
1158 expectedPostToAcquire.size()),
1159 expectedPostToAcquire.size()));
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001160 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, LATE_ACQUIRE_FRAMES));
1161 EXPECT_CALL(*mDelegate,
1162 statsEventWriteInt64(mDelegate->mEvent, BAD_DESIRED_PRESENT_FRAMES));
Alec Mouri9a29e672020-09-14 12:39:14 -07001163 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, UID_0));
1164 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 5));
1165 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 4));
1166 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1167 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1168 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1169 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
Alec Mouri75de8f22021-01-20 14:53:44 -08001170 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 0));
1171 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 0));
1172 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 0));
1173 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 0));
1174 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 0));
1175 EXPECT_CALL(*mDelegate,
1176 statsEventWriteByteArray(mDelegate->mEvent,
1177 BytesEq((const uint8_t*)
1178 expectedFrameRateOverride.c_str(),
1179 expectedFrameRateOverride.size()),
1180 expectedFrameRateOverride.size()));
1181 EXPECT_CALL(*mDelegate,
1182 statsEventWriteByteArray(mDelegate->mEvent,
1183 BytesEq((const uint8_t*)expectedEmptyHistogram.c_str(),
1184 expectedEmptyHistogram.size()),
1185 expectedEmptyHistogram.size()));
Alec Mouri9a29e672020-09-14 12:39:14 -07001186
Alec Mouri37384342020-01-02 17:23:37 -08001187 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
1188 }
Tej Singh2a457b62020-01-31 16:16:10 -08001189 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001190 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1191 mDelegate->mCookie));
1192
1193 SFTimeStatsGlobalProto globalProto;
1194 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
1195
1196 EXPECT_EQ(0, globalProto.stats_size());
1197}
1198
1199TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleLayers) {
1200 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1201
1202 mTimeStats->onBootFinished();
1203
1204 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1205 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1206 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1207 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1208
1209 EXPECT_THAT(mDelegate->mAtomTags,
1210 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1211 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1212 EXPECT_NE(nullptr, mDelegate->mCallback);
1213 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1214
1215 EXPECT_CALL(*mDelegate,
1216 statsEventSetAtomId(mDelegate->mEvent,
1217 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1218 .Times(2);
1219 EXPECT_CALL(*mDelegate,
1220 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_0).c_str())));
1221 EXPECT_CALL(*mDelegate,
1222 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001223 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001224 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1225 mDelegate->mCookie));
1226}
1227
1228TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleBuckets) {
1229 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1230
1231 mTimeStats->onBootFinished();
1232
1233 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1234 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1235 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1236 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1237
Tej Singh38a4b212020-03-13 19:04:51 -07001238 // Now make sure that TimeStats flushes global stats to set the callback.
Peiyong Lin65248e02020-04-18 21:15:07 -07001239 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouri37384342020-01-02 17:23:37 -08001240 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
1241 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
1242 EXPECT_THAT(mDelegate->mAtomTags,
1243 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1244 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1245 EXPECT_NE(nullptr, mDelegate->mCallback);
1246 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1247
1248 EXPECT_THAT(mDelegate->mAtomTags,
1249 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1250 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1251 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1, 2}, {2, 1});
1252 {
1253 InSequence seq;
1254 EXPECT_CALL(*mDelegate,
1255 statsEventWriteByteArray(mDelegate->mEvent,
1256 BytesEq((const uint8_t*)
1257 expectedPresentToPresent.c_str(),
1258 expectedPresentToPresent.size()),
1259 expectedPresentToPresent.size()));
1260 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1261 .Times(AnyNumber());
1262 }
Tej Singh2a457b62020-01-31 16:16:10 -08001263 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001264 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1265 mDelegate->mCookie));
1266}
1267
1268TEST_F(TimeStatsTest, layerStatsCallback_limitsHistogramBuckets) {
1269 mDelegate = new FakeStatsEventDelegate;
1270 mTimeStats =
1271 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
1272 std::nullopt, 1);
1273 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1274
1275 mTimeStats->onBootFinished();
1276
1277 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1278 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1279 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1280 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1281
1282 EXPECT_THAT(mDelegate->mAtomTags,
1283 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1284 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1285 EXPECT_NE(nullptr, mDelegate->mCallback);
1286 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1287
1288 EXPECT_THAT(mDelegate->mAtomTags,
1289 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1290 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1291 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {2});
1292 {
1293 InSequence seq;
1294 EXPECT_CALL(*mDelegate,
1295 statsEventWriteByteArray(mDelegate->mEvent,
1296 BytesEq((const uint8_t*)
1297 expectedPresentToPresent.c_str(),
1298 expectedPresentToPresent.size()),
1299 expectedPresentToPresent.size()));
1300 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1301 .Times(AnyNumber());
1302 }
Tej Singh2a457b62020-01-31 16:16:10 -08001303 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001304 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1305 mDelegate->mCookie));
1306}
1307
1308TEST_F(TimeStatsTest, layerStatsCallback_limitsLayers) {
1309 mDelegate = new FakeStatsEventDelegate;
1310 mTimeStats =
1311 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate), 1,
1312 std::nullopt);
1313 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1314
1315 mTimeStats->onBootFinished();
1316
1317 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1318 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1319 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1320 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1321 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 4, 5000000);
1322
1323 EXPECT_THAT(mDelegate->mAtomTags,
1324 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1325 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1326 EXPECT_NE(nullptr, mDelegate->mCallback);
1327 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1328
1329 EXPECT_CALL(*mDelegate,
1330 statsEventSetAtomId(mDelegate->mEvent,
1331 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1332 .Times(1);
1333 EXPECT_CALL(*mDelegate,
1334 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001335 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001336 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1337 mDelegate->mCookie));
1338}
1339
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001340TEST_F(TimeStatsTest, canSurviveMonkey) {
Lloyd Pique067fe1e2018-12-06 19:44:13 -08001341 if (g_noSlowTests) {
1342 GTEST_SKIP();
1343 }
1344
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001345 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1346
1347 for (size_t i = 0; i < 10000000; ++i) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001348 const int32_t layerId = genRandomInt32(-1, 10);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001349 const int32_t frameNumber = genRandomInt32(1, 10);
1350 switch (genRandomInt32(0, 100)) {
1351 case 0:
1352 ALOGV("removeTimeRecord");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001353 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(layerId, frameNumber));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001354 continue;
1355 case 1:
1356 ALOGV("onDestroy");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001357 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(layerId));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001358 continue;
1359 }
1360 TimeStamp type = static_cast<TimeStamp>(genRandomInt32(TIME_STAMP_BEGIN, TIME_STAMP_END));
1361 const int32_t ts = genRandomInt32(1, 1000000000);
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001362 ALOGV("type[%d], layerId[%d], frameNumber[%d], ts[%d]", type, layerId, frameNumber, ts);
1363 setTimeStamp(type, layerId, frameNumber, ts);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001364 }
1365}
1366
1367} // namespace
1368} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -08001369
1370// TODO(b/129481165): remove the #pragma below and fix conversion issues
Marin Shalamanovbed7fd32020-12-21 20:02:20 +01001371#pragma clang diagnostic pop // ignored "-Wconversion -Wextra"