blob: 91a40d012c3236296af681bcd6cc205464816f1d [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
895TEST_F(TimeStatsTest, layerStatsCallback_pullsAllHistogramsAndClears) {
896 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
897
898 mTimeStats->onBootFinished();
899
900 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
901 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
902
903 EXPECT_THAT(mDelegate->mAtomTags,
904 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
905 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
906 EXPECT_NE(nullptr, mDelegate->mCallback);
907 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
908
909 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {1});
910 std::string expectedPostToPresent = buildExpectedHistogramBytestring({4}, {1});
911 std::string expectedAcquireToPresent = buildExpectedHistogramBytestring({3}, {1});
912 std::string expectedLatchToPresent = buildExpectedHistogramBytestring({2}, {1});
913 std::string expectedDesiredToPresent = buildExpectedHistogramBytestring({1}, {1});
914 std::string expectedPostToAcquire = buildExpectedHistogramBytestring({1}, {1});
915 {
916 InSequence seq;
917 EXPECT_CALL(*mDelegate,
918 statsEventSetAtomId(mDelegate->mEvent,
919 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
920 EXPECT_CALL(*mDelegate,
921 statsEventWriteString8(mDelegate->mEvent,
922 StrEq(genLayerName(LAYER_ID_0).c_str())));
923 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 1));
924 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 0));
925 EXPECT_CALL(*mDelegate,
926 statsEventWriteByteArray(mDelegate->mEvent,
927 BytesEq((const uint8_t*)
928 expectedPresentToPresent.c_str(),
929 expectedPresentToPresent.size()),
930 expectedPresentToPresent.size()));
931 EXPECT_CALL(*mDelegate,
932 statsEventWriteByteArray(mDelegate->mEvent,
933 BytesEq((const uint8_t*)expectedPostToPresent.c_str(),
934 expectedPostToPresent.size()),
935 expectedPostToPresent.size()));
936 EXPECT_CALL(*mDelegate,
937 statsEventWriteByteArray(mDelegate->mEvent,
938 BytesEq((const uint8_t*)
939 expectedAcquireToPresent.c_str(),
940 expectedAcquireToPresent.size()),
941 expectedAcquireToPresent.size()));
942 EXPECT_CALL(*mDelegate,
943 statsEventWriteByteArray(mDelegate->mEvent,
944 BytesEq((const uint8_t*)expectedLatchToPresent.c_str(),
945 expectedLatchToPresent.size()),
946 expectedLatchToPresent.size()));
947 EXPECT_CALL(*mDelegate,
948 statsEventWriteByteArray(mDelegate->mEvent,
949 BytesEq((const uint8_t*)
950 expectedDesiredToPresent.c_str(),
951 expectedDesiredToPresent.size()),
952 expectedDesiredToPresent.size()));
953 EXPECT_CALL(*mDelegate,
954 statsEventWriteByteArray(mDelegate->mEvent,
955 BytesEq((const uint8_t*)expectedPostToAcquire.c_str(),
956 expectedPostToAcquire.size()),
957 expectedPostToAcquire.size()));
958 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
959 }
Tej Singh2a457b62020-01-31 16:16:10 -0800960 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -0800961 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
962 mDelegate->mCookie));
963
964 SFTimeStatsGlobalProto globalProto;
965 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
966
967 EXPECT_EQ(0, globalProto.stats_size());
968}
969
970TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleLayers) {
971 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
972
973 mTimeStats->onBootFinished();
974
975 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
976 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
977 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
978 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
979
980 EXPECT_THAT(mDelegate->mAtomTags,
981 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
982 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
983 EXPECT_NE(nullptr, mDelegate->mCallback);
984 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
985
986 EXPECT_CALL(*mDelegate,
987 statsEventSetAtomId(mDelegate->mEvent,
988 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
989 .Times(2);
990 EXPECT_CALL(*mDelegate,
991 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_0).c_str())));
992 EXPECT_CALL(*mDelegate,
993 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -0800994 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -0800995 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
996 mDelegate->mCookie));
997}
998
999TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleBuckets) {
1000 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1001
1002 mTimeStats->onBootFinished();
1003
1004 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1005 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1006 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1007 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1008
1009 // Now make sure that TimeStats flushes global stats to register the
1010 // callback.
1011 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
1012 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
1013 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
1014 EXPECT_THAT(mDelegate->mAtomTags,
1015 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1016 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1017 EXPECT_NE(nullptr, mDelegate->mCallback);
1018 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1019
1020 EXPECT_THAT(mDelegate->mAtomTags,
1021 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1022 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1023 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1, 2}, {2, 1});
1024 {
1025 InSequence seq;
1026 EXPECT_CALL(*mDelegate,
1027 statsEventWriteByteArray(mDelegate->mEvent,
1028 BytesEq((const uint8_t*)
1029 expectedPresentToPresent.c_str(),
1030 expectedPresentToPresent.size()),
1031 expectedPresentToPresent.size()));
1032 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1033 .Times(AnyNumber());
1034 }
Tej Singh2a457b62020-01-31 16:16:10 -08001035 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001036 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1037 mDelegate->mCookie));
1038}
1039
1040TEST_F(TimeStatsTest, layerStatsCallback_limitsHistogramBuckets) {
1041 mDelegate = new FakeStatsEventDelegate;
1042 mTimeStats =
1043 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
1044 std::nullopt, 1);
1045 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1046
1047 mTimeStats->onBootFinished();
1048
1049 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1050 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1051 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1052 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1053
1054 EXPECT_THAT(mDelegate->mAtomTags,
1055 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1056 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1057 EXPECT_NE(nullptr, mDelegate->mCallback);
1058 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1059
1060 EXPECT_THAT(mDelegate->mAtomTags,
1061 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1062 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1063 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {2});
1064 {
1065 InSequence seq;
1066 EXPECT_CALL(*mDelegate,
1067 statsEventWriteByteArray(mDelegate->mEvent,
1068 BytesEq((const uint8_t*)
1069 expectedPresentToPresent.c_str(),
1070 expectedPresentToPresent.size()),
1071 expectedPresentToPresent.size()));
1072 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1073 .Times(AnyNumber());
1074 }
Tej Singh2a457b62020-01-31 16:16:10 -08001075 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001076 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1077 mDelegate->mCookie));
1078}
1079
1080TEST_F(TimeStatsTest, layerStatsCallback_limitsLayers) {
1081 mDelegate = new FakeStatsEventDelegate;
1082 mTimeStats =
1083 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate), 1,
1084 std::nullopt);
1085 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1086
1087 mTimeStats->onBootFinished();
1088
1089 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1090 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1091 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1092 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1093 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 4, 5000000);
1094
1095 EXPECT_THAT(mDelegate->mAtomTags,
1096 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1097 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1098 EXPECT_NE(nullptr, mDelegate->mCallback);
1099 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1100
1101 EXPECT_CALL(*mDelegate,
1102 statsEventSetAtomId(mDelegate->mEvent,
1103 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1104 .Times(1);
1105 EXPECT_CALL(*mDelegate,
1106 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001107 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001108 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1109 mDelegate->mCookie));
1110}
1111
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001112TEST_F(TimeStatsTest, canSurviveMonkey) {
Lloyd Pique067fe1e2018-12-06 19:44:13 -08001113 if (g_noSlowTests) {
1114 GTEST_SKIP();
1115 }
1116
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001117 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1118
1119 for (size_t i = 0; i < 10000000; ++i) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001120 const int32_t layerId = genRandomInt32(-1, 10);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001121 const int32_t frameNumber = genRandomInt32(1, 10);
1122 switch (genRandomInt32(0, 100)) {
1123 case 0:
1124 ALOGV("removeTimeRecord");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001125 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(layerId, frameNumber));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001126 continue;
1127 case 1:
1128 ALOGV("onDestroy");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001129 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(layerId));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001130 continue;
1131 }
1132 TimeStamp type = static_cast<TimeStamp>(genRandomInt32(TIME_STAMP_BEGIN, TIME_STAMP_END));
1133 const int32_t ts = genRandomInt32(1, 1000000000);
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001134 ALOGV("type[%d], layerId[%d], frameNumber[%d], ts[%d]", type, layerId, frameNumber, ts);
1135 setTimeStamp(type, layerId, frameNumber, ts);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001136 }
1137}
1138
1139} // namespace
1140} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -08001141
1142// TODO(b/129481165): remove the #pragma below and fix conversion issues
1143#pragma clang diagnostic pop // ignored "-Wconversion"