[base] Make sure 'ThreadController active' trace event outscopes all other RunTask events

This was missed in the original implementation because on Windows
the pump always processes a native event before DoWork() and
hence always kicks off the "ThreadController active" trace event
prior to DoWork(). On platforms that don't do this, the tasks nested
backwards (and the ends were out of order which messed up the trace
layout).

Also cover DidRunTask() now to cover microtasks and added extra brackets
to make it extra clear what the scope of "things we do to run the task"
are.

R=altimin@chromium.org

Bug: 899897, 1074019
Change-Id: I67a01853365e173ed924513592191d6098a4f621
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2536998
Commit-Queue: Gabriel Charette <gab@chromium.org>
Reviewed-by: Alexander Timin <altimin@chromium.org>
Cr-Commit-Position: refs/heads/master@{#827482}

base/task/sequence_manager/thread_controller_impl.cc

@@ -181,26 +181,32 @@ void ThreadControllerImpl::DoWork(WorkType work_type) {
     if (!task)
       break;
 
-    // Trace-parsing tools (DevTools, Lighthouse, etc) consume this event
-    // to determine long tasks.
-    // The event scope must span across DidRunTask call below to make sure
-    // it covers RunMicrotasks event.
-    // See https://crbug.com/681863 and https://crbug.com/874982
-    TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("devtools.timeline"), "RunTask");
-
+    // [OnTaskStarted(), OnTaskEnded()] must outscope all other tracing calls
+    // so that the "ThreadController active" trace event lives on top of all
+    // "run task" events. It must also encompass DidRunTask() to cover
+    // microtasks.
+    DCHECK_GT(main_sequence_only().run_level_tracker.num_run_levels(), 0U);
+    main_sequence_only().run_level_tracker.OnTaskStarted();
     {
-      // Trace events should finish before we call DidRunTask to ensure that
-      // SequenceManager trace events do not interfere with them.
-      TRACE_TASK_EXECUTION("ThreadControllerImpl::RunTask", *task);
-      DCHECK_GT(main_sequence_only().run_level_tracker.num_run_levels(), 0U);
-      main_sequence_only().run_level_tracker.OnTaskStarted();
-      task_annotator_.RunTask("SequenceManager RunTask", task);
-      if (!weak_ptr)
-        return;
-      main_sequence_only().run_level_tracker.OnTaskEnded();
+      // Trace-parsing tools (DevTools, Lighthouse, etc) consume this event
+      // to determine long tasks.
+      // The event scope must span across DidRunTask call below to make sure
+      // it covers RunMicrotasks event.
+      // See https://crbug.com/681863 and https://crbug.com/874982
+      TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("devtools.timeline"), "RunTask");
+
+      {
+        // Trace events should finish before we call DidRunTask to ensure that
+        // SequenceManager trace events do not interfere with them.
+        TRACE_TASK_EXECUTION("ThreadControllerImpl::RunTask", *task);
+        task_annotator_.RunTask("SequenceManager RunTask", task);
+        if (!weak_ptr)
+          return;
+      }
+
+      sequence_->DidRunTask();
     }
-
-    sequence_->DidRunTask();
+    main_sequence_only().run_level_tracker.OnTaskEnded();
 
     // NOTE: https://crbug.com/828835.
     // When we're running inside a nested RunLoop it may quit anytime, so any

base/task/sequence_manager/thread_controller_with_message_pump_impl.cc

@@ -332,37 +332,43 @@ TimeDelta ThreadControllerWithMessagePumpImpl::DoWorkImpl(
     if (!task)
       break;
 
-    // Execute the task and assume the worst: it is probably not reentrant.
-    main_thread_only().task_execution_allowed = false;
-
     work_id_provider_->IncrementWorkId();
 
-    // Trace-parsing tools (DevTools, Lighthouse, etc) consume this event
-    // to determine long tasks.
-    // The event scope must span across DidRunTask call below to make sure
-    // it covers RunMicrotasks event.
-    // See https://crbug.com/681863 and https://crbug.com/874982
-    TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("devtools.timeline"), "RunTask");
-
+    // [OnTaskStarted(), OnTaskEnded()] must outscope all other tracing calls
+    // so that the "ThreadController active" trace event lives on top of all
+    // "run task" events. It must also encompass DidRunTask() to cover
+    // microtasks.
+    main_thread_only().run_level_tracker.OnTaskStarted();
     {
-      // Trace events should finish before we call DidRunTask to ensure that
-      // SequenceManager trace events do not interfere with them.
-      TRACE_TASK_EXECUTION("ThreadControllerImpl::RunTask", *task);
-      main_thread_only().run_level_tracker.OnTaskStarted();
-      task_annotator_.RunTask("SequenceManager RunTask", task);
-      main_thread_only().run_level_tracker.OnTaskEnded();
-    }
+      // Execute the task and assume the worst: it is probably not reentrant.
+      main_thread_only().task_execution_allowed = false;
+
+      // Trace-parsing tools (DevTools, Lighthouse, etc) consume this event
+      // to determine long tasks.
+      // The event scope must span across DidRunTask call below to make sure
+      // it covers RunMicrotasks event.
+      // See https://crbug.com/681863 and https://crbug.com/874982
+      TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("devtools.timeline"), "RunTask");
+
+      {
+        // Trace events should finish before we call DidRunTask to ensure that
+        // SequenceManager trace events do not interfere with them.
+        TRACE_TASK_EXECUTION("ThreadControllerImpl::RunTask", *task);
+        task_annotator_.RunTask("SequenceManager RunTask", task);
+      }
 
 #if DCHECK_IS_ON()
-    if (log_runloop_quit_and_quit_when_idle_ && !quit_when_idle_requested_ &&
-        ShouldQuitWhenIdle()) {
-      DVLOG(1) << "ThreadControllerWithMessagePumpImpl::QuitWhenIdle";
-      quit_when_idle_requested_ = true;
-    }
+      if (log_runloop_quit_and_quit_when_idle_ && !quit_when_idle_requested_ &&
+          ShouldQuitWhenIdle()) {
+        DVLOG(1) << "ThreadControllerWithMessagePumpImpl::QuitWhenIdle";
+        quit_when_idle_requested_ = true;
+      }
 #endif
 
-    main_thread_only().task_execution_allowed = true;
-    main_thread_only().task_source->DidRunTask();
+      main_thread_only().task_execution_allowed = true;
+      main_thread_only().task_source->DidRunTask();
+    }
+    main_thread_only().run_level_tracker.OnTaskEnded();
 
     // When Quit() is called we must stop running the batch because the caller
     // expects per-task granularity.