| 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" |
| 11 #include "base/base_switches.h" | 11 #include "base/base_switches.h" |
| 12 #include "base/command_line.h" | 12 #include "base/command_line.h" |
| 13 #include "base/compiler_specific.h" | 13 #include "base/compiler_specific.h" |
| 14 #include "base/debug/leak_annotations.h" | 14 #include "base/debug/leak_annotations.h" |
| 15 #include "base/logging.h" | 15 #include "base/logging.h" |
| 16 #include "base/process/process_handle.h" | 16 #include "base/process/process_handle.h" |
| 17 #include "base/profiler/alternate_timer.h" | 17 #include "base/profiler/alternate_timer.h" |
| 18 #include "base/strings/stringprintf.h" | 18 #include "base/strings/stringprintf.h" |
| 19 #include "base/third_party/valgrind/memcheck.h" | 19 #include "base/third_party/valgrind/memcheck.h" |
| 20 #include "base/tracking_info.h" | 20 #include "base/tracking_info.h" |
| 21 #include "build/build_config.h" |
| 21 | 22 |
| 22 using base::TimeDelta; | 23 using base::TimeDelta; |
| 23 | 24 |
| 24 namespace base { | 25 namespace base { |
| 25 class TimeDelta; | 26 class TimeDelta; |
| 26 } | 27 } |
| 27 | 28 |
| 28 namespace tracked_objects { | 29 namespace tracked_objects { |
| 29 | 30 |
| 30 namespace { | 31 namespace { |
| (...skipping 93 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 124 } | 125 } |
| 125 | 126 |
| 126 // TODO(jar): I need to see if this macro to optimize branching is worth using. | 127 // TODO(jar): I need to see if this macro to optimize branching is worth using. |
| 127 // | 128 // |
| 128 // This macro has no branching, so it is surely fast, and is equivalent to: | 129 // This macro has no branching, so it is surely fast, and is equivalent to: |
| 129 // if (assign_it) | 130 // if (assign_it) |
| 130 // target = source; | 131 // target = source; |
| 131 // We use a macro rather than a template to force this to inline. | 132 // We use a macro rather than a template to force this to inline. |
| 132 // Related code for calculating max is discussed on the web. | 133 // Related code for calculating max is discussed on the web. |
| 133 #define CONDITIONAL_ASSIGN(assign_it, target, source) \ | 134 #define CONDITIONAL_ASSIGN(assign_it, target, source) \ |
| 134 ((target) ^= ((target) ^ (source)) & -static_cast<int32>(assign_it)) | 135 ((target) ^= ((target) ^ (source)) & -static_cast<int32_t>(assign_it)) |
| 135 | 136 |
| 136 void DeathData::RecordDeath(const int32 queue_duration, | 137 void DeathData::RecordDeath(const int32_t queue_duration, |
| 137 const int32 run_duration, | 138 const int32_t run_duration, |
| 138 const uint32 random_number) { | 139 const uint32_t random_number) { |
| 139 // We'll just clamp at INT_MAX, but we should note this in the UI as such. | 140 // We'll just clamp at INT_MAX, but we should note this in the UI as such. |
| 140 if (count_ < INT_MAX) | 141 if (count_ < INT_MAX) |
| 141 ++count_; | 142 ++count_; |
| 142 | 143 |
| 143 int sample_probability_count = sample_probability_count_; | 144 int sample_probability_count = sample_probability_count_; |
| 144 if (sample_probability_count < INT_MAX) | 145 if (sample_probability_count < INT_MAX) |
| 145 ++sample_probability_count; | 146 ++sample_probability_count; |
| 146 sample_probability_count_ = sample_probability_count; | 147 sample_probability_count_ = sample_probability_count; |
| 147 | 148 |
| 148 queue_duration_sum_ += queue_duration; | 149 queue_duration_sum_ += queue_duration; |
| (...skipping 59 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 208 : count(-1), | 209 : count(-1), |
| 209 run_duration_sum(-1), | 210 run_duration_sum(-1), |
| 210 run_duration_max(-1), | 211 run_duration_max(-1), |
| 211 run_duration_sample(-1), | 212 run_duration_sample(-1), |
| 212 queue_duration_sum(-1), | 213 queue_duration_sum(-1), |
| 213 queue_duration_max(-1), | 214 queue_duration_max(-1), |
| 214 queue_duration_sample(-1) { | 215 queue_duration_sample(-1) { |
| 215 } | 216 } |
| 216 | 217 |
| 217 DeathDataSnapshot::DeathDataSnapshot(int count, | 218 DeathDataSnapshot::DeathDataSnapshot(int count, |
| 218 int32 run_duration_sum, | 219 int32_t run_duration_sum, |
| 219 int32 run_duration_max, | 220 int32_t run_duration_max, |
| 220 int32 run_duration_sample, | 221 int32_t run_duration_sample, |
| 221 int32 queue_duration_sum, | 222 int32_t queue_duration_sum, |
| 222 int32 queue_duration_max, | 223 int32_t queue_duration_max, |
| 223 int32 queue_duration_sample) | 224 int32_t queue_duration_sample) |
| 224 : count(count), | 225 : count(count), |
| 225 run_duration_sum(run_duration_sum), | 226 run_duration_sum(run_duration_sum), |
| 226 run_duration_max(run_duration_max), | 227 run_duration_max(run_duration_max), |
| 227 run_duration_sample(run_duration_sample), | 228 run_duration_sample(run_duration_sample), |
| 228 queue_duration_sum(queue_duration_sum), | 229 queue_duration_sum(queue_duration_sum), |
| 229 queue_duration_max(queue_duration_max), | 230 queue_duration_max(queue_duration_max), |
| 230 queue_duration_sample(queue_duration_sample) { | 231 queue_duration_sample(queue_duration_sample) {} |
| 231 } | |
| 232 | 232 |
| 233 DeathDataSnapshot::~DeathDataSnapshot() { | 233 DeathDataSnapshot::~DeathDataSnapshot() { |
| 234 } | 234 } |
| 235 | 235 |
| 236 DeathDataSnapshot DeathDataSnapshot::Delta( | 236 DeathDataSnapshot DeathDataSnapshot::Delta( |
| 237 const DeathDataSnapshot& older) const { | 237 const DeathDataSnapshot& older) const { |
| 238 return DeathDataSnapshot(count - older.count, | 238 return DeathDataSnapshot(count - older.count, |
| 239 run_duration_sum - older.run_duration_sum, | 239 run_duration_sum - older.run_duration_sum, |
| 240 run_duration_max, run_duration_sample, | 240 run_duration_max, run_duration_sample, |
| 241 queue_duration_sum - older.queue_duration_sum, | 241 queue_duration_sum - older.queue_duration_sum, |
| (...skipping 93 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 335 } | 335 } |
| 336 | 336 |
| 337 ThreadData::~ThreadData() { | 337 ThreadData::~ThreadData() { |
| 338 } | 338 } |
| 339 | 339 |
| 340 void ThreadData::PushToHeadOfList() { | 340 void ThreadData::PushToHeadOfList() { |
| 341 // Toss in a hint of randomness (atop the uniniitalized value). | 341 // Toss in a hint of randomness (atop the uniniitalized value). |
| 342 (void)VALGRIND_MAKE_MEM_DEFINED_IF_ADDRESSABLE(&random_number_, | 342 (void)VALGRIND_MAKE_MEM_DEFINED_IF_ADDRESSABLE(&random_number_, |
| 343 sizeof(random_number_)); | 343 sizeof(random_number_)); |
| 344 MSAN_UNPOISON(&random_number_, sizeof(random_number_)); | 344 MSAN_UNPOISON(&random_number_, sizeof(random_number_)); |
| 345 random_number_ += static_cast<uint32>(this - static_cast<ThreadData*>(0)); | 345 random_number_ += static_cast<uint32_t>(this - static_cast<ThreadData*>(0)); |
| 346 random_number_ ^= (Now() - TrackedTime()).InMilliseconds(); | 346 random_number_ ^= (Now() - TrackedTime()).InMilliseconds(); |
| 347 | 347 |
| 348 DCHECK(!next_); | 348 DCHECK(!next_); |
| 349 base::AutoLock lock(*list_lock_.Pointer()); | 349 base::AutoLock lock(*list_lock_.Pointer()); |
| 350 incarnation_count_for_pool_ = incarnation_counter_; | 350 incarnation_count_for_pool_ = incarnation_counter_; |
| 351 next_ = all_thread_data_list_head_; | 351 next_ = all_thread_data_list_head_; |
| 352 all_thread_data_list_head_ = this; | 352 all_thread_data_list_head_ = this; |
| 353 } | 353 } |
| 354 | 354 |
| 355 // static | 355 // static |
| (...skipping 136 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 492 // Lock since the map may get relocated now, and other threads sometimes | 492 // Lock since the map may get relocated now, and other threads sometimes |
| 493 // snapshot it (but they lock before copying it). | 493 // snapshot it (but they lock before copying it). |
| 494 base::AutoLock lock(map_lock_); | 494 base::AutoLock lock(map_lock_); |
| 495 birth_map_[location] = child; | 495 birth_map_[location] = child; |
| 496 } | 496 } |
| 497 | 497 |
| 498 return child; | 498 return child; |
| 499 } | 499 } |
| 500 | 500 |
| 501 void ThreadData::TallyADeath(const Births& births, | 501 void ThreadData::TallyADeath(const Births& births, |
| 502 int32 queue_duration, | 502 int32_t queue_duration, |
| 503 const TaskStopwatch& stopwatch) { | 503 const TaskStopwatch& stopwatch) { |
| 504 int32 run_duration = stopwatch.RunDurationMs(); | 504 int32_t run_duration = stopwatch.RunDurationMs(); |
| 505 | 505 |
| 506 // Stir in some randomness, plus add constant in case durations are zero. | 506 // Stir in some randomness, plus add constant in case durations are zero. |
| 507 const uint32 kSomePrimeNumber = 2147483647; | 507 const uint32_t kSomePrimeNumber = 2147483647; |
| 508 random_number_ += queue_duration + run_duration + kSomePrimeNumber; | 508 random_number_ += queue_duration + run_duration + kSomePrimeNumber; |
| 509 // An address is going to have some randomness to it as well ;-). | 509 // An address is going to have some randomness to it as well ;-). |
| 510 random_number_ ^= static_cast<uint32>(&births - reinterpret_cast<Births*>(0)); | 510 random_number_ ^= |
| 511 static_cast<uint32_t>(&births - reinterpret_cast<Births*>(0)); |
| 511 | 512 |
| 512 // We don't have queue durations without OS timer. OS timer is automatically | 513 // We don't have queue durations without OS timer. OS timer is automatically |
| 513 // used for task-post-timing, so the use of an alternate timer implies all | 514 // used for task-post-timing, so the use of an alternate timer implies all |
| 514 // queue times are invalid, unless it was explicitly said that we can trust | 515 // queue times are invalid, unless it was explicitly said that we can trust |
| 515 // the alternate timer. | 516 // the alternate timer. |
| 516 if (kAllowAlternateTimeSourceHandling && | 517 if (kAllowAlternateTimeSourceHandling && |
| 517 now_function_ && | 518 now_function_ && |
| 518 !now_function_is_time_) { | 519 !now_function_is_time_) { |
| 519 queue_duration = 0; | 520 queue_duration = 0; |
| 520 } | 521 } |
| (...skipping 32 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 553 ThreadData* current_thread_data = stopwatch.GetThreadData(); | 554 ThreadData* current_thread_data = stopwatch.GetThreadData(); |
| 554 if (!current_thread_data) | 555 if (!current_thread_data) |
| 555 return; | 556 return; |
| 556 | 557 |
| 557 // Watch out for a race where status_ is changing, and hence one or both | 558 // Watch out for a race where status_ is changing, and hence one or both |
| 558 // of start_of_run or end_of_run is zero. In that case, we didn't bother to | 559 // of start_of_run or end_of_run is zero. In that case, we didn't bother to |
| 559 // get a time value since we "weren't tracking" and we were trying to be | 560 // get a time value since we "weren't tracking" and we were trying to be |
| 560 // efficient by not calling for a genuine time value. For simplicity, we'll | 561 // efficient by not calling for a genuine time value. For simplicity, we'll |
| 561 // use a default zero duration when we can't calculate a true value. | 562 // use a default zero duration when we can't calculate a true value. |
| 562 TrackedTime start_of_run = stopwatch.StartTime(); | 563 TrackedTime start_of_run = stopwatch.StartTime(); |
| 563 int32 queue_duration = 0; | 564 int32_t queue_duration = 0; |
| 564 if (!start_of_run.is_null()) { | 565 if (!start_of_run.is_null()) { |
| 565 queue_duration = (start_of_run - completed_task.EffectiveTimePosted()) | 566 queue_duration = (start_of_run - completed_task.EffectiveTimePosted()) |
| 566 .InMilliseconds(); | 567 .InMilliseconds(); |
| 567 } | 568 } |
| 568 current_thread_data->TallyADeath(*births, queue_duration, stopwatch); | 569 current_thread_data->TallyADeath(*births, queue_duration, stopwatch); |
| 569 } | 570 } |
| 570 | 571 |
| 571 // static | 572 // static |
| 572 void ThreadData::TallyRunOnWorkerThreadIfTracking( | 573 void ThreadData::TallyRunOnWorkerThreadIfTracking( |
| 573 const Births* births, | 574 const Births* births, |
| (...skipping 12 matching lines...) Expand all Loading... |
| 586 // that the locks on TallyADeath will be *after* the worker thread has run, | 587 // that the locks on TallyADeath will be *after* the worker thread has run, |
| 587 // and hence nothing will be waiting for the completion (... besides some | 588 // and hence nothing will be waiting for the completion (... besides some |
| 588 // other thread that might like to run). Also, the worker threads tasks are | 589 // other thread that might like to run). Also, the worker threads tasks are |
| 589 // generally longer, and hence the cost of the lock may perchance be amortized | 590 // generally longer, and hence the cost of the lock may perchance be amortized |
| 590 // over the long task's lifetime. | 591 // over the long task's lifetime. |
| 591 ThreadData* current_thread_data = stopwatch.GetThreadData(); | 592 ThreadData* current_thread_data = stopwatch.GetThreadData(); |
| 592 if (!current_thread_data) | 593 if (!current_thread_data) |
| 593 return; | 594 return; |
| 594 | 595 |
| 595 TrackedTime start_of_run = stopwatch.StartTime(); | 596 TrackedTime start_of_run = stopwatch.StartTime(); |
| 596 int32 queue_duration = 0; | 597 int32_t queue_duration = 0; |
| 597 if (!start_of_run.is_null()) { | 598 if (!start_of_run.is_null()) { |
| 598 queue_duration = (start_of_run - time_posted).InMilliseconds(); | 599 queue_duration = (start_of_run - time_posted).InMilliseconds(); |
| 599 } | 600 } |
| 600 current_thread_data->TallyADeath(*births, queue_duration, stopwatch); | 601 current_thread_data->TallyADeath(*births, queue_duration, stopwatch); |
| 601 } | 602 } |
| 602 | 603 |
| 603 // static | 604 // static |
| 604 void ThreadData::TallyRunInAScopedRegionIfTracking( | 605 void ThreadData::TallyRunInAScopedRegionIfTracking( |
| 605 const Births* births, | 606 const Births* births, |
| 606 const TaskStopwatch& stopwatch) { | 607 const TaskStopwatch& stopwatch) { |
| 607 // Even if we have been DEACTIVATED, we will process any pending births so | 608 // Even if we have been DEACTIVATED, we will process any pending births so |
| 608 // that our data structures (which counted the outstanding births) remain | 609 // that our data structures (which counted the outstanding births) remain |
| 609 // consistent. | 610 // consistent. |
| 610 if (!births) | 611 if (!births) |
| 611 return; | 612 return; |
| 612 | 613 |
| 613 ThreadData* current_thread_data = stopwatch.GetThreadData(); | 614 ThreadData* current_thread_data = stopwatch.GetThreadData(); |
| 614 if (!current_thread_data) | 615 if (!current_thread_data) |
| 615 return; | 616 return; |
| 616 | 617 |
| 617 int32 queue_duration = 0; | 618 int32_t queue_duration = 0; |
| 618 current_thread_data->TallyADeath(*births, queue_duration, stopwatch); | 619 current_thread_data->TallyADeath(*births, queue_duration, stopwatch); |
| 619 } | 620 } |
| 620 | 621 |
| 621 void ThreadData::SnapshotExecutedTasks( | 622 void ThreadData::SnapshotExecutedTasks( |
| 622 int current_profiling_phase, | 623 int current_profiling_phase, |
| 623 PhasedProcessDataSnapshotMap* phased_snapshots, | 624 PhasedProcessDataSnapshotMap* phased_snapshots, |
| 624 BirthCountMap* birth_counts) { | 625 BirthCountMap* birth_counts) { |
| 625 // Get copy of data, so that the data will not change during the iterations | 626 // Get copy of data, so that the data will not change during the iterations |
| 626 // and processing. | 627 // and processing. |
| 627 BirthMap birth_map; | 628 BirthMap birth_map; |
| (...skipping 290 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 918 } | 919 } |
| 919 | 920 |
| 920 TrackedTime TaskStopwatch::StartTime() const { | 921 TrackedTime TaskStopwatch::StartTime() const { |
| 921 #if DCHECK_IS_ON() | 922 #if DCHECK_IS_ON() |
| 922 DCHECK(state_ != CREATED); | 923 DCHECK(state_ != CREATED); |
| 923 #endif | 924 #endif |
| 924 | 925 |
| 925 return start_time_; | 926 return start_time_; |
| 926 } | 927 } |
| 927 | 928 |
| 928 int32 TaskStopwatch::RunDurationMs() const { | 929 int32_t TaskStopwatch::RunDurationMs() const { |
| 929 #if DCHECK_IS_ON() | 930 #if DCHECK_IS_ON() |
| 930 DCHECK(state_ == STOPPED); | 931 DCHECK(state_ == STOPPED); |
| 931 #endif | 932 #endif |
| 932 | 933 |
| 933 return wallclock_duration_ms_ - excluded_duration_ms_; | 934 return wallclock_duration_ms_ - excluded_duration_ms_; |
| 934 } | 935 } |
| 935 | 936 |
| 936 ThreadData* TaskStopwatch::GetThreadData() const { | 937 ThreadData* TaskStopwatch::GetThreadData() const { |
| 937 #if DCHECK_IS_ON() | 938 #if DCHECK_IS_ON() |
| 938 DCHECK(state_ != CREATED); | 939 DCHECK(state_ != CREATED); |
| 939 #endif | 940 #endif |
| 940 | 941 |
| 941 return current_thread_data_; | 942 return current_thread_data_; |
| 942 } | 943 } |
| 943 | 944 |
| 944 //------------------------------------------------------------------------------ | 945 //------------------------------------------------------------------------------ |
| 945 // DeathDataPhaseSnapshot | 946 // DeathDataPhaseSnapshot |
| 946 | 947 |
| 947 DeathDataPhaseSnapshot::DeathDataPhaseSnapshot( | 948 DeathDataPhaseSnapshot::DeathDataPhaseSnapshot( |
| 948 int profiling_phase, | 949 int profiling_phase, |
| 949 int count, | 950 int count, |
| 950 int32 run_duration_sum, | 951 int32_t run_duration_sum, |
| 951 int32 run_duration_max, | 952 int32_t run_duration_max, |
| 952 int32 run_duration_sample, | 953 int32_t run_duration_sample, |
| 953 int32 queue_duration_sum, | 954 int32_t queue_duration_sum, |
| 954 int32 queue_duration_max, | 955 int32_t queue_duration_max, |
| 955 int32 queue_duration_sample, | 956 int32_t queue_duration_sample, |
| 956 const DeathDataPhaseSnapshot* prev) | 957 const DeathDataPhaseSnapshot* prev) |
| 957 : profiling_phase(profiling_phase), | 958 : profiling_phase(profiling_phase), |
| 958 death_data(count, | 959 death_data(count, |
| 959 run_duration_sum, | 960 run_duration_sum, |
| 960 run_duration_max, | 961 run_duration_max, |
| 961 run_duration_sample, | 962 run_duration_sample, |
| 962 queue_duration_sum, | 963 queue_duration_sum, |
| 963 queue_duration_max, | 964 queue_duration_max, |
| 964 queue_duration_sample), | 965 queue_duration_sample), |
| 965 prev(prev) { | 966 prev(prev) {} |
| 966 } | |
| 967 | 967 |
| 968 //------------------------------------------------------------------------------ | 968 //------------------------------------------------------------------------------ |
| 969 // TaskSnapshot | 969 // TaskSnapshot |
| 970 | 970 |
| 971 TaskSnapshot::TaskSnapshot() { | 971 TaskSnapshot::TaskSnapshot() { |
| 972 } | 972 } |
| 973 | 973 |
| 974 TaskSnapshot::TaskSnapshot(const BirthOnThreadSnapshot& birth, | 974 TaskSnapshot::TaskSnapshot(const BirthOnThreadSnapshot& birth, |
| 975 const DeathDataSnapshot& death_data, | 975 const DeathDataSnapshot& death_data, |
| 976 const std::string& death_thread_name) | 976 const std::string& death_thread_name) |
| (...skipping 22 matching lines...) Expand all Loading... |
| 999 : process_id(base::GetCurrentProcId()) { | 999 : process_id(base::GetCurrentProcId()) { |
| 1000 #else | 1000 #else |
| 1001 : process_id(base::kNullProcessId) { | 1001 : process_id(base::kNullProcessId) { |
| 1002 #endif | 1002 #endif |
| 1003 } | 1003 } |
| 1004 | 1004 |
| 1005 ProcessDataSnapshot::~ProcessDataSnapshot() { | 1005 ProcessDataSnapshot::~ProcessDataSnapshot() { |
| 1006 } | 1006 } |
| 1007 | 1007 |
| 1008 } // namespace tracked_objects | 1008 } // namespace tracked_objects |
| OLD | NEW |