[Tracing] Fix runtime call stats tracing for GC.

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"
 
 namespace v8 {
 namespace internal {
 
 static intptr_t CountTotalHolesSize(Heap* heap) {
   intptr_t holes_size = 0;
   OldSpaces spaces(heap);
   for (OldSpace* space = spaces.next(); space != NULL; space = spaces.next()) {
     holes_size += space->Waste() + space->Available();
   }
   return holes_size;
 }
 
 
 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) {
+  if (TRACE_EVENT_RUNTIME_CALL_STATS_TRACING_ENABLED()) {
+    RuntimeCallStats::Enter(
+        tracer_->heap_->isolate()->counters()->tracing_runtime_call_stats(),

[ulan, 2016/09/08 12:03:37]

Naive question: why can't we use the same counter for tracing runtime calls and
ordinary runtime calls?

They seem to be mutually exclusive.

[Camillo Bruni, 2016/09/08 15:47:52]

You're right. Previously they weren't mutually exclusive which would have
justified the separate counter lists.

[lpy, 2016/09/08 18:23:53]

Done.

[lpy, 2016/09/08 18:23:53]

right, this is also what fmeawad@ is suggesting. Done.

+        &timer_, &RuntimeCallStats::GC);

[fmeawad, 2016/09/07 17:31:28]

This code is repeated 2 times, should we move it to counters?

[lpy, 2016/09/08 18:23:53]

I don't think we should make another enter and leave in counter.

+  } else if (FLAG_runtime_call_stats) {
+    // TODO(cbruni): remove once we fully moved to a trace-based system.
     RuntimeCallStats::Enter(
         tracer_->heap_->isolate()->counters()->runtime_call_stats(), &timer_,
         &RuntimeCallStats::GC);
   }
-  // TODO(lpy): Add a tracing equivalent for the runtime call stats.
 }
 
 GCTracer::Scope::~Scope() {
   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) {
+  if (TRACE_EVENT_RUNTIME_CALL_STATS_TRACING_ENABLED()) {
+    RuntimeCallStats::Leave(
+        tracer_->heap_->isolate()->counters()->tracing_runtime_call_stats(),
+        &timer_);
+  } else if (FLAG_runtime_call_stats) {
+    // TODO(cbruni): remove once we fully moved to a trace-based system.
     RuntimeCallStats::Leave(
         tracer_->heap_->isolate()->counters()->runtime_call_stats(), &timer_);
   }
-  // TODO(lpy): Add a tracing equivalent for the runtime call stats.
 }
 
 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;
@@ skipping 154 matching lines @@
   Counters* counters = heap_->isolate()->counters();
 
   if (collector == SCAVENGER) {
     counters->scavenge_reason()->AddSample(static_cast<int>(gc_reason));
   } else {
     counters->mark_compact_reason()->AddSample(static_cast<int>(gc_reason));
   }
   counters->aggregated_memory_heap_committed()->AddSample(start_time,
                                                           committed_memory);
   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) {
+  if (TRACE_EVENT_RUNTIME_CALL_STATS_TRACING_ENABLED()) {
+    RuntimeCallStats::Enter(
+        heap_->isolate()->counters()->tracing_runtime_call_stats(), &timer_,
+        &RuntimeCallStats::GC);
+  } else if (FLAG_runtime_call_stats) {
+    // TODO(cbruni): remove once we fully moved to a trace-based system.
     RuntimeCallStats::Enter(heap_->isolate()->counters()->runtime_call_stats(),
                             &timer_, &RuntimeCallStats::GC);
   }
-  // TODO(lpy): Add a tracing equivalent for the runtime call stats.
 }
 
 void GCTracer::MergeBaseline(const Event& baseline) {
   current_.incremental_marking_bytes =
       current_.cumulative_incremental_marking_bytes -
       baseline.cumulative_incremental_marking_bytes;
   current_.pure_incremental_marking_duration =
       current_.cumulative_pure_incremental_marking_duration -
       baseline.cumulative_pure_incremental_marking_duration;
   for (int i = Scope::FIRST_INCREMENTAL_SCOPE;
@@ skipping 80 matching lines @@
   if (FLAG_trace_gc_nvp) {
     PrintNVP();
   } else {
     Print();
   }
 
   if (FLAG_trace_gc) {
     heap_->PrintShortHeapStatistics();
   }
 
-  // TODO(cbruni): remove once we fully moved to a trace-based system.
-  if (FLAG_runtime_call_stats) {
+  if (TRACE_EVENT_RUNTIME_CALL_STATS_TRACING_ENABLED()) {
+    RuntimeCallStats::Leave(
+        heap_->isolate()->counters()->tracing_runtime_call_stats(), &timer_);
+  } else if (FLAG_runtime_call_stats) {
+    // TODO(cbruni): remove once we fully moved to a trace-based system.
     RuntimeCallStats::Leave(heap_->isolate()->counters()->runtime_call_stats(),
                             &timer_);
   }
-  // TODO(lpy): Add a tracing equivalent for the runtime call stats.
 }
 
 
 void GCTracer::SampleAllocation(double current_ms,
                                 size_t new_space_counter_bytes,
                                 size_t old_generation_counter_bytes) {
   if (allocation_time_ms_ == 0) {
     // It is the first sample.
     allocation_time_ms_ = current_ms;
     new_space_allocation_counter_bytes_ = new_space_counter_bytes;
@@ skipping 493 matching lines @@
 }
 
 void GCTracer::ResetSurvivalEvents() { recorded_survival_ratios_.Reset(); }
 
 void GCTracer::NotifyIncrementalMarkingStart() {
   incremental_marking_start_time_ = heap_->MonotonicallyIncreasingTimeInMs();
 }
 
 }  // namespace internal
 }  // namespace v8