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