Enable tracking of objects by default
This is a reland of accumulated patches including CLs
8414036, 8425010, 8425013, 8424013.
It fully enables tracking of objects, as seen in about:tracking
in teh release build.
The problem this had in its initaial landing centered on
Mac instability in base_unittest. We were encountering crash
on exit of the tests, with a stack dump involving pthreads.
r=rtenneti
BUG=101856
Review URL: http://codereview.chromium.org/8429009
git-svn-id: svn://svn.chromium.org/chrome/trunk/src@108026 0039d316-1c4b-4281-b951-d872f2087c98
CrOS-Libchrome-Original-Commit: b2a9bbd42c6d5215c43067582fa2bca3cfc5e20e
diff --git a/base/tracked_objects.cc b/base/tracked_objects.cc
index dfb88eb..7833129 100644
--- a/base/tracked_objects.cc
+++ b/base/tracked_objects.cc
@@ -11,57 +11,54 @@
#include "base/string_util.h"
#include "base/stringprintf.h"
#include "base/threading/thread_restrictions.h"
+#include "build/build_config.h"
using base::TimeDelta;
namespace tracked_objects {
-
-#if defined(TRACK_ALL_TASK_OBJECTS)
-static const bool kTrackAllTaskObjects = true;
-#else
+namespace {
+// Flag to compile out almost all of the task tracking code.
+#if defined(NDEBUG) && defined(OS_MAC)
+// Avoid problems with base_unittest crashes in Mac for now.
static const bool kTrackAllTaskObjects = false;
+#else
+static const bool kTrackAllTaskObjects = true;
#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;
-
-// 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;
+// 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.
//------------------------------------------------------------------------------
// Death data tallies durations when a death takes place.
-void DeathData::RecordDeath(const TimeDelta& queue_duration,
- const TimeDelta& run_duration) {
+void DeathData::RecordDeath(const Duration& queue_duration,
+ const Duration& run_duration) {
++count_;
queue_duration_ += queue_duration;
run_duration_ += run_duration;
}
int DeathData::AverageMsRunDuration() const {
- if (run_duration_ == base::TimeDelta())
+ if (run_duration_ == Duration() || !count_)
return 0;
- return static_cast<int>(run_duration_.InMilliseconds() / count_);
+ // Add half of denominator to achieve rounding.
+ return static_cast<int>(run_duration_.InMilliseconds() + count_ / 2) /
+ count_;
}
int DeathData::AverageMsQueueDuration() const {
- if (queue_duration_ == base::TimeDelta())
+ if (queue_duration_ == Duration() || !count_)
return 0;
- return static_cast<int>(queue_duration_.InMilliseconds() / count_);
+ // Add half of denominator to achieve rounding.
+ return (static_cast<int>(queue_duration_.InMilliseconds() + count_ / 2) /
+ count_);
}
void DeathData::AddDeathData(const DeathData& other) {
@@ -75,11 +72,14 @@
return;
base::StringAppendF(output, "%s:%d, ",
(count_ == 1) ? "Life" : "Lives", count_);
- base::StringAppendF(output, "Run:%"PRId64"ms(%dms/life) ",
- run_duration_.InMilliseconds(),
+ // 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()),
AverageMsRunDuration());
- base::StringAppendF(output, "Queue:%"PRId64"ms(%dms/life) ",
- queue_duration_.InMilliseconds(),
+ base::StringAppendF(output, "Queue:%dms(%dms/life) ",
+ static_cast<int>(queue_duration_.InMilliseconds()),
AverageMsQueueDuration());
}
@@ -95,8 +95,8 @@
void DeathData::Clear() {
count_ = 0;
- queue_duration_ = TimeDelta();
- run_duration_ = TimeDelta();
+ queue_duration_ = Duration();
+ run_duration_ = Duration();
}
//------------------------------------------------------------------------------
@@ -113,6 +113,23 @@
//------------------------------------------------------------------------------
// 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
+int ThreadData::incarnation_counter_ = 0;
+
// static
ThreadData* ThreadData::all_thread_data_list_head_ = NULL;
@@ -120,44 +137,52 @@
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;
ThreadData::ThreadData(const std::string& suggested_name)
- : next_(NULL),
+ : incarnation_count_for_pool_(-1),
+ next_(NULL),
is_a_worker_thread_(false) {
DCHECK_GE(suggested_name.size(), 0u);
thread_name_ = suggested_name;
- PushToHeadOfList();
+ PushToHeadOfList(); // Which sets real incarnation_count_for_pool_.
}
-ThreadData::ThreadData() : next_(NULL), is_a_worker_thread_(true) {
+ThreadData::ThreadData()
+ : incarnation_count_for_pool_(-1),
+ 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);
- PushToHeadOfList();
+ PushToHeadOfList(); // Which sets real incarnation_count_for_pool_.
}
ThreadData::~ThreadData() {}
void ThreadData::PushToHeadOfList() {
DCHECK(!next_);
- base::AutoLock lock(list_lock_);
+ base::AutoLock lock(*list_lock_);
+ incarnation_count_for_pool_ = incarnation_counter_;
next_ = all_thread_data_list_head_;
all_thread_data_list_head_ = this;
}
// static
void ThreadData::InitializeThreadContext(const std::string& 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);
+ 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);
tls_index_.Set(current_thread_data);
}
@@ -172,7 +197,7 @@
// 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());
@@ -192,24 +217,29 @@
void ThreadData::OnThreadTermination(void* thread_data) {
if (!kTrackAllTaskObjects)
return; // Not compiled in.
- DCHECK(tls_index_.initialized());
if (!thread_data)
return;
reinterpret_cast<ThreadData*>(thread_data)->OnThreadTerminationCleanup();
- DCHECK_EQ(tls_index_.Get(), reinterpret_cast<ThreadData*>(NULL));
}
void ThreadData::OnThreadTerminationCleanup() const {
- tls_index_.Set(NULL);
if (!is_a_worker_thread_)
return;
- base::AutoLock lock(list_lock_);
- unregistered_thread_data_pool_->push(this);
+ base::AutoLock lock(*list_lock_);
+ if (incarnation_counter_ != incarnation_count_for_pool_)
+ return; // ThreadData was constructed in an earlier unit test.
+
+ // Handle case where we are in unit tests, and have become UNINITIALIZED.
+ // In that case, the pool might be NULL. We really should detect this via the
+ // incarnation_counter_, but this call is rarely made, so we can afford to
+ // code defensively.
+ if (unregistered_thread_data_pool_)
+ unregistered_thread_data_pool_->push(this);
}
// static
void ThreadData::WriteHTML(const std::string& query, std::string* output) {
- if (!ThreadData::IsActive())
+ if (status_ == UNINITIALIZED)
return; // Not yet initialized.
DataCollector collected_data; // Gather data.
@@ -316,13 +346,12 @@
}
// static
-base::Value* ThreadData::ToValue(int process_type) {
+base::DictionaryValue* ThreadData::ToValue() {
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;
}
@@ -342,8 +371,8 @@
}
void ThreadData::TallyADeath(const Births& birth,
- const TimeDelta& queue_duration,
- const TimeDelta& run_duration) {
+ const Duration& queue_duration,
+ const Duration& run_duration) {
DeathMap::iterator it = death_map_.find(&birth);
DeathData* death_data;
if (it != death_map_.end()) {
@@ -360,7 +389,7 @@
if (!kTrackAllTaskObjects)
return NULL; // Not compiled in.
- if (!IsActive())
+ if (!tracking_status())
return NULL;
ThreadData* current_thread_data = Get();
if (!current_thread_data)
@@ -369,37 +398,89 @@
}
// static
-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) {
+void ThreadData::TallyRunOnNamedThreadIfTracking(
+ const base::TrackingInfo& completed_task,
+ const TrackedTime& start_of_run,
+ const TrackedTime& end_of_run) {
if (!kTrackAllTaskObjects)
return; // Not compiled in.
- if (!IsActive() || !birth)
+ // 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)
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 sechudled (requested?) to emerge from the delayed task queue. This
+ // were scheduled (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.
- 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;
+ 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);
+
+ // Watch out for a race where status_ is changing, and hence one or both
+ // of start_of_run or end_of_run is zero. IN that case, we didn't bother to
+ // get a time value since we "weren't tracking" and we were trying to be
+ // efficient by not calling for a genuine time value. For simplicity, we'll
+ // use a default zero duration when we can't calculate a true value.
+ Duration queue_duration;
+ Duration run_duration;
+ if (!start_of_run.is_null()) {
+ queue_duration = start_of_run - effective_post_time;
+ if (!end_of_run.is_null())
+ 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;
+ Duration run_duration;
+ if (!start_of_run.is_null()) {
+ queue_duration = start_of_run - time_posted;
+ if (!end_of_run.is_null())
+ 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_;
}
@@ -439,71 +520,86 @@
it->second->Clear();
}
-// static
-bool ThreadData::StartTracking(bool status) {
+bool ThreadData::Initialize() {
if (!kTrackAllTaskObjects)
return false; // Not compiled in.
-
- // 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
+ 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
// process termination.
- if (!tls_index_.initialized())
+ if (!tls_index_.initialized()) // Testing may have initialized this.
tls_index_.Initialize(&ThreadData::OnThreadTermination);
DCHECK(tls_index_.initialized());
+ ThreadDataPool* 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;
- 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;
+ base::AutoLock lock(*list_lock_);
+ DCHECK_EQ(unregistered_thread_data_pool_,
+ reinterpret_cast<ThreadDataPool*>(NULL));
+ unregistered_thread_data_pool_ = pool;
+ ++incarnation_counter_;
return true;
}
// static
-bool ThreadData::IsActive() {
+bool ThreadData::InitializeAndSetTrackingStatus(bool status) {
+ if (!Initialize()) // No-op if already initialized.
+ return false; // Not compiled in.
+
+ status_ = status ? ACTIVE : DEACTIVATED;
+ return true;
+}
+
+// static
+bool ThreadData::tracking_status() {
return status_ == ACTIVE;
}
// static
-base::TimeTicks ThreadData::Now() {
- if (kTrackAllTaskObjects && status_ == ACTIVE)
- return base::TimeTicks::Now();
- return base::TimeTicks(); // Super fast when disabled, or not compiled in.
+TrackedTime ThreadData::Now() {
+ if (kTrackAllTaskObjects && tracking_status())
+ return TrackedTime::Now();
+ return TrackedTime(); // Super fast when disabled, or not compiled.
}
// static
-void ThreadData::ShutdownSingleThreadedCleanup() {
+void ThreadData::ShutdownSingleThreadedCleanup(bool leak) {
// 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 (!StartTracking(false))
+ if (!InitializeAndSetTrackingStatus(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_;
unregistered_thread_data_pool_ = NULL;
+ ++incarnation_counter_;
}
+ // Put most global static back in pristine shape.
+ thread_number_counter_ = 0;
+ tls_index_.Set(NULL);
+ status_ = UNINITIALIZED;
+
+ // To avoid any chance of racing in unit tests, which is the only place we
+ // call this function, we may sometimes leak all the data structures we
+ // recovered, as they may still be in use on threads from prior tests!
+ if (leak)
+ return;
+
+ // When we want to cleanup (on a single thread), here is what we do.
+
if (final_pool) {
// The thread_data_list contains *all* the instances, and we'll use it to
// delete them. This pool has pointers to some instances, and we just
@@ -525,10 +621,6 @@
next_thread_data->death_map_.clear();
delete next_thread_data; // Includes all Death Records.
}
- // Put most global static back in pristine shape.
- thread_number_counter_ = 0;
- tls_index_.Set(NULL);
- status_ = UNINITIALIZED;
}
//------------------------------------------------------------------------------
@@ -574,16 +666,12 @@
return dictionary;
}
-void Snapshot::Add(const Snapshot& other) {
- death_data_.AddDeathData(other.death_data_);
-}
-
//------------------------------------------------------------------------------
// DataCollector
DataCollector::DataCollector() {
- if (!ThreadData::IsActive())
- return;
+ if (!kTrackAllTaskObjects)
+ return; // Not compiled in.
// Get an unchanging copy of a ThreadData list.
ThreadData* my_list = ThreadData::first();
@@ -740,6 +828,35 @@
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_) {
@@ -956,28 +1073,6 @@
}
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);
@@ -987,13 +1082,14 @@
}
std::string keyword(key_phrase.substr(0, equal_offset));
keyword = StringToLowerASCII(keyword);
- KeyMap::iterator it = key_map.find(keyword);
- if (key_map.end() == it)
- return; // Unknown keyword.
- if (it->second == RESET_ALL_DATA)
+ Selector selector = FindSelector(keyword);
+ if (selector == UNKNOWN_KEYWORD)
+ return;
+ if (selector == RESET_ALL_DATA) {
ThreadData::ResetAllThreadData();
- else
- SetTiebreaker(key_map[keyword], required);
+ return;
+ }
+ SetTiebreaker(selector, required);
}
bool Comparator::ParseQuery(const std::string& query) {