Reland of "[heap] Tracer: Handle incremental marking scopes"

src/heap/gc-tracer.cc

 // 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/heap/gc-tracer.h"
 
 #include "src/counters.h"
 #include "src/heap/heap-inl.h"
 #include "src/isolate.h"
 
@@ skipping 13 matching lines @@
 GCTracer::Scope::Scope(GCTracer* tracer, ScopeId scope)
     : tracer_(tracer), scope_(scope) {
   start_time_ = tracer_->heap_->MonotonicallyIncreasingTimeInMs();
   // TODO(cbruni): remove once we fully moved to a trace-based system.
   if (FLAG_runtime_call_stats) {
     RuntimeCallStats::Enter(tracer_->heap_->isolate(), &timer_,
                             &RuntimeCallStats::GC);
   }
 }
 
-
 GCTracer::Scope::~Scope() {
-  DCHECK(scope_ < NUMBER_OF_SCOPES);  // scope_ is unsigned.
-  tracer_->current_.scopes[scope_] +=
-      tracer_->heap_->MonotonicallyIncreasingTimeInMs() - start_time_;
+  tracer_->AddScopeSample(
+      scope_, tracer_->heap_->MonotonicallyIncreasingTimeInMs() - start_time_);
   // TODO(cbruni): remove once we fully moved to a trace-based system.
   if (FLAG_runtime_call_stats) {
     RuntimeCallStats::Leave(tracer_->heap_->isolate(), &timer_);
   }
 }
 
+void GCTracer::AddScopeSample(Scope::ScopeId scope, double duration) {
+  DCHECK(scope < Scope::NUMBER_OF_SCOPES);
+  if (scope >= Scope::FIRST_INCREMENTAL_SCOPE &&
+      scope <= Scope::LAST_INCREMENTAL_SCOPE) {
+    cumulative_incremental_scopes_[scope] += duration;
+  } else {
+    current_.scopes[scope] += duration;
+  }
+}
+
 const char* GCTracer::Scope::Name(ScopeId id) {
 #define CASE(scope)  \
   case Scope::scope: \
     return "V8.GC_" #scope;
   switch (id) {
     TRACER_SCOPES(CASE)
     case Scope::NUMBER_OF_SCOPES:
       break;
   }
 #undef CASE
   return "(unknown)";
 }
 
 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),
       reduce_memory(false),
       start_object_size(0),
       end_object_size(0),
       start_memory_size(0),
       end_memory_size(0),
       start_holes_size(0),
       end_holes_size(0),
