blob: a7a4d4837e960a70aead72e6aee658948f6913d0 [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 Mouri37384342020-01-02 17:23:37 -0800800namespace {
801std::string buildExpectedHistogramBytestring(const std::vector<int32_t>& times,
802 const std::vector<int32_t>& frameCounts) {
803 util::ProtoOutputStream proto;
804 for (int i = 0; i < times.size(); i++) {
805 ALOGE("Writing time: %d", times[i]);
806 proto.write(util::FIELD_TYPE_INT32 | util::FIELD_COUNT_REPEATED | 1 /* field id */,
807 (int32_t)times[i]);
808 ALOGE("Writing count: %d", frameCounts[i]);
809 proto.write(util::FIELD_TYPE_INT64 | util::FIELD_COUNT_REPEATED | 2 /* field id */,
810 (int64_t)frameCounts[i]);
811 }
812 std::string byteString;
813 proto.serializeToString(&byteString);
814 return byteString;
815}
816
817std::string dumpByteStringHex(const std::string& str) {
818 std::stringstream ss;
819 ss << std::hex;
820 for (const char& c : str) {
821 ss << (int)c << " ";
822 }
823
824 return ss.str();
825}
826
827} // namespace
828
829MATCHER_P2(BytesEq, bytes, size, "") {
830 std::string expected;
831 expected.append((const char*)bytes, size);
832 std::string actual;
833 actual.append((const char*)arg, size);
834
835 *result_listener << "Bytes are not equal! \n";
836 *result_listener << "size: " << size << "\n";
837 *result_listener << "expected: " << dumpByteStringHex(expected).c_str() << "\n";
838 *result_listener << "actual: " << dumpByteStringHex(actual).c_str() << "\n";
839
840 return expected == actual;
841}
842
Alec Mouridfad9002020-02-12 17:49:09 -0800843TEST_F(TimeStatsTest, globalStatsCallback) {
844 constexpr size_t TOTAL_FRAMES = 5;
845 constexpr size_t MISSED_FRAMES = 4;
846 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
847 constexpr size_t DISPLAY_EVENT_CONNECTIONS = 14;
848
849 mTimeStats->onBootFinished();
850 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
851
852 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
853 mTimeStats->incrementTotalFrames();
854 }
855 for (size_t i = 0; i < MISSED_FRAMES; i++) {
856 mTimeStats->incrementMissedFrames();
857 }
858 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
859 mTimeStats->incrementClientCompositionFrames();
860 }
861
862 mTimeStats->recordDisplayEventConnectionCount(DISPLAY_EVENT_CONNECTIONS);
863 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
864 mTimeStats->recordFrameDuration(1000000, 3000000);
865 mTimeStats->recordRenderEngineDuration(2000000, 4000000);
866 mTimeStats->recordRenderEngineDuration(2000000, std::make_shared<FenceTime>(3000000));
867
868 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
869 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
870
871 EXPECT_THAT(mDelegate->mAtomTags,
872 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
873 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
874 EXPECT_NE(nullptr, mDelegate->mCallback);
875 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
876
877 std::string expectedFrameDuration = buildExpectedHistogramBytestring({2}, {1});
878 std::string expectedRenderEngineTiming = buildExpectedHistogramBytestring({1, 2}, {1, 1});
879
880 {
881 InSequence seq;
882 EXPECT_CALL(*mDelegate,
883 statsEventSetAtomId(mDelegate->mEvent,
884 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
885 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, TOTAL_FRAMES));
886 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, MISSED_FRAMES));
887 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, CLIENT_COMPOSITION_FRAMES));
888 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, _));
889 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 2));
890 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, DISPLAY_EVENT_CONNECTIONS));
891 EXPECT_CALL(*mDelegate,
892 statsEventWriteByteArray(mDelegate->mEvent,
893 BytesEq((const uint8_t*)expectedFrameDuration.c_str(),
894 expectedFrameDuration.size()),
895 expectedFrameDuration.size()));
896 EXPECT_CALL(*mDelegate,
897 statsEventWriteByteArray(mDelegate->mEvent,
898 BytesEq((const uint8_t*)
899 expectedRenderEngineTiming.c_str(),
900 expectedRenderEngineTiming.size()),
901 expectedRenderEngineTiming.size()));
902 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
903 }
904 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
905 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
906 mDelegate->mCookie));
907
908 SFTimeStatsGlobalProto globalProto;
909 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
910
911 EXPECT_EQ(0, globalProto.total_frames());
912 EXPECT_EQ(0, globalProto.missed_frames());
913 EXPECT_EQ(0, globalProto.client_composition_frames());
914 EXPECT_EQ(0, globalProto.present_to_present_size());
915}
916
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -0800917TEST_F(TimeStatsTest, layerStatsCallback_pullsAllAndClears) {
918 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
919 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 3;
Alec Mouri37384342020-01-02 17:23:37 -0800920 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
921
922 mTimeStats->onBootFinished();
923
924 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -0800925 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
926 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
927 }
928 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
929 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
930 }
Alec Mouri37384342020-01-02 17:23:37 -0800931 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
932
933 EXPECT_THAT(mDelegate->mAtomTags,
934 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
935 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
936 EXPECT_NE(nullptr, mDelegate->mCallback);
937 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
938
939 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {1});
940 std::string expectedPostToPresent = buildExpectedHistogramBytestring({4}, {1});
941 std::string expectedAcquireToPresent = buildExpectedHistogramBytestring({3}, {1});
942 std::string expectedLatchToPresent = buildExpectedHistogramBytestring({2}, {1});
943 std::string expectedDesiredToPresent = buildExpectedHistogramBytestring({1}, {1});
944 std::string expectedPostToAcquire = buildExpectedHistogramBytestring({1}, {1});
945 {
946 InSequence seq;
947 EXPECT_CALL(*mDelegate,
948 statsEventSetAtomId(mDelegate->mEvent,
949 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
950 EXPECT_CALL(*mDelegate,
951 statsEventWriteString8(mDelegate->mEvent,
952 StrEq(genLayerName(LAYER_ID_0).c_str())));
953 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 1));
954 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 0));
955 EXPECT_CALL(*mDelegate,
956 statsEventWriteByteArray(mDelegate->mEvent,
957 BytesEq((const uint8_t*)
958 expectedPresentToPresent.c_str(),
959 expectedPresentToPresent.size()),
960 expectedPresentToPresent.size()));
961 EXPECT_CALL(*mDelegate,
962 statsEventWriteByteArray(mDelegate->mEvent,
963 BytesEq((const uint8_t*)expectedPostToPresent.c_str(),
964 expectedPostToPresent.size()),
965 expectedPostToPresent.size()));
966 EXPECT_CALL(*mDelegate,
967 statsEventWriteByteArray(mDelegate->mEvent,
968 BytesEq((const uint8_t*)
969 expectedAcquireToPresent.c_str(),
970 expectedAcquireToPresent.size()),
971 expectedAcquireToPresent.size()));
972 EXPECT_CALL(*mDelegate,
973 statsEventWriteByteArray(mDelegate->mEvent,
974 BytesEq((const uint8_t*)expectedLatchToPresent.c_str(),
975 expectedLatchToPresent.size()),
976 expectedLatchToPresent.size()));
977 EXPECT_CALL(*mDelegate,
978 statsEventWriteByteArray(mDelegate->mEvent,
979 BytesEq((const uint8_t*)
980 expectedDesiredToPresent.c_str(),
981 expectedDesiredToPresent.size()),
982 expectedDesiredToPresent.size()));
983 EXPECT_CALL(*mDelegate,
984 statsEventWriteByteArray(mDelegate->mEvent,
985 BytesEq((const uint8_t*)expectedPostToAcquire.c_str(),
986 expectedPostToAcquire.size()),
987 expectedPostToAcquire.size()));
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -0800988 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, LATE_ACQUIRE_FRAMES));
989 EXPECT_CALL(*mDelegate,
990 statsEventWriteInt64(mDelegate->mEvent, BAD_DESIRED_PRESENT_FRAMES));
Alec Mouri37384342020-01-02 17:23:37 -0800991 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
992 }
Tej Singh2a457b62020-01-31 16:16:10 -0800993 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -0800994 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
995 mDelegate->mCookie));
996
997 SFTimeStatsGlobalProto globalProto;
998 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
999
1000 EXPECT_EQ(0, globalProto.stats_size());
1001}
1002
1003TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleLayers) {
1004 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1005
1006 mTimeStats->onBootFinished();
1007
1008 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1009 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1010 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1011 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1012
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_CALL(*mDelegate,
1020 statsEventSetAtomId(mDelegate->mEvent,
1021 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1022 .Times(2);
1023 EXPECT_CALL(*mDelegate,
1024 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_0).c_str())));
1025 EXPECT_CALL(*mDelegate,
1026 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001027 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001028 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1029 mDelegate->mCookie));
1030}
1031
1032TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleBuckets) {
1033 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1034
1035 mTimeStats->onBootFinished();
1036
1037 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1038 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1039 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1040 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1041
1042 // Now make sure that TimeStats flushes global stats to register the
1043 // callback.
1044 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
1045 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
1046 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
1047 EXPECT_THAT(mDelegate->mAtomTags,
1048 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1049 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1050 EXPECT_NE(nullptr, mDelegate->mCallback);
1051 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1052
1053 EXPECT_THAT(mDelegate->mAtomTags,
1054 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1055 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1056 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1, 2}, {2, 1});
1057 {
1058 InSequence seq;
1059 EXPECT_CALL(*mDelegate,
1060 statsEventWriteByteArray(mDelegate->mEvent,
1061 BytesEq((const uint8_t*)
1062 expectedPresentToPresent.c_str(),
1063 expectedPresentToPresent.size()),
1064 expectedPresentToPresent.size()));
1065 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1066 .Times(AnyNumber());
1067 }
Tej Singh2a457b62020-01-31 16:16:10 -08001068 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001069 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1070 mDelegate->mCookie));
1071}
1072
1073TEST_F(TimeStatsTest, layerStatsCallback_limitsHistogramBuckets) {
1074 mDelegate = new FakeStatsEventDelegate;
1075 mTimeStats =
1076 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
1077 std::nullopt, 1);
1078 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1079
1080 mTimeStats->onBootFinished();
1081
1082 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1083 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1084 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1085 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1086
1087 EXPECT_THAT(mDelegate->mAtomTags,
1088 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1089 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1090 EXPECT_NE(nullptr, mDelegate->mCallback);
1091 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1092
1093 EXPECT_THAT(mDelegate->mAtomTags,
1094 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1095 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1096 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {2});
1097 {
1098 InSequence seq;
1099 EXPECT_CALL(*mDelegate,
1100 statsEventWriteByteArray(mDelegate->mEvent,
1101 BytesEq((const uint8_t*)
1102 expectedPresentToPresent.c_str(),
1103 expectedPresentToPresent.size()),
1104 expectedPresentToPresent.size()));
1105 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1106 .Times(AnyNumber());
1107 }
Tej Singh2a457b62020-01-31 16:16:10 -08001108 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001109 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1110 mDelegate->mCookie));
1111}
1112
1113TEST_F(TimeStatsTest, layerStatsCallback_limitsLayers) {
1114 mDelegate = new FakeStatsEventDelegate;
1115 mTimeStats =
1116 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate), 1,
1117 std::nullopt);
1118 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1119
1120 mTimeStats->onBootFinished();
1121
1122 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1123 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1124 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1125 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1126 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 4, 5000000);
1127
1128 EXPECT_THAT(mDelegate->mAtomTags,
1129 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1130 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1131 EXPECT_NE(nullptr, mDelegate->mCallback);
1132 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1133
1134 EXPECT_CALL(*mDelegate,
1135 statsEventSetAtomId(mDelegate->mEvent,
1136 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1137 .Times(1);
1138 EXPECT_CALL(*mDelegate,
1139 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001140 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001141 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1142 mDelegate->mCookie));
1143}
1144
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001145TEST_F(TimeStatsTest, canSurviveMonkey) {
Lloyd Pique067fe1e2018-12-06 19:44:13 -08001146 if (g_noSlowTests) {
1147 GTEST_SKIP();
1148 }
1149
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001150 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1151
1152 for (size_t i = 0; i < 10000000; ++i) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001153 const int32_t layerId = genRandomInt32(-1, 10);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001154 const int32_t frameNumber = genRandomInt32(1, 10);
1155 switch (genRandomInt32(0, 100)) {
1156 case 0:
1157 ALOGV("removeTimeRecord");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001158 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(layerId, frameNumber));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001159 continue;
1160 case 1:
1161 ALOGV("onDestroy");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001162 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(layerId));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001163 continue;
1164 }
1165 TimeStamp type = static_cast<TimeStamp>(genRandomInt32(TIME_STAMP_BEGIN, TIME_STAMP_END));
1166 const int32_t ts = genRandomInt32(1, 1000000000);
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001167 ALOGV("type[%d], layerId[%d], frameNumber[%d], ts[%d]", type, layerId, frameNumber, ts);
1168 setTimeStamp(type, layerId, frameNumber, ts);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001169 }
1170}
1171
1172} // namespace
1173} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -08001174
1175// TODO(b/129481165): remove the #pragma below and fix conversion issues
1176#pragma clang diagnostic pop // ignored "-Wconversion"