diff --git a/src/cpu-profiler-inl.h b/src/cpu-profiler-inl.h index bafea0679f..868ec64fd6 100644 --- a/src/cpu-profiler-inl.h +++ b/src/cpu-profiler-inl.h @@ -68,7 +68,6 @@ void ReportBuiltinEventRecord::UpdateCodeMap(CodeMap* code_map) { TickSample* ProfilerEventsProcessor::TickSampleEvent() { - generator_->Tick(); TickSampleEventRecord* evt = new(ticks_buffer_.Enqueue()) TickSampleEventRecord(last_code_event_id_); return &evt->sample; diff --git a/src/cpu-profiler.cc b/src/cpu-profiler.cc index 0d226cfb3f..0a83b85f50 100644 --- a/src/cpu-profiler.cc +++ b/src/cpu-profiler.cc @@ -452,9 +452,8 @@ void CpuProfiler::StartProcessorIfNotStarted() { CpuProfile* CpuProfiler::StopProfiling(const char* title) { if (!is_profiling_) return NULL; - const double actual_sampling_rate = generator_->actual_sampling_rate(); StopProcessorIfLastProfile(title); - CpuProfile* result = profiles_->StopProfiling(title, actual_sampling_rate); + CpuProfile* result = profiles_->StopProfiling(title); if (result != NULL) { result->Print(); } @@ -464,10 +463,9 @@ CpuProfile* CpuProfiler::StopProfiling(const char* title) { CpuProfile* CpuProfiler::StopProfiling(String* title) { if (!is_profiling_) return NULL; - const double actual_sampling_rate = generator_->actual_sampling_rate(); const char* profile_title = profiles_->GetName(title); StopProcessorIfLastProfile(profile_title); - return profiles_->StopProfiling(profile_title, actual_sampling_rate); + return profiles_->StopProfiling(profile_title); } diff --git a/src/profile-generator.cc b/src/profile-generator.cc index 8428303afe..4e2e38988a 100644 --- a/src/profile-generator.cc +++ b/src/profile-generator.cc @@ -372,19 +372,30 @@ void ProfileTree::ShortPrint() { } +CpuProfile::CpuProfile(const char* title, unsigned uid, bool record_samples) + : title_(title), + uid_(uid), + record_samples_(record_samples), + start_time_ms_(OS::TimeCurrentMillis()), + end_time_ms_(0) { +} + + void CpuProfile::AddPath(const Vector& path) { ProfileNode* top_frame_node = top_down_.AddPathFromEnd(path); if (record_samples_) samples_.Add(top_frame_node); } -void CpuProfile::CalculateTotalTicks() { +void CpuProfile::CalculateTotalTicksAndSamplingRate() { + end_time_ms_ = OS::TimeCurrentMillis(); top_down_.CalculateTotalTicks(); -} - -void CpuProfile::SetActualSamplingRate(double actual_sampling_rate) { - top_down_.SetTickRatePerMs(actual_sampling_rate); + double duration = end_time_ms_ - start_time_ms_; + if (duration < 1) duration = 1; + unsigned ticks = top_down_.root()->total_ticks(); + double rate = ticks / duration; + top_down_.SetTickRatePerMs(rate); } @@ -529,8 +540,7 @@ bool CpuProfilesCollection::StartProfiling(const char* title, unsigned uid, } -CpuProfile* CpuProfilesCollection::StopProfiling(const char* title, - double actual_sampling_rate) { +CpuProfile* CpuProfilesCollection::StopProfiling(const char* title) { const int title_len = StrLength(title); CpuProfile* profile = NULL; current_profiles_semaphore_->Wait(); @@ -543,8 +553,7 @@ CpuProfile* CpuProfilesCollection::StopProfiling(const char* title, current_profiles_semaphore_->Signal(); if (profile == NULL) return NULL; - profile->CalculateTotalTicks(); - profile->SetActualSamplingRate(actual_sampling_rate); + profile->CalculateTotalTicksAndSamplingRate(); finished_profiles_.Add(profile); return profile; } @@ -601,29 +610,6 @@ CodeEntry* CpuProfilesCollection::NewCodeEntry( } -void SampleRateCalculator::Tick() { - if (--wall_time_query_countdown_ == 0) - UpdateMeasurements(OS::TimeCurrentMillis()); -} - - -void SampleRateCalculator::UpdateMeasurements(double current_time) { - if (measurements_count_++ != 0) { - const double measured_ticks_per_ms = - (kWallTimeQueryIntervalMs * ticks_per_ms_) / - (current_time - last_wall_time_); - // Update the average value. - ticks_per_ms_ += - (measured_ticks_per_ms - ticks_per_ms_) / measurements_count_; - // Update the externally accessible result. - result_ = static_cast(ticks_per_ms_ * kResultScale); - } - last_wall_time_ = current_time; - wall_time_query_countdown_ = - static_cast(kWallTimeQueryIntervalMs * ticks_per_ms_); -} - - const char* const ProfileGenerator::kAnonymousFunctionName = "(anonymous function)"; const char* const ProfileGenerator::kProgramEntryName = diff --git a/src/profile-generator.h b/src/profile-generator.h index 6b02368816..7861ccd817 100644 --- a/src/profile-generator.h +++ b/src/profile-generator.h @@ -203,13 +203,11 @@ class ProfileTree { class CpuProfile { public: - CpuProfile(const char* title, unsigned uid, bool record_samples) - : title_(title), uid_(uid), record_samples_(record_samples) { } + CpuProfile(const char* title, unsigned uid, bool record_samples); // Add pc -> ... -> main() call path to the profile. void AddPath(const Vector& path); - void CalculateTotalTicks(); - void SetActualSamplingRate(double actual_sampling_rate); + void CalculateTotalTicksAndSamplingRate(); INLINE(const char* title() const) { return title_; } INLINE(unsigned uid() const) { return uid_; } @@ -227,6 +225,8 @@ class CpuProfile { const char* title_; unsigned uid_; bool record_samples_; + double start_time_ms_; + double end_time_ms_; List samples_; ProfileTree top_down_; @@ -286,7 +286,7 @@ class CpuProfilesCollection { ~CpuProfilesCollection(); bool StartProfiling(const char* title, unsigned uid, bool record_samples); - CpuProfile* StopProfiling(const char* title, double actual_sampling_rate); + CpuProfile* StopProfiling(const char* title); List* profiles() { return &finished_profiles_; } const char* GetName(Name* name) { return function_and_resource_names_.GetName(name); @@ -329,44 +329,6 @@ class CpuProfilesCollection { }; -class SampleRateCalculator { - public: - SampleRateCalculator() - : result_(Logger::kSamplingIntervalMs * kResultScale), - ticks_per_ms_(Logger::kSamplingIntervalMs), - measurements_count_(0), - wall_time_query_countdown_(1) { - } - - double ticks_per_ms() { - return result_ / static_cast(kResultScale); - } - void Tick(); - void UpdateMeasurements(double current_time); - - // Instead of querying current wall time each tick, - // we use this constant to control query intervals. - static const unsigned kWallTimeQueryIntervalMs = 100; - - private: - // As the result needs to be accessed from a different thread, we - // use type that guarantees atomic writes to memory. There should - // be <= 1000 ticks per second, thus storing a value of a 10 ** 5 - // order should provide enough precision while keeping away from a - // potential overflow. - static const int kResultScale = 100000; - - AtomicWord result_; - // All other fields are accessed only from the sampler thread. - double ticks_per_ms_; - unsigned measurements_count_; - unsigned wall_time_query_countdown_; - double last_wall_time_; - - DISALLOW_COPY_AND_ASSIGN(SampleRateCalculator); -}; - - class ProfileGenerator { public: explicit ProfileGenerator(CpuProfilesCollection* profiles); @@ -375,11 +337,6 @@ class ProfileGenerator { INLINE(CodeMap* code_map()) { return &code_map_; } - INLINE(void Tick()) { sample_rate_calc_.Tick(); } - INLINE(double actual_sampling_rate()) { - return sample_rate_calc_.ticks_per_ms(); - } - static const char* const kAnonymousFunctionName; static const char* const kProgramEntryName; static const char* const kGarbageCollectorEntryName; @@ -395,7 +352,6 @@ class ProfileGenerator { CodeEntry* program_entry_; CodeEntry* gc_entry_; CodeEntry* unresolved_entry_; - SampleRateCalculator sample_rate_calc_; DISALLOW_COPY_AND_ASSIGN(ProfileGenerator); }; diff --git a/test/cctest/test-cpu-profiler.cc b/test/cctest/test-cpu-profiler.cc index fe5e2788ff..d9ecc41a74 100644 --- a/test/cctest/test-cpu-profiler.cc +++ b/test/cctest/test-cpu-profiler.cc @@ -222,7 +222,7 @@ TEST(TickEvents) { processor.StopSynchronously(); processor.Join(); - CpuProfile* profile = profiles->StopProfiling("", 1); + CpuProfile* profile = profiles->StopProfiling(""); CHECK_NE(NULL, profile); // Check call trees. @@ -286,7 +286,7 @@ TEST(Issue1398) { processor.StopSynchronously(); processor.Join(); - CpuProfile* profile = profiles->StopProfiling("", 1); + CpuProfile* profile = profiles->StopProfiling(""); CHECK_NE(NULL, profile); int actual_depth = 0; diff --git a/test/cctest/test-profile-generator.cc b/test/cctest/test-profile-generator.cc index 7b8278ba66..f56275c1be 100644 --- a/test/cctest/test-profile-generator.cc +++ b/test/cctest/test-profile-generator.cc @@ -41,7 +41,6 @@ using i::CpuProfilesCollection; using i::ProfileNode; using i::ProfileTree; using i::ProfileGenerator; -using i::SampleRateCalculator; using i::TickSample; using i::Vector; @@ -485,7 +484,7 @@ TEST(RecordTickSample) { sample3.frames_count = 2; generator.RecordTickSample(sample3); - CpuProfile* profile = profiles.StopProfiling("", 1); + CpuProfile* profile = profiles.StopProfiling(""); CHECK_NE(NULL, profile); ProfileTreeTestHelper top_down_test_helper(profile->top_down()); CHECK_EQ(NULL, top_down_test_helper.Walk(entry2)); @@ -505,56 +504,6 @@ TEST(RecordTickSample) { } -TEST(SampleRateCalculator) { - const double kSamplingIntervalMs = i::Logger::kSamplingIntervalMs; - - // Verify that ticking exactly in query intervals results in the - // initial sampling interval. - double time = 0.0; - SampleRateCalculator calc1; - CHECK_EQ(kSamplingIntervalMs, calc1.ticks_per_ms()); - calc1.UpdateMeasurements(time); - CHECK_EQ(kSamplingIntervalMs, calc1.ticks_per_ms()); - time += SampleRateCalculator::kWallTimeQueryIntervalMs; - calc1.UpdateMeasurements(time); - CHECK_EQ(kSamplingIntervalMs, calc1.ticks_per_ms()); - time += SampleRateCalculator::kWallTimeQueryIntervalMs; - calc1.UpdateMeasurements(time); - CHECK_EQ(kSamplingIntervalMs, calc1.ticks_per_ms()); - time += SampleRateCalculator::kWallTimeQueryIntervalMs; - calc1.UpdateMeasurements(time); - CHECK_EQ(kSamplingIntervalMs, calc1.ticks_per_ms()); - - SampleRateCalculator calc2; - time = 0.0; - CHECK_EQ(kSamplingIntervalMs, calc2.ticks_per_ms()); - calc2.UpdateMeasurements(time); - CHECK_EQ(kSamplingIntervalMs, calc2.ticks_per_ms()); - time += SampleRateCalculator::kWallTimeQueryIntervalMs * 0.5; - calc2.UpdateMeasurements(time); - // (1.0 + 2.0) / 2 - CHECK_EQ(kSamplingIntervalMs * 1.5, calc2.ticks_per_ms()); - time += SampleRateCalculator::kWallTimeQueryIntervalMs * 0.75; - calc2.UpdateMeasurements(time); - // (1.0 + 2.0 + 2.0) / 3 - CHECK_EQ(kSamplingIntervalMs * 5.0, floor(calc2.ticks_per_ms() * 3.0 + 0.5)); - - SampleRateCalculator calc3; - time = 0.0; - CHECK_EQ(kSamplingIntervalMs, calc3.ticks_per_ms()); - calc3.UpdateMeasurements(time); - CHECK_EQ(kSamplingIntervalMs, calc3.ticks_per_ms()); - time += SampleRateCalculator::kWallTimeQueryIntervalMs * 2; - calc3.UpdateMeasurements(time); - // (1.0 + 0.5) / 2 - CHECK_EQ(kSamplingIntervalMs * 0.75, calc3.ticks_per_ms()); - time += SampleRateCalculator::kWallTimeQueryIntervalMs * 1.5; - calc3.UpdateMeasurements(time); - // (1.0 + 0.5 + 0.5) / 3 - CHECK_EQ(kSamplingIntervalMs * 2.0, floor(calc3.ticks_per_ms() * 3.0 + 0.5)); -} - - static void CheckNodeIds(ProfileNode* node, int* expectedId) { CHECK_EQ((*expectedId)++, node->id()); for (int i = 0; i < node->children()->length(); i++) { @@ -598,7 +547,7 @@ TEST(SampleIds) { sample3.frames_count = 2; generator.RecordTickSample(sample3); - CpuProfile* profile = profiles.StopProfiling("", 1); + CpuProfile* profile = profiles.StopProfiling(""); int nodeId = 1; CheckNodeIds(profile->top_down()->root(), &nodeId); CHECK_EQ(7, nodeId - 1); @@ -627,7 +576,7 @@ TEST(NoSamples) { sample1.frames_count = 1; generator.RecordTickSample(sample1); - CpuProfile* profile = profiles.StopProfiling("", 1); + CpuProfile* profile = profiles.StopProfiling(""); int nodeId = 1; CheckNodeIds(profile->top_down()->root(), &nodeId); CHECK_EQ(3, nodeId - 1);