blob: 30505b9a26d482527267008ea40c4889c6d5ce39 [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
152 struct stats_event* addStatsEventToPullData(pulled_stats_event_list*) override {
153 return mEvent;
154 }
155 void registerStatsPullAtomCallback(int32_t atom_tag, stats_pull_atom_callback_t callback,
156 pull_atom_metadata*, void* cookie) override {
Alec Mouri37384342020-01-02 17:23:37 -0800157 mAtomTags.push_back(atom_tag);
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000158 mCallback = callback;
159 mCookie = cookie;
160 }
161
162 status_pull_atom_return_t makePullAtomCallback(int32_t atom_tag, void* cookie) {
163 return (*mCallback)(atom_tag, nullptr, cookie);
164 }
165
166 MOCK_METHOD1(unregisterStatsPullAtomCallback, void(int32_t));
167 MOCK_METHOD2(statsEventSetAtomId, void(struct stats_event*, uint32_t));
168 MOCK_METHOD2(statsEventWriteInt64, void(struct stats_event*, int64_t));
Alec Mouri37384342020-01-02 17:23:37 -0800169 MOCK_METHOD2(statsEventWriteString8, void(struct stats_event*, const char*));
170 MOCK_METHOD3(statsEventWriteByteArray, void(struct stats_event*, const uint8_t*, size_t));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000171 MOCK_METHOD1(statsEventBuild, void(struct stats_event*));
172
173 struct stats_event* mEvent = stats_event_obtain();
Alec Mouri37384342020-01-02 17:23:37 -0800174 std::vector<int32_t> mAtomTags;
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000175 stats_pull_atom_callback_t mCallback = nullptr;
176 void* mCookie = nullptr;
177 };
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000178 FakeStatsEventDelegate* mDelegate = new FakeStatsEventDelegate;
179 std::unique_ptr<TimeStats> mTimeStats =
Alec Mouri37384342020-01-02 17:23:37 -0800180 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
181 std::nullopt, std::nullopt);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800182};
183
184std::string TimeStatsTest::inputCommand(InputCommand cmd, bool useProto) {
Yiwei Zhang5434a782018-12-05 18:06:32 -0800185 std::string result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800186 Vector<String16> args;
187
188 switch (cmd) {
189 case InputCommand::ENABLE:
190 args.push_back(String16("-enable"));
191 break;
192 case InputCommand::DISABLE:
193 args.push_back(String16("-disable"));
194 break;
195 case InputCommand::CLEAR:
196 args.push_back(String16("-clear"));
197 break;
198 case InputCommand::DUMP_ALL:
199 args.push_back(String16("-dump"));
200 break;
201 case InputCommand::DUMP_MAXLAYERS_1:
202 args.push_back(String16("-dump"));
203 args.push_back(String16("-maxlayers"));
204 args.push_back(String16(std::to_string(NUM_LAYERS).c_str()));
205 break;
206 case InputCommand::DUMP_MAXLAYERS_INVALID:
207 args.push_back(String16("-dump"));
208 args.push_back(String16("-maxlayers"));
209 args.push_back(String16(NUM_LAYERS_INVALID));
210 break;
211 default:
212 ALOGD("Invalid control command");
213 }
214
Dominik Laskowskic2867142019-01-21 11:33:38 -0800215 EXPECT_NO_FATAL_FAILURE(mTimeStats->parseArgs(useProto, args, result));
Yiwei Zhang5434a782018-12-05 18:06:32 -0800216 return result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800217}
218
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800219static std::string genLayerName(int32_t layerId) {
220 return (layerId < 0 ? "PopupWindow:b54fcd1#0" : "com.dummy#") + std::to_string(layerId);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800221}
222
223void TimeStatsTest::setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts) {
224 switch (type) {
225 case TimeStamp::POST:
226 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPostTime(id, frameNumber, genLayerName(id), ts));
227 break;
228 case TimeStamp::ACQUIRE:
229 ASSERT_NO_FATAL_FAILURE(mTimeStats->setAcquireTime(id, frameNumber, ts));
230 break;
231 case TimeStamp::ACQUIRE_FENCE:
232 ASSERT_NO_FATAL_FAILURE(
233 mTimeStats->setAcquireFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
234 break;
235 case TimeStamp::LATCH:
236 ASSERT_NO_FATAL_FAILURE(mTimeStats->setLatchTime(id, frameNumber, ts));
237 break;
238 case TimeStamp::DESIRED:
239 ASSERT_NO_FATAL_FAILURE(mTimeStats->setDesiredTime(id, frameNumber, ts));
240 break;
241 case TimeStamp::PRESENT:
242 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPresentTime(id, frameNumber, ts));
243 break;
244 case TimeStamp::PRESENT_FENCE:
245 ASSERT_NO_FATAL_FAILURE(
246 mTimeStats->setPresentFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
247 break;
248 default:
249 ALOGD("Invalid timestamp type");
250 }
251}
252
253int32_t TimeStatsTest::genRandomInt32(int32_t begin, int32_t end) {
254 std::uniform_int_distribution<int32_t> distr(begin, end);
255 return distr(mRandomEngine);
256}
257
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000258TEST_F(TimeStatsTest, disabledByDefault) {
259 ASSERT_FALSE(mTimeStats->isEnabled());
260}
261
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800262TEST_F(TimeStatsTest, registersCallbacksAfterBoot) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000263 mTimeStats->onBootFinished();
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800264 EXPECT_THAT(mDelegate->mAtomTags,
265 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
266 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
267}
268
269TEST_F(TimeStatsTest, unregistersCallbacksOnDestruction) {
270 EXPECT_CALL(*mDelegate,
271 unregisterStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
272 EXPECT_CALL(*mDelegate,
273 unregisterStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO));
274 mTimeStats.reset();
Alec Mourib3885ad2019-09-06 17:08:55 -0700275}
276
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800277TEST_F(TimeStatsTest, canEnableAndDisableTimeStats) {
278 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
279 ASSERT_TRUE(mTimeStats->isEnabled());
280
281 EXPECT_TRUE(inputCommand(InputCommand::DISABLE, FMT_STRING).empty());
282 ASSERT_FALSE(mTimeStats->isEnabled());
283}
284
285TEST_F(TimeStatsTest, canIncreaseGlobalStats) {
286 constexpr size_t TOTAL_FRAMES = 5;
287 constexpr size_t MISSED_FRAMES = 4;
288 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
289
290 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
291
292 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
293 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
294 }
295 for (size_t i = 0; i < MISSED_FRAMES; i++) {
296 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
297 }
298 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
299 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
300 }
301
302 SFTimeStatsGlobalProto globalProto;
303 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
304
305 ASSERT_TRUE(globalProto.has_total_frames());
306 EXPECT_EQ(TOTAL_FRAMES, globalProto.total_frames());
307 ASSERT_TRUE(globalProto.has_missed_frames());
308 EXPECT_EQ(MISSED_FRAMES, globalProto.missed_frames());
309 ASSERT_TRUE(globalProto.has_client_composition_frames());
310 EXPECT_EQ(CLIENT_COMPOSITION_FRAMES, globalProto.client_composition_frames());
311}
312
Alec Mouri91f6df32020-01-30 08:48:58 -0800313TEST_F(TimeStatsTest, canIncreaseLateAcquireFrames) {
314 // this stat is not in the proto so verify by checking the string dump
315 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
316
317 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
318
319 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
320 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
321 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
322 }
323 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
324
325 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
326 const std::string expectedResult = "lateAcquireFrames = " + std::to_string(LATE_ACQUIRE_FRAMES);
327 EXPECT_THAT(result, HasSubstr(expectedResult));
328}
329
330TEST_F(TimeStatsTest, canIncreaseBadDesiredPresent) {
331 // this stat is not in the proto so verify by checking the string dump
332 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 2;
333
334 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
335
336 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
337 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
338 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
339 }
340 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
341
342 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
343 const std::string expectedResult =
344 "badDesiredPresentFrames = " + std::to_string(BAD_DESIRED_PRESENT_FRAMES);
345 EXPECT_THAT(result, HasSubstr(expectedResult));
346}
347
Vishnu Nair9b079a22020-01-21 14:36:08 -0800348TEST_F(TimeStatsTest, canIncreaseClientCompositionReusedFrames) {
349 // this stat is not in the proto so verify by checking the string dump
350 constexpr size_t CLIENT_COMPOSITION_REUSED_FRAMES = 2;
351
352 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
353 for (size_t i = 0; i < CLIENT_COMPOSITION_REUSED_FRAMES; i++) {
354 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
355 }
356
357 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
358 const std::string expectedResult =
359 "clientCompositionReusedFrames = " + std::to_string(CLIENT_COMPOSITION_REUSED_FRAMES);
360 EXPECT_THAT(result, HasSubstr(expectedResult));
361}
362
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800363TEST_F(TimeStatsTest, canAverageFrameDuration) {
364 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
365 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
366 mTimeStats
367 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
368 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
369 .count());
370 mTimeStats
371 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
372 std::chrono::duration_cast<std::chrono::nanoseconds>(16ms)
373 .count());
374
375 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
376 EXPECT_THAT(result, HasSubstr("averageFrameDuration = 10.000 ms"));
377}
378
379TEST_F(TimeStatsTest, canAverageRenderEngineTimings) {
380 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
381 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms)
382 .count(),
383 std::make_shared<FenceTime>(
384 std::chrono::duration_cast<
385 std::chrono::nanoseconds>(3ms)
386 .count()));
387
388 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
389 .count(),
390 std::chrono::duration_cast<std::chrono::nanoseconds>(8ms)
391 .count());
392
393 // Push a dummy present fence to trigger flushing the RenderEngine timings.
394 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
395 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
396 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
397
398 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
399 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 3.000 ms"));
400}
401
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800402TEST_F(TimeStatsTest, canInsertGlobalPresentToPresent) {
403 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
404
405 ASSERT_NO_FATAL_FAILURE(
406 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
407 ASSERT_NO_FATAL_FAILURE(
408 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
409
410 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL));
411 ASSERT_NO_FATAL_FAILURE(
412 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000)));
413 ASSERT_NO_FATAL_FAILURE(
414 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000)));
415
416 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_OFF));
417 ASSERT_NO_FATAL_FAILURE(
418 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(6000000)));
419 ASSERT_NO_FATAL_FAILURE(
420 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(8000000)));
421
422 SFTimeStatsGlobalProto globalProto;
423 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
424
425 ASSERT_EQ(1, globalProto.present_to_present_size());
426 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.present_to_present().Get(0);
427 EXPECT_EQ(1, histogramProto.frame_count());
428 EXPECT_EQ(2, histogramProto.time_millis());
429}
430
Alec Mouri9519bf12019-11-15 16:54:44 -0800431TEST_F(TimeStatsTest, canInsertGlobalFrameDuration) {
432 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
433
Alec Mouri9519bf12019-11-15 16:54:44 -0800434 mTimeStats->setPowerMode(HWC_POWER_MODE_OFF);
435 mTimeStats
436 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
437 std::chrono::duration_cast<std::chrono::nanoseconds>(5ms)
438 .count());
439 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
440 mTimeStats
441 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
442 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
443 .count());
444
445 SFTimeStatsGlobalProto globalProto;
446 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
447
448 ASSERT_EQ(1, globalProto.frame_duration_size());
449 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.frame_duration().Get(0);
450 EXPECT_EQ(1, histogramProto.frame_count());
451 EXPECT_EQ(3, histogramProto.time_millis());
452}
453
Alec Mourie4034bb2019-11-19 12:45:54 -0800454TEST_F(TimeStatsTest, canInsertGlobalRenderEngineTiming) {
455 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
456
Alec Mourie4034bb2019-11-19 12:45:54 -0800457 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms)
458 .count(),
459 std::make_shared<FenceTime>(
460 std::chrono::duration_cast<
461 std::chrono::nanoseconds>(3ms)
462 .count()));
463
464 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
465 .count(),
466 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
467 .count());
468
469 // First verify that flushing RenderEngine durations did not occur yet.
470 SFTimeStatsGlobalProto preFlushProto;
471 ASSERT_TRUE(preFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
472 ASSERT_EQ(0, preFlushProto.render_engine_timing_size());
473
474 // Push a dummy present fence to trigger flushing the RenderEngine timings.
475 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
476 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
477 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
478
479 // Now we can verify that RenderEngine durations were flushed now.
480 SFTimeStatsGlobalProto postFlushProto;
481 ASSERT_TRUE(postFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
482
483 ASSERT_EQ(1, postFlushProto.render_engine_timing_size());
484 const SFTimeStatsHistogramBucketProto& histogramProto =
485 postFlushProto.render_engine_timing().Get(0);
486 EXPECT_EQ(2, histogramProto.frame_count());
487 EXPECT_EQ(2, histogramProto.time_millis());
488}
489
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800490TEST_F(TimeStatsTest, canInsertOneLayerTimeStats) {
491 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
492
493 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
494 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
495
496 SFTimeStatsGlobalProto globalProto;
497 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
498
499 ASSERT_EQ(1, globalProto.stats_size());
500 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
501 ASSERT_TRUE(layerProto.has_layer_name());
502 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
503 ASSERT_TRUE(layerProto.has_total_frames());
504 EXPECT_EQ(1, layerProto.total_frames());
505 ASSERT_EQ(6, layerProto.deltas_size());
506 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
507 ASSERT_EQ(1, deltaProto.histograms_size());
508 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
509 EXPECT_EQ(1, histogramProto.frame_count());
510 if ("post2acquire" == deltaProto.delta_name()) {
511 EXPECT_EQ(1, histogramProto.time_millis());
512 } else if ("post2present" == deltaProto.delta_name()) {
513 EXPECT_EQ(4, histogramProto.time_millis());
514 } else if ("acquire2present" == deltaProto.delta_name()) {
515 EXPECT_EQ(3, histogramProto.time_millis());
516 } else if ("latch2present" == deltaProto.delta_name()) {
517 EXPECT_EQ(2, histogramProto.time_millis());
518 } else if ("desired2present" == deltaProto.delta_name()) {
519 EXPECT_EQ(1, histogramProto.time_millis());
520 } else if ("present2present" == deltaProto.delta_name()) {
521 EXPECT_EQ(1, histogramProto.time_millis());
522 } else {
523 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
524 }
525 }
526}
527
528TEST_F(TimeStatsTest, canNotInsertInvalidLayerNameTimeStats) {
529 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
530
531 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_INVALID, 1, 1000000);
532 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_INVALID, 2, 2000000);
533
534 SFTimeStatsGlobalProto globalProto;
535 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
536
537 ASSERT_EQ(0, globalProto.stats_size());
538}
539
540TEST_F(TimeStatsTest, canInsertMultipleLayersTimeStats) {
541 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
542
543 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
544 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
545 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
546 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
547
548 SFTimeStatsGlobalProto globalProto;
549 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
550
551 EXPECT_EQ(2, globalProto.stats_size());
552}
553
554TEST_F(TimeStatsTest, canInsertUnorderedLayerTimeStats) {
555 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
556
557 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
558 insertTimeRecord(UNORDERED_SEQUENCE, LAYER_ID_0, 2, 2000000);
559
560 SFTimeStatsGlobalProto globalProto;
561 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
562
563 ASSERT_EQ(1, globalProto.stats_size());
564 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
565 ASSERT_TRUE(layerProto.has_layer_name());
566 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
567 ASSERT_TRUE(layerProto.has_total_frames());
568 EXPECT_EQ(1, layerProto.total_frames());
569 ASSERT_EQ(6, layerProto.deltas_size());
570 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
571 ASSERT_EQ(1, deltaProto.histograms_size());
572 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
573 EXPECT_EQ(1, histogramProto.frame_count());
574 if ("post2acquire" == deltaProto.delta_name()) {
575 EXPECT_EQ(0, histogramProto.time_millis());
576 } else if ("post2present" == deltaProto.delta_name()) {
577 EXPECT_EQ(2, histogramProto.time_millis());
578 } else if ("acquire2present" == deltaProto.delta_name()) {
579 EXPECT_EQ(2, histogramProto.time_millis());
580 } else if ("latch2present" == deltaProto.delta_name()) {
581 EXPECT_EQ(2, histogramProto.time_millis());
582 } else if ("desired2present" == deltaProto.delta_name()) {
583 EXPECT_EQ(1, histogramProto.time_millis());
584 } else if ("present2present" == deltaProto.delta_name()) {
585 EXPECT_EQ(1, histogramProto.time_millis());
586 } else {
587 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
588 }
589 }
590}
591
Alec Mourifb571ea2019-01-24 18:42:10 -0800592TEST_F(TimeStatsTest, recordRefreshRateNewConfigs) {
593 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
594
595 uint32_t fpsOne = 30;
596 uint32_t fpsTwo = 90;
597 uint64_t millisOne = 5000;
598 uint64_t millisTwo = 7000;
599
600 mTimeStats->recordRefreshRate(fpsOne, ms2ns(millisOne));
601 mTimeStats->recordRefreshRate(fpsTwo, ms2ns(millisTwo));
602
603 SFTimeStatsGlobalProto globalProto;
604 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
605
606 SFTimeStatsDisplayConfigBucketProto expectedBucketOne;
607 SFTimeStatsDisplayConfigProto* expectedConfigOne = expectedBucketOne.mutable_config();
608 expectedConfigOne->set_fps(fpsOne);
609 expectedBucketOne.set_duration_millis(millisOne);
610
611 SFTimeStatsDisplayConfigBucketProto expectedBucketTwo;
612 SFTimeStatsDisplayConfigProto* expectedConfigTwo = expectedBucketTwo.mutable_config();
613 expectedConfigTwo->set_fps(fpsTwo);
614 expectedBucketTwo.set_duration_millis(millisTwo);
615
616 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(2));
617
618 std::unordered_set<uint32_t> seen_fps;
619 for (const auto& bucket : globalProto.display_config_stats()) {
620 seen_fps.emplace(bucket.config().fps());
621 if (fpsOne == bucket.config().fps()) {
622 EXPECT_EQ(millisOne, bucket.duration_millis());
623 } else if (fpsTwo == bucket.config().fps()) {
624 EXPECT_EQ(millisTwo, bucket.duration_millis());
625 } else {
626 FAIL() << "Unknown fps: " << bucket.config().fps();
627 }
628 }
629 EXPECT_THAT(seen_fps, UnorderedElementsAre(fpsOne, fpsTwo));
630}
631
632TEST_F(TimeStatsTest, recordRefreshRateUpdatesConfig) {
633 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
634
635 uint32_t fps = 30;
636 uint64_t millisOne = 5000;
637 uint64_t millisTwo = 7000;
638
639 mTimeStats->recordRefreshRate(fps, ms2ns(millisOne));
640 mTimeStats->recordRefreshRate(fps, ms2ns(millisTwo));
641
642 SFTimeStatsGlobalProto globalProto;
643 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
644 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(1));
645 EXPECT_EQ(fps, globalProto.display_config_stats().Get(0).config().fps());
646 EXPECT_EQ(millisOne + millisTwo, globalProto.display_config_stats().Get(0).duration_millis());
647}
648
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800649TEST_F(TimeStatsTest, canRemoveTimeRecord) {
650 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
651
652 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
653 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 2, 2000000);
654 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(0, 2));
655 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
656
657 SFTimeStatsGlobalProto globalProto;
658 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
659
660 ASSERT_EQ(1, globalProto.stats_size());
661 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
662 ASSERT_TRUE(layerProto.has_total_frames());
663 EXPECT_EQ(1, layerProto.total_frames());
664}
665
666TEST_F(TimeStatsTest, canRecoverFromIncompleteTimeRecordError) {
667 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
668
669 uint64_t frameNumber = 1;
670 nsecs_t ts = 1000000;
671 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 1, 1000000);
Alec Mourifb571ea2019-01-24 18:42:10 -0800672 for (size_t i = 0; i < impl::TimeStats::MAX_NUM_TIME_RECORDS + 2; i++) {
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800673 frameNumber++;
674 ts += 1000000;
675 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, frameNumber, ts);
676 }
677
678 SFTimeStatsGlobalProto globalProto;
679 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
680
681 ASSERT_EQ(1, globalProto.stats_size());
682 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
683 ASSERT_TRUE(layerProto.has_total_frames());
684 EXPECT_EQ(1, layerProto.total_frames());
685}
686
687TEST_F(TimeStatsTest, layerTimeStatsOnDestroy) {
688 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
689
690 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
691 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
692 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(0));
693 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
694
695 SFTimeStatsGlobalProto globalProto;
696 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
697
698 ASSERT_EQ(1, globalProto.stats_size());
699 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
700 ASSERT_TRUE(layerProto.has_total_frames());
701 EXPECT_EQ(1, layerProto.total_frames());
702}
703
704TEST_F(TimeStatsTest, canClearTimeStats) {
705 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
706
707 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
708 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
709 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
710 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL));
Alec Mouri31ac64a2020-01-09 09:26:22 -0800711
Alec Mouri31ac64a2020-01-09 09:26:22 -0800712 mTimeStats
713 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
714 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
715 .count());
716 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
717 .count(),
718 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
719 .count());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800720 ASSERT_NO_FATAL_FAILURE(
721 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
722 ASSERT_NO_FATAL_FAILURE(
723 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
724 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
725 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
726
727 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
728
729 SFTimeStatsGlobalProto globalProto;
730 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
731
732 EXPECT_EQ(0, globalProto.total_frames());
733 EXPECT_EQ(0, globalProto.missed_frames());
734 EXPECT_EQ(0, globalProto.client_composition_frames());
735 EXPECT_EQ(0, globalProto.present_to_present_size());
Alec Mouri31ac64a2020-01-09 09:26:22 -0800736 EXPECT_EQ(0, globalProto.frame_duration_size());
737 EXPECT_EQ(0, globalProto.render_engine_timing_size());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800738 EXPECT_EQ(0, globalProto.stats_size());
739}
740
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800741TEST_F(TimeStatsTest, canClearDumpOnlyTimeStats) {
742 // These stats are not in the proto so verify by checking the string dump.
Vishnu Nair9b079a22020-01-21 14:36:08 -0800743 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
744 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800745 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
746 mTimeStats
747 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
748 std::chrono::duration_cast<std::chrono::nanoseconds>(5ms)
749 .count());
750 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
751 .count(),
752 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
753 .count());
754 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
755 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
Vishnu Nair9b079a22020-01-21 14:36:08 -0800756 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
757
758 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
759 EXPECT_THAT(result, HasSubstr("clientCompositionReusedFrames = 0"));
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800760 EXPECT_THAT(result, HasSubstr("averageFrameDuration = 0.000 ms"));
761 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 0.000 ms"));
Vishnu Nair9b079a22020-01-21 14:36:08 -0800762}
763
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800764TEST_F(TimeStatsTest, canDumpWithMaxLayers) {
765 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
766
767 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
768 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
769 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
770 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
771 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 3, 2000000);
772
773 SFTimeStatsGlobalProto globalProto;
774 ASSERT_TRUE(
775 globalProto.ParseFromString(inputCommand(InputCommand::DUMP_MAXLAYERS_1, FMT_PROTO)));
776
777 ASSERT_EQ(1, globalProto.stats_size());
778 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
779 ASSERT_TRUE(layerProto.has_layer_name());
780 EXPECT_EQ(genLayerName(LAYER_ID_1), layerProto.layer_name());
781 ASSERT_TRUE(layerProto.has_total_frames());
782 EXPECT_EQ(2, layerProto.total_frames());
783}
784
785TEST_F(TimeStatsTest, canDumpWithInvalidMaxLayers) {
786 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
787
788 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
789 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
790
791 SFTimeStatsGlobalProto globalProto;
792 ASSERT_TRUE(globalProto.ParseFromString(
793 inputCommand(InputCommand::DUMP_MAXLAYERS_INVALID, FMT_PROTO)));
794
795 ASSERT_EQ(0, globalProto.stats_size());
796}
797
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000798TEST_F(TimeStatsTest, globalStatsCallback) {
799 constexpr size_t TOTAL_FRAMES = 5;
800 constexpr size_t MISSED_FRAMES = 4;
801 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
802
803 mTimeStats->onBootFinished();
804 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
805
806 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
807 mTimeStats->incrementTotalFrames();
808 }
809 for (size_t i = 0; i < MISSED_FRAMES; i++) {
810 mTimeStats->incrementMissedFrames();
811 }
812 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
813 mTimeStats->incrementClientCompositionFrames();
814 }
815
816 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
817 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
818 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
819
Alec Mouri37384342020-01-02 17:23:37 -0800820 EXPECT_THAT(mDelegate->mAtomTags,
821 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
822 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000823 EXPECT_NE(nullptr, mDelegate->mCallback);
824 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
825
826 {
827 InSequence seq;
828 EXPECT_CALL(*mDelegate,
829 statsEventSetAtomId(mDelegate->mEvent,
830 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
831 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, TOTAL_FRAMES));
832 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, MISSED_FRAMES));
833 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, CLIENT_COMPOSITION_FRAMES));
834 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, _));
835 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 2));
836 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
837 }
838 EXPECT_EQ(STATS_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -0800839 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
840 mDelegate->mCookie));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000841
842 SFTimeStatsGlobalProto globalProto;
843 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
844
845 EXPECT_EQ(0, globalProto.total_frames());
846 EXPECT_EQ(0, globalProto.missed_frames());
847 EXPECT_EQ(0, globalProto.client_composition_frames());
848 EXPECT_EQ(0, globalProto.present_to_present_size());
849}
850
Alec Mouri37384342020-01-02 17:23:37 -0800851namespace {
852std::string buildExpectedHistogramBytestring(const std::vector<int32_t>& times,
853 const std::vector<int32_t>& frameCounts) {
854 util::ProtoOutputStream proto;
855 for (int i = 0; i < times.size(); i++) {
856 ALOGE("Writing time: %d", times[i]);
857 proto.write(util::FIELD_TYPE_INT32 | util::FIELD_COUNT_REPEATED | 1 /* field id */,
858 (int32_t)times[i]);
859 ALOGE("Writing count: %d", frameCounts[i]);
860 proto.write(util::FIELD_TYPE_INT64 | util::FIELD_COUNT_REPEATED | 2 /* field id */,
861 (int64_t)frameCounts[i]);
862 }
863 std::string byteString;
864 proto.serializeToString(&byteString);
865 return byteString;
866}
867
868std::string dumpByteStringHex(const std::string& str) {
869 std::stringstream ss;
870 ss << std::hex;
871 for (const char& c : str) {
872 ss << (int)c << " ";
873 }
874
875 return ss.str();
876}
877
878} // namespace
879
880MATCHER_P2(BytesEq, bytes, size, "") {
881 std::string expected;
882 expected.append((const char*)bytes, size);
883 std::string actual;
884 actual.append((const char*)arg, size);
885
886 *result_listener << "Bytes are not equal! \n";
887 *result_listener << "size: " << size << "\n";
888 *result_listener << "expected: " << dumpByteStringHex(expected).c_str() << "\n";
889 *result_listener << "actual: " << dumpByteStringHex(actual).c_str() << "\n";
890
891 return expected == actual;
892}
893
894TEST_F(TimeStatsTest, layerStatsCallback_pullsAllHistogramsAndClears) {
895 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
896
897 mTimeStats->onBootFinished();
898
899 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
900 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
901
902 EXPECT_THAT(mDelegate->mAtomTags,
903 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
904 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
905 EXPECT_NE(nullptr, mDelegate->mCallback);
906 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
907
908 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {1});
909 std::string expectedPostToPresent = buildExpectedHistogramBytestring({4}, {1});
910 std::string expectedAcquireToPresent = buildExpectedHistogramBytestring({3}, {1});
911 std::string expectedLatchToPresent = buildExpectedHistogramBytestring({2}, {1});
912 std::string expectedDesiredToPresent = buildExpectedHistogramBytestring({1}, {1});
913 std::string expectedPostToAcquire = buildExpectedHistogramBytestring({1}, {1});
914 {
915 InSequence seq;
916 EXPECT_CALL(*mDelegate,
917 statsEventSetAtomId(mDelegate->mEvent,
918 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
919 EXPECT_CALL(*mDelegate,
920 statsEventWriteString8(mDelegate->mEvent,
921 StrEq(genLayerName(LAYER_ID_0).c_str())));
922 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 1));
923 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 0));
924 EXPECT_CALL(*mDelegate,
925 statsEventWriteByteArray(mDelegate->mEvent,
926 BytesEq((const uint8_t*)
927 expectedPresentToPresent.c_str(),
928 expectedPresentToPresent.size()),
929 expectedPresentToPresent.size()));
930 EXPECT_CALL(*mDelegate,
931 statsEventWriteByteArray(mDelegate->mEvent,
932 BytesEq((const uint8_t*)expectedPostToPresent.c_str(),
933 expectedPostToPresent.size()),
934 expectedPostToPresent.size()));
935 EXPECT_CALL(*mDelegate,
936 statsEventWriteByteArray(mDelegate->mEvent,
937 BytesEq((const uint8_t*)
938 expectedAcquireToPresent.c_str(),
939 expectedAcquireToPresent.size()),
940 expectedAcquireToPresent.size()));
941 EXPECT_CALL(*mDelegate,
942 statsEventWriteByteArray(mDelegate->mEvent,
943 BytesEq((const uint8_t*)expectedLatchToPresent.c_str(),
944 expectedLatchToPresent.size()),
945 expectedLatchToPresent.size()));
946 EXPECT_CALL(*mDelegate,
947 statsEventWriteByteArray(mDelegate->mEvent,
948 BytesEq((const uint8_t*)
949 expectedDesiredToPresent.c_str(),
950 expectedDesiredToPresent.size()),
951 expectedDesiredToPresent.size()));
952 EXPECT_CALL(*mDelegate,
953 statsEventWriteByteArray(mDelegate->mEvent,
954 BytesEq((const uint8_t*)expectedPostToAcquire.c_str(),
955 expectedPostToAcquire.size()),
956 expectedPostToAcquire.size()));
957 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
958 }
959 EXPECT_EQ(STATS_PULL_SUCCESS,
960 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
961 mDelegate->mCookie));
962
963 SFTimeStatsGlobalProto globalProto;
964 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
965
966 EXPECT_EQ(0, globalProto.stats_size());
967}
968
969TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleLayers) {
970 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
971
972 mTimeStats->onBootFinished();
973
974 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
975 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
976 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
977 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
978
979 EXPECT_THAT(mDelegate->mAtomTags,
980 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
981 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
982 EXPECT_NE(nullptr, mDelegate->mCallback);
983 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
984
985 EXPECT_CALL(*mDelegate,
986 statsEventSetAtomId(mDelegate->mEvent,
987 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
988 .Times(2);
989 EXPECT_CALL(*mDelegate,
990 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_0).c_str())));
991 EXPECT_CALL(*mDelegate,
992 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
993 EXPECT_EQ(STATS_PULL_SUCCESS,
994 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
995 mDelegate->mCookie));
996}
997
998TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleBuckets) {
999 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1000
1001 mTimeStats->onBootFinished();
1002
1003 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1004 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1005 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1006 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1007
1008 // Now make sure that TimeStats flushes global stats to register the
1009 // callback.
1010 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
1011 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
1012 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
1013 EXPECT_THAT(mDelegate->mAtomTags,
1014 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1015 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1016 EXPECT_NE(nullptr, mDelegate->mCallback);
1017 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1018
1019 EXPECT_THAT(mDelegate->mAtomTags,
1020 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1021 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1022 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1, 2}, {2, 1});
1023 {
1024 InSequence seq;
1025 EXPECT_CALL(*mDelegate,
1026 statsEventWriteByteArray(mDelegate->mEvent,
1027 BytesEq((const uint8_t*)
1028 expectedPresentToPresent.c_str(),
1029 expectedPresentToPresent.size()),
1030 expectedPresentToPresent.size()));
1031 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1032 .Times(AnyNumber());
1033 }
1034 EXPECT_EQ(STATS_PULL_SUCCESS,
1035 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1036 mDelegate->mCookie));
1037}
1038
1039TEST_F(TimeStatsTest, layerStatsCallback_limitsHistogramBuckets) {
1040 mDelegate = new FakeStatsEventDelegate;
1041 mTimeStats =
1042 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
1043 std::nullopt, 1);
1044 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1045
1046 mTimeStats->onBootFinished();
1047
1048 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1049 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1050 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1051 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1052
1053 EXPECT_THAT(mDelegate->mAtomTags,
1054 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1055 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1056 EXPECT_NE(nullptr, mDelegate->mCallback);
1057 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1058
1059 EXPECT_THAT(mDelegate->mAtomTags,
1060 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1061 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1062 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {2});
1063 {
1064 InSequence seq;
1065 EXPECT_CALL(*mDelegate,
1066 statsEventWriteByteArray(mDelegate->mEvent,
1067 BytesEq((const uint8_t*)
1068 expectedPresentToPresent.c_str(),
1069 expectedPresentToPresent.size()),
1070 expectedPresentToPresent.size()));
1071 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1072 .Times(AnyNumber());
1073 }
1074 EXPECT_EQ(STATS_PULL_SUCCESS,
1075 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1076 mDelegate->mCookie));
1077}
1078
1079TEST_F(TimeStatsTest, layerStatsCallback_limitsLayers) {
1080 mDelegate = new FakeStatsEventDelegate;
1081 mTimeStats =
1082 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate), 1,
1083 std::nullopt);
1084 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1085
1086 mTimeStats->onBootFinished();
1087
1088 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1089 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1090 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1091 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1092 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 4, 5000000);
1093
1094 EXPECT_THAT(mDelegate->mAtomTags,
1095 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1096 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1097 EXPECT_NE(nullptr, mDelegate->mCallback);
1098 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1099
1100 EXPECT_CALL(*mDelegate,
1101 statsEventSetAtomId(mDelegate->mEvent,
1102 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1103 .Times(1);
1104 EXPECT_CALL(*mDelegate,
1105 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
1106 EXPECT_EQ(STATS_PULL_SUCCESS,
1107 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1108 mDelegate->mCookie));
1109}
1110
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001111TEST_F(TimeStatsTest, canSurviveMonkey) {
Lloyd Pique067fe1e2018-12-06 19:44:13 -08001112 if (g_noSlowTests) {
1113 GTEST_SKIP();
1114 }
1115
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001116 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1117
1118 for (size_t i = 0; i < 10000000; ++i) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001119 const int32_t layerId = genRandomInt32(-1, 10);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001120 const int32_t frameNumber = genRandomInt32(1, 10);
1121 switch (genRandomInt32(0, 100)) {
1122 case 0:
1123 ALOGV("removeTimeRecord");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001124 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(layerId, frameNumber));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001125 continue;
1126 case 1:
1127 ALOGV("onDestroy");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001128 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(layerId));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001129 continue;
1130 }
1131 TimeStamp type = static_cast<TimeStamp>(genRandomInt32(TIME_STAMP_BEGIN, TIME_STAMP_END));
1132 const int32_t ts = genRandomInt32(1, 1000000000);
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001133 ALOGV("type[%d], layerId[%d], frameNumber[%d], ts[%d]", type, layerId, frameNumber, ts);
1134 setTimeStamp(type, layerId, frameNumber, ts);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001135 }
1136}
1137
1138} // namespace
1139} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -08001140
1141// TODO(b/129481165): remove the #pragma below and fix conversion issues
1142#pragma clang diagnostic pop // ignored "-Wconversion"