Trace PostTasks from post to run

base/threading/sequenced_worker_pool.cc

 // Copyright (c) 2012 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/threading/sequenced_worker_pool.h"
 
 #include <list>
 #include <map>
 #include <set>
 #include <utility>
 #include <vector>
 
 #include "base/atomicops.h"
 #include "base/callback.h"
 #include "base/compiler_specific.h"
 #include "base/critical_closure.h"
+#include "base/debug/trace_event.h"
 #include "base/logging.h"
 #include "base/memory/linked_ptr.h"
 #include "base/message_loop_proxy.h"
 #include "base/metrics/histogram.h"
 #include "base/stl_util.h"
 #include "base/stringprintf.h"
 #include "base/synchronization/condition_variable.h"
 #include "base/synchronization/lock.h"
 #include "base/threading/platform_thread.h"
 #include "base/threading/simple_thread.h"
 #include "base/threading/thread_restrictions.h"
 #include "base/time.h"
 #include "base/tracked_objects.h"
 
 #if defined(OS_MACOSX)
 #include "base/mac/scoped_nsautorelease_pool.h"
 #endif
 
 namespace base {
 
 namespace {
 
 struct SequencedTask : public TrackingInfo  {
   SequencedTask()
       : sequence_token_id(0),
+        trace_id(0),
         shutdown_behavior(SequencedWorkerPool::BLOCK_SHUTDOWN) {}
 
   explicit SequencedTask(const tracked_objects::Location& from_here)
       : base::TrackingInfo(from_here, TimeTicks()),
         sequence_token_id(0),
+        trace_id(0),
         shutdown_behavior(SequencedWorkerPool::BLOCK_SHUTDOWN) {}
 
   ~SequencedTask() {}
 
   int sequence_token_id;
+  int trace_id;
   SequencedWorkerPool::WorkerShutdown shutdown_behavior;
   tracked_objects::Location posted_from;
   Closure task;
 };
 
 // SequencedWorkerPoolTaskRunner ---------------------------------------------
 // A TaskRunner which posts tasks to a SequencedWorkerPool with a
 // fixed ShutdownBehavior.
 //
 // Note that this class is RefCountedThreadSafe (inherited from TaskRunner).
@@ skipping 139 matching lines @@
     TimeDelta delay) {
   // TODO(francoisk777@gmail.com): Change the following two statements once
   // SequencedWorkerPool supports non-zero delays.
   DCHECK_EQ(delay.InMillisecondsRoundedUp(), 0)
       << "SequencedWorkerPoolSequencedTaskRunner does not yet support non-zero"
          " delays";
   return pool_->PostSequencedWorkerTaskWithShutdownBehavior(
       token_, from_here, task, shutdown_behavior_);
 }
 
+// Create a process-wide unique ID to represent this task in trace events. This
+// will be mangled with a Process ID hash to reduce the likelyhood of colliding
+// with MessageLoop pointers on other processes.
+uint64 GetTaskTraceID(const SequencedTask& task,
+                      void* pool) {
+  return (static_cast<uint64>(task.trace_id) << 32) |
+         static_cast<uint64>(reinterpret_cast<intptr_t>(pool));
+}
+
 }  // namespace
 
 // Worker ---------------------------------------------------------------------
 
 class SequencedWorkerPool::Worker : public SimpleThread {
  public:
   // Hold a (cyclic) ref to |worker_pool|, since we want to keep it
   // around as long as we are running.
   Worker(const scoped_refptr<SequencedWorkerPool>& worker_pool,
          int thread_number,
@@ skipping 168 matching lines @@
   std::list<SequencedTask> pending_tasks_;
   size_t pending_task_count_;
 
   // Number of tasks in the pending_tasks_ list that are marked as blocking
   // shutdown.
   size_t blocking_shutdown_pending_task_count_;
 
   // Lists all sequence tokens currently executing.
   std::set<int> current_sequences_;
 
+  // An ID for each posted task to distinguish the task from others in traces.
+  int trace_id_;
+
   // Set when Shutdown is called and no further tasks should be
   // allowed, though we may still be running existing tasks.
   bool shutdown_called_;
 
   TestingObserver* const testing_observer_;
 
   DISALLOW_COPY_AND_ASSIGN(Inner);
 };
 
 // Worker definitions ---------------------------------------------------------
@@ skipping 35 matching lines @@
       has_work_cv_(&lock_),
       is_idle_cv_(&lock_),
       can_shutdown_cv_(&lock_),
       max_threads_(max_threads),
       thread_name_prefix_(thread_name_prefix),
       thread_being_created_(false),
       waiting_thread_count_(0),
       blocking_shutdown_thread_count_(0),
       pending_task_count_(0),
       blocking_shutdown_pending_task_count_(0),
+      trace_id_(0),
       shutdown_called_(false),
       testing_observer_(observer) {}
 
 SequencedWorkerPool::Inner::~Inner() {
   // You must call Shutdown() before destroying the pool.
   DCHECK(shutdown_called_);
 
   // Need to explicitly join with the threads before they're destroyed or else
   // they will be running when our object is half torn down.
   for (ThreadMap::iterator it = threads_.begin(); it != threads_.end(); ++it)
@@ skipping 30 matching lines @@
   sequenced.task =
       shutdown_behavior == BLOCK_SHUTDOWN ?
       base::MakeCriticalClosure(task) : task;
 
   int create_thread_id = 0;
   {
     AutoLock lock(lock_);
     if (shutdown_called_)
       return false;
 
+    // The trace_id is used for identifying the task in about:tracing.
+    sequenced.trace_id = trace_id_++;
+
+    TRACE_EVENT_FLOW_BEGIN0("task", "SequencedWorkerPool::PostTask",
+        TRACE_ID_MANGLE(GetTaskTraceID(sequenced, static_cast<void*>(this))));
+
     // Now that we have the lock, apply the named token rules.
     if (optional_token_name)
       sequenced.sequence_token_id = LockedGetNamedTokenID(*optional_token_name);
 
     pending_tasks_.push_back(sequenced);
     pending_task_count_++;
     if (shutdown_behavior == BLOCK_SHUTDOWN)
       blocking_shutdown_pending_task_count_++;
 
     create_thread_id = PrepareToStartAdditionalThreadIfHelpful();
@@ skipping 84 matching lines @@
 
     while (true) {
 #if defined(OS_MACOSX)
       base::mac::ScopedNSAutoreleasePool autorelease_pool;
 #endif
 
       // See GetWork for what delete_these_outside_lock is doing.
       SequencedTask task;
       std::vector<Closure> delete_these_outside_lock;
       if (GetWork(&task, &delete_these_outside_lock)) {
+        TRACE_EVENT_FLOW_END0("task", "SequencedWorkerPool::PostTask",
+            TRACE_ID_MANGLE(GetTaskTraceID(task, static_cast<void*>(this))));
+        TRACE_EVENT2("task", "SequencedWorkerPool::ThreadLoop",
+                     "src_file", task.posted_from.file_name(),
+                     "src_func", task.posted_from.function_name());
         int new_thread_id = WillRunWorkerTask(task);
         {
           AutoUnlock unlock(lock_);
           // There may be more work available, so wake up another
           // worker thread. (Technically not required, since we
           // already get a signal for each new task, but it doesn't
           // hurt.)
           SignalHasWork();
           delete_these_outside_lock.clear();
 
@@ skipping 397 matching lines @@
 void SequencedWorkerPool::SignalHasWorkForTesting() {
   inner_->SignalHasWorkForTesting();
 }
 
 void SequencedWorkerPool::Shutdown() {
   DCHECK(constructor_message_loop_->BelongsToCurrentThread());
   inner_->Shutdown();
 }
 
 }  // namespace base