1 // Copyright 2014 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/task/common/task_annotator.h"
6
7 #include <algorithm>
8 #include <vector>
9
10 #include "base/functional/bind.h"
11 #include "base/functional/callback.h"
12 #include "base/functional/callback_helpers.h"
13 #include "base/pending_task.h"
14 #include "base/run_loop.h"
15 #include "base/strings/stringprintf.h"
16 #include "base/synchronization/lock.h"
17 #include "base/synchronization/waitable_event.h"
18 #include "base/task/single_thread_task_runner.h"
19 #include "base/task/thread_pool.h"
20 #include "base/test/bind.h"
21 #include "base/test/task_environment.h"
22 #include "base/threading/thread.h"
23 #include "testing/gtest/include/gtest/gtest.h"
24
25 namespace base {
26 namespace {
27
TestTask(int * result)28 void TestTask(int* result) {
29 *result = 123;
30 }
31
32 } // namespace
33
TEST(TaskAnnotatorTest,QueueAndRunTask)34 TEST(TaskAnnotatorTest, QueueAndRunTask) {
35 int result = 0;
36 PendingTask pending_task(FROM_HERE, BindOnce(&TestTask, &result));
37
38 TaskAnnotator annotator;
39 annotator.WillQueueTask("TaskAnnotatorTest::Queue", &pending_task);
40 EXPECT_EQ(0, result);
41 annotator.RunTask("TaskAnnotator::RunTask", pending_task);
42 EXPECT_EQ(123, result);
43 }
44
45 // Test task annotator integration in base APIs and ensuing support for
46 // backtraces. Tasks posted across multiple threads in this test fixture should
47 // be synchronized as BeforeRunTask() and VerifyTraceAndPost() assume tasks are
48 // observed in lock steps, one at a time.
49 class TaskAnnotatorBacktraceIntegrationTest
50 : public ::testing::Test,
51 public TaskAnnotator::ObserverForTesting {
52 public:
53 using ExpectedTrace = std::vector<const void*>;
54
55 TaskAnnotatorBacktraceIntegrationTest() = default;
56
57 TaskAnnotatorBacktraceIntegrationTest(
58 const TaskAnnotatorBacktraceIntegrationTest&) = delete;
59 TaskAnnotatorBacktraceIntegrationTest& operator=(
60 const TaskAnnotatorBacktraceIntegrationTest&) = delete;
61
62 ~TaskAnnotatorBacktraceIntegrationTest() override = default;
63
64 // TaskAnnotator::ObserverForTesting:
BeforeRunTask(const PendingTask * pending_task)65 void BeforeRunTask(const PendingTask* pending_task) override {
66 AutoLock auto_lock(on_before_run_task_lock_);
67 last_posted_from_ = pending_task->posted_from;
68 last_task_backtrace_ = pending_task->task_backtrace;
69 last_ipc_hash_ = pending_task->ipc_hash;
70 }
71
SetUp()72 void SetUp() override { TaskAnnotator::RegisterObserverForTesting(this); }
73
TearDown()74 void TearDown() override { TaskAnnotator::ClearObserverForTesting(); }
75
VerifyTraceAndPost(const scoped_refptr<SequencedTaskRunner> & task_runner,const Location & posted_from,const Location & next_from_here,const ExpectedTrace & expected_trace,uint32_t expected_ipc_hash,OnceClosure task)76 void VerifyTraceAndPost(const scoped_refptr<SequencedTaskRunner>& task_runner,
77 const Location& posted_from,
78 const Location& next_from_here,
79 const ExpectedTrace& expected_trace,
80 uint32_t expected_ipc_hash,
81 OnceClosure task) {
82 SCOPED_TRACE(StringPrintf("Callback Depth: %zu", expected_trace.size()));
83
84 EXPECT_EQ(posted_from, last_posted_from_);
85 for (size_t i = 0; i < last_task_backtrace_.size(); i++) {
86 SCOPED_TRACE(StringPrintf("Trace frame: %zu", i));
87 if (i < expected_trace.size())
88 EXPECT_EQ(expected_trace[i], last_task_backtrace_[i]);
89 else
90 EXPECT_EQ(nullptr, last_task_backtrace_[i]);
91 }
92 EXPECT_EQ(expected_ipc_hash, last_ipc_hash_);
93
94 task_runner->PostTask(next_from_here, std::move(task));
95 }
96
VerifyTraceAndPostWithIpcContext(const scoped_refptr<SequencedTaskRunner> & task_runner,const Location & posted_from,const Location & next_from_here,const ExpectedTrace & expected_trace,uint32_t expected_ipc_hash,OnceClosure task,uint32_t new_ipc_hash)97 void VerifyTraceAndPostWithIpcContext(
98 const scoped_refptr<SequencedTaskRunner>& task_runner,
99 const Location& posted_from,
100 const Location& next_from_here,
101 const ExpectedTrace& expected_trace,
102 uint32_t expected_ipc_hash,
103 OnceClosure task,
104 uint32_t new_ipc_hash) {
105 TaskAnnotator::ScopedSetIpcHash scoped_ipc_hash(new_ipc_hash);
106 VerifyTraceAndPost(task_runner, posted_from, next_from_here, expected_trace,
107 expected_ipc_hash, std::move(task));
108 }
109
110 // Same as VerifyTraceAndPost() with the exception that it also posts a task
111 // that will prevent |task| from running until |wait_before_next_task| is
112 // signaled.
VerifyTraceAndPostWithBlocker(const scoped_refptr<SequencedTaskRunner> & task_runner,const Location & posted_from,const Location & next_from_here,const ExpectedTrace & expected_trace,uint32_t expected_ipc_hash,OnceClosure task,WaitableEvent * wait_before_next_task)113 void VerifyTraceAndPostWithBlocker(
114 const scoped_refptr<SequencedTaskRunner>& task_runner,
115 const Location& posted_from,
116 const Location& next_from_here,
117 const ExpectedTrace& expected_trace,
118 uint32_t expected_ipc_hash,
119 OnceClosure task,
120 WaitableEvent* wait_before_next_task) {
121 DCHECK(wait_before_next_task);
122
123 // Need to lock to ensure the upcoming VerifyTraceAndPost() runs before the
124 // BeforeRunTask() hook for the posted WaitableEvent::Wait(). Otherwise the
125 // upcoming VerifyTraceAndPost() will race to read the state saved in the
126 // BeforeRunTask() hook preceding the current task.
127 AutoLock auto_lock(on_before_run_task_lock_);
128 task_runner->PostTask(
129 FROM_HERE,
130 BindOnce(&WaitableEvent::Wait, Unretained(wait_before_next_task)));
131 VerifyTraceAndPost(task_runner, posted_from, next_from_here, expected_trace,
132 expected_ipc_hash, std::move(task));
133 }
134
135 protected:
RunTwo(OnceClosure c1,OnceClosure c2)136 static void RunTwo(OnceClosure c1, OnceClosure c2) {
137 std::move(c1).Run();
138 std::move(c2).Run();
139 }
140
141 private:
142 // While calls to VerifyTraceAndPost() are strictly ordered in tests below
143 // (and hence non-racy), some helper methods (e.g. Wait/Signal) do racily call
144 // into BeforeRunTask(). This Lock ensures these unobserved writes are not
145 // racing. Locking isn't required on read per the VerifyTraceAndPost()
146 // themselves being ordered.
147 Lock on_before_run_task_lock_;
148
149 Location last_posted_from_ = {};
150 std::array<const void*, PendingTask::kTaskBacktraceLength>
151 last_task_backtrace_ = {};
152
153 uint32_t last_ipc_hash_ = 0;
154 };
155
156 // Ensure the task backtrace populates correctly.
TEST_F(TaskAnnotatorBacktraceIntegrationTest,SingleThreadedSimple)157 TEST_F(TaskAnnotatorBacktraceIntegrationTest, SingleThreadedSimple) {
158 test::TaskEnvironment task_environment;
159 const uint32_t dummy_ipc_hash = 0xDEADBEEF;
160 const Location location0 = FROM_HERE;
161 const Location location1 = FROM_HERE;
162 const Location location2 = FROM_HERE;
163 const Location location3 = FROM_HERE;
164 const Location location4 = FROM_HERE;
165 const Location location5 = FROM_HERE;
166
167 RunLoop run_loop;
168
169 // Task 0 executes with no IPC context. Task 1 executes under an explicitly
170 // set IPC context. Tasks 2-5 don't necessarily inherit that context, as
171 // IPCs may spawn subtasks that aren't necessarily IPCs themselves.
172
173 // Task 5 has tasks 4/3/2/1 as parents (task 0 isn't visible as only the
174 // last 4 parents are kept).
175 OnceClosure task5 = BindOnce(
176 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
177 Unretained(this), SingleThreadTaskRunner::GetCurrentDefault(), location5,
178 FROM_HERE,
179 ExpectedTrace({location4.program_counter(), location3.program_counter(),
180 location2.program_counter(), location1.program_counter()}),
181 0, run_loop.QuitClosure());
182
183 // Task i=4/3/2/1/0 have tasks [0,i) as parents.
184 OnceClosure task4 = BindOnce(
185 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
186 Unretained(this), SingleThreadTaskRunner::GetCurrentDefault(), location4,
187 location5,
188 ExpectedTrace({location3.program_counter(), location2.program_counter(),
189 location1.program_counter(), location0.program_counter()}),
190 0, std::move(task5));
191 OnceClosure task3 = BindOnce(
192 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
193 Unretained(this), SingleThreadTaskRunner::GetCurrentDefault(), location3,
194 location4,
195 ExpectedTrace({location2.program_counter(), location1.program_counter(),
196 location0.program_counter()}),
197 0, std::move(task4));
198 OnceClosure task2 = BindOnce(
199 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
200 Unretained(this), SingleThreadTaskRunner::GetCurrentDefault(), location2,
201 location3,
202 ExpectedTrace({location1.program_counter(), location0.program_counter()}),
203 dummy_ipc_hash, std::move(task3));
204 OnceClosure task1 = BindOnce(
205 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPostWithIpcContext,
206 Unretained(this), SingleThreadTaskRunner::GetCurrentDefault(), location1,
207 location2, ExpectedTrace({location0.program_counter()}), 0,
208 std::move(task2), dummy_ipc_hash);
209 OnceClosure task0 =
210 BindOnce(&TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
211 Unretained(this), SingleThreadTaskRunner::GetCurrentDefault(),
212 location0, location1, ExpectedTrace({}), 0, std::move(task1));
213
214 SingleThreadTaskRunner::GetCurrentDefault()->PostTask(location0,
215 std::move(task0));
216
217 run_loop.Run();
218 }
219
220 // Ensure it works when posting tasks across multiple threads managed by //base.
TEST_F(TaskAnnotatorBacktraceIntegrationTest,MultipleThreads)221 TEST_F(TaskAnnotatorBacktraceIntegrationTest, MultipleThreads) {
222 test::TaskEnvironment task_environment;
223
224 // Use diverse task runners (a task environment main thread, a ThreadPool
225 // based SequencedTaskRunner, and a ThreadPool based
226 // SingleThreadTaskRunner) to verify that TaskAnnotator can capture backtraces
227 // for PostTasks back-and-forth between these.
228 auto main_thread_a = SingleThreadTaskRunner::GetCurrentDefault();
229 auto task_runner_b = ThreadPool::CreateSingleThreadTaskRunner({});
230 auto task_runner_c = ThreadPool::CreateSequencedTaskRunner(
231 {base::MayBlock(), base::WithBaseSyncPrimitives()});
232
233 const Location& location_a0 = FROM_HERE;
234 const Location& location_a1 = FROM_HERE;
235 const Location& location_a2 = FROM_HERE;
236 const Location& location_a3 = FROM_HERE;
237
238 const Location& location_b0 = FROM_HERE;
239 const Location& location_b1 = FROM_HERE;
240
241 const Location& location_c0 = FROM_HERE;
242
243 RunLoop run_loop;
244
245 // All tasks below happen in lock step by nature of being posted by the
246 // previous one (plus the synchronous nature of RunTwo()) with the exception
247 // of the follow-up local task to |task_b0_local|. This WaitableEvent ensures
248 // it completes before |task_c0| runs to avoid racy invocations of
249 // BeforeRunTask()+VerifyTraceAndPost().
250 WaitableEvent lock_step(WaitableEvent::ResetPolicy::AUTOMATIC,
251 WaitableEvent::InitialState::NOT_SIGNALED);
252
253 // Here is the execution order generated below:
254 // A: TA0 -> TA1 \ TA2
255 // B: TB0L \ + TB0F \ Signal \ /
256 // ---------\--/ \ /
257 // \ \ /
258 // C: Wait........ TC0 /
259
260 // IPC contexts:
261 // TA0 and TA1 execute with no IPC context.
262 // TB0L is the first task to execute with an explicit IPC context.
263 // TB0F inherits no context.
264 // TC0 is posted with a new IPC context from TB0L.
265 // TA2 inherits that IPC context.
266 const uint32_t dummy_ipc_hash0 = 0xDEADBEEF;
267 const uint32_t dummy_ipc_hash1 = 0xBAADF00D;
268
269 // On task runner c, post a task back to main thread that verifies its trace
270 // and terminates after one more self-post.
271 OnceClosure task_a2 = BindOnce(
272 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
273 Unretained(this), main_thread_a, location_a2, location_a3,
274 ExpectedTrace(
275 {location_c0.program_counter(), location_b0.program_counter(),
276 location_a1.program_counter(), location_a0.program_counter()}),
277 dummy_ipc_hash1, run_loop.QuitClosure());
278 OnceClosure task_c0 = BindOnce(
279 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPostWithIpcContext,
280 Unretained(this), main_thread_a, location_c0, location_a2,
281 ExpectedTrace({location_b0.program_counter(),
282 location_a1.program_counter(),
283 location_a0.program_counter()}),
284 0, std::move(task_a2), dummy_ipc_hash1);
285
286 // On task runner b run two tasks that conceptually come from the same
287 // location (managed via RunTwo().) One will post back to task runner b and
288 // another will post to task runner c to test spawning multiple tasks on
289 // different message loops. The task posted to task runner c will not get
290 // location b1 whereas the one posted back to task runner b will.
291 OnceClosure task_b0_fork = BindOnce(
292 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPostWithBlocker,
293 Unretained(this), task_runner_c, location_b0, location_c0,
294 ExpectedTrace(
295 {location_a1.program_counter(), location_a0.program_counter()}),
296 0, std::move(task_c0), &lock_step);
297 OnceClosure task_b0_local = BindOnce(
298 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPostWithIpcContext,
299 Unretained(this), task_runner_b, location_b0, location_b1,
300 ExpectedTrace(
301 {location_a1.program_counter(), location_a0.program_counter()}),
302 0, BindOnce(&WaitableEvent::Signal, Unretained(&lock_step)),
303 dummy_ipc_hash0);
304
305 OnceClosure task_a1 =
306 BindOnce(&TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
307 Unretained(this), task_runner_b, location_a1, location_b0,
308 ExpectedTrace({location_a0.program_counter()}), 0,
309 BindOnce(&TaskAnnotatorBacktraceIntegrationTest::RunTwo,
310 std::move(task_b0_local), std::move(task_b0_fork)));
311 OnceClosure task_a0 =
312 BindOnce(&TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
313 Unretained(this), main_thread_a, location_a0, location_a1,
314 ExpectedTrace({}), 0, std::move(task_a1));
315
316 main_thread_a->PostTask(location_a0, std::move(task_a0));
317
318 run_loop.Run();
319 }
320
321 // Ensure nesting doesn't break the chain.
TEST_F(TaskAnnotatorBacktraceIntegrationTest,SingleThreadedNested)322 TEST_F(TaskAnnotatorBacktraceIntegrationTest, SingleThreadedNested) {
323 test::TaskEnvironment task_environment;
324 uint32_t dummy_ipc_hash = 0xDEADBEEF;
325 uint32_t dummy_ipc_hash1 = 0xBAADF00D;
326 uint32_t dummy_ipc_hash2 = 0x900DD099;
327 const Location location0 = FROM_HERE;
328 const Location location1 = FROM_HERE;
329 const Location location2 = FROM_HERE;
330 const Location location3 = FROM_HERE;
331 const Location location4 = FROM_HERE;
332 const Location location5 = FROM_HERE;
333
334 RunLoop run_loop;
335
336 // Task execution below looks like this, w.r.t. to RunLoop depths:
337 // 1 : T0 \ + NRL1 \ ---------> T4 -> T5
338 // 2 : ---------> T1 \ -> NRL2 \ ----> T2 -> T3 / + Quit /
339 // 3 : ---------> DN /
340
341 // NRL1 tests that tasks that occur at a different nesting depth than their
342 // parent have a sane backtrace nonetheless (both ways).
343
344 // NRL2 tests that posting T2 right after exiting the RunLoop (from the same
345 // task) results in NRL2 being its parent (and not the DoNothing() task that
346 // just ran -- which would have been the case if the "current task" wasn't
347 // restored properly when returning from a task within a task).
348
349 // In other words, this is regression test for a bug in the previous
350 // implementation. In the current implementation, replacing
351 // tls_for_current_pending_task->Set(previous_pending_task);
352 // by
353 // tls_for_current_pending_task->Set(nullptr);
354 // at the end of TaskAnnotator::RunTask() makes this test fail.
355
356 // This test also validates the IPC contexts are propagated appropriately, and
357 // then a context in an outer loop does not color tasks posted from a nested
358 // loop.
359
360 RunLoop nested_run_loop1(RunLoop::Type::kNestableTasksAllowed);
361
362 // Expectations are the same as in SingleThreadedSimple test despite the
363 // nested loop starting between tasks 0 and 1 and stopping between tasks 3 and
364 // 4.
365 OnceClosure task5 = BindOnce(
366 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
367 Unretained(this), SingleThreadTaskRunner::GetCurrentDefault(), location5,
368 FROM_HERE,
369 ExpectedTrace({location4.program_counter(), location3.program_counter(),
370 location2.program_counter(), location1.program_counter()}),
371 0, run_loop.QuitClosure());
372 OnceClosure task4 = BindOnce(
373 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
374 Unretained(this), SingleThreadTaskRunner::GetCurrentDefault(), location4,
375 location5,
376 ExpectedTrace({location3.program_counter(), location2.program_counter(),
377 location1.program_counter(), location0.program_counter()}),
378 0, std::move(task5));
379 OnceClosure task3 = BindOnce(
380 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
381 Unretained(this), SingleThreadTaskRunner::GetCurrentDefault(), location3,
382 location4,
383 ExpectedTrace({location2.program_counter(), location1.program_counter(),
384 location0.program_counter()}),
385 0, std::move(task4));
386
387 OnceClosure run_task_3_then_quit_nested_loop1 =
388 BindOnce(&TaskAnnotatorBacktraceIntegrationTest::RunTwo, std::move(task3),
389 nested_run_loop1.QuitClosure());
390
391 OnceClosure task2 = BindOnce(
392 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPost,
393 Unretained(this), SingleThreadTaskRunner::GetCurrentDefault(), location2,
394 location3,
395 ExpectedTrace({location1.program_counter(), location0.program_counter()}),
396 0, std::move(run_task_3_then_quit_nested_loop1));
397
398 // Task 1 is custom. It enters another nested RunLoop, has it do work and exit
399 // before posting the next task. This confirms that |task1| is restored as the
400 // current task before posting |task2| after returning from the nested loop.
401 RunLoop nested_run_loop2(RunLoop::Type::kNestableTasksAllowed);
402 OnceClosure task1 = BindOnce(
403 BindLambdaForTesting([dummy_ipc_hash1](RunLoop* nested_run_loop,
404 const Location& location2,
405 OnceClosure task2) {
406 {
407 // Run the nested message loop with an explicitly set IPC context.
408 // This context should not leak out of the inner loop and color the
409 // tasks in the outer loop.
410 TaskAnnotator::ScopedSetIpcHash scoped_ipc_hash(dummy_ipc_hash1);
411 SingleThreadTaskRunner::GetCurrentDefault()->PostTask(FROM_HERE,
412 DoNothing());
413 nested_run_loop->RunUntilIdle();
414 }
415 SingleThreadTaskRunner::GetCurrentDefault()->PostTask(location2,
416 std::move(task2));
417 }),
418 Unretained(&nested_run_loop2), location2, std::move(task2));
419
420 OnceClosure task0 = BindOnce(
421 &TaskAnnotatorBacktraceIntegrationTest::VerifyTraceAndPostWithIpcContext,
422 Unretained(this), SingleThreadTaskRunner::GetCurrentDefault(), location0,
423 location1, ExpectedTrace({}), 0, std::move(task1), dummy_ipc_hash);
424
425 SingleThreadTaskRunner::GetCurrentDefault()->PostTask(location0,
426 std::move(task0));
427
428 {
429 TaskAnnotator::ScopedSetIpcHash scoped_ipc_hash(dummy_ipc_hash2);
430 SingleThreadTaskRunner::GetCurrentDefault()->PostTask(
431 FROM_HERE,
432 BindOnce(&RunLoop::Run, Unretained(&nested_run_loop1), FROM_HERE));
433 }
434
435 run_loop.Run();
436 }
437
438 } // namespace base
439