[--prof] Adding support for RuntimeCallTimerScope based tick separation

BUG=

Review-Url: https://codereview.chromium.org/2050713002
Cr-Commit-Position: refs/heads/master@{#36883}

src/counters.cc

@@ -9,6 +9,7 @@
 #include "src/base/platform/platform.h"
 #include "src/isolate.h"
 #include "src/log-inl.h"
+#include "src/log.h"
 
 namespace v8 {
 namespace internal {

src/counters.h

@@ -493,6 +493,8 @@ struct RuntimeCallCounter {
 class RuntimeCallTimer {
  public:
   RuntimeCallTimer() {}
+  RuntimeCallCounter* counter() { return counter_; }
+  base::ElapsedTimer timer() { return timer_; }
 
  private:
   friend class RuntimeCallStats;
@@ -775,6 +777,7 @@ class RuntimeCallStats {
   void Print(std::ostream& os);
 
   RuntimeCallStats() { Reset(); }
+  RuntimeCallTimer* current_timer() { return current_timer_; }
 
  private:
   // Counter to track recursive time events.

src/log.cc

@@ -11,6 +11,7 @@
 #include "src/base/platform/platform.h"
 #include "src/bootstrapper.h"
 #include "src/code-stubs.h"
+#include "src/counters.h"
 #include "src/deoptimizer.h"
 #include "src/global-handles.h"
 #include "src/interpreter/bytecodes.h"
@@ -1421,9 +1422,23 @@ void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
   msg.WriteToLogFile();
 }
 
+void Logger::RuntimeCallTimerEvent() {
+  RuntimeCallStats* stats = isolate_->counters()->runtime_call_stats();
+  RuntimeCallTimer* timer = stats->current_timer();
+  if (timer == nullptr) return;
+  RuntimeCallCounter* counter = timer->counter();
+  if (counter == nullptr) return;
+  Log::MessageBuilder msg(log_);
+  msg.Append("active-runtime-timer,");
+  msg.AppendDoubleQuotedString(counter->name);
+  msg.WriteToLogFile();
+}
 
 void Logger::TickEvent(TickSample* sample, bool overflow) {
   if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
+  if (FLAG_runtime_call_stats) {
+    RuntimeCallTimerEvent();
+  }
   Log::MessageBuilder msg(log_);
   msg.Append("%s,", kLogEventsNames[TICK_EVENT]);
   msg.AppendAddress(sample->pc);

src/log.h

@@ -68,6 +68,7 @@ class PositionsRecorder;
 class Profiler;
 class Ticker;
 struct TickSample;
+class RuntimeCallTimer;
 
 #undef LOG
 #define LOG(isolate, Call)                          \
@@ -354,6 +355,7 @@ class Logger {
 
   // Emits a profiler tick event. Used by the profiler thread.
   void TickEvent(TickSample* sample, bool overflow);
+  void RuntimeCallTimerEvent();
 
   PRINTF_FORMAT(2, 3) void ApiEvent(const char* format, ...);
 

tools/tickprocessor-driver.js

@@ -72,6 +72,7 @@ var tickProcessor = new TickProcessor(
   sourceMap,
   params.timedRange,
   params.pairwiseTimedRange,
-  params.onlySummary);
+  params.onlySummary,
+  params.runtimeTimerFilter);
 tickProcessor.processLogFile(params.logFileName);
 tickProcessor.printStatistics();

tools/tickprocessor.js

@@ -81,7 +81,8 @@ function TickProcessor(
     sourceMap,
     timedRange,
     pairwiseTimedRange,
-    onlySummary) {
+    onlySummary,
+    runtimeTimerFilter) {
   LogReader.call(this, {
       'shared-library': { parsers: [null, parseInt, parseInt, parseInt],
           processor: this.processSharedLibrary },
@@ -94,6 +95,9 @@ function TickProcessor(
           processor: this.processCodeDelete },
       'sfi-move': { parsers: [parseInt, parseInt],
           processor: this.processFunctionMove },
+      'active-runtime-timer': {
+        parsers: [null],
+        processor: this.processRuntimeTimerEvent },
       'tick': {
           parsers: [parseInt, parseInt, parseInt,
                     parseInt, parseInt, 'var-args'],
@@ -124,6 +128,7 @@ function TickProcessor(
   this.callGraphSize_ = callGraphSize;
   this.ignoreUnknown_ = ignoreUnknown;
   this.stateFilter_ = stateFilter;
+  this.runtimeTimerFilter_ = runtimeTimerFilter;
   this.sourceMap = sourceMap;
   this.deserializedEntriesNames_ = [];
   var ticks = this.ticks_ =
@@ -284,9 +289,18 @@ TickProcessor.prototype.processFunctionMove = function(from, to) {
 
 
 TickProcessor.prototype.includeTick = function(vmState) {
-  return this.stateFilter_ == null || this.stateFilter_ == vmState;
+  if (this.stateFilter_ !== null) {
+    return this.stateFilter_ == vmState;
+  } else if (this.runtimeTimerFilter_ !== null) {
+    return this.currentRuntimeTimer == this.runtimeTimerFilter_;
+  }
+  return true;
 };
 
+TickProcessor.prototype.processRuntimeTimerEvent = function(name) {
+  this.currentRuntimeTimer = name;
+}
+
 TickProcessor.prototype.processTick = function(pc,
                                                ns_since_start,
                                                is_external_callback,
@@ -781,6 +795,8 @@ function ArgumentsProcessor(args) {
         'Show only ticks from OTHER VM state'],
     '-e': ['stateFilter', TickProcessor.VmStates.EXTERNAL,
         'Show only ticks from EXTERNAL VM state'],
+    '--filter-runtime-timer': ['runtimeTimerFilter', null,
+            'Show only ticks matching the given runtime timer scope'],
     '--call-graph-size': ['callGraphSize', TickProcessor.CALL_GRAPH_SIZE,
         'Set the call graph size'],
     '--ignore-unknown': ['ignoreUnknown', true,
@@ -832,7 +848,8 @@ ArgumentsProcessor.DEFAULTS = {
   distortion: 0,
   timedRange: false,
   pairwiseTimedRange: false,
-  onlySummary: false
+  onlySummary: false,
+  runtimeTimerFilter: null,
 };