Revert "Track history of events in GCTracer."

src/heap.cc

 // Copyright 2012 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/accessors.h"
 #include "src/api.h"
 #include "src/base/once.h"
 #include "src/base/utils/random-number-generator.h"
@@ skipping 35 matching lines @@
 
 namespace v8 {
 namespace internal {
 
 
 Heap::Heap()
     : amount_of_external_allocated_memory_(0),
       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),
       always_allocate_scope_depth_(0),
       contexts_disposed_(0),
       global_ic_age_(0),
       flush_monomorphic_ics_(false),
       scan_on_scavenge_pages_(0),
       new_space_(this),
       old_pointer_space_(NULL),
@@ skipping 29 matching lines @@
       semi_space_copied_object_size_(0),
       semi_space_copied_rate_(0),
       nodes_died_in_new_space_(0),
       nodes_copied_in_new_space_(0),
       nodes_promoted_(0),
       maximum_size_scavenges_(0),
       max_gc_pause_(0.0),
       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),
       store_buffer_(this),
       marking_(this),
       incremental_marking_(this),
       number_idle_notifications_(0),
       last_idle_notification_gc_count_(0),
       last_idle_notification_gc_count_init_(false),
       mark_sweeps_since_idle_round_started_(0),
@@ skipping 705 matching lines @@
       if (FLAG_trace_incremental_marking) {
         PrintF("[IncrementalMarking] Delaying MarkSweep.\n");
       }
       collector = SCAVENGER;
       collector_reason = "incremental marking delaying mark-sweep";
     }
   }
 
   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();
 
     {
       HistogramTimerScope histogram_timer_scope(
           (collector == SCAVENGER) ? isolate_->counters()->gc_scavenger()
                                    : isolate_->counters()->gc_compactor());
       next_gc_likely_to_collect_more =
           PerformGarbageCollection(collector, gc_callback_flags);
     }
 
     GarbageCollectionEpilogue();
-    tracer()->Stop();
+    tracer()->stop();
   }
 
   // Start incremental marking for the next cycle. The heap snapshot
   // generator needs incremental marking to stay off after it aborted.
   if (!mark_compact_collector()->abort_incremental_marking() &&
       incremental_marking()->IsStopped() &&
       incremental_marking()->WorthActivating() &&
       NextGCIsLikelyToBeFull()) {
     incremental_marking()->Start();
   }
@@ skipping 5092 matching lines @@
   OldSpaces spaces(heap);
   for (OldSpace* space = spaces.next();
        space != NULL;
        space = spaces.next()) {
     holes_size += space->Waste() + space->Available();
   }
   return holes_size;
 }
 
 
-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;
   }
 
   marking_time_ += marking_time;
 }
 
 
-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;
+    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";
-      }
+void GCTracer::start(GarbageCollector collector, const char* gc_reason,
+                     const char* collector_reason) {
+  if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
+
+  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();
+
+  for (int i = 0; i < Scope::NUMBER_OF_SCOPES; i++) {
+    scopes_[i] = 0;
   }
-  return "Unknown Event Type";
+
+  in_free_list_or_wasted_before_gc_ = CountTotalHolesSize(heap_);
+
+  allocated_since_last_gc_ =
+      heap_->SizeOfObjects() - heap_->alive_after_last_gc_;
+
+  spent_in_mutator_ = Max(start_time_ - heap_->last_gc_end_timestamp_, 0.0);
+
+  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();
 }
 
 
-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,
-                     const char* collector_reason) {
+void GCTracer::stop() {
   if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
 
-  previous_ = current_;
-  if (current_.type == Event::MARK_COMPACTOR)
-    previous_mark_compactor_event_ = current_;
+  end_time_ = base::OS::TimeCurrentMillis();
+  end_object_size_ = heap_->SizeOfObjects();
+  end_memory_size_ = heap_->isolate()->memory_allocator()->Size();
 
-  if (collector == SCAVENGER) {
-    current_ = Event(Event::SCAVENGER, gc_reason, collector_reason);
-  } else {
-    current_ = Event(Event::MARK_COMPACTOR, gc_reason, collector_reason);
-  }
+  heap_->UpdateGCStatistics(start_time_, end_time_, spent_in_mutator_,
+                            scopes_[Scope::MC_MARK]);
 
-  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_;
-
-  for (int i = 0; i < Scope::NUMBER_OF_SCOPES; i++) {
-    current_.scopes[i] = 0;
-  }
-}
-
-
-void GCTracer::Stop() {
-  if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
-
-  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_);
-  }
-
-  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);
-
-  heap_->UpdateCumulativeGCStatistics(duration,
-                                      spent_in_mutator,
-                                      current_.scopes[Scope::MC_MARK]);
-
-  if (current_.type == Event::SCAVENGER && FLAG_trace_gc_ignore_scavenger)
-    return;
+  if (collector_ == SCAVENGER && FLAG_trace_gc_ignore_scavenger) return;
 
   if (FLAG_trace_gc) {
     if (FLAG_trace_gc_nvp)
       PrintNVP();
     else
       Print();
 
     heap_->PrintShortHeapStatistics();
   }
 }
 
 
-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");
 }
 
 
 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 ", 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("pause=%.1f ", duration);
-  PrintF("mutator=%.1f ", spent_in_mutator);
-  PrintF("gc=%s ", current_.TypeName(true));
+  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 ",
+         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]);
+  PrintF("weakcollection_process=%.1f ",
+         scopes_[Scope::MC_WEAKCOLLECTION_PROCESS]);
+  PrintF("weakcollection_clear=%.1f ", scopes_[Scope::MC_WEAKCOLLECTION_CLEAR]);
 
-  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("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 ", 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);
-
-  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("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_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.
   uintptr_t addr_hash =
       static_cast<uint32_t>(reinterpret_cast<uintptr_t>(*map)) >> kMapHashShift;
   return static_cast<uint32_t>((addr_hash ^ name->Hash()) & kCapacityMask);
 }
 
 
 int KeyedLookupCache::Lookup(Handle<Map> map, Handle<Name> name) {
@@ skipping 246 matching lines @@
       static_cast<int>(object_sizes_last_time_[index]));
   CODE_AGE_LIST_COMPLETE(ADJUST_LAST_TIME_OBJECT_COUNT)
 #undef ADJUST_LAST_TIME_OBJECT_COUNT
 
   MemCopy(object_counts_last_time_, object_counts_, sizeof(object_counts_));
   MemCopy(object_sizes_last_time_, object_sizes_, sizeof(object_sizes_));
   ClearObjectStats();
 }
 
 } }  // namespace v8::internal