1 // Copyright 2018 The Chromium Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4
5 #include "content/browser/scheduler/responsiveness/calculator.h"
6
7 #include "build/build_config.h"
8 #include "content/public/test/browser_task_environment.h"
9 #include "testing/gmock/include/gmock/gmock.h"
10 #include "testing/gtest/include/gtest/gtest.h"
11
12 namespace content {
13 namespace responsiveness {
14
15 using JankType = Calculator::JankType;
16 using ::testing::_;
17
18 namespace {
19 // Copied from calculator.cc.
20 constexpr int kMeasurementIntervalInMs = 30 * 1000;
21 constexpr int kJankThresholdInMs = 100;
22
23 class FakeCalculator : public Calculator {
24 public:
25 MOCK_METHOD2(EmitResponsiveness,
26 void(JankType jank_type, size_t janky_slices));
27
28 using Calculator::GetLastCalculationTime;
29 };
30
31 } // namespace
32
33 class ResponsivenessCalculatorTest : public testing::Test {
34 public:
SetUp()35 void SetUp() override {
36 calculator_ = std::make_unique<testing::StrictMock<FakeCalculator>>();
37 last_calculation_time_ = calculator_->GetLastCalculationTime();
38 #if defined(OS_ANDROID)
39 base::android::ApplicationStatusListener::NotifyApplicationStateChange(
40 base::android::APPLICATION_STATE_HAS_RUNNING_ACTIVITIES);
41 base::RunLoop().RunUntilIdle();
42 #endif
43 }
44
AddEventUI(int queue_time_in_ms,int execution_start_time_in_ms,int execution_finish_time_in_ms)45 void AddEventUI(int queue_time_in_ms,
46 int execution_start_time_in_ms,
47 int execution_finish_time_in_ms) {
48 calculator_->TaskOrEventFinishedOnUIThread(
49 last_calculation_time_ +
50 base::TimeDelta::FromMilliseconds(queue_time_in_ms),
51 last_calculation_time_ +
52 base::TimeDelta::FromMilliseconds(execution_start_time_in_ms),
53 last_calculation_time_ +
54 base::TimeDelta::FromMilliseconds(execution_finish_time_in_ms));
55 }
56
AddEventIO(int queue_time_in_ms,int execution_start_time_in_ms,int execution_finish_time_in_ms)57 void AddEventIO(int queue_time_in_ms,
58 int execution_start_time_in_ms,
59 int execution_finish_time_in_ms) {
60 calculator_->TaskOrEventFinishedOnIOThread(
61 last_calculation_time_ +
62 base::TimeDelta::FromMilliseconds(queue_time_in_ms),
63 last_calculation_time_ +
64 base::TimeDelta::FromMilliseconds(execution_start_time_in_ms),
65 last_calculation_time_ +
66 base::TimeDelta::FromMilliseconds(execution_finish_time_in_ms));
67 }
68
TriggerCalculation()69 void TriggerCalculation() {
70 AddEventUI(kMeasurementIntervalInMs + 1, kMeasurementIntervalInMs + 1,
71 kMeasurementIntervalInMs + 1);
72 last_calculation_time_ = calculator_->GetLastCalculationTime();
73 }
74
75 protected:
76 // This member sets up BrowserThread::IO and BrowserThread::UI. It must be the
77 // first member, as other members may depend on these abstractions.
78 content::BrowserTaskEnvironment task_environment_;
79
80 std::unique_ptr<FakeCalculator> calculator_;
81 base::TimeTicks last_calculation_time_;
82 };
83
84 #define EXPECT_EXECUTION_JANKY_SLICES(num_slices) \
85 EXPECT_CALL(*calculator_, \
86 EmitResponsiveness(JankType::kExecution, num_slices));
87 #define EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(num_slices) \
88 EXPECT_CALL(*calculator_, \
89 EmitResponsiveness(JankType::kQueueAndExecution, num_slices));
90
91 // A single event executing slightly longer than kJankThresholdInMs.
TEST_F(ResponsivenessCalculatorTest,ShortExecutionJank)92 TEST_F(ResponsivenessCalculatorTest, ShortExecutionJank) {
93 constexpr int kQueueTime = 35;
94 constexpr int kStartTime = 40;
95 constexpr int kFinishTime = kStartTime + kJankThresholdInMs + 5;
96
97 AddEventUI(kQueueTime, kStartTime, kFinishTime);
98 EXPECT_EXECUTION_JANKY_SLICES(1u);
99 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(1u);
100 TriggerCalculation();
101 }
102
103 // A single event queued slightly longer than kJankThresholdInMs.
TEST_F(ResponsivenessCalculatorTest,ShortQueueJank)104 TEST_F(ResponsivenessCalculatorTest, ShortQueueJank) {
105 constexpr int kQueueTime = 35;
106 constexpr int kStartTime = kQueueTime + kJankThresholdInMs + 5;
107 constexpr int kFinishTime = kStartTime + 5;
108
109 AddEventUI(kQueueTime, kStartTime, kFinishTime);
110 EXPECT_EXECUTION_JANKY_SLICES(0u);
111 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(1u);
112 TriggerCalculation();
113 }
114
115 // A single event whose queuing and execution time together take longer than
116 // kJankThresholdInMs.
TEST_F(ResponsivenessCalculatorTest,ShortCombinedQueueAndExecutionJank)117 TEST_F(ResponsivenessCalculatorTest, ShortCombinedQueueAndExecutionJank) {
118 constexpr int kQueueTime = 35;
119 constexpr int kStartTime = kQueueTime + (kJankThresholdInMs / 2);
120 constexpr int kFinishTime = kStartTime + (kJankThresholdInMs / 2) + 1;
121
122 AddEventUI(kQueueTime, kStartTime, kFinishTime);
123 EXPECT_EXECUTION_JANKY_SLICES(0u);
124 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(1u);
125 TriggerCalculation();
126 }
127
128 // A single event executing slightly longer than 10 * kJankThresholdInMs.
TEST_F(ResponsivenessCalculatorTest,LongExecutionJank)129 TEST_F(ResponsivenessCalculatorTest, LongExecutionJank) {
130 constexpr int kQueueTime = 35;
131 constexpr int kStartTime = 40;
132 constexpr int kFinishTime = kStartTime + 10 * kJankThresholdInMs + 5;
133
134 AddEventUI(kQueueTime, kStartTime, kFinishTime);
135 EXPECT_CALL(*calculator_, EmitResponsiveness(JankType::kExecution, 10U));
136 EXPECT_CALL(*calculator_,
137 EmitResponsiveness(JankType::kQueueAndExecution, 10U));
138 TriggerCalculation();
139 }
140
141 // A single event executing slightly longer than 10 * kJankThresholdInMs.
TEST_F(ResponsivenessCalculatorTest,LongQueueJank)142 TEST_F(ResponsivenessCalculatorTest, LongQueueJank) {
143 constexpr int kQueueTime = 35;
144 constexpr int kStartTime = kQueueTime + 10 * kJankThresholdInMs + 5;
145 constexpr int kFinishTime = kStartTime + 5;
146
147 AddEventUI(kQueueTime, kStartTime, kFinishTime);
148 EXPECT_EXECUTION_JANKY_SLICES(0u);
149 EXPECT_CALL(*calculator_,
150 EmitResponsiveness(JankType::kQueueAndExecution, 10U));
151 TriggerCalculation();
152 }
153
154 // Events that execute in less than 100ms do not jank, regardless of start time.
TEST_F(ResponsivenessCalculatorTest,NoExecutionJank)155 TEST_F(ResponsivenessCalculatorTest, NoExecutionJank) {
156 int base_time = 30;
157 for (int i = 0; i < kJankThresholdInMs; ++i) {
158 AddEventUI(base_time, base_time, base_time + i);
159 }
160
161 base_time += kJankThresholdInMs;
162 for (int i = 0; i < kJankThresholdInMs; ++i) {
163 AddEventUI(base_time + i, base_time + i, base_time + 2 * i);
164 }
165
166 EXPECT_EXECUTION_JANKY_SLICES(0u);
167 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(0u);
168 TriggerCalculation();
169 }
170
171 // Events that are queued and execute in less than 100ms do not jank, regardless
172 // of start time.
TEST_F(ResponsivenessCalculatorTest,NoQueueJank)173 TEST_F(ResponsivenessCalculatorTest, NoQueueJank) {
174 int base_time = 30;
175 for (int i = 0; i < kJankThresholdInMs; ++i) {
176 AddEventUI(base_time, base_time + i, base_time + i);
177 }
178
179 base_time += kJankThresholdInMs;
180 for (int i = 0; i < kJankThresholdInMs; ++i) {
181 AddEventUI(base_time + i, base_time + 2 * i, base_time + 2 * i);
182 }
183
184 EXPECT_EXECUTION_JANKY_SLICES(0u);
185 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(0u);
186 TriggerCalculation();
187 }
188
189 // 10 execution jank events, but very closely overlapping. Time slices are
190 // discretized and fixed, e.g. [0 100] [100 200] [200 300]. In this test, the
191 // events all start in the [0 100] slice and end in the [100 200] slice. All of
192 // them end up marking the [100 200] slice as janky.
TEST_F(ResponsivenessCalculatorTest,OverlappingExecutionJank)193 TEST_F(ResponsivenessCalculatorTest, OverlappingExecutionJank) {
194 int base_time = 30;
195 for (int i = 0; i < 10; ++i) {
196 const int queue_time = base_time;
197 const int start_time = base_time;
198 const int finish_time = start_time + kJankThresholdInMs + i;
199 AddEventUI(queue_time, start_time, finish_time);
200 }
201
202 EXPECT_EXECUTION_JANKY_SLICES(1u);
203 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(1u);
204 TriggerCalculation();
205 }
206
207 // 10 queue jank events, but very closely overlapping. Time slices are
208 // discretized and fixed, e.g. [0 100] [100 200] [200 300]. In this test, the
209 // events are all queued in the [0 100] slice and start executing in the [100
210 // 200] slice. All of them end up marking the [100 200] slice as janky.
TEST_F(ResponsivenessCalculatorTest,OverlappingQueueJank)211 TEST_F(ResponsivenessCalculatorTest, OverlappingQueueJank) {
212 int base_time = 30;
213 for (int i = 0; i < 10; ++i) {
214 const int queue_time = base_time;
215 const int start_time = base_time + kJankThresholdInMs + i;
216 const int finish_time = start_time + 1;
217 AddEventUI(queue_time, start_time, finish_time);
218 }
219
220 EXPECT_EXECUTION_JANKY_SLICES(0u);
221 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(1u);
222 TriggerCalculation();
223 }
224
225 // UI thread has 3 execution jank events on slices 1, 2, 3
226 // IO thread has 3 execution jank events on slices 3, 4, 5,
227 // There should be a total of 5 jank events.
TEST_F(ResponsivenessCalculatorTest,OverlappingExecutionJankMultipleThreads)228 TEST_F(ResponsivenessCalculatorTest, OverlappingExecutionJankMultipleThreads) {
229 int base_time = 105;
230 for (int i = 0; i < 3; ++i) {
231 const int queue_time = base_time + i * kJankThresholdInMs;
232 const int start_time = queue_time;
233 const int finish_time = start_time + kJankThresholdInMs + 10;
234 AddEventUI(queue_time, start_time, finish_time);
235 }
236
237 base_time = 305;
238 for (int i = 0; i < 3; ++i) {
239 const int queue_time = base_time + i * kJankThresholdInMs;
240 const int start_time = queue_time;
241 const int finish_time = start_time + kJankThresholdInMs + 10;
242 AddEventIO(queue_time, start_time, finish_time);
243 }
244
245 EXPECT_EXECUTION_JANKY_SLICES(5u);
246 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(5u);
247 TriggerCalculation();
248 }
249
250 // UI thread has 3 queue jank events on slices 1, 2, 3
251 // IO thread has 3 queue jank events on slices 3, 4, 5,
252 // There should be a total of 5 jank events.
TEST_F(ResponsivenessCalculatorTest,OverlappingQueueJankMultipleThreads)253 TEST_F(ResponsivenessCalculatorTest, OverlappingQueueJankMultipleThreads) {
254 int base_time = 105;
255 for (int i = 0; i < 3; ++i) {
256 const int queue_time = base_time + i * kJankThresholdInMs;
257 const int start_time = queue_time + kJankThresholdInMs + 10;
258 const int finish_time = start_time;
259 AddEventUI(queue_time, start_time, finish_time);
260 }
261
262 base_time = 305;
263 for (int i = 0; i < 3; ++i) {
264 const int queue_time = base_time + i * kJankThresholdInMs;
265 const int start_time = queue_time + kJankThresholdInMs + 10;
266 const int finish_time = start_time;
267 AddEventIO(queue_time, start_time, finish_time);
268 }
269
270 EXPECT_EXECUTION_JANKY_SLICES(0u);
271 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(5u);
272 TriggerCalculation();
273 }
274
275 // Three execution janks, each of length 2, separated by some shorter events.
TEST_F(ResponsivenessCalculatorTest,SeparatedExecutionJanks)276 TEST_F(ResponsivenessCalculatorTest, SeparatedExecutionJanks) {
277 int base_time = 105;
278
279 for (int i = 0; i < 3; ++i) {
280 {
281 const int queue_time = base_time;
282 const int start_time = base_time;
283 const int finish_time = base_time + 1;
284 AddEventUI(queue_time, start_time, finish_time);
285 }
286 {
287 const int queue_time = base_time;
288 const int start_time = base_time;
289 const int finish_time = base_time + 2 * kJankThresholdInMs + 1;
290 AddEventUI(queue_time, start_time, finish_time);
291 }
292 base_time += 10 * kJankThresholdInMs;
293 }
294
295 EXPECT_EXECUTION_JANKY_SLICES(6u);
296 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(6u);
297 TriggerCalculation();
298 }
299
300 // Three queue janks, each of length 2, separated by some shorter events.
TEST_F(ResponsivenessCalculatorTest,SeparatedQueueJanks)301 TEST_F(ResponsivenessCalculatorTest, SeparatedQueueJanks) {
302 int base_time = 105;
303
304 for (int i = 0; i < 3; ++i) {
305 {
306 const int queue_time = base_time;
307 const int start_time = base_time + 1;
308 const int finish_time = start_time;
309 AddEventUI(queue_time, start_time, finish_time);
310 }
311 {
312 const int queue_time = base_time;
313 const int start_time = base_time + 2 * kJankThresholdInMs + 1;
314 const int finish_time = start_time;
315 AddEventUI(queue_time, start_time, finish_time);
316 }
317 base_time += 10 * kJankThresholdInMs;
318 }
319
320 EXPECT_EXECUTION_JANKY_SLICES(0u);
321 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(6u);
322 TriggerCalculation();
323 }
324
TEST_F(ResponsivenessCalculatorTest,MultipleTrigger)325 TEST_F(ResponsivenessCalculatorTest, MultipleTrigger) {
326 int base_time = 105;
327
328 // 3 Janks, then trigger, then repeat.
329 for (int i = 0; i < 10; ++i) {
330 for (int j = 0; j < 3; ++j) {
331 AddEventUI(base_time, base_time, base_time + 3 * kJankThresholdInMs + 1);
332 base_time += 3 * kJankThresholdInMs;
333 }
334
335 EXPECT_EXECUTION_JANKY_SLICES(9u);
336 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(9u);
337 TriggerCalculation();
338 testing::Mock::VerifyAndClear(calculator_.get());
339 }
340 }
341
342 // A long delay means that the machine likely went to sleep.
TEST_F(ResponsivenessCalculatorTest,LongDelay)343 TEST_F(ResponsivenessCalculatorTest, LongDelay) {
344 int base_time = 105;
345 AddEventUI(base_time, base_time, base_time + 3 * kJankThresholdInMs + 1);
346 base_time += 10 * kMeasurementIntervalInMs;
347 AddEventUI(base_time, base_time, base_time + 1);
348
349 EXPECT_CALL(*calculator_, EmitResponsiveness(_, _)).Times(0);
350 }
351
352 // A long event means that the machine likely went to sleep.
TEST_F(ResponsivenessCalculatorTest,LongEvent)353 TEST_F(ResponsivenessCalculatorTest, LongEvent) {
354 int base_time = 105;
355 AddEventUI(base_time, base_time, base_time + 10 * kMeasurementIntervalInMs);
356
357 EXPECT_CALL(*calculator_, EmitResponsiveness(_, _)).Times(0);
358 }
359
360 #if defined(OS_ANDROID)
361 // Metric should not be recorded when application is in background.
TEST_F(ResponsivenessCalculatorTest,ApplicationInBackground)362 TEST_F(ResponsivenessCalculatorTest, ApplicationInBackground) {
363 constexpr int kQueueTime = 35;
364 constexpr int kStartTime = 40;
365 constexpr int kFinishTime = kStartTime + kJankThresholdInMs + 5;
366 AddEventUI(kQueueTime, kStartTime, kFinishTime);
367
368 base::android::ApplicationStatusListener::NotifyApplicationStateChange(
369 base::android::APPLICATION_STATE_HAS_STOPPED_ACTIVITIES);
370 base::RunLoop().RunUntilIdle();
371
372 AddEventUI(kQueueTime, kStartTime + 1, kFinishTime + 1);
373
374 EXPECT_CALL(*calculator_, EmitResponsiveness(_, _)).Times(0);
375 TriggerCalculation();
376 }
377 #endif
378
379 // An event execution that crosses a measurement interval boundary should count
380 // towards both measurement intervals.
TEST_F(ResponsivenessCalculatorTest,ExecutionCrossesBoundary)381 TEST_F(ResponsivenessCalculatorTest, ExecutionCrossesBoundary) {
382 // Dummy event so that Calculator doesn't think the process is suspended.
383 {
384 const int kTime = 0.5 * kMeasurementIntervalInMs;
385 AddEventUI(kTime, kTime, kTime);
386 }
387
388 // The event goes from [29801, 30150]. It should count as 1 jank in the first
389 // measurement interval and 2 in the second.
390 {
391 EXPECT_EXECUTION_JANKY_SLICES(1u);
392 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(1u);
393 const int queue_time =
394 kMeasurementIntervalInMs - 2 * kJankThresholdInMs + 1;
395 const int start_time = queue_time;
396 const int finish_time = kMeasurementIntervalInMs + 1.5 * kJankThresholdInMs;
397 AddEventUI(queue_time, start_time, finish_time);
398 }
399
400 // Dummy event so that Calculator doesn't think the process is suspended.
401 {
402 const int kTime = 1.5 * kMeasurementIntervalInMs;
403 AddEventUI(kTime, kTime, kTime);
404 }
405
406 // Trigger another calculation.
407 EXPECT_EXECUTION_JANKY_SLICES(2u);
408 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(2u);
409
410 const int kTime = 2 * kMeasurementIntervalInMs + 1;
411 AddEventUI(kTime, kTime, kTime);
412 }
413
414 // An event queuing that crosses a measurement interval boundary should count
415 // towards both measurement intervals.
TEST_F(ResponsivenessCalculatorTest,QueuingCrossesBoundary)416 TEST_F(ResponsivenessCalculatorTest, QueuingCrossesBoundary) {
417 // Dummy event so that Calculator doesn't think the process is suspended.
418 {
419 const int kTime = 0.5 * kMeasurementIntervalInMs;
420 AddEventUI(kTime, kTime, kTime);
421 }
422
423 // The event goes from [29801, 30150]. It should count as 1 jank in the first
424 // measurement interval and 2 in the second.
425 {
426 EXPECT_EXECUTION_JANKY_SLICES(0u);
427 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(1u);
428 const int queue_time =
429 kMeasurementIntervalInMs - 2 * kJankThresholdInMs + 1;
430 const int start_time = kMeasurementIntervalInMs + 1.5 * kJankThresholdInMs;
431 const int finish_time = start_time;
432 AddEventUI(queue_time, start_time, finish_time);
433 }
434
435 // Dummy event so that Calculator doesn't think the process is suspended.
436 {
437 const int kTime = 1.5 * kMeasurementIntervalInMs;
438 AddEventUI(kTime, kTime, kTime);
439 }
440
441 // Trigger another calculation.
442 EXPECT_EXECUTION_JANKY_SLICES(0u);
443 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(2u);
444
445 const int kTime = 2 * kMeasurementIntervalInMs + 1;
446 AddEventUI(kTime, kTime, kTime);
447 }
448
449 // Events may not be ordered by start or end time.
TEST_F(ResponsivenessCalculatorTest,UnorderedEvents)450 TEST_F(ResponsivenessCalculatorTest, UnorderedEvents) {
451 // We add the following tasks:
452 // [100, 100, 250]
453 // [150, 150, 300]
454 // [50, 50, 200]
455 // [50, 50, 390] <- A
456 //
457 // [1100, 1250, 1251]
458 // [1150, 1300, 1301]
459 // [1050, 1200, 1201]
460 // [1050, 1390, 1391] <- B
461 //
462 // The execution jank in A subsumes all other execution janks. The queue jank
463 // in B subsumes all other queue janks.
464 AddEventUI(100, 100, 250);
465 AddEventUI(150, 150, 300);
466 AddEventUI(50, 50, 200);
467 AddEventUI(50, 50, 390);
468
469 AddEventUI(1100, 1250, 1251);
470 AddEventUI(1150, 1300, 1301);
471 AddEventUI(1050, 1200, 1201);
472 AddEventUI(1050, 1390, 1391);
473
474 EXPECT_EXECUTION_JANKY_SLICES(3u);
475 EXPECT_QUEUE_AND_EXECUTION_JANKY_SLICES(6u);
476 TriggerCalculation();
477 }
478
479 } // namespace responsiveness
480 } // namespace content
481