blob: 188ea758d42f0841490a4de2000e1af128fbf523 [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 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>
Tej Singhe2751772021-04-06 22:05:29 -070029#include <timestatsatomsproto/TimeStatsAtomsProtoHeader.h>
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080030#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 Mouri56e63852021-03-09 18:17:25 -080051using testing::Not;
Alec Mourifb571ea2019-01-24 18:42:10 -080052using testing::SizeIs;
Alec Mouri37384342020-01-02 17:23:37 -080053using testing::StrEq;
Alec Mourifb571ea2019-01-24 18:42:10 -080054using testing::UnorderedElementsAre;
55
Peiyong Lin65248e02020-04-18 21:15:07 -070056using PowerMode = hardware::graphics::composer::V2_4::IComposerClient::PowerMode;
57
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080058// clang-format off
Alec Mouri7d436ec2021-01-27 20:40:50 -080059#define FMT_PROTO true
60#define FMT_STRING false
61#define LAYER_ID_0 0
62#define LAYER_ID_1 1
63#define UID_0 123
64#define REFRESH_RATE_0 61
65#define RENDER_RATE_0 31
66#define REFRESH_RATE_BUCKET_0 60
67#define RENDER_RATE_BUCKET_0 30
68#define LAYER_ID_INVALID -1
69#define NUM_LAYERS 1
70#define NUM_LAYERS_INVALID "INVALID"
71
72const constexpr Fps kRefreshRate0 = Fps(static_cast<float>(REFRESH_RATE_0));
73const constexpr Fps kRenderRate0 = Fps(static_cast<float>(RENDER_RATE_0));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -080074
75enum InputCommand : int32_t {
76 ENABLE = 0,
77 DISABLE = 1,
78 CLEAR = 2,
79 DUMP_ALL = 3,
80 DUMP_MAXLAYERS_1 = 4,
81 DUMP_MAXLAYERS_INVALID = 5,
82 INPUT_COMMAND_BEGIN = ENABLE,
83 INPUT_COMMAND_END = DUMP_MAXLAYERS_INVALID,
84 INPUT_COMMAND_RANGE = INPUT_COMMAND_END - INPUT_COMMAND_BEGIN + 1,
85};
86
87enum TimeStamp : int32_t {
88 POST = 0,
89 ACQUIRE = 1,
90 ACQUIRE_FENCE = 2,
91 LATCH = 3,
92 DESIRED = 4,
93 PRESENT = 5,
94 PRESENT_FENCE = 6,
95 TIME_STAMP_BEGIN = POST,
96 TIME_STAMP_END = PRESENT,
97 TIME_STAMP_RANGE = TIME_STAMP_END - TIME_STAMP_BEGIN + 1,
98};
99
100static const TimeStamp NORMAL_SEQUENCE[] = {
101 TimeStamp::POST,
102 TimeStamp::ACQUIRE,
103 TimeStamp::LATCH,
104 TimeStamp::DESIRED,
105 TimeStamp::PRESENT,
106};
107
108static const TimeStamp NORMAL_SEQUENCE_2[] = {
109 TimeStamp::POST,
110 TimeStamp::ACQUIRE_FENCE,
111 TimeStamp::LATCH,
112 TimeStamp::DESIRED,
113 TimeStamp::PRESENT_FENCE,
114};
115
116static const TimeStamp UNORDERED_SEQUENCE[] = {
117 TimeStamp::ACQUIRE,
118 TimeStamp::LATCH,
119 TimeStamp::POST,
120 TimeStamp::DESIRED,
121 TimeStamp::PRESENT,
122};
123
124static const TimeStamp INCOMPLETE_SEQUENCE[] = {
125 TimeStamp::POST,
126};
127// clang-format on
128
129class TimeStatsTest : public testing::Test {
130public:
131 TimeStatsTest() {
132 const ::testing::TestInfo* const test_info =
133 ::testing::UnitTest::GetInstance()->current_test_info();
134 ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
135 }
136
137 ~TimeStatsTest() {
138 const ::testing::TestInfo* const test_info =
139 ::testing::UnitTest::GetInstance()->current_test_info();
140 ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
141 }
142
143 std::string inputCommand(InputCommand cmd, bool useProto);
144
Ady Abraham8b9e6122021-01-26 19:11:45 -0800145 void setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts,
146 TimeStats::SetFrameRateVote frameRateVote);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800147
148 int32_t genRandomInt32(int32_t begin, int32_t end);
149
150 template <size_t N>
151 void insertTimeRecord(const TimeStamp (&sequence)[N], int32_t id, uint64_t frameNumber,
Ady Abraham8b9e6122021-01-26 19:11:45 -0800152 nsecs_t ts, TimeStats::SetFrameRateVote frameRateVote = {}) {
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800153 for (size_t i = 0; i < N; i++, ts += 1000000) {
Ady Abraham8b9e6122021-01-26 19:11:45 -0800154 setTimeStamp(sequence[i], id, frameNumber, ts, frameRateVote);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800155 }
156 }
157
158 std::mt19937 mRandomEngine = std::mt19937(std::random_device()());
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000159 std::unique_ptr<TimeStats> mTimeStats =
Tej Singhe2751772021-04-06 22:05:29 -0700160 std::make_unique<impl::TimeStats>(std::nullopt, std::nullopt);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800161};
162
163std::string TimeStatsTest::inputCommand(InputCommand cmd, bool useProto) {
Yiwei Zhang5434a782018-12-05 18:06:32 -0800164 std::string result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800165 Vector<String16> args;
166
167 switch (cmd) {
168 case InputCommand::ENABLE:
169 args.push_back(String16("-enable"));
170 break;
171 case InputCommand::DISABLE:
172 args.push_back(String16("-disable"));
173 break;
174 case InputCommand::CLEAR:
175 args.push_back(String16("-clear"));
176 break;
177 case InputCommand::DUMP_ALL:
178 args.push_back(String16("-dump"));
179 break;
180 case InputCommand::DUMP_MAXLAYERS_1:
181 args.push_back(String16("-dump"));
182 args.push_back(String16("-maxlayers"));
183 args.push_back(String16(std::to_string(NUM_LAYERS).c_str()));
184 break;
185 case InputCommand::DUMP_MAXLAYERS_INVALID:
186 args.push_back(String16("-dump"));
187 args.push_back(String16("-maxlayers"));
188 args.push_back(String16(NUM_LAYERS_INVALID));
189 break;
190 default:
191 ALOGD("Invalid control command");
192 }
193
Dominik Laskowskic2867142019-01-21 11:33:38 -0800194 EXPECT_NO_FATAL_FAILURE(mTimeStats->parseArgs(useProto, args, result));
Yiwei Zhang5434a782018-12-05 18:06:32 -0800195 return result;
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800196}
197
Yiwei Zhang1a88c402019-11-18 10:43:58 -0800198static std::string genLayerName(int32_t layerId) {
Peiyong Lind8460c82020-07-28 16:04:22 -0700199 return (layerId < 0 ? "PopupWindow:b54fcd1#0" : "com.example.fake#") + std::to_string(layerId);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800200}
201
Ady Abraham8b9e6122021-01-26 19:11:45 -0800202void TimeStatsTest::setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts,
203 TimeStats::SetFrameRateVote frameRateVote) {
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800204 switch (type) {
205 case TimeStamp::POST:
Alec Mouri9a29e672020-09-14 12:39:14 -0700206 ASSERT_NO_FATAL_FAILURE(
207 mTimeStats->setPostTime(id, frameNumber, genLayerName(id), UID_0, ts));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800208 break;
209 case TimeStamp::ACQUIRE:
210 ASSERT_NO_FATAL_FAILURE(mTimeStats->setAcquireTime(id, frameNumber, ts));
211 break;
212 case TimeStamp::ACQUIRE_FENCE:
213 ASSERT_NO_FATAL_FAILURE(
214 mTimeStats->setAcquireFence(id, frameNumber, std::make_shared<FenceTime>(ts)));
215 break;
216 case TimeStamp::LATCH:
217 ASSERT_NO_FATAL_FAILURE(mTimeStats->setLatchTime(id, frameNumber, ts));
218 break;
219 case TimeStamp::DESIRED:
220 ASSERT_NO_FATAL_FAILURE(mTimeStats->setDesiredTime(id, frameNumber, ts));
221 break;
222 case TimeStamp::PRESENT:
Ady Abraham8b9e6122021-01-26 19:11:45 -0800223 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPresentTime(id, frameNumber, ts, kRefreshRate0,
224 kRenderRate0, frameRateVote));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800225 break;
226 case TimeStamp::PRESENT_FENCE:
Ady Abraham8b9e6122021-01-26 19:11:45 -0800227 ASSERT_NO_FATAL_FAILURE(
228 mTimeStats->setPresentFence(id, frameNumber, std::make_shared<FenceTime>(ts),
229 kRefreshRate0, kRenderRate0, frameRateVote));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800230 break;
231 default:
232 ALOGD("Invalid timestamp type");
233 }
234}
235
236int32_t TimeStatsTest::genRandomInt32(int32_t begin, int32_t end) {
237 std::uniform_int_distribution<int32_t> distr(begin, end);
238 return distr(mRandomEngine);
239}
240
Alec Mouri8e2f31b2020-01-16 22:04:35 +0000241TEST_F(TimeStatsTest, disabledByDefault) {
242 ASSERT_FALSE(mTimeStats->isEnabled());
243}
244
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800245TEST_F(TimeStatsTest, canEnableAndDisableTimeStats) {
246 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
247 ASSERT_TRUE(mTimeStats->isEnabled());
248
249 EXPECT_TRUE(inputCommand(InputCommand::DISABLE, FMT_STRING).empty());
250 ASSERT_FALSE(mTimeStats->isEnabled());
251}
252
253TEST_F(TimeStatsTest, canIncreaseGlobalStats) {
254 constexpr size_t TOTAL_FRAMES = 5;
255 constexpr size_t MISSED_FRAMES = 4;
256 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
257
258 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
259
260 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
261 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
262 }
263 for (size_t i = 0; i < MISSED_FRAMES; i++) {
264 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
265 }
266 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
267 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
268 }
269
270 SFTimeStatsGlobalProto globalProto;
271 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
272
273 ASSERT_TRUE(globalProto.has_total_frames());
274 EXPECT_EQ(TOTAL_FRAMES, globalProto.total_frames());
275 ASSERT_TRUE(globalProto.has_missed_frames());
276 EXPECT_EQ(MISSED_FRAMES, globalProto.missed_frames());
277 ASSERT_TRUE(globalProto.has_client_composition_frames());
278 EXPECT_EQ(CLIENT_COMPOSITION_FRAMES, globalProto.client_composition_frames());
279}
280
Alec Mouri91f6df32020-01-30 08:48:58 -0800281TEST_F(TimeStatsTest, canIncreaseLateAcquireFrames) {
282 // this stat is not in the proto so verify by checking the string dump
283 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
284
285 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
286
287 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
288 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
289 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
290 }
291 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
292
293 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
294 const std::string expectedResult = "lateAcquireFrames = " + std::to_string(LATE_ACQUIRE_FRAMES);
295 EXPECT_THAT(result, HasSubstr(expectedResult));
296}
297
298TEST_F(TimeStatsTest, canIncreaseBadDesiredPresent) {
299 // this stat is not in the proto so verify by checking the string dump
300 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 2;
301
302 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
303
304 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
305 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
306 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
307 }
308 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
309
310 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
311 const std::string expectedResult =
312 "badDesiredPresentFrames = " + std::to_string(BAD_DESIRED_PRESENT_FRAMES);
313 EXPECT_THAT(result, HasSubstr(expectedResult));
314}
315
Alec Mouri9a29e672020-09-14 12:39:14 -0700316TEST_F(TimeStatsTest, canIncreaseJankyFramesForLayer) {
317 // this stat is not in the proto so verify by checking the string dump
318 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
319
320 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
Alec Mouri363faf02021-01-29 16:34:55 -0800321 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
322 JankType::SurfaceFlingerCpuDeadlineMissed, 1, 2, 3});
323 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
324 JankType::SurfaceFlingerGpuDeadlineMissed, 1, 2, 3});
325 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
326 JankType::DisplayHAL, 1, 2, 3});
327 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
328 JankType::AppDeadlineMissed, 1, 2, 3});
329 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasanead17162021-02-18 02:17:37 +0000330 JankType::SurfaceFlingerScheduling, 1, 2, 3});
331 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
332 JankType::PredictionError, 1, 2, 3});
333 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
334 JankType::AppDeadlineMissed | JankType::BufferStuffing, 1, 2,
335 3});
336 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Alec Mouri363faf02021-01-29 16:34:55 -0800337 JankType::None, 1, 2, 3});
Alec Mouri9a29e672020-09-14 12:39:14 -0700338
339 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
Alec Mouri7d436ec2021-01-27 20:40:50 -0800340 std::string expectedResult =
341 "displayRefreshRate = " + std::to_string(REFRESH_RATE_BUCKET_0) + " fps";
342 EXPECT_THAT(result, HasSubstr(expectedResult));
343 expectedResult = "renderRate = " + std::to_string(RENDER_RATE_BUCKET_0) + " fps";
344 EXPECT_THAT(result, HasSubstr(expectedResult));
Adithya Srinivasanead17162021-02-18 02:17:37 +0000345 expectedResult = "totalTimelineFrames = " + std::to_string(8);
Alec Mouri9a29e672020-09-14 12:39:14 -0700346 EXPECT_THAT(result, HasSubstr(expectedResult));
Adithya Srinivasanead17162021-02-18 02:17:37 +0000347 expectedResult = "jankyFrames = " + std::to_string(7);
Alec Mouri9a29e672020-09-14 12:39:14 -0700348 EXPECT_THAT(result, HasSubstr(expectedResult));
349 expectedResult = "sfLongCpuJankyFrames = " + std::to_string(1);
350 EXPECT_THAT(result, HasSubstr(expectedResult));
351 expectedResult = "sfLongGpuJankyFrames = " + std::to_string(1);
352 EXPECT_THAT(result, HasSubstr(expectedResult));
Adithya Srinivasanead17162021-02-18 02:17:37 +0000353 expectedResult = "sfUnattributedJankyFrames = " + std::to_string(1);
Alec Mouri9a29e672020-09-14 12:39:14 -0700354 EXPECT_THAT(result, HasSubstr(expectedResult));
Adithya Srinivasanead17162021-02-18 02:17:37 +0000355 expectedResult = "appUnattributedJankyFrames = " + std::to_string(2);
356 EXPECT_THAT(result, HasSubstr(expectedResult));
357 expectedResult = "sfSchedulingJankyFrames = " + std::to_string(1);
358 EXPECT_THAT(result, HasSubstr(expectedResult));
359 expectedResult = "sfPredictionErrorJankyFrames = " + std::to_string(1);
360 EXPECT_THAT(result, HasSubstr(expectedResult));
361 expectedResult = "appBufferStuffingJankyFrames = " + std::to_string(1);
Alec Mouri9a29e672020-09-14 12:39:14 -0700362 EXPECT_THAT(result, HasSubstr(expectedResult));
363}
364
Ady Abraham8b9e6122021-01-26 19:11:45 -0800365TEST_F(TimeStatsTest, canCaptureSetFrameRateVote) {
366 // this stat is not in the proto so verify by checking the string dump
367 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
368
369 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
370
371 const auto frameRate60 = TimeStats::SetFrameRateVote{
372 .frameRate = 60.0f,
373 .frameRateCompatibility = TimeStats::SetFrameRateVote::FrameRateCompatibility::Default,
374 .seamlessness = TimeStats::SetFrameRateVote::Seamlessness::ShouldBeSeamless,
375 };
376 const auto frameRate90 = TimeStats::SetFrameRateVote{
377 .frameRate = 90.0f,
378 .frameRateCompatibility =
379 TimeStats::SetFrameRateVote::FrameRateCompatibility::ExactOrMultiple,
380 .seamlessness = TimeStats::SetFrameRateVote::Seamlessness::NotRequired,
381 };
382 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000, frameRate60);
383 std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
384 std::string expectedResult = "frameRate = 60.00";
385 EXPECT_THAT(result, HasSubstr(expectedResult));
386 expectedResult = "frameRateCompatibility = Default";
387 EXPECT_THAT(result, HasSubstr(expectedResult));
388 expectedResult = "seamlessness = ShouldBeSeamless";
389 EXPECT_THAT(result, HasSubstr(expectedResult));
390
391 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000, frameRate90);
392 result = inputCommand(InputCommand::DUMP_ALL, FMT_STRING);
393 expectedResult = "frameRate = 90.00";
394 EXPECT_THAT(result, HasSubstr(expectedResult));
395 expectedResult = "frameRateCompatibility = ExactOrMultiple";
396 EXPECT_THAT(result, HasSubstr(expectedResult));
397 expectedResult = "seamlessness = NotRequired";
398 EXPECT_THAT(result, HasSubstr(expectedResult));
399
400 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 4, 4000000, frameRate60);
401 result = inputCommand(InputCommand::DUMP_ALL, FMT_STRING);
402 expectedResult = "frameRate = 60.00";
403 EXPECT_THAT(result, HasSubstr(expectedResult));
404 expectedResult = "frameRateCompatibility = Default";
405 EXPECT_THAT(result, HasSubstr(expectedResult));
406 expectedResult = "seamlessness = ShouldBeSeamless";
407 EXPECT_THAT(result, HasSubstr(expectedResult));
408}
409
410TEST_F(TimeStatsTest, canCaptureSetFrameRateVoteAfterZeroForLayer) {
411 // this stat is not in the proto so verify by checking the string dump
412 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
413
414 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
415
416 const auto frameRate90 = TimeStats::SetFrameRateVote{
417 .frameRate = 90.0f,
418 .frameRateCompatibility =
419 TimeStats::SetFrameRateVote::FrameRateCompatibility::ExactOrMultiple,
420 .seamlessness = TimeStats::SetFrameRateVote::Seamlessness::NotRequired,
421 };
422 const auto frameRateDefault = TimeStats::SetFrameRateVote{
423 .frameRate = 0.0f,
424 .frameRateCompatibility = TimeStats::SetFrameRateVote::FrameRateCompatibility::Default,
425 .seamlessness = TimeStats::SetFrameRateVote::Seamlessness::ShouldBeSeamless,
426 };
427 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000, frameRate90);
428 std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
429 std::string expectedResult = "frameRate = 90.00";
430 EXPECT_THAT(result, HasSubstr(expectedResult));
431 expectedResult = "frameRateCompatibility = ExactOrMultiple";
432 EXPECT_THAT(result, HasSubstr(expectedResult));
433 expectedResult = "seamlessness = NotRequired";
434 EXPECT_THAT(result, HasSubstr(expectedResult));
435
436 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000, frameRateDefault);
437 result = inputCommand(InputCommand::DUMP_ALL, FMT_STRING);
438 expectedResult = "frameRate = 90.00";
439 EXPECT_THAT(result, HasSubstr(expectedResult));
440 expectedResult = "frameRateCompatibility = ExactOrMultiple";
441 EXPECT_THAT(result, HasSubstr(expectedResult));
442 expectedResult = "seamlessness = NotRequired";
443 EXPECT_THAT(result, HasSubstr(expectedResult));
444
445 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 4, 4000000, frameRateDefault);
446 result = inputCommand(InputCommand::DUMP_ALL, FMT_STRING);
447 expectedResult = "frameRate = 90.00";
448 EXPECT_THAT(result, HasSubstr(expectedResult));
449 expectedResult = "frameRateCompatibility = ExactOrMultiple";
450 EXPECT_THAT(result, HasSubstr(expectedResult));
451 expectedResult = "seamlessness = NotRequired";
452 EXPECT_THAT(result, HasSubstr(expectedResult));
453}
454
Vishnu Nair9b079a22020-01-21 14:36:08 -0800455TEST_F(TimeStatsTest, canIncreaseClientCompositionReusedFrames) {
456 // this stat is not in the proto so verify by checking the string dump
457 constexpr size_t CLIENT_COMPOSITION_REUSED_FRAMES = 2;
458
459 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
460 for (size_t i = 0; i < CLIENT_COMPOSITION_REUSED_FRAMES; i++) {
461 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
462 }
463
464 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
465 const std::string expectedResult =
466 "clientCompositionReusedFrames = " + std::to_string(CLIENT_COMPOSITION_REUSED_FRAMES);
467 EXPECT_THAT(result, HasSubstr(expectedResult));
468}
469
Alec Mouri8de697e2020-03-19 10:52:01 -0700470TEST_F(TimeStatsTest, canIncreaseRefreshRateSwitches) {
471 // this stat is not in the proto so verify by checking the string dump
472 constexpr size_t REFRESH_RATE_SWITCHES = 2;
473
474 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
475 for (size_t i = 0; i < REFRESH_RATE_SWITCHES; i++) {
476 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementRefreshRateSwitches());
477 }
478
479 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
480 const std::string expectedResult =
481 "refreshRateSwitches = " + std::to_string(REFRESH_RATE_SWITCHES);
482 EXPECT_THAT(result, HasSubstr(expectedResult));
483}
484
Alec Mouri8f7a0102020-04-15 12:11:10 -0700485TEST_F(TimeStatsTest, canIncreaseCompositionStrategyChanges) {
486 // this stat is not in the proto so verify by checking the string dump
487 constexpr size_t COMPOSITION_STRATEGY_CHANGES = 2;
488
489 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
490 for (size_t i = 0; i < COMPOSITION_STRATEGY_CHANGES; i++) {
491 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementCompositionStrategyChanges());
492 }
493
494 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
495 const std::string expectedResult =
496 "compositionStrategyChanges = " + std::to_string(COMPOSITION_STRATEGY_CHANGES);
497 EXPECT_THAT(result, HasSubstr(expectedResult));
498}
499
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800500TEST_F(TimeStatsTest, canAverageFrameDuration) {
501 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
Peiyong Lin65248e02020-04-18 21:15:07 -0700502 mTimeStats->setPowerMode(PowerMode::ON);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000503 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(1ms).count(),
504 std::chrono::nanoseconds(6ms).count());
505 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(1ms).count(),
506 std::chrono::nanoseconds(16ms).count());
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800507
508 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
509 EXPECT_THAT(result, HasSubstr("averageFrameDuration = 10.000 ms"));
510}
511
512TEST_F(TimeStatsTest, canAverageRenderEngineTimings) {
513 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
Adithya Srinivasanead17162021-02-18 02:17:37 +0000514 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(1ms).count(),
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800515 std::make_shared<FenceTime>(
516 std::chrono::duration_cast<
517 std::chrono::nanoseconds>(3ms)
518 .count()));
519
Adithya Srinivasanead17162021-02-18 02:17:37 +0000520 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(4ms).count(),
521 std::chrono::nanoseconds(8ms).count());
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800522
Peiyong Lind8460c82020-07-28 16:04:22 -0700523 // Push a fake present fence to trigger flushing the RenderEngine timings.
Peiyong Lin65248e02020-04-18 21:15:07 -0700524 mTimeStats->setPowerMode(PowerMode::ON);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000525 mTimeStats->setPresentFenceGlobal(
526 std::make_shared<FenceTime>(std::chrono::nanoseconds(1ms).count()));
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800527
528 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
529 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 3.000 ms"));
530}
531
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800532TEST_F(TimeStatsTest, canInsertGlobalPresentToPresent) {
533 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
534
535 ASSERT_NO_FATAL_FAILURE(
536 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
537 ASSERT_NO_FATAL_FAILURE(
538 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
539
Peiyong Lin65248e02020-04-18 21:15:07 -0700540 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::ON));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800541 ASSERT_NO_FATAL_FAILURE(
542 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000)));
543 ASSERT_NO_FATAL_FAILURE(
544 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000)));
545
Peiyong Lin65248e02020-04-18 21:15:07 -0700546 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::OFF));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800547 ASSERT_NO_FATAL_FAILURE(
548 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(6000000)));
549 ASSERT_NO_FATAL_FAILURE(
550 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(8000000)));
551
552 SFTimeStatsGlobalProto globalProto;
553 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
554
555 ASSERT_EQ(1, globalProto.present_to_present_size());
556 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.present_to_present().Get(0);
557 EXPECT_EQ(1, histogramProto.frame_count());
558 EXPECT_EQ(2, histogramProto.time_millis());
559}
560
Alec Mouri9519bf12019-11-15 16:54:44 -0800561TEST_F(TimeStatsTest, canInsertGlobalFrameDuration) {
562 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
563
Peiyong Lin65248e02020-04-18 21:15:07 -0700564 mTimeStats->setPowerMode(PowerMode::OFF);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000565 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(1ms).count(),
566 std::chrono::nanoseconds(5ms).count());
Peiyong Lin65248e02020-04-18 21:15:07 -0700567 mTimeStats->setPowerMode(PowerMode::ON);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000568 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(3ms).count(),
569 std::chrono::nanoseconds(6ms).count());
Alec Mouri9519bf12019-11-15 16:54:44 -0800570
571 SFTimeStatsGlobalProto globalProto;
572 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
573
574 ASSERT_EQ(1, globalProto.frame_duration_size());
575 const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.frame_duration().Get(0);
576 EXPECT_EQ(1, histogramProto.frame_count());
577 EXPECT_EQ(3, histogramProto.time_millis());
578}
579
Alec Mourie4034bb2019-11-19 12:45:54 -0800580TEST_F(TimeStatsTest, canInsertGlobalRenderEngineTiming) {
581 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
582
Adithya Srinivasanead17162021-02-18 02:17:37 +0000583 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(1ms).count(),
Alec Mourie4034bb2019-11-19 12:45:54 -0800584 std::make_shared<FenceTime>(
585 std::chrono::duration_cast<
586 std::chrono::nanoseconds>(3ms)
587 .count()));
588
Adithya Srinivasanead17162021-02-18 02:17:37 +0000589 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(4ms).count(),
590 std::chrono::nanoseconds(6ms).count());
Alec Mourie4034bb2019-11-19 12:45:54 -0800591
592 // First verify that flushing RenderEngine durations did not occur yet.
593 SFTimeStatsGlobalProto preFlushProto;
594 ASSERT_TRUE(preFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
595 ASSERT_EQ(0, preFlushProto.render_engine_timing_size());
596
Peiyong Lind8460c82020-07-28 16:04:22 -0700597 // Push a fake present fence to trigger flushing the RenderEngine timings.
Peiyong Lin65248e02020-04-18 21:15:07 -0700598 mTimeStats->setPowerMode(PowerMode::ON);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000599 mTimeStats->setPresentFenceGlobal(
600 std::make_shared<FenceTime>(std::chrono::nanoseconds(1ms).count()));
Alec Mourie4034bb2019-11-19 12:45:54 -0800601
602 // Now we can verify that RenderEngine durations were flushed now.
603 SFTimeStatsGlobalProto postFlushProto;
604 ASSERT_TRUE(postFlushProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
605
606 ASSERT_EQ(1, postFlushProto.render_engine_timing_size());
607 const SFTimeStatsHistogramBucketProto& histogramProto =
608 postFlushProto.render_engine_timing().Get(0);
609 EXPECT_EQ(2, histogramProto.frame_count());
610 EXPECT_EQ(2, histogramProto.time_millis());
611}
612
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800613TEST_F(TimeStatsTest, canInsertOneLayerTimeStats) {
614 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
615
616 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
617 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_0, 2, 2000000);
618
619 SFTimeStatsGlobalProto globalProto;
620 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
621
622 ASSERT_EQ(1, globalProto.stats_size());
623 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
624 ASSERT_TRUE(layerProto.has_layer_name());
625 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
626 ASSERT_TRUE(layerProto.has_total_frames());
627 EXPECT_EQ(1, layerProto.total_frames());
628 ASSERT_EQ(6, layerProto.deltas_size());
629 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
630 ASSERT_EQ(1, deltaProto.histograms_size());
631 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
632 EXPECT_EQ(1, histogramProto.frame_count());
633 if ("post2acquire" == deltaProto.delta_name()) {
634 EXPECT_EQ(1, histogramProto.time_millis());
635 } else if ("post2present" == deltaProto.delta_name()) {
636 EXPECT_EQ(4, histogramProto.time_millis());
637 } else if ("acquire2present" == deltaProto.delta_name()) {
638 EXPECT_EQ(3, histogramProto.time_millis());
639 } else if ("latch2present" == deltaProto.delta_name()) {
640 EXPECT_EQ(2, histogramProto.time_millis());
641 } else if ("desired2present" == deltaProto.delta_name()) {
642 EXPECT_EQ(1, histogramProto.time_millis());
643 } else if ("present2present" == deltaProto.delta_name()) {
644 EXPECT_EQ(1, histogramProto.time_millis());
645 } else {
646 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
647 }
648 }
649}
650
651TEST_F(TimeStatsTest, canNotInsertInvalidLayerNameTimeStats) {
652 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
653
654 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_INVALID, 1, 1000000);
655 insertTimeRecord(NORMAL_SEQUENCE_2, LAYER_ID_INVALID, 2, 2000000);
656
657 SFTimeStatsGlobalProto globalProto;
658 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
659
660 ASSERT_EQ(0, globalProto.stats_size());
661}
662
663TEST_F(TimeStatsTest, canInsertMultipleLayersTimeStats) {
664 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
665
666 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
667 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
668 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
669 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
670
671 SFTimeStatsGlobalProto globalProto;
672 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
673
674 EXPECT_EQ(2, globalProto.stats_size());
675}
676
677TEST_F(TimeStatsTest, canInsertUnorderedLayerTimeStats) {
678 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
679
680 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
681 insertTimeRecord(UNORDERED_SEQUENCE, LAYER_ID_0, 2, 2000000);
682
683 SFTimeStatsGlobalProto globalProto;
684 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
685
686 ASSERT_EQ(1, globalProto.stats_size());
687 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
688 ASSERT_TRUE(layerProto.has_layer_name());
689 EXPECT_EQ(genLayerName(LAYER_ID_0), layerProto.layer_name());
690 ASSERT_TRUE(layerProto.has_total_frames());
691 EXPECT_EQ(1, layerProto.total_frames());
692 ASSERT_EQ(6, layerProto.deltas_size());
693 for (const SFTimeStatsDeltaProto& deltaProto : layerProto.deltas()) {
694 ASSERT_EQ(1, deltaProto.histograms_size());
695 const SFTimeStatsHistogramBucketProto& histogramProto = deltaProto.histograms().Get(0);
696 EXPECT_EQ(1, histogramProto.frame_count());
697 if ("post2acquire" == deltaProto.delta_name()) {
698 EXPECT_EQ(0, histogramProto.time_millis());
699 } else if ("post2present" == deltaProto.delta_name()) {
700 EXPECT_EQ(2, histogramProto.time_millis());
701 } else if ("acquire2present" == deltaProto.delta_name()) {
702 EXPECT_EQ(2, histogramProto.time_millis());
703 } else if ("latch2present" == deltaProto.delta_name()) {
704 EXPECT_EQ(2, histogramProto.time_millis());
705 } else if ("desired2present" == deltaProto.delta_name()) {
706 EXPECT_EQ(1, histogramProto.time_millis());
707 } else if ("present2present" == deltaProto.delta_name()) {
708 EXPECT_EQ(1, histogramProto.time_millis());
709 } else {
710 FAIL() << "Unknown delta_name: " << deltaProto.delta_name();
711 }
712 }
713}
714
Alec Mourifb571ea2019-01-24 18:42:10 -0800715TEST_F(TimeStatsTest, recordRefreshRateNewConfigs) {
716 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
717
718 uint32_t fpsOne = 30;
719 uint32_t fpsTwo = 90;
720 uint64_t millisOne = 5000;
721 uint64_t millisTwo = 7000;
722
723 mTimeStats->recordRefreshRate(fpsOne, ms2ns(millisOne));
724 mTimeStats->recordRefreshRate(fpsTwo, ms2ns(millisTwo));
725
726 SFTimeStatsGlobalProto globalProto;
727 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
728
729 SFTimeStatsDisplayConfigBucketProto expectedBucketOne;
730 SFTimeStatsDisplayConfigProto* expectedConfigOne = expectedBucketOne.mutable_config();
731 expectedConfigOne->set_fps(fpsOne);
732 expectedBucketOne.set_duration_millis(millisOne);
733
734 SFTimeStatsDisplayConfigBucketProto expectedBucketTwo;
735 SFTimeStatsDisplayConfigProto* expectedConfigTwo = expectedBucketTwo.mutable_config();
736 expectedConfigTwo->set_fps(fpsTwo);
737 expectedBucketTwo.set_duration_millis(millisTwo);
738
739 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(2));
740
741 std::unordered_set<uint32_t> seen_fps;
742 for (const auto& bucket : globalProto.display_config_stats()) {
743 seen_fps.emplace(bucket.config().fps());
744 if (fpsOne == bucket.config().fps()) {
745 EXPECT_EQ(millisOne, bucket.duration_millis());
746 } else if (fpsTwo == bucket.config().fps()) {
747 EXPECT_EQ(millisTwo, bucket.duration_millis());
748 } else {
749 FAIL() << "Unknown fps: " << bucket.config().fps();
750 }
751 }
752 EXPECT_THAT(seen_fps, UnorderedElementsAre(fpsOne, fpsTwo));
753}
754
755TEST_F(TimeStatsTest, recordRefreshRateUpdatesConfig) {
756 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
757
758 uint32_t fps = 30;
759 uint64_t millisOne = 5000;
760 uint64_t millisTwo = 7000;
761
762 mTimeStats->recordRefreshRate(fps, ms2ns(millisOne));
763 mTimeStats->recordRefreshRate(fps, ms2ns(millisTwo));
764
765 SFTimeStatsGlobalProto globalProto;
766 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
767 EXPECT_THAT(globalProto.display_config_stats(), SizeIs(1));
768 EXPECT_EQ(fps, globalProto.display_config_stats().Get(0).config().fps());
769 EXPECT_EQ(millisOne + millisTwo, globalProto.display_config_stats().Get(0).duration_millis());
770}
771
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800772TEST_F(TimeStatsTest, canRemoveTimeRecord) {
773 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
774
775 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
776 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 2, 2000000);
777 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(0, 2));
778 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
779
780 SFTimeStatsGlobalProto globalProto;
781 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
782
783 ASSERT_EQ(1, globalProto.stats_size());
784 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
785 ASSERT_TRUE(layerProto.has_total_frames());
786 EXPECT_EQ(1, layerProto.total_frames());
787}
788
789TEST_F(TimeStatsTest, canRecoverFromIncompleteTimeRecordError) {
790 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
791
792 uint64_t frameNumber = 1;
793 nsecs_t ts = 1000000;
794 insertTimeRecord(INCOMPLETE_SEQUENCE, LAYER_ID_0, 1, 1000000);
Alec Mourifb571ea2019-01-24 18:42:10 -0800795 for (size_t i = 0; i < impl::TimeStats::MAX_NUM_TIME_RECORDS + 2; i++) {
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800796 frameNumber++;
797 ts += 1000000;
798 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, frameNumber, ts);
799 }
800
801 SFTimeStatsGlobalProto globalProto;
802 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
803
804 ASSERT_EQ(1, globalProto.stats_size());
805 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
806 ASSERT_TRUE(layerProto.has_total_frames());
807 EXPECT_EQ(1, layerProto.total_frames());
808}
809
810TEST_F(TimeStatsTest, layerTimeStatsOnDestroy) {
811 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
812
813 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
814 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
815 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(0));
816 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 3000000);
817
818 SFTimeStatsGlobalProto globalProto;
819 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
820
821 ASSERT_EQ(1, globalProto.stats_size());
822 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
823 ASSERT_TRUE(layerProto.has_total_frames());
824 EXPECT_EQ(1, layerProto.total_frames());
825}
826
827TEST_F(TimeStatsTest, canClearTimeStats) {
828 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
829
830 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementTotalFrames());
831 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementMissedFrames());
832 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionFrames());
Peiyong Lin65248e02020-04-18 21:15:07 -0700833 ASSERT_NO_FATAL_FAILURE(mTimeStats->setPowerMode(PowerMode::ON));
Alec Mouri31ac64a2020-01-09 09:26:22 -0800834
Adithya Srinivasanead17162021-02-18 02:17:37 +0000835 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(3ms).count(),
836 std::chrono::nanoseconds(6ms).count());
837 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(4ms).count(),
838 std::chrono::nanoseconds(6ms).count());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800839 ASSERT_NO_FATAL_FAILURE(
840 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(1000000)));
841 ASSERT_NO_FATAL_FAILURE(
842 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(2000000)));
843 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
844 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
845
846 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
847
848 SFTimeStatsGlobalProto globalProto;
849 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
850
851 EXPECT_EQ(0, globalProto.total_frames());
852 EXPECT_EQ(0, globalProto.missed_frames());
853 EXPECT_EQ(0, globalProto.client_composition_frames());
854 EXPECT_EQ(0, globalProto.present_to_present_size());
Alec Mouri31ac64a2020-01-09 09:26:22 -0800855 EXPECT_EQ(0, globalProto.frame_duration_size());
856 EXPECT_EQ(0, globalProto.render_engine_timing_size());
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800857 EXPECT_EQ(0, globalProto.stats_size());
858}
859
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800860TEST_F(TimeStatsTest, canClearDumpOnlyTimeStats) {
861 // These stats are not in the proto so verify by checking the string dump.
Vishnu Nair9b079a22020-01-21 14:36:08 -0800862 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
863 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementClientCompositionReusedFrames());
Alec Mouri8de697e2020-03-19 10:52:01 -0700864 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementRefreshRateSwitches());
Alec Mouri8f7a0102020-04-15 12:11:10 -0700865 ASSERT_NO_FATAL_FAILURE(mTimeStats->incrementCompositionStrategyChanges());
Peiyong Lin65248e02020-04-18 21:15:07 -0700866 mTimeStats->setPowerMode(PowerMode::ON);
Adithya Srinivasanead17162021-02-18 02:17:37 +0000867 mTimeStats->recordFrameDuration(std::chrono::nanoseconds(1ms).count(),
868 std::chrono::nanoseconds(5ms).count());
869 mTimeStats->recordRenderEngineDuration(std::chrono::nanoseconds(4ms).count(),
870 std::chrono::nanoseconds(6ms).count());
871 mTimeStats->setPresentFenceGlobal(
872 std::make_shared<FenceTime>(std::chrono::nanoseconds(1ms).count()));
Alec Mouri9a29e672020-09-14 12:39:14 -0700873
Alec Mouri363faf02021-01-29 16:34:55 -0800874 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
875 JankType::SurfaceFlingerCpuDeadlineMissed, 1, 2, 3});
876 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
877 JankType::SurfaceFlingerGpuDeadlineMissed, 1, 2, 3});
878 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
879 JankType::DisplayHAL, 1, 2, 3});
880 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
881 JankType::AppDeadlineMissed, 1, 2, 3});
882 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasanead17162021-02-18 02:17:37 +0000883 JankType::SurfaceFlingerScheduling, 1, 2, 3});
884 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
885 JankType::PredictionError, 1, 2, 3});
886 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
887 JankType::AppDeadlineMissed | JankType::BufferStuffing, 1, 2,
888 3});
889 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Alec Mouri363faf02021-01-29 16:34:55 -0800890 JankType::None, 1, 2, 3});
Alec Mouri9a29e672020-09-14 12:39:14 -0700891
Vishnu Nair9b079a22020-01-21 14:36:08 -0800892 EXPECT_TRUE(inputCommand(InputCommand::CLEAR, FMT_STRING).empty());
893
894 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
895 EXPECT_THAT(result, HasSubstr("clientCompositionReusedFrames = 0"));
Alec Mouri8de697e2020-03-19 10:52:01 -0700896 EXPECT_THAT(result, HasSubstr("refreshRateSwitches = 0"));
Alec Mouri8f7a0102020-04-15 12:11:10 -0700897 EXPECT_THAT(result, HasSubstr("compositionStrategyChanges = 0"));
Vishnu Nairabf97fd2020-02-03 13:51:16 -0800898 EXPECT_THAT(result, HasSubstr("averageFrameDuration = 0.000 ms"));
899 EXPECT_THAT(result, HasSubstr("averageRenderEngineTiming = 0.000 ms"));
Alec Mouri56e63852021-03-09 18:17:25 -0800900 std::string expectedResult = "totalTimelineFrames = " + std::to_string(0);
901 EXPECT_THAT(result, HasSubstr(expectedResult));
902 expectedResult = "jankyFrames = " + std::to_string(0);
903 EXPECT_THAT(result, HasSubstr(expectedResult));
904 expectedResult = "sfLongCpuJankyFrames = " + std::to_string(0);
905 EXPECT_THAT(result, HasSubstr(expectedResult));
906 expectedResult = "sfLongGpuJankyFrames = " + std::to_string(0);
907 EXPECT_THAT(result, HasSubstr(expectedResult));
908 expectedResult = "sfUnattributedJankyFrames = " + std::to_string(0);
909 EXPECT_THAT(result, HasSubstr(expectedResult));
910 expectedResult = "appUnattributedJankyFrames = " + std::to_string(0);
911 EXPECT_THAT(result, HasSubstr(expectedResult));
912 expectedResult = "sfSchedulingJankyFrames = " + std::to_string(0);
913 EXPECT_THAT(result, HasSubstr(expectedResult));
914 expectedResult = "sfPredictionErrorJankyFrames = " + std::to_string(0);
915 EXPECT_THAT(result, HasSubstr(expectedResult));
916 expectedResult = "appBufferStuffingJankyFrames = " + std::to_string(0);
917 EXPECT_THAT(result, HasSubstr(expectedResult));
Vishnu Nair9b079a22020-01-21 14:36:08 -0800918}
919
Yiwei Zhang16faa5d2018-11-13 18:12:59 -0800920TEST_F(TimeStatsTest, canDumpWithMaxLayers) {
921 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
922
923 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
924 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 1000000);
925 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
926 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 2000000);
927 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 3, 2000000);
928
929 SFTimeStatsGlobalProto globalProto;
930 ASSERT_TRUE(
931 globalProto.ParseFromString(inputCommand(InputCommand::DUMP_MAXLAYERS_1, FMT_PROTO)));
932
933 ASSERT_EQ(1, globalProto.stats_size());
934 const SFTimeStatsLayerProto& layerProto = globalProto.stats().Get(0);
935 ASSERT_TRUE(layerProto.has_layer_name());
936 EXPECT_EQ(genLayerName(LAYER_ID_1), layerProto.layer_name());
937 ASSERT_TRUE(layerProto.has_total_frames());
938 EXPECT_EQ(2, layerProto.total_frames());
939}
940
941TEST_F(TimeStatsTest, canDumpWithInvalidMaxLayers) {
942 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
943
944 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
945 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
946
947 SFTimeStatsGlobalProto globalProto;
948 ASSERT_TRUE(globalProto.ParseFromString(
949 inputCommand(InputCommand::DUMP_MAXLAYERS_INVALID, FMT_PROTO)));
950
951 ASSERT_EQ(0, globalProto.stats_size());
952}
953
Yiwei Zhangdd221b22020-06-12 11:06:19 -0700954TEST_F(TimeStatsTest, noInfInAverageFPS) {
955 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
956 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
957 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 1000000);
958
959 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
960 EXPECT_THAT(result, HasSubstr("averageFPS = 0.000"));
961}
962
Alec Mouri37384342020-01-02 17:23:37 -0800963namespace {
Tej Singhe2751772021-04-06 22:05:29 -0700964FrameTimingHistogram buildExpectedHistogram(const std::vector<int32_t>& times,
965 const std::vector<int32_t>& frameCounts) {
966 FrameTimingHistogram histogram;
Alec Mouri37384342020-01-02 17:23:37 -0800967 for (int i = 0; i < times.size(); i++) {
968 ALOGE("Writing time: %d", times[i]);
Tej Singhe2751772021-04-06 22:05:29 -0700969 histogram.add_time_millis_buckets(times[i]);
Alec Mouri37384342020-01-02 17:23:37 -0800970 ALOGE("Writing count: %d", frameCounts[i]);
Tej Singhe2751772021-04-06 22:05:29 -0700971 histogram.add_frame_counts((int64_t)frameCounts[i]);
Alec Mouri37384342020-01-02 17:23:37 -0800972 }
Tej Singhe2751772021-04-06 22:05:29 -0700973 return histogram;
Alec Mouri37384342020-01-02 17:23:37 -0800974}
Alec Mouri37384342020-01-02 17:23:37 -0800975} // namespace
976
Tej Singhe2751772021-04-06 22:05:29 -0700977MATCHER_P(HistogramEq, expected, "") {
978 *result_listener << "Histograms are not equal! \n";
Alec Mouri37384342020-01-02 17:23:37 -0800979
Tej Singhe2751772021-04-06 22:05:29 -0700980 if (arg.time_millis_buckets_size() != expected.time_millis_buckets_size()) {
981 *result_listener << "Time millis bucket are different sizes. Expected: "
982 << expected.time_millis_buckets_size() << ". Actual "
983 << arg.time_millis_buckets_size();
984 return false;
985 }
986 if (arg.frame_counts_size() != expected.frame_counts_size()) {
987 *result_listener << "Frame counts are different sizes. Expected: "
988 << expected.frame_counts_size() << ". Actual " << arg.frame_counts_size();
989 return false;
990 }
Alec Mouri37384342020-01-02 17:23:37 -0800991
Tej Singhe2751772021-04-06 22:05:29 -0700992 for (int i = 0; i < expected.time_millis_buckets_size(); i++) {
993 if (arg.time_millis_buckets(i) != expected.time_millis_buckets(i)) {
994 *result_listener << "time_millis_bucket[" << i
995 << "] is different. Expected: " << expected.time_millis_buckets(i)
996 << ". Actual: " << arg.time_millis_buckets(i);
997 return false;
998 }
999 if (arg.frame_counts(i) != expected.frame_counts(i)) {
1000 *result_listener << "frame_counts[" << i
1001 << "] is different. Expected: " << expected.frame_counts(i)
1002 << ". Actual: " << arg.frame_counts(i);
1003 return false;
1004 }
1005 }
1006 return true;
Alec Mouri37384342020-01-02 17:23:37 -08001007}
1008
Alec Mouridfad9002020-02-12 17:49:09 -08001009TEST_F(TimeStatsTest, globalStatsCallback) {
1010 constexpr size_t TOTAL_FRAMES = 5;
1011 constexpr size_t MISSED_FRAMES = 4;
1012 constexpr size_t CLIENT_COMPOSITION_FRAMES = 3;
1013 constexpr size_t DISPLAY_EVENT_CONNECTIONS = 14;
1014
Alec Mouridfad9002020-02-12 17:49:09 -08001015 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1016
1017 for (size_t i = 0; i < TOTAL_FRAMES; i++) {
1018 mTimeStats->incrementTotalFrames();
1019 }
1020 for (size_t i = 0; i < MISSED_FRAMES; i++) {
1021 mTimeStats->incrementMissedFrames();
1022 }
1023 for (size_t i = 0; i < CLIENT_COMPOSITION_FRAMES; i++) {
1024 mTimeStats->incrementClientCompositionFrames();
1025 }
1026
Alec Mouri9a29e672020-09-14 12:39:14 -07001027 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1028
Alec Mouridfad9002020-02-12 17:49:09 -08001029 mTimeStats->recordDisplayEventConnectionCount(DISPLAY_EVENT_CONNECTIONS);
Peiyong Lin65248e02020-04-18 21:15:07 -07001030 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouridfad9002020-02-12 17:49:09 -08001031 mTimeStats->recordFrameDuration(1000000, 3000000);
1032 mTimeStats->recordRenderEngineDuration(2000000, 4000000);
1033 mTimeStats->recordRenderEngineDuration(2000000, std::make_shared<FenceTime>(3000000));
1034
1035 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
1036 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
1037
Alec Mouri363faf02021-01-29 16:34:55 -08001038 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1039 JankType::SurfaceFlingerCpuDeadlineMissed, 1, 2, 3});
1040 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1041 JankType::SurfaceFlingerGpuDeadlineMissed, 1, 2, 3});
1042 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1043 JankType::DisplayHAL, 1, 2, 3});
1044 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1045 JankType::AppDeadlineMissed, 1, 2, 3});
1046 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasanead17162021-02-18 02:17:37 +00001047 JankType::SurfaceFlingerScheduling, 1, 2, 3});
1048 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1049 JankType::PredictionError, 1, 2, 3});
1050 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1051 JankType::AppDeadlineMissed | JankType::BufferStuffing, 1, 2,
1052 3});
1053 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasan53e5c402021-04-16 17:34:30 +00001054 JankType::BufferStuffing, 1, 2, 3});
1055 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Alec Mouri363faf02021-01-29 16:34:55 -08001056 JankType::None, 1, 2, 3});
Alec Mouri9a29e672020-09-14 12:39:14 -07001057
Tej Singhe2751772021-04-06 22:05:29 -07001058 std::string pulledData;
1059 EXPECT_TRUE(mTimeStats->onPullAtom(10062 /*SURFACEFLINGER_STATS_GLOBAL_INFO*/, &pulledData));
Alec Mouridfad9002020-02-12 17:49:09 -08001060
Tej Singhe2751772021-04-06 22:05:29 -07001061 android::surfaceflinger::SurfaceflingerStatsGlobalInfoWrapper atomList;
1062 ASSERT_TRUE(atomList.ParseFromString(pulledData));
1063 ASSERT_EQ(atomList.atom_size(), 1);
1064 const android::surfaceflinger::SurfaceflingerStatsGlobalInfo& atom = atomList.atom(0);
Alec Mouridfad9002020-02-12 17:49:09 -08001065
Tej Singhe2751772021-04-06 22:05:29 -07001066 EXPECT_EQ(atom.total_frames(), TOTAL_FRAMES);
1067 EXPECT_EQ(atom.missed_frames(), MISSED_FRAMES);
1068 EXPECT_EQ(atom.client_composition_frames(), CLIENT_COMPOSITION_FRAMES);
1069 // Display on millis is not checked.
1070 EXPECT_EQ(atom.animation_millis(), 2);
1071 EXPECT_EQ(atom.event_connection_count(), DISPLAY_EVENT_CONNECTIONS);
1072 EXPECT_THAT(atom.frame_duration(), HistogramEq(buildExpectedHistogram({2}, {1})));
1073 EXPECT_THAT(atom.render_engine_timing(), HistogramEq(buildExpectedHistogram({1, 2}, {1, 1})));
Adithya Srinivasan53e5c402021-04-16 17:34:30 +00001074 EXPECT_EQ(atom.total_timeline_frames(), 9);
Tej Singhe2751772021-04-06 22:05:29 -07001075 EXPECT_EQ(atom.total_janky_frames(), 7);
1076 EXPECT_EQ(atom.total_janky_frames_with_long_cpu(), 1);
1077 EXPECT_EQ(atom.total_janky_frames_with_long_gpu(), 1);
1078 EXPECT_EQ(atom.total_janky_frames_sf_unattributed(), 1);
1079 EXPECT_EQ(atom.total_janky_frames_app_unattributed(), 2);
1080 EXPECT_EQ(atom.total_janky_frames_sf_scheduling(), 1);
1081 EXPECT_EQ(atom.total_jank_frames_sf_prediction_error(), 1);
Adithya Srinivasan53e5c402021-04-16 17:34:30 +00001082 EXPECT_EQ(atom.total_jank_frames_app_buffer_stuffing(), 2);
Tej Singhe2751772021-04-06 22:05:29 -07001083 EXPECT_EQ(atom.display_refresh_rate_bucket(), REFRESH_RATE_BUCKET_0);
1084 EXPECT_THAT(atom.sf_deadline_misses(), HistogramEq(buildExpectedHistogram({1}, {7})));
1085 EXPECT_THAT(atom.sf_prediction_errors(), HistogramEq(buildExpectedHistogram({2}, {7})));
1086 EXPECT_EQ(atom.render_rate_bucket(), RENDER_RATE_BUCKET_0);
Alec Mouridfad9002020-02-12 17:49:09 -08001087
1088 SFTimeStatsGlobalProto globalProto;
1089 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
1090
1091 EXPECT_EQ(0, globalProto.total_frames());
1092 EXPECT_EQ(0, globalProto.missed_frames());
1093 EXPECT_EQ(0, globalProto.client_composition_frames());
1094 EXPECT_EQ(0, globalProto.present_to_present_size());
Alec Mouri56e63852021-03-09 18:17:25 -08001095
1096 // also check dump-only stats: expect that global stats are indeed dropped but there should
1097 // still be stats for the layer
1098 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
1099 std::string expectedResult = "totalTimelineFrames = " + std::to_string(0);
1100 EXPECT_THAT(result, HasSubstr(expectedResult));
Adithya Srinivasan53e5c402021-04-16 17:34:30 +00001101 expectedResult = "totalTimelineFrames = " + std::to_string(9);
Alec Mouri56e63852021-03-09 18:17:25 -08001102 EXPECT_THAT(result, HasSubstr(expectedResult));
1103 expectedResult = "jankyFrames = " + std::to_string(0);
1104 EXPECT_THAT(result, HasSubstr(expectedResult));
1105 expectedResult = "jankyFrames = " + std::to_string(7);
1106 EXPECT_THAT(result, HasSubstr(expectedResult));
1107 expectedResult = "sfLongCpuJankyFrames = " + std::to_string(0);
1108 EXPECT_THAT(result, HasSubstr(expectedResult));
1109 expectedResult = "sfLongCpuJankyFrames = " + std::to_string(1);
1110 EXPECT_THAT(result, HasSubstr(expectedResult));
1111 expectedResult = "sfLongGpuJankyFrames = " + std::to_string(0);
1112 EXPECT_THAT(result, HasSubstr(expectedResult));
1113 expectedResult = "sfLongGpuJankyFrames = " + std::to_string(1);
1114 EXPECT_THAT(result, HasSubstr(expectedResult));
1115 expectedResult = "sfUnattributedJankyFrames = " + std::to_string(0);
1116 EXPECT_THAT(result, HasSubstr(expectedResult));
1117 expectedResult = "sfUnattributedJankyFrames = " + std::to_string(1);
1118 EXPECT_THAT(result, HasSubstr(expectedResult));
1119 expectedResult = "appUnattributedJankyFrames = " + std::to_string(0);
1120 EXPECT_THAT(result, HasSubstr(expectedResult));
1121 expectedResult = "appUnattributedJankyFrames = " + std::to_string(2);
1122 EXPECT_THAT(result, HasSubstr(expectedResult));
1123 expectedResult = "sfSchedulingJankyFrames = " + std::to_string(0);
1124 EXPECT_THAT(result, HasSubstr(expectedResult));
1125 expectedResult = "sfSchedulingJankyFrames = " + std::to_string(1);
1126 EXPECT_THAT(result, HasSubstr(expectedResult));
1127 expectedResult = "sfPredictionErrorJankyFrames = " + std::to_string(0);
1128 EXPECT_THAT(result, HasSubstr(expectedResult));
1129 expectedResult = "sfPredictionErrorJankyFrames = " + std::to_string(1);
1130 EXPECT_THAT(result, HasSubstr(expectedResult));
1131 expectedResult = "appBufferStuffingJankyFrames = " + std::to_string(0);
1132 EXPECT_THAT(result, HasSubstr(expectedResult));
Adithya Srinivasan53e5c402021-04-16 17:34:30 +00001133 expectedResult = "appBufferStuffingJankyFrames = " + std::to_string(2);
Alec Mouri56e63852021-03-09 18:17:25 -08001134 EXPECT_THAT(result, HasSubstr(expectedResult));
Alec Mouridfad9002020-02-12 17:49:09 -08001135}
1136
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001137TEST_F(TimeStatsTest, layerStatsCallback_pullsAllAndClears) {
1138 constexpr size_t LATE_ACQUIRE_FRAMES = 2;
1139 constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 3;
Alec Mouri37384342020-01-02 17:23:37 -08001140 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1141
Alec Mouri37384342020-01-02 17:23:37 -08001142 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
Yiwei Zhang7bfc75b2020-02-10 11:20:34 -08001143 for (size_t i = 0; i < LATE_ACQUIRE_FRAMES; i++) {
1144 mTimeStats->incrementLatchSkipped(LAYER_ID_0, TimeStats::LatchSkipReason::LateAcquire);
1145 }
1146 for (size_t i = 0; i < BAD_DESIRED_PRESENT_FRAMES; i++) {
1147 mTimeStats->incrementBadDesiredPresent(LAYER_ID_0);
1148 }
Ady Abraham8b9e6122021-01-26 19:11:45 -08001149 const auto frameRate60 = TimeStats::SetFrameRateVote{
1150 .frameRate = 60.0f,
1151 .frameRateCompatibility =
1152 TimeStats::SetFrameRateVote::FrameRateCompatibility::ExactOrMultiple,
1153 .seamlessness = TimeStats::SetFrameRateVote::Seamlessness::NotRequired,
1154 };
1155 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000, frameRate60);
Alec Mouri37384342020-01-02 17:23:37 -08001156
Alec Mouri363faf02021-01-29 16:34:55 -08001157 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1158 JankType::SurfaceFlingerCpuDeadlineMissed, 1, 2, 3});
1159 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1160 JankType::SurfaceFlingerGpuDeadlineMissed, 1, 2, 3});
1161 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1162 JankType::DisplayHAL, 1, 2, 3});
1163 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1164 JankType::AppDeadlineMissed, 1, 2, 3});
1165 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Adithya Srinivasanead17162021-02-18 02:17:37 +00001166 JankType::SurfaceFlingerScheduling, 1, 2, 2});
1167 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1168 JankType::PredictionError, 1, 2, 2});
1169 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
1170 JankType::AppDeadlineMissed | JankType::BufferStuffing, 1, 2,
1171 2});
1172 mTimeStats->incrementJankyFrames({kRefreshRate0, kRenderRate0, UID_0, genLayerName(LAYER_ID_0),
Alec Mouri363faf02021-01-29 16:34:55 -08001173 JankType::None, 1, 2, 3});
Alec Mouri9a29e672020-09-14 12:39:14 -07001174
Tej Singhe2751772021-04-06 22:05:29 -07001175 std::string pulledData;
1176 EXPECT_TRUE(mTimeStats->onPullAtom(10063 /*SURFACEFLINGER_STATS_LAYER_INFO*/, &pulledData));
Alec Mouri37384342020-01-02 17:23:37 -08001177
Tej Singhe2751772021-04-06 22:05:29 -07001178 android::surfaceflinger::SurfaceflingerStatsLayerInfoWrapper atomList;
1179 ASSERT_TRUE(atomList.ParseFromString(pulledData));
1180 ASSERT_EQ(atomList.atom_size(), 1);
1181 const android::surfaceflinger::SurfaceflingerStatsLayerInfo& atom = atomList.atom(0);
Alec Mouri9a29e672020-09-14 12:39:14 -07001182
Tej Singhe2751772021-04-06 22:05:29 -07001183 EXPECT_EQ(atom.layer_name(), genLayerName(LAYER_ID_0));
1184 EXPECT_EQ(atom.total_frames(), 1);
1185 EXPECT_EQ(atom.dropped_frames(), 0);
1186 EXPECT_THAT(atom.present_to_present(), HistogramEq(buildExpectedHistogram({1}, {1})));
1187 EXPECT_THAT(atom.post_to_present(), HistogramEq(buildExpectedHistogram({4}, {1})));
1188 EXPECT_THAT(atom.acquire_to_present(), HistogramEq(buildExpectedHistogram({3}, {1})));
1189 EXPECT_THAT(atom.latch_to_present(), HistogramEq(buildExpectedHistogram({2}, {1})));
1190 EXPECT_THAT(atom.desired_to_present(), HistogramEq(buildExpectedHistogram({1}, {1})));
1191 EXPECT_THAT(atom.post_to_acquire(), HistogramEq(buildExpectedHistogram({1}, {1})));
1192 EXPECT_EQ(atom.late_acquire_frames(), LATE_ACQUIRE_FRAMES);
1193 EXPECT_EQ(atom.bad_desired_present_frames(), BAD_DESIRED_PRESENT_FRAMES);
1194 EXPECT_EQ(atom.uid(), UID_0);
1195 EXPECT_EQ(atom.total_timeline_frames(), 8);
1196 EXPECT_EQ(atom.total_janky_frames(), 7);
1197 EXPECT_EQ(atom.total_janky_frames_with_long_cpu(), 1);
1198 EXPECT_EQ(atom.total_janky_frames_with_long_gpu(), 1);
1199 EXPECT_EQ(atom.total_janky_frames_sf_unattributed(), 1);
1200 EXPECT_EQ(atom.total_janky_frames_app_unattributed(), 2);
1201 EXPECT_EQ(atom.total_janky_frames_sf_scheduling(), 1);
1202 EXPECT_EQ(atom.total_jank_frames_sf_prediction_error(), 1);
1203 EXPECT_EQ(atom.total_jank_frames_app_buffer_stuffing(), 1);
1204 EXPECT_EQ(atom.display_refresh_rate_bucket(), REFRESH_RATE_BUCKET_0);
1205 EXPECT_EQ(atom.render_rate_bucket(), RENDER_RATE_BUCKET_0);
1206 EXPECT_THAT(atom.set_frame_rate_vote().frame_rate(), testing::FloatEq(frameRate60.frameRate));
1207 EXPECT_EQ((int)atom.set_frame_rate_vote().frame_rate_compatibility(),
1208 (int)frameRate60.frameRateCompatibility);
1209 EXPECT_EQ((int)atom.set_frame_rate_vote().seamlessness(), (int)frameRate60.seamlessness);
1210 EXPECT_THAT(atom.app_deadline_misses(), HistogramEq(buildExpectedHistogram({3, 2}, {4, 3})));
Alec Mouri37384342020-01-02 17:23:37 -08001211
1212 SFTimeStatsGlobalProto globalProto;
1213 ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
1214
1215 EXPECT_EQ(0, globalProto.stats_size());
Alec Mouri56e63852021-03-09 18:17:25 -08001216
1217 // also check dump-only stats: expect that layer stats are indeed dropped but there should still
1218 // be global stats
1219 const std::string result(inputCommand(InputCommand::DUMP_ALL, FMT_STRING));
1220 std::string expectedResult = "totalTimelineFrames = " + std::to_string(8);
1221 EXPECT_THAT(result, HasSubstr(expectedResult));
1222 expectedResult = "jankyFrames = " + std::to_string(7);
1223 EXPECT_THAT(result, HasSubstr(expectedResult));
1224 expectedResult = "sfLongCpuJankyFrames = " + std::to_string(1);
1225 EXPECT_THAT(result, HasSubstr(expectedResult));
1226 expectedResult = "sfLongGpuJankyFrames = " + std::to_string(1);
1227 EXPECT_THAT(result, HasSubstr(expectedResult));
1228 expectedResult = "sfUnattributedJankyFrames = " + std::to_string(1);
1229 EXPECT_THAT(result, HasSubstr(expectedResult));
1230 expectedResult = "appUnattributedJankyFrames = " + std::to_string(2);
1231 EXPECT_THAT(result, HasSubstr(expectedResult));
1232 expectedResult = "sfSchedulingJankyFrames = " + std::to_string(1);
1233 EXPECT_THAT(result, HasSubstr(expectedResult));
1234 expectedResult = "sfPredictionErrorJankyFrames = " + std::to_string(1);
1235 EXPECT_THAT(result, HasSubstr(expectedResult));
1236 expectedResult = "appBufferStuffingJankyFrames = " + std::to_string(1);
1237 EXPECT_THAT(result, HasSubstr(expectedResult));
1238
1239 std::string expectedMissing = "uid = " + std::to_string(UID_0);
1240 EXPECT_THAT(result, Not(HasSubstr(expectedMissing)));
Alec Mouri37384342020-01-02 17:23:37 -08001241}
1242
1243TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleLayers) {
1244 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1245
Alec Mouri37384342020-01-02 17:23:37 -08001246 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1247 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1248 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1249 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1250
Tej Singhe2751772021-04-06 22:05:29 -07001251 std::string pulledData;
1252 EXPECT_TRUE(mTimeStats->onPullAtom(10063 /*SURFACEFLINGER_STATS_LAYER_INFO*/, &pulledData));
Alec Mouri37384342020-01-02 17:23:37 -08001253
Tej Singhe2751772021-04-06 22:05:29 -07001254 android::surfaceflinger::SurfaceflingerStatsLayerInfoWrapper atomList;
1255 ASSERT_TRUE(atomList.ParseFromString(pulledData));
1256 ASSERT_EQ(atomList.atom_size(), 2);
1257 std::vector<std::string> actualLayerNames = {atomList.atom(0).layer_name(),
1258 atomList.atom(1).layer_name()};
1259 EXPECT_THAT(actualLayerNames,
1260 UnorderedElementsAre(genLayerName(LAYER_ID_0), genLayerName(LAYER_ID_1)));
Alec Mouri37384342020-01-02 17:23:37 -08001261}
1262
1263TEST_F(TimeStatsTest, layerStatsCallback_pullsMultipleBuckets) {
1264 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1265
Alec Mouri37384342020-01-02 17:23:37 -08001266 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1267 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1268 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1269 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1270
Tej Singh38a4b212020-03-13 19:04:51 -07001271 // Now make sure that TimeStats flushes global stats to set the callback.
Peiyong Lin65248e02020-04-18 21:15:07 -07001272 mTimeStats->setPowerMode(PowerMode::ON);
Alec Mouri37384342020-01-02 17:23:37 -08001273 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
1274 mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));
Alec Mouri37384342020-01-02 17:23:37 -08001275
Tej Singhe2751772021-04-06 22:05:29 -07001276 std::string pulledData;
1277 EXPECT_TRUE(mTimeStats->onPullAtom(10063 /*SURFACEFLINGER_STATS_LAYER_INFO*/, &pulledData));
1278
1279 android::surfaceflinger::SurfaceflingerStatsLayerInfoWrapper atomList;
1280 ASSERT_TRUE(atomList.ParseFromString(pulledData));
1281 ASSERT_EQ(atomList.atom_size(), 1);
1282 const android::surfaceflinger::SurfaceflingerStatsLayerInfo& atom = atomList.atom(0);
1283 EXPECT_THAT(atom.present_to_present(), HistogramEq(buildExpectedHistogram({1, 2}, {2, 1})));
Alec Mouri37384342020-01-02 17:23:37 -08001284}
1285
1286TEST_F(TimeStatsTest, layerStatsCallback_limitsHistogramBuckets) {
Tej Singhe2751772021-04-06 22:05:29 -07001287 mTimeStats = std::make_unique<impl::TimeStats>(std::nullopt, 1);
Alec Mouri37384342020-01-02 17:23:37 -08001288 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1289
Alec Mouri37384342020-01-02 17:23:37 -08001290 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1291 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1292 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 3, 4000000);
1293 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 4, 5000000);
1294
Tej Singhe2751772021-04-06 22:05:29 -07001295 std::string pulledData;
1296 EXPECT_TRUE(mTimeStats->onPullAtom(10063 /*SURFACEFLINGER_STATS_LAYER_INFO*/, &pulledData));
Alec Mouri37384342020-01-02 17:23:37 -08001297
Tej Singhe2751772021-04-06 22:05:29 -07001298 android::surfaceflinger::SurfaceflingerStatsLayerInfoWrapper atomList;
1299 ASSERT_TRUE(atomList.ParseFromString(pulledData));
1300 ASSERT_EQ(atomList.atom_size(), 1);
1301 const android::surfaceflinger::SurfaceflingerStatsLayerInfo& atom = atomList.atom(0);
1302 EXPECT_THAT(atom.present_to_present(), HistogramEq(buildExpectedHistogram({1}, {2})));
Alec Mouri37384342020-01-02 17:23:37 -08001303}
1304
1305TEST_F(TimeStatsTest, layerStatsCallback_limitsLayers) {
Tej Singhe2751772021-04-06 22:05:29 -07001306 mTimeStats = std::make_unique<impl::TimeStats>(1, std::nullopt);
Alec Mouri37384342020-01-02 17:23:37 -08001307 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1308
Alec Mouri37384342020-01-02 17:23:37 -08001309 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 1, 1000000);
1310 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_0, 2, 2000000);
1311 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 1, 2000000);
1312 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 2, 3000000);
1313 insertTimeRecord(NORMAL_SEQUENCE, LAYER_ID_1, 4, 5000000);
1314
Tej Singhe2751772021-04-06 22:05:29 -07001315 std::string pulledData;
1316 EXPECT_TRUE(mTimeStats->onPullAtom(10063 /*SURFACEFLINGER_STATS_LAYER_INFO*/, &pulledData));
Alec Mouri37384342020-01-02 17:23:37 -08001317
Tej Singhe2751772021-04-06 22:05:29 -07001318 android::surfaceflinger::SurfaceflingerStatsLayerInfoWrapper atomList;
1319 ASSERT_TRUE(atomList.ParseFromString(pulledData));
1320 ASSERT_EQ(atomList.atom_size(), 1);
1321 EXPECT_EQ(atomList.atom(0).layer_name(), genLayerName(LAYER_ID_1));
Alec Mouri37384342020-01-02 17:23:37 -08001322}
1323
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001324TEST_F(TimeStatsTest, canSurviveMonkey) {
Lloyd Pique067fe1e2018-12-06 19:44:13 -08001325 if (g_noSlowTests) {
1326 GTEST_SKIP();
1327 }
1328
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001329 EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
1330
1331 for (size_t i = 0; i < 10000000; ++i) {
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001332 const int32_t layerId = genRandomInt32(-1, 10);
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001333 const int32_t frameNumber = genRandomInt32(1, 10);
1334 switch (genRandomInt32(0, 100)) {
1335 case 0:
1336 ALOGV("removeTimeRecord");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001337 ASSERT_NO_FATAL_FAILURE(mTimeStats->removeTimeRecord(layerId, frameNumber));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001338 continue;
1339 case 1:
1340 ALOGV("onDestroy");
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001341 ASSERT_NO_FATAL_FAILURE(mTimeStats->onDestroy(layerId));
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001342 continue;
1343 }
1344 TimeStamp type = static_cast<TimeStamp>(genRandomInt32(TIME_STAMP_BEGIN, TIME_STAMP_END));
1345 const int32_t ts = genRandomInt32(1, 1000000000);
Yiwei Zhang1a88c402019-11-18 10:43:58 -08001346 ALOGV("type[%d], layerId[%d], frameNumber[%d], ts[%d]", type, layerId, frameNumber, ts);
Ady Abraham8b9e6122021-01-26 19:11:45 -08001347 setTimeStamp(type, layerId, frameNumber, ts, {});
Yiwei Zhang16faa5d2018-11-13 18:12:59 -08001348 }
1349}
1350
1351} // namespace
1352} // namespace android
Ady Abrahamb0dbdaa2020-01-06 16:19:42 -08001353
1354// TODO(b/129481165): remove the #pragma below and fix conversion issues
Marin Shalamanovbed7fd32020-12-21 20:02:20 +01001355#pragma clang diagnostic pop // ignored "-Wconversion -Wextra"