OLD | NEW |
---|---|
1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. | 1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. |
2 // Use of this source code is governed by a BSD-style license that can be | 2 // Use of this source code is governed by a BSD-style license that can be |
3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
4 | 4 |
5 #include "base/tracked_objects.h" | 5 #include "base/tracked_objects.h" |
6 | 6 |
7 #include <limits.h> | 7 #include <limits.h> |
8 #include <stdlib.h> | 8 #include <stdlib.h> |
9 | 9 |
10 #include "base/atomicops.h" | 10 #include "base/atomicops.h" |
(...skipping 74 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
85 current_timing_enabled); | 85 current_timing_enabled); |
86 } | 86 } |
87 return current_timing_enabled == ENABLED_TIMING; | 87 return current_timing_enabled == ENABLED_TIMING; |
88 } | 88 } |
89 | 89 |
90 } // namespace | 90 } // namespace |
91 | 91 |
92 //------------------------------------------------------------------------------ | 92 //------------------------------------------------------------------------------ |
93 // DeathData tallies durations when a death takes place. | 93 // DeathData tallies durations when a death takes place. |
94 | 94 |
95 DeathData::DeathData() { | 95 DeathData::DeathData() |
96 Clear(); | 96 : count_(0), |
97 sample_probability_count_(0), | |
98 run_duration_sum_(0), | |
99 queue_duration_sum_(0), | |
100 run_duration_max_(0), | |
101 queue_duration_max_(0), | |
102 run_duration_sample_(0), | |
103 queue_duration_sample_(0), | |
104 last_phase_snapshot_(nullptr) { | |
97 } | 105 } |
98 | 106 |
99 DeathData::DeathData(int count) { | 107 DeathData::~DeathData() { |
100 Clear(); | 108 while (last_phase_snapshot_) { |
101 count_ = count; | 109 DeathDataPhaseSnapshot* snapshot = last_phase_snapshot_; |
110 last_phase_snapshot_ = snapshot->prev; | |
111 delete snapshot; | |
112 } | |
102 } | 113 } |
103 | 114 |
104 // TODO(jar): I need to see if this macro to optimize branching is worth using. | 115 // TODO(jar): I need to see if this macro to optimize branching is worth using. |
105 // | 116 // |
106 // This macro has no branching, so it is surely fast, and is equivalent to: | 117 // This macro has no branching, so it is surely fast, and is equivalent to: |
107 // if (assign_it) | 118 // if (assign_it) |
108 // target = source; | 119 // target = source; |
109 // We use a macro rather than a template to force this to inline. | 120 // We use a macro rather than a template to force this to inline. |
110 // Related code for calculating max is discussed on the web. | 121 // Related code for calculating max is discussed on the web. |
111 #define CONDITIONAL_ASSIGN(assign_it, target, source) \ | 122 #define CONDITIONAL_ASSIGN(assign_it, target, source) \ |
112 ((target) ^= ((target) ^ (source)) & -static_cast<int32>(assign_it)) | 123 ((target) ^= ((target) ^ (source)) & -static_cast<int32>(assign_it)) |
113 | 124 |
114 void DeathData::RecordDeath(const int32 queue_duration, | 125 void DeathData::RecordDeath(const int32 queue_duration, |
115 const int32 run_duration, | 126 const int32 run_duration, |
116 const uint32 random_number) { | 127 const uint32 random_number) { |
117 // We'll just clamp at INT_MAX, but we should note this in the UI as such. | 128 // We'll just clamp at INT_MAX, but we should note this in the UI as such. |
118 if (count_ < INT_MAX) | 129 if (count_ < INT_MAX) |
119 ++count_; | 130 ++count_; |
131 if (sample_probability_count_ < INT_MAX) | |
132 ++sample_probability_count_; | |
120 queue_duration_sum_ += queue_duration; | 133 queue_duration_sum_ += queue_duration; |
121 run_duration_sum_ += run_duration; | 134 run_duration_sum_ += run_duration; |
122 | 135 |
123 if (queue_duration_max_ < queue_duration) | 136 if (queue_duration_max_ < queue_duration) |
124 queue_duration_max_ = queue_duration; | 137 queue_duration_max_ = queue_duration; |
125 if (run_duration_max_ < run_duration) | 138 if (run_duration_max_ < run_duration) |
126 run_duration_max_ = run_duration; | 139 run_duration_max_ = run_duration; |
127 | 140 |
128 // Take a uniformly distributed sample over all durations ever supplied. | 141 // Take a uniformly distributed sample over all durations ever supplied during |
129 // The probability that we (instead) use this new sample is 1/count_. This | 142 // the current profiling phase. |
130 // results in a completely uniform selection of the sample (at least when we | 143 // The probability that we (instead) use this new sample is |
131 // don't clamp count_... but that should be inconsequentially likely). | 144 // 1/sample_probability_count_. This results in a completely uniform selection |
132 // We ignore the fact that we correlated our selection of a sample to the run | 145 // of the sample (at least when we don't clamp sample_probability_count_... |
133 // and queue times (i.e., we used them to generate random_number). | 146 // but that should be inconsequentially likely). We ignore the fact that we |
134 CHECK_GT(count_, 0); | 147 // correlated our selection of a sample to the run and queue times (i.e., we |
135 if (0 == (random_number % count_)) { | 148 // used them to generate random_number). |
149 CHECK_GT(sample_probability_count_, 0); | |
150 if (0 == (random_number % sample_probability_count_)) { | |
136 queue_duration_sample_ = queue_duration; | 151 queue_duration_sample_ = queue_duration; |
137 run_duration_sample_ = run_duration; | 152 run_duration_sample_ = run_duration; |
138 } | 153 } |
139 } | 154 } |
140 | 155 |
141 int DeathData::count() const { return count_; } | 156 int DeathData::count() const { return count_; } |
142 | 157 |
143 int32 DeathData::run_duration_sum() const { return run_duration_sum_; } | 158 int32 DeathData::run_duration_sum() const { return run_duration_sum_; } |
144 | 159 |
145 int32 DeathData::run_duration_max() const { return run_duration_max_; } | 160 int32 DeathData::run_duration_max() const { return run_duration_max_; } |
146 | 161 |
147 int32 DeathData::run_duration_sample() const { | 162 int32 DeathData::run_duration_sample() const { |
148 return run_duration_sample_; | 163 return run_duration_sample_; |
149 } | 164 } |
150 | 165 |
151 int32 DeathData::queue_duration_sum() const { | 166 int32 DeathData::queue_duration_sum() const { |
152 return queue_duration_sum_; | 167 return queue_duration_sum_; |
153 } | 168 } |
154 | 169 |
155 int32 DeathData::queue_duration_max() const { | 170 int32 DeathData::queue_duration_max() const { |
156 return queue_duration_max_; | 171 return queue_duration_max_; |
157 } | 172 } |
158 | 173 |
159 int32 DeathData::queue_duration_sample() const { | 174 int32 DeathData::queue_duration_sample() const { |
160 return queue_duration_sample_; | 175 return queue_duration_sample_; |
161 } | 176 } |
162 | 177 |
163 void DeathData::Clear() { | 178 DeathDataPhaseSnapshot* DeathData::last_phase_snapshot() const { |
164 count_ = 0; | 179 return last_phase_snapshot_; |
165 run_duration_sum_ = 0; | 180 } |
181 | |
182 void DeathData::OnProfilingPhaseCompleted(int profiling_phase) { | |
183 // Snapshotting and storing current state. | |
184 last_phase_snapshot_ = new DeathDataPhaseSnapshot( | |
185 profiling_phase, count_, run_duration_sum_, run_duration_max_, | |
186 run_duration_sample_, queue_duration_sum_, queue_duration_max_, | |
187 queue_duration_sample_, last_phase_snapshot_); | |
188 | |
189 // Not touching fields for which a delta can be computed by comparing with a | |
190 // snapshot from previos phase. Resetting other fields. Sample values will be | |
191 // reset upon next death recording because sample_probability_count_ is set to | |
192 // 0. | |
193 // We avoid resetting to 0 in favor of deltas whenever possible. The reason is | |
194 // that for incrementable fields, resetting to 0 from the snapshot thread | |
195 // potentially in parallel with incrementing in the death thread may result in | |
196 // significant data corruption that has a potential to grow with time. Not | |
197 // resetting incrementable fields and using deltas will cause any | |
198 // off-by-little corruptions to be likely fixed at the next snapshot. | |
199 // The max values are not incrementable, and cannot be deduced using deltas | |
200 // for a given phase. Hence, we have to reset them to 0. But the potential | |
201 // damage is limited to getting the previous phase's max to apply for the next | |
202 // phase, and the error doesn't have a potential to keep growing with new | |
203 // resets. | |
204 // sample_probability_count_ is incrementable, but must be reset to 0 at the | |
205 // phase end, so that we start a new uniformly randomized sample selection | |
206 // after the reset. Corruptions due to race conditions are possible, but the | |
207 // damage is limited to selecting a wrong sample, which is not something that | |
208 // can cause accumulating or cascading effects. | |
209 // If there were no corruptions caused by race conditions, we never send a | |
210 // sample for the previous phase in the next phase's snapshot because | |
211 // ThreadData::SnapshotExecutedTasks doesn't send deltas with 0 count. | |
212 sample_probability_count_ = 0; | |
166 run_duration_max_ = 0; | 213 run_duration_max_ = 0; |
167 run_duration_sample_ = 0; | |
168 queue_duration_sum_ = 0; | |
169 queue_duration_max_ = 0; | 214 queue_duration_max_ = 0; |
170 queue_duration_sample_ = 0; | |
171 } | 215 } |
172 | 216 |
173 //------------------------------------------------------------------------------ | 217 //------------------------------------------------------------------------------ |
174 DeathDataSnapshot::DeathDataSnapshot() | 218 DeathDataSnapshot::DeathDataSnapshot() |
175 : count(-1), | 219 : count(-1), |
176 run_duration_sum(-1), | 220 run_duration_sum(-1), |
177 run_duration_max(-1), | 221 run_duration_max(-1), |
178 run_duration_sample(-1), | 222 run_duration_sample(-1), |
179 queue_duration_sum(-1), | 223 queue_duration_sum(-1), |
180 queue_duration_max(-1), | 224 queue_duration_max(-1), |
181 queue_duration_sample(-1) { | 225 queue_duration_sample(-1) { |
182 } | 226 } |
183 | 227 |
184 DeathDataSnapshot::DeathDataSnapshot( | 228 DeathDataSnapshot::DeathDataSnapshot(int count, |
185 const tracked_objects::DeathData& death_data) | 229 int32 run_duration_sum, |
186 : count(death_data.count()), | 230 int32 run_duration_max, |
187 run_duration_sum(death_data.run_duration_sum()), | 231 int32 run_duration_sample, |
188 run_duration_max(death_data.run_duration_max()), | 232 int32 queue_duration_sum, |
189 run_duration_sample(death_data.run_duration_sample()), | 233 int32 queue_duration_max, |
190 queue_duration_sum(death_data.queue_duration_sum()), | 234 int32 queue_duration_sample) |
191 queue_duration_max(death_data.queue_duration_max()), | 235 : count(count), |
192 queue_duration_sample(death_data.queue_duration_sample()) { | 236 run_duration_sum(run_duration_sum), |
237 run_duration_max(run_duration_max), | |
238 run_duration_sample(run_duration_sample), | |
239 queue_duration_sum(queue_duration_sum), | |
240 queue_duration_max(queue_duration_max), | |
241 queue_duration_sample(queue_duration_sample) { | |
193 } | 242 } |
194 | 243 |
195 DeathDataSnapshot::~DeathDataSnapshot() { | 244 DeathDataSnapshot::~DeathDataSnapshot() { |
196 } | 245 } |
197 | 246 |
247 DeathDataSnapshot DeathDataSnapshot::Delta( | |
248 const DeathDataSnapshot& older) const { | |
249 return DeathDataSnapshot(count - older.count, | |
250 run_duration_sum - older.run_duration_sum, | |
251 run_duration_max, run_duration_sample, | |
252 queue_duration_sum - older.queue_duration_sum, | |
253 queue_duration_max, queue_duration_sample); | |
254 } | |
255 | |
198 //------------------------------------------------------------------------------ | 256 //------------------------------------------------------------------------------ |
199 BirthOnThread::BirthOnThread(const Location& location, | 257 BirthOnThread::BirthOnThread(const Location& location, |
200 const ThreadData& current) | 258 const ThreadData& current) |
201 : location_(location), | 259 : location_(location), |
202 birth_thread_(¤t) { | 260 birth_thread_(¤t) { |
203 } | 261 } |
204 | 262 |
205 //------------------------------------------------------------------------------ | 263 //------------------------------------------------------------------------------ |
206 BirthOnThreadSnapshot::BirthOnThreadSnapshot() { | 264 BirthOnThreadSnapshot::BirthOnThreadSnapshot() { |
207 } | 265 } |
208 | 266 |
209 BirthOnThreadSnapshot::BirthOnThreadSnapshot( | 267 BirthOnThreadSnapshot::BirthOnThreadSnapshot(const BirthOnThread& birth) |
210 const tracked_objects::BirthOnThread& birth) | |
211 : location(birth.location()), | 268 : location(birth.location()), |
212 thread_name(birth.birth_thread()->thread_name()) { | 269 thread_name(birth.birth_thread()->thread_name()) { |
213 } | 270 } |
214 | 271 |
215 BirthOnThreadSnapshot::~BirthOnThreadSnapshot() { | 272 BirthOnThreadSnapshot::~BirthOnThreadSnapshot() { |
216 } | 273 } |
217 | 274 |
218 //------------------------------------------------------------------------------ | 275 //------------------------------------------------------------------------------ |
219 Births::Births(const Location& location, const ThreadData& current) | 276 Births::Births(const Location& location, const ThreadData& current) |
220 : BirthOnThread(location, current), | 277 : BirthOnThread(location, current), |
(...skipping 36 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
257 ThreadData* ThreadData::all_thread_data_list_head_ = NULL; | 314 ThreadData* ThreadData::all_thread_data_list_head_ = NULL; |
258 | 315 |
259 // static | 316 // static |
260 ThreadData* ThreadData::first_retired_worker_ = NULL; | 317 ThreadData* ThreadData::first_retired_worker_ = NULL; |
261 | 318 |
262 // static | 319 // static |
263 base::LazyInstance<base::Lock>::Leaky | 320 base::LazyInstance<base::Lock>::Leaky |
264 ThreadData::list_lock_ = LAZY_INSTANCE_INITIALIZER; | 321 ThreadData::list_lock_ = LAZY_INSTANCE_INITIALIZER; |
265 | 322 |
266 // static | 323 // static |
324 base::LazyInstance<base::ThreadChecker>::Leaky | |
325 ThreadData::snapshot_thread_checker_ = LAZY_INSTANCE_INITIALIZER; | |
326 | |
327 // static | |
267 ThreadData::Status ThreadData::status_ = ThreadData::UNINITIALIZED; | 328 ThreadData::Status ThreadData::status_ = ThreadData::UNINITIALIZED; |
268 | 329 |
269 ThreadData::ThreadData(const std::string& suggested_name) | 330 ThreadData::ThreadData(const std::string& suggested_name) |
270 : next_(NULL), | 331 : next_(NULL), |
271 next_retired_worker_(NULL), | 332 next_retired_worker_(NULL), |
272 worker_thread_number_(0), | 333 worker_thread_number_(0), |
273 incarnation_count_for_pool_(-1), | 334 incarnation_count_for_pool_(-1), |
274 current_stopwatch_(NULL) { | 335 current_stopwatch_(NULL) { |
275 DCHECK_GE(suggested_name.size(), 0u); | 336 DCHECK_GE(suggested_name.size(), 0u); |
276 thread_name_ = suggested_name; | 337 thread_name_ = suggested_name; |
(...skipping 101 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
378 return; | 439 return; |
379 } | 440 } |
380 // We must NOT do any allocations during this callback. | 441 // We must NOT do any allocations during this callback. |
381 // Using the simple linked lists avoids all allocations. | 442 // Using the simple linked lists avoids all allocations. |
382 DCHECK_EQ(this->next_retired_worker_, reinterpret_cast<ThreadData*>(NULL)); | 443 DCHECK_EQ(this->next_retired_worker_, reinterpret_cast<ThreadData*>(NULL)); |
383 this->next_retired_worker_ = first_retired_worker_; | 444 this->next_retired_worker_ = first_retired_worker_; |
384 first_retired_worker_ = this; | 445 first_retired_worker_ = this; |
385 } | 446 } |
386 | 447 |
387 // static | 448 // static |
388 void ThreadData::Snapshot(ProcessDataSnapshot* process_data_snapshot) { | 449 void ThreadData::Snapshot(int current_profiling_phase, |
389 ThreadData::SnapshotCurrentPhase( | 450 ProcessDataSnapshot* process_data_snapshot) { |
390 &process_data_snapshot->phased_process_data_snapshots[0]); | 451 DCHECK(snapshot_thread_checker_.Get().CalledOnValidThread()); |
452 | |
453 // Get an unchanging copy of a ThreadData list. | |
454 ThreadData* my_list = ThreadData::first(); | |
455 | |
456 // Gather data serially. | |
457 // This hackish approach *can* get some slightly corrupt tallies, as we are | |
458 // grabbing values without the protection of a lock, but it has the advantage | |
459 // of working even with threads that don't have message loops. If a user | |
460 // sees any strangeness, they can always just run their stats gathering a | |
461 // second time. | |
462 BirthCountMap birth_counts; | |
463 | |
464 for (ThreadData* thread_data = my_list; thread_data; | |
465 thread_data = thread_data->next()) { | |
466 thread_data->SnapshotExecutedTasks(current_profiling_phase, | |
467 &process_data_snapshot->phased_snapshots, | |
468 &birth_counts); | |
469 } | |
470 | |
471 // Add births that are still active -- i.e. objects that have tallied a birth, | |
472 // but have not yet tallied a matching death, and hence must be either | |
473 // running, queued up, or being held in limbo for future posting. | |
474 auto current_phase_tasks = | |
475 &process_data_snapshot->phased_snapshots[current_profiling_phase].tasks; | |
476 for (const auto& birth_count : birth_counts) { | |
477 if (birth_count.second > 0) { | |
478 current_phase_tasks->push_back( | |
479 TaskSnapshot(BirthOnThreadSnapshot(*birth_count.first), | |
480 DeathDataSnapshot(birth_count.second, 0, 0, 0, 0, 0, 0), | |
481 "Still_Alive")); | |
482 } | |
483 } | |
484 } | |
485 | |
486 // static | |
487 void ThreadData::OnProfilingPhaseCompleted(int profiling_phase) { | |
488 DCHECK(snapshot_thread_checker_.Get().CalledOnValidThread()); | |
489 // Get an unchanging copy of a ThreadData list. | |
490 ThreadData* my_list = ThreadData::first(); | |
491 | |
492 // Add snapshots for all instances of death data in all threads serially. | |
493 // This hackish approach *can* get some slightly corrupt tallies, as we are | |
494 // grabbing values without the protection of a lock, but it has the advantage | |
495 // of working even with threads that don't have message loops. Any corruption | |
496 // shouldn't cause "cascading damage" to anything else (in later phases). | |
497 for (ThreadData* thread_data = my_list; thread_data; | |
498 thread_data = thread_data->next()) { | |
499 thread_data->OnProfilingPhaseCompletedOnThread(profiling_phase); | |
500 } | |
391 } | 501 } |
392 | 502 |
393 Births* ThreadData::TallyABirth(const Location& location) { | 503 Births* ThreadData::TallyABirth(const Location& location) { |
394 BirthMap::iterator it = birth_map_.find(location); | 504 BirthMap::iterator it = birth_map_.find(location); |
395 Births* child; | 505 Births* child; |
396 if (it != birth_map_.end()) { | 506 if (it != birth_map_.end()) { |
397 child = it->second; | 507 child = it->second; |
398 child->RecordBirth(); | 508 child->RecordBirth(); |
399 } else { | 509 } else { |
400 child = new Births(location, *this); // Leak this. | 510 child = new Births(location, *this); // Leak this. |
(...skipping 11 matching lines...) Expand all Loading... | |
412 // Lock since the map may get relocated now, and other threads sometimes | 522 // Lock since the map may get relocated now, and other threads sometimes |
413 // snapshot it (but they lock before copying it). | 523 // snapshot it (but they lock before copying it). |
414 base::AutoLock lock(map_lock_); | 524 base::AutoLock lock(map_lock_); |
415 parent_child_set_.insert(pair); | 525 parent_child_set_.insert(pair); |
416 } | 526 } |
417 } | 527 } |
418 | 528 |
419 return child; | 529 return child; |
420 } | 530 } |
421 | 531 |
422 void ThreadData::TallyADeath(const Births& birth, | 532 void ThreadData::TallyADeath(const Births& births, |
423 int32 queue_duration, | 533 int32 queue_duration, |
424 const TaskStopwatch& stopwatch) { | 534 const TaskStopwatch& stopwatch) { |
425 int32 run_duration = stopwatch.RunDurationMs(); | 535 int32 run_duration = stopwatch.RunDurationMs(); |
426 | 536 |
427 // Stir in some randomness, plus add constant in case durations are zero. | 537 // Stir in some randomness, plus add constant in case durations are zero. |
428 const uint32 kSomePrimeNumber = 2147483647; | 538 const uint32 kSomePrimeNumber = 2147483647; |
429 random_number_ += queue_duration + run_duration + kSomePrimeNumber; | 539 random_number_ += queue_duration + run_duration + kSomePrimeNumber; |
430 // An address is going to have some randomness to it as well ;-). | 540 // An address is going to have some randomness to it as well ;-). |
431 random_number_ ^= static_cast<uint32>(&birth - reinterpret_cast<Births*>(0)); | 541 random_number_ ^= static_cast<uint32>(&births - reinterpret_cast<Births*>(0)); |
432 | 542 |
433 // We don't have queue durations without OS timer. OS timer is automatically | 543 // We don't have queue durations without OS timer. OS timer is automatically |
434 // used for task-post-timing, so the use of an alternate timer implies all | 544 // used for task-post-timing, so the use of an alternate timer implies all |
435 // queue times are invalid, unless it was explicitly said that we can trust | 545 // queue times are invalid, unless it was explicitly said that we can trust |
436 // the alternate timer. | 546 // the alternate timer. |
437 if (kAllowAlternateTimeSourceHandling && | 547 if (kAllowAlternateTimeSourceHandling && |
438 now_function_ && | 548 now_function_ && |
439 !now_function_is_time_) { | 549 !now_function_is_time_) { |
440 queue_duration = 0; | 550 queue_duration = 0; |
441 } | 551 } |
442 | 552 |
443 DeathMap::iterator it = death_map_.find(&birth); | 553 DeathMap::iterator it = death_map_.find(&births); |
444 DeathData* death_data; | 554 DeathData* death_data; |
445 if (it != death_map_.end()) { | 555 if (it != death_map_.end()) { |
446 death_data = &it->second; | 556 death_data = &it->second; |
447 } else { | 557 } else { |
448 base::AutoLock lock(map_lock_); // Lock as the map may get relocated now. | 558 base::AutoLock lock(map_lock_); // Lock as the map may get relocated now. |
449 death_data = &death_map_[&birth]; | 559 death_data = &death_map_[&births]; |
450 } // Release lock ASAP. | 560 } // Release lock ASAP. |
451 death_data->RecordDeath(queue_duration, run_duration, random_number_); | 561 death_data->RecordDeath(queue_duration, run_duration, random_number_); |
452 | 562 |
453 if (!kTrackParentChildLinks) | 563 if (!kTrackParentChildLinks) |
454 return; | 564 return; |
455 if (!parent_stack_.empty()) { // We might get turned off. | 565 if (!parent_stack_.empty()) { // We might get turned off. |
456 DCHECK_EQ(parent_stack_.top(), &birth); | 566 DCHECK_EQ(parent_stack_.top(), &births); |
457 parent_stack_.pop(); | 567 parent_stack_.pop(); |
458 } | 568 } |
459 } | 569 } |
460 | 570 |
461 // static | 571 // static |
462 Births* ThreadData::TallyABirthIfActive(const Location& location) { | 572 Births* ThreadData::TallyABirthIfActive(const Location& location) { |
463 if (!TrackingStatus()) | 573 if (!TrackingStatus()) |
464 return NULL; | 574 return NULL; |
465 ThreadData* current_thread_data = Get(); | 575 ThreadData* current_thread_data = Get(); |
466 if (!current_thread_data) | 576 if (!current_thread_data) |
467 return NULL; | 577 return NULL; |
468 return current_thread_data->TallyABirth(location); | 578 return current_thread_data->TallyABirth(location); |
469 } | 579 } |
470 | 580 |
471 // static | 581 // static |
472 void ThreadData::TallyRunOnNamedThreadIfTracking( | 582 void ThreadData::TallyRunOnNamedThreadIfTracking( |
473 const base::TrackingInfo& completed_task, | 583 const base::TrackingInfo& completed_task, |
474 const TaskStopwatch& stopwatch) { | 584 const TaskStopwatch& stopwatch) { |
475 // Even if we have been DEACTIVATED, we will process any pending births so | 585 // Even if we have been DEACTIVATED, we will process any pending births so |
476 // that our data structures (which counted the outstanding births) remain | 586 // that our data structures (which counted the outstanding births) remain |
477 // consistent. | 587 // consistent. |
478 const Births* birth = completed_task.birth_tally; | 588 const Births* births = completed_task.birth_tally; |
479 if (!birth) | 589 if (!births) |
480 return; | 590 return; |
481 ThreadData* current_thread_data = stopwatch.GetThreadData(); | 591 ThreadData* current_thread_data = stopwatch.GetThreadData(); |
482 if (!current_thread_data) | 592 if (!current_thread_data) |
483 return; | 593 return; |
484 | 594 |
485 // Watch out for a race where status_ is changing, and hence one or both | 595 // Watch out for a race where status_ is changing, and hence one or both |
486 // of start_of_run or end_of_run is zero. In that case, we didn't bother to | 596 // of start_of_run or end_of_run is zero. In that case, we didn't bother to |
487 // get a time value since we "weren't tracking" and we were trying to be | 597 // get a time value since we "weren't tracking" and we were trying to be |
488 // efficient by not calling for a genuine time value. For simplicity, we'll | 598 // efficient by not calling for a genuine time value. For simplicity, we'll |
489 // use a default zero duration when we can't calculate a true value. | 599 // use a default zero duration when we can't calculate a true value. |
490 TrackedTime start_of_run = stopwatch.StartTime(); | 600 TrackedTime start_of_run = stopwatch.StartTime(); |
491 int32 queue_duration = 0; | 601 int32 queue_duration = 0; |
492 if (!start_of_run.is_null()) { | 602 if (!start_of_run.is_null()) { |
493 queue_duration = (start_of_run - completed_task.EffectiveTimePosted()) | 603 queue_duration = (start_of_run - completed_task.EffectiveTimePosted()) |
494 .InMilliseconds(); | 604 .InMilliseconds(); |
495 } | 605 } |
496 current_thread_data->TallyADeath(*birth, queue_duration, stopwatch); | 606 current_thread_data->TallyADeath(*births, queue_duration, stopwatch); |
497 } | 607 } |
498 | 608 |
499 // static | 609 // static |
500 void ThreadData::TallyRunOnWorkerThreadIfTracking( | 610 void ThreadData::TallyRunOnWorkerThreadIfTracking( |
501 const Births* birth, | 611 const Births* births, |
502 const TrackedTime& time_posted, | 612 const TrackedTime& time_posted, |
503 const TaskStopwatch& stopwatch) { | 613 const TaskStopwatch& stopwatch) { |
504 // Even if we have been DEACTIVATED, we will process any pending births so | 614 // Even if we have been DEACTIVATED, we will process any pending births so |
505 // that our data structures (which counted the outstanding births) remain | 615 // that our data structures (which counted the outstanding births) remain |
506 // consistent. | 616 // consistent. |
507 if (!birth) | 617 if (!births) |
508 return; | 618 return; |
509 | 619 |
510 // TODO(jar): Support the option to coalesce all worker-thread activity under | 620 // TODO(jar): Support the option to coalesce all worker-thread activity under |
511 // one ThreadData instance that uses locks to protect *all* access. This will | 621 // one ThreadData instance that uses locks to protect *all* access. This will |
512 // reduce memory (making it provably bounded), but run incrementally slower | 622 // reduce memory (making it provably bounded), but run incrementally slower |
513 // (since we'll use locks on TallyABirth and TallyADeath). The good news is | 623 // (since we'll use locks on TallyABirth and TallyADeath). The good news is |
514 // that the locks on TallyADeath will be *after* the worker thread has run, | 624 // that the locks on TallyADeath will be *after* the worker thread has run, |
515 // and hence nothing will be waiting for the completion (... besides some | 625 // and hence nothing will be waiting for the completion (... besides some |
516 // other thread that might like to run). Also, the worker threads tasks are | 626 // other thread that might like to run). Also, the worker threads tasks are |
517 // generally longer, and hence the cost of the lock may perchance be amortized | 627 // generally longer, and hence the cost of the lock may perchance be amortized |
518 // over the long task's lifetime. | 628 // over the long task's lifetime. |
519 ThreadData* current_thread_data = stopwatch.GetThreadData(); | 629 ThreadData* current_thread_data = stopwatch.GetThreadData(); |
520 if (!current_thread_data) | 630 if (!current_thread_data) |
521 return; | 631 return; |
522 | 632 |
523 TrackedTime start_of_run = stopwatch.StartTime(); | 633 TrackedTime start_of_run = stopwatch.StartTime(); |
524 int32 queue_duration = 0; | 634 int32 queue_duration = 0; |
525 if (!start_of_run.is_null()) { | 635 if (!start_of_run.is_null()) { |
526 queue_duration = (start_of_run - time_posted).InMilliseconds(); | 636 queue_duration = (start_of_run - time_posted).InMilliseconds(); |
527 } | 637 } |
528 current_thread_data->TallyADeath(*birth, queue_duration, stopwatch); | 638 current_thread_data->TallyADeath(*births, queue_duration, stopwatch); |
529 } | 639 } |
530 | 640 |
531 // static | 641 // static |
532 void ThreadData::TallyRunInAScopedRegionIfTracking( | 642 void ThreadData::TallyRunInAScopedRegionIfTracking( |
533 const Births* birth, | 643 const Births* births, |
534 const TaskStopwatch& stopwatch) { | 644 const TaskStopwatch& stopwatch) { |
535 // Even if we have been DEACTIVATED, we will process any pending births so | 645 // Even if we have been DEACTIVATED, we will process any pending births so |
536 // that our data structures (which counted the outstanding births) remain | 646 // that our data structures (which counted the outstanding births) remain |
537 // consistent. | 647 // consistent. |
538 if (!birth) | 648 if (!births) |
539 return; | 649 return; |
540 | 650 |
541 ThreadData* current_thread_data = stopwatch.GetThreadData(); | 651 ThreadData* current_thread_data = stopwatch.GetThreadData(); |
542 if (!current_thread_data) | 652 if (!current_thread_data) |
543 return; | 653 return; |
544 | 654 |
545 int32 queue_duration = 0; | 655 int32 queue_duration = 0; |
546 current_thread_data->TallyADeath(*birth, queue_duration, stopwatch); | 656 current_thread_data->TallyADeath(*births, queue_duration, stopwatch); |
547 } | |
548 | |
549 // static | |
550 void ThreadData::SnapshotAllExecutedTasks( | |
551 ProcessDataPhaseSnapshot* process_data_phase, | |
552 BirthCountMap* birth_counts) { | |
553 // Get an unchanging copy of a ThreadData list. | |
554 ThreadData* my_list = ThreadData::first(); | |
555 | |
556 // Gather data serially. | |
557 // This hackish approach *can* get some slighly corrupt tallies, as we are | |
558 // grabbing values without the protection of a lock, but it has the advantage | |
559 // of working even with threads that don't have message loops. If a user | |
560 // sees any strangeness, they can always just run their stats gathering a | |
561 // second time. | |
562 for (ThreadData* thread_data = my_list; | |
563 thread_data; | |
564 thread_data = thread_data->next()) { | |
565 thread_data->SnapshotExecutedTasks(process_data_phase, birth_counts); | |
566 } | |
567 } | |
568 | |
569 // static | |
570 void ThreadData::SnapshotCurrentPhase( | |
571 ProcessDataPhaseSnapshot* process_data_phase) { | |
572 // Add births that have run to completion to |collected_data|. | |
573 // |birth_counts| tracks the total number of births recorded at each location | |
574 // for which we have not seen a death count. | |
575 BirthCountMap birth_counts; | |
576 ThreadData::SnapshotAllExecutedTasks(process_data_phase, &birth_counts); | |
577 | |
578 // Add births that are still active -- i.e. objects that have tallied a birth, | |
579 // but have not yet tallied a matching death, and hence must be either | |
580 // running, queued up, or being held in limbo for future posting. | |
581 for (const auto& birth_count : birth_counts) { | |
582 if (birth_count.second > 0) { | |
583 process_data_phase->tasks.push_back(TaskSnapshot( | |
584 *birth_count.first, DeathData(birth_count.second), "Still_Alive")); | |
585 } | |
586 } | |
587 } | 657 } |
588 | 658 |
589 void ThreadData::SnapshotExecutedTasks( | 659 void ThreadData::SnapshotExecutedTasks( |
590 ProcessDataPhaseSnapshot* process_data_phase, | 660 int current_profiling_phase, |
661 PhasedProcessDataSnapshotMap* phased_snapshots, | |
591 BirthCountMap* birth_counts) { | 662 BirthCountMap* birth_counts) { |
592 // Get copy of data, so that the data will not change during the iterations | 663 // Get copy of data, so that the data will not change during the iterations |
593 // and processing. | 664 // and processing. |
594 ThreadData::BirthMap birth_map; | 665 BirthMap birth_map; |
595 ThreadData::DeathMap death_map; | 666 DeathsSnapshot deaths; |
596 ThreadData::ParentChildSet parent_child_set; | 667 ParentChildSet parent_child_set; |
597 SnapshotMaps(&birth_map, &death_map, &parent_child_set); | 668 SnapshotMaps(current_profiling_phase, &birth_map, &deaths, &parent_child_set); |
598 | |
599 for (const auto& death : death_map) { | |
600 process_data_phase->tasks.push_back( | |
601 TaskSnapshot(*death.first, death.second, thread_name())); | |
602 (*birth_counts)[death.first] -= death.first->birth_count(); | |
603 } | |
604 | 669 |
605 for (const auto& birth : birth_map) { | 670 for (const auto& birth : birth_map) { |
606 (*birth_counts)[birth.second] += birth.second->birth_count(); | 671 (*birth_counts)[birth.second] += birth.second->birth_count(); |
607 } | 672 } |
608 | 673 |
609 if (!kTrackParentChildLinks) | 674 for (const auto& death : deaths) { |
610 return; | 675 (*birth_counts)[death.first] -= death.first->birth_count(); |
611 | 676 |
612 for (const auto& parent_child : parent_child_set) { | 677 // For the current death data, walk through all its snapshots, starting from |
613 process_data_phase->descendants.push_back( | 678 // the current one, then from the previous profiling phase etc., and for |
614 ParentChildPairSnapshot(parent_child)); | 679 // each snapshot calculate the delta between the snapshot and the previous |
680 // phase, if any. Store the deltas in the result. | |
681 for (const DeathDataPhaseSnapshot* phase = &death.second; phase; | |
682 phase = phase->prev) { | |
683 const DeathDataSnapshot death_data = | |
Alexei Svitkine (slow)
2015/04/15 19:22:50
Nit: You can make this a reference and then in the
vadimt
2015/04/15 19:52:15
Nice!
| |
684 phase->prev ? phase->death_data.Delta(phase->prev->death_data) | |
685 : phase->death_data; | |
686 | |
687 if (death_data.count > 0) { | |
688 (*phased_snapshots)[phase->profiling_phase].tasks.push_back( | |
689 TaskSnapshot(BirthOnThreadSnapshot(*death.first), death_data, | |
690 thread_name())); | |
691 } | |
692 } | |
615 } | 693 } |
616 } | 694 } |
617 | 695 |
618 // This may be called from another thread. | 696 // This may be called from another thread. |
619 void ThreadData::SnapshotMaps(BirthMap* birth_map, | 697 void ThreadData::SnapshotMaps(int profiling_phase, |
620 DeathMap* death_map, | 698 BirthMap* birth_map, |
699 DeathsSnapshot* deaths, | |
621 ParentChildSet* parent_child_set) { | 700 ParentChildSet* parent_child_set) { |
622 base::AutoLock lock(map_lock_); | 701 base::AutoLock lock(map_lock_); |
702 | |
623 for (const auto& birth : birth_map_) | 703 for (const auto& birth : birth_map_) |
624 (*birth_map)[birth.first] = birth.second; | 704 (*birth_map)[birth.first] = birth.second; |
625 for (const auto& death : death_map_) | 705 |
626 (*death_map)[death.first] = death.second; | 706 for (const auto& death : death_map_) { |
707 deaths->push_back(DeathsSnapshot::value_type( | |
708 death.first, | |
709 DeathDataPhaseSnapshot(profiling_phase, death.second.count(), | |
710 death.second.run_duration_sum(), | |
711 death.second.run_duration_max(), | |
712 death.second.run_duration_sample(), | |
713 death.second.queue_duration_sum(), | |
714 death.second.queue_duration_max(), | |
715 death.second.queue_duration_sample(), | |
716 death.second.last_phase_snapshot()))); | |
717 } | |
627 | 718 |
628 if (!kTrackParentChildLinks) | 719 if (!kTrackParentChildLinks) |
629 return; | 720 return; |
630 | 721 |
631 for (const auto& parent_child : parent_child_set_) | 722 for (const auto& parent_child : parent_child_set_) |
632 parent_child_set->insert(parent_child); | 723 parent_child_set->insert(parent_child); |
633 } | 724 } |
634 | 725 |
726 void ThreadData::OnProfilingPhaseCompletedOnThread(int profiling_phase) { | |
727 base::AutoLock lock(map_lock_); | |
728 | |
729 for (auto& death : death_map_) { | |
730 death.second.OnProfilingPhaseCompleted(profiling_phase); | |
731 } | |
732 } | |
733 | |
635 static void OptionallyInitializeAlternateTimer() { | 734 static void OptionallyInitializeAlternateTimer() { |
636 NowFunction* alternate_time_source = GetAlternateTimeSource(); | 735 NowFunction* alternate_time_source = GetAlternateTimeSource(); |
637 if (alternate_time_source) | 736 if (alternate_time_source) |
638 ThreadData::SetAlternateTimeSource(alternate_time_source); | 737 ThreadData::SetAlternateTimeSource(alternate_time_source); |
639 } | 738 } |
640 | 739 |
641 bool ThreadData::Initialize() { | 740 bool ThreadData::Initialize() { |
642 if (status_ >= DEACTIVATED) | 741 if (status_ >= DEACTIVATED) |
643 return true; // Someone else did the initialization. | 742 return true; // Someone else did the initialization. |
644 // Due to racy lazy initialization in tests, we'll need to recheck status_ | 743 // Due to racy lazy initialization in tests, we'll need to recheck status_ |
(...skipping 257 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
902 | 1001 |
903 ThreadData* TaskStopwatch::GetThreadData() const { | 1002 ThreadData* TaskStopwatch::GetThreadData() const { |
904 #if DCHECK_IS_ON() | 1003 #if DCHECK_IS_ON() |
905 DCHECK(state_ != CREATED); | 1004 DCHECK(state_ != CREATED); |
906 #endif | 1005 #endif |
907 | 1006 |
908 return current_thread_data_; | 1007 return current_thread_data_; |
909 } | 1008 } |
910 | 1009 |
911 //------------------------------------------------------------------------------ | 1010 //------------------------------------------------------------------------------ |
1011 // DeathDataPhaseSnapshot | |
1012 | |
1013 DeathDataPhaseSnapshot::DeathDataPhaseSnapshot(int profiling_phase, | |
1014 int count, | |
1015 int32 run_duration_sum, | |
1016 int32 run_duration_max, | |
1017 int32 run_duration_sample, | |
1018 int32 queue_duration_sum, | |
1019 int32 queue_duration_max, | |
1020 int32 queue_duration_sample, | |
1021 DeathDataPhaseSnapshot* prev) | |
1022 : profiling_phase(profiling_phase), | |
1023 death_data(count, | |
1024 run_duration_sum, | |
1025 run_duration_max, | |
1026 run_duration_sample, | |
1027 queue_duration_sum, | |
1028 queue_duration_max, | |
1029 queue_duration_sample), | |
1030 prev(prev) { | |
1031 } | |
1032 | |
1033 //------------------------------------------------------------------------------ | |
1034 // TaskSnapshot | |
1035 | |
912 TaskSnapshot::TaskSnapshot() { | 1036 TaskSnapshot::TaskSnapshot() { |
913 } | 1037 } |
914 | 1038 |
915 TaskSnapshot::TaskSnapshot(const BirthOnThread& birth, | 1039 TaskSnapshot::TaskSnapshot(const BirthOnThreadSnapshot& birth, |
916 const DeathData& death_data, | 1040 const DeathDataSnapshot& death_data, |
917 const std::string& death_thread_name) | 1041 const std::string& death_thread_name) |
918 : birth(birth), | 1042 : birth(birth), |
919 death_data(death_data), | 1043 death_data(death_data), |
920 death_thread_name(death_thread_name) { | 1044 death_thread_name(death_thread_name) { |
921 } | 1045 } |
922 | 1046 |
923 TaskSnapshot::~TaskSnapshot() { | 1047 TaskSnapshot::~TaskSnapshot() { |
924 } | 1048 } |
925 | 1049 |
926 //------------------------------------------------------------------------------ | 1050 //------------------------------------------------------------------------------ |
(...skipping 28 matching lines...) Expand all Loading... | |
955 : process_id(base::GetCurrentProcId()) { | 1079 : process_id(base::GetCurrentProcId()) { |
956 #else | 1080 #else |
957 : process_id(base::kNullProcessId) { | 1081 : process_id(base::kNullProcessId) { |
958 #endif | 1082 #endif |
959 } | 1083 } |
960 | 1084 |
961 ProcessDataSnapshot::~ProcessDataSnapshot() { | 1085 ProcessDataSnapshot::~ProcessDataSnapshot() { |
962 } | 1086 } |
963 | 1087 |
964 } // namespace tracked_objects | 1088 } // namespace tracked_objects |
OLD | NEW |