blob: b1d5b165d7496671e8cb6f37fbd5efc787850ee2 [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"
20
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080021#undef LOG_TAG
22#define LOG_TAG "LibSurfaceFlingerUnittests"
23
Mikael Pessa2e1608f2019-07-19 11:25:35 -070024#include <TimeStats/TimeStats.h>
Alec Mouri37384342020-01-02 17:23:37 -080025#include <android/util/ProtoOutputStream.h>
Alec Mourifb571ea2019-01-24 18:42:10 -080026#include <gmock/gmock.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080027#include <gtest/gtest.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080028#include <log/log.h>
29#include <utils/String16.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080030#include <utils/Vector.h>
31
Alec Mouri9519bf12019-11-15 16:54:44 -080032#include <chrono>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080033#include <random>
Alec Mourifb571ea2019-01-24 18:42:10 -080034#include <unordered_set>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080035
Lloyd Pique067fe1e2018-12-06 19:44:13 -080036#include "libsurfaceflinger_unittest_main.h"
37
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080038using namespace android::surfaceflinger;
39using namespace google::protobuf;
Vishnu Nairabf97fd2020-02-03 13:51:16 -080040using namespace std::chrono_literals;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080041
42namespace android {
43namespace {
44
Alec Mouri8e2f31b2020-01-16 22:04:35 +000045using testing::_;
Alec Mouri37384342020-01-02 17:23:37 -080046using testing::AnyNumber;
Alec Mourifb571ea2019-01-24 18:42:10 -080047using testing::Contains;
Vishnu Nair9b079a22020-01-21 14:36:08 -080048using testing::HasSubstr;
Alec Mouri8e2f31b2020-01-16 22:04:35 +000049using testing::InSequence;
Alec Mourifb571ea2019-01-24 18:42:10 -080050using testing::SizeIs;
Alec Mouri37384342020-01-02 17:23:37 -080051using testing::StrEq;
Alec Mourifb571ea2019-01-24 18:42:10 -080052using testing::UnorderedElementsAre;
53
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080054// clang-format off
55#define FMT_PROTO true
56#define FMT_STRING false
57#define LAYER_ID_0 0
58#define LAYER_ID_1 1
59#define LAYER_ID_INVALID -1
60#define NUM_LAYERS 1
61#define NUM_LAYERS_INVALID "INVALID"
62
63enum InputCommand : int32_t {
64 ENABLE = 0,
65 DISABLE = 1,
66 CLEAR = 2,
67 DUMP_ALL = 3,
68 DUMP_MAXLAYERS_1 = 4,
69 DUMP_MAXLAYERS_INVALID = 5,
70 INPUT_COMMAND_BEGIN = ENABLE,
71 INPUT_COMMAND_END = DUMP_MAXLAYERS_INVALID,
72 INPUT_COMMAND_RANGE = INPUT_COMMAND_END - INPUT_COMMAND_BEGIN + 1,
73};
74
75enum TimeStamp : int32_t {
76 POST = 0,
77 ACQUIRE = 1,
78 ACQUIRE_FENCE = 2,
79 LATCH = 3,
80 DESIRED = 4,
81 PRESENT = 5,
82 PRESENT_FENCE = 6,
83 TIME_STAMP_BEGIN = POST,
84 TIME_STAMP_END = PRESENT,
85 TIME_STAMP_RANGE = TIME_STAMP_END - TIME_STAMP_BEGIN + 1,
86};
87
88static const TimeStamp NORMAL_SEQUENCE[] = {
89 TimeStamp::POST,
90 TimeStamp::ACQUIRE,
91 TimeStamp::LATCH,
92 TimeStamp::DESIRED,
93 TimeStamp::PRESENT,
94};
95
96static const TimeStamp NORMAL_SEQUENCE_2[] = {
97 TimeStamp::POST,
98 TimeStamp::ACQUIRE_FENCE,
99 TimeStamp::LATCH,
100 TimeStamp::DESIRED,
101 TimeStamp::PRESENT_FENCE,
102};
103
104static const TimeStamp UNORDERED_SEQUENCE[] = {
105 TimeStamp::ACQUIRE,
106 TimeStamp::LATCH,
107 TimeStamp::POST,
108 TimeStamp::DESIRED,
109 TimeStamp::PRESENT,
110};
111
112static const TimeStamp INCOMPLETE_SEQUENCE[] = {
113 TimeStamp::POST,
114};
115// clang-format on
116
117class TimeStatsTest : public testing::Test {
118public:
119 TimeStatsTest() {
120 const ::testing::TestInfo* const test_info =
121 ::testing::UnitTest::GetInstance()->current_test_info();
122 ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
123 }
124
125 ~TimeStatsTest() {
126 const ::testing::TestInfo* const test_info =
127 ::testing::UnitTest::GetInstance()->current_test_info();
128 ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
129 }
130
131 std::string inputCommand(InputCommand cmd, bool useProto);
132
133 void setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts);
134
135 int32_t genRandomInt32(int32_t begin, int32_t end);
136
137 template <size_t N>
138 void insertTimeRecord(const TimeStamp (&sequence)[N], int32_t id, uint64_t frameNumber,
139 nsecs_t ts) {
140 for (size_t i = 0; i < N; i++, ts += 1000000) {
141 setTimeStamp(sequence[i], id, frameNumber, ts);
142 }
143 }
144
145 std::mt19937 mRandomEngine = std::mt19937(std::random_device()());
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000146
147 class FakeStatsEventDelegate : public impl::TimeStats::StatsEventDelegate {
148 public:
149 FakeStatsEventDelegate() = default;
150 ~FakeStatsEventDelegate() override = default;
151
Tej Singh2a457b62020-01-31 16:16:10 -0800152 struct AStatsEvent* addStatsEventToPullData(AStatsEventList*) override {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000153 return mEvent;
154 }
Tej Singh2a457b62020-01-31 16:16:10 -0800155 void registerStatsPullAtomCallback(int32_t atom_tag,
156 AStatsManager_PullAtomCallback callback,
157 AStatsManager_PullAtomMetadata*, void* cookie) override {
Alec Mouri37384342020-01-02 17:23:37 -0800158 mAtomTags.push_back(atom_tag);
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000159 mCallback = callback;
160 mCookie = cookie;
161 }
162
Tej Singh2a457b62020-01-31 16:16:10 -0800163 AStatsManager_PullAtomCallbackReturn makePullAtomCallback(int32_t atom_tag, void* cookie) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000164 return (*mCallback)(atom_tag, nullptr, cookie);
165 }
166
167 MOCK_METHOD1(unregisterStatsPullAtomCallback, void(int32_t));
Tej Singh2a457b62020-01-31 16:16:10 -0800168 MOCK_METHOD2(statsEventSetAtomId, void(AStatsEvent*, uint32_t));
Alec Mouri717bcb62020-02-10 17:07:19 -0800169 MOCK_METHOD2(statsEventWriteInt32, void(AStatsEvent*, int32_t));
Tej Singh2a457b62020-01-31 16:16:10 -0800170 MOCK_METHOD2(statsEventWriteInt64, void(AStatsEvent*, int64_t));
171 MOCK_METHOD2(statsEventWriteString8, void(AStatsEvent*, const char*));
172 MOCK_METHOD3(statsEventWriteByteArray, void(AStatsEvent*, const uint8_t*, size_t));
173 MOCK_METHOD1(statsEventBuild, void(AStatsEvent*));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000174
Tej Singh2a457b62020-01-31 16:16:10 -0800175 AStatsEvent* mEvent = AStatsEvent_obtain();
Alec Mouri37384342020-01-02 17:23:37 -0800176 std::vector<int32_t> mAtomTags;
Tej Singh2a457b62020-01-31 16:16:10 -0800177 AStatsManager_PullAtomCallback mCallback = nullptr;
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000178 void* mCookie = nullptr;
179 };
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000180 FakeStatsEventDelegate* mDelegate = new FakeStatsEventDelegate;
181 std::unique_ptr<TimeStats> mTimeStats =
Alec Mouri37384342020-01-02 17:23:37 -0800182 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
183 std::nullopt, std::nullopt);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800184};
185
186std::string TimeStatsTest::inputCommand(InputCommand cmd, bool useProto) {
Yiwei Zhang5434a782018-12-05 18:06:32 -0800187 std::string result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800188 Vector<String16> args;
189
190 switch (cmd) {
191 case InputCommand::ENABLE:
192 args.push_back(String16("-enable"));
193 break;
194 case InputCommand::DISABLE:
195 args.push_back(String16("-disable"));
196 break;
197 case InputCommand::CLEAR:
198 args.push_back(String16("-clear"));
199 break;
200 case InputCommand::DUMP_ALL:
201 args.push_back(String16("-dump"));
202 break;
203 case InputCommand::DUMP_MAXLAYERS_1:
204 args.push_back(String16("-dump"));
205 args.push_back(String16("-maxlayers"));
206 args.push_back(String16(std::to_string(NUM_LAYERS).c_str()));
207 break;
208 case InputCommand::DUMP_MAXLAYERS_INVALID:
209 args.push_back(String16("-dump"));
210 args.push_back(String16("-maxlayers"));
211 args.push_back(String16(NUM_LAYERS_INVALID));
212 break;
213 default:
214 ALOGD("Invalid control command");
215 }
216
Dominik Laskowskic2867142019-01-21 11:33:38 -0800217 EXPECT_NO_FATAL_FAILURE(mTimeStats->parseArgs(useProto, args, result));
Yiwei Zhang5434a782018-12-05 18:06:32 -0800218 return result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800219}
220
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800221static std::string genLayerName(int32_t layerId) {
222 return (layerId < 0 ? "PopupWindow:b54fcd1#0" : "com.dummy#") + std::to_string(layerId);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800223}
224
225void TimeStatsTest::setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts) {
226 switch (type) {
227 case TimeStamp::POST:
228 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPostTime(id, frameNumber, genLayerName(id), ts));
229 break;
230 case TimeStamp::ACQUIRE:
231 ASSERT_NO_FATAL_FAILURE(mTimeStats->setAcquireTime(id, frameNumber, ts));
232 break;
233 case TimeStamp::ACQUIRE_FENCE:
234 ASSERT_NO_FATAL_FAILURE(
235 mTimeStats->setAcquireFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
236 break;
237 case TimeStamp::LATCH:
238 ASSERT_NO_FATAL_FAILURE(mTimeStats->setLatchTime(id, frameNumber, ts));
239 break;
240 case TimeStamp::DESIRED:
241 ASSERT_NO_FATAL_FAILURE(mTimeStats->setDesiredTime(id, frameNumber, ts));
242 break;
243 case TimeStamp::PRESENT:
244 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPresentTime(id, frameNumber, ts));
245 break;
246 case TimeStamp::PRESENT_FENCE:
247 ASSERT_NO_FATAL_FAILURE(
248 mTimeStats->setPresentFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
249 break;
250 default:
251 ALOGD("Invalid timestamp type");
252 }
253}
254
255int32_t TimeStatsTest::genRandomInt32(int32_t begin, int32_t end) {
256 std::uniform_int_distribution<int32_t> distr(begin, end);
257 return distr(mRandomEngine);
258}
259
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000260TEST_F(TimeStatsTest, disabledByDefault) {
261 ASSERT_FALSE(mTimeStats->isEnabled());
262}
263
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800264TEST_F(TimeStatsTest, registersCallbacksAfterBoot) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000265 mTimeStats->onBootFinished();
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800266 EXPECT_THAT(mDelegate->mAtomTags,
267 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
268 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
269}
270
271TEST_F(TimeStatsTest, unregistersCallbacksOnDestruction) {
272 EXPECT_CALL(*mDelegate,
273 unregisterStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
274 EXPECT_CALL(*mDelegate,
275 unregisterStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO));
276 mTimeStats.reset();
Alec Mourib3885ad2019-09-06 17:08:55 -0700277}
278
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800279TEST_F(TimeStatsTest, canEnableAndDisableTimeStats) {
280 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
281 ASSERT_TRUE(mTimeStats->isEnabled());
282
283 EXPECT_TRUE(inputCommand(InputCommand::DISABLE, FMT_STRING).empty());
284 ASSERT_FALSE(mTimeStats->isEnabled());
285}
286
287TEST_F(TimeStatsTest, canIncreaseGlobalStats) {
288 constexpr size_t TOTAL_FRAMES = 5;
289 constexpr size_t MISSED_FRAMES = 4;
290 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
291
292 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
293
294 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
295 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
296 }
297 for (size_t i = 0; i < MISSED_FRAMES; i++) {
298 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
299 }
300 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
301 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
302 }
303
304 SFTimeStatsGlobalProto globalProto;
305 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
306
307 ASSERT_TRUE(globalProto.has_total_frames());
308 EXPECT_EQ(TOTAL_FRAMES, globalProto.total_frames());
309 ASSERT_TRUE(globalProto.has_missed_frames());
310 EXPECT_EQ(MISSED_FRAMES, globalProto.missed_frames());
311 ASSERT_TRUE(globalProto.has_client_composition_frames());
312 EXPECT_EQ(CLIENT_COMPOSITION_FRAMES, globalProto.client_composition_frames());
313}
314
Alec Mouri91f6df32020-01-30 08:48:58 -0800315TEST_F(TimeStatsTest, canIncreaseLateAcquireFrames) {
316 // this stat is not in the proto so verify by checking the string dump
317 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
318
319 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
320
321 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
322 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
323 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
324 }
325 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
326
327 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
328 const std::string expectedResult = "lateAcquireFrames = " + std::to_string(LATE_ACQUIRE_FRAMES);
329 EXPECT_THAT(result, HasSubstr(expectedResult));
330}
331
332TEST_F(TimeStatsTest, canIncreaseBadDesiredPresent) {
333 // this stat is not in the proto so verify by checking the string dump
334 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 2;
335
336 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
337
338 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
339 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
340 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
341 }
342 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
343
344 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
345 const std::string expectedResult =
346 "badDesiredPresentFrames = " + std::to_string(BAD_DESIRED_PRESENT_FRAMES);
347 EXPECT_THAT(result, HasSubstr(expectedResult));
348}
349
Vishnu Nair9b079a22020-01-21 14:36:08 -0800350TEST_F(TimeStatsTest, canIncreaseClientCompositionReusedFrames) {
351 // this stat is not in the proto so verify by checking the string dump
352 constexpr size_t CLIENT_COMPOSITION_REUSED_FRAMES = 2;
353
354 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
355 for (size_t i = 0; i < CLIENT_COMPOSITION_REUSED_FRAMES; i++) {
356 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
357 }
358
359 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
360 const std::string expectedResult =
361 "clientCompositionReusedFrames = " + std::to_string(CLIENT_COMPOSITION_REUSED_FRAMES);
362 EXPECT_THAT(result, HasSubstr(expectedResult));
363}
364
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800365TEST_F(TimeStatsTest, canAverageFrameDuration) {
366 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
367 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
368 mTimeStats
369 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
370 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
371 .count());
372 mTimeStats
373 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
374 std::chrono::duration_cast<std::chrono::nanoseconds>(16ms)
375 .count());
376
377 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
378 EXPECT_THAT(result, HasSubstr("averageFrameDuration = 10.000 ms"));
379}
380
381TEST_F(TimeStatsTest, canAverageRenderEngineTimings) {
382 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
383 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms)
384 .count(),
385 std::make_shared<FenceTime>(
386 std::chrono::duration_cast<
387 std::chrono::nanoseconds>(3ms)
388 .count()));
389
390 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
391 .count(),
392 std::chrono::duration_cast<std::chrono::nanoseconds>(8ms)
393 .count());
394
395 // Push a dummy present fence to trigger flushing the RenderEngine timings.
396 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
397 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
398 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
399
400 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
401 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 3.000 ms"));
402}
403
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800404TEST_F(TimeStatsTest, canInsertGlobalPresentToPresent) {
405 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
406
407 ASSERT_NO_FATAL_FAILURE(
408 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
409 ASSERT_NO_FATAL_FAILURE(
410 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
411
412 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL));
413 ASSERT_NO_FATAL_FAILURE(
414 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000)));
415 ASSERT_NO_FATAL_FAILURE(
416 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000)));
417
418 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_OFF));
419 ASSERT_NO_FATAL_FAILURE(
420 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(6000000)));
421 ASSERT_NO_FATAL_FAILURE(
422 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(8000000)));
423
424 SFTimeStatsGlobalProto globalProto;
425 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
426
427 ASSERT_EQ(1, globalProto.present_to_present_size());
428 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.present_to_present().Get(0);
429 EXPECT_EQ(1, histogramProto.frame_count());
430 EXPECT_EQ(2, histogramProto.time_millis());
431}
432
Alec Mouri9519bf12019-11-15 16:54:44 -0800433TEST_F(TimeStatsTest, canInsertGlobalFrameDuration) {
434 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
435
Alec Mouri9519bf12019-11-15 16:54:44 -0800436 mTimeStats->setPowerMode(HWC_POWER_MODE_OFF);
437 mTimeStats
438 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
439 std::chrono::duration_cast<std::chrono::nanoseconds>(5ms)
440 .count());
441 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
442 mTimeStats
443 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
444 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
445 .count());
446
447 SFTimeStatsGlobalProto globalProto;
448 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
449
450 ASSERT_EQ(1, globalProto.frame_duration_size());
451 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.frame_duration().Get(0);
452 EXPECT_EQ(1, histogramProto.frame_count());
453 EXPECT_EQ(3, histogramProto.time_millis());
454}
455
Alec Mourie4034bb2019-11-19 12:45:54 -0800456TEST_F(TimeStatsTest, canInsertGlobalRenderEngineTiming) {
457 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
458
Alec Mourie4034bb2019-11-19 12:45:54 -0800459 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms)
460 .count(),
461 std::make_shared<FenceTime>(
462 std::chrono::duration_cast<
463 std::chrono::nanoseconds>(3ms)
464 .count()));
465
466 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
467 .count(),
468 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
469 .count());
470
471 // First verify that flushing RenderEngine durations did not occur yet.
472 SFTimeStatsGlobalProto preFlushProto;
473 ASSERT_TRUE(preFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
474 ASSERT_EQ(0, preFlushProto.render_engine_timing_size());
475
476 // Push a dummy present fence to trigger flushing the RenderEngine timings.
477 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
478 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
479 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
480
481 // Now we can verify that RenderEngine durations were flushed now.
482 SFTimeStatsGlobalProto postFlushProto;
483 ASSERT_TRUE(postFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
484
485 ASSERT_EQ(1, postFlushProto.render_engine_timing_size());
486 const SFTimeStatsHistogramBucketProto& histogramProto =
487 postFlushProto.render_engine_timing().Get(0);
488 EXPECT_EQ(2, histogramProto.frame_count());
489 EXPECT_EQ(2, histogramProto.time_millis());
490}
491
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800492TEST_F(TimeStatsTest, canInsertOneLayerTimeStats) {
493 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
494
495 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
496 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
497
498 SFTimeStatsGlobalProto globalProto;
499 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
500
501 ASSERT_EQ(1, globalProto.stats_size());
502 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
503 ASSERT_TRUE(layerProto.has_layer_name());
504 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
505 ASSERT_TRUE(layerProto.has_total_frames());
506 EXPECT_EQ(1, layerProto.total_frames());
507 ASSERT_EQ(6, layerProto.deltas_size());
508 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
509 ASSERT_EQ(1, deltaProto.histograms_size());
510 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
511 EXPECT_EQ(1, histogramProto.frame_count());
512 if ("post2acquire" == deltaProto.delta_name()) {
513 EXPECT_EQ(1, histogramProto.time_millis());
514 } else if ("post2present" == deltaProto.delta_name()) {
515 EXPECT_EQ(4, histogramProto.time_millis());
516 } else if ("acquire2present" == deltaProto.delta_name()) {
517 EXPECT_EQ(3, histogramProto.time_millis());
518 } else if ("latch2present" == deltaProto.delta_name()) {
519 EXPECT_EQ(2, histogramProto.time_millis());
520 } else if ("desired2present" == deltaProto.delta_name()) {
521 EXPECT_EQ(1, histogramProto.time_millis());
522 } else if ("present2present" == deltaProto.delta_name()) {
523 EXPECT_EQ(1, histogramProto.time_millis());
524 } else {
525 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
526 }
527 }
528}
529
530TEST_F(TimeStatsTest, canNotInsertInvalidLayerNameTimeStats) {
531 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
532
533 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_INVALID, 1, 1000000);
534 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_INVALID, 2, 2000000);
535
536 SFTimeStatsGlobalProto globalProto;
537 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
538
539 ASSERT_EQ(0, globalProto.stats_size());
540}
541
542TEST_F(TimeStatsTest, canInsertMultipleLayersTimeStats) {
543 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
544
545 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
546 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
547 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
548 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
549
550 SFTimeStatsGlobalProto globalProto;
551 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
552
553 EXPECT_EQ(2, globalProto.stats_size());
554}
555
556TEST_F(TimeStatsTest, canInsertUnorderedLayerTimeStats) {
557 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
558
559 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
560 insertTimeRecord(UNORDERED_SEQUENCE, LAYER_ID_0, 2, 2000000);
561
562 SFTimeStatsGlobalProto globalProto;
563 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
564
565 ASSERT_EQ(1, globalProto.stats_size());
566 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
567 ASSERT_TRUE(layerProto.has_layer_name());
568 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
569 ASSERT_TRUE(layerProto.has_total_frames());
570 EXPECT_EQ(1, layerProto.total_frames());
571 ASSERT_EQ(6, layerProto.deltas_size());
572 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
573 ASSERT_EQ(1, deltaProto.histograms_size());
574 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
575 EXPECT_EQ(1, histogramProto.frame_count());
576 if ("post2acquire" == deltaProto.delta_name()) {
577 EXPECT_EQ(0, histogramProto.time_millis());
578 } else if ("post2present" == deltaProto.delta_name()) {
579 EXPECT_EQ(2, histogramProto.time_millis());
580 } else if ("acquire2present" == deltaProto.delta_name()) {
581 EXPECT_EQ(2, histogramProto.time_millis());
582 } else if ("latch2present" == deltaProto.delta_name()) {
583 EXPECT_EQ(2, histogramProto.time_millis());
584 } else if ("desired2present" == deltaProto.delta_name()) {
585 EXPECT_EQ(1, histogramProto.time_millis());
586 } else if ("present2present" == deltaProto.delta_name()) {
587 EXPECT_EQ(1, histogramProto.time_millis());
588 } else {
589 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
590 }
591 }
592}
593
Alec Mourifb571ea2019-01-24 18:42:10 -0800594TEST_F(TimeStatsTest, recordRefreshRateNewConfigs) {
595 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
596
597 uint32_t fpsOne = 30;
598 uint32_t fpsTwo = 90;
599 uint64_t millisOne = 5000;
600 uint64_t millisTwo = 7000;
601
602 mTimeStats->recordRefreshRate(fpsOne, ms2ns(millisOne));
603 mTimeStats->recordRefreshRate(fpsTwo, ms2ns(millisTwo));
604
605 SFTimeStatsGlobalProto globalProto;
606 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
607
608 SFTimeStatsDisplayConfigBucketProto expectedBucketOne;
609 SFTimeStatsDisplayConfigProto* expectedConfigOne = expectedBucketOne.mutable_config();
610 expectedConfigOne->set_fps(fpsOne);
611 expectedBucketOne.set_duration_millis(millisOne);
612
613 SFTimeStatsDisplayConfigBucketProto expectedBucketTwo;
614 SFTimeStatsDisplayConfigProto* expectedConfigTwo = expectedBucketTwo.mutable_config();
615 expectedConfigTwo->set_fps(fpsTwo);
616 expectedBucketTwo.set_duration_millis(millisTwo);
617
618 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(2));
619
620 std::unordered_set<uint32_t> seen_fps;
621 for (const auto& bucket : globalProto.display_config_stats()) {
622 seen_fps.emplace(bucket.config().fps());
623 if (fpsOne == bucket.config().fps()) {
624 EXPECT_EQ(millisOne, bucket.duration_millis());
625 } else if (fpsTwo == bucket.config().fps()) {
626 EXPECT_EQ(millisTwo, bucket.duration_millis());
627 } else {
628 FAIL() << "Unknown fps: " << bucket.config().fps();
629 }
630 }
631 EXPECT_THAT(seen_fps, UnorderedElementsAre(fpsOne, fpsTwo));
632}
633
634TEST_F(TimeStatsTest, recordRefreshRateUpdatesConfig) {
635 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
636
637 uint32_t fps = 30;
638 uint64_t millisOne = 5000;
639 uint64_t millisTwo = 7000;
640
641 mTimeStats->recordRefreshRate(fps, ms2ns(millisOne));
642 mTimeStats->recordRefreshRate(fps, ms2ns(millisTwo));
643
644 SFTimeStatsGlobalProto globalProto;
645 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
646 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(1));
647 EXPECT_EQ(fps, globalProto.display_config_stats().Get(0).config().fps());
648 EXPECT_EQ(millisOne + millisTwo, globalProto.display_config_stats().Get(0).duration_millis());
649}
650
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800651TEST_F(TimeStatsTest, canRemoveTimeRecord) {
652 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
653
654 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
655 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 2, 2000000);
656 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(0, 2));
657 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
658
659 SFTimeStatsGlobalProto globalProto;
660 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
661
662 ASSERT_EQ(1, globalProto.stats_size());
663 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
664 ASSERT_TRUE(layerProto.has_total_frames());
665 EXPECT_EQ(1, layerProto.total_frames());
666}
667
668TEST_F(TimeStatsTest, canRecoverFromIncompleteTimeRecordError) {
669 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
670
671 uint64_t frameNumber = 1;
672 nsecs_t ts = 1000000;
673 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 1, 1000000);
Alec Mourifb571ea2019-01-24 18:42:10 -0800674 for (size_t i = 0; i < impl::TimeStats::MAX_NUM_TIME_RECORDS + 2; i++) {
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800675 frameNumber++;
676 ts += 1000000;
677 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, frameNumber, ts);
678 }
679
680 SFTimeStatsGlobalProto globalProto;
681 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
682
683 ASSERT_EQ(1, globalProto.stats_size());
684 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
685 ASSERT_TRUE(layerProto.has_total_frames());
686 EXPECT_EQ(1, layerProto.total_frames());
687}
688
689TEST_F(TimeStatsTest, layerTimeStatsOnDestroy) {
690 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
691
692 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
693 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
694 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(0));
695 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
696
697 SFTimeStatsGlobalProto globalProto;
698 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
699
700 ASSERT_EQ(1, globalProto.stats_size());
701 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
702 ASSERT_TRUE(layerProto.has_total_frames());
703 EXPECT_EQ(1, layerProto.total_frames());
704}
705
706TEST_F(TimeStatsTest, canClearTimeStats) {
707 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
708
709 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
710 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
711 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
712 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL));
Alec Mouri31ac64a2020-01-09 09:26:22 -0800713
Alec Mouri31ac64a2020-01-09 09:26:22 -0800714 mTimeStats
715 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
716 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
717 .count());
718 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
719 .count(),
720 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
721 .count());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800722 ASSERT_NO_FATAL_FAILURE(
723 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
724 ASSERT_NO_FATAL_FAILURE(
725 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
726 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
727 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
728
729 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
730
731 SFTimeStatsGlobalProto globalProto;
732 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
733
734 EXPECT_EQ(0, globalProto.total_frames());
735 EXPECT_EQ(0, globalProto.missed_frames());
736 EXPECT_EQ(0, globalProto.client_composition_frames());
737 EXPECT_EQ(0, globalProto.present_to_present_size());
Alec Mouri31ac64a2020-01-09 09:26:22 -0800738 EXPECT_EQ(0, globalProto.frame_duration_size());
739 EXPECT_EQ(0, globalProto.render_engine_timing_size());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800740 EXPECT_EQ(0, globalProto.stats_size());
741}
742
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800743TEST_F(TimeStatsTest, canClearDumpOnlyTimeStats) {
744 // These stats are not in the proto so verify by checking the string dump.
Vishnu Nair9b079a22020-01-21 14:36:08 -0800745 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
746 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800747 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
748 mTimeStats
749 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
750 std::chrono::duration_cast<std::chrono::nanoseconds>(5ms)
751 .count());
752 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
753 .count(),
754 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
755 .count());
756 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
757 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
Vishnu Nair9b079a22020-01-21 14:36:08 -0800758 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
759
760 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
761 EXPECT_THAT(result, HasSubstr("clientCompositionReusedFrames = 0"));
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800762 EXPECT_THAT(result, HasSubstr("averageFrameDuration = 0.000 ms"));
763 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 0.000 ms"));
Vishnu Nair9b079a22020-01-21 14:36:08 -0800764}
765
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800766TEST_F(TimeStatsTest, canDumpWithMaxLayers) {
767 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
768
769 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
770 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
771 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
772 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
773 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 3, 2000000);
774
775 SFTimeStatsGlobalProto globalProto;
776 ASSERT_TRUE(
777 globalProto.ParseFromString(inputCommand(InputCommand::DUMP_MAXLAYERS_1, FMT_PROTO)));
778
779 ASSERT_EQ(1, globalProto.stats_size());
780 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
781 ASSERT_TRUE(layerProto.has_layer_name());
782 EXPECT_EQ(genLayerName(LAYER_ID_1), layerProto.layer_name());
783 ASSERT_TRUE(layerProto.has_total_frames());
784 EXPECT_EQ(2, layerProto.total_frames());
785}
786
787TEST_F(TimeStatsTest, canDumpWithInvalidMaxLayers) {
788 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
789
790 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
791 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
792
793 SFTimeStatsGlobalProto globalProto;
794 ASSERT_TRUE(globalProto.ParseFromString(
795 inputCommand(InputCommand::DUMP_MAXLAYERS_INVALID, FMT_PROTO)));
796
797 ASSERT_EQ(0, globalProto.stats_size());
798}
799
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000800TEST_F(TimeStatsTest, globalStatsCallback) {
801 constexpr size_t TOTAL_FRAMES = 5;
802 constexpr size_t MISSED_FRAMES = 4;
803 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
Alec Mouri717bcb62020-02-10 17:07:19 -0800804 constexpr size_t DISPLAY_EVENT_CONNECTIONS = 14;
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000805
806 mTimeStats->onBootFinished();
807 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
808
809 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
810 mTimeStats->incrementTotalFrames();
811 }
812 for (size_t i = 0; i < MISSED_FRAMES; i++) {
813 mTimeStats->incrementMissedFrames();
814 }
815 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
816 mTimeStats->incrementClientCompositionFrames();
817 }
818
Alec Mouri717bcb62020-02-10 17:07:19 -0800819 mTimeStats->recordDisplayEventConnectionCount(DISPLAY_EVENT_CONNECTIONS);
820
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000821 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
822 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
823 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
824
Alec Mouri37384342020-01-02 17:23:37 -0800825 EXPECT_THAT(mDelegate->mAtomTags,
826 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
827 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000828 EXPECT_NE(nullptr, mDelegate->mCallback);
829 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
830
831 {
832 InSequence seq;
833 EXPECT_CALL(*mDelegate,
834 statsEventSetAtomId(mDelegate->mEvent,
835 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
836 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, TOTAL_FRAMES));
837 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, MISSED_FRAMES));
838 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, CLIENT_COMPOSITION_FRAMES));
839 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, _));
840 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 2));
Alec Mouri717bcb62020-02-10 17:07:19 -0800841 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, DISPLAY_EVENT_CONNECTIONS));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000842 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
843 }
Tej Singh2a457b62020-01-31 16:16:10 -0800844 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -0800845 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
846 mDelegate->mCookie));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000847
848 SFTimeStatsGlobalProto globalProto;
849 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
850
851 EXPECT_EQ(0, globalProto.total_frames());
852 EXPECT_EQ(0, globalProto.missed_frames());
853 EXPECT_EQ(0, globalProto.client_composition_frames());
854 EXPECT_EQ(0, globalProto.present_to_present_size());
855}
856
Alec Mouri37384342020-01-02 17:23:37 -0800857namespace {
858std::string buildExpectedHistogramBytestring(const std::vector<int32_t>& times,
859 const std::vector<int32_t>& frameCounts) {
860 util::ProtoOutputStream proto;
861 for (int i = 0; i < times.size(); i++) {
862 ALOGE("Writing time: %d", times[i]);
863 proto.write(util::FIELD_TYPE_INT32 | util::FIELD_COUNT_REPEATED | 1 /* field id */,
864 (int32_t)times[i]);
865 ALOGE("Writing count: %d", frameCounts[i]);
866 proto.write(util::FIELD_TYPE_INT64 | util::FIELD_COUNT_REPEATED | 2 /* field id */,
867 (int64_t)frameCounts[i]);
868 }
869 std::string byteString;
870 proto.serializeToString(&byteString);
871 return byteString;
872}
873
874std::string dumpByteStringHex(const std::string& str) {
875 std::stringstream ss;
876 ss << std::hex;
877 for (const char& c : str) {
878 ss << (int)c << " ";
879 }
880
881 return ss.str();
882}
883
884} // namespace
885
886MATCHER_P2(BytesEq, bytes, size, "") {
887 std::string expected;
888 expected.append((const char*)bytes, size);
889 std::string actual;
890 actual.append((const char*)arg, size);
891
892 *result_listener << "Bytes are not equal! \n";
893 *result_listener << "size: " << size << "\n";
894 *result_listener << "expected: " << dumpByteStringHex(expected).c_str() << "\n";
895 *result_listener << "actual: " << dumpByteStringHex(actual).c_str() << "\n";
896
897 return expected == actual;
898}
899
900TEST_F(TimeStatsTest, layerStatsCallback_pullsAllHistogramsAndClears) {
901 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
902
903 mTimeStats->onBootFinished();
904
905 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
906 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
907
908 EXPECT_THAT(mDelegate->mAtomTags,
909 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
910 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
911 EXPECT_NE(nullptr, mDelegate->mCallback);
912 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
913
914 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {1});
915 std::string expectedPostToPresent = buildExpectedHistogramBytestring({4}, {1});
916 std::string expectedAcquireToPresent = buildExpectedHistogramBytestring({3}, {1});
917 std::string expectedLatchToPresent = buildExpectedHistogramBytestring({2}, {1});
918 std::string expectedDesiredToPresent = buildExpectedHistogramBytestring({1}, {1});
919 std::string expectedPostToAcquire = buildExpectedHistogramBytestring({1}, {1});
920 {
921 InSequence seq;
922 EXPECT_CALL(*mDelegate,
923 statsEventSetAtomId(mDelegate->mEvent,
924 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
925 EXPECT_CALL(*mDelegate,
926 statsEventWriteString8(mDelegate->mEvent,
927 StrEq(genLayerName(LAYER_ID_0).c_str())));
928 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 1));
929 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 0));
930 EXPECT_CALL(*mDelegate,
931 statsEventWriteByteArray(mDelegate->mEvent,
932 BytesEq((const uint8_t*)
933 expectedPresentToPresent.c_str(),
934 expectedPresentToPresent.size()),
935 expectedPresentToPresent.size()));
936 EXPECT_CALL(*mDelegate,
937 statsEventWriteByteArray(mDelegate->mEvent,
938 BytesEq((const uint8_t*)expectedPostToPresent.c_str(),
939 expectedPostToPresent.size()),
940 expectedPostToPresent.size()));
941 EXPECT_CALL(*mDelegate,
942 statsEventWriteByteArray(mDelegate->mEvent,
943 BytesEq((const uint8_t*)
944 expectedAcquireToPresent.c_str(),
945 expectedAcquireToPresent.size()),
946 expectedAcquireToPresent.size()));
947 EXPECT_CALL(*mDelegate,
948 statsEventWriteByteArray(mDelegate->mEvent,
949 BytesEq((const uint8_t*)expectedLatchToPresent.c_str(),
950 expectedLatchToPresent.size()),
951 expectedLatchToPresent.size()));
952 EXPECT_CALL(*mDelegate,
953 statsEventWriteByteArray(mDelegate->mEvent,
954 BytesEq((const uint8_t*)
955 expectedDesiredToPresent.c_str(),
956 expectedDesiredToPresent.size()),
957 expectedDesiredToPresent.size()));
958 EXPECT_CALL(*mDelegate,
959 statsEventWriteByteArray(mDelegate->mEvent,
960 BytesEq((const uint8_t*)expectedPostToAcquire.c_str(),
961 expectedPostToAcquire.size()),
962 expectedPostToAcquire.size()));
963 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
964 }
Tej Singh2a457b62020-01-31 16:16:10 -0800965 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -0800966 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
967 mDelegate->mCookie));
968
969 SFTimeStatsGlobalProto globalProto;
970 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
971
972 EXPECT_EQ(0, globalProto.stats_size());
973}
974
975TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleLayers) {
976 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
977
978 mTimeStats->onBootFinished();
979
980 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
981 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
982 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
983 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
984
985 EXPECT_THAT(mDelegate->mAtomTags,
986 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
987 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
988 EXPECT_NE(nullptr, mDelegate->mCallback);
989 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
990
991 EXPECT_CALL(*mDelegate,
992 statsEventSetAtomId(mDelegate->mEvent,
993 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
994 .Times(2);
995 EXPECT_CALL(*mDelegate,
996 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_0).c_str())));
997 EXPECT_CALL(*mDelegate,
998 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -0800999 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001000 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1001 mDelegate->mCookie));
1002}
1003
1004TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleBuckets) {
1005 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1006
1007 mTimeStats->onBootFinished();
1008
1009 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1010 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1011 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1012 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1013
1014 // Now make sure that TimeStats flushes global stats to register the
1015 // callback.
1016 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
1017 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
1018 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
1019 EXPECT_THAT(mDelegate->mAtomTags,
1020 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1021 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1022 EXPECT_NE(nullptr, mDelegate->mCallback);
1023 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1024
1025 EXPECT_THAT(mDelegate->mAtomTags,
1026 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1027 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1028 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1, 2}, {2, 1});
1029 {
1030 InSequence seq;
1031 EXPECT_CALL(*mDelegate,
1032 statsEventWriteByteArray(mDelegate->mEvent,
1033 BytesEq((const uint8_t*)
1034 expectedPresentToPresent.c_str(),
1035 expectedPresentToPresent.size()),
1036 expectedPresentToPresent.size()));
1037 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1038 .Times(AnyNumber());
1039 }
Tej Singh2a457b62020-01-31 16:16:10 -08001040 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001041 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1042 mDelegate->mCookie));
1043}
1044
1045TEST_F(TimeStatsTest, layerStatsCallback_limitsHistogramBuckets) {
1046 mDelegate = new FakeStatsEventDelegate;
1047 mTimeStats =
1048 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
1049 std::nullopt, 1);
1050 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1051
1052 mTimeStats->onBootFinished();
1053
1054 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1055 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1056 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1057 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1058
1059 EXPECT_THAT(mDelegate->mAtomTags,
1060 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1061 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1062 EXPECT_NE(nullptr, mDelegate->mCallback);
1063 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1064
1065 EXPECT_THAT(mDelegate->mAtomTags,
1066 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1067 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1068 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {2});
1069 {
1070 InSequence seq;
1071 EXPECT_CALL(*mDelegate,
1072 statsEventWriteByteArray(mDelegate->mEvent,
1073 BytesEq((const uint8_t*)
1074 expectedPresentToPresent.c_str(),
1075 expectedPresentToPresent.size()),
1076 expectedPresentToPresent.size()));
1077 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1078 .Times(AnyNumber());
1079 }
Tej Singh2a457b62020-01-31 16:16:10 -08001080 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001081 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1082 mDelegate->mCookie));
1083}
1084
1085TEST_F(TimeStatsTest, layerStatsCallback_limitsLayers) {
1086 mDelegate = new FakeStatsEventDelegate;
1087 mTimeStats =
1088 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate), 1,
1089 std::nullopt);
1090 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1091
1092 mTimeStats->onBootFinished();
1093
1094 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1095 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1096 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1097 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1098 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 4, 5000000);
1099
1100 EXPECT_THAT(mDelegate->mAtomTags,
1101 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1102 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1103 EXPECT_NE(nullptr, mDelegate->mCallback);
1104 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1105
1106 EXPECT_CALL(*mDelegate,
1107 statsEventSetAtomId(mDelegate->mEvent,
1108 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1109 .Times(1);
1110 EXPECT_CALL(*mDelegate,
1111 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001112 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001113 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1114 mDelegate->mCookie));
1115}
1116
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001117TEST_F(TimeStatsTest, canSurviveMonkey) {
Lloyd Pique067fe1e2018-12-06 19:44:13 -08001118 if (g_noSlowTests) {
1119 GTEST_SKIP();
1120 }
1121
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001122 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1123
1124 for (size_t i = 0; i < 10000000; ++i) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001125 const int32_t layerId = genRandomInt32(-1, 10);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001126 const int32_t frameNumber = genRandomInt32(1, 10);
1127 switch (genRandomInt32(0, 100)) {
1128 case 0:
1129 ALOGV("removeTimeRecord");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001130 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(layerId, frameNumber));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001131 continue;
1132 case 1:
1133 ALOGV("onDestroy");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001134 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(layerId));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001135 continue;
1136 }
1137 TimeStamp type = static_cast<TimeStamp>(genRandomInt32(TIME_STAMP_BEGIN, TIME_STAMP_END));
1138 const int32_t ts = genRandomInt32(1, 1000000000);
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001139 ALOGV("type[%d], layerId[%d], frameNumber[%d], ts[%d]", type, layerId, frameNumber, ts);
1140 setTimeStamp(type, layerId, frameNumber, ts);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001141 }
1142}
1143
1144} // namespace
1145} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -08001146
1147// TODO(b/129481165): remove the #pragma below and fix conversion issues
1148#pragma clang diagnostic pop // ignored "-Wconversion"