[heap] GCTracer: Record details for incremental marking

src/heap/gc-tracer.h

 // 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.
 
 #ifndef V8_HEAP_GC_TRACER_H_
 #define V8_HEAP_GC_TRACER_H_
 
 #include "src/base/compiler-specific.h"
 #include "src/base/platform/platform.h"
 #include "src/counters.h"
@@ skipping 42 matching lines @@
 };
 
 typedef std::pair<uint64_t, double> BytesAndDuration;
 
 inline BytesAndDuration MakeBytesAndDuration(uint64_t bytes, double duration) {
   return std::make_pair(bytes, duration);
 }
 
 enum ScavengeSpeedMode { kForAllObjects, kForSurvivedObjects };
 
-#define INCREMENTAL_SCOPES(F)                \
-  F(MC_INCREMENTAL_WRAPPER_PROLOGUE)         \
-  F(MC_INCREMENTAL_WRAPPER_TRACING)          \
-  F(MC_INCREMENTAL_FINALIZE)                 \
-  F(MC_INCREMENTAL_FINALIZE_OBJECT_GROUPING) \
-  F(MC_INCREMENTAL_EXTERNAL_EPILOGUE)        \
+#define INCREMENTAL_SCOPES(F)                                      \
+  /* MC_INCREMENTAL is the top-level incremental marking scope. */ \
+  F(MC_INCREMENTAL)                                                \
+  F(MC_INCREMENTAL_WRAPPER_PROLOGUE)                               \
+  F(MC_INCREMENTAL_WRAPPER_TRACING)                                \
+  F(MC_INCREMENTAL_FINALIZE)                                       \
+  F(MC_INCREMENTAL_FINALIZE_BODY)                                  \
+  F(MC_INCREMENTAL_FINALIZE_OBJECT_GROUPING)                       \
+  F(MC_INCREMENTAL_EXTERNAL_EPILOGUE)                              \
   F(MC_INCREMENTAL_EXTERNAL_PROLOGUE)
 
 #define TRACER_SCOPES(F)                      \
   INCREMENTAL_SCOPES(F)                       \
   F(EXTERNAL_WEAK_GLOBAL_HANDLES)             \
   F(MC_CLEAR)                                 \
   F(MC_CLEAR_CODE_FLUSH)                      \
   F(MC_CLEAR_DEPENDENT_CODE)                  \
   F(MC_CLEAR_GLOBAL_HANDLES)                  \
   F(MC_CLEAR_MAPS)                            \
@@ skipping 42 matching lines @@
   F(SCAVENGER_WEAK)
 
 #define TRACE_GC(tracer, scope_id)                             \
   GCTracer::Scope::ScopeId gc_tracer_scope_id(scope_id);       \
   GCTracer::Scope gc_tracer_scope(tracer, gc_tracer_scope_id); \
   TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8.gc"),             \
                GCTracer::Scope::Name(gc_tracer_scope_id))
 
 // GCTracer collects and prints ONE line after each garbage collector
 // invocation IFF --trace_gc is used.
