Chromium Code Reviews
chromiumcodereview-hr@appspot.gserviceaccount.com (chromiumcodereview-hr) | Please choose your nickname with Settings | Help | Chromium Project | Gerrit Changes | Sign out
(362)

Unified Diff: src/heap.cc

Issue 391413006: Track history of events in GCTracer. (Closed) Base URL: https://v8.googlecode.com/svn/branches/bleeding_edge
Patch Set: Clean-ups Created 6 years, 5 months ago
Use n/p to move between diff chunks; N/P to move between comments. Draft comments are only viewable by you.
Jump to:
View side-by-side diff with in-line comments
Download patch
« no previous file with comments | « src/heap.h ('k') | src/incremental-marking.h » ('j') | no next file with comments »
Expand Comments ('e') | Collapse Comments ('c') | Show Comments Hide Comments ('s')
Index: src/heap.cc
diff --git a/src/heap.cc b/src/heap.cc
index f5f4604d3b98ed34969bf952bdbded6ee61d7c84..7e226c7d7d5c955c4a44bc1d5ed377d22aa9edd6 100644
--- a/src/heap.cc
+++ b/src/heap.cc
@@ -113,8 +113,6 @@ Heap::Heap()
total_gc_time_ms_(0.0),
max_alive_after_gc_(0),
min_in_mutator_(kMaxInt),
- alive_after_last_gc_(0),
- last_gc_end_timestamp_(base::OS::TimeCurrentMillis()),
marking_time_(0.0),
sweeping_time_(0.0),
mark_compact_collector_(this),
@@ -840,7 +838,7 @@ bool Heap::CollectGarbage(GarbageCollector collector,
bool next_gc_likely_to_collect_more = false;
- { tracer()->start(collector, gc_reason, collector_reason);
+ { tracer()->Start(collector, gc_reason, collector_reason);
ASSERT(AllowHeapAllocation::IsAllowed());
DisallowHeapAllocation no_allocation_during_gc;
GarbageCollectionPrologue();
@@ -854,7 +852,7 @@ bool Heap::CollectGarbage(GarbageCollector collector,
}
GarbageCollectionEpilogue();
- tracer()->stop();
+ tracer()->Stop();
}
// Start incremental marking for the next cycle. The heap snapshot
@@ -5958,18 +5956,13 @@ static intptr_t CountTotalHolesSize(Heap* heap) {
}
-void Heap::UpdateGCStatistics(double start_time,
- double end_time,
- double spent_in_mutator,
- double marking_time) {
- double duration = end_time - start_time;
- alive_after_last_gc_ = SizeOfObjects();
- last_gc_end_timestamp_ = end_time;
-
+void Heap::UpdateCumulativeGCStatistics(double duration,
+ double spent_in_mutator,
+ double marking_time) {
if (FLAG_print_cumulative_gc_stat) {
total_gc_time_ms_ += duration;
max_gc_pause_ = Max(max_gc_pause_, duration);
- max_alive_after_gc_ = Max(max_alive_after_gc_, alive_after_last_gc_);
+ max_alive_after_gc_ = Max(max_alive_after_gc_, SizeOfObjects());
min_in_mutator_ = Min(min_in_mutator_, spent_in_mutator);
} else if (FLAG_trace_gc_verbose) {
total_gc_time_ms_ += duration;
@@ -5979,77 +5972,121 @@ void Heap::UpdateGCStatistics(double start_time,
}
-GCTracer::GCTracer(Heap* heap)
- : start_time_(0.0),
- end_time_(0.0),
- start_object_size_(0),
- end_object_size_(0),
- start_memory_size_(0),
- end_memory_size_(0),
- in_free_list_or_wasted_before_gc_(0),
- allocated_since_last_gc_(0),
- spent_in_mutator_(0),
- steps_count_(0),
- steps_took_(0.0),
- longest_step_(0.0),
- steps_count_since_last_gc_(0),
- steps_took_since_last_gc_(0.0),
- heap_(heap),
- gc_reason_(NULL),
- collector_reason_(NULL) {
+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),
+ incremental_marking_steps(0),
+ incremental_marking_duration(0.0) {
for (int i = 0; i < Scope::NUMBER_OF_SCOPES; i++) {
- scopes_[i] = 0;
+ scopes[i] = 0;
}
}
-void GCTracer::start(GarbageCollector collector,
- const char* gc_reason,
- const char* collector_reason) {
- if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
+const char* GCTracer::Event::TypeName(bool short_name) const {
+ switch (type) {
+ case SCAVENGER:
+ if (short_name) {
+ return "s";
+ } else {
+ return "Scavenge";
+ }
+ case 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";
+}
- collector_ = collector;
- gc_reason_ = gc_reason;
- collector_reason_ = collector_reason;
- start_time_ = base::OS::TimeCurrentMillis();
- start_object_size_ = heap_->SizeOfObjects();
- start_memory_size_ = heap_->isolate()->memory_allocator()->Size();
+GCTracer::GCTracer(Heap* heap)
+ : heap_(heap),
+ incremental_marking_steps_(0),
+ incremental_marking_duration_(0.0),
+ longest_incremental_marking_step_(0.0) {
+ current_ = Event(Event::START, NULL, NULL);
+ current_.end_time = base::OS::TimeCurrentMillis();
+ previous_ = previous_mark_compactor_event_ = current_;
+}
- for (int i = 0; i < Scope::NUMBER_OF_SCOPES; i++) {
- scopes_[i] = 0;
- }
- in_free_list_or_wasted_before_gc_ = CountTotalHolesSize(heap_);
+void GCTracer::Start(GarbageCollector collector,
+ const char* gc_reason,
+ const char* collector_reason) {
+ if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
+
+ previous_ = current_;
+ if (current_.type == Event::MARK_COMPACTOR)
+ previous_mark_compactor_event_ = current_;
+
+ if (collector == SCAVENGER) {
+ current_ = Event(Event::SCAVENGER, gc_reason, collector_reason);
+ } else {
+ current_ = Event(Event::MARK_COMPACTOR, gc_reason, collector_reason);
+ }
- allocated_since_last_gc_ =
- heap_->SizeOfObjects() - heap_->alive_after_last_gc_;
+ current_.start_time = base::OS::TimeCurrentMillis();
+ current_.start_object_size = heap_->SizeOfObjects();
+ current_.start_memory_size = heap_->isolate()->memory_allocator()->Size();
+ current_.start_holes_size = CountTotalHolesSize(heap_);
- spent_in_mutator_ = Max(start_time_ - heap_->last_gc_end_timestamp_, 0.0);
+ current_.incremental_marking_steps = incremental_marking_steps_;
+ current_.incremental_marking_duration = incremental_marking_duration_;
+ current_.longest_incremental_marking_step = longest_incremental_marking_step_;
- steps_count_ = heap_->incremental_marking()->steps_count();
- steps_took_ = heap_->incremental_marking()->steps_took();
- longest_step_ = heap_->incremental_marking()->longest_step();
- steps_count_since_last_gc_ =
- heap_->incremental_marking()->steps_count_since_last_gc();
- steps_took_since_last_gc_ =
- heap_->incremental_marking()->steps_took_since_last_gc();
+ for (int i = 0; i < Scope::NUMBER_OF_SCOPES; i++) {
+ current_.scopes[i] = 0;
+ }
}
-void GCTracer::stop() {
+void GCTracer::Stop() {
if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
- end_time_ = base::OS::TimeCurrentMillis();
- end_object_size_ = heap_->SizeOfObjects();
- end_memory_size_ = heap_->isolate()->memory_allocator()->Size();
+ 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_);
+
+ if (current_.type == Event::SCAVENGER) {
+ scavenger_events_.push_front(current_);
+ } else {
+ mark_compactor_events_.push_front(current_);
+ }
- heap_->UpdateGCStatistics(start_time_,
- end_time_,
- spent_in_mutator_,
- scopes_[Scope::MC_MARK]);
+ if (current_.type == Event::MARK_COMPACTOR)
+ longest_incremental_marking_step_ = 0.0;
- if (collector_ == SCAVENGER && FLAG_trace_gc_ignore_scavenger) 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)
@@ -6062,40 +6099,57 @@ void GCTracer::stop() {
}
+void GCTracer::AddIncrementalMarkingStep(double duration) {
+ incremental_marking_steps_++;
+ incremental_marking_duration_ += duration;
+ longest_incremental_marking_step_ =
+ Max(longest_incremental_marking_step_, duration);
+}
+
+
void GCTracer::Print() const {
PrintPID("%8.0f ms: ", heap_->isolate()->time_millis_since_init());
PrintF("%s %.1f (%.1f) -> %.1f (%.1f) MB, ",
- CollectorString(),
- static_cast<double>(start_object_size_) / MB,
- static_cast<double>(start_memory_size_) / MB,
- static_cast<double>(end_object_size_) / MB,
- static_cast<double>(end_memory_size_) / 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>(scopes_[Scope::EXTERNAL]);
+ int external_time = static_cast<int>(current_.scopes[Scope::EXTERNAL]);
if (external_time > 0) PrintF("%d / ", external_time);
- PrintF("%.1f ms", end_time_ - start_time_);
- if (steps_count_ > 0) {
- if (collector_ == SCAVENGER) {
+ double duration = current_.end_time - current_.start_time;
+ PrintF("%.1f ms", duration);
+ if (current_.type == Event::SCAVENGER) {
+ int steps = current_.incremental_marking_steps -
+ previous_.incremental_marking_steps;
+ if (steps > 0) {
PrintF(" (+ %.1f ms in %d steps since last GC)",
- steps_took_since_last_gc_,
- steps_count_since_last_gc_);
- } else {
+ current_.incremental_marking_duration -
+ previous_.incremental_marking_duration,
+ steps);
+ }
+ } else {
+ int steps = current_.incremental_marking_steps -
+ previous_mark_compactor_event_.incremental_marking_steps;
+ if (steps > 0) {
PrintF(" (+ %.1f ms in %d steps since start of marking, "
"biggest step %.1f ms)",
- steps_took_,
- steps_count_,
- longest_step_);
+ current_.incremental_marking_duration -
+ previous_mark_compactor_event_.incremental_marking_duration,
+ steps,
+ current_.longest_incremental_marking_step);
}
}
- if (gc_reason_ != NULL) {
- PrintF(" [%s]", gc_reason_);
+ if (current_.gc_reason != NULL) {
+ PrintF(" [%s]", current_.gc_reason);
}
- if (collector_reason_ != NULL) {
- PrintF(" [%s]", collector_reason_);
+ if (current_.collector_reason != NULL) {
+ PrintF(" [%s]", current_.collector_reason);
}
PrintF(".\n");
@@ -6105,50 +6159,47 @@ void GCTracer::Print() const {
void GCTracer::PrintNVP() const {
PrintPID("%8.0f ms: ", heap_->isolate()->time_millis_since_init());
- PrintF("pause=%.1f ", end_time_ - start_time_);
- PrintF("mutator=%.1f ", spent_in_mutator_);
- PrintF("gc=");
- switch (collector_) {
- case SCAVENGER:
- PrintF("s");
- break;
- case MARK_COMPACTOR:
- PrintF("ms");
- break;
- default:
- UNREACHABLE();
- }
- PrintF(" ");
-
- PrintF("external=%.1f ", scopes_[Scope::EXTERNAL]);
- PrintF("mark=%.1f ", scopes_[Scope::MC_MARK]);
- PrintF("sweep=%.2f ", scopes_[Scope::MC_SWEEP]);
- PrintF("sweepns=%.2f ", scopes_[Scope::MC_SWEEP_NEWSPACE]);
- PrintF("sweepos=%.2f ", scopes_[Scope::MC_SWEEP_OLDSPACE]);
- PrintF("sweepcode=%.2f ", scopes_[Scope::MC_SWEEP_CODE]);
- PrintF("sweepcell=%.2f ", scopes_[Scope::MC_SWEEP_CELL]);
- PrintF("sweepmap=%.2f ", scopes_[Scope::MC_SWEEP_MAP]);
- PrintF("evacuate=%.1f ", scopes_[Scope::MC_EVACUATE_PAGES]);
- PrintF("new_new=%.1f ", scopes_[Scope::MC_UPDATE_NEW_TO_NEW_POINTERS]);
- PrintF("root_new=%.1f ", scopes_[Scope::MC_UPDATE_ROOT_TO_NEW_POINTERS]);
- PrintF("old_new=%.1f ", scopes_[Scope::MC_UPDATE_OLD_TO_NEW_POINTERS]);
+ 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 ",
- scopes_[Scope::MC_UPDATE_POINTERS_TO_EVACUATED]);
+ current_.scopes[Scope::MC_UPDATE_POINTERS_TO_EVACUATED]);
PrintF("intracompaction_ptrs=%.1f ",
- scopes_[Scope::MC_UPDATE_POINTERS_BETWEEN_EVACUATED]);
- PrintF("misc_compaction=%.1f ", scopes_[Scope::MC_UPDATE_MISC_POINTERS]);
+ current_.scopes[Scope::MC_UPDATE_POINTERS_BETWEEN_EVACUATED]);
+ PrintF("misc_compaction=%.1f ",
+ current_.scopes[Scope::MC_UPDATE_MISC_POINTERS]);
PrintF("weakcollection_process=%.1f ",
- scopes_[Scope::MC_WEAKCOLLECTION_PROCESS]);
+ current_.scopes[Scope::MC_WEAKCOLLECTION_PROCESS]);
PrintF("weakcollection_clear=%.1f ",
- scopes_[Scope::MC_WEAKCOLLECTION_CLEAR]);
+ current_.scopes[Scope::MC_WEAKCOLLECTION_CLEAR]);
- PrintF("total_size_before=%" V8_PTR_PREFIX "d ", start_object_size_);
- PrintF("total_size_after=%" V8_PTR_PREFIX "d ", end_object_size_);
- PrintF("holes_size_before=%" V8_PTR_PREFIX "d ",
- in_free_list_or_wasted_before_gc_);
- PrintF("holes_size_after=%" V8_PTR_PREFIX "d ", CountTotalHolesSize(heap_));
+ 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);
- PrintF("allocated=%" V8_PTR_PREFIX "d ", allocated_since_last_gc_);
+ 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_);
@@ -6158,30 +6209,23 @@ void GCTracer::PrintNVP() const {
PrintF("promotion_rate=%.1f%% ", heap_->promotion_rate_);
PrintF("semi_space_copy_rate=%.1f%% ", heap_->semi_space_copied_rate_);
- if (collector_ == SCAVENGER) {
- PrintF("stepscount=%d ", steps_count_since_last_gc_);
- PrintF("stepstook=%.1f ", steps_took_since_last_gc_);
+ if (current_.type == Event::SCAVENGER) {
+ PrintF("stepscount=%d ", current_.incremental_marking_steps -
+ previous_.incremental_marking_steps);
+ PrintF("stepstook=%.1f ", current_.incremental_marking_duration -
+ previous_.incremental_marking_duration);
} else {
- PrintF("stepscount=%d ", steps_count_);
- PrintF("stepstook=%.1f ", steps_took_);
- PrintF("longeststep=%.1f ", longest_step_);
+ PrintF("stepscount=%d ", current_.incremental_marking_steps -
+ previous_mark_compactor_event_.incremental_marking_steps);
+ PrintF("stepstook=%.1f ", current_.incremental_marking_duration -
+ previous_mark_compactor_event_.incremental_marking_duration);
+ PrintF("longeststep=%.1f ", current_.longest_incremental_marking_step);
}
PrintF("\n");
}
-const char* GCTracer::CollectorString() const {
- switch (collector_) {
- case SCAVENGER:
- return "Scavenge";
- case MARK_COMPACTOR:
- return "Mark-sweep";
- }
- return "Unknown GC";
-}
-
-
int KeyedLookupCache::Hash(Handle<Map> map, Handle<Name> name) {
DisallowHeapAllocation no_gc;
// Uses only lower 32 bits if pointers are larger.
« no previous file with comments | « src/heap.h ('k') | src/incremental-marking.h » ('j') | no next file with comments »

Powered by Google App Engine
This is Rietveld 408576698