blob: c667080b41bb6512827d2033199ac29e0b09f0d2 [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 Mourifb571ea2019-01-24 18:42:10 -080025#include <gmock/gmock.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080026#include <gtest/gtest.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080027#include <log/log.h>
28#include <utils/String16.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080029#include <utils/Vector.h>
30
Alec Mouri9519bf12019-11-15 16:54:44 -080031#include <chrono>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080032#include <random>
Alec Mourifb571ea2019-01-24 18:42:10 -080033#include <unordered_set>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080034
Lloyd Pique067fe1e2018-12-06 19:44:13 -080035#include "libsurfaceflinger_unittest_main.h"
36
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080037using namespace android::surfaceflinger;
38using namespace google::protobuf;
39
40namespace android {
41namespace {
42
Alec Mouri8e2f31b2020-01-16 22:04:35 +000043using testing::_;
Alec Mourifb571ea2019-01-24 18:42:10 -080044using testing::Contains;
Alec Mouri8e2f31b2020-01-16 22:04:35 +000045using testing::InSequence;
Alec Mourifb571ea2019-01-24 18:42:10 -080046using testing::SizeIs;
47using testing::UnorderedElementsAre;
48
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080049// clang-format off
50#define FMT_PROTO true
51#define FMT_STRING false
52#define LAYER_ID_0 0
53#define LAYER_ID_1 1
54#define LAYER_ID_INVALID -1
55#define NUM_LAYERS 1
56#define NUM_LAYERS_INVALID "INVALID"
57
58enum InputCommand : int32_t {
59 ENABLE = 0,
60 DISABLE = 1,
61 CLEAR = 2,
62 DUMP_ALL = 3,
63 DUMP_MAXLAYERS_1 = 4,
64 DUMP_MAXLAYERS_INVALID = 5,
65 INPUT_COMMAND_BEGIN = ENABLE,
66 INPUT_COMMAND_END = DUMP_MAXLAYERS_INVALID,
67 INPUT_COMMAND_RANGE = INPUT_COMMAND_END - INPUT_COMMAND_BEGIN + 1,
68};
69
70enum TimeStamp : int32_t {
71 POST = 0,
72 ACQUIRE = 1,
73 ACQUIRE_FENCE = 2,
74 LATCH = 3,
75 DESIRED = 4,
76 PRESENT = 5,
77 PRESENT_FENCE = 6,
78 TIME_STAMP_BEGIN = POST,
79 TIME_STAMP_END = PRESENT,
80 TIME_STAMP_RANGE = TIME_STAMP_END - TIME_STAMP_BEGIN + 1,
81};
82
83static const TimeStamp NORMAL_SEQUENCE[] = {
84 TimeStamp::POST,
85 TimeStamp::ACQUIRE,
86 TimeStamp::LATCH,
87 TimeStamp::DESIRED,
88 TimeStamp::PRESENT,
89};
90
91static const TimeStamp NORMAL_SEQUENCE_2[] = {
92 TimeStamp::POST,
93 TimeStamp::ACQUIRE_FENCE,
94 TimeStamp::LATCH,
95 TimeStamp::DESIRED,
96 TimeStamp::PRESENT_FENCE,
97};
98
99static const TimeStamp UNORDERED_SEQUENCE[] = {
100 TimeStamp::ACQUIRE,
101 TimeStamp::LATCH,
102 TimeStamp::POST,
103 TimeStamp::DESIRED,
104 TimeStamp::PRESENT,
105};
106
107static const TimeStamp INCOMPLETE_SEQUENCE[] = {
108 TimeStamp::POST,
109};
110// clang-format on
111
112class TimeStatsTest : public testing::Test {
113public:
114 TimeStatsTest() {
115 const ::testing::TestInfo* const test_info =
116 ::testing::UnitTest::GetInstance()->current_test_info();
117 ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
118 }
119
120 ~TimeStatsTest() {
121 const ::testing::TestInfo* const test_info =
122 ::testing::UnitTest::GetInstance()->current_test_info();
123 ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
124 }
125
126 std::string inputCommand(InputCommand cmd, bool useProto);
127
128 void setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts);
129
130 int32_t genRandomInt32(int32_t begin, int32_t end);
131
132 template <size_t N>
133 void insertTimeRecord(const TimeStamp (&sequence)[N], int32_t id, uint64_t frameNumber,
134 nsecs_t ts) {
135 for (size_t i = 0; i < N; i++, ts += 1000000) {
136 setTimeStamp(sequence[i], id, frameNumber, ts);
137 }
138 }
139
140 std::mt19937 mRandomEngine = std::mt19937(std::random_device()());
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000141
142 class FakeStatsEventDelegate : public impl::TimeStats::StatsEventDelegate {
143 public:
144 FakeStatsEventDelegate() = default;
145 ~FakeStatsEventDelegate() override = default;
146
147 struct stats_event* addStatsEventToPullData(pulled_stats_event_list*) override {
148 return mEvent;
149 }
150 void registerStatsPullAtomCallback(int32_t atom_tag, stats_pull_atom_callback_t callback,
151 pull_atom_metadata*, void* cookie) override {
152 mAtomTag = atom_tag;
153 mCallback = callback;
154 mCookie = cookie;
155 }
156
157 status_pull_atom_return_t makePullAtomCallback(int32_t atom_tag, void* cookie) {
158 return (*mCallback)(atom_tag, nullptr, cookie);
159 }
160
161 MOCK_METHOD1(unregisterStatsPullAtomCallback, void(int32_t));
162 MOCK_METHOD2(statsEventSetAtomId, void(struct stats_event*, uint32_t));
163 MOCK_METHOD2(statsEventWriteInt64, void(struct stats_event*, int64_t));
164 MOCK_METHOD1(statsEventBuild, void(struct stats_event*));
165
166 struct stats_event* mEvent = stats_event_obtain();
167 int32_t mAtomTag = 0;
168 stats_pull_atom_callback_t mCallback = nullptr;
169 void* mCookie = nullptr;
170 };
171
172 FakeStatsEventDelegate* mDelegate = new FakeStatsEventDelegate;
173 std::unique_ptr<TimeStats> mTimeStats =
174 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800175};
176
177std::string TimeStatsTest::inputCommand(InputCommand cmd, bool useProto) {
Yiwei Zhang5434a782018-12-05 18:06:32 -0800178 std::string result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800179 Vector<String16> args;
180
181 switch (cmd) {
182 case InputCommand::ENABLE:
183 args.push_back(String16("-enable"));
184 break;
185 case InputCommand::DISABLE:
186 args.push_back(String16("-disable"));
187 break;
188 case InputCommand::CLEAR:
189 args.push_back(String16("-clear"));
190 break;
191 case InputCommand::DUMP_ALL:
192 args.push_back(String16("-dump"));
193 break;
194 case InputCommand::DUMP_MAXLAYERS_1:
195 args.push_back(String16("-dump"));
196 args.push_back(String16("-maxlayers"));
197 args.push_back(String16(std::to_string(NUM_LAYERS).c_str()));
198 break;
199 case InputCommand::DUMP_MAXLAYERS_INVALID:
200 args.push_back(String16("-dump"));
201 args.push_back(String16("-maxlayers"));
202 args.push_back(String16(NUM_LAYERS_INVALID));
203 break;
204 default:
205 ALOGD("Invalid control command");
206 }
207
Dominik Laskowskic2867142019-01-21 11:33:38 -0800208 EXPECT_NO_FATAL_FAILURE(mTimeStats->parseArgs(useProto, args, result));
Yiwei Zhang5434a782018-12-05 18:06:32 -0800209 return result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800210}
211
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800212static std::string genLayerName(int32_t layerId) {
213 return (layerId < 0 ? "PopupWindow:b54fcd1#0" : "com.dummy#") + std::to_string(layerId);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800214}
215
216void TimeStatsTest::setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts) {
217 switch (type) {
218 case TimeStamp::POST:
219 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPostTime(id, frameNumber, genLayerName(id), ts));
220 break;
221 case TimeStamp::ACQUIRE:
222 ASSERT_NO_FATAL_FAILURE(mTimeStats->setAcquireTime(id, frameNumber, ts));
223 break;
224 case TimeStamp::ACQUIRE_FENCE:
225 ASSERT_NO_FATAL_FAILURE(
226 mTimeStats->setAcquireFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
227 break;
228 case TimeStamp::LATCH:
229 ASSERT_NO_FATAL_FAILURE(mTimeStats->setLatchTime(id, frameNumber, ts));
230 break;
231 case TimeStamp::DESIRED:
232 ASSERT_NO_FATAL_FAILURE(mTimeStats->setDesiredTime(id, frameNumber, ts));
233 break;
234 case TimeStamp::PRESENT:
235 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPresentTime(id, frameNumber, ts));
236 break;
237 case TimeStamp::PRESENT_FENCE:
238 ASSERT_NO_FATAL_FAILURE(
239 mTimeStats->setPresentFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
240 break;
241 default:
242 ALOGD("Invalid timestamp type");
243 }
244}
245
246int32_t TimeStatsTest::genRandomInt32(int32_t begin, int32_t end) {
247 std::uniform_int_distribution<int32_t> distr(begin, end);
248 return distr(mRandomEngine);
249}
250
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000251TEST_F(TimeStatsTest, disabledByDefault) {
252 ASSERT_FALSE(mTimeStats->isEnabled());
253}
254
255TEST_F(TimeStatsTest, enabledAfterBoot) {
256 mTimeStats->onBootFinished();
Alec Mourib3885ad2019-09-06 17:08:55 -0700257 ASSERT_TRUE(mTimeStats->isEnabled());
258}
259
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800260TEST_F(TimeStatsTest, canEnableAndDisableTimeStats) {
261 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
262 ASSERT_TRUE(mTimeStats->isEnabled());
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000263 EXPECT_EQ(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO, mDelegate->mAtomTag);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800264
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000265 EXPECT_CALL(*mDelegate,
266 unregisterStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800267 EXPECT_TRUE(inputCommand(InputCommand::DISABLE, FMT_STRING).empty());
268 ASSERT_FALSE(mTimeStats->isEnabled());
269}
270
271TEST_F(TimeStatsTest, canIncreaseGlobalStats) {
272 constexpr size_t TOTAL_FRAMES = 5;
273 constexpr size_t MISSED_FRAMES = 4;
274 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
275
276 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
277
278 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
279 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
280 }
281 for (size_t i = 0; i < MISSED_FRAMES; i++) {
282 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
283 }
284 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
285 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
286 }
287
288 SFTimeStatsGlobalProto globalProto;
289 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
290
291 ASSERT_TRUE(globalProto.has_total_frames());
292 EXPECT_EQ(TOTAL_FRAMES, globalProto.total_frames());
293 ASSERT_TRUE(globalProto.has_missed_frames());
294 EXPECT_EQ(MISSED_FRAMES, globalProto.missed_frames());
295 ASSERT_TRUE(globalProto.has_client_composition_frames());
296 EXPECT_EQ(CLIENT_COMPOSITION_FRAMES, globalProto.client_composition_frames());
297}
298
299TEST_F(TimeStatsTest, canInsertGlobalPresentToPresent) {
300 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
301
302 ASSERT_NO_FATAL_FAILURE(
303 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
304 ASSERT_NO_FATAL_FAILURE(
305 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
306
307 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL));
308 ASSERT_NO_FATAL_FAILURE(
309 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000)));
310 ASSERT_NO_FATAL_FAILURE(
311 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000)));
312
313 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_OFF));
314 ASSERT_NO_FATAL_FAILURE(
315 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(6000000)));
316 ASSERT_NO_FATAL_FAILURE(
317 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(8000000)));
318
319 SFTimeStatsGlobalProto globalProto;
320 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
321
322 ASSERT_EQ(1, globalProto.present_to_present_size());
323 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.present_to_present().Get(0);
324 EXPECT_EQ(1, histogramProto.frame_count());
325 EXPECT_EQ(2, histogramProto.time_millis());
326}
327
Alec Mouri9519bf12019-11-15 16:54:44 -0800328TEST_F(TimeStatsTest, canInsertGlobalFrameDuration) {
329 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
330
331 using namespace std::chrono_literals;
332
333 mTimeStats->setPowerMode(HWC_POWER_MODE_OFF);
334 mTimeStats
335 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
336 std::chrono::duration_cast<std::chrono::nanoseconds>(5ms)
337 .count());
338 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
339 mTimeStats
340 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
341 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
342 .count());
343
344 SFTimeStatsGlobalProto globalProto;
345 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
346
347 ASSERT_EQ(1, globalProto.frame_duration_size());
348 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.frame_duration().Get(0);
349 EXPECT_EQ(1, histogramProto.frame_count());
350 EXPECT_EQ(3, histogramProto.time_millis());
351}
352
Alec Mourie4034bb2019-11-19 12:45:54 -0800353TEST_F(TimeStatsTest, canInsertGlobalRenderEngineTiming) {
354 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
355
356 using namespace std::chrono_literals;
357
358 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms)
359 .count(),
360 std::make_shared<FenceTime>(
361 std::chrono::duration_cast<
362 std::chrono::nanoseconds>(3ms)
363 .count()));
364
365 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
366 .count(),
367 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
368 .count());
369
370 // First verify that flushing RenderEngine durations did not occur yet.
371 SFTimeStatsGlobalProto preFlushProto;
372 ASSERT_TRUE(preFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
373 ASSERT_EQ(0, preFlushProto.render_engine_timing_size());
374
375 // Push a dummy present fence to trigger flushing the RenderEngine timings.
376 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
377 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
378 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
379
380 // Now we can verify that RenderEngine durations were flushed now.
381 SFTimeStatsGlobalProto postFlushProto;
382 ASSERT_TRUE(postFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
383
384 ASSERT_EQ(1, postFlushProto.render_engine_timing_size());
385 const SFTimeStatsHistogramBucketProto& histogramProto =
386 postFlushProto.render_engine_timing().Get(0);
387 EXPECT_EQ(2, histogramProto.frame_count());
388 EXPECT_EQ(2, histogramProto.time_millis());
389}
390
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800391TEST_F(TimeStatsTest, canInsertOneLayerTimeStats) {
392 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
393
394 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
395 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
396
397 SFTimeStatsGlobalProto globalProto;
398 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
399
400 ASSERT_EQ(1, globalProto.stats_size());
401 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
402 ASSERT_TRUE(layerProto.has_layer_name());
403 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
404 ASSERT_TRUE(layerProto.has_total_frames());
405 EXPECT_EQ(1, layerProto.total_frames());
406 ASSERT_EQ(6, layerProto.deltas_size());
407 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
408 ASSERT_EQ(1, deltaProto.histograms_size());
409 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
410 EXPECT_EQ(1, histogramProto.frame_count());
411 if ("post2acquire" == deltaProto.delta_name()) {
412 EXPECT_EQ(1, histogramProto.time_millis());
413 } else if ("post2present" == deltaProto.delta_name()) {
414 EXPECT_EQ(4, histogramProto.time_millis());
415 } else if ("acquire2present" == deltaProto.delta_name()) {
416 EXPECT_EQ(3, histogramProto.time_millis());
417 } else if ("latch2present" == deltaProto.delta_name()) {
418 EXPECT_EQ(2, histogramProto.time_millis());
419 } else if ("desired2present" == deltaProto.delta_name()) {
420 EXPECT_EQ(1, histogramProto.time_millis());
421 } else if ("present2present" == deltaProto.delta_name()) {
422 EXPECT_EQ(1, histogramProto.time_millis());
423 } else {
424 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
425 }
426 }
427}
428
429TEST_F(TimeStatsTest, canNotInsertInvalidLayerNameTimeStats) {
430 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
431
432 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_INVALID, 1, 1000000);
433 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_INVALID, 2, 2000000);
434
435 SFTimeStatsGlobalProto globalProto;
436 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
437
438 ASSERT_EQ(0, globalProto.stats_size());
439}
440
441TEST_F(TimeStatsTest, canInsertMultipleLayersTimeStats) {
442 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
443
444 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
445 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
446 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
447 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
448
449 SFTimeStatsGlobalProto globalProto;
450 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
451
452 EXPECT_EQ(2, globalProto.stats_size());
453}
454
455TEST_F(TimeStatsTest, canInsertUnorderedLayerTimeStats) {
456 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
457
458 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
459 insertTimeRecord(UNORDERED_SEQUENCE, 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(0, histogramProto.time_millis());
477 } else if ("post2present" == deltaProto.delta_name()) {
478 EXPECT_EQ(2, histogramProto.time_millis());
479 } else if ("acquire2present" == deltaProto.delta_name()) {
480 EXPECT_EQ(2, 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
Alec Mourifb571ea2019-01-24 18:42:10 -0800493TEST_F(TimeStatsTest, recordRefreshRateNewConfigs) {
494 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
495
496 uint32_t fpsOne = 30;
497 uint32_t fpsTwo = 90;
498 uint64_t millisOne = 5000;
499 uint64_t millisTwo = 7000;
500
501 mTimeStats->recordRefreshRate(fpsOne, ms2ns(millisOne));
502 mTimeStats->recordRefreshRate(fpsTwo, ms2ns(millisTwo));
503
504 SFTimeStatsGlobalProto globalProto;
505 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
506
507 SFTimeStatsDisplayConfigBucketProto expectedBucketOne;
508 SFTimeStatsDisplayConfigProto* expectedConfigOne = expectedBucketOne.mutable_config();
509 expectedConfigOne->set_fps(fpsOne);
510 expectedBucketOne.set_duration_millis(millisOne);
511
512 SFTimeStatsDisplayConfigBucketProto expectedBucketTwo;
513 SFTimeStatsDisplayConfigProto* expectedConfigTwo = expectedBucketTwo.mutable_config();
514 expectedConfigTwo->set_fps(fpsTwo);
515 expectedBucketTwo.set_duration_millis(millisTwo);
516
517 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(2));
518
519 std::unordered_set<uint32_t> seen_fps;
520 for (const auto& bucket : globalProto.display_config_stats()) {
521 seen_fps.emplace(bucket.config().fps());
522 if (fpsOne == bucket.config().fps()) {
523 EXPECT_EQ(millisOne, bucket.duration_millis());
524 } else if (fpsTwo == bucket.config().fps()) {
525 EXPECT_EQ(millisTwo, bucket.duration_millis());
526 } else {
527 FAIL() << "Unknown fps: " << bucket.config().fps();
528 }
529 }
530 EXPECT_THAT(seen_fps, UnorderedElementsAre(fpsOne, fpsTwo));
531}
532
533TEST_F(TimeStatsTest, recordRefreshRateUpdatesConfig) {
534 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
535
536 uint32_t fps = 30;
537 uint64_t millisOne = 5000;
538 uint64_t millisTwo = 7000;
539
540 mTimeStats->recordRefreshRate(fps, ms2ns(millisOne));
541 mTimeStats->recordRefreshRate(fps, ms2ns(millisTwo));
542
543 SFTimeStatsGlobalProto globalProto;
544 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
545 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(1));
546 EXPECT_EQ(fps, globalProto.display_config_stats().Get(0).config().fps());
547 EXPECT_EQ(millisOne + millisTwo, globalProto.display_config_stats().Get(0).duration_millis());
548}
549
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800550TEST_F(TimeStatsTest, canRemoveTimeRecord) {
551 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
552
553 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
554 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 2, 2000000);
555 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(0, 2));
556 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
557
558 SFTimeStatsGlobalProto globalProto;
559 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
560
561 ASSERT_EQ(1, globalProto.stats_size());
562 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
563 ASSERT_TRUE(layerProto.has_total_frames());
564 EXPECT_EQ(1, layerProto.total_frames());
565}
566
567TEST_F(TimeStatsTest, canRecoverFromIncompleteTimeRecordError) {
568 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
569
570 uint64_t frameNumber = 1;
571 nsecs_t ts = 1000000;
572 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 1, 1000000);
Alec Mourifb571ea2019-01-24 18:42:10 -0800573 for (size_t i = 0; i < impl::TimeStats::MAX_NUM_TIME_RECORDS + 2; i++) {
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800574 frameNumber++;
575 ts += 1000000;
576 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, frameNumber, ts);
577 }
578
579 SFTimeStatsGlobalProto globalProto;
580 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
581
582 ASSERT_EQ(1, globalProto.stats_size());
583 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
584 ASSERT_TRUE(layerProto.has_total_frames());
585 EXPECT_EQ(1, layerProto.total_frames());
586}
587
588TEST_F(TimeStatsTest, layerTimeStatsOnDestroy) {
589 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
590
591 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
592 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
593 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(0));
594 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
595
596 SFTimeStatsGlobalProto globalProto;
597 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
598
599 ASSERT_EQ(1, globalProto.stats_size());
600 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
601 ASSERT_TRUE(layerProto.has_total_frames());
602 EXPECT_EQ(1, layerProto.total_frames());
603}
604
605TEST_F(TimeStatsTest, canClearTimeStats) {
606 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
607
608 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
609 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
610 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
611 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL));
Alec Mouri31ac64a2020-01-09 09:26:22 -0800612
613 using namespace std::chrono_literals;
614 mTimeStats
615 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
616 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
617 .count());
618 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
619 .count(),
620 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
621 .count());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800622 ASSERT_NO_FATAL_FAILURE(
623 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
624 ASSERT_NO_FATAL_FAILURE(
625 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
626 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
627 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
628
629 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
630
631 SFTimeStatsGlobalProto globalProto;
632 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
633
634 EXPECT_EQ(0, globalProto.total_frames());
635 EXPECT_EQ(0, globalProto.missed_frames());
636 EXPECT_EQ(0, globalProto.client_composition_frames());
637 EXPECT_EQ(0, globalProto.present_to_present_size());
Alec Mouri31ac64a2020-01-09 09:26:22 -0800638 EXPECT_EQ(0, globalProto.frame_duration_size());
639 EXPECT_EQ(0, globalProto.render_engine_timing_size());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800640 EXPECT_EQ(0, globalProto.stats_size());
641}
642
643TEST_F(TimeStatsTest, canDumpWithMaxLayers) {
644 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
645
646 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
647 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
648 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
649 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
650 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 3, 2000000);
651
652 SFTimeStatsGlobalProto globalProto;
653 ASSERT_TRUE(
654 globalProto.ParseFromString(inputCommand(InputCommand::DUMP_MAXLAYERS_1, FMT_PROTO)));
655
656 ASSERT_EQ(1, globalProto.stats_size());
657 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
658 ASSERT_TRUE(layerProto.has_layer_name());
659 EXPECT_EQ(genLayerName(LAYER_ID_1), layerProto.layer_name());
660 ASSERT_TRUE(layerProto.has_total_frames());
661 EXPECT_EQ(2, layerProto.total_frames());
662}
663
664TEST_F(TimeStatsTest, canDumpWithInvalidMaxLayers) {
665 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
666
667 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
668 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
669
670 SFTimeStatsGlobalProto globalProto;
671 ASSERT_TRUE(globalProto.ParseFromString(
672 inputCommand(InputCommand::DUMP_MAXLAYERS_INVALID, FMT_PROTO)));
673
674 ASSERT_EQ(0, globalProto.stats_size());
675}
676
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000677TEST_F(TimeStatsTest, globalStatsCallback) {
678 constexpr size_t TOTAL_FRAMES = 5;
679 constexpr size_t MISSED_FRAMES = 4;
680 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
681
682 mTimeStats->onBootFinished();
683 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
684
685 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
686 mTimeStats->incrementTotalFrames();
687 }
688 for (size_t i = 0; i < MISSED_FRAMES; i++) {
689 mTimeStats->incrementMissedFrames();
690 }
691 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
692 mTimeStats->incrementClientCompositionFrames();
693 }
694
695 mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
696 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
697 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
698
699 EXPECT_EQ(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO, mDelegate->mAtomTag);
700 EXPECT_NE(nullptr, mDelegate->mCallback);
701 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
702
703 {
704 InSequence seq;
705 EXPECT_CALL(*mDelegate,
706 statsEventSetAtomId(mDelegate->mEvent,
707 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
708 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, TOTAL_FRAMES));
709 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, MISSED_FRAMES));
710 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, CLIENT_COMPOSITION_FRAMES));
711 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, _));
712 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 2));
713 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
714 }
715 EXPECT_EQ(STATS_PULL_SUCCESS,
716 mDelegate->makePullAtomCallback(mDelegate->mAtomTag, mDelegate->mCookie));
717
718 SFTimeStatsGlobalProto globalProto;
719 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
720
721 EXPECT_EQ(0, globalProto.total_frames());
722 EXPECT_EQ(0, globalProto.missed_frames());
723 EXPECT_EQ(0, globalProto.client_composition_frames());
724 EXPECT_EQ(0, globalProto.present_to_present_size());
725}
726
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800727TEST_F(TimeStatsTest, canSurviveMonkey) {
Lloyd Pique067fe1e2018-12-06 19:44:13 -0800728 if (g_noSlowTests) {
729 GTEST_SKIP();
730 }
731
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800732 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
733
734 for (size_t i = 0; i < 10000000; ++i) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800735 const int32_t layerId = genRandomInt32(-1, 10);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800736 const int32_t frameNumber = genRandomInt32(1, 10);
737 switch (genRandomInt32(0, 100)) {
738 case 0:
739 ALOGV("removeTimeRecord");
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800740 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(layerId, frameNumber));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800741 continue;
742 case 1:
743 ALOGV("onDestroy");
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800744 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(layerId));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800745 continue;
746 }
747 TimeStamp type = static_cast<TimeStamp>(genRandomInt32(TIME_STAMP_BEGIN, TIME_STAMP_END));
748 const int32_t ts = genRandomInt32(1, 1000000000);
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800749 ALOGV("type[%d], layerId[%d], frameNumber[%d], ts[%d]", type, layerId, frameNumber, ts);
750 setTimeStamp(type, layerId, frameNumber, ts);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800751 }
752}
753
754} // namespace
755} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -0800756
757// TODO(b/129481165): remove the #pragma below and fix conversion issues
758#pragma clang diagnostic pop // ignored "-Wconversion"