Revert 107895 - Fully enable about:tracking by default

This is a re-land of:
http://codereview.chromium.org/8391019/
Committed: http://src.chromium.org/viewvc/chrome?view=rev&revision=107793

Original landing had trouble with message_loop_x.h, due to header
include ordering.  I pulled out the structure that was really needed by
tracked_objects.h into a new file tracked_info.*.  This allows tracked_objects
to inlude this tracked_info, but not have to include the message_loop.h
totality.  I also removed a DCHECK that that was triggering on a test,
and added yet one more file (browser_main.cc) where I removed a #ifdef
for TRACKING_ALL_OBJECTS.  The changes were minor, and I'm hoping to get
clear perf runs with tihs landing, so I'm going to TBR it and reland
early in the morning.



Comments from original landing:

Support is now controlled by the flag:
--enable-tracking
and the default is always on. To turn it off, use:
--enable-tracking=0

All profiler code is compiled now in release and official
builds (in addition to debug, where it was already active),
but most entry points can be disabled (turned into no-ops) 
by a single const bool setting atop tracked_objects.cc (in 
case folks want to revert the perf-impact of this change).

Transition to faster Now() service on Windows for the 
profiler use only.
The TimeTicks::Now() function on Window uses locking
to get a 64 bit time value. This CL transitions 
times used for profiling to more directly use a
32 bit Time interface, which is actually what drives the
64 bit TimeTicks. By using the smaller value, we avoid 
the need for locks, or even atomic operations for the most
part in the tracking system. On linux, we just down-sample
the standard TimeTicks to 32 bits for consistency (clean
ability to snapshot asyncronously without atomics...
but I should verify that such is helpful to performance).

I've also put in yet more cleanup and refactoring.

tbr=rtenneti
bug=101856
Review URL: http://codereview.chromium.org/8414036

TBR=jar@chromium.org
Review URL: http://codereview.chromium.org/8430004

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@107961 0039d316-1c4b-4281-b951-d872f2087c98

1 files changed, 131 insertions, 177 deletions

