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