blob: e90366448c8c54209ccd0c0b8172738694c3d64a [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"
Marin Shalamanovbed7fd32020-12-21 20:02:20 +010020#pragma clang diagnostic ignored "-Wextra"
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -080021
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080022#undef LOG_TAG
23#define LOG_TAG "LibSurfaceFlingerUnittests"
24
Mikael Pessa2e1608f2019-07-19 11:25:35 -070025#include <TimeStats/TimeStats.h>
Alec Mouri37384342020-01-02 17:23:37 -080026#include <android/util/ProtoOutputStream.h>
Alec Mourifb571ea2019-01-24 18:42:10 -080027#include <gmock/gmock.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080028#include <gtest/gtest.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080029#include <log/log.h>
30#include <utils/String16.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080031#include <utils/Vector.h>
32
Alec Mouri9519bf12019-11-15 16:54:44 -080033#include <chrono>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080034#include <random>
Alec Mourifb571ea2019-01-24 18:42:10 -080035#include <unordered_set>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080036
Lloyd Pique067fe1e2018-12-06 19:44:13 -080037#include "libsurfaceflinger_unittest_main.h"
38
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080039using namespace android::surfaceflinger;
40using namespace google::protobuf;
Vishnu Nairabf97fd2020-02-03 13:51:16 -080041using namespace std::chrono_literals;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080042
43namespace android {
44namespace {
45
Alec Mouri8e2f31b2020-01-16 22:04:35 +000046using testing::_;
Alec Mouri37384342020-01-02 17:23:37 -080047using testing::AnyNumber;
Alec Mourifb571ea2019-01-24 18:42:10 -080048using testing::Contains;
Vishnu Nair9b079a22020-01-21 14:36:08 -080049using testing::HasSubstr;
Alec Mouri8e2f31b2020-01-16 22:04:35 +000050using testing::InSequence;
Alec Mourifb571ea2019-01-24 18:42:10 -080051using testing::SizeIs;
Alec Mouri37384342020-01-02 17:23:37 -080052using testing::StrEq;
Alec Mourifb571ea2019-01-24 18:42:10 -080053using testing::UnorderedElementsAre;
54
Peiyong Lin65248e02020-04-18 21:15:07 -070055using PowerMode = hardware::graphics::composer::V2_4::IComposerClient::PowerMode;
56
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080057// clang-format off
Alec Mouri7d436ec2021-01-27 20:40:50 -080058#define FMT_PROTO true
59#define FMT_STRING false
60#define LAYER_ID_0 0
61#define LAYER_ID_1 1
62#define UID_0 123
63#define REFRESH_RATE_0 61
64#define RENDER_RATE_0 31
65#define REFRESH_RATE_BUCKET_0 60
66#define RENDER_RATE_BUCKET_0 30
67#define LAYER_ID_INVALID -1
68#define NUM_LAYERS 1
69#define NUM_LAYERS_INVALID "INVALID"
70
71const constexpr Fps kRefreshRate0 = Fps(static_cast<float>(REFRESH_RATE_0));
72const constexpr Fps kRenderRate0 = Fps(static_cast<float>(RENDER_RATE_0));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080073
74enum InputCommand : int32_t {
75 ENABLE = 0,
76 DISABLE = 1,
77 CLEAR = 2,
78 DUMP_ALL = 3,
79 DUMP_MAXLAYERS_1 = 4,
80 DUMP_MAXLAYERS_INVALID = 5,
81 INPUT_COMMAND_BEGIN = ENABLE,
82 INPUT_COMMAND_END = DUMP_MAXLAYERS_INVALID,
83 INPUT_COMMAND_RANGE = INPUT_COMMAND_END - INPUT_COMMAND_BEGIN + 1,
84};
85
86enum TimeStamp : int32_t {
87 POST = 0,
88 ACQUIRE = 1,
89 ACQUIRE_FENCE = 2,
90 LATCH = 3,
91 DESIRED = 4,
92 PRESENT = 5,
93 PRESENT_FENCE = 6,
94 TIME_STAMP_BEGIN = POST,
95 TIME_STAMP_END = PRESENT,
96 TIME_STAMP_RANGE = TIME_STAMP_END - TIME_STAMP_BEGIN + 1,
97};
98
99static const TimeStamp NORMAL_SEQUENCE[] = {
100 TimeStamp::POST,
101 TimeStamp::ACQUIRE,
102 TimeStamp::LATCH,
103 TimeStamp::DESIRED,
104 TimeStamp::PRESENT,
105};
106
107static const TimeStamp NORMAL_SEQUENCE_2[] = {
108 TimeStamp::POST,
109 TimeStamp::ACQUIRE_FENCE,
110 TimeStamp::LATCH,
111 TimeStamp::DESIRED,
112 TimeStamp::PRESENT_FENCE,
113};
114
115static const TimeStamp UNORDERED_SEQUENCE[] = {
116 TimeStamp::ACQUIRE,
117 TimeStamp::LATCH,
118 TimeStamp::POST,
119 TimeStamp::DESIRED,
120 TimeStamp::PRESENT,
121};
122
123static const TimeStamp INCOMPLETE_SEQUENCE[] = {
124 TimeStamp::POST,
125};
126// clang-format on
127
128class TimeStatsTest : public testing::Test {
129public:
130 TimeStatsTest() {
131 const ::testing::TestInfo* const test_info =
132 ::testing::UnitTest::GetInstance()->current_test_info();
133 ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
134 }
135
136 ~TimeStatsTest() {
137 const ::testing::TestInfo* const test_info =
138 ::testing::UnitTest::GetInstance()->current_test_info();
139 ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
140 }
141
142 std::string inputCommand(InputCommand cmd, bool useProto);
143
144 void setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts);
145
146 int32_t genRandomInt32(int32_t begin, int32_t end);
147
148 template <size_t N>
149 void insertTimeRecord(const TimeStamp (&sequence)[N], int32_t id, uint64_t frameNumber,
150 nsecs_t ts) {
151 for (size_t i = 0; i < N; i++, ts += 1000000) {
152 setTimeStamp(sequence[i], id, frameNumber, ts);
153 }
154 }
155
156 std::mt19937 mRandomEngine = std::mt19937(std::random_device()());
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000157
158 class FakeStatsEventDelegate : public impl::TimeStats::StatsEventDelegate {
159 public:
160 FakeStatsEventDelegate() = default;
161 ~FakeStatsEventDelegate() override = default;
162
Tej Singh2a457b62020-01-31 16:16:10 -0800163 struct AStatsEvent* addStatsEventToPullData(AStatsEventList*) override {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000164 return mEvent;
165 }
Tej Singh38a4b212020-03-13 19:04:51 -0700166 void setStatsPullAtomCallback(int32_t atom_tag, AStatsManager_PullAtomMetadata*,
167 AStatsManager_PullAtomCallback callback,
168 void* cookie) override {
Alec Mouri37384342020-01-02 17:23:37 -0800169 mAtomTags.push_back(atom_tag);
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000170 mCallback = callback;
171 mCookie = cookie;
172 }
173
Tej Singh2a457b62020-01-31 16:16:10 -0800174 AStatsManager_PullAtomCallbackReturn makePullAtomCallback(int32_t atom_tag, void* cookie) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000175 return (*mCallback)(atom_tag, nullptr, cookie);
176 }
177
Tej Singh38a4b212020-03-13 19:04:51 -0700178 MOCK_METHOD1(clearStatsPullAtomCallback, void(int32_t));
Tej Singh2a457b62020-01-31 16:16:10 -0800179 MOCK_METHOD2(statsEventSetAtomId, void(AStatsEvent*, uint32_t));
Alec Mouri717bcb62020-02-10 17:07:19 -0800180 MOCK_METHOD2(statsEventWriteInt32, void(AStatsEvent*, int32_t));
Tej Singh2a457b62020-01-31 16:16:10 -0800181 MOCK_METHOD2(statsEventWriteInt64, void(AStatsEvent*, int64_t));
182 MOCK_METHOD2(statsEventWriteString8, void(AStatsEvent*, const char*));
183 MOCK_METHOD3(statsEventWriteByteArray, void(AStatsEvent*, const uint8_t*, size_t));
184 MOCK_METHOD1(statsEventBuild, void(AStatsEvent*));
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000185
Tej Singh2a457b62020-01-31 16:16:10 -0800186 AStatsEvent* mEvent = AStatsEvent_obtain();
Alec Mouri37384342020-01-02 17:23:37 -0800187 std::vector<int32_t> mAtomTags;
Tej Singh2a457b62020-01-31 16:16:10 -0800188 AStatsManager_PullAtomCallback mCallback = nullptr;
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000189 void* mCookie = nullptr;
190 };
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000191 FakeStatsEventDelegate* mDelegate = new FakeStatsEventDelegate;
192 std::unique_ptr<TimeStats> mTimeStats =
Alec Mouri37384342020-01-02 17:23:37 -0800193 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
194 std::nullopt, std::nullopt);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800195};
196
197std::string TimeStatsTest::inputCommand(InputCommand cmd, bool useProto) {
Yiwei Zhang5434a782018-12-05 18:06:32 -0800198 std::string result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800199 Vector<String16> args;
200
201 switch (cmd) {
202 case InputCommand::ENABLE:
203 args.push_back(String16("-enable"));
204 break;
205 case InputCommand::DISABLE:
206 args.push_back(String16("-disable"));
207 break;
208 case InputCommand::CLEAR:
209 args.push_back(String16("-clear"));
210 break;
211 case InputCommand::DUMP_ALL:
212 args.push_back(String16("-dump"));
213 break;
214 case InputCommand::DUMP_MAXLAYERS_1:
215 args.push_back(String16("-dump"));
216 args.push_back(String16("-maxlayers"));
217 args.push_back(String16(std::to_string(NUM_LAYERS).c_str()));
218 break;
219 case InputCommand::DUMP_MAXLAYERS_INVALID:
220 args.push_back(String16("-dump"));
221 args.push_back(String16("-maxlayers"));
222 args.push_back(String16(NUM_LAYERS_INVALID));
223 break;
224 default:
225 ALOGD("Invalid control command");
226 }
227
Dominik Laskowskic2867142019-01-21 11:33:38 -0800228 EXPECT_NO_FATAL_FAILURE(mTimeStats->parseArgs(useProto, args, result));
Yiwei Zhang5434a782018-12-05 18:06:32 -0800229 return result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800230}
231
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800232static std::string genLayerName(int32_t layerId) {
Peiyong Lind8460c82020-07-28 16:04:22 -0700233 return (layerId < 0 ? "PopupWindow:b54fcd1#0" : "com.example.fake#") + std::to_string(layerId);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800234}
235
236void TimeStatsTest::setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts) {
237 switch (type) {
238 case TimeStamp::POST:
Alec Mouri9a29e672020-09-14 12:39:14 -0700239 ASSERT_NO_FATAL_FAILURE(
240 mTimeStats->setPostTime(id, frameNumber, genLayerName(id), UID_0, ts));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800241 break;
242 case TimeStamp::ACQUIRE:
243 ASSERT_NO_FATAL_FAILURE(mTimeStats->setAcquireTime(id, frameNumber, ts));
244 break;
245 case TimeStamp::ACQUIRE_FENCE:
246 ASSERT_NO_FATAL_FAILURE(
247 mTimeStats->setAcquireFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
248 break;
249 case TimeStamp::LATCH:
250 ASSERT_NO_FATAL_FAILURE(mTimeStats->setLatchTime(id, frameNumber, ts));
251 break;
252 case TimeStamp::DESIRED:
253 ASSERT_NO_FATAL_FAILURE(mTimeStats->setDesiredTime(id, frameNumber, ts));
254 break;
255 case TimeStamp::PRESENT:
Alec Mouri7d436ec2021-01-27 20:40:50 -0800256 ASSERT_NO_FATAL_FAILURE(
257 mTimeStats->setPresentTime(id, frameNumber, ts, kRefreshRate0, kRenderRate0));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800258 break;
259 case TimeStamp::PRESENT_FENCE:
Alec Mouri7d436ec2021-01-27 20:40:50 -0800260 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPresentFence(id, frameNumber,
261 std::make_shared<FenceTime>(ts),
262 kRefreshRate0, kRenderRate0));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800263 break;
264 default:
265 ALOGD("Invalid timestamp type");
266 }
267}
268
269int32_t TimeStatsTest::genRandomInt32(int32_t begin, int32_t end) {
270 std::uniform_int_distribution<int32_t> distr(begin, end);
271 return distr(mRandomEngine);
272}
273
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000274TEST_F(TimeStatsTest, disabledByDefault) {
275 ASSERT_FALSE(mTimeStats->isEnabled());
276}
277
Tej Singh38a4b212020-03-13 19:04:51 -0700278TEST_F(TimeStatsTest, setsCallbacksAfterBoot) {
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000279 mTimeStats->onBootFinished();
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800280 EXPECT_THAT(mDelegate->mAtomTags,
281 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
282 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
283}
284
Tej Singh38a4b212020-03-13 19:04:51 -0700285TEST_F(TimeStatsTest, clearsCallbacksOnDestruction) {
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800286 EXPECT_CALL(*mDelegate,
Tej Singh38a4b212020-03-13 19:04:51 -0700287 clearStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800288 EXPECT_CALL(*mDelegate,
Tej Singh38a4b212020-03-13 19:04:51 -0700289 clearStatsPullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO));
Alec Mouri3ecd5cd2020-01-29 12:53:07 -0800290 mTimeStats.reset();
Alec Mourib3885ad2019-09-06 17:08:55 -0700291}
292
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800293TEST_F(TimeStatsTest, canEnableAndDisableTimeStats) {
294 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
295 ASSERT_TRUE(mTimeStats->isEnabled());
296
297 EXPECT_TRUE(inputCommand(InputCommand::DISABLE, FMT_STRING).empty());
298 ASSERT_FALSE(mTimeStats->isEnabled());
299}
300
301TEST_F(TimeStatsTest, canIncreaseGlobalStats) {
302 constexpr size_t TOTAL_FRAMES = 5;
303 constexpr size_t MISSED_FRAMES = 4;
304 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
305
306 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
307
308 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
309 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
310 }
311 for (size_t i = 0; i < MISSED_FRAMES; i++) {
312 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
313 }
314 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
315 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
316 }
317
318 SFTimeStatsGlobalProto globalProto;
319 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
320
321 ASSERT_TRUE(globalProto.has_total_frames());
322 EXPECT_EQ(TOTAL_FRAMES, globalProto.total_frames());
323 ASSERT_TRUE(globalProto.has_missed_frames());
324 EXPECT_EQ(MISSED_FRAMES, globalProto.missed_frames());
325 ASSERT_TRUE(globalProto.has_client_composition_frames());
326 EXPECT_EQ(CLIENT_COMPOSITION_FRAMES, globalProto.client_composition_frames());
327}
328
Alec Mouri91f6df32020-01-30 08:48:58 -0800329TEST_F(TimeStatsTest, canIncreaseLateAcquireFrames) {
330 // this stat is not in the proto so verify by checking the string dump
331 constexpr size_t LATE_ACQUIRE_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 < LATE_ACQUIRE_FRAMES; i++) {
337 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
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 = "lateAcquireFrames = " + std::to_string(LATE_ACQUIRE_FRAMES);
343 EXPECT_THAT(result, HasSubstr(expectedResult));
344}
345
346TEST_F(TimeStatsTest, canIncreaseBadDesiredPresent) {
347 // this stat is not in the proto so verify by checking the string dump
348 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 2;
349
350 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
351
352 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
353 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
354 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
355 }
356 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
357
358 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
359 const std::string expectedResult =
360 "badDesiredPresentFrames = " + std::to_string(BAD_DESIRED_PRESENT_FRAMES);
361 EXPECT_THAT(result, HasSubstr(expectedResult));
362}
363
Alec Mouri9a29e672020-09-14 12:39:14 -0700364TEST_F(TimeStatsTest, canIncreaseJankyFramesForLayer) {
365 // this stat is not in the proto so verify by checking the string dump
366 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
367
368 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
Alec Mouri363faf02021-01-29 16:34:55 -0800369 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
370 JankType::SurfaceFlingerCpuDeadlineMissed, 1, 2, 3});
371 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
372 JankType::SurfaceFlingerGpuDeadlineMissed, 1, 2, 3});
373 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
374 JankType::DisplayHAL, 1, 2, 3});
375 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
376 JankType::AppDeadlineMissed, 1, 2, 3});
377 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasanead17162021-02-18 02:17:37 +0000378 JankType::SurfaceFlingerScheduling, 1, 2, 3});
379 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
380 JankType::PredictionError, 1, 2, 3});
381 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
382 JankType::AppDeadlineMissed | JankType::BufferStuffing, 1, 2,
383 3});
384 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Alec Mouri363faf02021-01-29 16:34:55 -0800385 JankType::None, 1, 2, 3});
Alec Mouri9a29e672020-09-14 12:39:14 -0700386
387 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
Alec Mouri7d436ec2021-01-27 20:40:50 -0800388 std::string expectedResult =
389 "displayRefreshRate = " + std::to_string(REFRESH_RATE_BUCKET_0) + " fps";
390 EXPECT_THAT(result, HasSubstr(expectedResult));
391 expectedResult = "renderRate = " + std::to_string(RENDER_RATE_BUCKET_0) + " fps";
392 EXPECT_THAT(result, HasSubstr(expectedResult));
Adithya Srinivasanead17162021-02-18 02:17:37 +0000393 expectedResult = "totalTimelineFrames = " + std::to_string(8);
Alec Mouri9a29e672020-09-14 12:39:14 -0700394 EXPECT_THAT(result, HasSubstr(expectedResult));
Adithya Srinivasanead17162021-02-18 02:17:37 +0000395 expectedResult = "jankyFrames = " + std::to_string(7);
Alec Mouri9a29e672020-09-14 12:39:14 -0700396 EXPECT_THAT(result, HasSubstr(expectedResult));
397 expectedResult = "sfLongCpuJankyFrames = " + std::to_string(1);
398 EXPECT_THAT(result, HasSubstr(expectedResult));
399 expectedResult = "sfLongGpuJankyFrames = " + std::to_string(1);
400 EXPECT_THAT(result, HasSubstr(expectedResult));
Adithya Srinivasanead17162021-02-18 02:17:37 +0000401 expectedResult = "sfUnattributedJankyFrames = " + std::to_string(1);
Alec Mouri9a29e672020-09-14 12:39:14 -0700402 EXPECT_THAT(result, HasSubstr(expectedResult));
Adithya Srinivasanead17162021-02-18 02:17:37 +0000403 expectedResult = "appUnattributedJankyFrames = " + std::to_string(2);
404 EXPECT_THAT(result, HasSubstr(expectedResult));
405 expectedResult = "sfSchedulingJankyFrames = " + std::to_string(1);
406 EXPECT_THAT(result, HasSubstr(expectedResult));
407 expectedResult = "sfPredictionErrorJankyFrames = " + std::to_string(1);
408 EXPECT_THAT(result, HasSubstr(expectedResult));
409 expectedResult = "appBufferStuffingJankyFrames = " + std::to_string(1);
Alec Mouri9a29e672020-09-14 12:39:14 -0700410 EXPECT_THAT(result, HasSubstr(expectedResult));
411}
412
Vishnu Nair9b079a22020-01-21 14:36:08 -0800413TEST_F(TimeStatsTest, canIncreaseClientCompositionReusedFrames) {
414 // this stat is not in the proto so verify by checking the string dump
415 constexpr size_t CLIENT_COMPOSITION_REUSED_FRAMES = 2;
416
417 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
418 for (size_t i = 0; i < CLIENT_COMPOSITION_REUSED_FRAMES; i++) {
419 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
420 }
421
422 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
423 const std::string expectedResult =
424 "clientCompositionReusedFrames = " + std::to_string(CLIENT_COMPOSITION_REUSED_FRAMES);
425 EXPECT_THAT(result, HasSubstr(expectedResult));
426}
427
Alec Mouri8de697e2020-03-19 10:52:01 -0700428TEST_F(TimeStatsTest, canIncreaseRefreshRateSwitches) {
429 // this stat is not in the proto so verify by checking the string dump
430 constexpr size_t REFRESH_RATE_SWITCHES = 2;
431
432 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
433 for (size_t i = 0; i < REFRESH_RATE_SWITCHES; i++) {
434 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementRefreshRateSwitches());
435 }
436
437 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
438 const std::string expectedResult =
439 "refreshRateSwitches = " + std::to_string(REFRESH_RATE_SWITCHES);
440 EXPECT_THAT(result, HasSubstr(expectedResult));
441}
442
Alec Mouri8f7a0102020-04-15 12:11:10 -0700443TEST_F(TimeStatsTest, canIncreaseCompositionStrategyChanges) {
444 // this stat is not in the proto so verify by checking the string dump
445 constexpr size_t COMPOSITION_STRATEGY_CHANGES = 2;
446
447 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
448 for (size_t i = 0; i < COMPOSITION_STRATEGY_CHANGES; i++) {
449 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementCompositionStrategyChanges());
450 }
451
452 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
453 const std::string expectedResult =
454 "compositionStrategyChanges = " + std::to_string(COMPOSITION_STRATEGY_CHANGES);
455 EXPECT_THAT(result, HasSubstr(expectedResult));
456}
457
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800458TEST_F(TimeStatsTest, canAverageFrameDuration) {
459 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
Peiyong Lin65248e02020-04-18 21:15:07 -0700460 mTimeStats->setPowerMode(PowerMode::ON);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000461 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(1ms).count(),
462 std::chrono::nanoseconds(6ms).count());
463 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(1ms).count(),
464 std::chrono::nanoseconds(16ms).count());
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800465
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());
Adithya Srinivasanead17162021-02-18 02:17:37 +0000472 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(1ms).count(),
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800473 std::make_shared<FenceTime>(
474 std::chrono::duration_cast<
475 std::chrono::nanoseconds>(3ms)
476 .count()));
477
Adithya Srinivasanead17162021-02-18 02:17:37 +0000478 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(4ms).count(),
479 std::chrono::nanoseconds(8ms).count());
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800480
Peiyong Lind8460c82020-07-28 16:04:22 -0700481 // Push a fake present fence to trigger flushing the RenderEngine timings.
Peiyong Lin65248e02020-04-18 21:15:07 -0700482 mTimeStats->setPowerMode(PowerMode::ON);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000483 mTimeStats->setPresentFenceGlobal(
484 std::make_shared<FenceTime>(std::chrono::nanoseconds(1ms).count()));
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800485
486 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
487 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 3.000 ms"));
488}
489
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800490TEST_F(TimeStatsTest, canInsertGlobalPresentToPresent) {
491 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
492
493 ASSERT_NO_FATAL_FAILURE(
494 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
495 ASSERT_NO_FATAL_FAILURE(
496 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
497
Peiyong Lin65248e02020-04-18 21:15:07 -0700498 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::ON));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800499 ASSERT_NO_FATAL_FAILURE(
500 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000)));
501 ASSERT_NO_FATAL_FAILURE(
502 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000)));
503
Peiyong Lin65248e02020-04-18 21:15:07 -0700504 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::OFF));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800505 ASSERT_NO_FATAL_FAILURE(
506 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(6000000)));
507 ASSERT_NO_FATAL_FAILURE(
508 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(8000000)));
509
510 SFTimeStatsGlobalProto globalProto;
511 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
512
513 ASSERT_EQ(1, globalProto.present_to_present_size());
514 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.present_to_present().Get(0);
515 EXPECT_EQ(1, histogramProto.frame_count());
516 EXPECT_EQ(2, histogramProto.time_millis());
517}
518
Alec Mouri9519bf12019-11-15 16:54:44 -0800519TEST_F(TimeStatsTest, canInsertGlobalFrameDuration) {
520 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
521
Peiyong Lin65248e02020-04-18 21:15:07 -0700522 mTimeStats->setPowerMode(PowerMode::OFF);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000523 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(1ms).count(),
524 std::chrono::nanoseconds(5ms).count());
Peiyong Lin65248e02020-04-18 21:15:07 -0700525 mTimeStats->setPowerMode(PowerMode::ON);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000526 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(3ms).count(),
527 std::chrono::nanoseconds(6ms).count());
Alec Mouri9519bf12019-11-15 16:54:44 -0800528
529 SFTimeStatsGlobalProto globalProto;
530 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
531
532 ASSERT_EQ(1, globalProto.frame_duration_size());
533 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.frame_duration().Get(0);
534 EXPECT_EQ(1, histogramProto.frame_count());
535 EXPECT_EQ(3, histogramProto.time_millis());
536}
537
Alec Mourie4034bb2019-11-19 12:45:54 -0800538TEST_F(TimeStatsTest, canInsertGlobalRenderEngineTiming) {
539 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
540
Adithya Srinivasanead17162021-02-18 02:17:37 +0000541 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(1ms).count(),
Alec Mourie4034bb2019-11-19 12:45:54 -0800542 std::make_shared<FenceTime>(
543 std::chrono::duration_cast<
544 std::chrono::nanoseconds>(3ms)
545 .count()));
546
Adithya Srinivasanead17162021-02-18 02:17:37 +0000547 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(4ms).count(),
548 std::chrono::nanoseconds(6ms).count());
Alec Mourie4034bb2019-11-19 12:45:54 -0800549
550 // First verify that flushing RenderEngine durations did not occur yet.
551 SFTimeStatsGlobalProto preFlushProto;
552 ASSERT_TRUE(preFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
553 ASSERT_EQ(0, preFlushProto.render_engine_timing_size());
554
Peiyong Lind8460c82020-07-28 16:04:22 -0700555 // Push a fake present fence to trigger flushing the RenderEngine timings.
Peiyong Lin65248e02020-04-18 21:15:07 -0700556 mTimeStats->setPowerMode(PowerMode::ON);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000557 mTimeStats->setPresentFenceGlobal(
558 std::make_shared<FenceTime>(std::chrono::nanoseconds(1ms).count()));
Alec Mourie4034bb2019-11-19 12:45:54 -0800559
560 // Now we can verify that RenderEngine durations were flushed now.
561 SFTimeStatsGlobalProto postFlushProto;
562 ASSERT_TRUE(postFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
563
564 ASSERT_EQ(1, postFlushProto.render_engine_timing_size());
565 const SFTimeStatsHistogramBucketProto& histogramProto =
566 postFlushProto.render_engine_timing().Get(0);
567 EXPECT_EQ(2, histogramProto.frame_count());
568 EXPECT_EQ(2, histogramProto.time_millis());
569}
570
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800571TEST_F(TimeStatsTest, canInsertOneLayerTimeStats) {
572 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
573
574 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
575 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
576
577 SFTimeStatsGlobalProto globalProto;
578 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
579
580 ASSERT_EQ(1, globalProto.stats_size());
581 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
582 ASSERT_TRUE(layerProto.has_layer_name());
583 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
584 ASSERT_TRUE(layerProto.has_total_frames());
585 EXPECT_EQ(1, layerProto.total_frames());
586 ASSERT_EQ(6, layerProto.deltas_size());
587 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
588 ASSERT_EQ(1, deltaProto.histograms_size());
589 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
590 EXPECT_EQ(1, histogramProto.frame_count());
591 if ("post2acquire" == deltaProto.delta_name()) {
592 EXPECT_EQ(1, histogramProto.time_millis());
593 } else if ("post2present" == deltaProto.delta_name()) {
594 EXPECT_EQ(4, histogramProto.time_millis());
595 } else if ("acquire2present" == deltaProto.delta_name()) {
596 EXPECT_EQ(3, histogramProto.time_millis());
597 } else if ("latch2present" == deltaProto.delta_name()) {
598 EXPECT_EQ(2, histogramProto.time_millis());
599 } else if ("desired2present" == deltaProto.delta_name()) {
600 EXPECT_EQ(1, histogramProto.time_millis());
601 } else if ("present2present" == deltaProto.delta_name()) {
602 EXPECT_EQ(1, histogramProto.time_millis());
603 } else {
604 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
605 }
606 }
607}
608
609TEST_F(TimeStatsTest, canNotInsertInvalidLayerNameTimeStats) {
610 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
611
612 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_INVALID, 1, 1000000);
613 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_INVALID, 2, 2000000);
614
615 SFTimeStatsGlobalProto globalProto;
616 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
617
618 ASSERT_EQ(0, globalProto.stats_size());
619}
620
621TEST_F(TimeStatsTest, canInsertMultipleLayersTimeStats) {
622 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
623
624 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
625 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
626 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
627 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
628
629 SFTimeStatsGlobalProto globalProto;
630 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
631
632 EXPECT_EQ(2, globalProto.stats_size());
633}
634
635TEST_F(TimeStatsTest, canInsertUnorderedLayerTimeStats) {
636 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
637
638 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
639 insertTimeRecord(UNORDERED_SEQUENCE, LAYER_ID_0, 2, 2000000);
640
641 SFTimeStatsGlobalProto globalProto;
642 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
643
644 ASSERT_EQ(1, globalProto.stats_size());
645 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
646 ASSERT_TRUE(layerProto.has_layer_name());
647 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
648 ASSERT_TRUE(layerProto.has_total_frames());
649 EXPECT_EQ(1, layerProto.total_frames());
650 ASSERT_EQ(6, layerProto.deltas_size());
651 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
652 ASSERT_EQ(1, deltaProto.histograms_size());
653 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
654 EXPECT_EQ(1, histogramProto.frame_count());
655 if ("post2acquire" == deltaProto.delta_name()) {
656 EXPECT_EQ(0, histogramProto.time_millis());
657 } else if ("post2present" == deltaProto.delta_name()) {
658 EXPECT_EQ(2, histogramProto.time_millis());
659 } else if ("acquire2present" == deltaProto.delta_name()) {
660 EXPECT_EQ(2, histogramProto.time_millis());
661 } else if ("latch2present" == deltaProto.delta_name()) {
662 EXPECT_EQ(2, histogramProto.time_millis());
663 } else if ("desired2present" == deltaProto.delta_name()) {
664 EXPECT_EQ(1, histogramProto.time_millis());
665 } else if ("present2present" == deltaProto.delta_name()) {
666 EXPECT_EQ(1, histogramProto.time_millis());
667 } else {
668 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
669 }
670 }
671}
672
Alec Mourifb571ea2019-01-24 18:42:10 -0800673TEST_F(TimeStatsTest, recordRefreshRateNewConfigs) {
674 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
675
676 uint32_t fpsOne = 30;
677 uint32_t fpsTwo = 90;
678 uint64_t millisOne = 5000;
679 uint64_t millisTwo = 7000;
680
681 mTimeStats->recordRefreshRate(fpsOne, ms2ns(millisOne));
682 mTimeStats->recordRefreshRate(fpsTwo, ms2ns(millisTwo));
683
684 SFTimeStatsGlobalProto globalProto;
685 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
686
687 SFTimeStatsDisplayConfigBucketProto expectedBucketOne;
688 SFTimeStatsDisplayConfigProto* expectedConfigOne = expectedBucketOne.mutable_config();
689 expectedConfigOne->set_fps(fpsOne);
690 expectedBucketOne.set_duration_millis(millisOne);
691
692 SFTimeStatsDisplayConfigBucketProto expectedBucketTwo;
693 SFTimeStatsDisplayConfigProto* expectedConfigTwo = expectedBucketTwo.mutable_config();
694 expectedConfigTwo->set_fps(fpsTwo);
695 expectedBucketTwo.set_duration_millis(millisTwo);
696
697 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(2));
698
699 std::unordered_set<uint32_t> seen_fps;
700 for (const auto& bucket : globalProto.display_config_stats()) {
701 seen_fps.emplace(bucket.config().fps());
702 if (fpsOne == bucket.config().fps()) {
703 EXPECT_EQ(millisOne, bucket.duration_millis());
704 } else if (fpsTwo == bucket.config().fps()) {
705 EXPECT_EQ(millisTwo, bucket.duration_millis());
706 } else {
707 FAIL() << "Unknown fps: " << bucket.config().fps();
708 }
709 }
710 EXPECT_THAT(seen_fps, UnorderedElementsAre(fpsOne, fpsTwo));
711}
712
713TEST_F(TimeStatsTest, recordRefreshRateUpdatesConfig) {
714 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
715
716 uint32_t fps = 30;
717 uint64_t millisOne = 5000;
718 uint64_t millisTwo = 7000;
719
720 mTimeStats->recordRefreshRate(fps, ms2ns(millisOne));
721 mTimeStats->recordRefreshRate(fps, ms2ns(millisTwo));
722
723 SFTimeStatsGlobalProto globalProto;
724 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
725 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(1));
726 EXPECT_EQ(fps, globalProto.display_config_stats().Get(0).config().fps());
727 EXPECT_EQ(millisOne + millisTwo, globalProto.display_config_stats().Get(0).duration_millis());
728}
729
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800730TEST_F(TimeStatsTest, canRemoveTimeRecord) {
731 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
732
733 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
734 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 2, 2000000);
735 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(0, 2));
736 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
737
738 SFTimeStatsGlobalProto globalProto;
739 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
740
741 ASSERT_EQ(1, globalProto.stats_size());
742 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
743 ASSERT_TRUE(layerProto.has_total_frames());
744 EXPECT_EQ(1, layerProto.total_frames());
745}
746
747TEST_F(TimeStatsTest, canRecoverFromIncompleteTimeRecordError) {
748 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
749
750 uint64_t frameNumber = 1;
751 nsecs_t ts = 1000000;
752 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 1, 1000000);
Alec Mourifb571ea2019-01-24 18:42:10 -0800753 for (size_t i = 0; i < impl::TimeStats::MAX_NUM_TIME_RECORDS + 2; i++) {
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800754 frameNumber++;
755 ts += 1000000;
756 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, frameNumber, ts);
757 }
758
759 SFTimeStatsGlobalProto globalProto;
760 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
761
762 ASSERT_EQ(1, globalProto.stats_size());
763 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
764 ASSERT_TRUE(layerProto.has_total_frames());
765 EXPECT_EQ(1, layerProto.total_frames());
766}
767
768TEST_F(TimeStatsTest, layerTimeStatsOnDestroy) {
769 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
770
771 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
772 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
773 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(0));
774 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
775
776 SFTimeStatsGlobalProto globalProto;
777 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
778
779 ASSERT_EQ(1, globalProto.stats_size());
780 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
781 ASSERT_TRUE(layerProto.has_total_frames());
782 EXPECT_EQ(1, layerProto.total_frames());
783}
784
785TEST_F(TimeStatsTest, canClearTimeStats) {
786 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
787
788 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
789 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
790 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
Peiyong Lin65248e02020-04-18 21:15:07 -0700791 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::ON));
Alec Mouri31ac64a2020-01-09 09:26:22 -0800792
Adithya Srinivasanead17162021-02-18 02:17:37 +0000793 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(3ms).count(),
794 std::chrono::nanoseconds(6ms).count());
795 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(4ms).count(),
796 std::chrono::nanoseconds(6ms).count());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800797 ASSERT_NO_FATAL_FAILURE(
798 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
799 ASSERT_NO_FATAL_FAILURE(
800 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
801 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
802 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
803
804 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
805
806 SFTimeStatsGlobalProto globalProto;
807 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
808
809 EXPECT_EQ(0, globalProto.total_frames());
810 EXPECT_EQ(0, globalProto.missed_frames());
811 EXPECT_EQ(0, globalProto.client_composition_frames());
812 EXPECT_EQ(0, globalProto.present_to_present_size());
Alec Mouri31ac64a2020-01-09 09:26:22 -0800813 EXPECT_EQ(0, globalProto.frame_duration_size());
814 EXPECT_EQ(0, globalProto.render_engine_timing_size());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800815 EXPECT_EQ(0, globalProto.stats_size());
816}
817
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800818TEST_F(TimeStatsTest, canClearDumpOnlyTimeStats) {
819 // These stats are not in the proto so verify by checking the string dump.
Vishnu Nair9b079a22020-01-21 14:36:08 -0800820 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
821 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
Alec Mouri8de697e2020-03-19 10:52:01 -0700822 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementRefreshRateSwitches());
Alec Mouri8f7a0102020-04-15 12:11:10 -0700823 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementCompositionStrategyChanges());
Peiyong Lin65248e02020-04-18 21:15:07 -0700824 mTimeStats->setPowerMode(PowerMode::ON);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000825 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(1ms).count(),
826 std::chrono::nanoseconds(5ms).count());
827 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(4ms).count(),
828 std::chrono::nanoseconds(6ms).count());
829 mTimeStats->setPresentFenceGlobal(
830 std::make_shared<FenceTime>(std::chrono::nanoseconds(1ms).count()));
Alec Mouri9a29e672020-09-14 12:39:14 -0700831
Alec Mouri363faf02021-01-29 16:34:55 -0800832 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
833 JankType::SurfaceFlingerCpuDeadlineMissed, 1, 2, 3});
834 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
835 JankType::SurfaceFlingerGpuDeadlineMissed, 1, 2, 3});
836 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
837 JankType::DisplayHAL, 1, 2, 3});
838 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
839 JankType::AppDeadlineMissed, 1, 2, 3});
840 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasanead17162021-02-18 02:17:37 +0000841 JankType::SurfaceFlingerScheduling, 1, 2, 3});
842 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
843 JankType::PredictionError, 1, 2, 3});
844 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
845 JankType::AppDeadlineMissed | JankType::BufferStuffing, 1, 2,
846 3});
847 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Alec Mouri363faf02021-01-29 16:34:55 -0800848 JankType::None, 1, 2, 3});
Alec Mouri9a29e672020-09-14 12:39:14 -0700849
Vishnu Nair9b079a22020-01-21 14:36:08 -0800850 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
851
852 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
853 EXPECT_THAT(result, HasSubstr("clientCompositionReusedFrames = 0"));
Alec Mouri8de697e2020-03-19 10:52:01 -0700854 EXPECT_THAT(result, HasSubstr("refreshRateSwitches = 0"));
Alec Mouri8f7a0102020-04-15 12:11:10 -0700855 EXPECT_THAT(result, HasSubstr("compositionStrategyChanges = 0"));
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800856 EXPECT_THAT(result, HasSubstr("averageFrameDuration = 0.000 ms"));
857 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 0.000 ms"));
Vishnu Nair9b079a22020-01-21 14:36:08 -0800858}
859
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800860TEST_F(TimeStatsTest, canDumpWithMaxLayers) {
861 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
862
863 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
864 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
865 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
866 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
867 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 3, 2000000);
868
869 SFTimeStatsGlobalProto globalProto;
870 ASSERT_TRUE(
871 globalProto.ParseFromString(inputCommand(InputCommand::DUMP_MAXLAYERS_1, FMT_PROTO)));
872
873 ASSERT_EQ(1, globalProto.stats_size());
874 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
875 ASSERT_TRUE(layerProto.has_layer_name());
876 EXPECT_EQ(genLayerName(LAYER_ID_1), layerProto.layer_name());
877 ASSERT_TRUE(layerProto.has_total_frames());
878 EXPECT_EQ(2, layerProto.total_frames());
879}
880
881TEST_F(TimeStatsTest, canDumpWithInvalidMaxLayers) {
882 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
883
884 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
885 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
886
887 SFTimeStatsGlobalProto globalProto;
888 ASSERT_TRUE(globalProto.ParseFromString(
889 inputCommand(InputCommand::DUMP_MAXLAYERS_INVALID, FMT_PROTO)));
890
891 ASSERT_EQ(0, globalProto.stats_size());
892}
893
Yiwei Zhangdd221b22020-06-12 11:06:19 -0700894TEST_F(TimeStatsTest, noInfInAverageFPS) {
895 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
896 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
897 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 1000000);
898
899 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
900 EXPECT_THAT(result, HasSubstr("averageFPS = 0.000"));
901}
902
Alec Mouri37384342020-01-02 17:23:37 -0800903namespace {
904std::string buildExpectedHistogramBytestring(const std::vector<int32_t>& times,
905 const std::vector<int32_t>& frameCounts) {
906 util::ProtoOutputStream proto;
907 for (int i = 0; i < times.size(); i++) {
908 ALOGE("Writing time: %d", times[i]);
909 proto.write(util::FIELD_TYPE_INT32 | util::FIELD_COUNT_REPEATED | 1 /* field id */,
910 (int32_t)times[i]);
911 ALOGE("Writing count: %d", frameCounts[i]);
912 proto.write(util::FIELD_TYPE_INT64 | util::FIELD_COUNT_REPEATED | 2 /* field id */,
913 (int64_t)frameCounts[i]);
914 }
915 std::string byteString;
916 proto.serializeToString(&byteString);
917 return byteString;
918}
919
Alec Mouri75de8f22021-01-20 14:53:44 -0800920std::string frameRateVoteToProtoByteString(float refreshRate, int frameRateCompatibility,
921 int seamlessness) {
922 util::ProtoOutputStream proto;
923 proto.write(android::util::FIELD_TYPE_FLOAT | 1 /* field id */, refreshRate);
924 proto.write(android::util::FIELD_TYPE_ENUM | 2 /* field id */, frameRateCompatibility);
925 proto.write(android::util::FIELD_TYPE_ENUM | 3 /* field id */, seamlessness);
926
927 std::string byteString;
928 proto.serializeToString(&byteString);
929 return byteString;
930}
931
Alec Mouri37384342020-01-02 17:23:37 -0800932std::string dumpByteStringHex(const std::string& str) {
933 std::stringstream ss;
934 ss << std::hex;
935 for (const char& c : str) {
936 ss << (int)c << " ";
937 }
938
939 return ss.str();
940}
941
942} // namespace
943
944MATCHER_P2(BytesEq, bytes, size, "") {
945 std::string expected;
946 expected.append((const char*)bytes, size);
947 std::string actual;
948 actual.append((const char*)arg, size);
949
950 *result_listener << "Bytes are not equal! \n";
951 *result_listener << "size: " << size << "\n";
952 *result_listener << "expected: " << dumpByteStringHex(expected).c_str() << "\n";
953 *result_listener << "actual: " << dumpByteStringHex(actual).c_str() << "\n";
954
955 return expected == actual;
956}
957
Alec Mouridfad9002020-02-12 17:49:09 -0800958TEST_F(TimeStatsTest, globalStatsCallback) {
959 constexpr size_t TOTAL_FRAMES = 5;
960 constexpr size_t MISSED_FRAMES = 4;
961 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
962 constexpr size_t DISPLAY_EVENT_CONNECTIONS = 14;
963
964 mTimeStats->onBootFinished();
965 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
966
967 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
968 mTimeStats->incrementTotalFrames();
969 }
970 for (size_t i = 0; i < MISSED_FRAMES; i++) {
971 mTimeStats->incrementMissedFrames();
972 }
973 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
974 mTimeStats->incrementClientCompositionFrames();
975 }
976
Alec Mouri9a29e672020-09-14 12:39:14 -0700977 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
978
Alec Mouridfad9002020-02-12 17:49:09 -0800979 mTimeStats->recordDisplayEventConnectionCount(DISPLAY_EVENT_CONNECTIONS);
Peiyong Lin65248e02020-04-18 21:15:07 -0700980 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouridfad9002020-02-12 17:49:09 -0800981 mTimeStats->recordFrameDuration(1000000, 3000000);
982 mTimeStats->recordRenderEngineDuration(2000000, 4000000);
983 mTimeStats->recordRenderEngineDuration(2000000, std::make_shared<FenceTime>(3000000));
984
985 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
986 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
987
Alec Mouri363faf02021-01-29 16:34:55 -0800988 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
989 JankType::SurfaceFlingerCpuDeadlineMissed, 1, 2, 3});
990 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
991 JankType::SurfaceFlingerGpuDeadlineMissed, 1, 2, 3});
992 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
993 JankType::DisplayHAL, 1, 2, 3});
994 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
995 JankType::AppDeadlineMissed, 1, 2, 3});
996 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasanead17162021-02-18 02:17:37 +0000997 JankType::SurfaceFlingerScheduling, 1, 2, 3});
998 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
999 JankType::PredictionError, 1, 2, 3});
1000 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1001 JankType::AppDeadlineMissed | JankType::BufferStuffing, 1, 2,
1002 3});
1003 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Alec Mouri363faf02021-01-29 16:34:55 -08001004 JankType::None, 1, 2, 3});
Alec Mouri9a29e672020-09-14 12:39:14 -07001005
Alec Mouridfad9002020-02-12 17:49:09 -08001006 EXPECT_THAT(mDelegate->mAtomTags,
1007 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1008 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1009 EXPECT_NE(nullptr, mDelegate->mCallback);
1010 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1011
1012 std::string expectedFrameDuration = buildExpectedHistogramBytestring({2}, {1});
1013 std::string expectedRenderEngineTiming = buildExpectedHistogramBytestring({1, 2}, {1, 1});
Alec Mouri75de8f22021-01-20 14:53:44 -08001014 std::string expectedEmptyHistogram = buildExpectedHistogramBytestring({}, {});
Adithya Srinivasanead17162021-02-18 02:17:37 +00001015 std::string expectedSfDeadlineMissed = buildExpectedHistogramBytestring({1}, {7});
1016 std::string expectedSfPredictionErrors = buildExpectedHistogramBytestring({2}, {7});
Alec Mouridfad9002020-02-12 17:49:09 -08001017
1018 {
1019 InSequence seq;
1020 EXPECT_CALL(*mDelegate,
1021 statsEventSetAtomId(mDelegate->mEvent,
1022 android::util::SURFACEFLINGER_STATS_GLOBAL_INFO));
1023 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, TOTAL_FRAMES));
1024 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, MISSED_FRAMES));
1025 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, CLIENT_COMPOSITION_FRAMES));
1026 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, _));
1027 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 2));
1028 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, DISPLAY_EVENT_CONNECTIONS));
1029 EXPECT_CALL(*mDelegate,
1030 statsEventWriteByteArray(mDelegate->mEvent,
1031 BytesEq((const uint8_t*)expectedFrameDuration.c_str(),
1032 expectedFrameDuration.size()),
1033 expectedFrameDuration.size()));
1034 EXPECT_CALL(*mDelegate,
1035 statsEventWriteByteArray(mDelegate->mEvent,
1036 BytesEq((const uint8_t*)
1037 expectedRenderEngineTiming.c_str(),
1038 expectedRenderEngineTiming.size()),
1039 expectedRenderEngineTiming.size()));
Adithya Srinivasanead17162021-02-18 02:17:37 +00001040 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 8));
1041 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 7));
Alec Mouri9a29e672020-09-14 12:39:14 -07001042 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1043 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1044 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
Adithya Srinivasanead17162021-02-18 02:17:37 +00001045 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 2));
Alec Mouri9a29e672020-09-14 12:39:14 -07001046 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
Adithya Srinivasanead17162021-02-18 02:17:37 +00001047 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1048 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
Alec Mouri7d436ec2021-01-27 20:40:50 -08001049 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, REFRESH_RATE_BUCKET_0));
Alec Mouri75de8f22021-01-20 14:53:44 -08001050 EXPECT_CALL(*mDelegate,
1051 statsEventWriteByteArray(mDelegate->mEvent,
Alec Mouri363faf02021-01-29 16:34:55 -08001052 BytesEq((const uint8_t*)
1053 expectedSfDeadlineMissed.c_str(),
1054 expectedSfDeadlineMissed.size()),
1055 expectedSfDeadlineMissed.size()));
Alec Mouri75de8f22021-01-20 14:53:44 -08001056 EXPECT_CALL(*mDelegate,
1057 statsEventWriteByteArray(mDelegate->mEvent,
Alec Mouri363faf02021-01-29 16:34:55 -08001058 BytesEq((const uint8_t*)
1059 expectedSfPredictionErrors.c_str(),
1060 expectedSfPredictionErrors.size()),
1061 expectedSfPredictionErrors.size()));
Alec Mouri7d436ec2021-01-27 20:40:50 -08001062 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, RENDER_RATE_BUCKET_0));
Alec Mouri75de8f22021-01-20 14:53:44 -08001063
Alec Mouridfad9002020-02-12 17:49:09 -08001064 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
1065 }
1066 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
1067 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1068 mDelegate->mCookie));
1069
1070 SFTimeStatsGlobalProto globalProto;
1071 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
1072
1073 EXPECT_EQ(0, globalProto.total_frames());
1074 EXPECT_EQ(0, globalProto.missed_frames());
1075 EXPECT_EQ(0, globalProto.client_composition_frames());
1076 EXPECT_EQ(0, globalProto.present_to_present_size());
1077}
1078
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001079TEST_F(TimeStatsTest, layerStatsCallback_pullsAllAndClears) {
1080 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
1081 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 3;
Alec Mouri37384342020-01-02 17:23:37 -08001082 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1083
1084 mTimeStats->onBootFinished();
1085
1086 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001087 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
1088 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
1089 }
1090 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
1091 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
1092 }
Alec Mouri37384342020-01-02 17:23:37 -08001093 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1094
Alec Mouri363faf02021-01-29 16:34:55 -08001095 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1096 JankType::SurfaceFlingerCpuDeadlineMissed, 1, 2, 3});
1097 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1098 JankType::SurfaceFlingerGpuDeadlineMissed, 1, 2, 3});
1099 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1100 JankType::DisplayHAL, 1, 2, 3});
1101 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1102 JankType::AppDeadlineMissed, 1, 2, 3});
1103 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasanead17162021-02-18 02:17:37 +00001104 JankType::SurfaceFlingerScheduling, 1, 2, 2});
1105 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1106 JankType::PredictionError, 1, 2, 2});
1107 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1108 JankType::AppDeadlineMissed | JankType::BufferStuffing, 1, 2,
1109 2});
1110 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Alec Mouri363faf02021-01-29 16:34:55 -08001111 JankType::None, 1, 2, 3});
Alec Mouri9a29e672020-09-14 12:39:14 -07001112
Alec Mouri37384342020-01-02 17:23:37 -08001113 EXPECT_THAT(mDelegate->mAtomTags,
1114 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1115 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1116 EXPECT_NE(nullptr, mDelegate->mCallback);
1117 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1118
1119 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {1});
1120 std::string expectedPostToPresent = buildExpectedHistogramBytestring({4}, {1});
1121 std::string expectedAcquireToPresent = buildExpectedHistogramBytestring({3}, {1});
1122 std::string expectedLatchToPresent = buildExpectedHistogramBytestring({2}, {1});
1123 std::string expectedDesiredToPresent = buildExpectedHistogramBytestring({1}, {1});
1124 std::string expectedPostToAcquire = buildExpectedHistogramBytestring({1}, {1});
Alec Mouri75de8f22021-01-20 14:53:44 -08001125 std::string expectedFrameRateOverride = frameRateVoteToProtoByteString(0.0, 0, 0);
Adithya Srinivasanead17162021-02-18 02:17:37 +00001126 std::string expectedAppDeadlineMissed = buildExpectedHistogramBytestring({3, 2}, {4, 3});
Alec Mouri37384342020-01-02 17:23:37 -08001127 {
1128 InSequence seq;
1129 EXPECT_CALL(*mDelegate,
1130 statsEventSetAtomId(mDelegate->mEvent,
1131 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1132 EXPECT_CALL(*mDelegate,
1133 statsEventWriteString8(mDelegate->mEvent,
1134 StrEq(genLayerName(LAYER_ID_0).c_str())));
1135 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 1));
1136 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 0));
1137 EXPECT_CALL(*mDelegate,
1138 statsEventWriteByteArray(mDelegate->mEvent,
1139 BytesEq((const uint8_t*)
1140 expectedPresentToPresent.c_str(),
1141 expectedPresentToPresent.size()),
1142 expectedPresentToPresent.size()));
1143 EXPECT_CALL(*mDelegate,
1144 statsEventWriteByteArray(mDelegate->mEvent,
1145 BytesEq((const uint8_t*)expectedPostToPresent.c_str(),
1146 expectedPostToPresent.size()),
1147 expectedPostToPresent.size()));
1148 EXPECT_CALL(*mDelegate,
1149 statsEventWriteByteArray(mDelegate->mEvent,
1150 BytesEq((const uint8_t*)
1151 expectedAcquireToPresent.c_str(),
1152 expectedAcquireToPresent.size()),
1153 expectedAcquireToPresent.size()));
1154 EXPECT_CALL(*mDelegate,
1155 statsEventWriteByteArray(mDelegate->mEvent,
1156 BytesEq((const uint8_t*)expectedLatchToPresent.c_str(),
1157 expectedLatchToPresent.size()),
1158 expectedLatchToPresent.size()));
1159 EXPECT_CALL(*mDelegate,
1160 statsEventWriteByteArray(mDelegate->mEvent,
1161 BytesEq((const uint8_t*)
1162 expectedDesiredToPresent.c_str(),
1163 expectedDesiredToPresent.size()),
1164 expectedDesiredToPresent.size()));
1165 EXPECT_CALL(*mDelegate,
1166 statsEventWriteByteArray(mDelegate->mEvent,
1167 BytesEq((const uint8_t*)expectedPostToAcquire.c_str(),
1168 expectedPostToAcquire.size()),
1169 expectedPostToAcquire.size()));
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001170 EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, LATE_ACQUIRE_FRAMES));
1171 EXPECT_CALL(*mDelegate,
1172 statsEventWriteInt64(mDelegate->mEvent, BAD_DESIRED_PRESENT_FRAMES));
Alec Mouri9a29e672020-09-14 12:39:14 -07001173 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, UID_0));
Adithya Srinivasanead17162021-02-18 02:17:37 +00001174 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 8));
1175 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 7));
Alec Mouri9a29e672020-09-14 12:39:14 -07001176 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1177 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1178 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
Adithya Srinivasanead17162021-02-18 02:17:37 +00001179 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 2));
Alec Mouri9a29e672020-09-14 12:39:14 -07001180 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
Adithya Srinivasanead17162021-02-18 02:17:37 +00001181 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
1182 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, 1));
Alec Mouri7d436ec2021-01-27 20:40:50 -08001183 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, REFRESH_RATE_BUCKET_0));
1184 EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, RENDER_RATE_BUCKET_0));
Alec Mouri75de8f22021-01-20 14:53:44 -08001185 EXPECT_CALL(*mDelegate,
1186 statsEventWriteByteArray(mDelegate->mEvent,
1187 BytesEq((const uint8_t*)
1188 expectedFrameRateOverride.c_str(),
1189 expectedFrameRateOverride.size()),
1190 expectedFrameRateOverride.size()));
1191 EXPECT_CALL(*mDelegate,
1192 statsEventWriteByteArray(mDelegate->mEvent,
Alec Mouri363faf02021-01-29 16:34:55 -08001193 BytesEq((const uint8_t*)
1194 expectedAppDeadlineMissed.c_str(),
1195 expectedAppDeadlineMissed.size()),
1196 expectedAppDeadlineMissed.size()));
Alec Mouri9a29e672020-09-14 12:39:14 -07001197
Alec Mouri37384342020-01-02 17:23:37 -08001198 EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
1199 }
Tej Singh2a457b62020-01-31 16:16:10 -08001200 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001201 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1202 mDelegate->mCookie));
1203
1204 SFTimeStatsGlobalProto globalProto;
1205 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
1206
1207 EXPECT_EQ(0, globalProto.stats_size());
1208}
1209
1210TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleLayers) {
1211 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1212
1213 mTimeStats->onBootFinished();
1214
1215 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1216 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1217 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1218 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1219
1220 EXPECT_THAT(mDelegate->mAtomTags,
1221 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1222 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1223 EXPECT_NE(nullptr, mDelegate->mCallback);
1224 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1225
1226 EXPECT_CALL(*mDelegate,
1227 statsEventSetAtomId(mDelegate->mEvent,
1228 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1229 .Times(2);
1230 EXPECT_CALL(*mDelegate,
1231 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_0).c_str())));
1232 EXPECT_CALL(*mDelegate,
1233 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001234 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001235 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1236 mDelegate->mCookie));
1237}
1238
1239TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleBuckets) {
1240 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1241
1242 mTimeStats->onBootFinished();
1243
1244 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1245 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1246 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1247 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1248
Tej Singh38a4b212020-03-13 19:04:51 -07001249 // Now make sure that TimeStats flushes global stats to set the callback.
Peiyong Lin65248e02020-04-18 21:15:07 -07001250 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouri37384342020-01-02 17:23:37 -08001251 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
1252 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
1253 EXPECT_THAT(mDelegate->mAtomTags,
1254 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1255 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1256 EXPECT_NE(nullptr, mDelegate->mCallback);
1257 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1258
1259 EXPECT_THAT(mDelegate->mAtomTags,
1260 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1261 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1262 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1, 2}, {2, 1});
1263 {
1264 InSequence seq;
1265 EXPECT_CALL(*mDelegate,
1266 statsEventWriteByteArray(mDelegate->mEvent,
1267 BytesEq((const uint8_t*)
1268 expectedPresentToPresent.c_str(),
1269 expectedPresentToPresent.size()),
1270 expectedPresentToPresent.size()));
1271 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1272 .Times(AnyNumber());
1273 }
Tej Singh2a457b62020-01-31 16:16:10 -08001274 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001275 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1276 mDelegate->mCookie));
1277}
1278
1279TEST_F(TimeStatsTest, layerStatsCallback_limitsHistogramBuckets) {
1280 mDelegate = new FakeStatsEventDelegate;
1281 mTimeStats =
1282 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate),
1283 std::nullopt, 1);
1284 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1285
1286 mTimeStats->onBootFinished();
1287
1288 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1289 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1290 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1291 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1292
1293 EXPECT_THAT(mDelegate->mAtomTags,
1294 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1295 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1296 EXPECT_NE(nullptr, mDelegate->mCallback);
1297 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1298
1299 EXPECT_THAT(mDelegate->mAtomTags,
1300 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1301 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1302 std::string expectedPresentToPresent = buildExpectedHistogramBytestring({1}, {2});
1303 {
1304 InSequence seq;
1305 EXPECT_CALL(*mDelegate,
1306 statsEventWriteByteArray(mDelegate->mEvent,
1307 BytesEq((const uint8_t*)
1308 expectedPresentToPresent.c_str(),
1309 expectedPresentToPresent.size()),
1310 expectedPresentToPresent.size()));
1311 EXPECT_CALL(*mDelegate, statsEventWriteByteArray(mDelegate->mEvent, _, _))
1312 .Times(AnyNumber());
1313 }
Tej Singh2a457b62020-01-31 16:16:10 -08001314 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001315 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1316 mDelegate->mCookie));
1317}
1318
1319TEST_F(TimeStatsTest, layerStatsCallback_limitsLayers) {
1320 mDelegate = new FakeStatsEventDelegate;
1321 mTimeStats =
1322 std::make_unique<impl::TimeStats>(std::unique_ptr<FakeStatsEventDelegate>(mDelegate), 1,
1323 std::nullopt);
1324 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1325
1326 mTimeStats->onBootFinished();
1327
1328 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1329 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1330 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1331 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1332 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 4, 5000000);
1333
1334 EXPECT_THAT(mDelegate->mAtomTags,
1335 UnorderedElementsAre(android::util::SURFACEFLINGER_STATS_GLOBAL_INFO,
1336 android::util::SURFACEFLINGER_STATS_LAYER_INFO));
1337 EXPECT_NE(nullptr, mDelegate->mCallback);
1338 EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);
1339
1340 EXPECT_CALL(*mDelegate,
1341 statsEventSetAtomId(mDelegate->mEvent,
1342 android::util::SURFACEFLINGER_STATS_LAYER_INFO))
1343 .Times(1);
1344 EXPECT_CALL(*mDelegate,
1345 statsEventWriteString8(mDelegate->mEvent, StrEq(genLayerName(LAYER_ID_1).c_str())));
Tej Singh2a457b62020-01-31 16:16:10 -08001346 EXPECT_EQ(AStatsManager_PULL_SUCCESS,
Alec Mouri37384342020-01-02 17:23:37 -08001347 mDelegate->makePullAtomCallback(android::util::SURFACEFLINGER_STATS_LAYER_INFO,
1348 mDelegate->mCookie));
1349}
1350
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001351TEST_F(TimeStatsTest, canSurviveMonkey) {
Lloyd Pique067fe1e2018-12-06 19:44:13 -08001352 if (g_noSlowTests) {
1353 GTEST_SKIP();
1354 }
1355
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001356 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1357
1358 for (size_t i = 0; i < 10000000; ++i) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001359 const int32_t layerId = genRandomInt32(-1, 10);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001360 const int32_t frameNumber = genRandomInt32(1, 10);
1361 switch (genRandomInt32(0, 100)) {
1362 case 0:
1363 ALOGV("removeTimeRecord");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001364 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(layerId, frameNumber));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001365 continue;
1366 case 1:
1367 ALOGV("onDestroy");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001368 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(layerId));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001369 continue;
1370 }
1371 TimeStamp type = static_cast<TimeStamp>(genRandomInt32(TIME_STAMP_BEGIN, TIME_STAMP_END));
1372 const int32_t ts = genRandomInt32(1, 1000000000);
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001373 ALOGV("type[%d], layerId[%d], frameNumber[%d], ts[%d]", type, layerId, frameNumber, ts);
1374 setTimeStamp(type, layerId, frameNumber, ts);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001375 }
1376}
1377
1378} // namespace
1379} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -08001380
1381// TODO(b/129481165): remove the #pragma below and fix conversion issues
Marin Shalamanovbed7fd32020-12-21 20:02:20 +01001382#pragma clang diagnostic pop // ignored "-Wconversion -Wextra"