xref: /aosp_15_r20/external/cronet/base/threading/scoped_blocking_call_unittest.cc (revision 6777b5387eb2ff775bb5750e3f5d96f37fb7352b)
1 // Copyright 2017 The Chromium Authors
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 "base/threading/scoped_blocking_call.h"
6 
7 #include <memory>
8 #include <optional>
9 #include <utility>
10 #include <vector>
11 
12 #include "base/barrier_closure.h"
13 #include "base/functional/bind.h"
14 #include "base/functional/callback.h"
15 #include "base/task/thread_pool.h"
16 #include "base/task/thread_pool/environment_config.h"
17 #include "base/task/thread_pool/thread_pool_impl.h"
18 #include "base/test/bind.h"
19 #include "base/test/gtest_util.h"
20 #include "base/test/task_environment.h"
21 #include "base/test/test_waitable_event.h"
22 #include "base/threading/scoped_blocking_call_internal.h"
23 #include "base/threading/thread_restrictions.h"
24 #include "base/time/time_override.h"
25 #include "build/build_config.h"
26 #include "testing/gmock/include/gmock/gmock.h"
27 #include "testing/gtest/include/gtest/gtest.h"
28 
29 using testing::ElementsAre;
30 
31 namespace base {
32 
33 namespace {
34 
35 class MockBlockingObserver : public internal::BlockingObserver {
36  public:
37   MockBlockingObserver() = default;
38 
39   MockBlockingObserver(const MockBlockingObserver&) = delete;
40   MockBlockingObserver& operator=(const MockBlockingObserver&) = delete;
41 
42   MOCK_METHOD1(BlockingStarted, void(BlockingType));
43   MOCK_METHOD0(BlockingTypeUpgraded, void());
44   MOCK_METHOD0(BlockingEnded, void());
45 };
46 
47 class ScopedBlockingCallTest : public testing::Test {
48  public:
49   ScopedBlockingCallTest(const ScopedBlockingCallTest&) = delete;
50   ScopedBlockingCallTest& operator=(const ScopedBlockingCallTest&) = delete;
51 
52  protected:
ScopedBlockingCallTest()53   ScopedBlockingCallTest() {
54     internal::SetBlockingObserverForCurrentThread(&observer_);
55   }
56 
~ScopedBlockingCallTest()57   ~ScopedBlockingCallTest() override {
58     internal::ClearBlockingObserverForCurrentThread();
59   }
60 
61   testing::StrictMock<MockBlockingObserver> observer_;
62 };
63 
64 }  // namespace
65 
TEST_F(ScopedBlockingCallTest,MayBlock)66 TEST_F(ScopedBlockingCallTest, MayBlock) {
67   EXPECT_CALL(observer_, BlockingStarted(BlockingType::MAY_BLOCK));
68   ScopedBlockingCall scoped_blocking_call(FROM_HERE, BlockingType::MAY_BLOCK);
69   testing::Mock::VerifyAndClear(&observer_);
70   EXPECT_CALL(observer_, BlockingEnded());
71 }
72 
TEST_F(ScopedBlockingCallTest,WillBlock)73 TEST_F(ScopedBlockingCallTest, WillBlock) {
74   EXPECT_CALL(observer_, BlockingStarted(BlockingType::WILL_BLOCK));
75   ScopedBlockingCall scoped_blocking_call(FROM_HERE, BlockingType::WILL_BLOCK);
76   testing::Mock::VerifyAndClear(&observer_);
77   EXPECT_CALL(observer_, BlockingEnded());
78 }
79 
TEST_F(ScopedBlockingCallTest,MayBlockWillBlock)80 TEST_F(ScopedBlockingCallTest, MayBlockWillBlock) {
81   EXPECT_CALL(observer_, BlockingStarted(BlockingType::MAY_BLOCK));
82   ScopedBlockingCall scoped_blocking_call_a(FROM_HERE, BlockingType::MAY_BLOCK);
83   testing::Mock::VerifyAndClear(&observer_);
84 
85   {
86     EXPECT_CALL(observer_, BlockingTypeUpgraded());
87     ScopedBlockingCall scoped_blocking_call_b(FROM_HERE,
88                                               BlockingType::WILL_BLOCK);
89     testing::Mock::VerifyAndClear(&observer_);
90   }
91 
92   EXPECT_CALL(observer_, BlockingEnded());
93 }
94 
TEST_F(ScopedBlockingCallTest,WillBlockMayBlock)95 TEST_F(ScopedBlockingCallTest, WillBlockMayBlock) {
96   EXPECT_CALL(observer_, BlockingStarted(BlockingType::WILL_BLOCK));
97   ScopedBlockingCall scoped_blocking_call_a(FROM_HERE,
98                                             BlockingType::WILL_BLOCK);
99   testing::Mock::VerifyAndClear(&observer_);
100 
101   {
102     ScopedBlockingCall scoped_blocking_call_b(FROM_HERE,
103                                               BlockingType::MAY_BLOCK);
104   }
105 
106   EXPECT_CALL(observer_, BlockingEnded());
107 }
108 
TEST_F(ScopedBlockingCallTest,MayBlockMayBlock)109 TEST_F(ScopedBlockingCallTest, MayBlockMayBlock) {
110   EXPECT_CALL(observer_, BlockingStarted(BlockingType::MAY_BLOCK));
111   ScopedBlockingCall scoped_blocking_call_a(FROM_HERE, BlockingType::MAY_BLOCK);
112   testing::Mock::VerifyAndClear(&observer_);
113 
114   {
115     ScopedBlockingCall scoped_blocking_call_b(FROM_HERE,
116                                               BlockingType::MAY_BLOCK);
117   }
118 
119   EXPECT_CALL(observer_, BlockingEnded());
120 }
121 
TEST_F(ScopedBlockingCallTest,WillBlockWillBlock)122 TEST_F(ScopedBlockingCallTest, WillBlockWillBlock) {
123   EXPECT_CALL(observer_, BlockingStarted(BlockingType::WILL_BLOCK));
124   ScopedBlockingCall scoped_blocking_call_a(FROM_HERE,
125                                             BlockingType::WILL_BLOCK);
126   testing::Mock::VerifyAndClear(&observer_);
127 
128   {
129     ScopedBlockingCall scoped_blocking_call_b(FROM_HERE,
130                                               BlockingType::WILL_BLOCK);
131   }
132 
133   EXPECT_CALL(observer_, BlockingEnded());
134 }
135 
TEST_F(ScopedBlockingCallTest,MayBlockWillBlockTwice)136 TEST_F(ScopedBlockingCallTest, MayBlockWillBlockTwice) {
137   EXPECT_CALL(observer_, BlockingStarted(BlockingType::MAY_BLOCK));
138   ScopedBlockingCall scoped_blocking_call_a(FROM_HERE, BlockingType::MAY_BLOCK);
139   testing::Mock::VerifyAndClear(&observer_);
140 
141   {
142     EXPECT_CALL(observer_, BlockingTypeUpgraded());
143     ScopedBlockingCall scoped_blocking_call_b(FROM_HERE,
144                                               BlockingType::WILL_BLOCK);
145     testing::Mock::VerifyAndClear(&observer_);
146 
147     {
148       ScopedBlockingCall scoped_blocking_call_c(FROM_HERE,
149                                                 BlockingType::MAY_BLOCK);
150       ScopedBlockingCall scoped_blocking_call_d(FROM_HERE,
151                                                 BlockingType::WILL_BLOCK);
152     }
153   }
154 
155   EXPECT_CALL(observer_, BlockingEnded());
156 }
157 
TEST(ScopedBlockingCallDestructionOrderTest,InvalidDestructionOrder)158 TEST(ScopedBlockingCallDestructionOrderTest, InvalidDestructionOrder) {
159   auto scoped_blocking_call_a =
160       std::make_unique<ScopedBlockingCall>(FROM_HERE, BlockingType::WILL_BLOCK);
161   auto scoped_blocking_call_b =
162       std::make_unique<ScopedBlockingCall>(FROM_HERE, BlockingType::WILL_BLOCK);
163 
164   EXPECT_DCHECK_DEATH({ scoped_blocking_call_a.reset(); });
165 }
166 
167 namespace {
168 
169 class ScopedBlockingCallIOJankMonitoringTest : public testing::Test {
170  public:
ScopedBlockingCallIOJankMonitoringTest(test::TaskEnvironment::TimeSource time_source=test::TaskEnvironment::TimeSource::MOCK_TIME)171   explicit ScopedBlockingCallIOJankMonitoringTest(
172       test::TaskEnvironment::TimeSource time_source =
173           test::TaskEnvironment::TimeSource::MOCK_TIME)
174       : task_environment_(std::in_place, time_source) {}
175 
SetUp()176   void SetUp() override {
177     // Note 1: While EnableIOJankMonitoringForProcess() is documented as being
178     // only callable once per process. The call to CancelMonitoringForTesting()
179     // in TearDown() makes it okay to call this in multiple tests in a row
180     // within a single process.
181     // Note 2: No need to check TimeTicks::IsConsistentAcrossProcesses() in
182     // spite of EnableIOJankMonitoringForProcess()'s requirement as
183     // TimeSource::MOCK_TIME avoids usage of the system clock and avoids the
184     // issue.
185     // OnlyObservedThreadsForTest(true) to prevent flakes which are believed to
186     // be caused by ScopedBlockingCall interference in the same process but
187     // outside this test's managed threads: crbug.com/1071166.
188     EnableIOJankMonitoringForProcess(
189         BindLambdaForTesting([&](int janky_intervals_per_minute,
190                                  int total_janks_per_minute) {
191           reports_.emplace_back(
192               janky_intervals_per_minute, total_janks_per_minute);
193         }),
194         OnlyObservedThreadsForTest(true));
195 
196     internal::SetBlockingObserverForCurrentThread(&main_thread_observer);
197   }
198 
StopMonitoring()199   void StopMonitoring() {
200     // Reclaim worker threads before CancelMonitoringForTesting() to avoid a
201     // data race (crbug.com/1071166#c16).
202     task_environment_.reset();
203     internal::IOJankMonitoringWindow::CancelMonitoringForTesting();
204     internal::ClearBlockingObserverForCurrentThread();
205   }
206 
TearDown()207   void TearDown() override {
208     if (task_environment_)
209       StopMonitoring();
210   }
211 
212  protected:
213   // A member initialized before |task_environment_| that forces worker threads
214   // to be started synchronously. This avoids a tricky race where Linux invokes
215   // SetCurrentThreadType() from early main, before invoking ThreadMain and
216   // yielding control to the thread pool impl. That causes a ScopedBlockingCall
217   // in platform_thread_linux.cc:SetThreadCgroupForThreadType and interferes
218   // with this test. This solution is quite intrusive but is the simplest we can
219   // do for this unique corner case.
220   struct SetSynchronousThreadStart {
SetSynchronousThreadStartbase::__anonf99ff7a40211::ScopedBlockingCallIOJankMonitoringTest::SetSynchronousThreadStart221     SetSynchronousThreadStart() {
222       internal::ThreadPoolImpl::SetSynchronousThreadStartForTesting(true);
223     }
~SetSynchronousThreadStartbase::__anonf99ff7a40211::ScopedBlockingCallIOJankMonitoringTest::SetSynchronousThreadStart224     ~SetSynchronousThreadStart() {
225       internal::ThreadPoolImpl::SetSynchronousThreadStartForTesting(false);
226     }
227   } set_synchronous_thread_start_;
228 
229   // The registered lambda above may report to this from any thread. It is
230   // nonetheless safe to read this from the test body as
231   // TaskEnvironment+MOCK_TIME advances the test in lock steps.
232   std::vector<std::pair<int, int>> reports_;
233 
234   std::optional<test::TaskEnvironment> task_environment_;
235 
236   // The main thread needs to register a BlockingObserver per
237   // OnlyObservedThreadsForTest(true) but doesn't otherwise care about
238   // observing.
239   testing::NiceMock<MockBlockingObserver> main_thread_observer;
240 };
241 
242 }  // namespace
243 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,Basic)244 TEST_F(ScopedBlockingCallIOJankMonitoringTest, Basic) {
245   constexpr auto kJankTiming =
246       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
247   {
248     ScopedBlockingCall blocked_for_7s(FROM_HERE, BlockingType::MAY_BLOCK);
249     task_environment_->FastForwardBy(kJankTiming);
250   }
251 
252   // No janks reported before the monitoring window completes.
253   EXPECT_THAT(reports_, ElementsAre());
254 
255   // Advance precisely to the end of this window.
256   task_environment_->FastForwardBy(
257       internal::IOJankMonitoringWindow::kMonitoringWindow - kJankTiming);
258 
259   EXPECT_THAT(reports_, ElementsAre(std::make_pair(7, 7)));
260 }
261 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,NestedDoesntMatter)262 TEST_F(ScopedBlockingCallIOJankMonitoringTest, NestedDoesntMatter) {
263   constexpr auto kJankTiming =
264       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
265   {
266     ScopedBlockingCall blocked_for_7s(FROM_HERE, BlockingType::MAY_BLOCK);
267     ScopedBlockingCall nested(FROM_HERE, BlockingType::MAY_BLOCK);
268     task_environment_->FastForwardBy(kJankTiming);
269   }
270 
271   // No janks reported before the monitoring window completes.
272   EXPECT_THAT(reports_, ElementsAre());
273 
274   // Jump to the next window.
275   task_environment_->FastForwardBy(
276       internal::IOJankMonitoringWindow::kMonitoringWindow);
277 
278   EXPECT_THAT(reports_, ElementsAre(std::make_pair(7, 7)));
279 }
280 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,ManyInAWindow)281 TEST_F(ScopedBlockingCallIOJankMonitoringTest, ManyInAWindow) {
282   constexpr auto kJankTiming =
283       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
284   constexpr auto kIdleTiming = Seconds(3);
285 
286   for (int i = 0; i < 3; ++i) {
287     {
288       ScopedBlockingCall blocked_for_7s(FROM_HERE, BlockingType::MAY_BLOCK);
289       task_environment_->FastForwardBy(kJankTiming);
290     }
291     task_environment_->FastForwardBy(kIdleTiming);
292   }
293 
294   // No janks reported before the monitoring window completes.
295   EXPECT_THAT(reports_, ElementsAre());
296 
297   // Complete the current window.
298   task_environment_->FastForwardBy(
299       internal::IOJankMonitoringWindow::kMonitoringWindow -
300       (kJankTiming + kIdleTiming) * 3);
301 
302   EXPECT_THAT(reports_, ElementsAre(std::make_pair(7 * 3, 7 * 3)));
303 }
304 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,OverlappingMultipleWindows)305 TEST_F(ScopedBlockingCallIOJankMonitoringTest, OverlappingMultipleWindows) {
306   constexpr auto kJankTiming =
307       internal::IOJankMonitoringWindow::kMonitoringWindow * 3 +
308       internal::IOJankMonitoringWindow::kIOJankInterval * 5;
309 
310   {
311     ScopedBlockingCall blocked_for_3windows(FROM_HERE, BlockingType::MAY_BLOCK);
312     task_environment_->FastForwardBy(kJankTiming);
313   }
314 
315   // Fast-forward by another window with no active blocking calls.
316   task_environment_->FastForwardBy(
317       internal::IOJankMonitoringWindow::kMonitoringWindow);
318 
319   // 3 windows janky for their full breadth and 1 window janky for 5 seconds.
320   EXPECT_THAT(reports_,
321               ElementsAre(std::make_pair(60, 60), std::make_pair(60, 60),
322                           std::make_pair(60, 60), std::make_pair(5, 5)));
323 }
324 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,InstantUnblockReportsZero)325 TEST_F(ScopedBlockingCallIOJankMonitoringTest, InstantUnblockReportsZero) {
326   { ScopedBlockingCall instant_unblock(FROM_HERE, BlockingType::MAY_BLOCK); }
327 
328   // No janks reported before the monitoring window completes.
329   EXPECT_THAT(reports_, ElementsAre());
330 
331   task_environment_->FastForwardBy(
332       internal::IOJankMonitoringWindow::kMonitoringWindow);
333 
334   EXPECT_THAT(reports_, ElementsAre(std::make_pair(0, 0)));
335 
336   // No blocking call in next window also reports zero.
337   task_environment_->FastForwardBy(
338       internal::IOJankMonitoringWindow::kMonitoringWindow);
339   EXPECT_THAT(reports_,
340               ElementsAre(std::make_pair(0, 0), std::make_pair(0, 0)));
341 }
342 
343 // Start the jank mid-interval; that interval should be counted but the last
344 // incomplete interval won't count.
TEST_F(ScopedBlockingCallIOJankMonitoringTest,Jank7sMidInterval)345 TEST_F(ScopedBlockingCallIOJankMonitoringTest, Jank7sMidInterval) {
346   task_environment_->FastForwardBy(
347       internal::IOJankMonitoringWindow::kIOJankInterval / 3);
348 
349   constexpr auto kJankTiming =
350       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
351   {
352     ScopedBlockingCall blocked_for_7s(FROM_HERE, BlockingType::MAY_BLOCK);
353     task_environment_->FastForwardBy(kJankTiming);
354   }
355 
356   // No janks reported before the monitoring window completes.
357   EXPECT_THAT(reports_, ElementsAre());
358 
359   task_environment_->FastForwardBy(
360       internal::IOJankMonitoringWindow::kMonitoringWindow);
361 
362   EXPECT_THAT(reports_, ElementsAre(std::make_pair(7, 7)));
363 }
364 
365 // Start the jank mid-interval; that interval should be counted but the second
366 // one won't count.
TEST_F(ScopedBlockingCallIOJankMonitoringTest,Jank1sMidInterval)367 TEST_F(ScopedBlockingCallIOJankMonitoringTest, Jank1sMidInterval) {
368   task_environment_->FastForwardBy(
369       internal::IOJankMonitoringWindow::kIOJankInterval / 3);
370 
371   constexpr auto kJankTiming =
372       internal::IOJankMonitoringWindow::kIOJankInterval;
373   {
374     ScopedBlockingCall blocked_for_1s(FROM_HERE, BlockingType::MAY_BLOCK);
375     task_environment_->FastForwardBy(kJankTiming);
376   }
377 
378   // No janks reported before the monitoring window completes.
379   EXPECT_THAT(reports_, ElementsAre());
380 
381   task_environment_->FastForwardBy(
382       internal::IOJankMonitoringWindow::kMonitoringWindow);
383 
384   EXPECT_THAT(reports_, ElementsAre(std::make_pair(1, 1)));
385 }
386 
387 // Jank that lasts for 1.3 intervals should be rounded down to 1.
TEST_F(ScopedBlockingCallIOJankMonitoringTest,JankRoundDown)388 TEST_F(ScopedBlockingCallIOJankMonitoringTest, JankRoundDown) {
389   task_environment_->FastForwardBy(
390       internal::IOJankMonitoringWindow::kIOJankInterval * 0.9);
391 
392   constexpr auto kJankTiming =
393       internal::IOJankMonitoringWindow::kIOJankInterval * 1.3;
394   {
395     ScopedBlockingCall blocked_for_1s(FROM_HERE, BlockingType::MAY_BLOCK);
396     task_environment_->FastForwardBy(kJankTiming);
397   }
398 
399   // No janks reported before the monitoring window completes.
400   EXPECT_THAT(reports_, ElementsAre());
401 
402   task_environment_->FastForwardBy(
403       internal::IOJankMonitoringWindow::kMonitoringWindow);
404 
405   EXPECT_THAT(reports_, ElementsAre(std::make_pair(1, 1)));
406 }
407 
408 // Jank that lasts for 1.7 intervals should be rounded up to 2.
TEST_F(ScopedBlockingCallIOJankMonitoringTest,JankRoundUp)409 TEST_F(ScopedBlockingCallIOJankMonitoringTest, JankRoundUp) {
410   task_environment_->FastForwardBy(
411       internal::IOJankMonitoringWindow::kIOJankInterval * 0.5);
412 
413   constexpr auto kJankTiming =
414       internal::IOJankMonitoringWindow::kIOJankInterval * 1.7;
415   {
416     ScopedBlockingCall blocked_for_1s(FROM_HERE, BlockingType::MAY_BLOCK);
417     task_environment_->FastForwardBy(kJankTiming);
418   }
419 
420   // No janks reported before the monitoring window completes.
421   EXPECT_THAT(reports_, ElementsAre());
422 
423   task_environment_->FastForwardBy(
424       internal::IOJankMonitoringWindow::kMonitoringWindow);
425 
426   EXPECT_THAT(reports_, ElementsAre(std::make_pair(2, 2)));
427 }
428 
429 // Start mid-interval and perform an operation that overlaps into the next one
430 // but is under the jank timing.
TEST_F(ScopedBlockingCallIOJankMonitoringTest,NoJankMidInterval)431 TEST_F(ScopedBlockingCallIOJankMonitoringTest, NoJankMidInterval) {
432   task_environment_->FastForwardBy(
433       internal::IOJankMonitoringWindow::kIOJankInterval / 3);
434 
435   {
436     ScopedBlockingCall non_janky(FROM_HERE, BlockingType::MAY_BLOCK);
437     task_environment_->FastForwardBy(
438         internal::IOJankMonitoringWindow::kIOJankInterval - Milliseconds(1));
439   }
440 
441   // No janks reported before the monitoring window completes.
442   EXPECT_THAT(reports_, ElementsAre());
443 
444   task_environment_->FastForwardBy(
445       internal::IOJankMonitoringWindow::kMonitoringWindow);
446 
447   EXPECT_THAT(reports_, ElementsAre(std::make_pair(0, 0)));
448 }
449 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,MultiThreaded)450 TEST_F(ScopedBlockingCallIOJankMonitoringTest, MultiThreaded) {
451   constexpr auto kJankTiming =
452       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
453 
454   // Every worker needs to block for precise clock management; hence we can't
455   // test beyond the TaskEnvironment's capacity.
456   const int kNumJankyTasks =
457       test::TaskEnvironment::kNumForegroundThreadPoolThreads;
458 
459   TestWaitableEvent all_threads_blocked;
460   auto on_thread_blocked = BarrierClosure(
461       kNumJankyTasks,
462       BindOnce(&TestWaitableEvent::Signal, Unretained(&all_threads_blocked)));
463 
464   TestWaitableEvent resume_all_threads;
465 
466   for (int i = 0; i < kNumJankyTasks; ++i) {
467     base::ThreadPool::PostTask(
468         FROM_HERE, {MayBlock()}, BindLambdaForTesting([&]() {
469           ScopedBlockingCall blocked_until_signal(FROM_HERE,
470                                                   BlockingType::MAY_BLOCK);
471           on_thread_blocked.Run();
472 
473           ScopedAllowBaseSyncPrimitivesForTesting allow_wait;
474           resume_all_threads.Wait();
475         }));
476   }
477 
478   all_threads_blocked.Wait();
479   task_environment_->AdvanceClock(kJankTiming);
480   resume_all_threads.Signal();
481   task_environment_->RunUntilIdle();
482 
483   // No janks reported before the monitoring window completes.
484   EXPECT_THAT(reports_, ElementsAre());
485 
486   task_environment_->FastForwardBy(
487       internal::IOJankMonitoringWindow::kMonitoringWindow);
488 
489   // Still only 7 janky internals, but more overall janks.
490   EXPECT_THAT(reports_, ElementsAre(std::make_pair(7, 7 * kNumJankyTasks)));
491 }
492 
493 // 3 janks of 3 seconds; overlapping but starting 1 second apart from each
494 // other.
TEST_F(ScopedBlockingCallIOJankMonitoringTest,MultiThreadedOverlapped)495 TEST_F(ScopedBlockingCallIOJankMonitoringTest, MultiThreadedOverlapped) {
496   static const int kNumJankyTasks = 3;
497   static_assert(
498       kNumJankyTasks <= test::TaskEnvironment::kNumForegroundThreadPoolThreads,
499       "");
500 
501   TestWaitableEvent next_task_is_blocked(WaitableEvent::ResetPolicy::AUTOMATIC);
502 
503   TestWaitableEvent resume_thread[kNumJankyTasks] = {};
504   TestWaitableEvent exited_blocking_scope[kNumJankyTasks] = {};
505 
506   auto blocking_task = BindLambdaForTesting([&](int task_index) {
507     {
508       // Simulate jank until |resume_thread[task_index]| is signaled.
509       ScopedBlockingCall blocked_until_signal(FROM_HERE,
510                                               BlockingType::MAY_BLOCK);
511       next_task_is_blocked.Signal();
512 
513       ScopedAllowBaseSyncPrimitivesForTesting allow_wait;
514       resume_thread[task_index].Wait();
515     }
516     exited_blocking_scope[task_index].Signal();
517   });
518 
519   // [0-1]s
520   base::ThreadPool::PostTask(FROM_HERE, {MayBlock()},
521                              BindOnce(blocking_task, 0));
522   next_task_is_blocked.Wait();
523   task_environment_->AdvanceClock(
524       internal::IOJankMonitoringWindow::kIOJankInterval);
525 
526   // [1-2]s
527   base::ThreadPool::PostTask(FROM_HERE, {MayBlock()},
528                              BindOnce(blocking_task, 1));
529   next_task_is_blocked.Wait();
530   task_environment_->AdvanceClock(
531       internal::IOJankMonitoringWindow::kIOJankInterval);
532 
533   // [2-3]s
534   base::ThreadPool::PostTask(FROM_HERE, {MayBlock()},
535                              BindOnce(blocking_task, 2));
536   next_task_is_blocked.Wait();
537   task_environment_->AdvanceClock(
538       internal::IOJankMonitoringWindow::kIOJankInterval);
539 
540   // [3-6]s
541   for (int i = 0; i < kNumJankyTasks; ++i) {
542     resume_thread[i].Signal();
543     exited_blocking_scope[i].Wait();
544     task_environment_->AdvanceClock(
545         internal::IOJankMonitoringWindow::kIOJankInterval);
546   }
547 
548   // No janks reported before the monitoring window completes.
549   EXPECT_THAT(reports_, ElementsAre());
550 
551   task_environment_->FastForwardBy(
552       internal::IOJankMonitoringWindow::kMonitoringWindow);
553 
554   // 9s of total janks spread across 5 intervals.
555   EXPECT_THAT(reports_, ElementsAre(std::make_pair(5, 9)));
556 }
557 
558 // 3 janks of 180 seconds; overlapping but starting 60s apart from each other.
559 // First one starting at 10 seconds (can't start later than that or we'll trip
560 // the kTimeDiscrepancyTimeout per TaskEnvironment's inability to RunUntilIdle()
561 // with pending blocked tasks).
TEST_F(ScopedBlockingCallIOJankMonitoringTest,MultiThreadedOverlappedWindows)562 TEST_F(ScopedBlockingCallIOJankMonitoringTest, MultiThreadedOverlappedWindows) {
563   constexpr int kNumJankyTasks = 3;
564   static_assert(
565       kNumJankyTasks <= test::TaskEnvironment::kNumForegroundThreadPoolThreads,
566       "");
567 
568   TestWaitableEvent next_task_is_blocked(WaitableEvent::ResetPolicy::AUTOMATIC);
569 
570   TestWaitableEvent resume_thread[kNumJankyTasks] = {};
571   TestWaitableEvent exited_blocking_scope[kNumJankyTasks] = {};
572 
573   auto blocking_task = BindLambdaForTesting([&](int task_index) {
574     {
575       // Simulate jank until |resume_thread[task_index]| is signaled.
576       ScopedBlockingCall blocked_until_signal(FROM_HERE,
577                                               BlockingType::MAY_BLOCK);
578       next_task_is_blocked.Signal();
579 
580       ScopedAllowBaseSyncPrimitivesForTesting allow_wait;
581       resume_thread[task_index].Wait();
582     }
583     exited_blocking_scope[task_index].Signal();
584   });
585 
586   // [0-10s] (minus 1 ms to avoid reaching the timeout; this also tests the
587   // logic that intervals are rounded down to the starting interval (e.g.
588   // interval 9/60 in this case)).
589   task_environment_->AdvanceClock(
590       internal::IOJankMonitoringWindow::kTimeDiscrepancyTimeout -
591       Milliseconds(1));
592 
593   // [10-70]s
594   base::ThreadPool::PostTask(FROM_HERE, {MayBlock()},
595                              BindOnce(blocking_task, 0));
596   next_task_is_blocked.Wait();
597   task_environment_->AdvanceClock(
598       internal::IOJankMonitoringWindow::kMonitoringWindow);
599 
600   // [70-130]s
601   base::ThreadPool::PostTask(FROM_HERE, {MayBlock()},
602                              BindOnce(blocking_task, 1));
603   next_task_is_blocked.Wait();
604   task_environment_->AdvanceClock(
605       internal::IOJankMonitoringWindow::kMonitoringWindow);
606 
607   // [130-190]s
608   base::ThreadPool::PostTask(FROM_HERE, {MayBlock()},
609                              BindOnce(blocking_task, 2));
610   next_task_is_blocked.Wait();
611   task_environment_->AdvanceClock(
612       internal::IOJankMonitoringWindow::kMonitoringWindow);
613 
614   // [190-370]s
615   for (int i = 0; i < kNumJankyTasks; ++i) {
616     resume_thread[i].Signal();
617     exited_blocking_scope[i].Wait();
618     task_environment_->AdvanceClock(
619         internal::IOJankMonitoringWindow::kMonitoringWindow);
620   }
621 
622   // Already past the last window (relevant events end at 360s); flush the
623   // pending ripe delayed task that will complete the last window.
624   task_environment_->RunUntilIdle();
625 
626   // 540s(180s*3) of total janks spread across 300 intervals in 6 windows.
627   // Distributed as such (zoomed out to 6 intervals per window):
628   // [011111]
629   //        [122222]
630   //               [233333]
631   //                      [322222]
632   //                             [21111]
633   //                                   [100000]
634   // Starting at the 9th interval per the 10s-1ms offset start.
635   EXPECT_THAT(reports_,
636               ElementsAre(std::make_pair(51, 51), std::make_pair(60, 111),
637                           std::make_pair(60, 171), std::make_pair(60, 129),
638                           std::make_pair(60, 69), std::make_pair(9, 9)));
639 }
640 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,CancellationAcrossSleep)641 TEST_F(ScopedBlockingCallIOJankMonitoringTest, CancellationAcrossSleep) {
642   constexpr auto kJankTiming =
643       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
644   {
645     ScopedBlockingCall blocked_for_7s(FROM_HERE, BlockingType::MAY_BLOCK);
646     task_environment_->FastForwardBy(kJankTiming);
647   }
648 
649   // Jump just beyond the kTimeDiscrepancyTimeout for the next window.
650   task_environment_->AdvanceClock(
651       internal::IOJankMonitoringWindow::kMonitoringWindow +
652       internal::IOJankMonitoringWindow::kTimeDiscrepancyTimeout - kJankTiming);
653   task_environment_->RunUntilIdle();
654 
655   // Window was canceled and previous jank was not reported.
656   EXPECT_THAT(reports_, ElementsAre());
657 
658   // The second window should be independent and need a full kMonitoringWindow
659   // to elapse before reporting.
660   task_environment_->FastForwardBy(
661       internal::IOJankMonitoringWindow::kMonitoringWindow - Seconds(1));
662   EXPECT_THAT(reports_, ElementsAre());
663 
664   task_environment_->FastForwardBy(Seconds(1));
665   EXPECT_THAT(reports_, ElementsAre(std::make_pair(0, 0)));
666 }
667 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,SleepWithLongJank)668 TEST_F(ScopedBlockingCallIOJankMonitoringTest, SleepWithLongJank) {
669   {
670     ScopedBlockingCall blocked_through_sleep(FROM_HERE,
671                                              BlockingType::MAY_BLOCK);
672 
673     // Fast-forward 2 full windows and almost to the end of the 3rd.
674     task_environment_->FastForwardBy(
675         internal::IOJankMonitoringWindow::kMonitoringWindow * 3 - Seconds(1));
676 
677     // Simulate a "sleep" over the timeout threshold.
678     task_environment_->AdvanceClock(
679         Seconds(1) + internal::IOJankMonitoringWindow::kTimeDiscrepancyTimeout);
680   }
681 
682   // Two full jank windows are reported when the ScopedBlokcingCall unwinds but
683   // the 3rd is canceled.
684   EXPECT_THAT(reports_,
685               ElementsAre(std::make_pair(60, 60), std::make_pair(60, 60)));
686 
687   // The 4th window has a new |start_time| so completing the "remaining delta"
688   // doesn't cause a report from the cancelled 3rd window.
689   task_environment_->FastForwardBy(
690       internal::IOJankMonitoringWindow::kMonitoringWindow - Seconds(1));
691   EXPECT_THAT(reports_,
692               ElementsAre(std::make_pair(60, 60), std::make_pair(60, 60)));
693 
694   // Completing the whole 4th window generates a report.
695   task_environment_->FastForwardBy(Seconds(1));
696   EXPECT_THAT(reports_,
697               ElementsAre(std::make_pair(60, 60), std::make_pair(60, 60),
698                           std::make_pair(0, 0)));
699 }
700 
701 // Verifies that blocking calls on background workers aren't monitored.
702 // Platforms where !CanUseBackgroundThreadTypeForWorkerThread() will still
703 // monitor this jank (as it may interfere with other foreground work).
TEST_F(ScopedBlockingCallIOJankMonitoringTest,BackgroundBlockingCallsIgnored)704 TEST_F(ScopedBlockingCallIOJankMonitoringTest, BackgroundBlockingCallsIgnored) {
705   constexpr auto kJankTiming =
706       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
707 
708   TestWaitableEvent task_running;
709   TestWaitableEvent resume_task;
710 
711   base::ThreadPool::PostTask(
712       FROM_HERE, {TaskPriority::BEST_EFFORT, MayBlock()},
713       BindLambdaForTesting([&]() {
714         ScopedBlockingCall blocked_for_7s(FROM_HERE, BlockingType::MAY_BLOCK);
715         task_running.Signal();
716 
717         ScopedAllowBaseSyncPrimitivesForTesting allow_wait;
718         resume_task.Wait();
719       }));
720 
721   task_running.Wait();
722   task_environment_->AdvanceClock(kJankTiming);
723   resume_task.Signal();
724 
725   // No janks reported before the monitoring window completes.
726   EXPECT_THAT(reports_, ElementsAre());
727 
728   task_environment_->FastForwardBy(
729       internal::IOJankMonitoringWindow::kMonitoringWindow);
730 
731   if (internal::CanUseBackgroundThreadTypeForWorkerThread())
732     EXPECT_THAT(reports_, ElementsAre(std::make_pair(0, 0)));
733   else
734     EXPECT_THAT(reports_, ElementsAre(std::make_pair(7, 7)));
735 }
736 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,BackgroundAndForegroundCallsMixed)737 TEST_F(ScopedBlockingCallIOJankMonitoringTest,
738        BackgroundAndForegroundCallsMixed) {
739   constexpr auto kJankTiming =
740       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
741 
742   TestWaitableEvent tasks_running;
743   auto on_task_running = BarrierClosure(
744       2, BindOnce(&TestWaitableEvent::Signal, Unretained(&tasks_running)));
745   TestWaitableEvent resume_tasks;
746 
747   base::ThreadPool::PostTask(
748       FROM_HERE, {TaskPriority::BEST_EFFORT, MayBlock()},
749       BindLambdaForTesting([&]() {
750         ScopedBlockingCall blocked_for_7s(FROM_HERE, BlockingType::MAY_BLOCK);
751         on_task_running.Run();
752 
753         ScopedAllowBaseSyncPrimitivesForTesting allow_wait;
754         resume_tasks.Wait();
755       }));
756 
757   base::ThreadPool::PostTask(
758       FROM_HERE, {TaskPriority::USER_BLOCKING, MayBlock()},
759       BindLambdaForTesting([&]() {
760         ScopedBlockingCall blocked_for_7s(FROM_HERE, BlockingType::MAY_BLOCK);
761         on_task_running.Run();
762 
763         ScopedAllowBaseSyncPrimitivesForTesting allow_wait;
764         resume_tasks.Wait();
765       }));
766 
767   tasks_running.Wait();
768   task_environment_->AdvanceClock(kJankTiming);
769   resume_tasks.Signal();
770 
771   // No janks reported before the monitoring window completes.
772   EXPECT_THAT(reports_, ElementsAre());
773 
774   task_environment_->FastForwardBy(
775       internal::IOJankMonitoringWindow::kMonitoringWindow);
776 
777   if (internal::CanUseBackgroundThreadTypeForWorkerThread())
778     EXPECT_THAT(reports_, ElementsAre(std::make_pair(7, 7)));
779   else
780     EXPECT_THAT(reports_, ElementsAre(std::make_pair(7, 14)));
781 }
782 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,WillBlockNotMonitored)783 TEST_F(ScopedBlockingCallIOJankMonitoringTest, WillBlockNotMonitored) {
784   constexpr auto kBlockedTiming =
785       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
786   {
787     ScopedBlockingCall blocked_for_7s(FROM_HERE, BlockingType::WILL_BLOCK);
788     task_environment_->FastForwardBy(kBlockedTiming);
789   }
790 
791   task_environment_->FastForwardBy(
792       internal::IOJankMonitoringWindow::kMonitoringWindow);
793 
794   EXPECT_THAT(reports_, ElementsAre(std::make_pair(0, 0)));
795 }
796 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,NestedWillBlockCancelsMonitoring)797 TEST_F(ScopedBlockingCallIOJankMonitoringTest,
798        NestedWillBlockCancelsMonitoring) {
799   constexpr auto kBlockedTiming =
800       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
801   {
802     ScopedBlockingCall blocked_for_14s(FROM_HERE, BlockingType::MAY_BLOCK);
803     task_environment_->FastForwardBy(kBlockedTiming);
804     ScopedBlockingCall will_block_for_7s(FROM_HERE, BlockingType::WILL_BLOCK);
805     task_environment_->FastForwardBy(kBlockedTiming);
806   }
807 
808   task_environment_->FastForwardBy(
809       internal::IOJankMonitoringWindow::kMonitoringWindow);
810 
811   EXPECT_THAT(reports_, ElementsAre(std::make_pair(0, 0)));
812 }
813 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,NestedMayBlockIgnored)814 TEST_F(ScopedBlockingCallIOJankMonitoringTest, NestedMayBlockIgnored) {
815   constexpr auto kBlockedTiming =
816       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
817   {
818     ScopedBlockingCall blocked_for_14s(FROM_HERE, BlockingType::MAY_BLOCK);
819     task_environment_->FastForwardBy(kBlockedTiming);
820     ScopedBlockingCall may_block_for_7s(FROM_HERE, BlockingType::MAY_BLOCK);
821     task_environment_->FastForwardBy(kBlockedTiming);
822   }
823 
824   task_environment_->FastForwardBy(
825       internal::IOJankMonitoringWindow::kMonitoringWindow);
826 
827   EXPECT_THAT(reports_, ElementsAre(std::make_pair(14, 14)));
828 }
829 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,BaseSyncPrimitivesNotMonitored)830 TEST_F(ScopedBlockingCallIOJankMonitoringTest, BaseSyncPrimitivesNotMonitored) {
831   constexpr auto kBlockedTiming =
832       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
833   {
834     // Even with MAY_BLOCK; base-sync-primitives aren't considered I/O jank
835     // (base-sync-primitives induced janks/hangs are captured by other tools,
836     // like Slow Reports and HangWatcher).
837     internal::ScopedBlockingCallWithBaseSyncPrimitives
838         base_sync_primitives_for_7s(FROM_HERE, BlockingType::MAY_BLOCK);
839     task_environment_->FastForwardBy(kBlockedTiming);
840   }
841 
842   task_environment_->FastForwardBy(
843       internal::IOJankMonitoringWindow::kMonitoringWindow);
844 
845   EXPECT_THAT(reports_, ElementsAre(std::make_pair(0, 0)));
846 }
847 
TEST_F(ScopedBlockingCallIOJankMonitoringTest,NestedBaseSyncPrimitivesCancels)848 TEST_F(ScopedBlockingCallIOJankMonitoringTest,
849        NestedBaseSyncPrimitivesCancels) {
850   constexpr auto kBlockedTiming =
851       internal::IOJankMonitoringWindow::kIOJankInterval * 7;
852   {
853     ScopedBlockingCall blocked_for_14s(FROM_HERE, BlockingType::MAY_BLOCK);
854     task_environment_->FastForwardBy(kBlockedTiming);
855     internal::ScopedBlockingCallWithBaseSyncPrimitives
856         base_sync_primitives_for_7s(FROM_HERE, BlockingType::MAY_BLOCK);
857     task_environment_->FastForwardBy(kBlockedTiming);
858   }
859 
860   task_environment_->FastForwardBy(
861       internal::IOJankMonitoringWindow::kMonitoringWindow);
862 
863   EXPECT_THAT(reports_, ElementsAre(std::make_pair(0, 0)));
864 }
865 
866 // Regression test for crbug.com/1209622
TEST_F(ScopedBlockingCallIOJankMonitoringTest,RacySampleNearMonitoringWindowBoundary)867 TEST_F(ScopedBlockingCallIOJankMonitoringTest,
868        RacySampleNearMonitoringWindowBoundary) {
869   constexpr auto kDeltaFromBoundary = Milliseconds(1);
870   const int kNumBlockedIntervals = 7;
871   constexpr auto kBlockedTiming =
872       internal::IOJankMonitoringWindow::kIOJankInterval * kNumBlockedIntervals;
873   // kBlockedTiming must be below kTimeDiscrepancyTimeout or racing worker
874   // threads might cancel the next window when ~ScopedBlockingCall lands too far
875   // in the future (since AdvanceClock() doesn't cause delayed tasks to run and
876   // the first window to expire when expected).
877   static_assert(kBlockedTiming <=
878                     internal::IOJankMonitoringWindow::kTimeDiscrepancyTimeout,
879                 "");
880 
881   // Start this test near an IOJankMonitoringWindow boundary.
882   task_environment_->FastForwardBy(
883       internal::IOJankMonitoringWindow::kMonitoringWindow - kDeltaFromBoundary);
884 
885   const int kNumRacingThreads =
886       test::TaskEnvironment::kNumForegroundThreadPoolThreads;
887 
888   TestWaitableEvent all_threads_blocked;
889   auto on_thread_blocked = BarrierClosure(
890       kNumRacingThreads,
891       BindOnce(&TestWaitableEvent::Signal, Unretained(&all_threads_blocked)));
892   TestWaitableEvent unblock_worker_threads;
893 
894   // First warmup the ThreadPool so there are kNumRacingThreads ready threads
895   // (to maximize the likelihood of a race).
896   for (int i = 0; i < kNumRacingThreads; ++i) {
897     ThreadPool::PostTask(FROM_HERE, {MayBlock()}, BindLambdaForTesting([&]() {
898                            on_thread_blocked.Run();
899                            unblock_worker_threads.Wait();
900                          }));
901   }
902   all_threads_blocked.Wait();
903   unblock_worker_threads.Signal();
904   task_environment_->RunUntilIdle();
905 
906   all_threads_blocked.Reset();
907   on_thread_blocked = BarrierClosure(
908       kNumRacingThreads,
909       BindOnce(&TestWaitableEvent::Signal, Unretained(&all_threads_blocked)));
910   unblock_worker_threads.Reset();
911 
912   for (int i = 0; i < kNumRacingThreads; ++i) {
913     ThreadPool::PostTask(FROM_HERE, {MayBlock()}, BindLambdaForTesting([&]() {
914                            ScopedBlockingCall blocked_for_14s(
915                                FROM_HERE, BlockingType::MAY_BLOCK);
916                            on_thread_blocked.Run();
917                            unblock_worker_threads.Wait();
918                          }));
919   }
920 
921   // Race the worker threads sampling Now() at the start of their blocking call
922   // to reproduce the conditions of crbug.com/1209622. The race occurs if a
923   // worker thread samples Now() before it moves across the boundary but then
924   // the boundary is crossed before it sampled its assigned
925   // IOJankMonitoringWindow, getting a window which doesn't overlap with the
926   // sampled Now() identifying the ScopedBlockingCall's entry point.
927   task_environment_->AdvanceClock(kDeltaFromBoundary);
928   {
929     // We have to use AdvanceClock() above as a FastForwardBy() would stall on
930     // the blocked workers. This means the delayed task causing the first
931     // IOJankMonitoringWindow to expire didn't run. Entering a new
932     // ScopedBlockingCall forces this to happen.
933     ScopedBlockingCall trigger_window(FROM_HERE, BlockingType::MAY_BLOCK);
934   }
935 
936   all_threads_blocked.Wait();
937   task_environment_->AdvanceClock(kBlockedTiming);
938   // If a worker thread holds a "begin" timestamp in the past versus its
939   // assigned IOJankMonitoringWindow, completing the janky ScopedBlockingCall
940   // will result in an OOB-index into
941   // |IOJankMonitoringWindow::intervals_jank_count_|.
942   unblock_worker_threads.Signal();
943   task_environment_->RunUntilIdle();
944 
945   // Force a report immediately.
946   StopMonitoring();
947 
948   // Test covered 2 monitoring windows.
949   ASSERT_EQ(reports_.size(), 2U);
950 
951   // Between 0 and kNumRacingThreads sampled Now() and their
952   // IOJankMonitoringWindow before Now() was fast-forwarded by
953   // kDeltaFromBoundary.
954   auto [janky_intervals_count, total_jank_count] = reports_[0];
955   EXPECT_GE(janky_intervals_count, 0);
956   EXPECT_LE(janky_intervals_count, 1);
957   EXPECT_GE(total_jank_count, 0);
958   EXPECT_LE(total_jank_count, kNumRacingThreads);
959   std::tie(janky_intervals_count, total_jank_count) = reports_[1];
960   EXPECT_GE(janky_intervals_count, kNumBlockedIntervals - 1);
961   EXPECT_LE(janky_intervals_count, kNumBlockedIntervals);
962   EXPECT_GE(total_jank_count, (kNumBlockedIntervals - 1) * kNumRacingThreads);
963   EXPECT_LE(total_jank_count, kNumBlockedIntervals * kNumRacingThreads);
964 }
965 
966 }  // namespace base
967