Add a task_scheduler tracing category which will record an extra event per task.

base/task_scheduler/task_tracker.cc

 // Copyright 2016 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "base/task_scheduler/task_tracker.h"
 
 #include <limits>
 
 #include "base/callback.h"
 #include "base/debug/task_annotator.h"
+#include "base/json/json_writer.h"
 #include "base/logging.h"
+#include "base/memory/ptr_util.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/sequence_token.h"
 #include "base/synchronization/condition_variable.h"
 #include "base/threading/sequenced_task_runner_handle.h"
 #include "base/threading/thread_restrictions.h"
 #include "base/threading/thread_task_runner_handle.h"
 #include "base/trace_event/trace_event.h"
+#include "base/values.h"
 
 namespace base {
 namespace internal {
 
 namespace {
 
+// An immutable copy of a scheduler task's info required by tracing.
+class TaskTracingInfo : public trace_event::ConvertableToTraceFormat {
+ public:
+  TaskTracingInfo(const TaskTraits& task_traits,
+                  ExecutionMode execution_mode,
+                  const SequenceToken& sequence_token)
+      : task_traits_(task_traits),
+        execution_mode_(execution_mode),
+        sequence_token_(sequence_token) {}
+
+  // Overridden from trace_event::ConvertableToTraceFormat:
+  void AppendAsTraceFormat(std::string* out) const override;
+
+ private:
+  const TaskTraits task_traits_;
+  const ExecutionMode execution_mode_;
+  const SequenceToken sequence_token_;
+
+  DISALLOW_COPY_AND_ASSIGN(TaskTracingInfo);
+};
+
+void TaskTracingInfo::AppendAsTraceFormat(std::string* out) const {
+  DictionaryValue dict;
+
+  const char* priority_str = nullptr;
+  switch (task_traits_.priority()) {

[fdoray, 2016/10/05 12:39:40]

Add a char* ToString(TaskPriority priority) function in task_traits.h and use it
both here and in operator<<?

https://cs.chromium.org/chromium/src/base/task_scheduler/task_traits.h?l=134

[gab, 2016/10/05 20:12:43]

I had debated that and weakly opted against it, but now that you bring it up too
I agree that's better :-).

Except I didn't use "ToString()" as it's in base:: and a bit too generic with
that name.

+    case TaskPriority::BACKGROUND:
+      priority_str = "BACKGROUND";
+      break;
+    case TaskPriority::USER_VISIBLE:
+      priority_str = "USER_VISIBLE";
+      break;
+    case TaskPriority::USER_BLOCKING:
+      priority_str = "USER_BLOCKING";
+      break;
+  }
+  dict.SetString("TaskPriority", priority_str);
+
+  const char* execution_mode_str = nullptr;
+  switch (execution_mode_) {

[fdoray, 2016/10/05 12:39:40]

Same as above

[gab, 2016/10/05 20:12:43]

Done.

+    case ExecutionMode::PARALLEL:
+      execution_mode_str = "PARALLEL";
+      break;
+    case ExecutionMode::SEQUENCED:
+      execution_mode_str = "SEQUENCED";
+      break;
+    case ExecutionMode::SINGLE_THREADED:
+      execution_mode_str = "SINGLE_THREADED";
+      break;
+  }
+  dict.SetString("ExecutionMode", execution_mode_str);
+
+  if (execution_mode_ != ExecutionMode::PARALLEL)
+    dict.SetString("SequenceToken", sequence_token_.ToString());

[fdoray, 2016/10/05 12:39:40]

why not
dict.SetInteger("SequenceToken", sequence_token_.ToIntervalValue());

ToIntervalValue returns an int

[gab, 2016/10/05 20:12:43]

Great idea, done.

+
+  std::string tmp;
+  JSONWriter::Write(dict, &tmp);
+  out->append(tmp);
+}
+
 const char kQueueFunctionName[] = "base::PostTask";
 
 // This name conveys that a Task is run by the task scheduler without revealing
 // its implementation details.
 const char kRunFunctionName[] = "TaskSchedulerRunTask";
 
 // Upper bound for the
 // TaskScheduler.BlockShutdownTasksPostedDuringShutdown histogram.
 const HistogramBase::Sample kMaxBlockShutdownTasksPostedDuringShutdown = 1000;
 
@@ skipping 161 matching lines @@
       if (task->sequenced_task_runner_ref) {
         sequenced_task_runner_handle.reset(
             new SequencedTaskRunnerHandle(task->sequenced_task_runner_ref));
       } else if (task->single_thread_task_runner_ref) {
         single_thread_task_runner_handle.reset(
             new ThreadTaskRunnerHandle(task->single_thread_task_runner_ref));
       }
 
       TRACE_TASK_EXECUTION(kRunFunctionName, *task);
 
+      ExecutionMode execution_mode =

[fdoray, 2016/10/05 12:39:40]

const ExecutionMode execution_mode =

[gab, 2016/10/05 20:12:43]

Done.

+          task->single_thread_task_runner_ref
+              ? ExecutionMode::SINGLE_THREADED
+              : (task->sequenced_task_runner_ref ? ExecutionMode::SEQUENCED
+                                                 : ExecutionMode::PARALLEL);
+      // TODO(gab): In a better world this would be tacked on as an extra arg
+      // to the trace event generated above. This is not possible however until
+      // http://crbug.com/652692 is resolved.
+      TRACE_EVENT1("task_scheduler", "TaskTracker::RunTask", "task_info",
+                   MakeUnique<TaskTracingInfo>(
+                       task->traits, execution_mode, sequence_token));
+
       debug::TaskAnnotator task_annotator;
       task_annotator.RunTask(kQueueFunctionName, *task);
     }
 
     AfterRunTask(shutdown_behavior);
   }
 
   if (task->delayed_run_time.is_null())
     DecrementNumPendingUndelayedTasks();
 
@@ skipping 168 matching lines @@
       subtle::NoBarrier_AtomicIncrement(&num_pending_undelayed_tasks_, -1);
   DCHECK_GE(new_num_pending_undelayed_tasks, 0);
   if (new_num_pending_undelayed_tasks == 0) {
     AutoSchedulerLock auto_lock(flush_lock_);
     flush_cv_->Signal();
   }
 }
 
 }  // namespace internal
 }  // namespace base