v8: GCTracer clean-up part 1.
authorernstm@chromium.org <ernstm@chromium.org@ce2b1a6d-e550-0410-aec6-3dcde31c8c00>
Thu, 17 Jul 2014 07:50:55 +0000 (07:50 +0000)
committerernstm@chromium.org <ernstm@chromium.org@ce2b1a6d-e550-0410-aec6-3dcde31c8c00>
Thu, 17 Jul 2014 07:50:55 +0000 (07:50 +0000)
- Split GCTracer::~GCTracer into printing functions and update of variables
tracked on Heap.
- Clean-up recording of time, object size and memory size at the beginning and
end of GC.
- Consistently use enum notation in ScopeId.
- Disallow copy and assign for Scope and GCTracer.
- Remove unused stats on GCTracer.

R=hpayer@chromium.org
BUG=

Review URL: https://codereview.chromium.org/396893004

git-svn-id: https://v8.googlecode.com/svn/branches/bleeding_edge@22439 ce2b1a6d-e550-0410-aec6-3dcde31c8c00

src/heap-inl.h
src/heap.cc
src/heap.h

index 844a375..3fd849c 100644 (file)
@@ -804,11 +804,6 @@ void VerifySmisVisitor::VisitPointers(Object** start, Object** end) {
 }
 
 
-double GCTracer::SizeOfHeapObjects() {
-  return (static_cast<double>(heap_->SizeOfObjects())) / MB;
-}
-
-
 } }  // namespace v8::internal
 
 #endif  // V8_HEAP_INL_H_
