[heap] Add detailed timers to --trace-gc-nvp MC marking phase.

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 451 matching lines @@
     case Event::MARK_COMPACTOR:
     case Event::INCREMENTAL_MARK_COMPACTOR:
       PrintIsolate(heap_->isolate(),
                    "[I:%p] %8.0f ms: "
                    "pause=%.1f "
                    "mutator=%.1f "
                    "gc=%s "
                    "reduce_memory=%d "
                    "external=%.1f "
                    "mark=%.1f "
+                   "mark_inc=%.1f "
+                   "mark_prepcodeflush=%.1f "
+                   "mark_root=%.1f "
+                   "mark_topopt=%.1f "
+                   "mark_retainmaps=%.1f "
+                   "mark_weakclosure=%.1f "
+                   "mark_stringtable=%.1f "
+                   "mark_weakrefs=%.1f "
+                   "mark_globalhandles=%.1f "
+                   "mark_codeflush=%.1f "
                    "sweep=%.2f "
                    "sweepns=%.2f "
                    "sweepos=%.2f "
                    "sweepcode=%.2f "
                    "sweepcell=%.2f "
                    "sweepmap=%.2f "
                    "evacuate=%.1f "
                    "new_new=%.1f "
                    "root_new=%.1f "
                    "old_new=%.1f "
                    "compaction_ptrs=%.1f "
                    "intracompaction_ptrs=%.1f "
                    "misc_compaction=%.1f "
                    "weak_closure=%.1f "
                    "inc_weak_closure=%.1f "
                    "weakcollection_process=%.1f "
                    "weakcollection_clear=%.1f "
                    "weakcollection_abort=%.1f "
                    "weakcells=%.1f "
                    "nonlive_refs=%.1f "
                    "steps_count=%d "
                    "steps_took=%.1f "
                    "longest_step=%.1f "
-                   "incremental_marking_throughput=%" V8_PTR_PREFIX "d "
-                   "total_size_before=%" V8_PTR_PREFIX "d "
-                   "total_size_after=%" V8_PTR_PREFIX "d "
-                   "holes_size_before=%" V8_PTR_PREFIX "d "
-                   "holes_size_after=%" V8_PTR_PREFIX "d "
-                   "allocated=%" V8_PTR_PREFIX "d "
-                   "promoted=%" V8_PTR_PREFIX "d "
-                   "semi_space_copied=%" V8_PTR_PREFIX "d "
+                   "incremental_marking_throughput=%" V8_PTR_PREFIX
+                   "d "
+                   "total_size_before=%" V8_PTR_PREFIX
+                   "d "
+                   "total_size_after=%" V8_PTR_PREFIX
+                   "d "
+                   "holes_size_before=%" V8_PTR_PREFIX
+                   "d "
+                   "holes_size_after=%" V8_PTR_PREFIX
+                   "d "
+                   "allocated=%" V8_PTR_PREFIX
+                   "d "
+                   "promoted=%" V8_PTR_PREFIX
+                   "d "
+                   "semi_space_copied=%" V8_PTR_PREFIX
+                   "d "
                    "nodes_died_in_new=%d "
                    "nodes_copied_in_new=%d "
                    "nodes_promoted=%d "
                    "promotion_ratio=%.1f%% "
                    "average_survival_ratio=%.1f%% "
                    "promotion_rate=%.1f%% "
                    "semi_space_copy_rate=%.1f%% "
-                   "new_space_allocation_throughput=%" V8_PTR_PREFIX "d "
+                   "new_space_allocation_throughput=%" V8_PTR_PREFIX
+                   "d "
                    "context_disposal_rate=%.1f\n",
-                   heap_->isolate(),
-                   heap_->isolate()->time_millis_since_init(),
-                   duration, spent_in_mutator,
-                   current_.TypeName(true),
-                   current_.reduce_memory,
-                   current_.scopes[Scope::EXTERNAL],
+                   heap_->isolate(), heap_->isolate()->time_millis_since_init(),
+                   duration, spent_in_mutator, current_.TypeName(true),
+                   current_.reduce_memory, current_.scopes[Scope::EXTERNAL],
                    current_.scopes[Scope::MC_MARK],
+                   current_.scopes[Scope::MC_MARK_FINISH_INCREMENTAL],
+                   current_.scopes[Scope::MC_MARK_PREPARE_CODE_FLUSH],
+                   current_.scopes[Scope::MC_MARK_ROOT],
+                   current_.scopes[Scope::MC_MARK_TOPOPT],
+                   current_.scopes[Scope::MC_MARK_RETAIN_MAPS],
+                   current_.scopes[Scope::MC_MARK_WEAK_CLOSURE],
+                   current_.scopes[Scope::MC_MARK_STRING_TABLE],
+                   current_.scopes[Scope::MC_MARK_WEAK_REFERENCES],
+                   current_.scopes[Scope::MC_MARK_GLOBAL_HANDLES],
+                   current_.scopes[Scope::MC_MARK_CODE_FLUSH],
                    current_.scopes[Scope::MC_SWEEP],
                    current_.scopes[Scope::MC_SWEEP_NEWSPACE],
                    current_.scopes[Scope::MC_SWEEP_OLDSPACE],
                    current_.scopes[Scope::MC_SWEEP_CODE],
                    current_.scopes[Scope::MC_SWEEP_CELL],
                    current_.scopes[Scope::MC_SWEEP_MAP],
                    current_.scopes[Scope::MC_EVACUATE_PAGES],
                    current_.scopes[Scope::MC_UPDATE_NEW_TO_NEW_POINTERS],
                    current_.scopes[Scope::MC_UPDATE_ROOT_TO_NEW_POINTERS],
                    current_.scopes[Scope::MC_UPDATE_OLD_TO_NEW_POINTERS],
@@ skipping 286 matching lines @@
 
 
 bool GCTracer::SurvivalEventsRecorded() const {
   return survival_events_.size() > 0;
 }
 
 
 void GCTracer::ResetSurvivalEvents() { survival_events_.reset(); }
 }  // namespace internal
 }  // namespace v8