blob: 1774c41e4b63b560013315553b8c82f8078067e9 [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;
40
41namespace android {
42namespace {
43
Alec Mouri8e2f31b2020-01-16 22:04:35 +000044using testing::_;
Alec Mouri37384342020-01-02 17:23:37 -080045using testing::AnyNumber;
Alec Mourifb571ea2019-01-24 18:42:10 -080046using testing::Contains;
Vishnu Nair9b079a22020-01-21 14:36:08 -080047using testing::HasSubstr;
Alec Mouri8e2f31b2020-01-16 22:04:35 +000048using testing::InSequence;
Alec Mourifb571ea2019-01-24 18:42:10 -080049using testing::SizeIs;
Alec Mouri37384342020-01-02 17:23:37 -080050using testing::StrEq;
Alec Mourifb571ea2019-01-24 18:42:10 -080051using testing::UnorderedElementsAre;
52
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080053// clang-format off
54#define FMT_PROTO true
55#define FMT_STRING false
56#define LAYER_ID_0 0
57#define LAYER_ID_1 1
58#define LAYER_ID_INVALID -1
59#define NUM_LAYERS 1
60#define NUM_LAYERS_INVALID "INVALID"
61
62enum InputCommand : int32_t {
63 ENABLE = 0,
64 DISABLE = 1,
65 CLEAR = 2,
66 DUMP_ALL = 3,
67 DUMP_MAXLAYERS_1 = 4,
68 DUMP_MAXLAYERS_INVALID = 5,
69 INPUT_COMMAND_BEGIN = ENABLE,
70 INPUT_COMMAND_END = DUMP_MAXLAYERS_INVALID,
71 INPUT_COMMAND_RANGE = INPUT_COMMAND_END - INPUT_COMMAND_BEGIN + 1,
72};
73
74enum TimeStamp : int32_t {
75 POST = 0,
76 ACQUIRE = 1,
77 ACQUIRE_FENCE = 2,
78 LATCH = 3,
79 DESIRED = 4,
80 PRESENT = 5,
81 PRESENT_FENCE = 6,
82 TIME_STAMP_BEGIN = POST,
83 TIME_STAMP_END = PRESENT,
84 TIME_STAMP_RANGE = TIME_STAMP_END - TIME_STAMP_BEGIN + 1,
85};
86
87static const TimeStamp NORMAL_SEQUENCE[] = {
88 TimeStamp::POST,
89 TimeStamp::ACQUIRE,
90 TimeStamp::LATCH,
91 TimeStamp::DESIRED,
92 TimeStamp::PRESENT,
93};
94
95static const TimeStamp NORMAL_SEQUENCE_2[] = {
96 TimeStamp::POST,
97 TimeStamp::ACQUIRE_FENCE,
98 TimeStamp::LATCH,
99 TimeStamp::DESIRED,
100 TimeStamp::PRESENT_FENCE,
101};
102
103static const TimeStamp UNORDERED_SEQUENCE[] = {
104 TimeStamp::ACQUIRE,
105 TimeStamp::LATCH,
106 TimeStamp::POST,
107 TimeStamp::DESIRED,
108 TimeStamp::PRESENT,
109};
110
111static const TimeStamp INCOMPLETE_SEQUENCE[] = {
112 TimeStamp::POST,
113};
114// clang-format on
115
116class TimeStatsTest : public testing::Test {
117public:
118 TimeStatsTest() {
119 const ::testing::TestInfo* const test_info =
120 ::testing::UnitTest::GetInstance()->current_test_info();
121 ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
122 }
123
124 ~TimeStatsTest() {
125 const ::testing::TestInfo* const test_info =
126 ::testing::UnitTest::GetInstance()->current_test_info();
127 ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
128 }
129
130 std::string inputCommand(InputCommand cmd, bool useProto);
131
132 void setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts);
133
134 int32_t genRandomInt32(int32_t begin, int32_t end);
135
136 template <size_t N>
137 void insertTimeRecord(const TimeStamp (&sequence)[N], int32_t id, uint64_t frameNumber,
138 nsecs_t ts) {
139 for (size_t i = 0; i < N; i++, ts += 1000000) {
140 setTimeStamp(sequence[i], id, frameNumber, ts);
141 }
142 }
143
144 std::mt19937 mRandomEngine = std::mt19937(std::random_device()());
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000145
146 class FakeStatsEventDelegate : public impl::TimeStats::StatsEventDelegate {
147 public:
148 FakeStatsEventDelegate() = default;
149 ~FakeStatsEventDelegate() override = default;
150
Tej Singh2a457b62020-01-31 16:16:10 -0800151 struct AStatsEvent* addStatsEventToPullData(AStatsEventList*) override {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000152 return mEvent;
153 }
Tej Singh2a457b62020-01-31 16:16:10 -0800154 void registerStatsPullAtomCallback(int32_t atom_tag,
155 AStatsManager_PullAtomCallback callback,
156 AStatsManager_PullAtomMetadata*, void* cookie) override {
Alec Mouri37384342020-01-02 17:23:37 -0800157 mAtomTags.push_back(atom_tag);
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000158 mCallback = callback;
159 mCookie = cookie;
160 }
161
Tej Singh2a457b62020-01-31 16:16:10 -0800162 AStatsManager_PullAtomCallbackReturn makePullAtomCallback(int32_t atom_tag, void* cookie) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000163 return (*mCallback)(atom_tag, nullptr, cookie);
164 }
165
166 MOCK_METHOD1(unregisterStatsPullAtomCallback, void(int32_t));
Tej Singh2a457b62020-01-31 16:16:10 -0800167 MOCK_METHOD2(statsEventSetAtomId, void(AStatsEvent*, uint32_t));
168 MOCK_METHOD2(statsEventWriteInt64, void(AStatsEvent*, int64_t));
169 MOCK_METHOD2(statsEventWriteString8, void(AStatsEvent*, const char*));
170 MOCK_METHOD3(statsEventWriteByteArray, void(AStatsEvent*, const uint8_t*, size_t));
171 MOCK_METHOD1(statsEventBuild, void(AStatsEvent*));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000172
Tej Singh2a457b62020-01-31 16:16:10 -0800173 AStatsEvent* mEvent = AStatsEvent_obtain();
Alec Mouri37384342020-01-02 17:23:37 -0800174 std::vector<int32_t> mAtomTags;
Tej Singh2a457b62020-01-31 16:16:10 -0800175 AStatsManager_PullAtomCallback mCallback = nullptr;
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000176 void* mCookie = nullptr;
177 };
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000178 FakeStatsEventDelegate* mDelegate = new FakeStatsEventDelegate;
179 std::unique_ptr<TimeStats> mTimeStats =
Alec Mouri37384342020-01-02 17:23:37 -0800180 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
181 std::nullopt, std::nullopt);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800182};
183
184std::string TimeStatsTest::inputCommand(InputCommand cmd, bool useProto) {
Yiwei Zhang5434a782018-12-05 18:06:32 -0800185 std::string result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800186 Vector<String16> args;
187
188 switch (cmd) {
189 case InputCommand::ENABLE:
190 args.push_back(String16("-enable"));
191 break;
192 case InputCommand::DISABLE:
193 args.push_back(String16("-disable"));
194 break;
195 case InputCommand::CLEAR:
196 args.push_back(String16("-clear"));
197 break;
198 case InputCommand::DUMP_ALL:
199 args.push_back(String16("-dump"));
200 break;
201 case InputCommand::DUMP_MAXLAYERS_1:
202 args.push_back(String16("-dump"));
203 args.push_back(String16("-maxlayers"));
204 args.push_back(String16(std::to_string(NUM_LAYERS).c_str()));
205 break;
206 case InputCommand::DUMP_MAXLAYERS_INVALID:
207 args.push_back(String16("-dump"));
208 args.push_back(String16("-maxlayers"));
209 args.push_back(String16(NUM_LAYERS_INVALID));
210 break;
211 default:
212 ALOGD("Invalid control command");
213 }
214
Dominik Laskowskic2867142019-01-21 11:33:38 -0800215 EXPECT_NO_FATAL_FAILURE(mTimeStats->parseArgs(useProto, args, result));
Yiwei Zhang5434a782018-12-05 18:06:32 -0800216 return result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800217}
218
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800219static std::string genLayerName(int32_t layerId) {
220 return (layerId < 0 ? "PopupWindow:b54fcd1#0" : "com.dummy#") + std::to_string(layerId);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800221}
222
223void TimeStatsTest::setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts) {
224 switch (type) {
225 case TimeStamp::POST:
226 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPostTime(id, frameNumber, genLayerName(id), ts));
227 break;
228 case TimeStamp::ACQUIRE:
229 ASSERT_NO_FATAL_FAILURE(mTimeStats->setAcquireTime(id, frameNumber, ts));
230 break;
231 case TimeStamp::ACQUIRE_FENCE:
232 ASSERT_NO_FATAL_FAILURE(
233 mTimeStats->setAcquireFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
234 break;
235 case TimeStamp::LATCH:
236 ASSERT_NO_FATAL_FAILURE(mTimeStats->setLatchTime(id, frameNumber, ts));
237 break;
238 case TimeStamp::DESIRED:
239 ASSERT_NO_FATAL_FAILURE(mTimeStats->setDesiredTime(id, frameNumber, ts));
240 break;
241 case TimeStamp::PRESENT:
242 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPresentTime(id, frameNumber, ts));
243 break;
244 case TimeStamp::PRESENT_FENCE:
245 ASSERT_NO_FATAL_FAILURE(
246 mTimeStats->setPresentFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
247 break;
248 default:
249 ALOGD("Invalid timestamp type");
250 }
251}
252
253int32_t TimeStatsTest::genRandomInt32(int32_t begin, int32_t end) {
254 std::uniform_int_distribution<int32_t> distr(begin, end);
255 return distr(mRandomEngine);
256}
257
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000258TEST_F(TimeStatsTest, disabledByDefault) {
259 ASSERT_FALSE(mTimeStats->isEnabled());
260}
261
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800262TEST_F(TimeStatsTest, registersCallbacksAfterBoot) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000263 mTimeStats->onBootFinished();
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800264 EXPECT_THAT(mDelegate->mAtomTags,
265 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
266 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
267}
268
269TEST_F(TimeStatsTest, unregistersCallbacksOnDestruction) {
270 EXPECT_CALL(*mDelegate,
271 unregisterStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
272 EXPECT_CALL(*mDelegate,
273 unregisterStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO));
274 mTimeStats.reset();
Alec Mourib3885ad2019-09-06 17:08:55 -0700275}
276
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800277TEST_F(TimeStatsTest, canEnableAndDisableTimeStats) {
278 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
279 ASSERT_TRUE(mTimeStats->isEnabled());
280
281 EXPECT_TRUE(inputCommand(InputCommand::DISABLE, FMT_STRING).empty());
282 ASSERT_FALSE(mTimeStats->isEnabled());
283}
284
285TEST_F(TimeStatsTest, canIncreaseGlobalStats) {
286 constexpr size_t TOTAL_FRAMES = 5;
287 constexpr size_t MISSED_FRAMES = 4;
288 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
289
290 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
291
292 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
293 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
294 }
295 for (size_t i = 0; i < MISSED_FRAMES; i++) {
296 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
297 }
298 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
299 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
300 }
301
302 SFTimeStatsGlobalProto globalProto;
303 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
304
305 ASSERT_TRUE(globalProto.has_total_frames());
306 EXPECT_EQ(TOTAL_FRAMES, globalProto.total_frames());
307 ASSERT_TRUE(globalProto.has_missed_frames());
308 EXPECT_EQ(MISSED_FRAMES, globalProto.missed_frames());
309 ASSERT_TRUE(globalProto.has_client_composition_frames());
310 EXPECT_EQ(CLIENT_COMPOSITION_FRAMES, globalProto.client_composition_frames());
311}
312
Alec Mouri91f6df32020-01-30 08:48:58 -0800313TEST_F(TimeStatsTest, canIncreaseLateAcquireFrames) {
314 // this stat is not in the proto so verify by checking the string dump
315 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
316
317 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
318
319 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
320 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
321 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
322 }
323 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
324
325 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
326 const std::string expectedResult = "lateAcquireFrames = " + std::to_string(LATE_ACQUIRE_FRAMES);
327 EXPECT_THAT(result, HasSubstr(expectedResult));
328}
329
330TEST_F(TimeStatsTest, canIncreaseBadDesiredPresent) {
331 // this stat is not in the proto so verify by checking the string dump
332 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 2;
333
334 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
335
336 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
337 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
338 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
339 }
340 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
341
342 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
343 const std::string expectedResult =
344 "badDesiredPresentFrames = " + std::to_string(BAD_DESIRED_PRESENT_FRAMES);
345 EXPECT_THAT(result, HasSubstr(expectedResult));
346}
347
Vishnu Nair9b079a22020-01-21 14:36:08 -0800348TEST_F(TimeStatsTest, canIncreaseClientCompositionReusedFrames) {
349 // this stat is not in the proto so verify by checking the string dump
350 constexpr size_t CLIENT_COMPOSITION_REUSED_FRAMES = 2;
351
352 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
353 for (size_t i = 0; i < CLIENT_COMPOSITION_REUSED_FRAMES; i++) {
354 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
355 }
356
357 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
358 const std::string expectedResult =
359 "clientCompositionReusedFrames = " + std::to_string(CLIENT_COMPOSITION_REUSED_FRAMES);
360 EXPECT_THAT(result, HasSubstr(expectedResult));
361}
362
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800363TEST_F(TimeStatsTest, canInsertGlobalPresentToPresent) {
364 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
365
366 ASSERT_NO_FATAL_FAILURE(
367 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
368 ASSERT_NO_FATAL_FAILURE(
369 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
370
371 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL));
372 ASSERT_NO_FATAL_FAILURE(
373 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000)));
374 ASSERT_NO_FATAL_FAILURE(
375 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000)));
376
377 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_OFF));
378 ASSERT_NO_FATAL_FAILURE(
379 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(6000000)));
380 ASSERT_NO_FATAL_FAILURE(
381 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(8000000)));
382
383 SFTimeStatsGlobalProto globalProto;
384 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
385
386 ASSERT_EQ(1, globalProto.present_to_present_size());
387 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.present_to_present().Get(0);
388 EXPECT_EQ(1, histogramProto.frame_count());
389 EXPECT_EQ(2, histogramProto.time_millis());
390}
391
Alec Mouri9519bf12019-11-15 16:54:44 -0800392TEST_F(TimeStatsTest, canInsertGlobalFrameDuration) {
393 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
394
395 using namespace std::chrono_literals;
396
397 mTimeStats->setPowerMode(HWC_POWER_MODE_OFF);
398 mTimeStats
399 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
400 std::chrono::duration_cast<std::chrono::nanoseconds>(5ms)
401 .count());
402 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
403 mTimeStats
404 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
405 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
406 .count());
407
408 SFTimeStatsGlobalProto globalProto;
409 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
410
411 ASSERT_EQ(1, globalProto.frame_duration_size());
412 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.frame_duration().Get(0);
413 EXPECT_EQ(1, histogramProto.frame_count());
414 EXPECT_EQ(3, histogramProto.time_millis());
415}
416
Alec Mourie4034bb2019-11-19 12:45:54 -0800417TEST_F(TimeStatsTest, canInsertGlobalRenderEngineTiming) {
418 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
419
420 using namespace std::chrono_literals;
421
422 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms)
423 .count(),
424 std::make_shared<FenceTime>(
425 std::chrono::duration_cast<
426 std::chrono::nanoseconds>(3ms)
427 .count()));
428
429 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
430 .count(),
431 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
432 .count());
433
434 // First verify that flushing RenderEngine durations did not occur yet.
435 SFTimeStatsGlobalProto preFlushProto;
436 ASSERT_TRUE(preFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
437 ASSERT_EQ(0, preFlushProto.render_engine_timing_size());
438
439 // Push a dummy present fence to trigger flushing the RenderEngine timings.
440 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
441 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
442 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
443
444 // Now we can verify that RenderEngine durations were flushed now.
445 SFTimeStatsGlobalProto postFlushProto;
446 ASSERT_TRUE(postFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
447
448 ASSERT_EQ(1, postFlushProto.render_engine_timing_size());
449 const SFTimeStatsHistogramBucketProto& histogramProto =
450 postFlushProto.render_engine_timing().Get(0);
451 EXPECT_EQ(2, histogramProto.frame_count());
452 EXPECT_EQ(2, histogramProto.time_millis());
453}
454
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800455TEST_F(TimeStatsTest, canInsertOneLayerTimeStats) {
456 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
457
458 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
459 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
460
461 SFTimeStatsGlobalProto globalProto;
462 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
463
464 ASSERT_EQ(1, globalProto.stats_size());
465 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
466 ASSERT_TRUE(layerProto.has_layer_name());
467 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
468 ASSERT_TRUE(layerProto.has_total_frames());
469 EXPECT_EQ(1, layerProto.total_frames());
470 ASSERT_EQ(6, layerProto.deltas_size());
471 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
472 ASSERT_EQ(1, deltaProto.histograms_size());
473 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
474 EXPECT_EQ(1, histogramProto.frame_count());
475 if ("post2acquire" == deltaProto.delta_name()) {
476 EXPECT_EQ(1, histogramProto.time_millis());
477 } else if ("post2present" == deltaProto.delta_name()) {
478 EXPECT_EQ(4, histogramProto.time_millis());
479 } else if ("acquire2present" == deltaProto.delta_name()) {
480 EXPECT_EQ(3, histogramProto.time_millis());
481 } else if ("latch2present" == deltaProto.delta_name()) {
482 EXPECT_EQ(2, histogramProto.time_millis());
483 } else if ("desired2present" == deltaProto.delta_name()) {
484 EXPECT_EQ(1, histogramProto.time_millis());
485 } else if ("present2present" == deltaProto.delta_name()) {
486 EXPECT_EQ(1, histogramProto.time_millis());
487 } else {
488 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
489 }
490 }
491}
492
493TEST_F(TimeStatsTest, canNotInsertInvalidLayerNameTimeStats) {
494 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
495
496 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_INVALID, 1, 1000000);
497 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_INVALID, 2, 2000000);
498
499 SFTimeStatsGlobalProto globalProto;
500 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
501
502 ASSERT_EQ(0, globalProto.stats_size());
503}
504
505TEST_F(TimeStatsTest, canInsertMultipleLayersTimeStats) {
506 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
507
508 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
509 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
510 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
511 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
512
513 SFTimeStatsGlobalProto globalProto;
514 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
515
516 EXPECT_EQ(2, globalProto.stats_size());
517}
518
519TEST_F(TimeStatsTest, canInsertUnorderedLayerTimeStats) {
520 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
521
522 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
523 insertTimeRecord(UNORDERED_SEQUENCE, LAYER_ID_0, 2, 2000000);
524
525 SFTimeStatsGlobalProto globalProto;
526 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
527
528 ASSERT_EQ(1, globalProto.stats_size());
529 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
530 ASSERT_TRUE(layerProto.has_layer_name());
531 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
532 ASSERT_TRUE(layerProto.has_total_frames());
533 EXPECT_EQ(1, layerProto.total_frames());
534 ASSERT_EQ(6, layerProto.deltas_size());
535 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
536 ASSERT_EQ(1, deltaProto.histograms_size());
537 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
538 EXPECT_EQ(1, histogramProto.frame_count());
539 if ("post2acquire" == deltaProto.delta_name()) {
540 EXPECT_EQ(0, histogramProto.time_millis());
541 } else if ("post2present" == deltaProto.delta_name()) {
542 EXPECT_EQ(2, histogramProto.time_millis());
543 } else if ("acquire2present" == deltaProto.delta_name()) {
544 EXPECT_EQ(2, histogramProto.time_millis());
545 } else if ("latch2present" == deltaProto.delta_name()) {
546 EXPECT_EQ(2, histogramProto.time_millis());
547 } else if ("desired2present" == deltaProto.delta_name()) {
548 EXPECT_EQ(1, histogramProto.time_millis());
549 } else if ("present2present" == deltaProto.delta_name()) {
550 EXPECT_EQ(1, histogramProto.time_millis());
551 } else {
552 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
553 }
554 }
555}
556
Alec Mourifb571ea2019-01-24 18:42:10 -0800557TEST_F(TimeStatsTest, recordRefreshRateNewConfigs) {
558 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
559
560 uint32_t fpsOne = 30;
561 uint32_t fpsTwo = 90;
562 uint64_t millisOne = 5000;
563 uint64_t millisTwo = 7000;
564
565 mTimeStats->recordRefreshRate(fpsOne, ms2ns(millisOne));
566 mTimeStats->recordRefreshRate(fpsTwo, ms2ns(millisTwo));
567
568 SFTimeStatsGlobalProto globalProto;
569 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
570
571 SFTimeStatsDisplayConfigBucketProto expectedBucketOne;
572 SFTimeStatsDisplayConfigProto* expectedConfigOne = expectedBucketOne.mutable_config();
573 expectedConfigOne->set_fps(fpsOne);
574 expectedBucketOne.set_duration_millis(millisOne);
575
576 SFTimeStatsDisplayConfigBucketProto expectedBucketTwo;
577 SFTimeStatsDisplayConfigProto* expectedConfigTwo = expectedBucketTwo.mutable_config();
578 expectedConfigTwo->set_fps(fpsTwo);
579 expectedBucketTwo.set_duration_millis(millisTwo);
580
581 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(2));
582
583 std::unordered_set<uint32_t> seen_fps;
584 for (const auto& bucket : globalProto.display_config_stats()) {
585 seen_fps.emplace(bucket.config().fps());
586 if (fpsOne == bucket.config().fps()) {
587 EXPECT_EQ(millisOne, bucket.duration_millis());
588 } else if (fpsTwo == bucket.config().fps()) {
589 EXPECT_EQ(millisTwo, bucket.duration_millis());
590 } else {
591 FAIL() << "Unknown fps: " << bucket.config().fps();
592 }
593 }
594 EXPECT_THAT(seen_fps, UnorderedElementsAre(fpsOne, fpsTwo));
595}
596
597TEST_F(TimeStatsTest, recordRefreshRateUpdatesConfig) {
598 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
599
600 uint32_t fps = 30;
601 uint64_t millisOne = 5000;
602 uint64_t millisTwo = 7000;
603
604 mTimeStats->recordRefreshRate(fps, ms2ns(millisOne));
605 mTimeStats->recordRefreshRate(fps, ms2ns(millisTwo));
606
607 SFTimeStatsGlobalProto globalProto;
608 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
609 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(1));
610 EXPECT_EQ(fps, globalProto.display_config_stats().Get(0).config().fps());
611 EXPECT_EQ(millisOne + millisTwo, globalProto.display_config_stats().Get(0).duration_millis());
612}
613
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800614TEST_F(TimeStatsTest, canRemoveTimeRecord) {
615 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
616
617 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
618 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 2, 2000000);
619 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(0, 2));
620 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
621
622 SFTimeStatsGlobalProto globalProto;
623 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
624
625 ASSERT_EQ(1, globalProto.stats_size());
626 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
627 ASSERT_TRUE(layerProto.has_total_frames());
628 EXPECT_EQ(1, layerProto.total_frames());
629}
630
631TEST_F(TimeStatsTest, canRecoverFromIncompleteTimeRecordError) {
632 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
633
634 uint64_t frameNumber = 1;
635 nsecs_t ts = 1000000;
636 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 1, 1000000);
Alec Mourifb571ea2019-01-24 18:42:10 -0800637 for (size_t i = 0; i < impl::TimeStats::MAX_NUM_TIME_RECORDS + 2; i++) {
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800638 frameNumber++;
639 ts += 1000000;
640 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, frameNumber, ts);
641 }
642
643 SFTimeStatsGlobalProto globalProto;
644 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
645
646 ASSERT_EQ(1, globalProto.stats_size());
647 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
648 ASSERT_TRUE(layerProto.has_total_frames());
649 EXPECT_EQ(1, layerProto.total_frames());
650}
651
652TEST_F(TimeStatsTest, layerTimeStatsOnDestroy) {
653 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
654
655 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
656 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
657 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(0));
658 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
659
660 SFTimeStatsGlobalProto globalProto;
661 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
662
663 ASSERT_EQ(1, globalProto.stats_size());
664 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
665 ASSERT_TRUE(layerProto.has_total_frames());
666 EXPECT_EQ(1, layerProto.total_frames());
667}
668
669TEST_F(TimeStatsTest, canClearTimeStats) {
670 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
671
672 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
673 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
674 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
675 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL));
Alec Mouri31ac64a2020-01-09 09:26:22 -0800676
677 using namespace std::chrono_literals;
678 mTimeStats
679 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
680 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
681 .count());
682 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
683 .count(),
684 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
685 .count());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800686 ASSERT_NO_FATAL_FAILURE(
687 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
688 ASSERT_NO_FATAL_FAILURE(
689 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
690 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
691 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
692
693 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
694
695 SFTimeStatsGlobalProto globalProto;
696 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
697
698 EXPECT_EQ(0, globalProto.total_frames());
699 EXPECT_EQ(0, globalProto.missed_frames());
700 EXPECT_EQ(0, globalProto.client_composition_frames());
701 EXPECT_EQ(0, globalProto.present_to_present_size());
Alec Mouri31ac64a2020-01-09 09:26:22 -0800702 EXPECT_EQ(0, globalProto.frame_duration_size());
703 EXPECT_EQ(0, globalProto.render_engine_timing_size());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800704 EXPECT_EQ(0, globalProto.stats_size());
705}
706
Alec Mouri91f6df32020-01-30 08:48:58 -0800707TEST_F(TimeStatsTest, canClearClientCompositionReusedFrames) {
Vishnu Nair9b079a22020-01-21 14:36:08 -0800708 // this stat is not in the proto so verify by checking the string dump
709 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
710 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
711 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
712
713 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
714 EXPECT_THAT(result, HasSubstr("clientCompositionReusedFrames = 0"));
715}
716
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800717TEST_F(TimeStatsTest, canDumpWithMaxLayers) {
718 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
719
720 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
721 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
722 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
723 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
724 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 3, 2000000);
725
726 SFTimeStatsGlobalProto globalProto;
727 ASSERT_TRUE(
728 globalProto.ParseFromString(inputCommand(InputCommand::DUMP_MAXLAYERS_1, FMT_PROTO)));
729
730 ASSERT_EQ(1, globalProto.stats_size());
731 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
732 ASSERT_TRUE(layerProto.has_layer_name());
733 EXPECT_EQ(genLayerName(LAYER_ID_1), layerProto.layer_name());
734 ASSERT_TRUE(layerProto.has_total_frames());
735 EXPECT_EQ(2, layerProto.total_frames());
736}
737
738TEST_F(TimeStatsTest, canDumpWithInvalidMaxLayers) {
739 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
740
741 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
742 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
743
744 SFTimeStatsGlobalProto globalProto;
745 ASSERT_TRUE(globalProto.ParseFromString(
746 inputCommand(InputCommand::DUMP_MAXLAYERS_INVALID, FMT_PROTO)));
747
748 ASSERT_EQ(0, globalProto.stats_size());
749}
750
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000751TEST_F(TimeStatsTest, globalStatsCallback) {
752 constexpr size_t TOTAL_FRAMES = 5;
753 constexpr size_t MISSED_FRAMES = 4;
754 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
755
756 mTimeStats->onBootFinished();
757 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
758
759 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
760 mTimeStats->incrementTotalFrames();
761 }
762 for (size_t i = 0; i < MISSED_FRAMES; i++) {
763 mTimeStats->incrementMissedFrames();
764 }
765 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
766 mTimeStats->incrementClientCompositionFrames();
767 }
768
769 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
770 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
771 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
772
Alec Mouri37384342020-01-02 17:23:37 -0800773 EXPECT_THAT(mDelegate->mAtomTags,
774 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
775 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000776 EXPECT_NE(nullptr, mDelegate->mCallback);
777 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
778
779 {
780 InSequence seq;
781 EXPECT_CALL(*mDelegate,
782 statsEventSetAtomId(mDelegate->mEvent,
783 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
784 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, TOTAL_FRAMES));
785 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, MISSED_FRAMES));
786 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, CLIENT_COMPOSITION_FRAMES));
787 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, _));
788 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 2));
789 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
790 }
Tej Singh2a457b62020-01-31 16:16:10 -0800791 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -0800792 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
793 mDelegate->mCookie));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000794
795 SFTimeStatsGlobalProto globalProto;
796 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
797
798 EXPECT_EQ(0, globalProto.total_frames());
799 EXPECT_EQ(0, globalProto.missed_frames());
800 EXPECT_EQ(0, globalProto.client_composition_frames());
801 EXPECT_EQ(0, globalProto.present_to_present_size());
802}
803
Alec Mouri37384342020-01-02 17:23:37 -0800804namespace {
805std::string buildExpectedHistogramBytestring(const std::vector<int32_t>& times,
806 const std::vector<int32_t>& frameCounts) {
807 util::ProtoOutputStream proto;
808 for (int i = 0; i < times.size(); i++) {
809 ALOGE("Writing time: %d", times[i]);
810 proto.write(util::FIELD_TYPE_INT32 | util::FIELD_COUNT_REPEATED | 1 /* field id */,
811 (int32_t)times[i]);
812 ALOGE("Writing count: %d", frameCounts[i]);
813 proto.write(util::FIELD_TYPE_INT64 | util::FIELD_COUNT_REPEATED | 2 /* field id */,
814 (int64_t)frameCounts[i]);
815 }
816 std::string byteString;
817 proto.serializeToString(&byteString);
818 return byteString;
819}
820
821std::string dumpByteStringHex(const std::string& str) {
822 std::stringstream ss;
823 ss << std::hex;
824 for (const char& c : str) {
825 ss << (int)c << " ";
826 }
827
828 return ss.str();
829}
830
831} // namespace
832
833MATCHER_P2(BytesEq, bytes, size, "") {
834 std::string expected;
835 expected.append((const char*)bytes, size);
836 std::string actual;
837 actual.append((const char*)arg, size);
838
839 *result_listener << "Bytes are not equal! \n";
840 *result_listener << "size: " << size << "\n";
841 *result_listener << "expected: " << dumpByteStringHex(expected).c_str() << "\n";
842 *result_listener << "actual: " << dumpByteStringHex(actual).c_str() << "\n";
843
844 return expected == actual;
845}
846
847TEST_F(TimeStatsTest, layerStatsCallback_pullsAllHistogramsAndClears) {
848 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
849
850 mTimeStats->onBootFinished();
851
852 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
853 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
854
855 EXPECT_THAT(mDelegate->mAtomTags,
856 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
857 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
858 EXPECT_NE(nullptr, mDelegate->mCallback);
859 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
860
861 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {1});
862 std::string expectedPostToPresent = buildExpectedHistogramBytestring({4}, {1});
863 std::string expectedAcquireToPresent = buildExpectedHistogramBytestring({3}, {1});
864 std::string expectedLatchToPresent = buildExpectedHistogramBytestring({2}, {1});
865 std::string expectedDesiredToPresent = buildExpectedHistogramBytestring({1}, {1});
866 std::string expectedPostToAcquire = buildExpectedHistogramBytestring({1}, {1});
867 {
868 InSequence seq;
869 EXPECT_CALL(*mDelegate,
870 statsEventSetAtomId(mDelegate->mEvent,
871 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
872 EXPECT_CALL(*mDelegate,
873 statsEventWriteString8(mDelegate->mEvent,
874 StrEq(genLayerName(LAYER_ID_0).c_str())));
875 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 1));
876 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 0));
877 EXPECT_CALL(*mDelegate,
878 statsEventWriteByteArray(mDelegate->mEvent,
879 BytesEq((const uint8_t*)
880 expectedPresentToPresent.c_str(),
881 expectedPresentToPresent.size()),
882 expectedPresentToPresent.size()));
883 EXPECT_CALL(*mDelegate,
884 statsEventWriteByteArray(mDelegate->mEvent,
885 BytesEq((const uint8_t*)expectedPostToPresent.c_str(),
886 expectedPostToPresent.size()),
887 expectedPostToPresent.size()));
888 EXPECT_CALL(*mDelegate,
889 statsEventWriteByteArray(mDelegate->mEvent,
890 BytesEq((const uint8_t*)
891 expectedAcquireToPresent.c_str(),
892 expectedAcquireToPresent.size()),
893 expectedAcquireToPresent.size()));
894 EXPECT_CALL(*mDelegate,
895 statsEventWriteByteArray(mDelegate->mEvent,
896 BytesEq((const uint8_t*)expectedLatchToPresent.c_str(),
897 expectedLatchToPresent.size()),
898 expectedLatchToPresent.size()));
899 EXPECT_CALL(*mDelegate,
900 statsEventWriteByteArray(mDelegate->mEvent,
901 BytesEq((const uint8_t*)
902 expectedDesiredToPresent.c_str(),
903 expectedDesiredToPresent.size()),
904 expectedDesiredToPresent.size()));
905 EXPECT_CALL(*mDelegate,
906 statsEventWriteByteArray(mDelegate->mEvent,
907 BytesEq((const uint8_t*)expectedPostToAcquire.c_str(),
908 expectedPostToAcquire.size()),
909 expectedPostToAcquire.size()));
910 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
911 }
Tej Singh2a457b62020-01-31 16:16:10 -0800912 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -0800913 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
914 mDelegate->mCookie));
915
916 SFTimeStatsGlobalProto globalProto;
917 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
918
919 EXPECT_EQ(0, globalProto.stats_size());
920}
921
922TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleLayers) {
923 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
924
925 mTimeStats->onBootFinished();
926
927 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
928 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
929 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
930 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
931
932 EXPECT_THAT(mDelegate->mAtomTags,
933 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
934 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
935 EXPECT_NE(nullptr, mDelegate->mCallback);
936 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
937
938 EXPECT_CALL(*mDelegate,
939 statsEventSetAtomId(mDelegate->mEvent,
940 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
941 .Times(2);
942 EXPECT_CALL(*mDelegate,
943 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_0).c_str())));
944 EXPECT_CALL(*mDelegate,
945 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -0800946 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -0800947 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
948 mDelegate->mCookie));
949}
950
951TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleBuckets) {
952 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
953
954 mTimeStats->onBootFinished();
955
956 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
957 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
958 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
959 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
960
961 // Now make sure that TimeStats flushes global stats to register the
962 // callback.
963 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
964 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
965 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
966 EXPECT_THAT(mDelegate->mAtomTags,
967 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
968 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
969 EXPECT_NE(nullptr, mDelegate->mCallback);
970 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
971
972 EXPECT_THAT(mDelegate->mAtomTags,
973 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
974 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
975 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1, 2}, {2, 1});
976 {
977 InSequence seq;
978 EXPECT_CALL(*mDelegate,
979 statsEventWriteByteArray(mDelegate->mEvent,
980 BytesEq((const uint8_t*)
981 expectedPresentToPresent.c_str(),
982 expectedPresentToPresent.size()),
983 expectedPresentToPresent.size()));
984 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
985 .Times(AnyNumber());
986 }
Tej Singh2a457b62020-01-31 16:16:10 -0800987 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -0800988 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
989 mDelegate->mCookie));
990}
991
992TEST_F(TimeStatsTest, layerStatsCallback_limitsHistogramBuckets) {
993 mDelegate = new FakeStatsEventDelegate;
994 mTimeStats =
995 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
996 std::nullopt, 1);
997 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
998
999 mTimeStats->onBootFinished();
1000
1001 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1002 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1003 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1004 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1005
1006 EXPECT_THAT(mDelegate->mAtomTags,
1007 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1008 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1009 EXPECT_NE(nullptr, mDelegate->mCallback);
1010 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1011
1012 EXPECT_THAT(mDelegate->mAtomTags,
1013 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1014 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1015 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {2});
1016 {
1017 InSequence seq;
1018 EXPECT_CALL(*mDelegate,
1019 statsEventWriteByteArray(mDelegate->mEvent,
1020 BytesEq((const uint8_t*)
1021 expectedPresentToPresent.c_str(),
1022 expectedPresentToPresent.size()),
1023 expectedPresentToPresent.size()));
1024 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1025 .Times(AnyNumber());
1026 }
Tej Singh2a457b62020-01-31 16:16:10 -08001027 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001028 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1029 mDelegate->mCookie));
1030}
1031
1032TEST_F(TimeStatsTest, layerStatsCallback_limitsLayers) {
1033 mDelegate = new FakeStatsEventDelegate;
1034 mTimeStats =
1035 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate), 1,
1036 std::nullopt);
1037 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1038
1039 mTimeStats->onBootFinished();
1040
1041 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1042 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1043 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1044 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1045 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 4, 5000000);
1046
1047 EXPECT_THAT(mDelegate->mAtomTags,
1048 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1049 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1050 EXPECT_NE(nullptr, mDelegate->mCallback);
1051 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1052
1053 EXPECT_CALL(*mDelegate,
1054 statsEventSetAtomId(mDelegate->mEvent,
1055 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1056 .Times(1);
1057 EXPECT_CALL(*mDelegate,
1058 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001059 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001060 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1061 mDelegate->mCookie));
1062}
1063
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001064TEST_F(TimeStatsTest, canSurviveMonkey) {
Lloyd Pique067fe1e2018-12-06 19:44:13 -08001065 if (g_noSlowTests) {
1066 GTEST_SKIP();
1067 }
1068
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001069 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1070
1071 for (size_t i = 0; i < 10000000; ++i) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001072 const int32_t layerId = genRandomInt32(-1, 10);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001073 const int32_t frameNumber = genRandomInt32(1, 10);
1074 switch (genRandomInt32(0, 100)) {
1075 case 0:
1076 ALOGV("removeTimeRecord");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001077 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(layerId, frameNumber));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001078 continue;
1079 case 1:
1080 ALOGV("onDestroy");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001081 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(layerId));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001082 continue;
1083 }
1084 TimeStamp type = static_cast<TimeStamp>(genRandomInt32(TIME_STAMP_BEGIN, TIME_STAMP_END));
1085 const int32_t ts = genRandomInt32(1, 1000000000);
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001086 ALOGV("type[%d], layerId[%d], frameNumber[%d], ts[%d]", type, layerId, frameNumber, ts);
1087 setTimeStamp(type, layerId, frameNumber, ts);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001088 }
1089}
1090
1091} // namespace
1092} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -08001093
1094// TODO(b/129481165): remove the #pragma below and fix conversion issues
1095#pragma clang diagnostic pop // ignored "-Wconversion"