[DevTools] Re-implemented Profiler.getRuntimeCallStats.

The original Profiler.getRuntimeCallStats implementation retrieved
a bunch of V8 Counters instead of runtime call counters. This
functionality is now available through the new APIs:
enableCounters, disableCounters and getCounters.

The getRuntimeCallStats API now retrieves real V8 Runtime Call Stats.

Change-Id: I702f60a6c43773f5c41b6861be3f9435975c370f
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/2380853
Commit-Queue: Peter Kvitek <kvitekp@chromium.org>
Reviewed-by: Yang Guo <yangguo@chromium.org>
Reviewed-by: Toon Verwaest <verwaest@chromium.org>
Cr-Commit-Position: refs/heads/master@{#69753}

include/js_protocol.pdl

@@ -863,6 +863,16 @@ domain Profiler
       # Counter value.
       integer value
 
+  # Runtime call counter information.
+  experimental type RuntimeCallCounterInfo extends object
+    properties
+      # Counter name.
+      string name
+      # Counter value.
+      number value
+      # Counter time in seconds.
+      number time
+
   command disable
 
   command enable
@@ -927,6 +937,18 @@ domain Profiler
       # Type profile for all scripts since startTypeProfile() was turned on.
       array of ScriptTypeProfile result
 
+  # Enable counters collection.
+  experimental command enableCounters
+
+  # Disable counters collection.
+  experimental command disableCounters
+
+  # Retrieve counters.
+  experimental command getCounters
+    returns
+      # Collected counters information.
+      array of CounterInfo result
+
   # Enable run time call stats collection.
   experimental command enableRuntimeCallStats
 
@@ -936,8 +958,8 @@ domain Profiler
   # Retrieve run time call stats.
   experimental command getRuntimeCallStats
     returns
-      # Collected counter information.
-      array of CounterInfo result
+      # Collected runtime call counter information.
+      array of RuntimeCallCounterInfo result
 
   event consoleProfileFinished
     parameters

src/api/api.cc

@@ -10244,6 +10244,14 @@ int64_t debug::GetNextRandomInt64(v8::Isolate* v8_isolate) {
       ->NextInt64();
 }
 
+void debug::EnumerateRuntimeCallCounters(v8::Isolate* v8_isolate,
+                                         RuntimeCallCounterCallback callback) {
+  i::Isolate* isolate = reinterpret_cast<i::Isolate*>(v8_isolate);
+  if (isolate->counters()) {
+    isolate->counters()->runtime_call_stats()->EnumerateCounters(callback);
+  }
+}
+
 int debug::GetDebuggingId(v8::Local<v8::Function> function) {
   i::Handle<i::JSReceiver> callable = v8::Utils::OpenHandle(*function);
   if (!callable->IsJSFunction()) return i::DebugInfo::kNoDebuggingId;

src/debug/debug-interface.h

@@ -10,6 +10,7 @@
 #include "include/v8-inspector.h"
 #include "include/v8-util.h"
 #include "include/v8.h"
+#include "src/base/platform/time.h"
 #include "src/common/globals.h"
 #include "src/debug/interface-types.h"
 #include "src/utils/vector.h"
@@ -505,6 +506,11 @@ enum class NativeAccessorType {
 
 int64_t GetNextRandomInt64(v8::Isolate* isolate);
 
+using RuntimeCallCounterCallback =
+    std::function<void(const char* name, int64_t count, base::TimeDelta time)>;
+void EnumerateRuntimeCallCounters(v8::Isolate* isolate,
+                                  RuntimeCallCounterCallback callback);
+
 enum class EvaluateGlobalMode {
   kDefault,
   kDisableBreaks,

src/inspector/DEPS

@@ -13,6 +13,7 @@ include_rules = [
   "+src/base/safe_conversions.h",
   "+src/base/template-utils.h",
   "+src/base/v8-fallthrough.h",
+  "+src/logging/tracing-flags.h",
   "+src/numbers/conversions.h",
   "+src/inspector",
   "+src/tracing",

src/inspector/v8-profiler-agent-impl.cc

@@ -6,6 +6,7 @@
 
 #include <vector>
 
+#include "include/v8-profiler.h"
 #include "src/base/atomicops.h"
 #include "src/base/platform/time.h"
 #include "src/debug/debug-interface.h"
@@ -15,8 +16,7 @@
 #include "src/inspector/v8-inspector-impl.h"
 #include "src/inspector/v8-inspector-session-impl.h"
 #include "src/inspector/v8-stack-trace-impl.h"
-
-#include "include/v8-profiler.h"
+#include "src/logging/tracing-flags.h"
 
 namespace v8_inspector {
 
@@ -30,6 +30,8 @@ static const char preciseCoverageDetailed[] = "preciseCoverageDetailed";
 static const char preciseCoverageAllowTriggeredUpdates[] =
     "preciseCoverageAllowTriggeredUpdates";
 static const char typeProfileStarted[] = "typeProfileStarted";
+static const char countersEnabled[] = "countersEnabled";
+static const char runtimeCallStatsEnabled[] = "runtimeCallStatsEnabled";
 }  // namespace ProfilerAgentState
 
 namespace {
@@ -220,14 +222,16 @@ void V8ProfilerAgentImpl::consoleProfileEnd(const String16& title) {
 }
 
 Response V8ProfilerAgentImpl::enable() {
-  if (m_enabled) return Response::Success();
+  if (!m_enabled) {
     m_enabled = true;
     m_state->setBoolean(ProfilerAgentState::profilerEnabled, true);
+  }
+
   return Response::Success();
 }
 
 Response V8ProfilerAgentImpl::disable() {
-  if (!m_enabled) return Response::Success();
+  if (m_enabled) {
     for (size_t i = m_startedProfiles.size(); i > 0; --i)
       stopProfiling(m_startedProfiles[i - 1].m_id, false);
     m_startedProfiles.clear();
@@ -236,6 +240,18 @@ Response V8ProfilerAgentImpl::disable() {
     DCHECK(!m_profiler);
     m_enabled = false;
     m_state->setBoolean(ProfilerAgentState::profilerEnabled, false);
+  }
+
+  if (m_counters) {
+    disableCounters();
+    m_state->setBoolean(ProfilerAgentState::countersEnabled, false);
+  }
+
+  if (m_runtime_call_stats_enabled) {
+    disableRuntimeCallStats();
+    m_state->setBoolean(ProfilerAgentState::runtimeCallStatsEnabled, false);
+  }
+
   return Response::Success();
 }
 
@@ -250,8 +266,7 @@ Response V8ProfilerAgentImpl::setSamplingInterval(int interval) {
 
 void V8ProfilerAgentImpl::restore() {
   DCHECK(!m_enabled);
-  if (!m_state->booleanProperty(ProfilerAgentState::profilerEnabled, false))
-    return;
+  if (m_state->booleanProperty(ProfilerAgentState::profilerEnabled, false)) {
     m_enabled = true;
     DCHECK(!m_profiler);
     if (m_state->booleanProperty(ProfilerAgentState::userInitiatedProfiling,
@@ -270,6 +285,16 @@ void V8ProfilerAgentImpl::restore() {
       startPreciseCoverage(Maybe<bool>(callCount), Maybe<bool>(detailed),
                            Maybe<bool>(updatesAllowed), &timestamp);
     }
+  }
+
+  if (m_state->booleanProperty(ProfilerAgentState::countersEnabled, false)) {
+    enableCounters();
+  }
+
+  if (m_state->booleanProperty(ProfilerAgentState::runtimeCallStatsEnabled,
+                               false)) {
+    enableRuntimeCallStats();
+  }
 }
 
 Response V8ProfilerAgentImpl::start() {
@@ -525,10 +550,9 @@ Response V8ProfilerAgentImpl::takeTypeProfile(
   return Response::Success();
 }
 
-Response V8ProfilerAgentImpl::enableRuntimeCallStats() {
+Response V8ProfilerAgentImpl::enableCounters() {
   if (m_counters)
-    return Response::ServerError(
-        "RuntimeCallStats collection already enabled.");
+    return Response::ServerError("Counters collection already enabled.");
 
   if (V8Inspector* inspector = v8::debug::GetInspector(m_isolate))
     m_counters = inspector->enableCounters();
@@ -538,16 +562,16 @@ Response V8ProfilerAgentImpl::enableRuntimeCallStats() {
   return Response::Success();
 }
 
-Response V8ProfilerAgentImpl::disableRuntimeCallStats() {
+Response V8ProfilerAgentImpl::disableCounters() {
   if (m_counters) m_counters.reset();
   return Response::Success();
 }
 
-Response V8ProfilerAgentImpl::getRuntimeCallStats(
+Response V8ProfilerAgentImpl::getCounters(
     std::unique_ptr<protocol::Array<protocol::Profiler::CounterInfo>>*
         out_result) {
   if (!m_counters)
-    return Response::ServerError("RuntimeCallStats collection is not enabled.");
+    return Response::ServerError("Counters collection is not enabled.");
 
   *out_result =
       std::make_unique<protocol::Array<protocol::Profiler::CounterInfo>>();
@@ -564,6 +588,66 @@ Response V8ProfilerAgentImpl::getRuntimeCallStats(
   return Response::Success();
 }
 
+Response V8ProfilerAgentImpl::enableRuntimeCallStats() {
+  if (v8::internal::TracingFlags::runtime_stats.load()) {
+    return Response::ServerError(
+        "Runtime Call Stats collection is already enabled.");
+  }
+
+  v8::internal::TracingFlags::runtime_stats.store(true);
+  m_runtime_call_stats_enabled = true;
+
+  return Response::Success();
+}
+
+Response V8ProfilerAgentImpl::disableRuntimeCallStats() {
+  if (!v8::internal::TracingFlags::runtime_stats.load()) {
+    return Response::ServerError(
+        "Runtime Call Stats collection is not enabled.");
+  }
+
+  if (!m_runtime_call_stats_enabled) {
+    return Response::ServerError(
+        "Runtime Call Stats collection was not enabled by this session.");
+  }
+
+  v8::internal::TracingFlags::runtime_stats.store(false);
+  m_runtime_call_stats_enabled = false;
+
+  return Response::Success();
+}
+
+Response V8ProfilerAgentImpl::getRuntimeCallStats(
+    std::unique_ptr<
+        protocol::Array<protocol::Profiler::RuntimeCallCounterInfo>>*
+        out_result) {
+  if (!m_runtime_call_stats_enabled) {
+    return Response::ServerError(
+        "Runtime Call Stats collection is not enabled.");
+  }
+
+  if (!v8::internal::TracingFlags::runtime_stats.load()) {
+    return Response::ServerError(
+        "Runtime Call Stats collection was disabled outside of this session.");
+  }
+
+  *out_result = std::make_unique<
+      protocol::Array<protocol::Profiler::RuntimeCallCounterInfo>>();
+
+  v8::debug::EnumerateRuntimeCallCounters(
+      m_isolate,
+      [&](const char* name, int64_t count, v8::base::TimeDelta time) {
+        (*out_result)
+            ->emplace_back(protocol::Profiler::RuntimeCallCounterInfo::create()
+                               .setName(String16(name))
+                               .setValue(static_cast<double>(count))
+                               .setTime(time.InSecondsF())
+                               .build());
+      });
+
+  return Response::Success();
+}
+
 String16 V8ProfilerAgentImpl::nextProfileId() {
   return String16::fromInteger(
       v8::base::Relaxed_AtomicIncrement(&s_lastProfileId, 1));

src/inspector/v8-profiler-agent-impl.h

@@ -57,10 +57,17 @@ class V8ProfilerAgentImpl : public protocol::Profiler::Backend {
       std::unique_ptr<protocol::Array<protocol::Profiler::ScriptTypeProfile>>*
           out_result) override;
 
+  Response enableCounters() override;
+  Response disableCounters() override;
+  Response getCounters(
+      std::unique_ptr<protocol::Array<protocol::Profiler::CounterInfo>>*
+          out_result) override;
+
   Response enableRuntimeCallStats() override;
   Response disableRuntimeCallStats() override;
   Response getRuntimeCallStats(
-      std::unique_ptr<protocol::Array<protocol::Profiler::CounterInfo>>*
+      std::unique_ptr<
+          protocol::Array<protocol::Profiler::RuntimeCallCounterInfo>>*
           out_result) override;
 
   void consoleProfile(const String16& title);
@@ -87,6 +94,7 @@ class V8ProfilerAgentImpl : public protocol::Profiler::Backend {
   String16 m_frontendInitiatedProfileId;
   int m_startedProfilesCount = 0;
   std::shared_ptr<V8Inspector::Counters> m_counters;
+  bool m_runtime_call_stats_enabled = false;
 
   DISALLOW_COPY_AND_ASSIGN(V8ProfilerAgentImpl);
 };

src/logging/counters.cc

@@ -557,6 +557,17 @@ void RuntimeCallStats::Print(std::ostream& os) {
   entries.Print(os);
 }
 
+void RuntimeCallStats::EnumerateCounters(
+    debug::RuntimeCallCounterCallback callback) {
+  if (current_timer_.Value() != nullptr) {
+    current_timer_.Value()->Snapshot();
+  }
+  for (int i = 0; i < kNumberOfCounters; i++) {
+    RuntimeCallCounter* counter = GetCounter(i);
+    callback(counter->name(), counter->count(), counter->time());
+  }
+}
+
 void RuntimeCallStats::Reset() {
   if (V8_LIKELY(!TracingFlags::is_runtime_stats_enabled())) return;
 

src/logging/counters.h

@@ -13,6 +13,7 @@
 #include "src/base/platform/elapsed-timer.h"
 #include "src/base/platform/time.h"
 #include "src/common/globals.h"
+#include "src/debug/debug-interface.h"
 #include "src/execution/isolate.h"
 #include "src/init/heap-symbols.h"
 #include "src/logging/counters-definitions.h"
@@ -1146,6 +1147,9 @@ class RuntimeCallStats final {
   V8_EXPORT_PRIVATE void Print();
   V8_NOINLINE void Dump(v8::tracing::TracedValue* value);
 
+  V8_EXPORT_PRIVATE void EnumerateCounters(
+      debug::RuntimeCallCounterCallback callback);
+
   ThreadId thread_id() const { return thread_id_; }
   RuntimeCallTimer* current_timer() { return current_timer_.Value(); }
   RuntimeCallCounter* current_counter() { return current_counter_.Value(); }

test/inspector/BUILD.gn

@@ -32,6 +32,7 @@ v8_executable("inspector-test") {
 
   data = [
     "console/",
+    "counters/",
     "cpu-profiler/",
     "debugger/",
     "heap-profiler/",

test/inspector/counters/collection-expected.txt

@@ -0,0 +1,2 @@
+Test Counters collection using Profiler.getCounters.
+PASSED

test/inspector/counters/collection.js

@@ -0,0 +1,83 @@
+// Copyright 2020 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.
+
+let {session, contextGroup, Protocol} = InspectorTest.start(
+    'Test Counters collection using Profiler.getCounters.');
+
+var source =
+`
+function fib(x) {
+  if (x < 2) return 1;
+  return fib(x-1) + fib(x-2);
+}
+fib(5);
+`;
+
+function buildCounterMap(result) {
+  let counterMap = new Map();
+
+  let counters = result.result.result;
+  for (const {name, value} of counters) {
+    counterMap.set(name, value);
+  }
+
+  return counterMap;
+}
+
+function compareCounterMaps(counterMap, counterMap2) {
+  // Check for counters that are present in the first map but are not found
+  // in the the second map
+  for (let counter of counterMap.keys()) {
+    if (!counterMap2.has(counter)) {
+      InspectorTest.log(`Counter ${counter} is missing`);
+      return false;
+    }
+  }
+
+  // Check for the counter value changes
+  let counterValueIncreased = false;
+  for (let [counter, value2] of counterMap2) {
+    let value = counterMap.get(counter);
+    if (value !== undefined) {
+      if (value2 < value) {
+        InspectorTest.log(`Counter ${counter} value decreased: ${value} -> ${value2}`);
+        return false;
+      }
+      if (value2 > value) {
+        counterValueIncreased = true;
+      }
+    }
+  }
+
+  if (!counterValueIncreased && counterMap.size === counterMap2.size) {
+    InspectorTest.log(`No counter values has increased or added`);
+    return false;
+  }
+
+  return true;
+}
+
+(async function test() {
+  await Protocol.Runtime.enable();
+  await Protocol.Profiler.enableCounters();
+
+  let counterMap = buildCounterMap(await Protocol.Profiler.getCounters());
+
+  await Protocol.Runtime.evaluate({ expression: source, sourceURL: arguments.callee.name, persistScript: true });
+
+  let counterMap2 = buildCounterMap(await Protocol.Profiler.getCounters());
+  const check1 = compareCounterMaps(counterMap, counterMap2);
+
+  await Protocol.Runtime.evaluate({ expression: source, sourceURL: arguments.callee.name, persistScript: true });
+
+  let counterMap3 = buildCounterMap(await Protocol.Profiler.getCounters());
+  const check2 = compareCounterMaps(counterMap2, counterMap3);
+
+  await Protocol.Profiler.disableCounters();
+  await Protocol.Runtime.disable();
+
+  InspectorTest.log(check1 && check2 ? 'PASSED' : 'FAILED');
+
+  InspectorTest.completeTest();
+})().catch(e => InspectorTest.log('caught: ' + e));

test/inspector/counters/enable-disable-expected.txt

@@ -0,0 +1,6 @@
+Test Counters collection enabling and disabling.
+Expected error: "Counters collection is not enabled."
+Expected error: "Counters collection already enabled."
+Some counters reported
+Expected error: "Counters collection is not enabled."
+Less counters reported

test/inspector/counters/enable-disable.js

@@ -0,0 +1,51 @@
+// Copyright 2020 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.
+
+let {session, contextGroup, Protocol} = InspectorTest.start(
+    'Test Counters collection enabling and disabling.');
+
+var source =
+`
+function fib(x) {
+  if (x < 2) return 1;
+  return fib(x-1) + fib(x-2);
+}
+fib(5);
+`;
+
+function logErrorMessage(result) {
+  InspectorTest.log('Expected error: "' + result.error.message + '"');
+}
+
+(async function test() {
+  await Protocol.Runtime.enable();
+
+  // This should fail with "not enabled" error.
+  logErrorMessage(await Protocol.Profiler.getCounters());
+
+  // This should fail with "already enabled" error.
+  await Protocol.Profiler.enableCounters();
+  logErrorMessage(await Protocol.Profiler.enableCounters());
+
+  // The result should not be empty.
+  await Protocol.Runtime.evaluate({ expression: source, sourceURL: arguments.callee.name, persistScript: true });
+  const counters = (await Protocol.Profiler.getCounters()).result.result;
+  if (counters.length > 0)
+    InspectorTest.log('Some counters reported');
+  await Protocol.Profiler.disableCounters();
+
+  // This should fail with "not enabled" error too.
+  logErrorMessage(await Protocol.Profiler.getCounters());
+
+  // The result should not be empty and have smaller amount of counters than
+  // the first result.
+  await Protocol.Profiler.enableCounters();
+  const counters2 = (await Protocol.Profiler.getCounters()).result.result;
+  if (counters2.length > 0 && counters2.length < counters.length)
+    InspectorTest.log('Less counters reported');
+  await Protocol.Profiler.disableCounters();
+
+  await Protocol.Runtime.disable();
+  InspectorTest.completeTest();
+})().catch(e => InspectorTest.log('caught: ' + e));

test/inspector/runtime-call-stats/collection.js

@@ -1,4 +1,4 @@
-// Copyright 2019 the V8 project authors. All rights reserved.
+// Copyright 2020 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.
 

test/inspector/runtime-call-stats/enable-disable-expected.txt

@@ -1,6 +1,5 @@
-Test RunTimeCallStats collection enabling and disabling.
-Expected error: "RuntimeCallStats collection is not enabled."
-Expected error: "RuntimeCallStats collection already enabled."
+Test Runtime Call Stats collection enabling and disabling.
+Expected error: "Runtime Call Stats collection is not enabled."
+Expected error: "Runtime Call Stats collection is already enabled."
 Some counters reported
-Expected error: "RuntimeCallStats collection is not enabled."
-Less counters reported
+Expected error: "Runtime Call Stats collection is not enabled."

test/inspector/runtime-call-stats/enable-disable.js

@@ -1,51 +1,51 @@
-// Copyright 2019 the V8 project authors. All rights reserved.
+// Copyright 2020 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.
 
 let {session, contextGroup, Protocol} = InspectorTest.start(
-    'Test RunTimeCallStats collection enabling and disabling.');
+  'Test Runtime Call Stats collection enabling and disabling.');
 
 var source =
 `
 function fib(x) {
-  if (x < 2) return 1;
-  return fib(x-1) + fib(x-2);
+if (x < 2) return 1;
+return fib(x-1) + fib(x-2);
 }
 fib(5);
 `;
 
 function logErrorMessage(result) {
-  InspectorTest.log('Expected error: "' + result.error.message + '"');
+InspectorTest.log('Expected error: "' + result.error.message + '"');
 }
 
 (async function test() {
-  await Protocol.Runtime.enable();
+await Protocol.Runtime.enable();
 
-  // This should fail with "not enabled" error.
-  logErrorMessage(await Protocol.Profiler.getRuntimeCallStats());
+// This should fail with "not enabled" error.
+logErrorMessage(await Protocol.Profiler.getRuntimeCallStats());
 
-  // This should fail with "already enabled" error.
-  await Protocol.Profiler.enableRuntimeCallStats();
-  logErrorMessage(await Protocol.Profiler.enableRuntimeCallStats());
+// This should fail with "already enabled" error.
+await Protocol.Profiler.enableRuntimeCallStats();
+logErrorMessage(await Protocol.Profiler.enableRuntimeCallStats());
 
-  // The result should not be empty.
-  await Protocol.Runtime.evaluate({ expression: source, sourceURL: arguments.callee.name, persistScript: true });
-  const counters = (await Protocol.Profiler.getRuntimeCallStats()).result.result;
-  if (counters.length > 0)
+// The result should not be empty.
+await Protocol.Runtime.evaluate({ expression: source, sourceURL: arguments.callee.name, persistScript: true });
+const counters = (await Protocol.Profiler.getRuntimeCallStats()).result.result;
+if (counters.length > 0)
   InspectorTest.log('Some counters reported');
-  await Protocol.Profiler.disableRuntimeCallStats();
+await Protocol.Profiler.disableRuntimeCallStats();
 
-  // This should fail with "not enabled" error too.
-  logErrorMessage(await Protocol.Profiler.getRuntimeCallStats());
+// This should fail with "not enabled" error too.
+logErrorMessage(await Protocol.Profiler.getRuntimeCallStats());
 
-  // The result should not be empty and have smaller amount of counters than
-  // the first result.
-  await Protocol.Profiler.enableRuntimeCallStats();
-  const counters2 = (await Protocol.Profiler.getRuntimeCallStats()).result.result;
-  if (counters2.length > 0 && counters2.length < counters.length)
+// The result should not be empty and have smaller amount of counters than
+// the first result.
+await Protocol.Profiler.enableRuntimeCallStats();
+const counters2 = (await Protocol.Profiler.getRuntimeCallStats()).result.result;
+if (counters2.length > 0 && counters2.length < counters.length)
   InspectorTest.log('Less counters reported');
-  await Protocol.Profiler.disableRuntimeCallStats();
+await Protocol.Profiler.disableRuntimeCallStats();
 
-  await Protocol.Runtime.disable();
-  InspectorTest.completeTest();
+await Protocol.Runtime.disable();
+InspectorTest.completeTest();
 })().catch(e => InspectorTest.log('caught: ' + e));