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