Chromium Code Reviews| Index: base/tracked_objects.cc |
| diff --git a/base/tracked_objects.cc b/base/tracked_objects.cc |
| index a60e260b23660b31140593f6b7e0b63652a18f8b..d7cc1c6369b9d54071da8762651afc3f669f3959 100644 |
| --- a/base/tracked_objects.cc |
| +++ b/base/tracked_objects.cc |
| @@ -15,6 +15,7 @@ |
| #include "base/logging.h" |
| #include "base/process/process_handle.h" |
| #include "base/profiler/alternate_timer.h" |
| +#include "base/stl_util.h" |
| #include "base/strings/stringprintf.h" |
| #include "base/third_party/valgrind/memcheck.h" |
| #include "base/tracking_info.h" |
| @@ -93,12 +94,23 @@ inline bool IsProfilerTimingEnabled() { |
| // DeathData tallies durations when a death takes place. |
| DeathData::DeathData() { |
| - Clear(); |
| + count_ = 0; |
| + sample_probability_count_ = 0; |
| + run_duration_sum_ = 0; |
| + run_duration_max_ = 0; |
| + run_duration_sample_ = 0; |
| + queue_duration_sum_ = 0; |
| + queue_duration_max_ = 0; |
| + queue_duration_sample_ = 0; |
| + last_phase_snapshot_ = nullptr; |
| } |
| -DeathData::DeathData(int count) { |
| - Clear(); |
| - count_ = count; |
| +DeathData::~DeathData() { |
| + while (last_phase_snapshot_) { |
| + DeathDataPhaseSnapshot* snapshot = last_phase_snapshot_; |
| + last_phase_snapshot_ = snapshot->prev; |
| + delete snapshot; |
| + } |
| } |
| // TODO(jar): I need to see if this macro to optimize branching is worth using. |
| @@ -117,6 +129,8 @@ void DeathData::RecordDeath(const int32 queue_duration, |
| // We'll just clamp at INT_MAX, but we should note this in the UI as such. |
| if (count_ < INT_MAX) |
| ++count_; |
| + if (sample_probability_count_ < INT_MAX) |
| + ++sample_probability_count_; |
| queue_duration_sum_ += queue_duration; |
| run_duration_sum_ += run_duration; |
| @@ -125,14 +139,16 @@ void DeathData::RecordDeath(const int32 queue_duration, |
| if (run_duration_max_ < run_duration) |
| run_duration_max_ = run_duration; |
| - // Take a uniformly distributed sample over all durations ever supplied. |
| - // The probability that we (instead) use this new sample is 1/count_. This |
| - // results in a completely uniform selection of the sample (at least when we |
| - // don't clamp count_... but that should be inconsequentially likely). |
| - // We ignore the fact that we correlated our selection of a sample to the run |
| - // and queue times (i.e., we used them to generate random_number). |
| - CHECK_GT(count_, 0); |
| - if (0 == (random_number % count_)) { |
| + // Take a uniformly distributed sample over all durations ever supplied during |
| + // currrent profiling phase. |
| + // The probability that we (instead) use this new sample is |
| + // 1/sample_probability_count_. This results in a completely uniform selection |
| + // of the sample (at least when we don't clamp sample_probability_count_... |
| + // but that should be inconsequentially likely). We ignore the fact that we |
| + // correlated our selection of a sample to the run and queue times (i.e., we |
| + // used them to generate random_number). |
| + CHECK_GT(sample_probability_count_, 0); |
| + if (0 == (random_number % sample_probability_count_)) { |
| queue_duration_sample_ = queue_duration; |
| run_duration_sample_ = run_duration; |
| } |
| @@ -160,14 +176,24 @@ int32 DeathData::queue_duration_sample() const { |
| return queue_duration_sample_; |
| } |
| -void DeathData::Clear() { |
| - count_ = 0; |
| - run_duration_sum_ = 0; |
| +DeathDataPhaseSnapshot* DeathData::last_phase_snapshot() const { |
| + return last_phase_snapshot_; |
| +} |
| + |
| +void DeathData::OnProfilingPhaseCompleted(int profiling_phase) { |
| + // Snapshotting and storing current state. |
| + last_phase_snapshot_ = new DeathDataPhaseSnapshot( |
| + profiling_phase, count_, run_duration_sum_, run_duration_max_, |
| + run_duration_sample_, queue_duration_sum_, queue_duration_max_, |
| + queue_duration_sample_, last_phase_snapshot_); |
| + |
| + // Not touching fields for which a delta can be computed by comparing with a |
| + // snapshot from previos phase. Resetting other fields. Sample values will be |
| + // reset upon next death recording because sample_probability_count_ is set to |
| + // 0. |
|
Alexei Svitkine (slow)
2015/04/09 15:39:06
This comment needs to discuss *why* it's done this
vadimt
2015/04/09 21:28:39
Done
|
| + sample_probability_count_ = 0; |
| run_duration_max_ = 0; |
| - run_duration_sample_ = 0; |
| - queue_duration_sum_ = 0; |
| queue_duration_max_ = 0; |
| - queue_duration_sample_ = 0; |
| } |
| //------------------------------------------------------------------------------ |
| @@ -181,20 +207,31 @@ DeathDataSnapshot::DeathDataSnapshot() |
| queue_duration_sample(-1) { |
| } |
| -DeathDataSnapshot::DeathDataSnapshot( |
| - const tracked_objects::DeathData& death_data) |
| - : count(death_data.count()), |
| - run_duration_sum(death_data.run_duration_sum()), |
| - run_duration_max(death_data.run_duration_max()), |
| - run_duration_sample(death_data.run_duration_sample()), |
| - queue_duration_sum(death_data.queue_duration_sum()), |
| - queue_duration_max(death_data.queue_duration_max()), |
| - queue_duration_sample(death_data.queue_duration_sample()) { |
| +DeathDataSnapshot::DeathDataSnapshot(int count, |
| + int32 run_duration_sum, |
| + int32 run_duration_max, |
| + int32 run_duration_sample, |
| + int32 queue_duration_sum, |
| + int32 queue_duration_max, |
| + int32 queue_duration_sample) |
| + : count(count), |
| + run_duration_sum(run_duration_sum), |
| + run_duration_max(run_duration_max), |
| + run_duration_sample(run_duration_sample), |
| + queue_duration_sum(queue_duration_sum), |
| + queue_duration_max(queue_duration_max), |
| + queue_duration_sample(queue_duration_sample) { |
| } |
| DeathDataSnapshot::~DeathDataSnapshot() { |
| } |
| +void DeathDataSnapshot::CalculateDelta(const DeathDataSnapshot& older) { |
|
Alexei Svitkine (slow)
2015/04/09 15:39:05
How about SubtractDelta()?
Calculate doesn't make
vadimt
2015/04/09 21:28:40
Done, but we are not subtracting the delta, we are
|
| + count -= older.count; |
| + run_duration_sum -= older.run_duration_sum; |
| + queue_duration_sum -= older.queue_duration_sum; |
| +} |
| + |
| //------------------------------------------------------------------------------ |
| BirthOnThread::BirthOnThread(const Location& location, |
| const ThreadData& current) |
| @@ -206,8 +243,7 @@ BirthOnThread::BirthOnThread(const Location& location, |
| BirthOnThreadSnapshot::BirthOnThreadSnapshot() { |
| } |
| -BirthOnThreadSnapshot::BirthOnThreadSnapshot( |
| - const tracked_objects::BirthOnThread& birth) |
| +BirthOnThreadSnapshot::BirthOnThreadSnapshot(const BirthOnThread& birth) |
| : location(birth.location()), |
| thread_name(birth.birth_thread()->thread_name()) { |
| } |
| @@ -264,6 +300,9 @@ base::LazyInstance<base::Lock>::Leaky |
| ThreadData::list_lock_ = LAZY_INSTANCE_INITIALIZER; |
| // static |
| +base::ThreadChecker ThreadData::snapshot_thread_checker_; |
|
Alexei Svitkine (slow)
2015/04/09 15:39:05
Hmm, this isn't correct actually. I think this cau
vadimt
2015/04/09 21:28:39
Fixed the lazy instance initialization.
I think,
|
| + |
| +// static |
| ThreadData::Status ThreadData::status_ = ThreadData::UNINITIALIZED; |
| ThreadData::ThreadData(const std::string& suggested_name) |
| @@ -385,9 +424,57 @@ void ThreadData::OnThreadTerminationCleanup() { |
| } |
| // static |
| -void ThreadData::Snapshot(ProcessDataSnapshot* process_data_snapshot) { |
| - ThreadData::SnapshotCurrentPhase( |
| - &process_data_snapshot->phased_process_data_snapshots[0]); |
| +void ThreadData::Snapshot(int current_profiling_phase, |
| + ProcessDataSnapshot* process_data_snapshot) { |
| + DCHECK(snapshot_thread_checker_.CalledOnValidThread()); |
| + BirthCountMap birth_counts; |
| + |
| + // Get an unchanging copy of a ThreadData list. |
| + ThreadData* my_list = ThreadData::first(); |
| + |
| + // Gather data serially. |
| + // This hackish approach *can* get some slighly corrupt tallies, as we are |
| + // grabbing values without the protection of a lock, but it has the advantage |
| + // of working even with threads that don't have message loops. If a user |
| + // sees any strangeness, they can always just run their stats gathering a |
| + // second time. |
| + for (ThreadData* thread_data = my_list; thread_data; |
| + thread_data = thread_data->next()) { |
| + thread_data->SnapshotExecutedTasks( |
| + current_profiling_phase, |
| + &process_data_snapshot->phased_process_data_snapshots, &birth_counts); |
| + } |
| + |
| + // Add births that are still active -- i.e. objects that have tallied a birth, |
| + // but have not yet tallied a matching death, and hence must be either |
| + // running, queued up, or being held in limbo for future posting. |
| + for (const auto& birth_count : birth_counts) { |
| + if (birth_count.second > 0) { |
| + process_data_snapshot |
| + ->phased_process_data_snapshots[current_profiling_phase] |
| + .tasks.push_back(TaskSnapshot( |
|
Alexei Svitkine (slow)
2015/04/09 15:39:05
Nit: Can you make a local variable pointer outside
vadimt
2015/04/09 21:28:39
Done.
|
| + BirthOnThreadSnapshot(*birth_count.first), |
| + DeathDataSnapshot(birth_count.second, 0, 0, 0, 0, 0, 0), |
| + "Still_Alive")); |
| + } |
| + } |
| +} |
| + |
| +// static |
| +void ThreadData::OnProfilingPhaseCompleted(int profiling_phase) { |
| + DCHECK(snapshot_thread_checker_.CalledOnValidThread()); |
| + // Get an unchanging copy of a ThreadData list. |
| + ThreadData* my_list = ThreadData::first(); |
| + |
| + // Add snapshots for all death datas in all threads serially. |
| + // This hackish approach *can* get some slighly corrupt tallies, as we are |
| + // grabbing values without the protection of a lock, but it has the advantage |
| + // of working even with threads that don't have message loops. Any corruption |
| + // shouldn't cause "cascading damage" to anything else (in later phases). |
| + for (ThreadData* thread_data = my_list; thread_data; |
| + thread_data = thread_data->next()) { |
| + thread_data->OnProfilingPhaseCompletionOnThread(profiling_phase); |
| + } |
| } |
| Births* ThreadData::TallyABirth(const Location& location) { |
| @@ -419,7 +506,7 @@ Births* ThreadData::TallyABirth(const Location& location) { |
| return child; |
| } |
| -void ThreadData::TallyADeath(const Births& birth, |
| +void ThreadData::TallyADeath(const Births& births, |
| int32 queue_duration, |
| const TaskStopwatch& stopwatch) { |
| int32 run_duration = stopwatch.RunDurationMs(); |
| @@ -428,7 +515,7 @@ void ThreadData::TallyADeath(const Births& birth, |
| const uint32 kSomePrimeNumber = 2147483647; |
| random_number_ += queue_duration + run_duration + kSomePrimeNumber; |
| // An address is going to have some randomness to it as well ;-). |
| - random_number_ ^= static_cast<uint32>(&birth - reinterpret_cast<Births*>(0)); |
| + random_number_ ^= static_cast<uint32>(&births - reinterpret_cast<Births*>(0)); |
| // We don't have queue durations without OS timer. OS timer is automatically |
| // used for task-post-timing, so the use of an alternate timer implies all |
| @@ -440,20 +527,20 @@ void ThreadData::TallyADeath(const Births& birth, |
| queue_duration = 0; |
| } |
| - DeathMap::iterator it = death_map_.find(&birth); |
| + DeathMap::iterator it = death_map_.find(&births); |
| DeathData* death_data; |
| if (it != death_map_.end()) { |
| death_data = &it->second; |
| } else { |
| base::AutoLock lock(map_lock_); // Lock as the map may get relocated now. |
| - death_data = &death_map_[&birth]; |
| + death_data = &death_map_[&births]; |
| } // Release lock ASAP. |
| death_data->RecordDeath(queue_duration, run_duration, random_number_); |
| if (!kTrackParentChildLinks) |
| return; |
| if (!parent_stack_.empty()) { // We might get turned off. |
| - DCHECK_EQ(parent_stack_.top(), &birth); |
| + DCHECK_EQ(parent_stack_.top(), &births); |
| parent_stack_.pop(); |
| } |
| } |
| @@ -475,8 +562,8 @@ void ThreadData::TallyRunOnNamedThreadIfTracking( |
| // 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) |
| + const Births* births = completed_task.birth_tally; |
| + if (!births) |
| return; |
| ThreadData* current_thread_data = stopwatch.GetThreadData(); |
| if (!current_thread_data) |
| @@ -493,18 +580,18 @@ void ThreadData::TallyRunOnNamedThreadIfTracking( |
| queue_duration = (start_of_run - completed_task.EffectiveTimePosted()) |
| .InMilliseconds(); |
| } |
| - current_thread_data->TallyADeath(*birth, queue_duration, stopwatch); |
| + current_thread_data->TallyADeath(*births, queue_duration, stopwatch); |
| } |
| // static |
| void ThreadData::TallyRunOnWorkerThreadIfTracking( |
| - const Births* birth, |
| + const Births* births, |
| const TrackedTime& time_posted, |
| const TaskStopwatch& stopwatch) { |
| // 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) |
| + if (!births) |
| return; |
| // TODO(jar): Support the option to coalesce all worker-thread activity under |
| @@ -525,17 +612,17 @@ void ThreadData::TallyRunOnWorkerThreadIfTracking( |
| if (!start_of_run.is_null()) { |
| queue_duration = (start_of_run - time_posted).InMilliseconds(); |
| } |
| - current_thread_data->TallyADeath(*birth, queue_duration, stopwatch); |
| + current_thread_data->TallyADeath(*births, queue_duration, stopwatch); |
| } |
| // static |
| void ThreadData::TallyRunInAScopedRegionIfTracking( |
| - const Births* birth, |
| + const Births* births, |
| const TaskStopwatch& stopwatch) { |
| // 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) |
| + if (!births) |
| return; |
| ThreadData* current_thread_data = stopwatch.GetThreadData(); |
| @@ -543,87 +630,65 @@ void ThreadData::TallyRunInAScopedRegionIfTracking( |
| return; |
| int32 queue_duration = 0; |
| - current_thread_data->TallyADeath(*birth, queue_duration, stopwatch); |
| -} |
| - |
| -// static |
| -void ThreadData::SnapshotAllExecutedTasks( |
| - ProcessDataPhaseSnapshot* process_data_phase, |
| - BirthCountMap* birth_counts) { |
| - // Get an unchanging copy of a ThreadData list. |
| - ThreadData* my_list = ThreadData::first(); |
| - |
| - // Gather data serially. |
| - // This hackish approach *can* get some slighly corrupt tallies, as we are |
| - // grabbing values without the protection of a lock, but it has the advantage |
| - // of working even with threads that don't have message loops. If a user |
| - // sees any strangeness, they can always just run their stats gathering a |
| - // second time. |
| - for (ThreadData* thread_data = my_list; |
| - thread_data; |
| - thread_data = thread_data->next()) { |
| - thread_data->SnapshotExecutedTasks(process_data_phase, birth_counts); |
| - } |
| -} |
| - |
| -// static |
| -void ThreadData::SnapshotCurrentPhase( |
| - ProcessDataPhaseSnapshot* process_data_phase) { |
| - // Add births that have run to completion to |collected_data|. |
| - // |birth_counts| tracks the total number of births recorded at each location |
| - // for which we have not seen a death count. |
| - BirthCountMap birth_counts; |
| - ThreadData::SnapshotAllExecutedTasks(process_data_phase, &birth_counts); |
| - |
| - // Add births that are still active -- i.e. objects that have tallied a birth, |
| - // but have not yet tallied a matching death, and hence must be either |
| - // running, queued up, or being held in limbo for future posting. |
| - for (const auto& birth_count : birth_counts) { |
| - if (birth_count.second > 0) { |
| - process_data_phase->tasks.push_back(TaskSnapshot( |
| - *birth_count.first, DeathData(birth_count.second), "Still_Alive")); |
| - } |
| - } |
| + current_thread_data->TallyADeath(*births, queue_duration, stopwatch); |
| } |
| void ThreadData::SnapshotExecutedTasks( |
| - ProcessDataPhaseSnapshot* process_data_phase, |
| + int current_profiling_phase, |
| + PhasedProcessDataSnapshotMap* phased_process_data_snapshots, |
| BirthCountMap* birth_counts) { |
| // Get copy of data, so that the data will not change during the iterations |
| // and processing. |
| - ThreadData::BirthMap birth_map; |
| - ThreadData::DeathMap death_map; |
| - ThreadData::ParentChildSet parent_child_set; |
| - SnapshotMaps(&birth_map, &death_map, &parent_child_set); |
| - |
| - for (const auto& death : death_map) { |
| - process_data_phase->tasks.push_back( |
| - TaskSnapshot(*death.first, death.second, thread_name())); |
| - (*birth_counts)[death.first] -= death.first->birth_count(); |
| - } |
| + BirthMap birth_map; |
| + DeathsSnapshot deaths; |
| + ParentChildSet parent_child_set; |
| + SnapshotMaps(current_profiling_phase, &birth_map, &deaths, &parent_child_set); |
| for (const auto& birth : birth_map) { |
| (*birth_counts)[birth.second] += birth.second->birth_count(); |
| } |
| - if (!kTrackParentChildLinks) |
| - return; |
| + for (const auto& death : deaths) { |
|
Alexei Svitkine (slow)
2015/04/09 15:39:06
Add a short comment above this outlining what this
vadimt
2015/04/09 21:28:39
Done.
|
| + (*birth_counts)[death.first] -= death.first->birth_count(); |
| - for (const auto& parent_child : parent_child_set) { |
|
Alexei Svitkine (slow)
2015/04/09 15:39:05
Is it intentional that this feature is being remov
vadimt
2015/04/09 21:28:39
Not quite; feel through cracks :)
I'd remove it th
|
| - process_data_phase->descendants.push_back( |
| - ParentChildPairSnapshot(parent_child)); |
| + for (const DeathDataPhaseSnapshot* phase = &death.second; phase; |
| + phase = phase->prev) { |
| + DeathDataSnapshot death_data = phase->death_data; |
|
Alexei Svitkine (slow)
2015/04/09 15:39:06
I'm guessing it's important that you do this on th
vadimt
2015/04/09 21:28:39
Done.
|
| + |
| + if (phase->prev) |
| + death_data.CalculateDelta(phase->prev->death_data); |
| + |
| + if (death_data.count > 0) { |
| + (*phased_process_data_snapshots)[phase->profiling_phase] |
| + .tasks.push_back(TaskSnapshot(BirthOnThreadSnapshot(*death.first), |
| + death_data, thread_name())); |
| + } |
| + } |
| } |
| } |
| // This may be called from another thread. |
| -void ThreadData::SnapshotMaps(BirthMap* birth_map, |
| - DeathMap* death_map, |
| +void ThreadData::SnapshotMaps(int profiling_phase, |
| + BirthMap* birth_map, |
| + DeathsSnapshot* deaths, |
| ParentChildSet* parent_child_set) { |
| base::AutoLock lock(map_lock_); |
| + |
| for (const auto& birth : birth_map_) |
| (*birth_map)[birth.first] = birth.second; |
| - for (const auto& death : death_map_) |
| - (*death_map)[death.first] = death.second; |
| + |
| + for (const auto& death : death_map_) { |
| + deaths->push_back(DeathsSnapshot::value_type( |
| + death.first, |
| + DeathDataPhaseSnapshot(profiling_phase, death.second.count(), |
|
Alexei Svitkine (slow)
2015/04/09 15:39:06
To make this cleaner, how about adding a Snapshot(
vadimt
2015/04/09 21:28:39
I'm not super-thrilled with the additional amount
Alexei Svitkine (slow)
2015/04/09 22:19:44
I believe modern compilers will actually optimize
vadimt
2015/04/09 22:42:20
Given these not-quite-pleasant choices, the curren
Alexei Svitkine (slow)
2015/04/10 15:27:26
All right, though probably worth recording the rat
vadimt
2015/04/14 15:52:05
Done. Also reordered declarations to avoid forward
|
| + death.second.run_duration_sum(), |
| + death.second.run_duration_max(), |
| + death.second.run_duration_sample(), |
| + death.second.queue_duration_sum(), |
| + death.second.queue_duration_max(), |
| + death.second.queue_duration_sample(), |
| + death.second.last_phase_snapshot()))); |
| + } |
| if (!kTrackParentChildLinks) |
| return; |
| @@ -632,6 +697,14 @@ void ThreadData::SnapshotMaps(BirthMap* birth_map, |
| parent_child_set->insert(parent_child); |
| } |
| +void ThreadData::OnProfilingPhaseCompletionOnThread(int profiling_phase) { |
| + base::AutoLock lock(map_lock_); |
| + |
| + for (auto& death : death_map_) { |
| + death.second.OnProfilingPhaseCompleted(profiling_phase); |
| + } |
| +} |
| + |
| static void OptionallyInitializeAlternateTimer() { |
| NowFunction* alternate_time_source = GetAlternateTimeSource(); |
| if (alternate_time_source) |
| @@ -909,11 +982,36 @@ ThreadData* TaskStopwatch::GetThreadData() const { |
| } |
| //------------------------------------------------------------------------------ |
| +// DeathDataPhaseSnapshot |
| + |
| +DeathDataPhaseSnapshot::DeathDataPhaseSnapshot(int profiling_phase, |
| + int count, |
| + int32 run_duration_sum, |
| + int32 run_duration_max, |
| + int32 run_duration_sample, |
| + int32 queue_duration_sum, |
| + int32 queue_duration_max, |
| + int32 queue_duration_sample, |
| + DeathDataPhaseSnapshot* prev) |
| + : profiling_phase(profiling_phase), |
| + death_data(count, |
| + run_duration_sum, |
| + run_duration_max, |
| + run_duration_sample, |
| + queue_duration_sum, |
| + queue_duration_max, |
| + queue_duration_sample), |
| + prev(prev) { |
| +} |
| + |
| +//------------------------------------------------------------------------------ |
| +// TaskSnapshot |
| + |
| TaskSnapshot::TaskSnapshot() { |
| } |
| -TaskSnapshot::TaskSnapshot(const BirthOnThread& birth, |
| - const DeathData& death_data, |
| +TaskSnapshot::TaskSnapshot(const BirthOnThreadSnapshot& birth, |
| + const DeathDataSnapshot& death_data, |
| const std::string& death_thread_name) |
| : birth(birth), |
| death_data(death_data), |