| // Copyright 2014 the V8 project authors. All rights reserved. |
| // Use of this source code is governed by a BSD-style license that can be |
| // found in the LICENSE file. |
| |
| #include "src/v8.h" |
| |
| #include "src/heap/gc-tracer.h" |
| |
| namespace v8 { |
| namespace internal { |
| |
| static intptr_t CountTotalHolesSize(Heap* heap) { |
| intptr_t holes_size = 0; |
| OldSpaces spaces(heap); |
| for (OldSpace* space = spaces.next(); space != NULL; space = spaces.next()) { |
| holes_size += space->Waste() + space->Available(); |
| } |
| return holes_size; |
| } |
| |
| |
| GCTracer::AllocationEvent::AllocationEvent(double duration, |
| intptr_t allocation_in_bytes) { |
| duration_ = duration; |
| allocation_in_bytes_ = allocation_in_bytes; |
| } |
| |
| |
| GCTracer::ContextDisposalEvent::ContextDisposalEvent(double time) { |
| time_ = time; |
| } |
| |
| |
| GCTracer::SurvivalEvent::SurvivalEvent(double survival_rate) { |
| survival_rate_ = survival_rate; |
| } |
| |
| |
| GCTracer::Event::Event(Type type, const char* gc_reason, |
| const char* collector_reason) |
| : type(type), |
| gc_reason(gc_reason), |
| collector_reason(collector_reason), |
| start_time(0.0), |
| end_time(0.0), |
| start_object_size(0), |
| end_object_size(0), |
| start_memory_size(0), |
| end_memory_size(0), |
| start_holes_size(0), |
| end_holes_size(0), |
| cumulative_incremental_marking_steps(0), |
| incremental_marking_steps(0), |
| cumulative_incremental_marking_bytes(0), |
| incremental_marking_bytes(0), |
| cumulative_incremental_marking_duration(0.0), |
| incremental_marking_duration(0.0), |
| cumulative_pure_incremental_marking_duration(0.0), |
| pure_incremental_marking_duration(0.0), |
| longest_incremental_marking_step(0.0) { |
| for (int i = 0; i < Scope::NUMBER_OF_SCOPES; i++) { |
| scopes[i] = 0; |
| } |
| } |
| |
| |
| const char* GCTracer::Event::TypeName(bool short_name) const { |
| switch (type) { |
| case SCAVENGER: |
| if (short_name) { |
| return "s"; |
| } else { |
| return "Scavenge"; |
| } |
| case MARK_COMPACTOR: |
| case INCREMENTAL_MARK_COMPACTOR: |
| if (short_name) { |
| return "ms"; |
| } else { |
| return "Mark-sweep"; |
| } |
| case START: |
| if (short_name) { |
| return "st"; |
| } else { |
| return "Start"; |
| } |
| } |
| return "Unknown Event Type"; |
| } |
| |
| |
| GCTracer::GCTracer(Heap* heap) |
| : heap_(heap), |
| cumulative_incremental_marking_steps_(0), |
| cumulative_incremental_marking_bytes_(0), |
| cumulative_incremental_marking_duration_(0.0), |
| cumulative_pure_incremental_marking_duration_(0.0), |
| longest_incremental_marking_step_(0.0), |
| cumulative_marking_duration_(0.0), |
| cumulative_sweeping_duration_(0.0), |
| new_space_top_after_gc_(0), |
| start_counter_(0) { |
| current_ = Event(Event::START, NULL, NULL); |
| current_.end_time = base::OS::TimeCurrentMillis(); |
| previous_ = previous_incremental_mark_compactor_event_ = current_; |
| } |
| |
| |
| void GCTracer::Start(GarbageCollector collector, const char* gc_reason, |
| const char* collector_reason) { |
| start_counter_++; |
| if (start_counter_ != 1) return; |
| |
| previous_ = current_; |
| double start_time = base::OS::TimeCurrentMillis(); |
| if (new_space_top_after_gc_ != 0) { |
| AddNewSpaceAllocationTime( |
| start_time - previous_.end_time, |
| reinterpret_cast<intptr_t>((heap_->new_space()->top()) - |
| new_space_top_after_gc_)); |
| } |
| if (current_.type == Event::INCREMENTAL_MARK_COMPACTOR) |
| previous_incremental_mark_compactor_event_ = current_; |
| |
| if (collector == SCAVENGER) { |
| current_ = Event(Event::SCAVENGER, gc_reason, collector_reason); |
| } else if (collector == MARK_COMPACTOR) { |
| if (heap_->incremental_marking()->WasActivated()) { |
| current_ = |
| Event(Event::INCREMENTAL_MARK_COMPACTOR, gc_reason, collector_reason); |
| } else { |
| current_ = Event(Event::MARK_COMPACTOR, gc_reason, collector_reason); |
| } |
| } |
| |
| current_.start_time = start_time; |
| current_.start_object_size = heap_->SizeOfObjects(); |
| current_.start_memory_size = heap_->isolate()->memory_allocator()->Size(); |
| current_.start_holes_size = CountTotalHolesSize(heap_); |
| current_.new_space_object_size = |
| heap_->new_space()->top() - heap_->new_space()->bottom(); |
| |
| current_.cumulative_incremental_marking_steps = |
| cumulative_incremental_marking_steps_; |
| current_.cumulative_incremental_marking_bytes = |
| cumulative_incremental_marking_bytes_; |
| current_.cumulative_incremental_marking_duration = |
| cumulative_incremental_marking_duration_; |
| current_.cumulative_pure_incremental_marking_duration = |
| cumulative_pure_incremental_marking_duration_; |
| current_.longest_incremental_marking_step = longest_incremental_marking_step_; |
| |
| for (int i = 0; i < Scope::NUMBER_OF_SCOPES; i++) { |
| current_.scopes[i] = 0; |
| } |
| } |
| |
| |
| void GCTracer::Stop(GarbageCollector collector) { |
| start_counter_--; |
| if (start_counter_ != 0) { |
| if (FLAG_trace_gc) { |
| PrintF("[Finished reentrant %s during %s.]\n", |
| collector == SCAVENGER ? "Scavenge" : "Mark-sweep", |
| current_.TypeName(false)); |
| } |
| return; |
| } |
| |
| DCHECK(start_counter_ >= 0); |
| DCHECK((collector == SCAVENGER && current_.type == Event::SCAVENGER) || |
| (collector == MARK_COMPACTOR && |
| (current_.type == Event::MARK_COMPACTOR || |
| current_.type == Event::INCREMENTAL_MARK_COMPACTOR))); |
| |
| current_.end_time = base::OS::TimeCurrentMillis(); |
| current_.end_object_size = heap_->SizeOfObjects(); |
| current_.end_memory_size = heap_->isolate()->memory_allocator()->Size(); |
| current_.end_holes_size = CountTotalHolesSize(heap_); |
| new_space_top_after_gc_ = |
| reinterpret_cast<intptr_t>(heap_->new_space()->top()); |
| |
| if (current_.type == Event::SCAVENGER) { |
| current_.incremental_marking_steps = |
| current_.cumulative_incremental_marking_steps - |
| previous_.cumulative_incremental_marking_steps; |
| current_.incremental_marking_bytes = |
| current_.cumulative_incremental_marking_bytes - |
| previous_.cumulative_incremental_marking_bytes; |
| current_.incremental_marking_duration = |
| current_.cumulative_incremental_marking_duration - |
| previous_.cumulative_incremental_marking_duration; |
| current_.pure_incremental_marking_duration = |
| current_.cumulative_pure_incremental_marking_duration - |
| previous_.cumulative_pure_incremental_marking_duration; |
| scavenger_events_.push_front(current_); |
| } else if (current_.type == Event::INCREMENTAL_MARK_COMPACTOR) { |
| current_.incremental_marking_steps = |
| current_.cumulative_incremental_marking_steps - |
| previous_incremental_mark_compactor_event_ |
| .cumulative_incremental_marking_steps; |
| current_.incremental_marking_bytes = |
| current_.cumulative_incremental_marking_bytes - |
| previous_incremental_mark_compactor_event_ |
| .cumulative_incremental_marking_bytes; |
| current_.incremental_marking_duration = |
| current_.cumulative_incremental_marking_duration - |
| previous_incremental_mark_compactor_event_ |
| .cumulative_incremental_marking_duration; |
| current_.pure_incremental_marking_duration = |
| current_.cumulative_pure_incremental_marking_duration - |
| previous_incremental_mark_compactor_event_ |
| .cumulative_pure_incremental_marking_duration; |
| longest_incremental_marking_step_ = 0.0; |
| incremental_mark_compactor_events_.push_front(current_); |
| } else { |
| DCHECK(current_.incremental_marking_bytes == 0); |
| DCHECK(current_.incremental_marking_duration == 0); |
| DCHECK(current_.pure_incremental_marking_duration == 0); |
| DCHECK(longest_incremental_marking_step_ == 0.0); |
| mark_compactor_events_.push_front(current_); |
| } |
| |
| // TODO(ernstm): move the code below out of GCTracer. |
| |
| if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return; |
| |
| double duration = current_.end_time - current_.start_time; |
| double spent_in_mutator = Max(current_.start_time - previous_.end_time, 0.0); |
| |
| heap_->UpdateCumulativeGCStatistics(duration, spent_in_mutator, |
| current_.scopes[Scope::MC_MARK]); |
| |
| if (current_.type == Event::SCAVENGER && FLAG_trace_gc_ignore_scavenger) |
| return; |
| |
| if (FLAG_trace_gc) { |
| if (FLAG_trace_gc_nvp) |
| PrintNVP(); |
| else |
| Print(); |
| |
| heap_->PrintShortHeapStatistics(); |
| } |
| } |
| |
| |
| void GCTracer::AddNewSpaceAllocationTime(double duration, |
| intptr_t allocation_in_bytes) { |
| allocation_events_.push_front(AllocationEvent(duration, allocation_in_bytes)); |
| } |
| |
| |
| void GCTracer::AddContextDisposalTime(double time) { |
| context_disposal_events_.push_front(ContextDisposalEvent(time)); |
| } |
| |
| |
| void GCTracer::AddSurvivalRate(double survival_rate) { |
| survival_events_.push_front(SurvivalEvent(survival_rate)); |
| } |
| |
| |
| void GCTracer::AddIncrementalMarkingStep(double duration, intptr_t bytes) { |
| cumulative_incremental_marking_steps_++; |
| cumulative_incremental_marking_bytes_ += bytes; |
| cumulative_incremental_marking_duration_ += duration; |
| longest_incremental_marking_step_ = |
| Max(longest_incremental_marking_step_, duration); |
| cumulative_marking_duration_ += duration; |
| if (bytes > 0) { |
| cumulative_pure_incremental_marking_duration_ += duration; |
| } |
| } |
| |
| |
| void GCTracer::Print() const { |
| PrintPID("%8.0f ms: ", heap_->isolate()->time_millis_since_init()); |
| |
| PrintF("%s %.1f (%.1f) -> %.1f (%.1f) MB, ", current_.TypeName(false), |
| static_cast<double>(current_.start_object_size) / MB, |
| static_cast<double>(current_.start_memory_size) / MB, |
| static_cast<double>(current_.end_object_size) / MB, |
| static_cast<double>(current_.end_memory_size) / MB); |
| |
| int external_time = static_cast<int>(current_.scopes[Scope::EXTERNAL]); |
| if (external_time > 0) PrintF("%d / ", external_time); |
| |
| double duration = current_.end_time - current_.start_time; |
| PrintF("%.1f ms", duration); |
| if (current_.type == Event::SCAVENGER) { |
| if (current_.incremental_marking_steps > 0) { |
| PrintF(" (+ %.1f ms in %d steps since last GC)", |
| current_.incremental_marking_duration, |
| current_.incremental_marking_steps); |
| } |
| } else { |
| if (current_.incremental_marking_steps > 0) { |
| PrintF( |
| " (+ %.1f ms in %d steps since start of marking, " |
| "biggest step %.1f ms)", |
| current_.incremental_marking_duration, |
| current_.incremental_marking_steps, |
| current_.longest_incremental_marking_step); |
| } |
| } |
| |
| if (current_.gc_reason != NULL) { |
| PrintF(" [%s]", current_.gc_reason); |
| } |
| |
| if (current_.collector_reason != NULL) { |
| PrintF(" [%s]", current_.collector_reason); |
| } |
| |
| PrintF(".\n"); |
| } |
| |
| |
| void GCTracer::PrintNVP() const { |
| PrintPID("%8.0f ms: ", heap_->isolate()->time_millis_since_init()); |
| |
| double duration = current_.end_time - current_.start_time; |
| double spent_in_mutator = current_.start_time - previous_.end_time; |
| |
| PrintF("pause=%.1f ", duration); |
| PrintF("mutator=%.1f ", spent_in_mutator); |
| PrintF("gc=%s ", current_.TypeName(true)); |
| |
| PrintF("external=%.1f ", current_.scopes[Scope::EXTERNAL]); |
| PrintF("mark=%.1f ", current_.scopes[Scope::MC_MARK]); |
| PrintF("sweep=%.2f ", current_.scopes[Scope::MC_SWEEP]); |
| PrintF("sweepns=%.2f ", current_.scopes[Scope::MC_SWEEP_NEWSPACE]); |
| PrintF("sweepos=%.2f ", current_.scopes[Scope::MC_SWEEP_OLDSPACE]); |
| PrintF("sweepcode=%.2f ", current_.scopes[Scope::MC_SWEEP_CODE]); |
| PrintF("sweepcell=%.2f ", current_.scopes[Scope::MC_SWEEP_CELL]); |
| PrintF("sweepmap=%.2f ", current_.scopes[Scope::MC_SWEEP_MAP]); |
| PrintF("evacuate=%.1f ", current_.scopes[Scope::MC_EVACUATE_PAGES]); |
| PrintF("new_new=%.1f ", |
| current_.scopes[Scope::MC_UPDATE_NEW_TO_NEW_POINTERS]); |
| PrintF("root_new=%.1f ", |
| current_.scopes[Scope::MC_UPDATE_ROOT_TO_NEW_POINTERS]); |
| PrintF("old_new=%.1f ", |
| current_.scopes[Scope::MC_UPDATE_OLD_TO_NEW_POINTERS]); |
| PrintF("compaction_ptrs=%.1f ", |
| current_.scopes[Scope::MC_UPDATE_POINTERS_TO_EVACUATED]); |
| PrintF("intracompaction_ptrs=%.1f ", |
| current_.scopes[Scope::MC_UPDATE_POINTERS_BETWEEN_EVACUATED]); |
| PrintF("misc_compaction=%.1f ", |
| current_.scopes[Scope::MC_UPDATE_MISC_POINTERS]); |
| PrintF("weak_closure=%.1f ", current_.scopes[Scope::MC_WEAKCLOSURE]); |
| PrintF("weakcollection_process=%.1f ", |
| current_.scopes[Scope::MC_WEAKCOLLECTION_PROCESS]); |
| PrintF("weakcollection_clear=%.1f ", |
| current_.scopes[Scope::MC_WEAKCOLLECTION_CLEAR]); |
| PrintF("weakcollection_abort=%.1f ", |
| current_.scopes[Scope::MC_WEAKCOLLECTION_ABORT]); |
| |
| PrintF("total_size_before=%" V8_PTR_PREFIX "d ", current_.start_object_size); |
| PrintF("total_size_after=%" V8_PTR_PREFIX "d ", current_.end_object_size); |
| PrintF("holes_size_before=%" V8_PTR_PREFIX "d ", current_.start_holes_size); |
| PrintF("holes_size_after=%" V8_PTR_PREFIX "d ", current_.end_holes_size); |
| |
| intptr_t allocated_since_last_gc = |
| current_.start_object_size - previous_.end_object_size; |
| PrintF("allocated=%" V8_PTR_PREFIX "d ", allocated_since_last_gc); |
| PrintF("promoted=%" V8_PTR_PREFIX "d ", heap_->promoted_objects_size_); |
| PrintF("semi_space_copied=%" V8_PTR_PREFIX "d ", |
| heap_->semi_space_copied_object_size_); |
| PrintF("nodes_died_in_new=%d ", heap_->nodes_died_in_new_space_); |
| PrintF("nodes_copied_in_new=%d ", heap_->nodes_copied_in_new_space_); |
| PrintF("nodes_promoted=%d ", heap_->nodes_promoted_); |
| PrintF("promotion_ratio=%.1f%% ", heap_->promotion_ratio_); |
| PrintF("promotion_rate=%.1f%% ", heap_->promotion_rate_); |
| PrintF("semi_space_copy_rate=%.1f%% ", heap_->semi_space_copied_rate_); |
| PrintF("average_survival_rate%.1f%% ", AverageSurvivalRate()); |
| PrintF("new_space_allocation_throughput=%" V8_PTR_PREFIX "d ", |
| NewSpaceAllocationThroughputInBytesPerMillisecond()); |
| PrintF("context_disposal_rate=%.1f ", ContextDisposalRateInMilliseconds()); |
| |
| if (current_.type == Event::SCAVENGER) { |
| PrintF("steps_count=%d ", current_.incremental_marking_steps); |
| PrintF("steps_took=%.1f ", current_.incremental_marking_duration); |
| PrintF("scavenge_throughput=%" V8_PTR_PREFIX "d ", |
| ScavengeSpeedInBytesPerMillisecond()); |
| } else { |
| PrintF("steps_count=%d ", current_.incremental_marking_steps); |
| PrintF("steps_took=%.1f ", current_.incremental_marking_duration); |
| PrintF("longest_step=%.1f ", current_.longest_incremental_marking_step); |
| PrintF("incremental_marking_throughput=%" V8_PTR_PREFIX "d ", |
| IncrementalMarkingSpeedInBytesPerMillisecond()); |
| } |
| |
| PrintF("\n"); |
| } |
| |
| |
| double GCTracer::MeanDuration(const EventBuffer& events) const { |
| if (events.empty()) return 0.0; |
| |
| double mean = 0.0; |
| EventBuffer::const_iterator iter = events.begin(); |
| while (iter != events.end()) { |
| mean += iter->end_time - iter->start_time; |
| ++iter; |
| } |
| |
| return mean / events.size(); |
| } |
| |
| |
| double GCTracer::MaxDuration(const EventBuffer& events) const { |
| if (events.empty()) return 0.0; |
| |
| double maximum = 0.0f; |
| EventBuffer::const_iterator iter = events.begin(); |
| while (iter != events.end()) { |
| maximum = Max(iter->end_time - iter->start_time, maximum); |
| ++iter; |
| } |
| |
| return maximum; |
| } |
| |
| |
| double GCTracer::MeanIncrementalMarkingDuration() const { |
| if (cumulative_incremental_marking_steps_ == 0) return 0.0; |
| |
| // We haven't completed an entire round of incremental marking, yet. |
| // Use data from GCTracer instead of data from event buffers. |
| if (incremental_mark_compactor_events_.empty()) { |
| return cumulative_incremental_marking_duration_ / |
| cumulative_incremental_marking_steps_; |
| } |
| |
| int steps = 0; |
| double durations = 0.0; |
| EventBuffer::const_iterator iter = incremental_mark_compactor_events_.begin(); |
| while (iter != incremental_mark_compactor_events_.end()) { |
| steps += iter->incremental_marking_steps; |
| durations += iter->incremental_marking_duration; |
| ++iter; |
| } |
| |
| if (steps == 0) return 0.0; |
| |
| return durations / steps; |
| } |
| |
| |
| double GCTracer::MaxIncrementalMarkingDuration() const { |
| // We haven't completed an entire round of incremental marking, yet. |
| // Use data from GCTracer instead of data from event buffers. |
| if (incremental_mark_compactor_events_.empty()) |
| return longest_incremental_marking_step_; |
| |
| double max_duration = 0.0; |
| EventBuffer::const_iterator iter = incremental_mark_compactor_events_.begin(); |
| while (iter != incremental_mark_compactor_events_.end()) |
| max_duration = Max(iter->longest_incremental_marking_step, max_duration); |
| |
| return max_duration; |
| } |
| |
| |
| intptr_t GCTracer::IncrementalMarkingSpeedInBytesPerMillisecond() const { |
| if (cumulative_incremental_marking_duration_ == 0.0) return 0; |
| |
| // We haven't completed an entire round of incremental marking, yet. |
| // Use data from GCTracer instead of data from event buffers. |
| if (incremental_mark_compactor_events_.empty()) { |
| return static_cast<intptr_t>(cumulative_incremental_marking_bytes_ / |
| cumulative_pure_incremental_marking_duration_); |
| } |
| |
| intptr_t bytes = 0; |
| double durations = 0.0; |
| EventBuffer::const_iterator iter = incremental_mark_compactor_events_.begin(); |
| while (iter != incremental_mark_compactor_events_.end()) { |
| bytes += iter->incremental_marking_bytes; |
| durations += iter->pure_incremental_marking_duration; |
| ++iter; |
| } |
| |
| if (durations == 0.0) return 0; |
| |
| return static_cast<intptr_t>(bytes / durations); |
| } |
| |
| |
| intptr_t GCTracer::ScavengeSpeedInBytesPerMillisecond() const { |
| intptr_t bytes = 0; |
| double durations = 0.0; |
| EventBuffer::const_iterator iter = scavenger_events_.begin(); |
| while (iter != scavenger_events_.end()) { |
| bytes += iter->new_space_object_size; |
| durations += iter->end_time - iter->start_time; |
| ++iter; |
| } |
| |
| if (durations == 0.0) return 0; |
| |
| return static_cast<intptr_t>(bytes / durations); |
| } |
| |
| |
| intptr_t GCTracer::MarkCompactSpeedInBytesPerMillisecond() const { |
| intptr_t bytes = 0; |
| double durations = 0.0; |
| EventBuffer::const_iterator iter = mark_compactor_events_.begin(); |
| while (iter != mark_compactor_events_.end()) { |
| bytes += iter->start_object_size; |
| durations += iter->end_time - iter->start_time; |
| ++iter; |
| } |
| |
| if (durations == 0.0) return 0; |
| |
| return static_cast<intptr_t>(bytes / durations); |
| } |
| |
| |
| intptr_t GCTracer::FinalIncrementalMarkCompactSpeedInBytesPerMillisecond() |
| const { |
| intptr_t bytes = 0; |
| double durations = 0.0; |
| EventBuffer::const_iterator iter = incremental_mark_compactor_events_.begin(); |
| while (iter != incremental_mark_compactor_events_.end()) { |
| bytes += iter->start_object_size; |
| durations += iter->end_time - iter->start_time; |
| ++iter; |
| } |
| |
| if (durations == 0.0) return 0; |
| |
| return static_cast<intptr_t>(bytes / durations); |
| } |
| |
| |
| intptr_t GCTracer::NewSpaceAllocationThroughputInBytesPerMillisecond() const { |
| intptr_t bytes = 0; |
| double durations = 0.0; |
| AllocationEventBuffer::const_iterator iter = allocation_events_.begin(); |
| while (iter != allocation_events_.end()) { |
| bytes += iter->allocation_in_bytes_; |
| durations += iter->duration_; |
| ++iter; |
| } |
| |
| if (durations == 0.0) return 0; |
| |
| return static_cast<intptr_t>(bytes / durations); |
| } |
| |
| |
| double GCTracer::ContextDisposalRateInMilliseconds() const { |
| if (context_disposal_events_.size() < kRingBufferMaxSize) return 0.0; |
| |
| double begin = base::OS::TimeCurrentMillis(); |
| double end = 0.0; |
| ContextDisposalEventBuffer::const_iterator iter = |
| context_disposal_events_.begin(); |
| while (iter != context_disposal_events_.end()) { |
| end = iter->time_; |
| ++iter; |
| } |
| |
| return (begin - end) / context_disposal_events_.size(); |
| } |
| |
| |
| double GCTracer::AverageSurvivalRate() const { |
| if (survival_events_.size() == 0) return 0.0; |
| |
| double sum_of_rates = 0.0; |
| SurvivalEventBuffer::const_iterator iter = survival_events_.begin(); |
| while (iter != survival_events_.end()) { |
| sum_of_rates += iter->survival_rate_; |
| ++iter; |
| } |
| |
| return sum_of_rates / static_cast<double>(survival_events_.size()); |
| } |
| |
| |
| bool GCTracer::SurvivalEventsRecorded() const { |
| return survival_events_.size() > 0; |
| } |
| |
| |
| void GCTracer::ResetSurvivalEvents() { survival_events_.reset(); } |
| } |
| } // namespace v8::internal |