[heap] Add timer to incremental marking finalization phase.

BUG=

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

Cr-Commit-Position: refs/heads/master@{#32601}

src/heap/gc-tracer.cc

@@ -113,6 +113,9 @@ GCTracer::GCTracer(Heap* heap)
       cumulative_incremental_marking_duration_(0.0),
       cumulative_pure_incremental_marking_duration_(0.0),
       longest_incremental_marking_step_(0.0),
+      cumulative_incremental_marking_finalization_steps_(0),
+      cumulative_incremental_marking_finalization_duration_(0.0),
+      longest_incremental_marking_finalization_step_(0.0),
       cumulative_marking_duration_(0.0),
       cumulative_sweeping_duration_(0.0),
       allocation_time_ms_(0.0),
@@ -274,6 +277,10 @@ void GCTracer::Stop(GarbageCollector collector) {
   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;
 }
 
 
@@ -347,6 +354,14 @@ void GCTracer::AddIncrementalMarkingStep(double duration, intptr_t bytes) {
 }
 
 
+void GCTracer::AddIncrementalMarkingFinalizationStep(double duration) {
+  cumulative_incremental_marking_finalization_steps_++;
+  cumulative_incremental_marking_finalization_duration_ += duration;
+  longest_incremental_marking_finalization_step_ =
+      Max(longest_incremental_marking_finalization_step_, duration);
+}
+
+
 void GCTracer::Output(const char* format, ...) const {
   if (FLAG_trace_gc) {
     va_list arguments;
@@ -533,6 +548,9 @@ void GCTracer::PrintNVP() const {
                    "steps_count=%d "
                    "steps_took=%.1f "
                    "longest_step=%.1f "
+                   "finalization_steps_count=%d "
+                   "finalization_steps_took=%.1f "
+                   "finalization_longest_step=%.1f "
                    "incremental_marking_throughput=%" V8_PTR_PREFIX
                    "d "
                    "total_size_before=%" V8_PTR_PREFIX
@@ -602,6 +620,9 @@ void GCTracer::PrintNVP() const {
                    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,

src/heap/gc-tracer.h

@@ -353,6 +353,8 @@ class GCTracer {
   // 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;
@@ -503,6 +505,9 @@ class GCTracer {
     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;
   }
@@ -559,6 +564,17 @@ class GCTracer {
   // 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_;

src/heap/incremental-marking.cc

@@ -690,6 +690,8 @@ void IncrementalMarking::FinalizeIncrementally() {
   DCHECK(!finalize_marking_completed_);
   DCHECK(IsMarking());
 
+  double start = heap_->MonotonicallyIncreasingTimeInMs();
+
   int old_marking_deque_top =
       heap_->mark_compact_collector()->marking_deque()->top();
 
@@ -707,6 +709,18 @@ void IncrementalMarking::FinalizeIncrementally() {
       abs(old_marking_deque_top -
           heap_->mark_compact_collector()->marking_deque()->top());
 
+  double end = heap_->MonotonicallyIncreasingTimeInMs();
+  double delta = end - start;
+  heap_->tracer()->AddMarkingTime(delta);
+  heap_->tracer()->AddIncrementalMarkingFinalizationStep(delta);
+  if (FLAG_trace_incremental_marking) {
+    PrintF(
+        "[IncrementalMarking] Finalize incrementally round %d, "
+        "spent %d ms, marking progress %d.\n",
+        static_cast<int>(delta), incremental_marking_finalization_rounds_,
+        marking_progress);
+  }
+
   ++incremental_marking_finalization_rounds_;
   if ((incremental_marking_finalization_rounds_ >=
        FLAG_max_incremental_marking_finalization_rounds) ||