1 // Copyright 2020 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_internal.h"
6
7 #include <algorithm>
8 #include <utility>
9
10 #include "base/check_op.h"
11 #include "base/compiler_specific.h"
12 #include "base/functional/bind.h"
13 #include "base/functional/callback_helpers.h"
14 #include "base/no_destructor.h"
15 #include "base/numerics/safe_conversions.h"
16 #include "base/scoped_clear_last_error.h"
17 #include "base/task/scoped_set_task_priority_for_current_thread.h"
18 #include "base/task/thread_pool.h"
19 #include "base/task/thread_pool/environment_config.h"
20 #include "base/task/thread_pool/thread_pool_instance.h"
21 #include "base/threading/scoped_blocking_call.h"
22 #include "build/build_config.h"
23 #include "third_party/abseil-cpp/absl/base/attributes.h"
24
25 namespace base {
26 namespace internal {
27
28 namespace {
29
30 ABSL_CONST_INIT thread_local BlockingObserver* blocking_observer = nullptr;
31
32 // Last ScopedBlockingCall instantiated on this thread.
33 ABSL_CONST_INIT thread_local UncheckedScopedBlockingCall*
34 last_scoped_blocking_call = nullptr;
35
36 // These functions can be removed, and the calls below replaced with direct
37 // variable accesses, once the MSAN workaround is not necessary.
GetBlockingObserver()38 BlockingObserver* GetBlockingObserver() {
39 // Workaround false-positive MSAN use-of-uninitialized-value on
40 // thread_local storage for loaded libraries:
41 // https://github.com/google/sanitizers/issues/1265
42 MSAN_UNPOISON(&blocking_observer, sizeof(BlockingObserver*));
43
44 return blocking_observer;
45 }
GetLastScopedBlockingCall()46 UncheckedScopedBlockingCall* GetLastScopedBlockingCall() {
47 // Workaround false-positive MSAN use-of-uninitialized-value on
48 // thread_local storage for loaded libraries:
49 // https://github.com/google/sanitizers/issues/1265
50 MSAN_UNPOISON(&last_scoped_blocking_call,
51 sizeof(UncheckedScopedBlockingCall*));
52
53 return last_scoped_blocking_call;
54 }
55
56 // Set to true by scoped_blocking_call_unittest to ensure unrelated threads
57 // entering ScopedBlockingCalls don't affect test outcomes.
58 bool g_only_monitor_observed_threads = false;
59
IsBackgroundPriorityWorker()60 bool IsBackgroundPriorityWorker() {
61 return GetTaskPriorityForCurrentThread() == TaskPriority::BEST_EFFORT &&
62 CanUseBackgroundThreadTypeForWorkerThread();
63 }
64
65 } // namespace
66
SetBlockingObserverForCurrentThread(BlockingObserver * new_blocking_observer)67 void SetBlockingObserverForCurrentThread(
68 BlockingObserver* new_blocking_observer) {
69 DCHECK(!GetBlockingObserver());
70 blocking_observer = new_blocking_observer;
71 }
72
ClearBlockingObserverForCurrentThread()73 void ClearBlockingObserverForCurrentThread() {
74 blocking_observer = nullptr;
75 }
76
ScopedMonitoredCall()77 IOJankMonitoringWindow::ScopedMonitoredCall::ScopedMonitoredCall()
78 : call_start_(TimeTicks::Now()),
79 assigned_jank_window_(MonitorNextJankWindowIfNecessary(call_start_)) {
80 if (assigned_jank_window_ &&
81 call_start_ < assigned_jank_window_->start_time_) {
82 // Sampling |call_start_| and being assigned an IOJankMonitoringWindow is
83 // racy. It is possible that |call_start_| is sampled near the very end of
84 // the current window; meanwhile, another ScopedMonitoredCall on another
85 // thread samples a |call_start_| which lands in the next window. If that
86 // thread beats this one to MonitorNextJankWindowIfNecessary(), this thread
87 // will incorrectly be assigned that window (in the future w.r.t. to its
88 // |call_start_|). To avoid OOB-indexing in AddJank(), crbug.com/1209622, it
89 // is necessary to correct this by bumping |call_start_| to the received
90 // window's |start_time_|.
91 //
92 // Note: The alternate approach of getting |assigned_jank_window_| before
93 // |call_start_| has the opposite problem where |call_start_| can be more
94 // than kNumIntervals ahead of |start_time_| when sampling across the window
95 // boundary, resulting in OOB-indexing the other way. To solve that a loop
96 // would be required (re-getting the latest window and re-sampling
97 // |call_start_| until the condition holds). The loopless solution is thus
98 // preferred.
99 //
100 // A lock covering this entire constructor is also undesired because of the
101 // lock-free logic at the end of MonitorNextJankWindowIfNecessary().
102 call_start_ = assigned_jank_window_->start_time_;
103 }
104 }
105
~ScopedMonitoredCall()106 IOJankMonitoringWindow::ScopedMonitoredCall::~ScopedMonitoredCall() {
107 if (assigned_jank_window_) {
108 assigned_jank_window_->OnBlockingCallCompleted(call_start_,
109 TimeTicks::Now());
110 }
111 }
112
Cancel()113 void IOJankMonitoringWindow::ScopedMonitoredCall::Cancel() {
114 assigned_jank_window_ = nullptr;
115 }
116
IOJankMonitoringWindow(TimeTicks start_time)117 IOJankMonitoringWindow::IOJankMonitoringWindow(TimeTicks start_time)
118 : start_time_(start_time) {}
119
120 // static
CancelMonitoringForTesting()121 void IOJankMonitoringWindow::CancelMonitoringForTesting() {
122 g_only_monitor_observed_threads = false;
123 AutoLock lock(current_jank_window_lock());
124 current_jank_window_storage() = nullptr;
125 reporting_callback_storage() = NullCallback();
126 }
127
128 // static
129 constexpr TimeDelta IOJankMonitoringWindow::kIOJankInterval;
130 // static
131 constexpr TimeDelta IOJankMonitoringWindow::kMonitoringWindow;
132 // static
133 constexpr TimeDelta IOJankMonitoringWindow::kTimeDiscrepancyTimeout;
134 // static
135 constexpr int IOJankMonitoringWindow::kNumIntervals;
136
137 // static
138 scoped_refptr<IOJankMonitoringWindow>
MonitorNextJankWindowIfNecessary(TimeTicks recent_now)139 IOJankMonitoringWindow::MonitorNextJankWindowIfNecessary(TimeTicks recent_now) {
140 DCHECK_GE(TimeTicks::Now(), recent_now);
141
142 scoped_refptr<IOJankMonitoringWindow> next_jank_window;
143
144 {
145 AutoLock lock(current_jank_window_lock());
146
147 if (!reporting_callback_storage())
148 return nullptr;
149
150 scoped_refptr<IOJankMonitoringWindow>& current_jank_window_ref =
151 current_jank_window_storage();
152
153 // Start the next window immediately after the current one (rather than
154 // based on Now() to avoid uncovered gaps). Only use Now() for the very
155 // first window in a monitoring chain.
156 TimeTicks next_window_start_time =
157 current_jank_window_ref
158 ? current_jank_window_ref->start_time_ + kMonitoringWindow
159 : recent_now;
160
161 if (next_window_start_time > recent_now) {
162 // Another thread beat us to constructing the next monitoring window and
163 // |current_jank_window_ref| already covers |recent_now|.
164 return current_jank_window_ref;
165 }
166
167 if (recent_now - next_window_start_time >= kTimeDiscrepancyTimeout) {
168 // If the delayed task runs on a regular heartbeat, |recent_now| should be
169 // roughly equal to |next_window_start_time|. If we miss by more than
170 // kTimeDiscrepancyTimeout, we likely hit machine sleep, cancel sampling
171 // that window in that case.
172 //
173 // Note: It is safe to touch |canceled_| without a lock here as this is
174 // the only time it's set and it naturally happens-before
175 // |current_jank_window_ref|'s destructor reads it.
176 current_jank_window_ref->canceled_ = true;
177 next_window_start_time = recent_now;
178 }
179
180 next_jank_window =
181 MakeRefCounted<IOJankMonitoringWindow>(next_window_start_time);
182
183 if (current_jank_window_ref && !current_jank_window_ref->canceled_) {
184 // If there are still IO operations in progress within
185 // |current_jank_window_ref|, they have a ref to it and will be the ones
186 // triggering ~IOJankMonitoringWindow(). When doing so, they will overlap
187 // into the |next_jank_window| we are setting up (|next_| will also own a
188 // ref so a very long jank can safely unwind across a chain of pending
189 // |next_|'s).
190 DCHECK(!current_jank_window_ref->next_);
191 current_jank_window_ref->next_ = next_jank_window;
192 }
193
194 // Make |next_jank_window| the new current before releasing the lock.
195 current_jank_window_ref = next_jank_window;
196 }
197
198 // Post a task to kick off the next monitoring window if no monitored thread
199 // beats us to it. Adjust the timing to alleviate any drift in the timer. Do
200 // this outside the lock to avoid scheduling tasks while holding it.
201 ThreadPool::PostDelayedTask(
202 FROM_HERE, BindOnce([]() {
203 IOJankMonitoringWindow::MonitorNextJankWindowIfNecessary(
204 TimeTicks::Now());
205 }),
206 kMonitoringWindow - (recent_now - next_jank_window->start_time_));
207
208 return next_jank_window;
209 }
210
211 // NO_THREAD_SAFETY_ANALYSIS because ~RefCountedThreadSafe() guarantees we're
212 // the last ones to access this state (and ordered after all other accesses).
~IOJankMonitoringWindow()213 IOJankMonitoringWindow::~IOJankMonitoringWindow() NO_THREAD_SAFETY_ANALYSIS {
214 if (canceled_)
215 return;
216
217 int janky_intervals_count = 0;
218 int total_jank_count = 0;
219
220 for (size_t interval_jank_count : intervals_jank_count_) {
221 if (interval_jank_count > 0) {
222 ++janky_intervals_count;
223 total_jank_count += interval_jank_count;
224 }
225 }
226
227 // reporting_callback_storage() is safe to access without lock because an
228 // IOJankMonitoringWindow existing means we're after the call to
229 // EnableIOJankMonitoringForProcess() and it will not change after that call.
230 DCHECK(reporting_callback_storage());
231 reporting_callback_storage().Run(janky_intervals_count, total_jank_count);
232 }
233
OnBlockingCallCompleted(TimeTicks call_start,TimeTicks call_end)234 void IOJankMonitoringWindow::OnBlockingCallCompleted(TimeTicks call_start,
235 TimeTicks call_end) {
236 // Confirm we never hit a case of TimeTicks going backwards on the same thread
237 // nor of TimeTicks rolling over the int64_t boundary (which would break
238 // comparison operators).
239 DCHECK_LE(call_start, call_end);
240
241 if (call_end - call_start < kIOJankInterval)
242 return;
243
244 // Make sure the chain of |next_| pointers is sufficient to reach
245 // |call_end| (e.g. if this runs before the delayed task kicks in)
246 if (call_end >= start_time_ + kMonitoringWindow)
247 MonitorNextJankWindowIfNecessary(call_end);
248
249 // Begin attributing jank to the first interval in which it appeared, no
250 // matter how far into the interval the jank began.
251 const int jank_start_index =
252 ClampFloor((call_start - start_time_) / kIOJankInterval);
253
254 // Round the jank duration so the total number of intervals marked janky is as
255 // close as possible to the actual jank duration.
256 const int num_janky_intervals =
257 ClampRound((call_end - call_start) / kIOJankInterval);
258
259 AddJank(jank_start_index, num_janky_intervals);
260 }
261
AddJank(int local_jank_start_index,int num_janky_intervals)262 void IOJankMonitoringWindow::AddJank(int local_jank_start_index,
263 int num_janky_intervals) {
264 DCHECK_GE(local_jank_start_index, 0);
265 DCHECK_LT(local_jank_start_index, kNumIntervals);
266
267 // Increment jank counts for intervals in this window. If
268 // |num_janky_intervals| lands beyond kNumIntervals, the additional intervals
269 // will be reported to |next_|.
270 const int jank_end_index = local_jank_start_index + num_janky_intervals;
271 const int local_jank_end_index = std::min(kNumIntervals, jank_end_index);
272
273 {
274 // Note: while this window could be |canceled| here we must add our count
275 // unconditionally as it is only thread-safe to read |canceled| in
276 // ~IOJankMonitoringWindow().
277 AutoLock lock(intervals_lock_);
278 for (int i = local_jank_start_index; i < local_jank_end_index; ++i)
279 ++intervals_jank_count_[i];
280 }
281
282 if (jank_end_index != local_jank_end_index) {
283 // OnBlockingCallCompleted() should have already ensured there's a |next_|
284 // chain covering |num_janky_intervals| unless it caused this to be
285 // |canceled_|. Exceptionally for this check, reading these fields when
286 // they're expected to be true is thread-safe as their only modification
287 // happened-before this point.
288 DCHECK(next_ || canceled_);
289 if (next_) {
290 // If |next_| is non-null, it means |this| wasn't canceled and it implies
291 // |next_| covers the time range starting immediately after this window.
292 DCHECK_EQ(next_->start_time_, start_time_ + kMonitoringWindow);
293 next_->AddJank(0, jank_end_index - local_jank_end_index);
294 }
295 }
296 }
297
298 // static
current_jank_window_lock()299 Lock& IOJankMonitoringWindow::current_jank_window_lock() {
300 static NoDestructor<Lock> current_jank_window_lock;
301 return *current_jank_window_lock;
302 }
303
304 // static
305 scoped_refptr<IOJankMonitoringWindow>&
current_jank_window_storage()306 IOJankMonitoringWindow::current_jank_window_storage() {
307 static NoDestructor<scoped_refptr<IOJankMonitoringWindow>>
308 current_jank_window;
309 return *current_jank_window;
310 }
311
312 // static
reporting_callback_storage()313 IOJankReportingCallback& IOJankMonitoringWindow::reporting_callback_storage() {
314 static NoDestructor<IOJankReportingCallback> reporting_callback;
315 return *reporting_callback;
316 }
317
UncheckedScopedBlockingCall(BlockingType blocking_type,BlockingCallType blocking_call_type)318 UncheckedScopedBlockingCall::UncheckedScopedBlockingCall(
319 BlockingType blocking_type,
320 BlockingCallType blocking_call_type)
321 : blocking_observer_(GetBlockingObserver()),
322 previous_scoped_blocking_call_(GetLastScopedBlockingCall()),
323 resetter_(&last_scoped_blocking_call, this),
324 is_will_block_(blocking_type == BlockingType::WILL_BLOCK ||
325 (previous_scoped_blocking_call_ &&
326 previous_scoped_blocking_call_->is_will_block_)) {
327 // Only monitor non-nested ScopedBlockingCall(MAY_BLOCK) calls on foreground
328 // threads. Cancels() any pending monitored call when a WILL_BLOCK or
329 // ScopedBlockingCallWithBaseSyncPrimitives nests into a
330 // ScopedBlockingCall(MAY_BLOCK).
331 if (!IsBackgroundPriorityWorker() &&
332 (!g_only_monitor_observed_threads || blocking_observer_)) {
333 const bool is_monitored_type =
334 blocking_call_type == BlockingCallType::kRegular && !is_will_block_;
335 if (is_monitored_type && !previous_scoped_blocking_call_) {
336 monitored_call_.emplace();
337 } else if (!is_monitored_type && previous_scoped_blocking_call_ &&
338 previous_scoped_blocking_call_->monitored_call_) {
339 previous_scoped_blocking_call_->monitored_call_->Cancel();
340 }
341 }
342
343 if (blocking_observer_) {
344 if (!previous_scoped_blocking_call_) {
345 blocking_observer_->BlockingStarted(blocking_type);
346 } else if (blocking_type == BlockingType::WILL_BLOCK &&
347 !previous_scoped_blocking_call_->is_will_block_) {
348 blocking_observer_->BlockingTypeUpgraded();
349 }
350 }
351 }
352
~UncheckedScopedBlockingCall()353 UncheckedScopedBlockingCall::~UncheckedScopedBlockingCall() {
354 // TLS affects result of GetLastError() on Windows. ScopedClearLastError
355 // prevents side effect.
356 ScopedClearLastError save_last_error;
357 DCHECK_EQ(this, GetLastScopedBlockingCall());
358 if (blocking_observer_ && !previous_scoped_blocking_call_)
359 blocking_observer_->BlockingEnded();
360 }
361
362 } // namespace internal
363
EnableIOJankMonitoringForProcess(IOJankReportingCallback reporting_callback,OnlyObservedThreadsForTest only_observed_threads)364 void EnableIOJankMonitoringForProcess(
365 IOJankReportingCallback reporting_callback,
366 OnlyObservedThreadsForTest only_observed_threads) {
367 {
368 AutoLock lock(internal::IOJankMonitoringWindow::current_jank_window_lock());
369
370 DCHECK(internal::IOJankMonitoringWindow::reporting_callback_storage()
371 .is_null());
372 internal::IOJankMonitoringWindow::reporting_callback_storage() =
373 std::move(reporting_callback);
374 }
375
376 if (only_observed_threads) {
377 internal::g_only_monitor_observed_threads = true;
378 } else {
379 // Do not set it to `false` when it already is as that causes data races in
380 // browser tests (which EnableIOJankMonitoringForProcess after ThreadPool is
381 // already running).
382 DCHECK(!internal::g_only_monitor_observed_threads);
383 }
384
385 // Make sure monitoring starts now rather than randomly at the next
386 // ScopedMonitoredCall construction.
387 internal::IOJankMonitoringWindow::MonitorNextJankWindowIfNecessary(
388 TimeTicks::Now());
389 }
390
391 } // namespace base
392