+      new_space_object_size(0),
+      survived_new_space_object_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) {
+      longest_incremental_marking_step(0.0),
+      cumulative_incremental_marking_finalization_steps(0),
+      cumulative_incremental_marking_finalizaton_duration(0),
+      longest_incremental_marking_finalization_step(0),
+      incremental_marking_finalizaton_steps(0),
+      incremental_marking_finalization_duration(0) {
+  for (int i = 0; i < Scope::NUMBER_OF_INCREMENTAL_SCOPES; i++) {
+    cumulative_incremental_scopes[i] = 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) {
@@ skipping 56 matching lines @@
   cumulative_marking_duration_ = 0.0;
   cumulative_sweeping_duration_ = 0.0;
   allocation_time_ms_ = 0.0;
   new_space_allocation_counter_bytes_ = 0.0;
   old_generation_allocation_counter_bytes_ = 0.0;
   allocation_duration_since_gc_ = 0.0;
   new_space_allocation_in_bytes_since_gc_ = 0.0;
   old_generation_allocation_in_bytes_since_gc_ = 0.0;
   combined_mark_compact_speed_cache_ = 0.0;
   start_counter_ = 0;
+  for (int i = 0; i < Scope::NUMBER_OF_INCREMENTAL_SCOPES; i++) {
+    cumulative_incremental_scopes_[i] = 0;
+  }
+  current_ = Event(Event::START, NULL, NULL);
+  current_.end_time = heap_->MonotonicallyIncreasingTimeInMs();
+  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 = heap_->MonotonicallyIncreasingTimeInMs();
   SampleAllocation(start_time, heap_->NewSpaceAllocationCounter(),
@@ skipping 22 matching lines @@
 
   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_;
+  current_.cumulative_incremental_marking_finalization_steps =
+      cumulative_incremental_marking_finalization_steps_;
+  current_.cumulative_incremental_marking_finalizaton_duration =
+      cumulative_incremental_marking_finalization_duration_;
+  current_.longest_incremental_marking_finalization_step =
+      longest_incremental_marking_finalization_step_;
 
   for (int i = 0; i < Scope::NUMBER_OF_SCOPES; i++) {
     current_.scopes[i] = 0;
   }
+
   int committed_memory = static_cast<int>(heap_->CommittedMemory() / KB);
   int used_memory = static_cast<int>(current_.start_object_size / KB);
   heap_->isolate()->counters()->aggregated_memory_heap_committed()->AddSample(
       start_time, committed_memory);
   heap_->isolate()->counters()->aggregated_memory_heap_used()->AddSample(
       start_time, used_memory);
   // TODO(cbruni): remove once we fully moved to a trace-based system.
   if (FLAG_runtime_call_stats) {
     RuntimeCallStats::Enter(heap_->isolate(), &timer_, &RuntimeCallStats::GC);
   }
 }
 
 void GCTracer::Stop(GarbageCollector collector) {
   start_counter_--;
   if (start_counter_ != 0) {
     Output("[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)));
 
+  for (int i = Scope::FIRST_INCREMENTAL_SCOPE;
+       i <= Scope::LAST_INCREMENTAL_SCOPE; i++) {
+    current_.cumulative_incremental_scopes[i] =
+        cumulative_incremental_scopes_[i];
+  }
+
   current_.end_time = heap_->MonotonicallyIncreasingTimeInMs();
   current_.end_object_size = heap_->SizeOfObjects();
   current_.end_memory_size = heap_->memory_allocator()->Size();
   current_.end_holes_size = CountTotalHolesSize(heap_);
   current_.survived_new_space_object_size = heap_->SurvivedNewSpaceObjectSize();
 
   AddAllocation(current_.end_time);
 
   int committed_memory = static_cast<int>(heap_->CommittedMemory() / KB);
   int used_memory = static_cast<int>(current_.end_object_size / KB);
   heap_->isolate()->counters()->aggregated_memory_heap_committed()->AddSample(
       current_.end_time, committed_memory);
   heap_->isolate()->counters()->aggregated_memory_heap_used()->AddSample(
       current_.end_time, used_memory);
 
   double duration = current_.end_time - current_.start_time;
+
+  const Event* baseline = nullptr;
   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;
+    baseline = &previous_;
     recorded_scavenges_total_.Push(
         MakeBytesAndDuration(current_.new_space_object_size, duration));
     recorded_scavenges_survived_.Push(MakeBytesAndDuration(
         current_.survived_new_space_object_size, duration));
   } 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;
+    baseline = &previous_incremental_mark_compactor_event_;
     longest_incremental_marking_step_ = 0.0;
+    longest_incremental_marking_finalization_step_ = 0.0;
     recorded_incremental_marking_steps_.Push(
         MakeBytesAndDuration(current_.incremental_marking_bytes,
                              current_.pure_incremental_marking_duration));
     recorded_incremental_mark_compacts_.Push(
         MakeBytesAndDuration(current_.start_object_size, duration));
     combined_mark_compact_speed_cache_ = 0.0;
   } else {
     DCHECK(current_.incremental_marking_bytes == 0);
     DCHECK(current_.incremental_marking_duration == 0);
     DCHECK(current_.pure_incremental_marking_duration == 0);
     longest_incremental_marking_step_ = 0.0;
+    longest_incremental_marking_finalization_step_ = 0.0;
     recorded_mark_compacts_.Push(
         MakeBytesAndDuration(current_.start_object_size, duration));
     combined_mark_compact_speed_cache_ = 0.0;
   }
 
-  // TODO(ernstm): move the code below out of GCTracer.
+  if (baseline != nullptr) {
+    current_.incremental_marking_steps =
+        current_.cumulative_incremental_marking_steps -
+        baseline->cumulative_incremental_marking_steps;
+    current_.incremental_marking_bytes =
+        current_.cumulative_incremental_marking_bytes -
+        baseline->cumulative_incremental_marking_bytes;
+    current_.incremental_marking_duration =
+        current_.cumulative_incremental_marking_duration -
+        baseline->cumulative_incremental_marking_duration;
+    current_.pure_incremental_marking_duration =
+        current_.cumulative_pure_incremental_marking_duration -
+        baseline->cumulative_pure_incremental_marking_duration;
+    current_.incremental_marking_finalizaton_steps =
+        current_.cumulative_incremental_marking_finalization_steps -
+        baseline->cumulative_incremental_marking_finalization_steps;
+    current_.incremental_marking_finalization_duration =
+        current_.cumulative_incremental_marking_finalizaton_duration -
+        baseline->cumulative_incremental_marking_finalizaton_duration;
+    for (int i = Scope::FIRST_INCREMENTAL_SCOPE;
+         i <= Scope::LAST_INCREMENTAL_SCOPE; i++) {
+      current_.scopes[i] = current_.cumulative_incremental_scopes[i] -
+                           baseline->cumulative_incremental_scopes[i];
+    }
+  }
 
   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_nvp)
+  if (FLAG_trace_gc_nvp) {
     PrintNVP();
-  else
+  } else {
     Print();
+  }
 
   if (FLAG_trace_gc) {
     heap_->PrintShortHeapStatistics();
   }
 
-  longest_incremental_marking_finalization_step_ = 0.0;
-  cumulative_incremental_marking_finalization_steps_ = 0;
-  cumulative_incremental_marking_finalization_duration_ = 0.0;
   // TODO(cbruni): remove once we fully moved to a trace-based system.
   if (FLAG_runtime_call_stats) {
     RuntimeCallStats::Leave(heap_->isolate(), &timer_);
   }
 }
 
 
 void GCTracer::SampleAllocation(double current_ms,
                                 size_t new_space_counter_bytes,
                                 size_t old_generation_counter_bytes) {
@@ skipping 239 matching lines @@
           "evacuate=%.1f "
           "evacuate.candidates=%.1f "
           "evacuate.clean_up=%.1f "
           "evacuate.copy=%.1f "
           "evacuate.update_pointers=%.1f "
           "evacuate.update_pointers.to_evacuated=%.1f "
           "evacuate.update_pointers.to_new=%.1f "
           "evacuate.update_pointers.weak=%.1f "
           "external.mc_prologue=%.1f "
           "external.mc_epilogue=%.1f "
-          "external.mc_incremental_prologue=%.1f "
-          "external.mc_incremental_epilogue=%.1f "
           "external.weak_global_handles=%.1f "
           "finish=%.1f "
           "mark=%.1f "
           "mark.finish_incremental=%.1f "
+          "mark.object_grouping=%.1f "
           "mark.prepare_code_flush=%.1f "
           "mark.roots=%.1f "
           "mark.weak_closure=%.1f "
           "mark.weak_closure.ephemeral=%.1f "
           "mark.weak_closure.weak_handles=%.1f "
           "mark.weak_closure.weak_roots=%.1f "
           "mark.weak_closure.harmony=%.1f "
+          "mark.wrapper_prologue=%.1f "
+          "mark.wrapper_epilogue=%.1f "
+          "mark.wrapper_tracing=%.1f "
           "sweep=%.1f "
           "sweep.code=%.1f "
           "sweep.map=%.1f "
           "sweep.old=%.1f "
-          "incremental_finalize=%.1f "
-          "steps_count=%d "
-          "steps_took=%.1f "
-          "longest_step=%.1f "
-          "finalization_steps_count=%d "
-          "finalization_steps_took=%.1f "
-          "finalization_longest_step=%.1f "
+          "incremental=%.1f "
+          "incremental.finalize=%.1f "
+          "incremental.finalize.external.prologue=%.1f "
+          "incremental.finalize.external.epilogue=%.1f "
+          "incremental.finalize.object_grouping=%.1f "
+          "incremental.wrapper_prologue=%.1f "
+          "incremental.wrapper_tracing=%.1f "
+          "incremental_finalize_longest_step=%.1f "
+          "incremental_finalize_steps_count=%d "
+          "incremental_steps_count=%d "
+          "incremental_longest_step=%.1f "
           "incremental_marking_throughput=%.f "
           "total_size_before=%" V8PRIdPTR
           " "
           "total_size_after=%" V8PRIdPTR
           " "
           "holes_size_before=%" V8PRIdPTR
           " "
           "holes_size_after=%" V8PRIdPTR
           " "
           "allocated=%" V8PRIdPTR
@@ skipping 28 matching lines @@
           current_.scopes[Scope::MC_EVACUATE],
           current_.scopes[Scope::MC_EVACUATE_CANDIDATES],
           current_.scopes[Scope::MC_EVACUATE_CLEAN_UP],
           current_.scopes[Scope::MC_EVACUATE_COPY],
           current_.scopes[Scope::MC_EVACUATE_UPDATE_POINTERS],
           current_.scopes[Scope::MC_EVACUATE_UPDATE_POINTERS_TO_EVACUATED],
           current_.scopes[Scope::MC_EVACUATE_UPDATE_POINTERS_TO_NEW],
           current_.scopes[Scope::MC_EVACUATE_UPDATE_POINTERS_WEAK],
           current_.scopes[Scope::MC_EXTERNAL_PROLOGUE],
           current_.scopes[Scope::MC_EXTERNAL_EPILOGUE],
-          current_.scopes[Scope::MC_INCREMENTAL_EXTERNAL_PROLOGUE],
-          current_.scopes[Scope::MC_INCREMENTAL_EXTERNAL_EPILOGUE],
           current_.scopes[Scope::EXTERNAL_WEAK_GLOBAL_HANDLES],
           current_.scopes[Scope::MC_FINISH], current_.scopes[Scope::MC_MARK],
           current_.scopes[Scope::MC_MARK_FINISH_INCREMENTAL],
+          current_.scopes[Scope::MC_MARK_OBJECT_GROUPING],
           current_.scopes[Scope::MC_MARK_PREPARE_CODE_FLUSH],
           current_.scopes[Scope::MC_MARK_ROOTS],
           current_.scopes[Scope::MC_MARK_WEAK_CLOSURE],
           current_.scopes[Scope::MC_MARK_WEAK_CLOSURE_EPHEMERAL],
           current_.scopes[Scope::MC_MARK_WEAK_CLOSURE_WEAK_HANDLES],
           current_.scopes[Scope::MC_MARK_WEAK_CLOSURE_WEAK_ROOTS],
           current_.scopes[Scope::MC_MARK_WEAK_CLOSURE_HARMONY],
+          current_.scopes[Scope::MC_MARK_WRAPPER_PROLOGUE],
+          current_.scopes[Scope::MC_MARK_WRAPPER_EPILOGUE],
+          current_.scopes[Scope::MC_MARK_WRAPPER_TRACING],
           current_.scopes[Scope::MC_SWEEP],
           current_.scopes[Scope::MC_SWEEP_CODE],
           current_.scopes[Scope::MC_SWEEP_MAP],
           current_.scopes[Scope::MC_SWEEP_OLD],
+          current_.incremental_marking_duration,
           current_.scopes[Scope::MC_INCREMENTAL_FINALIZE],
+          current_.scopes[Scope::MC_INCREMENTAL_EXTERNAL_PROLOGUE],
+          current_.scopes[Scope::MC_INCREMENTAL_EXTERNAL_EPILOGUE],
+          current_.scopes[Scope::MC_INCREMENTAL_FINALIZE_OBJECT_GROUPING],
+          current_.scopes[Scope::MC_INCREMENTAL_WRAPPER_PROLOGUE],
+          current_.scopes[Scope::MC_INCREMENTAL_WRAPPER_TRACING],
+          current_.longest_incremental_marking_finalization_step,
+          current_.incremental_marking_finalizaton_steps,
           current_.incremental_marking_steps,
-          current_.incremental_marking_duration,
           current_.longest_incremental_marking_step,
-          cumulative_incremental_marking_finalization_steps_,
-          cumulative_incremental_marking_finalization_duration_,
-          longest_incremental_marking_finalization_step_,
           IncrementalMarkingSpeedInBytesPerMillisecond(),
           current_.start_object_size, current_.end_object_size,
           current_.start_holes_size, current_.end_holes_size,
           allocated_since_last_gc, heap_->promoted_objects_size(),
           heap_->semi_space_copied_object_size(),
           heap_->nodes_died_in_new_space_, heap_->nodes_copied_in_new_space_,
           heap_->nodes_promoted_, heap_->promotion_ratio_,
           AverageSurvivalRatio(), heap_->promotion_rate_,
           heap_->semi_space_copied_rate_,
           NewSpaceAllocationThroughputInBytesPerMillisecond(),
@@ skipping 130 matching lines @@
   return sum / recorded_survival_ratios_.Count();
 }
 
 bool GCTracer::SurvivalEventsRecorded() const {
   return recorded_survival_ratios_.Count() > 0;
 }
 
 void GCTracer::ResetSurvivalEvents() { recorded_survival_ratios_.Reset(); }
 }  // namespace internal
 }  // namespace v8