diff --git a/base/tracked_objects.cc b/base/tracked_objects.cc
index 470d157..dfb88eb 100644
--- a/base/tracked_objects.cc
+++ b/base/tracked_objects.cc
@@ -16,43 +16,52 @@ using base::TimeDelta;
 
 namespace tracked_objects {
 
-namespace {
-// Flag to compile out almost all of the task tracking code.
+
+#if defined(TRACK_ALL_TASK_OBJECTS)
 static const bool kTrackAllTaskObjects = true;
+#else
+static const bool kTrackAllTaskObjects = false;
+#endif
+
+// Can we count on thread termination to call for thread cleanup?  If not, then
+// we can't risk putting references to ThreadData in TLS, as it will leak on
+// worker thread termination.
+static const bool kWorkerThreadCleanupSupported = true;
 
-// When ThreadData is first initialized, should we start in an ACTIVE state to
-// record all of the startup-time tasks, or should we start up DEACTIVATED, so
-// that we only record after parsing the command line flag --enable-tracking.
-// Note that the flag may force either state, so this really controls only the
-// period of time up until that flag is parsed. If there is no flag seen, then
-// this state may prevail for much or all of the process lifetime.
-static const ThreadData::Status kInitialStartupState = ThreadData::ACTIVE;
-}  // anonymous namespace.
+// A TLS slot which points to the ThreadData instance for the current thread. We
+// do a fake initialization here (zeroing out data), and then the real in-place
+// construction happens when we call tls_index_.Initialize().
+// static
+base::ThreadLocalStorage::Slot ThreadData::tls_index_(base::LINKER_INITIALIZED);
+
+// A global state variable to prevent repeated initialization during tests.
+// static
+AutoTracking::State AutoTracking::state_ = AutoTracking::kNeverBeenRun;
+
+// A locked protected counter to assign sequence number to threads.
+// static
+int ThreadData::thread_number_counter_ = 0;
 
 //------------------------------------------------------------------------------
 // Death data tallies durations when a death takes place.
 
-void DeathData::RecordDeath(const Duration& queue_duration,
-                            const Duration& run_duration) {
+void DeathData::RecordDeath(const TimeDelta& queue_duration,
+                            const TimeDelta& run_duration) {
   ++count_;
   queue_duration_ += queue_duration;
   run_duration_ += run_duration;
 }
 
 int DeathData::AverageMsRunDuration() const {
-  if (run_duration_ == Duration() || !count_)
+  if (run_duration_ == base::TimeDelta())
     return 0;
-  // Add half of denominator to achieve rounding.
-  return static_cast<int>(run_duration_.InMilliseconds() + count_ / 2) /
-      count_;
+  return static_cast<int>(run_duration_.InMilliseconds() / count_);
 }
 
 int DeathData::AverageMsQueueDuration() const {
-  if (queue_duration_ == Duration() || !count_)
+  if (queue_duration_ == base::TimeDelta())
     return 0;
-  // Add half of denominator to achieve rounding.
-  return (static_cast<int>(queue_duration_.InMilliseconds() + count_ / 2) /
-      count_);
+  return static_cast<int>(queue_duration_.InMilliseconds() / count_);
 }
 
 void DeathData::AddDeathData(const DeathData& other) {
@@ -66,14 +75,11 @@ void DeathData::WriteHTML(std::string* output) const {
     return;
   base::StringAppendF(output, "%s:%d, ",
                       (count_ == 1) ? "Life" : "Lives", count_);
-  // Be careful to leave static_casts intact, as the type returned by
-  // InMilliseconds() may not always be an int, even if it can generally fit
-  // into an int.
-  base::StringAppendF(output, "Run:%dms(%dms/life) ",
-                      static_cast<int>(run_duration_.InMilliseconds()),
+  base::StringAppendF(output, "Run:%"PRId64"ms(%dms/life) ",
+                      run_duration_.InMilliseconds(),
                       AverageMsRunDuration());
-  base::StringAppendF(output, "Queue:%dms(%dms/life) ",
-                      static_cast<int>(queue_duration_.InMilliseconds()),
+  base::StringAppendF(output, "Queue:%"PRId64"ms(%dms/life) ",
+                      queue_duration_.InMilliseconds(),
                       AverageMsQueueDuration());
 }
 
@@ -89,8 +95,8 @@ base::DictionaryValue* DeathData::ToValue() const {
 
 void DeathData::Clear() {
   count_ = 0;
-  queue_duration_ = Duration();
-  run_duration_ = Duration();
+  queue_duration_ = TimeDelta();
+  run_duration_ = TimeDelta();
 }
 
 //------------------------------------------------------------------------------
@@ -107,20 +113,6 @@ Births::Births(const Location& location, const ThreadData& current)
 //------------------------------------------------------------------------------
 // ThreadData maintains the central data for all births and deaths.
 
-// TODO(jar): We should pull all these static vars together, into a struct, and
-// optimize layout so that we benefit from locality of reference during accesses
-// to them.
-
-// A TLS slot which points to the ThreadData instance for the current thread. We
-// do a fake initialization here (zeroing out data), and then the real in-place
-// construction happens when we call tls_index_.Initialize().
-// static
-base::ThreadLocalStorage::Slot ThreadData::tls_index_(base::LINKER_INITIALIZED);
-
-// A lock-protected counter to assign sequence number to threads.
-// static
-int ThreadData::thread_number_counter_ = 0;
-
 // static
 ThreadData* ThreadData::all_thread_data_list_head_ = NULL;
 
@@ -128,7 +120,7 @@ ThreadData* ThreadData::all_thread_data_list_head_ = NULL;
 ThreadData::ThreadDataPool* ThreadData::unregistered_thread_data_pool_ = NULL;
 
 // static
-base::Lock* ThreadData::list_lock_;
+base::Lock ThreadData::list_lock_;
 
 // static
 ThreadData::Status ThreadData::status_ = ThreadData::UNINITIALIZED;
@@ -144,7 +136,7 @@ ThreadData::ThreadData(const std::string& suggested_name)
 ThreadData::ThreadData() : next_(NULL), is_a_worker_thread_(true) {
   int thread_number;
   {
-    base::AutoLock lock(*list_lock_);
+    base::AutoLock lock(list_lock_);
     thread_number = ++thread_number_counter_;
   }
   base::StringAppendF(&thread_name_, "WorkerThread-%d", thread_number);
@@ -155,20 +147,17 @@ ThreadData::~ThreadData() {}
 
 void ThreadData::PushToHeadOfList() {
   DCHECK(!next_);
-  base::AutoLock lock(*list_lock_);
+  base::AutoLock lock(list_lock_);
   next_ = all_thread_data_list_head_;
   all_thread_data_list_head_ = this;
 }
 
 // static
 void ThreadData::InitializeThreadContext(const std::string& suggested_name) {
-  if (!Initialize())  // Always initialize if needed.
-    return;
-  ThreadData* current_thread_data =
-      reinterpret_cast<ThreadData*>(tls_index_.Get());
-  if (current_thread_data)
-    return;  // Browser tests instigate this.
-  current_thread_data = new ThreadData(suggested_name);
+  if (!tls_index_.initialized())
+    return;  // For unittests only.
+  DCHECK_EQ(tls_index_.Get(), reinterpret_cast<void*>(NULL));
+  ThreadData* current_thread_data = new ThreadData(suggested_name);
   tls_index_.Set(current_thread_data);
 }
 
@@ -183,7 +172,7 @@ ThreadData* ThreadData::Get() {
   // We must be a worker thread, since we didn't pre-register.
   ThreadData* worker_thread_data = NULL;
   {
-    base::AutoLock lock(*list_lock_);
+    base::AutoLock lock(list_lock_);
     if (!unregistered_thread_data_pool_->empty()) {
       worker_thread_data =
         const_cast<ThreadData*>(unregistered_thread_data_pool_->top());
@@ -214,13 +203,13 @@ void ThreadData::OnThreadTerminationCleanup() const {
   tls_index_.Set(NULL);
   if (!is_a_worker_thread_)
     return;
-  base::AutoLock lock(*list_lock_);
+  base::AutoLock lock(list_lock_);
   unregistered_thread_data_pool_->push(this);
 }
 
 // static
 void ThreadData::WriteHTML(const std::string& query, std::string* output) {
-  if (!ThreadData::tracking_status())
+  if (!ThreadData::IsActive())
     return;  // Not yet initialized.
 
   DataCollector collected_data;  // Gather data.
@@ -327,12 +316,13 @@ void ThreadData::WriteHTMLTotalAndSubtotals(
 }
 
 // static
-base::DictionaryValue* ThreadData::ToValue() {
+base::Value* ThreadData::ToValue(int process_type) {
   DataCollector collected_data;  // Gather data.
   collected_data.AddListOfLivingObjects();  // Add births that are still alive.
   base::ListValue* list = collected_data.ToValue();
   base::DictionaryValue* dictionary = new base::DictionaryValue();
   dictionary->Set("list", list);
+  dictionary->SetInteger("process", process_type);
   return dictionary;
 }
 
@@ -352,8 +342,8 @@ Births* ThreadData::TallyABirth(const Location& location) {
 }
 
 void ThreadData::TallyADeath(const Births& birth,
-                             const Duration& queue_duration,
-                             const Duration& run_duration) {
+                             const TimeDelta& queue_duration,
+                             const TimeDelta& run_duration) {
   DeathMap::iterator it = death_map_.find(&birth);
   DeathData* death_data;
   if (it != death_map_.end()) {
@@ -370,7 +360,7 @@ Births* ThreadData::TallyABirthIfActive(const Location& location) {
   if (!kTrackAllTaskObjects)
     return NULL;  // Not compiled in.
 
-  if (!tracking_status())
+  if (!IsActive())
     return NULL;
   ThreadData* current_thread_data = Get();
   if (!current_thread_data)
@@ -379,74 +369,37 @@ Births* ThreadData::TallyABirthIfActive(const Location& location) {
 }
 
 // static
-void ThreadData::TallyRunOnNamedThreadIfTracking(
-    const base::TrackingInfo& completed_task,
-    const TrackedTime& start_of_run,
-    const TrackedTime& end_of_run) {
+void ThreadData::TallyADeathIfActive(const Births* birth,
+                                     const base::TimeTicks& time_posted,
+                                     const base::TimeTicks& delayed_start_time,
+                                     const base::TimeTicks& start_of_run,
+                                     const base::TimeTicks& end_of_run) {
   if (!kTrackAllTaskObjects)
     return;  // Not compiled in.
 
-  // Even if we have been DEACTIVATED, we will process any pending births so
-  // that our data structures (which counted the outstanding births) remain
-  // consistent.
-  const Births* birth = completed_task.birth_tally;
-  if (!birth)
+  if (!IsActive() || !birth)
     return;
+
   ThreadData* current_thread_data = Get();
   if (!current_thread_data)
     return;
 
   // To avoid conflating our stats with the delay duration in a PostDelayedTask,
   // we identify such tasks, and replace their post_time with the time they
-  // were scheduled (requested?) to emerge from the delayed task queue. This
+  // were sechudled (requested?) to emerge from the delayed task queue. This
   // means that queueing delay for such tasks will show how long they went
   // unserviced, after they *could* be serviced.  This is the same stat as we
   // have for non-delayed tasks, and we consistently call it queueing delay.
-  TrackedTime effective_post_time = completed_task.delayed_run_time.is_null()
-      ? tracked_objects::TrackedTime(completed_task.time_posted)
-      : tracked_objects::TrackedTime(completed_task.delayed_run_time);
-
-  Duration queue_duration = start_of_run - effective_post_time;
-  Duration run_duration = end_of_run - start_of_run;
-  current_thread_data->TallyADeath(*birth, queue_duration, run_duration);
-}
-
-// static
-void ThreadData::TallyRunOnWorkerThreadIfTracking(
-    const Births* birth,
-    const TrackedTime& time_posted,
-    const TrackedTime& start_of_run,
-    const TrackedTime& end_of_run) {
-  if (!kTrackAllTaskObjects)
-    return;  // Not compiled in.
-
-  // Even if we have been DEACTIVATED, we will process any pending births so
-  // that our data structures (which counted the outstanding births) remain
-  // consistent.
-  if (!birth)
-    return;
-
-  // TODO(jar): Support the option to coalesce all worker-thread activity under
-  // one ThreadData instance that uses locks to protect *all* access.  This will
-  // reduce memory (making it provably bounded), but run incrementally slower
-  // (since we'll use locks on TallyBirth and TallyDeath).  The good news is
-  // that the locks on TallyDeath will be *after* the worker thread has run, and
-  // hence nothing will be waiting for the completion (... besides some other
-  // thread that might like to run).  Also, the worker threads tasks are
-  // generally longer, and hence the cost of the lock may perchance be amortized
-  // over the long task's lifetime.
-  ThreadData* current_thread_data = Get();
-  if (!current_thread_data)
-    return;
-
-  Duration queue_duration = start_of_run - time_posted;
-  Duration run_duration = end_of_run - start_of_run;
+  base::TimeTicks effective_post_time =
+      (delayed_start_time.is_null()) ? time_posted : delayed_start_time;
+  base::TimeDelta queue_duration = start_of_run - effective_post_time;
+  base::TimeDelta run_duration = end_of_run - start_of_run;
   current_thread_data->TallyADeath(*birth, queue_duration, run_duration);
 }
 
 // static
 ThreadData* ThreadData::first() {
-  base::AutoLock lock(*list_lock_);
+  base::AutoLock lock(list_lock_);
   return all_thread_data_list_head_;
 }
 
@@ -486,47 +439,52 @@ void ThreadData::Reset() {
     it->second->Clear();
 }
 
-bool ThreadData::Initialize() {
+// static
+bool ThreadData::StartTracking(bool status) {
   if (!kTrackAllTaskObjects)
     return false;  // Not compiled in.
-  if (status_ != UNINITIALIZED)
-    return true;
-  // Initialize all leaking constants that are difficult to toggle in and out
-  // of existance.
-  // First call must be made when single threaded at startup.
-  // Perform the "real" TLS initialization now, and leave it intact through
+
+  // Do a bit of class initialization.
+  if (!unregistered_thread_data_pool_) {
+    ThreadDataPool* initial_pool = new ThreadDataPool;
+    {
+      base::AutoLock lock(list_lock_);
+      if (!unregistered_thread_data_pool_) {
+        unregistered_thread_data_pool_ = initial_pool;
+        initial_pool = NULL;
+      }
+    }
+    delete initial_pool;  // In case it was not used.
+  }
+
+  // Perform the "real" initialization now, and leave it intact through
   // process termination.
-  if (!tls_index_.initialized())  // Testing may have initialized this.
+  if (!tls_index_.initialized())
     tls_index_.Initialize(&ThreadData::OnThreadTermination);
   DCHECK(tls_index_.initialized());
-  unregistered_thread_data_pool_ = new ThreadDataPool;
-  // TODO(jar): A linker initialized spin lock would be much safer than this
-  // allocation, which relies on being called while single threaded.
-  if (!list_lock_)  // In case testing deleted this.
-    list_lock_ = new base::Lock;
-  status_ = kInitialStartupState;
-  return true;
-}
 
-// static
-bool ThreadData::InitializeAndSetTrackingStatus(bool status) {
-  if (!Initialize())  // No-op if already initialized.
-    return false;  // Not compiled in.
-
-  status_ = status ? ACTIVE : DEACTIVATED;
+  if (!status) {
+    base::AutoLock lock(list_lock_);
+    DCHECK(status_ == ACTIVE || status_ == SHUTDOWN);
+    status_ = SHUTDOWN;
+    return true;
+  }
+  base::AutoLock lock(list_lock_);
+  DCHECK_EQ(UNINITIALIZED, status_);
+  status_ = ACTIVE;
   return true;
 }
 
 // static
-bool ThreadData::tracking_status() {
+bool ThreadData::IsActive() {
   return status_ == ACTIVE;
 }
 
 // static
-TrackedTime ThreadData::Now() {
-  if (!kTrackAllTaskObjects || status_ != ACTIVE)
-    return TrackedTime();  // Super fast when disabled, or not compiled.
-  return TrackedTime::Now();
+base::TimeTicks ThreadData::Now() {
+  if (kTrackAllTaskObjects && status_ == ACTIVE)
+    return base::TimeTicks::Now();
+  return base::TimeTicks();  // Super fast when disabled, or not compiled in.
 }
 
 // static
@@ -534,12 +492,12 @@ void ThreadData::ShutdownSingleThreadedCleanup() {
   // This is only called from test code, where we need to cleanup so that
   // additional tests can be run.
   // We must be single threaded... but be careful anyway.
-  if (!InitializeAndSetTrackingStatus(false))
+  if (!StartTracking(false))
     return;
   ThreadData* thread_data_list;
   ThreadDataPool* final_pool;
   {
-    base::AutoLock lock(*list_lock_);
+    base::AutoLock lock(list_lock_);
     thread_data_list = all_thread_data_list_head_;
     all_thread_data_list_head_ = NULL;
     final_pool = unregistered_thread_data_pool_;
@@ -616,12 +574,16 @@ base::DictionaryValue* Snapshot::ToValue() const {
   return dictionary;
 }
 
+void Snapshot::Add(const Snapshot& other) {
+  death_data_.AddDeathData(other.death_data_);
+}
+
 //------------------------------------------------------------------------------
 // DataCollector
 
 DataCollector::DataCollector() {
-  if (!kTrackAllTaskObjects)
-    return;  // Not compiled in.
+  if (!ThreadData::IsActive())
+    return;
 
   // Get an unchanging copy of a ThreadData list.
   ThreadData* my_list = ThreadData::first();
@@ -778,35 +740,6 @@ void Comparator::Clear() {
   selector_ = NIL;
 }
 
-// static
-Comparator::Selector Comparator::FindSelector(const std::string& keyword) {
-  // Sorting and aggretation keywords, which specify how to sort the data, or
-  // can specify a required match from the specified field in the record.
-  if (0 == keyword.compare("count"))
-    return COUNT;
-  if (0 == keyword.compare("totalduration"))
-    return TOTAL_RUN_DURATION;
-  if (0 == keyword.compare("duration"))
-    return AVERAGE_RUN_DURATION;
-  if (0 == keyword.compare("totalqueueduration"))
-    return TOTAL_QUEUE_DURATION;
-  if (0 == keyword.compare("averagequeueduration"))
-    return AVERAGE_QUEUE_DURATION;
-  if (0 == keyword.compare("birth"))
-    return BIRTH_THREAD;
-  if (0 == keyword.compare("death"))
-    return DEATH_THREAD;
-  if (0 == keyword.compare("file"))
-    return BIRTH_FILE;
-  if (0 == keyword.compare("function"))
-    return BIRTH_FUNCTION;
-  if (0 == keyword.compare("line"))
-    return BIRTH_LINE;
-  if (0 == keyword.compare("reset"))
-    return RESET_ALL_DATA;
-  return UNKNOWN_KEYWORD;
-}
-
 bool Comparator::operator()(const Snapshot& left,
                             const Snapshot& right) const {
   switch (selector_) {
@@ -1023,6 +956,28 @@ void Comparator::SetSubgroupTiebreaker(Selector selector) {
 }
 
 void Comparator::ParseKeyphrase(const std::string& key_phrase) {
+  typedef std::map<const std::string, Selector> KeyMap;
+  static KeyMap key_map;
+  static bool initialized = false;
+  if (!initialized) {
+    initialized = true;
+    // Sorting and aggretation keywords, which specify how to sort the data, or
+    // can specify a required match from the specified field in the record.
+    key_map["count"]                = COUNT;
+    key_map["totalduration"]        = TOTAL_RUN_DURATION;
+    key_map["duration"]             = AVERAGE_RUN_DURATION;
+    key_map["totalqueueduration"]   = TOTAL_QUEUE_DURATION;
+    key_map["averagequeueduration"] = AVERAGE_QUEUE_DURATION;
+    key_map["birth"]                = BIRTH_THREAD;
+    key_map["death"]                = DEATH_THREAD;
+    key_map["file"]                 = BIRTH_FILE;
+    key_map["function"]             = BIRTH_FUNCTION;
+    key_map["line"]                 = BIRTH_LINE;
+
+    // Immediate commands that do not involve setting sort order.
+    key_map["reset"]     = RESET_ALL_DATA;
+  }
+
   std::string required;
   // Watch for: "sort_key=value" as we parse.
   size_t equal_offset = key_phrase.find('=', 0);
@@ -1032,14 +987,13 @@ void Comparator::ParseKeyphrase(const std::string& key_phrase) {
   }
   std::string keyword(key_phrase.substr(0, equal_offset));
   keyword = StringToLowerASCII(keyword);
-  Selector selector = FindSelector(keyword);
-  if (selector == UNKNOWN_KEYWORD)
-    return;
-  if (selector == RESET_ALL_DATA) {
+  KeyMap::iterator it = key_map.find(keyword);
+  if (key_map.end() == it)
+    return;  // Unknown keyword.
+  if (it->second == RESET_ALL_DATA)
     ThreadData::ResetAllThreadData();
-    return;
-  }
-  SetTiebreaker(selector, required);
+  else
+    SetTiebreaker(key_map[keyword], required);
 }
 
 bool Comparator::ParseQuery(const std::string& query) {