Revert "Track history of events in GCTracer."

src/heap.cc

Index: src/heap.cc
diff --git a/src/heap.cc b/src/heap.cc
index 648deb0fc3d1cac1dc4125dfd4853b66f8571827..c41cfc7c75edce956d85a878791643322b2537d8 100644
--- a/src/heap.cc
+++ b/src/heap.cc
@@ -53,17 +53,18 @@ Heap::Heap()
       amount_of_external_allocated_memory_at_last_global_gc_(0),
       isolate_(NULL),
       code_range_size_(0),
-// semispace_size_ should be a power of 2 and old_generation_size_ should be
-// a multiple of Page::kPageSize.
+      // semispace_size_ should be a power of 2 and old_generation_size_ should
+      // be
+      // a multiple of Page::kPageSize.
       reserved_semispace_size_(8 * (kPointerSize / 4) * MB),
-      max_semi_space_size_(8 * (kPointerSize / 4)  * MB),
+      max_semi_space_size_(8 * (kPointerSize / 4) * MB),
       initial_semispace_size_(Page::kPageSize),
       max_old_generation_size_(700ul * (kPointerSize / 4) * MB),
       max_executable_size_(256ul * (kPointerSize / 4) * MB),
-// Variables set based on semispace_size_ and old_generation_size_ in
-// ConfigureHeap.
-// Will be 4 * reserved_semispace_size_ to ensure that young
-// generation can be aligned to its size.
+      // Variables set based on semispace_size_ and old_generation_size_ in
+      // ConfigureHeap.
+      // Will be 4 * reserved_semispace_size_ to ensure that young
+      // generation can be aligned to its size.
       maximum_committed_(0),
       survived_since_last_expansion_(0),
       sweep_generation_(0),
@@ -113,6 +114,8 @@ 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),
@@ -838,7 +841,8 @@ 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();
@@ -852,7 +856,7 @@ bool Heap::CollectGarbage(GarbageCollector collector,
     }
 
     GarbageCollectionEpilogue();
-    tracer()->Stop();
+    tracer()->stop();
   }
 
   // Start incremental marking for the next cycle. The heap snapshot
@@ -5965,13 +5969,16 @@ static intptr_t CountTotalHolesSize(Heap* heap) {
 }
 
 
-void Heap::UpdateCumulativeGCStatistics(double duration,
-                                        double spent_in_mutator,
-                                        double marking_time) {
+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;
+
   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_, SizeOfObjects());
+    max_alive_after_gc_ = Max(max_alive_after_gc_, alive_after_last_gc_);
     min_in_mutator_ = Min(min_in_mutator_, spent_in_mutator);
   } else if (FLAG_trace_gc_verbose) {
     total_gc_time_ms_ += duration;
@@ -5981,121 +5988,74 @@ void Heap::UpdateCumulativeGCStatistics(double duration,
 }
 
 
-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) {
+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) {
   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:
-      if (short_name) {
-        return "ms";
-      } else {
-        return "Mark-sweep";
-      }
-    case START:
-      if (short_name) {
-        return "st";
-      } else {
-        return "Start";
-      }
+    scopes_[i] = 0;
   }
-  return "Unknown Event Type";
-}
-
-
-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_;
 }
 
 
-void GCTracer::Start(GarbageCollector collector,
-                     const char* gc_reason,
+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);
-  }
+  collector_ = collector;
+  gc_reason_ = gc_reason;
+  collector_reason_ = collector_reason;
 
-  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_);
-
-  current_.incremental_marking_steps = incremental_marking_steps_;
-  current_.incremental_marking_duration = incremental_marking_duration_;
-  current_.longest_incremental_marking_step = longest_incremental_marking_step_;
+  start_time_ = base::OS::TimeCurrentMillis();
+  start_object_size_ = heap_->SizeOfObjects();
+  start_memory_size_ = heap_->isolate()->memory_allocator()->Size();
 
   for (int i = 0; i < Scope::NUMBER_OF_SCOPES; i++) {
-    current_.scopes[i] = 0;
+    scopes_[i] = 0;
   }
-}
 
+  in_free_list_or_wasted_before_gc_ = CountTotalHolesSize(heap_);
 
-void GCTracer::Stop() {
-  if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
+  allocated_since_last_gc_ =
+      heap_->SizeOfObjects() - heap_->alive_after_last_gc_;
 
-  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_);
+  spent_in_mutator_ = Max(start_time_ - heap_->last_gc_end_timestamp_, 0.0);
 
