blob: ace370f283ebd7dc92d5e5732eab94a1332ba27b [file] [log] [blame]
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001/*
2 * Copyright 2018 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -080017// TODO(b/129481165): remove the #pragma below and fix conversion issues
18#pragma clang diagnostic push
19#pragma clang diagnostic ignored "-Wconversion"
20
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080021#undef LOG_TAG
22#define LOG_TAG "LibSurfaceFlingerUnittests"
23
Mikael Pessa2e1608f2019-07-19 11:25:35 -070024#include <TimeStats/TimeStats.h>
Alec Mouri37384342020-01-02 17:23:37 -080025#include <android/util/ProtoOutputStream.h>
Alec Mourifb571ea2019-01-24 18:42:10 -080026#include <gmock/gmock.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080027#include <gtest/gtest.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080028#include <log/log.h>
29#include <utils/String16.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080030#include <utils/Vector.h>
31
Alec Mouri9519bf12019-11-15 16:54:44 -080032#include <chrono>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080033#include <random>
Alec Mourifb571ea2019-01-24 18:42:10 -080034#include <unordered_set>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080035
Lloyd Pique067fe1e2018-12-06 19:44:13 -080036#include "libsurfaceflinger_unittest_main.h"
37
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080038using namespace android::surfaceflinger;
39using namespace google::protobuf;
Vishnu Nairabf97fd2020-02-03 13:51:16 -080040using namespace std::chrono_literals;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080041
42namespace android {
43namespace {
44
Alec Mouri8e2f31b2020-01-16 22:04:35 +000045using testing::_;
Alec Mouri37384342020-01-02 17:23:37 -080046using testing::AnyNumber;
Alec Mourifb571ea2019-01-24 18:42:10 -080047using testing::Contains;
Vishnu Nair9b079a22020-01-21 14:36:08 -080048using testing::HasSubstr;
Alec Mouri8e2f31b2020-01-16 22:04:35 +000049using testing::InSequence;
Alec Mourifb571ea2019-01-24 18:42:10 -080050using testing::SizeIs;
Alec Mouri37384342020-01-02 17:23:37 -080051using testing::StrEq;
Alec Mourifb571ea2019-01-24 18:42:10 -080052using testing::UnorderedElementsAre;
53
Peiyong Lin65248e02020-04-18 21:15:07 -070054using PowerMode = hardware::graphics::composer::V2_4::IComposerClient::PowerMode;
55
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080056// clang-format off
57#define FMT_PROTO true
58#define FMT_STRING false
59#define LAYER_ID_0 0
60#define LAYER_ID_1 1
Alec Mouri9a29e672020-09-14 12:39:14 -070061#define UID_0 123
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080062#define LAYER_ID_INVALID -1
63#define NUM_LAYERS 1
64#define NUM_LAYERS_INVALID "INVALID"
65
66enum InputCommand : int32_t {
67 ENABLE = 0,
68 DISABLE = 1,
69 CLEAR = 2,
70 DUMP_ALL = 3,
71 DUMP_MAXLAYERS_1 = 4,
72 DUMP_MAXLAYERS_INVALID = 5,
73 INPUT_COMMAND_BEGIN = ENABLE,
74 INPUT_COMMAND_END = DUMP_MAXLAYERS_INVALID,
75 INPUT_COMMAND_RANGE = INPUT_COMMAND_END - INPUT_COMMAND_BEGIN + 1,
76};
77
78enum TimeStamp : int32_t {
79 POST = 0,
80 ACQUIRE = 1,
81 ACQUIRE_FENCE = 2,
82 LATCH = 3,
83 DESIRED = 4,
84 PRESENT = 5,
85 PRESENT_FENCE = 6,
86 TIME_STAMP_BEGIN = POST,
87 TIME_STAMP_END = PRESENT,
88 TIME_STAMP_RANGE = TIME_STAMP_END - TIME_STAMP_BEGIN + 1,
89};
90
91static const TimeStamp NORMAL_SEQUENCE[] = {
92 TimeStamp::POST,
93 TimeStamp::ACQUIRE,
94 TimeStamp::LATCH,
95 TimeStamp::DESIRED,
96 TimeStamp::PRESENT,
97};
98
99static const TimeStamp NORMAL_SEQUENCE_2[] = {
100 TimeStamp::POST,
101 TimeStamp::ACQUIRE_FENCE,
102 TimeStamp::LATCH,
103 TimeStamp::DESIRED,
104 TimeStamp::PRESENT_FENCE,
105};
106
107static const TimeStamp UNORDERED_SEQUENCE[] = {
108 TimeStamp::ACQUIRE,
109 TimeStamp::LATCH,
110 TimeStamp::POST,
111 TimeStamp::DESIRED,
112 TimeStamp::PRESENT,
113};
114
115static const TimeStamp INCOMPLETE_SEQUENCE[] = {
116 TimeStamp::POST,
117};
118// clang-format on
119
120class TimeStatsTest : public testing::Test {
121public:
122 TimeStatsTest() {
123 const ::testing::TestInfo* const test_info =
124 ::testing::UnitTest::GetInstance()->current_test_info();
125 ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
126 }
127
128 ~TimeStatsTest() {
129 const ::testing::TestInfo* const test_info =
130 ::testing::UnitTest::GetInstance()->current_test_info();
131 ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
132 }
133
134 std::string inputCommand(InputCommand cmd, bool useProto);
135
136 void setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts);
137
138 int32_t genRandomInt32(int32_t begin, int32_t end);
139
140 template <size_t N>
141 void insertTimeRecord(const TimeStamp (&sequence)[N], int32_t id, uint64_t frameNumber,
142 nsecs_t ts) {
143 for (size_t i = 0; i < N; i++, ts += 1000000) {
144 setTimeStamp(sequence[i], id, frameNumber, ts);
145 }
146 }
147
148 std::mt19937 mRandomEngine = std::mt19937(std::random_device()());
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000149
150 class FakeStatsEventDelegate : public impl::TimeStats::StatsEventDelegate {
151 public:
152 FakeStatsEventDelegate() = default;
153 ~FakeStatsEventDelegate() override = default;
154
Tej Singh2a457b62020-01-31 16:16:10 -0800155 struct AStatsEvent* addStatsEventToPullData(AStatsEventList*) override {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000156 return mEvent;
157 }
Tej Singh38a4b212020-03-13 19:04:51 -0700158 void setStatsPullAtomCallback(int32_t atom_tag, AStatsManager_PullAtomMetadata*,
159 AStatsManager_PullAtomCallback callback,
160 void* cookie) override {
Alec Mouri37384342020-01-02 17:23:37 -0800161 mAtomTags.push_back(atom_tag);
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000162 mCallback = callback;
163 mCookie = cookie;
164 }
165
Tej Singh2a457b62020-01-31 16:16:10 -0800166 AStatsManager_PullAtomCallbackReturn makePullAtomCallback(int32_t atom_tag, void* cookie) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000167 return (*mCallback)(atom_tag, nullptr, cookie);
168 }
169
Tej Singh38a4b212020-03-13 19:04:51 -0700170 MOCK_METHOD1(clearStatsPullAtomCallback, void(int32_t));
Tej Singh2a457b62020-01-31 16:16:10 -0800171 MOCK_METHOD2(statsEventSetAtomId, void(AStatsEvent*, uint32_t));
Alec Mouri717bcb62020-02-10 17:07:19 -0800172 MOCK_METHOD2(statsEventWriteInt32, void(AStatsEvent*, int32_t));
Tej Singh2a457b62020-01-31 16:16:10 -0800173 MOCK_METHOD2(statsEventWriteInt64, void(AStatsEvent*, int64_t));
174 MOCK_METHOD2(statsEventWriteString8, void(AStatsEvent*, const char*));
175 MOCK_METHOD3(statsEventWriteByteArray, void(AStatsEvent*, const uint8_t*, size_t));
176 MOCK_METHOD1(statsEventBuild, void(AStatsEvent*));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000177
Tej Singh2a457b62020-01-31 16:16:10 -0800178 AStatsEvent* mEvent = AStatsEvent_obtain();
Alec Mouri37384342020-01-02 17:23:37 -0800179 std::vector<int32_t> mAtomTags;
Tej Singh2a457b62020-01-31 16:16:10 -0800180 AStatsManager_PullAtomCallback mCallback = nullptr;
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000181 void* mCookie = nullptr;
182 };
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000183 FakeStatsEventDelegate* mDelegate = new FakeStatsEventDelegate;
184 std::unique_ptr<TimeStats> mTimeStats =
Alec Mouri37384342020-01-02 17:23:37 -0800185 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
186 std::nullopt, std::nullopt);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800187};
188
189std::string TimeStatsTest::inputCommand(InputCommand cmd, bool useProto) {
Yiwei Zhang5434a782018-12-05 18:06:32 -0800190 std::string result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800191 Vector<String16> args;
192
193 switch (cmd) {
194 case InputCommand::ENABLE:
195 args.push_back(String16("-enable"));
196 break;
197 case InputCommand::DISABLE:
198 args.push_back(String16("-disable"));
199 break;
200 case InputCommand::CLEAR:
201 args.push_back(String16("-clear"));
202 break;
203 case InputCommand::DUMP_ALL:
204 args.push_back(String16("-dump"));
205 break;
206 case InputCommand::DUMP_MAXLAYERS_1:
207 args.push_back(String16("-dump"));
208 args.push_back(String16("-maxlayers"));
209 args.push_back(String16(std::to_string(NUM_LAYERS).c_str()));
210 break;
211 case InputCommand::DUMP_MAXLAYERS_INVALID:
212 args.push_back(String16("-dump"));
213 args.push_back(String16("-maxlayers"));
214 args.push_back(String16(NUM_LAYERS_INVALID));
215 break;
216 default:
217 ALOGD("Invalid control command");
218 }
219
Dominik Laskowskic2867142019-01-21 11:33:38 -0800220 EXPECT_NO_FATAL_FAILURE(mTimeStats->parseArgs(useProto, args, result));
Yiwei Zhang5434a782018-12-05 18:06:32 -0800221 return result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800222}
223
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800224static std::string genLayerName(int32_t layerId) {
Peiyong Lind8460c82020-07-28 16:04:22 -0700225 return (layerId < 0 ? "PopupWindow:b54fcd1#0" : "com.example.fake#") + std::to_string(layerId);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800226}
227
228void TimeStatsTest::setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts) {
229 switch (type) {
230 case TimeStamp::POST:
Alec Mouri9a29e672020-09-14 12:39:14 -0700231 ASSERT_NO_FATAL_FAILURE(
232 mTimeStats->setPostTime(id, frameNumber, genLayerName(id), UID_0, ts));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800233 break;
234 case TimeStamp::ACQUIRE:
235 ASSERT_NO_FATAL_FAILURE(mTimeStats->setAcquireTime(id, frameNumber, ts));
236 break;
237 case TimeStamp::ACQUIRE_FENCE:
238 ASSERT_NO_FATAL_FAILURE(
239 mTimeStats->setAcquireFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
240 break;
241 case TimeStamp::LATCH:
242 ASSERT_NO_FATAL_FAILURE(mTimeStats->setLatchTime(id, frameNumber, ts));
243 break;
244 case TimeStamp::DESIRED:
245 ASSERT_NO_FATAL_FAILURE(mTimeStats->setDesiredTime(id, frameNumber, ts));
246 break;
247 case TimeStamp::PRESENT:
248 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPresentTime(id, frameNumber, ts));
249 break;
250 case TimeStamp::PRESENT_FENCE:
251 ASSERT_NO_FATAL_FAILURE(
252 mTimeStats->setPresentFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
253 break;
254 default:
255 ALOGD("Invalid timestamp type");
256 }
257}
258
259int32_t TimeStatsTest::genRandomInt32(int32_t begin, int32_t end) {
260 std::uniform_int_distribution<int32_t> distr(begin, end);
261 return distr(mRandomEngine);
262}
263
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000264TEST_F(TimeStatsTest, disabledByDefault) {
265 ASSERT_FALSE(mTimeStats->isEnabled());
266}
267
Tej Singh38a4b212020-03-13 19:04:51 -0700268TEST_F(TimeStatsTest, setsCallbacksAfterBoot) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000269 mTimeStats->onBootFinished();
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800270 EXPECT_THAT(mDelegate->mAtomTags,
271 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
272 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
273}
274
Tej Singh38a4b212020-03-13 19:04:51 -0700275TEST_F(TimeStatsTest, clearsCallbacksOnDestruction) {
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800276 EXPECT_CALL(*mDelegate,
Tej Singh38a4b212020-03-13 19:04:51 -0700277 clearStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800278 EXPECT_CALL(*mDelegate,
Tej Singh38a4b212020-03-13 19:04:51 -0700279 clearStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO));
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800280 mTimeStats.reset();
Alec Mourib3885ad2019-09-06 17:08:55 -0700281}
282
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800283TEST_F(TimeStatsTest, canEnableAndDisableTimeStats) {
284 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
285 ASSERT_TRUE(mTimeStats->isEnabled());
286
287 EXPECT_TRUE(inputCommand(InputCommand::DISABLE, FMT_STRING).empty());
288 ASSERT_FALSE(mTimeStats->isEnabled());
289}
290
291TEST_F(TimeStatsTest, canIncreaseGlobalStats) {
292 constexpr size_t TOTAL_FRAMES = 5;
293 constexpr size_t MISSED_FRAMES = 4;
294 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
295
296 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
297
298 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
299 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
300 }
301 for (size_t i = 0; i < MISSED_FRAMES; i++) {
302 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
303 }
304 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
305 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
306 }
307
308 SFTimeStatsGlobalProto globalProto;
309 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
310
311 ASSERT_TRUE(globalProto.has_total_frames());
312 EXPECT_EQ(TOTAL_FRAMES, globalProto.total_frames());
313 ASSERT_TRUE(globalProto.has_missed_frames());
314 EXPECT_EQ(MISSED_FRAMES, globalProto.missed_frames());
315 ASSERT_TRUE(globalProto.has_client_composition_frames());
316 EXPECT_EQ(CLIENT_COMPOSITION_FRAMES, globalProto.client_composition_frames());
317}
318
Alec Mouri91f6df32020-01-30 08:48:58 -0800319TEST_F(TimeStatsTest, canIncreaseLateAcquireFrames) {
320 // this stat is not in the proto so verify by checking the string dump
321 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
322
323 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
324
325 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
326 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
327 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
328 }
329 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
330
331 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
332 const std::string expectedResult = "lateAcquireFrames = " + std::to_string(LATE_ACQUIRE_FRAMES);
333 EXPECT_THAT(result, HasSubstr(expectedResult));
334}
335
336TEST_F(TimeStatsTest, canIncreaseBadDesiredPresent) {
337 // this stat is not in the proto so verify by checking the string dump
338 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 2;
339
340 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
341
342 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
343 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
344 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
345 }
346 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
347
348 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
349 const std::string expectedResult =
350 "badDesiredPresentFrames = " + std::to_string(BAD_DESIRED_PRESENT_FRAMES);
351 EXPECT_THAT(result, HasSubstr(expectedResult));
352}
353
Alec Mouri9a29e672020-09-14 12:39:14 -0700354TEST_F(TimeStatsTest, canIncreaseJankyFrames) {
355 // this stat is not in the proto so verify by checking the string dump
356 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
357
358 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800359 mTimeStats->incrementJankyFrames(JankType::SurfaceFlingerCpuDeadlineMissed);
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100360 mTimeStats->incrementJankyFrames(JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800361 mTimeStats->incrementJankyFrames(JankType::DisplayHAL);
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100362 mTimeStats->incrementJankyFrames(JankType::AppDeadlineMissed);
363 mTimeStats->incrementJankyFrames(JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -0700364
365 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
366 std::string expectedResult = "totalTimelineFrames = " + std::to_string(5);
367 EXPECT_THAT(result, HasSubstr(expectedResult));
368 expectedResult = "jankyFrames = " + std::to_string(4);
369 EXPECT_THAT(result, HasSubstr(expectedResult));
370 expectedResult = "sfLongCpuJankyFrames = " + std::to_string(1);
371 EXPECT_THAT(result, HasSubstr(expectedResult));
372 expectedResult = "sfLongGpuJankyFrames = " + std::to_string(1);
373 EXPECT_THAT(result, HasSubstr(expectedResult));
374 expectedResult = "sfUnattributedJankyFrame = " + std::to_string(1);
375 EXPECT_THAT(result, HasSubstr(expectedResult));
376 expectedResult = "appUnattributedJankyFrame = " + std::to_string(1);
377 EXPECT_THAT(result, HasSubstr(expectedResult));
378}
379
380TEST_F(TimeStatsTest, canIncreaseJankyFramesForLayer) {
381 // this stat is not in the proto so verify by checking the string dump
382 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
383
384 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
385 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800386 JankType::SurfaceFlingerCpuDeadlineMissed);
Alec Mouri9a29e672020-09-14 12:39:14 -0700387 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100388 JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800389 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::DisplayHAL);
Alec Mouri9a29e672020-09-14 12:39:14 -0700390 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100391 JankType::AppDeadlineMissed);
392 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -0700393
394 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
395 std::string expectedResult = "totalTimelineFrames = " + std::to_string(5);
396 EXPECT_THAT(result, HasSubstr(expectedResult));
397 expectedResult = "jankyFrames = " + std::to_string(4);
398 EXPECT_THAT(result, HasSubstr(expectedResult));
399 expectedResult = "sfLongCpuJankyFrames = " + std::to_string(1);
400 EXPECT_THAT(result, HasSubstr(expectedResult));
401 expectedResult = "sfLongGpuJankyFrames = " + std::to_string(1);
402 EXPECT_THAT(result, HasSubstr(expectedResult));
403 expectedResult = "sfUnattributedJankyFrame = " + std::to_string(1);
404 EXPECT_THAT(result, HasSubstr(expectedResult));
405 expectedResult = "appUnattributedJankyFrame = " + std::to_string(1);
406 EXPECT_THAT(result, HasSubstr(expectedResult));
407}
408
Vishnu Nair9b079a22020-01-21 14:36:08 -0800409TEST_F(TimeStatsTest, canIncreaseClientCompositionReusedFrames) {
410 // this stat is not in the proto so verify by checking the string dump
411 constexpr size_t CLIENT_COMPOSITION_REUSED_FRAMES = 2;
412
413 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
414 for (size_t i = 0; i < CLIENT_COMPOSITION_REUSED_FRAMES; i++) {
415 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
416 }
417
418 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
419 const std::string expectedResult =
420 "clientCompositionReusedFrames = " + std::to_string(CLIENT_COMPOSITION_REUSED_FRAMES);
421 EXPECT_THAT(result, HasSubstr(expectedResult));
422}
423
Alec Mouri8de697e2020-03-19 10:52:01 -0700424TEST_F(TimeStatsTest, canIncreaseRefreshRateSwitches) {
425 // this stat is not in the proto so verify by checking the string dump
426 constexpr size_t REFRESH_RATE_SWITCHES = 2;
427
428 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
429 for (size_t i = 0; i < REFRESH_RATE_SWITCHES; i++) {
430 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementRefreshRateSwitches());
431 }
432
433 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
434 const std::string expectedResult =
435 "refreshRateSwitches = " + std::to_string(REFRESH_RATE_SWITCHES);
436 EXPECT_THAT(result, HasSubstr(expectedResult));
437}
438
Alec Mouri8f7a0102020-04-15 12:11:10 -0700439TEST_F(TimeStatsTest, canIncreaseCompositionStrategyChanges) {
440 // this stat is not in the proto so verify by checking the string dump
441 constexpr size_t COMPOSITION_STRATEGY_CHANGES = 2;
442
443 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
444 for (size_t i = 0; i < COMPOSITION_STRATEGY_CHANGES; i++) {
445 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementCompositionStrategyChanges());
446 }
447
448 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
449 const std::string expectedResult =
450 "compositionStrategyChanges = " + std::to_string(COMPOSITION_STRATEGY_CHANGES);
451 EXPECT_THAT(result, HasSubstr(expectedResult));
452}
453
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800454TEST_F(TimeStatsTest, canAverageFrameDuration) {
455 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
Peiyong Lin65248e02020-04-18 21:15:07 -0700456 mTimeStats->setPowerMode(PowerMode::ON);
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800457 mTimeStats
458 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
459 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
460 .count());
461 mTimeStats
462 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
463 std::chrono::duration_cast<std::chrono::nanoseconds>(16ms)
464 .count());
465
466 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
467 EXPECT_THAT(result, HasSubstr("averageFrameDuration = 10.000 ms"));
468}
469
470TEST_F(TimeStatsTest, canAverageRenderEngineTimings) {
471 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
472 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms)
473 .count(),
474 std::make_shared<FenceTime>(
475 std::chrono::duration_cast<
476 std::chrono::nanoseconds>(3ms)
477 .count()));
478
479 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
480 .count(),
481 std::chrono::duration_cast<std::chrono::nanoseconds>(8ms)
482 .count());
483
Peiyong Lind8460c82020-07-28 16:04:22 -0700484 // Push a fake present fence to trigger flushing the RenderEngine timings.
Peiyong Lin65248e02020-04-18 21:15:07 -0700485 mTimeStats->setPowerMode(PowerMode::ON);
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800486 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
487 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
488
489 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
490 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 3.000 ms"));
491}
492
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800493TEST_F(TimeStatsTest, canInsertGlobalPresentToPresent) {
494 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
495
496 ASSERT_NO_FATAL_FAILURE(
497 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
498 ASSERT_NO_FATAL_FAILURE(
499 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
500
Peiyong Lin65248e02020-04-18 21:15:07 -0700501 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::ON));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800502 ASSERT_NO_FATAL_FAILURE(
503 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000)));
504 ASSERT_NO_FATAL_FAILURE(
505 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000)));
506
Peiyong Lin65248e02020-04-18 21:15:07 -0700507 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::OFF));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800508 ASSERT_NO_FATAL_FAILURE(
509 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(6000000)));
510 ASSERT_NO_FATAL_FAILURE(
511 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(8000000)));
512
513 SFTimeStatsGlobalProto globalProto;
514 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
515
516 ASSERT_EQ(1, globalProto.present_to_present_size());
517 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.present_to_present().Get(0);
518 EXPECT_EQ(1, histogramProto.frame_count());
519 EXPECT_EQ(2, histogramProto.time_millis());
520}
521
Alec Mouri9519bf12019-11-15 16:54:44 -0800522TEST_F(TimeStatsTest, canInsertGlobalFrameDuration) {
523 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
524
Peiyong Lin65248e02020-04-18 21:15:07 -0700525 mTimeStats->setPowerMode(PowerMode::OFF);
Alec Mouri9519bf12019-11-15 16:54:44 -0800526 mTimeStats
527 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
528 std::chrono::duration_cast<std::chrono::nanoseconds>(5ms)
529 .count());
Peiyong Lin65248e02020-04-18 21:15:07 -0700530 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouri9519bf12019-11-15 16:54:44 -0800531 mTimeStats
532 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
533 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
534 .count());
535
536 SFTimeStatsGlobalProto globalProto;
537 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
538
539 ASSERT_EQ(1, globalProto.frame_duration_size());
540 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.frame_duration().Get(0);
541 EXPECT_EQ(1, histogramProto.frame_count());
542 EXPECT_EQ(3, histogramProto.time_millis());
543}
544
Alec Mourie4034bb2019-11-19 12:45:54 -0800545TEST_F(TimeStatsTest, canInsertGlobalRenderEngineTiming) {
546 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
547
Alec Mourie4034bb2019-11-19 12:45:54 -0800548 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms)
549 .count(),
550 std::make_shared<FenceTime>(
551 std::chrono::duration_cast<
552 std::chrono::nanoseconds>(3ms)
553 .count()));
554
555 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
556 .count(),
557 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
558 .count());
559
560 // First verify that flushing RenderEngine durations did not occur yet.
561 SFTimeStatsGlobalProto preFlushProto;
562 ASSERT_TRUE(preFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
563 ASSERT_EQ(0, preFlushProto.render_engine_timing_size());
564
Peiyong Lind8460c82020-07-28 16:04:22 -0700565 // Push a fake present fence to trigger flushing the RenderEngine timings.
Peiyong Lin65248e02020-04-18 21:15:07 -0700566 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mourie4034bb2019-11-19 12:45:54 -0800567 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
568 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
569
570 // Now we can verify that RenderEngine durations were flushed now.
571 SFTimeStatsGlobalProto postFlushProto;
572 ASSERT_TRUE(postFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
573
574 ASSERT_EQ(1, postFlushProto.render_engine_timing_size());
575 const SFTimeStatsHistogramBucketProto& histogramProto =
576 postFlushProto.render_engine_timing().Get(0);
577 EXPECT_EQ(2, histogramProto.frame_count());
578 EXPECT_EQ(2, histogramProto.time_millis());
579}
580
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800581TEST_F(TimeStatsTest, canInsertOneLayerTimeStats) {
582 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
583
584 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
585 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
586
587 SFTimeStatsGlobalProto globalProto;
588 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
589
590 ASSERT_EQ(1, globalProto.stats_size());
591 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
592 ASSERT_TRUE(layerProto.has_layer_name());
593 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
594 ASSERT_TRUE(layerProto.has_total_frames());
595 EXPECT_EQ(1, layerProto.total_frames());
596 ASSERT_EQ(6, layerProto.deltas_size());
597 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
598 ASSERT_EQ(1, deltaProto.histograms_size());
599 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
600 EXPECT_EQ(1, histogramProto.frame_count());
601 if ("post2acquire" == deltaProto.delta_name()) {
602 EXPECT_EQ(1, histogramProto.time_millis());
603 } else if ("post2present" == deltaProto.delta_name()) {
604 EXPECT_EQ(4, histogramProto.time_millis());
605 } else if ("acquire2present" == deltaProto.delta_name()) {
606 EXPECT_EQ(3, histogramProto.time_millis());
607 } else if ("latch2present" == deltaProto.delta_name()) {
608 EXPECT_EQ(2, histogramProto.time_millis());
609 } else if ("desired2present" == deltaProto.delta_name()) {
610 EXPECT_EQ(1, histogramProto.time_millis());
611 } else if ("present2present" == deltaProto.delta_name()) {
612 EXPECT_EQ(1, histogramProto.time_millis());
613 } else {
614 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
615 }
616 }
617}
618
619TEST_F(TimeStatsTest, canNotInsertInvalidLayerNameTimeStats) {
620 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
621
622 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_INVALID, 1, 1000000);
623 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_INVALID, 2, 2000000);
624
625 SFTimeStatsGlobalProto globalProto;
626 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
627
628 ASSERT_EQ(0, globalProto.stats_size());
629}
630
631TEST_F(TimeStatsTest, canInsertMultipleLayersTimeStats) {
632 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
633
634 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
635 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
636 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
637 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
638
639 SFTimeStatsGlobalProto globalProto;
640 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
641
642 EXPECT_EQ(2, globalProto.stats_size());
643}
644
645TEST_F(TimeStatsTest, canInsertUnorderedLayerTimeStats) {
646 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
647
648 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
649 insertTimeRecord(UNORDERED_SEQUENCE, LAYER_ID_0, 2, 2000000);
650
651 SFTimeStatsGlobalProto globalProto;
652 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
653
654 ASSERT_EQ(1, globalProto.stats_size());
655 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
656 ASSERT_TRUE(layerProto.has_layer_name());
657 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
658 ASSERT_TRUE(layerProto.has_total_frames());
659 EXPECT_EQ(1, layerProto.total_frames());
660 ASSERT_EQ(6, layerProto.deltas_size());
661 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
662 ASSERT_EQ(1, deltaProto.histograms_size());
663 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
664 EXPECT_EQ(1, histogramProto.frame_count());
665 if ("post2acquire" == deltaProto.delta_name()) {
666 EXPECT_EQ(0, histogramProto.time_millis());
667 } else if ("post2present" == deltaProto.delta_name()) {
668 EXPECT_EQ(2, histogramProto.time_millis());
669 } else if ("acquire2present" == deltaProto.delta_name()) {
670 EXPECT_EQ(2, histogramProto.time_millis());
671 } else if ("latch2present" == deltaProto.delta_name()) {
672 EXPECT_EQ(2, histogramProto.time_millis());
673 } else if ("desired2present" == deltaProto.delta_name()) {
674 EXPECT_EQ(1, histogramProto.time_millis());
675 } else if ("present2present" == deltaProto.delta_name()) {
676 EXPECT_EQ(1, histogramProto.time_millis());
677 } else {
678 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
679 }
680 }
681}
682
Alec Mourifb571ea2019-01-24 18:42:10 -0800683TEST_F(TimeStatsTest, recordRefreshRateNewConfigs) {
684 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
685
686 uint32_t fpsOne = 30;
687 uint32_t fpsTwo = 90;
688 uint64_t millisOne = 5000;
689 uint64_t millisTwo = 7000;
690
691 mTimeStats->recordRefreshRate(fpsOne, ms2ns(millisOne));
692 mTimeStats->recordRefreshRate(fpsTwo, ms2ns(millisTwo));
693
694 SFTimeStatsGlobalProto globalProto;
695 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
696
697 SFTimeStatsDisplayConfigBucketProto expectedBucketOne;
698 SFTimeStatsDisplayConfigProto* expectedConfigOne = expectedBucketOne.mutable_config();
699 expectedConfigOne->set_fps(fpsOne);
700 expectedBucketOne.set_duration_millis(millisOne);
701
702 SFTimeStatsDisplayConfigBucketProto expectedBucketTwo;
703 SFTimeStatsDisplayConfigProto* expectedConfigTwo = expectedBucketTwo.mutable_config();
704 expectedConfigTwo->set_fps(fpsTwo);
705 expectedBucketTwo.set_duration_millis(millisTwo);
706
707 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(2));
708
709 std::unordered_set<uint32_t> seen_fps;
710 for (const auto& bucket : globalProto.display_config_stats()) {
711 seen_fps.emplace(bucket.config().fps());
712 if (fpsOne == bucket.config().fps()) {
713 EXPECT_EQ(millisOne, bucket.duration_millis());
714 } else if (fpsTwo == bucket.config().fps()) {
715 EXPECT_EQ(millisTwo, bucket.duration_millis());
716 } else {
717 FAIL() << "Unknown fps: " << bucket.config().fps();
718 }
719 }
720 EXPECT_THAT(seen_fps, UnorderedElementsAre(fpsOne, fpsTwo));
721}
722
723TEST_F(TimeStatsTest, recordRefreshRateUpdatesConfig) {
724 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
725
726 uint32_t fps = 30;
727 uint64_t millisOne = 5000;
728 uint64_t millisTwo = 7000;
729
730 mTimeStats->recordRefreshRate(fps, ms2ns(millisOne));
731 mTimeStats->recordRefreshRate(fps, ms2ns(millisTwo));
732
733 SFTimeStatsGlobalProto globalProto;
734 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
735 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(1));
736 EXPECT_EQ(fps, globalProto.display_config_stats().Get(0).config().fps());
737 EXPECT_EQ(millisOne + millisTwo, globalProto.display_config_stats().Get(0).duration_millis());
738}
739
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800740TEST_F(TimeStatsTest, canRemoveTimeRecord) {
741 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
742
743 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
744 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 2, 2000000);
745 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(0, 2));
746 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
747
748 SFTimeStatsGlobalProto globalProto;
749 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
750
751 ASSERT_EQ(1, globalProto.stats_size());
752 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
753 ASSERT_TRUE(layerProto.has_total_frames());
754 EXPECT_EQ(1, layerProto.total_frames());
755}
756
757TEST_F(TimeStatsTest, canRecoverFromIncompleteTimeRecordError) {
758 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
759
760 uint64_t frameNumber = 1;
761 nsecs_t ts = 1000000;
762 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 1, 1000000);
Alec Mourifb571ea2019-01-24 18:42:10 -0800763 for (size_t i = 0; i < impl::TimeStats::MAX_NUM_TIME_RECORDS + 2; i++) {
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800764 frameNumber++;
765 ts += 1000000;
766 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, frameNumber, ts);
767 }
768
769 SFTimeStatsGlobalProto globalProto;
770 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
771
772 ASSERT_EQ(1, globalProto.stats_size());
773 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
774 ASSERT_TRUE(layerProto.has_total_frames());
775 EXPECT_EQ(1, layerProto.total_frames());
776}
777
778TEST_F(TimeStatsTest, layerTimeStatsOnDestroy) {
779 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
780
781 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
782 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
783 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(0));
784 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
785
786 SFTimeStatsGlobalProto globalProto;
787 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
788
789 ASSERT_EQ(1, globalProto.stats_size());
790 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
791 ASSERT_TRUE(layerProto.has_total_frames());
792 EXPECT_EQ(1, layerProto.total_frames());
793}
794
795TEST_F(TimeStatsTest, canClearTimeStats) {
796 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
797
798 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
799 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
800 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
Peiyong Lin65248e02020-04-18 21:15:07 -0700801 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::ON));
Alec Mouri31ac64a2020-01-09 09:26:22 -0800802
Alec Mouri31ac64a2020-01-09 09:26:22 -0800803 mTimeStats
804 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
805 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
806 .count());
807 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
808 .count(),
809 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
810 .count());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800811 ASSERT_NO_FATAL_FAILURE(
812 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
813 ASSERT_NO_FATAL_FAILURE(
814 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
815 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
816 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
817
818 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
819
820 SFTimeStatsGlobalProto globalProto;
821 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
822
823 EXPECT_EQ(0, globalProto.total_frames());
824 EXPECT_EQ(0, globalProto.missed_frames());
825 EXPECT_EQ(0, globalProto.client_composition_frames());
826 EXPECT_EQ(0, globalProto.present_to_present_size());
Alec Mouri31ac64a2020-01-09 09:26:22 -0800827 EXPECT_EQ(0, globalProto.frame_duration_size());
828 EXPECT_EQ(0, globalProto.render_engine_timing_size());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800829 EXPECT_EQ(0, globalProto.stats_size());
830}
831
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800832TEST_F(TimeStatsTest, canClearDumpOnlyTimeStats) {
833 // These stats are not in the proto so verify by checking the string dump.
Vishnu Nair9b079a22020-01-21 14:36:08 -0800834 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
835 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
Alec Mouri8de697e2020-03-19 10:52:01 -0700836 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementRefreshRateSwitches());
Alec Mouri8f7a0102020-04-15 12:11:10 -0700837 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementCompositionStrategyChanges());
Peiyong Lin65248e02020-04-18 21:15:07 -0700838 mTimeStats->setPowerMode(PowerMode::ON);
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800839 mTimeStats
840 ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
841 std::chrono::duration_cast<std::chrono::nanoseconds>(5ms)
842 .count());
843 mTimeStats->recordRenderEngineDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(4ms)
844 .count(),
845 std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
846 .count());
847 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(
848 std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count()));
Alec Mouri9a29e672020-09-14 12:39:14 -0700849
850 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800851 JankType::SurfaceFlingerCpuDeadlineMissed);
Alec Mouri9a29e672020-09-14 12:39:14 -0700852 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100853 JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800854 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::DisplayHAL);
Alec Mouri9a29e672020-09-14 12:39:14 -0700855 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100856 JankType::AppDeadlineMissed);
857 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -0700858
Vishnu Nair9b079a22020-01-21 14:36:08 -0800859 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
860
861 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
862 EXPECT_THAT(result, HasSubstr("clientCompositionReusedFrames = 0"));
Alec Mouri8de697e2020-03-19 10:52:01 -0700863 EXPECT_THAT(result, HasSubstr("refreshRateSwitches = 0"));
Alec Mouri8f7a0102020-04-15 12:11:10 -0700864 EXPECT_THAT(result, HasSubstr("compositionStrategyChanges = 0"));
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800865 EXPECT_THAT(result, HasSubstr("averageFrameDuration = 0.000 ms"));
866 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 0.000 ms"));
Alec Mouri9a29e672020-09-14 12:39:14 -0700867 EXPECT_THAT(result, HasSubstr("jankyFrames = 0"));
868 EXPECT_THAT(result, HasSubstr("sfLongCpuJankyFrames = 0"));
869 EXPECT_THAT(result, HasSubstr("sfLongGpuJankyFrames = 0"));
870 EXPECT_THAT(result, HasSubstr("sfUnattributedJankyFrame = 0"));
871 EXPECT_THAT(result, HasSubstr("appUnattributedJankyFrame = 0"));
Vishnu Nair9b079a22020-01-21 14:36:08 -0800872}
873
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800874TEST_F(TimeStatsTest, canDumpWithMaxLayers) {
875 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
876
877 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
878 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
879 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
880 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
881 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 3, 2000000);
882
883 SFTimeStatsGlobalProto globalProto;
884 ASSERT_TRUE(
885 globalProto.ParseFromString(inputCommand(InputCommand::DUMP_MAXLAYERS_1, FMT_PROTO)));
886
887 ASSERT_EQ(1, globalProto.stats_size());
888 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
889 ASSERT_TRUE(layerProto.has_layer_name());
890 EXPECT_EQ(genLayerName(LAYER_ID_1), layerProto.layer_name());
891 ASSERT_TRUE(layerProto.has_total_frames());
892 EXPECT_EQ(2, layerProto.total_frames());
893}
894
895TEST_F(TimeStatsTest, canDumpWithInvalidMaxLayers) {
896 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
897
898 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
899 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
900
901 SFTimeStatsGlobalProto globalProto;
902 ASSERT_TRUE(globalProto.ParseFromString(
903 inputCommand(InputCommand::DUMP_MAXLAYERS_INVALID, FMT_PROTO)));
904
905 ASSERT_EQ(0, globalProto.stats_size());
906}
907
Yiwei Zhangdd221b22020-06-12 11:06:19 -0700908TEST_F(TimeStatsTest, noInfInAverageFPS) {
909 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
910 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
911 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 1000000);
912
913 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
914 EXPECT_THAT(result, HasSubstr("averageFPS = 0.000"));
915}
916
Alec Mouri37384342020-01-02 17:23:37 -0800917namespace {
918std::string buildExpectedHistogramBytestring(const std::vector<int32_t>& times,
919 const std::vector<int32_t>& frameCounts) {
920 util::ProtoOutputStream proto;
921 for (int i = 0; i < times.size(); i++) {
922 ALOGE("Writing time: %d", times[i]);
923 proto.write(util::FIELD_TYPE_INT32 | util::FIELD_COUNT_REPEATED | 1 /* field id */,
924 (int32_t)times[i]);
925 ALOGE("Writing count: %d", frameCounts[i]);
926 proto.write(util::FIELD_TYPE_INT64 | util::FIELD_COUNT_REPEATED | 2 /* field id */,
927 (int64_t)frameCounts[i]);
928 }
929 std::string byteString;
930 proto.serializeToString(&byteString);
931 return byteString;
932}
933
934std::string dumpByteStringHex(const std::string& str) {
935 std::stringstream ss;
936 ss << std::hex;
937 for (const char& c : str) {
938 ss << (int)c << " ";
939 }
940
941 return ss.str();
942}
943
944} // namespace
945
946MATCHER_P2(BytesEq, bytes, size, "") {
947 std::string expected;
948 expected.append((const char*)bytes, size);
949 std::string actual;
950 actual.append((const char*)arg, size);
951
952 *result_listener << "Bytes are not equal! \n";
953 *result_listener << "size: " << size << "\n";
954 *result_listener << "expected: " << dumpByteStringHex(expected).c_str() << "\n";
955 *result_listener << "actual: " << dumpByteStringHex(actual).c_str() << "\n";
956
957 return expected == actual;
958}
959
Alec Mouridfad9002020-02-12 17:49:09 -0800960TEST_F(TimeStatsTest, globalStatsCallback) {
961 constexpr size_t TOTAL_FRAMES = 5;
962 constexpr size_t MISSED_FRAMES = 4;
963 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
964 constexpr size_t DISPLAY_EVENT_CONNECTIONS = 14;
965
966 mTimeStats->onBootFinished();
967 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
968
969 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
970 mTimeStats->incrementTotalFrames();
971 }
972 for (size_t i = 0; i < MISSED_FRAMES; i++) {
973 mTimeStats->incrementMissedFrames();
974 }
975 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
976 mTimeStats->incrementClientCompositionFrames();
977 }
978
Alec Mouri9a29e672020-09-14 12:39:14 -0700979 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
980
Alec Mouridfad9002020-02-12 17:49:09 -0800981 mTimeStats->recordDisplayEventConnectionCount(DISPLAY_EVENT_CONNECTIONS);
Peiyong Lin65248e02020-04-18 21:15:07 -0700982 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouridfad9002020-02-12 17:49:09 -0800983 mTimeStats->recordFrameDuration(1000000, 3000000);
984 mTimeStats->recordRenderEngineDuration(2000000, 4000000);
985 mTimeStats->recordRenderEngineDuration(2000000, std::make_shared<FenceTime>(3000000));
986
987 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
988 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
989
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800990 mTimeStats->incrementJankyFrames(JankType::SurfaceFlingerCpuDeadlineMissed);
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100991 mTimeStats->incrementJankyFrames(JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -0800992 mTimeStats->incrementJankyFrames(JankType::DisplayHAL);
Jorim Jaggi5814ab82020-12-03 20:45:58 +0100993 mTimeStats->incrementJankyFrames(JankType::AppDeadlineMissed);
994 mTimeStats->incrementJankyFrames(JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -0700995
Alec Mouridfad9002020-02-12 17:49:09 -0800996 EXPECT_THAT(mDelegate->mAtomTags,
997 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
998 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
999 EXPECT_NE(nullptr, mDelegate->mCallback);
1000 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1001
1002 std::string expectedFrameDuration = buildExpectedHistogramBytestring({2}, {1});
1003 std::string expectedRenderEngineTiming = buildExpectedHistogramBytestring({1, 2}, {1, 1});
1004
1005 {
1006 InSequence seq;
1007 EXPECT_CALL(*mDelegate,
1008 statsEventSetAtomId(mDelegate->mEvent,
1009 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
1010 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, TOTAL_FRAMES));
1011 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, MISSED_FRAMES));
1012 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, CLIENT_COMPOSITION_FRAMES));
1013 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, _));
1014 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 2));
1015 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, DISPLAY_EVENT_CONNECTIONS));
1016 EXPECT_CALL(*mDelegate,
1017 statsEventWriteByteArray(mDelegate->mEvent,
1018 BytesEq((const uint8_t*)expectedFrameDuration.c_str(),
1019 expectedFrameDuration.size()),
1020 expectedFrameDuration.size()));
1021 EXPECT_CALL(*mDelegate,
1022 statsEventWriteByteArray(mDelegate->mEvent,
1023 BytesEq((const uint8_t*)
1024 expectedRenderEngineTiming.c_str(),
1025 expectedRenderEngineTiming.size()),
1026 expectedRenderEngineTiming.size()));
Alec Mouri9a29e672020-09-14 12:39:14 -07001027 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 5));
1028 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 4));
1029 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1030 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1031 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1032 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
Alec Mouridfad9002020-02-12 17:49:09 -08001033 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
1034 }
1035 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
1036 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1037 mDelegate->mCookie));
1038
1039 SFTimeStatsGlobalProto globalProto;
1040 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
1041
1042 EXPECT_EQ(0, globalProto.total_frames());
1043 EXPECT_EQ(0, globalProto.missed_frames());
1044 EXPECT_EQ(0, globalProto.client_composition_frames());
1045 EXPECT_EQ(0, globalProto.present_to_present_size());
1046}
1047
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001048TEST_F(TimeStatsTest, layerStatsCallback_pullsAllAndClears) {
1049 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
1050 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 3;
Alec Mouri37384342020-01-02 17:23:37 -08001051 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1052
1053 mTimeStats->onBootFinished();
1054
1055 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001056 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
1057 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
1058 }
1059 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
1060 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
1061 }
Alec Mouri37384342020-01-02 17:23:37 -08001062 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1063
Alec Mouri9a29e672020-09-14 12:39:14 -07001064 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001065 JankType::SurfaceFlingerCpuDeadlineMissed);
Alec Mouri9a29e672020-09-14 12:39:14 -07001066 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +01001067 JankType::SurfaceFlingerGpuDeadlineMissed);
Adithya Srinivasan9b2ca3e2020-11-10 10:14:17 -08001068 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::DisplayHAL);
Alec Mouri9a29e672020-09-14 12:39:14 -07001069 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0),
Jorim Jaggi5814ab82020-12-03 20:45:58 +01001070 JankType::AppDeadlineMissed);
1071 mTimeStats->incrementJankyFrames(UID_0, genLayerName(LAYER_ID_0), JankType::None);
Alec Mouri9a29e672020-09-14 12:39:14 -07001072
Alec Mouri37384342020-01-02 17:23:37 -08001073 EXPECT_THAT(mDelegate->mAtomTags,
1074 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1075 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1076 EXPECT_NE(nullptr, mDelegate->mCallback);
1077 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1078
1079 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {1});
1080 std::string expectedPostToPresent = buildExpectedHistogramBytestring({4}, {1});
1081 std::string expectedAcquireToPresent = buildExpectedHistogramBytestring({3}, {1});
1082 std::string expectedLatchToPresent = buildExpectedHistogramBytestring({2}, {1});
1083 std::string expectedDesiredToPresent = buildExpectedHistogramBytestring({1}, {1});
1084 std::string expectedPostToAcquire = buildExpectedHistogramBytestring({1}, {1});
1085 {
1086 InSequence seq;
1087 EXPECT_CALL(*mDelegate,
1088 statsEventSetAtomId(mDelegate->mEvent,
1089 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1090 EXPECT_CALL(*mDelegate,
1091 statsEventWriteString8(mDelegate->mEvent,
1092 StrEq(genLayerName(LAYER_ID_0).c_str())));
1093 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 1));
1094 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 0));
1095 EXPECT_CALL(*mDelegate,
1096 statsEventWriteByteArray(mDelegate->mEvent,
1097 BytesEq((const uint8_t*)
1098 expectedPresentToPresent.c_str(),
1099 expectedPresentToPresent.size()),
1100 expectedPresentToPresent.size()));
1101 EXPECT_CALL(*mDelegate,
1102 statsEventWriteByteArray(mDelegate->mEvent,
1103 BytesEq((const uint8_t*)expectedPostToPresent.c_str(),
1104 expectedPostToPresent.size()),
1105 expectedPostToPresent.size()));
1106 EXPECT_CALL(*mDelegate,
1107 statsEventWriteByteArray(mDelegate->mEvent,
1108 BytesEq((const uint8_t*)
1109 expectedAcquireToPresent.c_str(),
1110 expectedAcquireToPresent.size()),
1111 expectedAcquireToPresent.size()));
1112 EXPECT_CALL(*mDelegate,
1113 statsEventWriteByteArray(mDelegate->mEvent,
1114 BytesEq((const uint8_t*)expectedLatchToPresent.c_str(),
1115 expectedLatchToPresent.size()),
1116 expectedLatchToPresent.size()));
1117 EXPECT_CALL(*mDelegate,
1118 statsEventWriteByteArray(mDelegate->mEvent,
1119 BytesEq((const uint8_t*)
1120 expectedDesiredToPresent.c_str(),
1121 expectedDesiredToPresent.size()),
1122 expectedDesiredToPresent.size()));
1123 EXPECT_CALL(*mDelegate,
1124 statsEventWriteByteArray(mDelegate->mEvent,
1125 BytesEq((const uint8_t*)expectedPostToAcquire.c_str(),
1126 expectedPostToAcquire.size()),
1127 expectedPostToAcquire.size()));
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001128 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, LATE_ACQUIRE_FRAMES));
1129 EXPECT_CALL(*mDelegate,
1130 statsEventWriteInt64(mDelegate->mEvent, BAD_DESIRED_PRESENT_FRAMES));
Alec Mouri9a29e672020-09-14 12:39:14 -07001131 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, UID_0));
1132 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 5));
1133 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 4));
1134 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1135 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1136 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1137 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1138
Alec Mouri37384342020-01-02 17:23:37 -08001139 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
1140 }
Tej Singh2a457b62020-01-31 16:16:10 -08001141 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001142 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1143 mDelegate->mCookie));
1144
1145 SFTimeStatsGlobalProto globalProto;
1146 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
1147
1148 EXPECT_EQ(0, globalProto.stats_size());
1149}
1150
1151TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleLayers) {
1152 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1153
1154 mTimeStats->onBootFinished();
1155
1156 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1157 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1158 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1159 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1160
1161 EXPECT_THAT(mDelegate->mAtomTags,
1162 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1163 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1164 EXPECT_NE(nullptr, mDelegate->mCallback);
1165 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1166
1167 EXPECT_CALL(*mDelegate,
1168 statsEventSetAtomId(mDelegate->mEvent,
1169 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1170 .Times(2);
1171 EXPECT_CALL(*mDelegate,
1172 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_0).c_str())));
1173 EXPECT_CALL(*mDelegate,
1174 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001175 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001176 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1177 mDelegate->mCookie));
1178}
1179
1180TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleBuckets) {
1181 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1182
1183 mTimeStats->onBootFinished();
1184
1185 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1186 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1187 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1188 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1189
Tej Singh38a4b212020-03-13 19:04:51 -07001190 // Now make sure that TimeStats flushes global stats to set the callback.
Peiyong Lin65248e02020-04-18 21:15:07 -07001191 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouri37384342020-01-02 17:23:37 -08001192 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
1193 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
1194 EXPECT_THAT(mDelegate->mAtomTags,
1195 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1196 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1197 EXPECT_NE(nullptr, mDelegate->mCallback);
1198 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1199
1200 EXPECT_THAT(mDelegate->mAtomTags,
1201 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1202 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1203 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1, 2}, {2, 1});
1204 {
1205 InSequence seq;
1206 EXPECT_CALL(*mDelegate,
1207 statsEventWriteByteArray(mDelegate->mEvent,
1208 BytesEq((const uint8_t*)
1209 expectedPresentToPresent.c_str(),
1210 expectedPresentToPresent.size()),
1211 expectedPresentToPresent.size()));
1212 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1213 .Times(AnyNumber());
1214 }
Tej Singh2a457b62020-01-31 16:16:10 -08001215 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001216 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1217 mDelegate->mCookie));
1218}
1219
1220TEST_F(TimeStatsTest, layerStatsCallback_limitsHistogramBuckets) {
1221 mDelegate = new FakeStatsEventDelegate;
1222 mTimeStats =
1223 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
1224 std::nullopt, 1);
1225 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1226
1227 mTimeStats->onBootFinished();
1228
1229 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1230 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1231 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1232 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1233
1234 EXPECT_THAT(mDelegate->mAtomTags,
1235 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1236 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1237 EXPECT_NE(nullptr, mDelegate->mCallback);
1238 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1239
1240 EXPECT_THAT(mDelegate->mAtomTags,
1241 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1242 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1243 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {2});
1244 {
1245 InSequence seq;
1246 EXPECT_CALL(*mDelegate,
1247 statsEventWriteByteArray(mDelegate->mEvent,
1248 BytesEq((const uint8_t*)
1249 expectedPresentToPresent.c_str(),
1250 expectedPresentToPresent.size()),
1251 expectedPresentToPresent.size()));
1252 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1253 .Times(AnyNumber());
1254 }
Tej Singh2a457b62020-01-31 16:16:10 -08001255 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001256 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1257 mDelegate->mCookie));
1258}
1259
1260TEST_F(TimeStatsTest, layerStatsCallback_limitsLayers) {
1261 mDelegate = new FakeStatsEventDelegate;
1262 mTimeStats =
1263 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate), 1,
1264 std::nullopt);
1265 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1266
1267 mTimeStats->onBootFinished();
1268
1269 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1270 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1271 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1272 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1273 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 4, 5000000);
1274
1275 EXPECT_THAT(mDelegate->mAtomTags,
1276 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1277 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1278 EXPECT_NE(nullptr, mDelegate->mCallback);
1279 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1280
1281 EXPECT_CALL(*mDelegate,
1282 statsEventSetAtomId(mDelegate->mEvent,
1283 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1284 .Times(1);
1285 EXPECT_CALL(*mDelegate,
1286 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001287 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001288 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1289 mDelegate->mCookie));
1290}
1291
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001292TEST_F(TimeStatsTest, canSurviveMonkey) {
Lloyd Pique067fe1e2018-12-06 19:44:13 -08001293 if (g_noSlowTests) {
1294 GTEST_SKIP();
1295 }
1296
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001297 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1298
1299 for (size_t i = 0; i < 10000000; ++i) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001300 const int32_t layerId = genRandomInt32(-1, 10);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001301 const int32_t frameNumber = genRandomInt32(1, 10);
1302 switch (genRandomInt32(0, 100)) {
1303 case 0:
1304 ALOGV("removeTimeRecord");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001305 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(layerId, frameNumber));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001306 continue;
1307 case 1:
1308 ALOGV("onDestroy");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001309 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(layerId));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001310 continue;
1311 }
1312 TimeStamp type = static_cast<TimeStamp>(genRandomInt32(TIME_STAMP_BEGIN, TIME_STAMP_END));
1313 const int32_t ts = genRandomInt32(1, 1000000000);
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001314 ALOGV("type[%d], layerId[%d], frameNumber[%d], ts[%d]", type, layerId, frameNumber, ts);
1315 setTimeStamp(type, layerId, frameNumber, ts);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001316 }
1317}
1318
1319} // namespace
1320} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -08001321
1322// TODO(b/129481165): remove the #pragma below and fix conversion issues
1323#pragma clang diagnostic pop // ignored "-Wconversion"