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