-// TODO(ernstm): Unit tests.
 class GCTracer {
  public:
+  struct IncrementalMarkingInfos {
+    IncrementalMarkingInfos()
+        : cumulative_duration(0), longest_step(0), steps(0) {}
+
+    void Update(double duration) {
+      steps++;
+      cumulative_duration += duration;
+      if (duration > longest_step) {
+        longest_step = duration;
+      }
+    }
+
+    void ResetCurrentCycle() {
+      longest_step = 0;
+      steps = 0;
+    }
+
+    double cumulative_duration;
+    double longest_step;
+    int steps;
+  };
+
   class Scope {
    public:
     enum ScopeId {
 #define DEFINE_SCOPE(scope) scope,
       TRACER_SCOPES(DEFINE_SCOPE)
 #undef DEFINE_SCOPE
           NUMBER_OF_SCOPES,
 
-      FIRST_INCREMENTAL_SCOPE = MC_INCREMENTAL_WRAPPER_PROLOGUE,
+      FIRST_INCREMENTAL_SCOPE = MC_INCREMENTAL,
       LAST_INCREMENTAL_SCOPE = MC_INCREMENTAL_EXTERNAL_PROLOGUE,
       NUMBER_OF_INCREMENTAL_SCOPES =
           LAST_INCREMENTAL_SCOPE - FIRST_INCREMENTAL_SCOPE + 1
     };
 
     Scope(GCTracer* tracer, ScopeId scope);
     ~Scope();
     static const char* Name(ScopeId id);
 
    private:
     GCTracer* tracer_;
     ScopeId scope_;
     double start_time_;
     RuntimeCallTimer timer_;
 
     DISALLOW_COPY_AND_ASSIGN(Scope);
   };
 
 
   class Event {
    public:
     enum Type {
       SCAVENGER = 0,
       MARK_COMPACTOR = 1,
       INCREMENTAL_MARK_COMPACTOR = 2,
       START = 3
     };
 
-    // Default constructor leaves the event uninitialized.
-    Event() {}
-
     Event(Type type, const char* gc_reason, const char* collector_reason);
 
     // Returns a string describing the event type.
     const char* TypeName(bool short_name) const;
 
     // Type of event
     Type type;
 
     const char* gc_reason;
     const char* collector_reason;
@@ skipping 22 matching lines @@
     // Total amount of space either wasted or contained in one of free lists
     // before the current GC.
     intptr_t start_holes_size;
 
     // Total amount of space either wasted or contained in one of free lists
     // after the current GC.
     intptr_t end_holes_size;
 
     // Size of new space objects in constructor.
     intptr_t new_space_object_size;
+
     // Size of survived new space objects in destructor.
     intptr_t survived_new_space_object_size;
 
-    // Number of incremental marking steps since creation of tracer.
-    // (value at start of event)
-    int cumulative_incremental_marking_steps;
-
-    // Incremental marking steps since
-    // - last event for SCAVENGER events
-    // - last INCREMENTAL_MARK_COMPACTOR event for INCREMENTAL_MARK_COMPACTOR
-    // events
-    int incremental_marking_steps;
-
     // Bytes marked since creation of tracer (value at start of event).
     intptr_t cumulative_incremental_marking_bytes;
 
     // Bytes marked since
     // - last event for SCAVENGER events
     // - last INCREMENTAL_MARK_COMPACTOR event for INCREMENTAL_MARK_COMPACTOR
     // events
     intptr_t incremental_marking_bytes;
 
-    // Cumulative duration of incremental marking steps since creation of
-    // tracer. (value at start of event)
-    double cumulative_incremental_marking_duration;
-
-    // Duration of incremental marking steps since
-    // - last event for SCAVENGER events
-    // - last INCREMENTAL_MARK_COMPACTOR event for INCREMENTAL_MARK_COMPACTOR
-    // events
-    double incremental_marking_duration;
-
     // Cumulative pure duration of incremental marking steps since creation of
     // tracer. (value at start of event)
     double cumulative_pure_incremental_marking_duration;
 
     // Duration of pure incremental marking steps since
     // - last event for SCAVENGER events
     // - last INCREMENTAL_MARK_COMPACTOR event for INCREMENTAL_MARK_COMPACTOR
     // events
     double pure_incremental_marking_duration;
 
-    // Longest incremental marking step since start of marking (start of event).
-    double longest_incremental_marking_step;
-
-    // Number of incremental marking finalization steps since creation of
-    // tracer.
-    int cumulative_incremental_marking_finalization_steps;
-
-    // Cumulative pure duration of incremental marking steps since creation of
-    // tracer. (value at start of event)
-    double cumulative_incremental_marking_finalizaton_duration;
-
-    // Longest incremental marking finalization step since start of marking
-    // (start of event).
-    double longest_incremental_marking_finalization_step;
-
-    // Incremental marking finalization steps since
-    // - last event for SCAVENGER events
-    // - last INCREMENTAL_MARK_COMPACTOR event for INCREMENTAL_MARK_COMPACTOR
-    // events
-    int incremental_marking_finalizaton_steps;
-
-    // Duration of incremental marking finalization steps since
-    // - last event for SCAVENGER events
-    // - last INCREMENTAL_MARK_COMPACTOR event for INCREMENTAL_MARK_COMPACTOR
-    // events
-    double incremental_marking_finalization_duration;
-
-    double cumulative_incremental_scopes[Scope::NUMBER_OF_INCREMENTAL_SCOPES];
-
     // Amounts of time spent in different scopes during GC.
     double scopes[Scope::NUMBER_OF_SCOPES];
+
+    // Holds details for incremental marking scopes.
+    IncrementalMarkingInfos
+        incremental_marking_scopes[Scope::NUMBER_OF_INCREMENTAL_SCOPES];
   };
 
   static const int kThroughputTimeFrameMs = 5000;
 
   explicit GCTracer(Heap* heap);
 
   // Start collecting data.
   void Start(GarbageCollector collector, const char* gc_reason,
              const char* collector_reason);
 
   // Stop collecting data and print results.
   void Stop(GarbageCollector collector);
 
   // Sample and accumulate bytes allocated since the last GC.
   void SampleAllocation(double current_ms, size_t new_space_counter_bytes,
                         size_t old_generation_counter_bytes);
 
   // Log the accumulated new space allocation bytes.
   void AddAllocation(double current_ms);
 
   void AddContextDisposalTime(double time);
 
   void AddCompactionEvent(double duration, intptr_t live_bytes_compacted);
 
   void AddSurvivalRatio(double survival_ratio);
 
   // Log an incremental marking step.
   void AddIncrementalMarkingStep(double duration, intptr_t bytes);
 
-  void AddIncrementalMarkingFinalizationStep(double duration);
-
   // Log time spent in marking.
   void AddMarkingTime(double duration) {
     cumulative_marking_duration_ += duration;
   }
 
   // Time spent in marking.
   double cumulative_marking_duration() const {
     return cumulative_marking_duration_;
   }
 
@@ skipping 69 matching lines @@
   // events.
   // Returns 0 if no events have been recorded.
   double AverageSurvivalRatio() const;
 
   // Returns true if at least one survival event was recorded.
   bool SurvivalEventsRecorded() const;
 
   // Discard all recorded survival events.
   void ResetSurvivalEvents();
 
-  void AddScopeSample(Scope::ScopeId scope, double duration);
+  V8_INLINE void AddScopeSample(Scope::ScopeId scope, double duration) {
+    DCHECK(scope < Scope::NUMBER_OF_SCOPES);
+    if (scope >= Scope::FIRST_INCREMENTAL_SCOPE &&
+        scope <= Scope::LAST_INCREMENTAL_SCOPE) {
+      incremental_marking_scopes_[scope].Update(duration);
+    } else {
+      current_.scopes[scope] += duration;
+    }
+  }
 
  private:
   FRIEND_TEST(GCTracer, AverageSpeed);
   FRIEND_TEST(GCTracerTest, AllocationThroughput);
   FRIEND_TEST(GCTracerTest, NewSpaceAllocationThroughput);
   FRIEND_TEST(GCTracerTest, NewSpaceAllocationThroughputWithProvidedTime);
   FRIEND_TEST(GCTracerTest, OldGenerationAllocationThroughputWithProvidedTime);
   FRIEND_TEST(GCTracerTest, RegularScope);
+  FRIEND_TEST(GCTracerTest, IncrementalMarkingDetails);
   FRIEND_TEST(GCTracerTest, IncrementalScope);
 
   // Returns the average speed of the events in the buffer.
   // If the buffer is empty, the result is 0.
   // Otherwise, the result is between 1 byte/ms and 1 GB/ms.
   static double AverageSpeed(const RingBuffer<BytesAndDuration>& buffer);
   static double AverageSpeed(const RingBuffer<BytesAndDuration>& buffer,
                              const BytesAndDuration& initial, double time_ms);
 
+  void MergeBaseline(const Event& baseline);
+
   void ResetForTesting();
 
   // Print one detailed trace line in name=value format.
   // TODO(ernstm): Move to Heap.
   void PrintNVP() const;
 
   // Print one trace line.
   // TODO(ernstm): Move to Heap.
   void Print() const;
 
   // Prints a line and also adds it to the heap's ring buffer so that
   // it can be included in later crash dumps.
   void PRINTF_FORMAT(2, 3) Output(const char* format, ...) const;
 
-  void ClearMarkCompactStatistics() {
-    cumulative_incremental_marking_steps_ = 0;
-    cumulative_incremental_marking_bytes_ = 0;
-    cumulative_incremental_marking_duration_ = 0;
-    cumulative_pure_incremental_marking_duration_ = 0;
-    longest_incremental_marking_step_ = 0;
-    cumulative_incremental_marking_finalization_steps_ = 0;
-    cumulative_incremental_marking_finalization_duration_ = 0;
-    longest_incremental_marking_finalization_step_ = 0;
-    cumulative_marking_duration_ = 0;
-    cumulative_sweeping_duration_ = 0;
-  }
-
   double TotalExternalTime() const {
     return current_.scopes[Scope::EXTERNAL_WEAK_GLOBAL_HANDLES] +
            current_.scopes[Scope::MC_EXTERNAL_EPILOGUE] +
            current_.scopes[Scope::MC_EXTERNAL_PROLOGUE] +
            current_.scopes[Scope::MC_INCREMENTAL_EXTERNAL_EPILOGUE] +
            current_.scopes[Scope::MC_INCREMENTAL_EXTERNAL_PROLOGUE] +
            current_.scopes[Scope::SCAVENGER_EXTERNAL_EPILOGUE] +
            current_.scopes[Scope::SCAVENGER_EXTERNAL_PROLOGUE];
   }
 
   // Pointer to the heap that owns this tracer.
   Heap* heap_;
 
   // Current tracer event. Populated during Start/Stop cycle. Valid after Stop()
   // has returned.
   Event current_;
 
   // Previous tracer event.
   Event previous_;
 
   // Previous INCREMENTAL_MARK_COMPACTOR event.
   Event previous_incremental_mark_compactor_event_;
 
-  // Cumulative number of incremental marking steps since creation of tracer.
-  int cumulative_incremental_marking_steps_;
-
   // Cumulative size of incremental marking steps (in bytes) since creation of
   // tracer.
   intptr_t cumulative_incremental_marking_bytes_;
 
   // Cumulative duration of incremental marking steps since creation of tracer.
   double cumulative_incremental_marking_duration_;
 
   // Cumulative duration of pure incremental marking steps since creation of
   // tracer.
   double cumulative_pure_incremental_marking_duration_;
 
-  // Longest incremental marking step since start of marking.
-  double longest_incremental_marking_step_;
-
-  // Cumulative number of incremental marking finalization steps since creation
-  // of tracer.
-  int cumulative_incremental_marking_finalization_steps_;
-
-  // Cumulative duration of incremental marking finalization steps since
-  // creation of tracer.
-  double cumulative_incremental_marking_finalization_duration_;
-
-  // Longest incremental marking finalization step since start of marking.
-  double longest_incremental_marking_finalization_step_;
-
   // Total marking time.
   // This timer is precise when run with --print-cumulative-gc-stat
   double cumulative_marking_duration_;
 
-  // Cumulative duration of incremental marking scopes since the creation of
-  // the tracer.
-  double cumulative_incremental_scopes_[Scope::NUMBER_OF_INCREMENTAL_SCOPES];
+  // Incremental scopes carry more information than just the duration. The infos
+  // here are merged back upon starting/stopping the GC tracer.
+  IncrementalMarkingInfos
+      incremental_marking_scopes_[Scope::NUMBER_OF_INCREMENTAL_SCOPES];
 
   // Total sweeping time on the main thread.
   // This timer is precise when run with --print-cumulative-gc-stat
   // TODO(hpayer): Account for sweeping time on sweeper threads. Add a
   // different field for that.
   // TODO(hpayer): This timer right now just holds the sweeping time
   // of the initial atomic sweeping pause. Make sure that it accumulates
   // all sweeping operations performed on the main thread.
   double cumulative_sweeping_duration_;
 
@@ skipping 25 matching lines @@
   RingBuffer<BytesAndDuration> recorded_old_generation_allocations_;
   RingBuffer<double> recorded_context_disposal_times_;
   RingBuffer<double> recorded_survival_ratios_;
 
   DISALLOW_COPY_AND_ASSIGN(GCTracer);
 };
 }  // namespace internal
 }  // namespace v8
 
 #endif  // V8_HEAP_GC_TRACER_H_