index 8ffa438..75a48f1 100644 (file)
@@ -834,16 +834,10 @@ bool Heap::CollectGarbage(GarbageCollector collector,
 
   bool next_gc_likely_to_collect_more = false;
 
-  { GCTracer tracer(this, gc_reason, collector_reason);
+  { GCTracer tracer(this, collector, gc_reason, collector_reason);
     ASSERT(AllowHeapAllocation::IsAllowed());
     DisallowHeapAllocation no_allocation_during_gc;
     GarbageCollectionPrologue();
-    // The GC count was incremented in the prologue.  Tell the tracer about
-    // it.
-    tracer.set_gc_count(gc_count_);
-
-    // Tell the tracer which collector we've selected.
-    tracer.set_collector(collector);
 
     {
       HistogramTimerScope histogram_timer_scope(
@@ -1205,7 +1199,6 @@ void Heap::MarkCompact(GCTracer* tracer) {
   mark_compact_collector_.Prepare(tracer);
 
   ms_count_++;
-  tracer->set_full_gc_count(ms_count_);
 
   MarkCompactPrologue();
 
@@ -5956,14 +5949,40 @@ 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();
+  bool first_gc = (last_gc_end_timestamp_ == 0);
+  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_, alive_after_last_gc_);
+    if (!first_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::GCTracer(Heap* heap,
+                   GarbageCollector collector,
                    const char* gc_reason,
                    const char* collector_reason)
     : start_time_(0.0),
+      end_time_(0.0),
       start_object_size_(0),
+      end_object_size_(0),
       start_memory_size_(0),
-      gc_count_(0),
-      full_gc_count_(0),
+      end_memory_size_(0),
+      collector_(collector),
       allocated_since_last_gc_(0),
       spent_in_mutator_(0),
       nodes_died_in_new_space_(0),
@@ -5973,11 +5992,12 @@ GCTracer::GCTracer(Heap* heap,
       gc_reason_(gc_reason),
       collector_reason_(collector_reason) {
   if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
+
   start_time_ = base::OS::TimeCurrentMillis();
   start_object_size_ = heap_->SizeOfObjects();
   start_memory_size_ = heap_->isolate()->memory_allocator()->Size();
 
-  for (int i = 0; i < Scope::kNumberOfScopes; i++) {
+  for (int i = 0; i < Scope::NUMBER_OF_SCOPES; i++) {
     scopes_[i] = 0;
   }
 
@@ -6001,146 +6021,140 @@ GCTracer::GCTracer(Heap* heap,
 
 
 GCTracer::~GCTracer() {
-  // Printf ONE line iff flag is set.
   if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
 
-  bool first_gc = (heap_->last_gc_end_timestamp_ == 0);
+  end_time_ = base::OS::TimeCurrentMillis();
+  end_object_size_ = heap_->SizeOfObjects();
+  end_memory_size_ = heap_->isolate()->memory_allocator()->Size();
 
-  heap_->alive_after_last_gc_ = heap_->SizeOfObjects();
-  heap_->last_gc_end_timestamp_ = base::OS::TimeCurrentMillis();
+  heap_->UpdateGCStatistics(start_time_,
+                            end_time_,
+                            spent_in_mutator_,
+                            scopes_[Scope::MC_MARK]);
 
-  double time = heap_->last_gc_end_timestamp_ - start_time_;
+  if (collector_ == SCAVENGER && FLAG_trace_gc_ignore_scavenger) return;
 
-  // Update cumulative GC statistics if required.
-  if (FLAG_print_cumulative_gc_stat) {
-    heap_->total_gc_time_ms_ += time;
-    heap_->max_gc_pause_ = Max(heap_->max_gc_pause_, time);
-    heap_->max_alive_after_gc_ = Max(heap_->max_alive_after_gc_,
-                                     heap_->alive_after_last_gc_);
-    if (!first_gc) {
-      heap_->min_in_mutator_ = Min(heap_->min_in_mutator_,
-                                   spent_in_mutator_);
-    }
-  } else if (FLAG_trace_gc_verbose) {
-    heap_->total_gc_time_ms_ += time;
-  }
+  if (FLAG_trace_gc) {
+    if (FLAG_trace_gc_nvp)
+      PrintNVP();
+    else
+      Print();
 
-  if (collector_ == SCAVENGER && FLAG_trace_gc_ignore_scavenger) return;
+    heap_->PrintShortHeapStatistics();
+  }
+}
 
-  heap_->AddMarkingTime(scopes_[Scope::MC_MARK]);
 
-  if (FLAG_print_cumulative_gc_stat && !FLAG_trace_gc) return;
+void GCTracer::Print() const {
   PrintPID("%8.0f ms: ", heap_->isolate()->time_millis_since_init());
 
-  if (!FLAG_trace_gc_nvp) {
-    int external_time = static_cast<int>(scopes_[Scope::EXTERNAL]);
-
-    double end_memory_size_mb =
-        static_cast<double>(heap_->isolate()->memory_allocator()->Size()) / MB;
-
-    PrintF("%s %.1f (%.1f) -> %.1f (%.1f) MB, ",
-           CollectorString(),
-           static_cast<double>(start_object_size_) / MB,
-           static_cast<double>(start_memory_size_) / MB,
-           SizeOfHeapObjects(),
-           end_memory_size_mb);
-
-    if (external_time > 0) PrintF("%d / ", external_time);
-    PrintF("%.1f ms", time);
-    if (steps_count_ > 0) {
-      if (collector_ == SCAVENGER) {
-        PrintF(" (+ %.1f ms in %d steps since last GC)",
-               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_);
-      }
-    }
+  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);
 
-    if (gc_reason_ != NULL) {
-      PrintF(" [%s]", gc_reason_);
-    }
-
-    if (collector_reason_ != NULL) {
-      PrintF(" [%s]", collector_reason_);
-    }
-
-    PrintF(".\n");
-  } else {
-    PrintF("pause=%.1f ", 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 ",
-        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("total_size_before=%" V8_PTR_PREFIX "d ", start_object_size_);
-    PrintF("total_size_after=%" V8_PTR_PREFIX "d ", heap_->SizeOfObjects());
-    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_);
-    PrintF("nodes_died_in_new=%d ", nodes_died_in_new_space_);
-    PrintF("nodes_copied_in_new=%d ", nodes_copied_in_new_space_);
-    PrintF("nodes_promoted=%d ", nodes_promoted_);
-    PrintF("promotion_rate=%.1f%% ", heap_->promotion_rate_);
-    PrintF("semi_space_copy_rate=%.1f%% ", heap_->semi_space_copied_rate_);
+  int external_time = static_cast<int>(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) {
-      PrintF("stepscount=%d ", steps_count_since_last_gc_);
-      PrintF("stepstook=%.1f ", steps_took_since_last_gc_);
+      PrintF(" (+ %.1f ms in %d steps since last GC)",
+             steps_took_since_last_gc_,
+             steps_count_since_last_gc_);
     } else {
-      PrintF("stepscount=%d ", steps_count_);
-      PrintF("stepstook=%.1f ", steps_took_);
-      PrintF("longeststep=%.1f ", longest_step_);
+      PrintF(" (+ %.1f ms in %d steps since start of marking, "
+             "biggest step %.1f ms)",
+             steps_took_,
+             steps_count_,
+             longest_step_);
     }
+  }
 
-    PrintF("\n");
+  if (gc_reason_ != NULL) {
+    PrintF(" [%s]", gc_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());
+
+  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 ",
+         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("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_);
+  PrintF("nodes_died_in_new=%d ", nodes_died_in_new_space_);
+  PrintF("nodes_copied_in_new=%d ", nodes_copied_in_new_space_);
+  PrintF("nodes_promoted=%d ", nodes_promoted_);
+  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_);
+  } else {
+    PrintF("stepscount=%d ", steps_count_);
+    PrintF("stepstook=%.1f ", steps_took_);
+    PrintF("longeststep=%.1f ", longest_step_);
   }
 
-  heap_->PrintShortHeapStatistics();
+  PrintF("\n");
 }
 
 
-const char* GCTracer::CollectorString() {
+const char* GCTracer::CollectorString() const {
   switch (collector_) {
     case SCAVENGER:
       return "Scavenge";
index a6a14f6..9eaa6ab 100644 (file)
@@ -1236,6 +1236,12 @@ class Heap {
     }
   }
 
+  // Update GC statistics that are tracked on the Heap.
+  void UpdateGCStatistics(double start_time,
+                          double end_time,
+                          double spent_in_mutator,
+                          double marking_time);
+
   // Returns maximum GC pause.
   double get_max_gc_pause() { return max_gc_pause_; }
 
@@ -2535,7 +2541,7 @@ class GCTracer BASE_EMBEDDED {
       MC_WEAKCOLLECTION_PROCESS,
       MC_WEAKCOLLECTION_CLEAR,
       MC_FLUSH_CODE,
-      kNumberOfScopes
+      NUMBER_OF_SCOPES
     };
 
     Scope(GCTracer* tracer, ScopeId scope)
@@ -2545,7 +2551,7 @@ class GCTracer BASE_EMBEDDED {
     }
 
     ~Scope() {
-      ASSERT(scope_ < kNumberOfScopes);  // scope_ is unsigned.
+      ASSERT(scope_ < NUMBER_OF_SCOPES);  // scope_ is unsigned.
       tracer_->scopes_[scope_] += base::OS::TimeCurrentMillis() - start_time_;
     }
 
@@ -2553,22 +2559,16 @@ class GCTracer BASE_EMBEDDED {
     GCTracer* tracer_;
     ScopeId scope_;
     double start_time_;
+
+    DISALLOW_COPY_AND_ASSIGN(Scope);
   };
 
   explicit GCTracer(Heap* heap,
+                    GarbageCollector collector,
                     const char* gc_reason,
                     const char* collector_reason);
   ~GCTracer();
 
-  // Sets the collector.
-  void set_collector(GarbageCollector collector) { collector_ = collector; }
-
-  // Sets the GC count.
-  void set_gc_count(unsigned int count) { gc_count_ = count; }
-
-  // Sets the full GC count.
-  void set_full_gc_count(int count) { full_gc_count_ = count; }
-
   void increment_nodes_died_in_new_space() {
     nodes_died_in_new_space_++;
   }
@@ -2583,32 +2583,37 @@ class GCTracer BASE_EMBEDDED {
 
  private:
   // Returns a string matching the collector.
-  const char* CollectorString();
+  const char* CollectorString() const;
+
+  // Print one detailed trace line in name=value format.
+  void PrintNVP() const;
 
-  // Returns size of object in heap (in MB).
-  inline double SizeOfHeapObjects();
+  // Print one trace line.
+  void Print() const;
 
   // Timestamp set in the constructor.
   double start_time_;
 
+  // Timestamp set in the destructor.
+  double end_time_;
+
   // Size of objects in heap set in constructor.
   intptr_t start_object_size_;
 
+  // Size of objects in heap set in destructor.
+  intptr_t end_object_size_;
+
   // Size of memory allocated from OS set in constructor.
   intptr_t start_memory_size_;
 
+  // Size of memory allocated from OS set in destructor.
+  intptr_t end_memory_size_;
+
   // Type of collector.
   GarbageCollector collector_;
 
-  // A count (including this one, e.g. the first collection is 1) of the
-  // number of garbage collections.
-  unsigned int gc_count_;
-
-  // A count (including this one) of the number of full garbage collections.
-  int full_gc_count_;
-
   // Amounts of time spent in different scopes during GC.
-  double scopes_[Scope::kNumberOfScopes];
+  double scopes_[Scope::NUMBER_OF_SCOPES];
 
   // Total amount of space either wasted or contained in one of free lists
   // before the current GC.
@@ -2642,6 +2647,8 @@ class GCTracer BASE_EMBEDDED {
 
   const char* gc_reason_;
   const char* collector_reason_;
+
+  DISALLOW_COPY_AND_ASSIGN(GCTracer);
 };