-  if (current_.type == Event::SCAVENGER) {
-    scavenger_events_.push_front(current_);
-  } else {
-    mark_compactor_events_.push_front(current_);
-  }
+  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();
+}
 
-  if (current_.type == Event::MARK_COMPACTOR)
-    longest_incremental_marking_step_ = 0.0;
 
-  double duration = current_.end_time - current_.start_time;
-  double spent_in_mutator =
-      Max(current_.start_time - previous_.end_time, 0.0);
+void GCTracer::stop() {
+  if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
 
-  heap_->UpdateCumulativeGCStatistics(duration,
-                                      spent_in_mutator,
-                                      current_.scopes[Scope::MC_MARK]);
+  end_time_ = base::OS::TimeCurrentMillis();
+  end_object_size_ = heap_->SizeOfObjects();
+  end_memory_size_ = heap_->isolate()->memory_allocator()->Size();
 
-  if (current_.type == Event::SCAVENGER && FLAG_trace_gc_ignore_scavenger)
-    return;
+  heap_->UpdateGCStatistics(start_time_, end_time_, spent_in_mutator_,
+                            scopes_[Scope::MC_MARK]);
+
+  if (collector_ == SCAVENGER && FLAG_trace_gc_ignore_scavenger) return;
 
   if (FLAG_trace_gc) {
     if (FLAG_trace_gc_nvp)
@@ -6108,57 +6068,37 @@ 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, ",
-         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);
+  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);
 
-  int external_time = static_cast<int>(current_.scopes[Scope::EXTERNAL]);
+  int external_time = static_cast<int>(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) {
-    int steps = current_.incremental_marking_steps -
-        previous_.incremental_marking_steps;
-    if (steps > 0) {
+  PrintF("%.1f ms", end_time_ - start_time_);
+  if (steps_count_ > 0) {
+    if (collector_ == SCAVENGER) {
       PrintF(" (+ %.1f ms in %d steps since last GC)",
-             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)",
-             current_.incremental_marking_duration -
-             previous_mark_compactor_event_.incremental_marking_duration,
-             steps,
-             current_.longest_incremental_marking_step);
+             steps_took_since_last_gc_, steps_count_since_last_gc_);
+    } else {
+      PrintF(
+          " (+ %.1f ms in %d steps since start of marking, "
+          "biggest step %.1f ms)",
+          steps_took_, steps_count_, longest_step_);
     }
   }
 
-  if (current_.gc_reason != NULL) {
-    PrintF(" [%s]", current_.gc_reason);
+  if (gc_reason_ != NULL) {
+    PrintF(" [%s]", gc_reason_);
   }
 
-  if (current_.collector_reason != NULL) {
-    PrintF(" [%s]", current_.collector_reason);
+  if (collector_reason_ != NULL) {
+    PrintF(" [%s]", collector_reason_);
   }
 
   PrintF(".\n");
@@ -6168,47 +6108,49 @@ void GCTracer::Print() const {
 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("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]);
   PrintF("compaction_ptrs=%.1f ",
-         current_.scopes[Scope::MC_UPDATE_POINTERS_TO_EVACUATED]);
+         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]);
+         scopes_[Scope::MC_UPDATE_POINTERS_BETWEEN_EVACUATED]);
+  PrintF("misc_compaction=%.1f ", scopes_[Scope::MC_UPDATE_MISC_POINTERS]);
   PrintF("weakcollection_process=%.1f ",
-         current_.scopes[Scope::MC_WEAKCOLLECTION_PROCESS]);
-  PrintF("weakcollection_clear=%.1f ",
-         current_.scopes[Scope::MC_WEAKCOLLECTION_CLEAR]);
-
-  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);
+         scopes_[Scope::MC_WEAKCOLLECTION_PROCESS]);
+  PrintF("weakcollection_clear=%.1f ", 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("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_);
@@ -6218,23 +6160,30 @@ void GCTracer::PrintNVP() const {
   PrintF("promotion_rate=%.1f%% ", heap_->promotion_rate_);
   PrintF("semi_space_copy_rate=%.1f%% ", heap_->semi_space_copied_rate_);
 
-  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);
+  if (collector_ == SCAVENGER) {
+    PrintF("stepscount=%d ", steps_count_since_last_gc_);
+    PrintF("stepstook=%.1f ", steps_took_since_last_gc_);
   } else {
-    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("stepscount=%d ", steps_count_);
+    PrintF("stepstook=%.1f ", steps_took_);
+    PrintF("longeststep=%.1f ", longest_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.