blob: fb9afd404555ea4fb73806f942826be4c531cb8d [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
935std::string dumpByteStringHex(const std::string& str) {
936 std::stringstream ss;
937 ss << std::hex;
938 for (const char& c : str) {
939 ss << (int)c << " ";
940 }
941
942 return ss.str();
943}
944
945} // namespace
946
947MATCHER_P2(BytesEq, bytes, size, "") {
948 std::string expected;
949 expected.append((const char*)bytes, size);
950 std::string actual;
951 actual.append((const char*)arg, size);
952
953 *result_listener << "Bytes are not equal! \n";
954 *result_listener << "size: " << size << "\n";
955 *result_listener << "expected: " << dumpByteStringHex(expected).c_str() << "\n";
956 *result_listener << "actual: " << dumpByteStringHex(actual).c_str() << "\n";
957
958 return expected == actual;
959}
960
Alec Mouridfad9002020-02-12 17:49:09 -0800961TEST_F(TimeStatsTest, globalStatsCallback) {
962 constexpr size_t TOTAL_FRAMES = 5;
963 constexpr size_t MISSED_FRAMES = 4;
964 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
965 constexpr size_t DISPLAY_EVENT_CONNECTIONS = 14;
966
967 mTimeStats->onBootFinished();
968 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
969
970 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
971 mTimeStats->incrementTotalFrames();
972 }
973 for (size_t i = 0; i < MISSED_FRAMES; i++) {
974 mTimeStats->incrementMissedFrames();
975 }
976 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
977 mTimeStats->incrementClientCompositionFrames();
978 }
979
Alec Mouri9a29e672020-09-14 12:39:14 -0700980 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
981
Alec Mouridfad9002020-02-12 17:49:09 -0800982 mTimeStats->recordDisplayEventConnectionCount(DISPLAY_EVENT_CONNECTIONS);
Peiyong Lin65248e02020-04-18 21:15:07 -0700983 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouridfad9002020-02-12 17:49:09 -0800984 mTimeStats->recordFrameDuration(1000000, 3000000);
985 mTimeStats->recordRenderEngineDuration(2000000, 4000000);
986 mTimeStats->recordRenderEngineDuration(2000000, std::make_shared<FenceTime>(3000000));
987
988 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
989 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
990
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800991 mTimeStats->incrementJankyFrames(JankType::SurfaceFlingerCpuDeadlineMissed);
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100992 mTimeStats->incrementJankyFrames(JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800993 mTimeStats->incrementJankyFrames(JankType::DisplayHAL);
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100994 mTimeStats->incrementJankyFrames(JankType::AppDeadlineMissed);
995 mTimeStats->incrementJankyFrames(JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -0700996
Alec Mouridfad9002020-02-12 17:49:09 -0800997 EXPECT_THAT(mDelegate->mAtomTags,
998 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
999 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1000 EXPECT_NE(nullptr, mDelegate->mCallback);
1001 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1002
1003 std::string expectedFrameDuration = buildExpectedHistogramBytestring({2}, {1});
1004 std::string expectedRenderEngineTiming = buildExpectedHistogramBytestring({1, 2}, {1, 1});
1005
1006 {
1007 InSequence seq;
1008 EXPECT_CALL(*mDelegate,
1009 statsEventSetAtomId(mDelegate->mEvent,
1010 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
1011 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, TOTAL_FRAMES));
1012 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, MISSED_FRAMES));
1013 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, CLIENT_COMPOSITION_FRAMES));
1014 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, _));
1015 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 2));
1016 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, DISPLAY_EVENT_CONNECTIONS));
1017 EXPECT_CALL(*mDelegate,
1018 statsEventWriteByteArray(mDelegate->mEvent,
1019 BytesEq((const uint8_t*)expectedFrameDuration.c_str(),
1020 expectedFrameDuration.size()),
1021 expectedFrameDuration.size()));
1022 EXPECT_CALL(*mDelegate,
1023 statsEventWriteByteArray(mDelegate->mEvent,
1024 BytesEq((const uint8_t*)
1025 expectedRenderEngineTiming.c_str(),
1026 expectedRenderEngineTiming.size()),
1027 expectedRenderEngineTiming.size()));
Alec Mouri9a29e672020-09-14 12:39:14 -07001028 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 5));
1029 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 4));
1030 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1031 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1032 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1033 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
Alec Mouridfad9002020-02-12 17:49:09 -08001034 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
1035 }
1036 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
1037 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1038 mDelegate->mCookie));
1039
1040 SFTimeStatsGlobalProto globalProto;
1041 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
1042
1043 EXPECT_EQ(0, globalProto.total_frames());
1044 EXPECT_EQ(0, globalProto.missed_frames());
1045 EXPECT_EQ(0, globalProto.client_composition_frames());
1046 EXPECT_EQ(0, globalProto.present_to_present_size());
1047}
1048
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001049TEST_F(TimeStatsTest, layerStatsCallback_pullsAllAndClears) {
1050 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
1051 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 3;
Alec Mouri37384342020-01-02 17:23:37 -08001052 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1053
1054 mTimeStats->onBootFinished();
1055
1056 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001057 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
1058 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
1059 }
1060 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
1061 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
1062 }
Alec Mouri37384342020-01-02 17:23:37 -08001063 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1064
Alec Mouri9a29e672020-09-14 12:39:14 -07001065 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001066 JankType::SurfaceFlingerCpuDeadlineMissed);
Alec Mouri9a29e672020-09-14 12:39:14 -07001067 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +01001068 JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001069 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::DisplayHAL);
Alec Mouri9a29e672020-09-14 12:39:14 -07001070 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +01001071 JankType::AppDeadlineMissed);
1072 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -07001073
Alec Mouri37384342020-01-02 17:23:37 -08001074 EXPECT_THAT(mDelegate->mAtomTags,
1075 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1076 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1077 EXPECT_NE(nullptr, mDelegate->mCallback);
1078 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1079
1080 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {1});
1081 std::string expectedPostToPresent = buildExpectedHistogramBytestring({4}, {1});
1082 std::string expectedAcquireToPresent = buildExpectedHistogramBytestring({3}, {1});
1083 std::string expectedLatchToPresent = buildExpectedHistogramBytestring({2}, {1});
1084 std::string expectedDesiredToPresent = buildExpectedHistogramBytestring({1}, {1});
1085 std::string expectedPostToAcquire = buildExpectedHistogramBytestring({1}, {1});
1086 {
1087 InSequence seq;
1088 EXPECT_CALL(*mDelegate,
1089 statsEventSetAtomId(mDelegate->mEvent,
1090 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1091 EXPECT_CALL(*mDelegate,
1092 statsEventWriteString8(mDelegate->mEvent,
1093 StrEq(genLayerName(LAYER_ID_0).c_str())));
1094 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 1));
1095 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 0));
1096 EXPECT_CALL(*mDelegate,
1097 statsEventWriteByteArray(mDelegate->mEvent,
1098 BytesEq((const uint8_t*)
1099 expectedPresentToPresent.c_str(),
1100 expectedPresentToPresent.size()),
1101 expectedPresentToPresent.size()));
1102 EXPECT_CALL(*mDelegate,
1103 statsEventWriteByteArray(mDelegate->mEvent,
1104 BytesEq((const uint8_t*)expectedPostToPresent.c_str(),
1105 expectedPostToPresent.size()),
1106 expectedPostToPresent.size()));
1107 EXPECT_CALL(*mDelegate,
1108 statsEventWriteByteArray(mDelegate->mEvent,
1109 BytesEq((const uint8_t*)
1110 expectedAcquireToPresent.c_str(),
1111 expectedAcquireToPresent.size()),
1112 expectedAcquireToPresent.size()));
1113 EXPECT_CALL(*mDelegate,
1114 statsEventWriteByteArray(mDelegate->mEvent,
1115 BytesEq((const uint8_t*)expectedLatchToPresent.c_str(),
1116 expectedLatchToPresent.size()),
1117 expectedLatchToPresent.size()));
1118 EXPECT_CALL(*mDelegate,
1119 statsEventWriteByteArray(mDelegate->mEvent,
1120 BytesEq((const uint8_t*)
1121 expectedDesiredToPresent.c_str(),
1122 expectedDesiredToPresent.size()),
1123 expectedDesiredToPresent.size()));
1124 EXPECT_CALL(*mDelegate,
1125 statsEventWriteByteArray(mDelegate->mEvent,
1126 BytesEq((const uint8_t*)expectedPostToAcquire.c_str(),
1127 expectedPostToAcquire.size()),
1128 expectedPostToAcquire.size()));
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001129 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, LATE_ACQUIRE_FRAMES));
1130 EXPECT_CALL(*mDelegate,
1131 statsEventWriteInt64(mDelegate->mEvent, BAD_DESIRED_PRESENT_FRAMES));
Alec Mouri9a29e672020-09-14 12:39:14 -07001132 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, UID_0));
1133 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 5));
1134 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 4));
1135 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1136 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1137 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1138 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1139
Alec Mouri37384342020-01-02 17:23:37 -08001140 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
1141 }
Tej Singh2a457b62020-01-31 16:16:10 -08001142 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001143 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1144 mDelegate->mCookie));
1145
1146 SFTimeStatsGlobalProto globalProto;
1147 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
1148
1149 EXPECT_EQ(0, globalProto.stats_size());
1150}
1151
1152TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleLayers) {
1153 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1154
1155 mTimeStats->onBootFinished();
1156
1157 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1158 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1159 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1160 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1161
1162 EXPECT_THAT(mDelegate->mAtomTags,
1163 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1164 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1165 EXPECT_NE(nullptr, mDelegate->mCallback);
1166 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1167
1168 EXPECT_CALL(*mDelegate,
1169 statsEventSetAtomId(mDelegate->mEvent,
1170 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1171 .Times(2);
1172 EXPECT_CALL(*mDelegate,
1173 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_0).c_str())));
1174 EXPECT_CALL(*mDelegate,
1175 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001176 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001177 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1178 mDelegate->mCookie));
1179}
1180
1181TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleBuckets) {
1182 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1183
1184 mTimeStats->onBootFinished();
1185
1186 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1187 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1188 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1189 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1190
Tej Singh38a4b212020-03-13 19:04:51 -07001191 // Now make sure that TimeStats flushes global stats to set the callback.
Peiyong Lin65248e02020-04-18 21:15:07 -07001192 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouri37384342020-01-02 17:23:37 -08001193 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
1194 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
1195 EXPECT_THAT(mDelegate->mAtomTags,
1196 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1197 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1198 EXPECT_NE(nullptr, mDelegate->mCallback);
1199 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1200
1201 EXPECT_THAT(mDelegate->mAtomTags,
1202 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1203 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1204 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1, 2}, {2, 1});
1205 {
1206 InSequence seq;
1207 EXPECT_CALL(*mDelegate,
1208 statsEventWriteByteArray(mDelegate->mEvent,
1209 BytesEq((const uint8_t*)
1210 expectedPresentToPresent.c_str(),
1211 expectedPresentToPresent.size()),
1212 expectedPresentToPresent.size()));
1213 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1214 .Times(AnyNumber());
1215 }
Tej Singh2a457b62020-01-31 16:16:10 -08001216 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001217 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1218 mDelegate->mCookie));
1219}
1220
1221TEST_F(TimeStatsTest, layerStatsCallback_limitsHistogramBuckets) {
1222 mDelegate = new FakeStatsEventDelegate;
1223 mTimeStats =
1224 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
1225 std::nullopt, 1);
1226 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1227
1228 mTimeStats->onBootFinished();
1229
1230 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1231 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1232 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1233 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1234
1235 EXPECT_THAT(mDelegate->mAtomTags,
1236 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1237 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1238 EXPECT_NE(nullptr, mDelegate->mCallback);
1239 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1240
1241 EXPECT_THAT(mDelegate->mAtomTags,
1242 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1243 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1244 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {2});
1245 {
1246 InSequence seq;
1247 EXPECT_CALL(*mDelegate,
1248 statsEventWriteByteArray(mDelegate->mEvent,
1249 BytesEq((const uint8_t*)
1250 expectedPresentToPresent.c_str(),
1251 expectedPresentToPresent.size()),
1252 expectedPresentToPresent.size()));
1253 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1254 .Times(AnyNumber());
1255 }
Tej Singh2a457b62020-01-31 16:16:10 -08001256 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001257 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1258 mDelegate->mCookie));
1259}
1260
1261TEST_F(TimeStatsTest, layerStatsCallback_limitsLayers) {
1262 mDelegate = new FakeStatsEventDelegate;
1263 mTimeStats =
1264 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate), 1,
1265 std::nullopt);
1266 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1267
1268 mTimeStats->onBootFinished();
1269
1270 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1271 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1272 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1273 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1274 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 4, 5000000);
1275
1276 EXPECT_THAT(mDelegate->mAtomTags,
1277 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1278 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1279 EXPECT_NE(nullptr, mDelegate->mCallback);
1280 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1281
1282 EXPECT_CALL(*mDelegate,
1283 statsEventSetAtomId(mDelegate->mEvent,
1284 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1285 .Times(1);
1286 EXPECT_CALL(*mDelegate,
1287 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001288 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001289 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1290 mDelegate->mCookie));
1291}
1292
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001293TEST_F(TimeStatsTest, canSurviveMonkey) {
Lloyd Pique067fe1e2018-12-06 19:44:13 -08001294 if (g_noSlowTests) {
1295 GTEST_SKIP();
1296 }
1297
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001298 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1299
1300 for (size_t i = 0; i < 10000000; ++i) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001301 const int32_t layerId = genRandomInt32(-1, 10);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001302 const int32_t frameNumber = genRandomInt32(1, 10);
1303 switch (genRandomInt32(0, 100)) {
1304 case 0:
1305 ALOGV("removeTimeRecord");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001306 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(layerId, frameNumber));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001307 continue;
1308 case 1:
1309 ALOGV("onDestroy");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001310 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(layerId));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001311 continue;
1312 }
1313 TimeStamp type = static_cast<TimeStamp>(genRandomInt32(TIME_STAMP_BEGIN, TIME_STAMP_END));
1314 const int32_t ts = genRandomInt32(1, 1000000000);
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001315 ALOGV("type[%d], layerId[%d], frameNumber[%d], ts[%d]", type, layerId, frameNumber, ts);
1316 setTimeStamp(type, layerId, frameNumber, ts);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001317 }
1318}
1319
1320} // namespace
1321} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -08001322
1323// TODO(b/129481165): remove the #pragma below and fix conversion issues
Marin Shalamanovbed7fd32020-12-21 20:02:20 +01001324#pragma clang diagnostic pop // ignored "-Wconversion -Wextra"