v8: implement v8.takeCoverage()

Add an v8.takeCoverage() API that allows the user to write the
coverage started by NODE_V8_COVERAGE to disk on demand.
The coverage can be written multiple times during the lifetime
of the process, each time the execution counter will be reset.
When the process is about to exit, one last coverage will
still be written to disk.

Also refactors the internal profiler connection code
so that we use the inspector response id to identify
the profile response instead of using an ad-hoc flag in C++.

PR-URL: #33807
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: Jiawen Geng <technicalcute@gmail.com>
Reviewed-By: Ben Coe <bencoe@gmail.com>

Author: joyeecheung

doc/api/v8.md

@@ -223,6 +223,21 @@ v8.setFlagsFromString('--trace_gc');
 setTimeout(() => { v8.setFlagsFromString('--notrace_gc'); }, 60e3);
 ```
 
+## `v8.takeCoverage()`
+
+<!-- YAML
+added: REPLACEME
+-->
+
+The `v8.takeCoverage()` method allows the user to write the coverage started by
+[`NODE_V8_COVERAGE`][] to disk on demand. This method can be invoked multiple
+times during the lifetime of the process, each time the execution counter will
+be reset and a new coverage report will be written to the directory specified
+by [`NODE_V8_COVERAGE`][].
+
+When the process is about to exit, one last coverage will still be written to
+disk.
+
 ## `v8.writeHeapSnapshot([filename])`
 <!-- YAML
 added: v11.13.0
@@ -520,6 +535,7 @@ A subclass of [`Deserializer`][] corresponding to the format written by
 [`Deserializer`]: #v8_class_v8_deserializer
 [`Error`]: errors.md#errors_class_error
 [`GetHeapSpaceStatistics`]: https://v8docs.nodesource.com/node-13.2/d5/dda/classv8_1_1_isolate.html#ac673576f24fdc7a33378f8f57e1d13a4
+[`NODE_V8_COVERAGE`]: cli.html#cli_node_v8_coverage_dir
 [`Serializer`]: #v8_class_v8_serializer
 [`deserializer._readHostObject()`]: #v8_deserializer_readhostobject
 [`deserializer.transferArrayBuffer()`]: #v8_deserializer_transferarraybuffer_id_arraybuffer

lib/v8.js

@@ -40,6 +40,12 @@ const {
   Serializer,
   Deserializer
 } = internalBinding('serdes');
+
+let profiler = {};
+if (internalBinding('config').hasInspector) {
+  profiler = internalBinding('profiler');
+}
+
 const assert = require('internal/assert');
 const { copy } = internalBinding('buffer');
 const { inspect } = require('internal/util/inspect');
@@ -272,6 +278,7 @@ module.exports = {
   DefaultSerializer,
   DefaultDeserializer,
   deserialize,
+  takeCoverage: profiler.takeCoverage,
   serialize,
   writeHeapSnapshot,
 };

src/inspector_profiler.cc

@@ -9,6 +9,7 @@
 #include "util-inl.h"
 #include "v8-inspector.h"
 
+#include <cinttypes>
 #include <sstream>
 
 namespace node {
@@ -36,10 +37,11 @@ V8ProfilerConnection::V8ProfilerConnection(Environment* env)
           false)),
       env_(env) {}
 
-size_t V8ProfilerConnection::DispatchMessage(const char* method,
-                                             const char* params) {
+uint32_t V8ProfilerConnection::DispatchMessage(const char* method,
+                                               const char* params,
+                                               bool is_profile_request) {
   std::stringstream ss;
-  size_t id = next_id();
+  uint32_t id = next_id();
   ss << R"({ "id": )" << id;
   DCHECK(method != nullptr);
   ss << R"(, "method": ")" << method << '"';
@@ -50,12 +52,15 @@ size_t V8ProfilerConnection::DispatchMessage(const char* method,
   std::string message = ss.str();
   const uint8_t* message_data =
       reinterpret_cast<const uint8_t*>(message.c_str());
+  // Save the id of the profile request to identify its response.
+  if (is_profile_request) {
+    profile_ids_.insert(id);
+  }
   Debug(env(),
         DebugCategory::INSPECTOR_PROFILER,
         "Dispatching message %s\n",
         message.c_str());
   session_->Dispatch(StringView(message_data, message.length()));
-  // TODO(joyeecheung): use this to identify the ending message.
   return id;
 }
 
@@ -77,33 +82,73 @@ void V8ProfilerConnection::V8ProfilerSessionDelegate::SendMessageToFrontend(
   Environment* env = connection_->env();
   Isolate* isolate = env->isolate();
   HandleScope handle_scope(isolate);
-  Context::Scope context_scope(env->context());
+  Local<Context> context = env->context();
+  Context::Scope context_scope(context);
 
-  // TODO(joyeecheung): always parse the message so that we can use the id to
-  // identify ending messages as well as printing the message in the debug
-  // output when there is an error.
   const char* type = connection_->type();
-  Debug(env,
-        DebugCategory::INSPECTOR_PROFILER,
-        "Receive %s profile message, ending = %s\n",
-        type,
-        connection_->ending() ? "true" : "false");
-  if (!connection_->ending()) {
-    return;
-  }
-
   // Convert StringView to a Local<String>.
   Local<String> message_str;
   if (!String::NewFromTwoByte(isolate,
                               message.characters16(),
                               NewStringType::kNormal,
                               message.length())
            .ToLocal(&message_str)) {
-    fprintf(stderr, "Failed to convert %s profile message\n", type);
+    fprintf(
+        stderr, "Failed to convert %s profile message to V8 string\n", type);
+    return;
+  }
+
+  Debug(env,
+        DebugCategory::INSPECTOR_PROFILER,
+        "Receive %s profile message\n",
+        type);
+
+  Local<Value> parsed;
+  if (!v8::JSON::Parse(context, message_str).ToLocal(&parsed) ||
+      !parsed->IsObject()) {
+    fprintf(stderr, "Failed to parse %s profile result as JSON object\n", type);
     return;
   }
 
-  connection_->WriteProfile(message_str);
+  Local<Object> response = parsed.As<Object>();
+  Local<Value> id_v;
+  if (!response->Get(context, FIXED_ONE_BYTE_STRING(isolate, "id"))
+           .ToLocal(&id_v) ||
+      !id_v->IsUint32()) {
+    Utf8Value str(isolate, message_str);
+    fprintf(
+        stderr, "Cannot retrieve id from the response message:\n%s\n", *str);
+    return;
+  }
+  uint32_t id = id_v.As<v8::Uint32>()->Value();
+
+  if (!connection_->HasProfileId(id)) {
+    Utf8Value str(isolate, message_str);
+    Debug(env, DebugCategory::INSPECTOR_PROFILER, "%s\n", *str);
+    return;
+  } else {
+    Debug(env,
+          DebugCategory::INSPECTOR_PROFILER,
+          "Writing profile response (id = %" PRIu64 ")\n",
+          static_cast<uint64_t>(id));
+  }
+
+  // Get message.result from the response.
+  Local<Value> result_v;
+  if (!response->Get(context, FIXED_ONE_BYTE_STRING(isolate, "result"))
+           .ToLocal(&result_v)) {
+    fprintf(stderr, "Failed to get 'result' from %s profile response\n", type);
+    return;
+  }
+
+  if (!result_v->IsObject()) {
+    fprintf(
+        stderr, "'result' from %s profile response is not an object\n", type);
+    return;
+  }
+
+  connection_->WriteProfile(result_v.As<Object>());
+  connection_->RemoveProfileId(id);
 }
 
 static bool EnsureDirectory(const std::string& directory, const char* type) {
@@ -138,45 +183,9 @@ std::string V8CoverageConnection::GetFilename() const {
   return filename;
 }
 
-static MaybeLocal<Object> ParseProfile(Environment* env,
-                                       Local<String> message,
-                                       const char* type) {
-  Local<Context> context = env->context();
-  Isolate* isolate = env->isolate();
-
-  // Get message.result from the response
-  Local<Value> parsed;
-  if (!v8::JSON::Parse(context, message).ToLocal(&parsed) ||
-      !parsed->IsObject()) {
-    fprintf(stderr, "Failed to parse %s profile result as JSON object\n", type);
-    return MaybeLocal<Object>();
-  }
-
-  Local<Value> result_v;
-  if (!parsed.As<Object>()
-           ->Get(context, FIXED_ONE_BYTE_STRING(isolate, "result"))
-           .ToLocal(&result_v)) {
-    fprintf(stderr, "Failed to get 'result' from %s profile message\n", type);
-    return MaybeLocal<Object>();
-  }
-
-  if (!result_v->IsObject()) {
-    fprintf(
-        stderr, "'result' from %s profile message is not an object\n", type);
-    return MaybeLocal<Object>();
-  }
-
-  return result_v.As<Object>();
-}
-
-void V8ProfilerConnection::WriteProfile(Local<String> message) {
+void V8ProfilerConnection::WriteProfile(Local<Object> result) {
   Local<Context> context = env_->context();
 
-  // Get message.result from the response.
-  Local<Object> result;
-  if (!ParseProfile(env_, message, type()).ToLocal(&result)) {
-    return;
-  }
   // Generate the profile output from the subclass.
   Local<Object> profile;
   if (!GetProfile(result).ToLocal(&profile)) {
@@ -203,7 +212,7 @@ void V8ProfilerConnection::WriteProfile(Local<String> message) {
   WriteResult(env_, path.c_str(), result_s);
 }
 
-void V8CoverageConnection::WriteProfile(Local<String> message) {
+void V8CoverageConnection::WriteProfile(Local<Object> result) {
   Isolate* isolate = env_->isolate();
   Local<Context> context = env_->context();
   HandleScope handle_scope(isolate);
@@ -219,11 +228,6 @@ void V8CoverageConnection::WriteProfile(Local<String> message) {
     return;
   }
 
-  // Get message.result from the response.
-  Local<Object> result;
-  if (!ParseProfile(env_, message, type()).ToLocal(&result)) {
-    return;
-  }
   // Generate the profile output from the subclass.
   Local<Object> profile;
   if (!GetProfile(result).ToLocal(&profile)) {
@@ -287,10 +291,19 @@ void V8CoverageConnection::Start() {
                   R"({ "callCount": true, "detailed": true })");
 }
 
+void V8CoverageConnection::TakeCoverage() {
+  DispatchMessage("Profiler.takePreciseCoverage", nullptr, true);
+}
+
 void V8CoverageConnection::End() {
-  CHECK_EQ(ending_, false);
+  Debug(env_,
+      DebugCategory::INSPECTOR_PROFILER,
+      "V8CoverageConnection::End(), ending = %d\n", ending_);
+  if (ending_) {
+    return;
+  }
   ending_ = true;
-  DispatchMessage("Profiler.takePreciseCoverage");
+  TakeCoverage();
 }
 
 std::string V8CpuProfilerConnection::GetDirectory() const {
@@ -327,9 +340,14 @@ void V8CpuProfilerConnection::Start() {
 }
 
 void V8CpuProfilerConnection::End() {
-  CHECK_EQ(ending_, false);
+  Debug(env_,
+      DebugCategory::INSPECTOR_PROFILER,
+      "V8CpuProfilerConnection::End(), ending = %d\n", ending_);
+  if (ending_) {
+    return;
+  }
   ending_ = true;
-  DispatchMessage("Profiler.stop");
+  DispatchMessage("Profiler.stop", nullptr, true);
 }
 
 std::string V8HeapProfilerConnection::GetDirectory() const {
@@ -365,31 +383,33 @@ void V8HeapProfilerConnection::Start() {
 }
 
 void V8HeapProfilerConnection::End() {
-  CHECK_EQ(ending_, false);
+  Debug(env_,
+      DebugCategory::INSPECTOR_PROFILER,
+      "V8HeapProfilerConnection::End(), ending = %d\n", ending_);
+  if (ending_) {
+    return;
+  }
   ending_ = true;
-  DispatchMessage("HeapProfiler.stopSampling");
+  DispatchMessage("HeapProfiler.stopSampling", nullptr, true);
 }
 
 // For now, we only support coverage profiling, but we may add more
 // in the future.
 static void EndStartedProfilers(Environment* env) {
+  // TODO(joyeechueng): merge these connections and use one session per env.
   Debug(env, DebugCategory::INSPECTOR_PROFILER, "EndStartedProfilers\n");
   V8ProfilerConnection* connection = env->cpu_profiler_connection();
-  if (connection != nullptr && !connection->ending()) {
-    Debug(env, DebugCategory::INSPECTOR_PROFILER, "Ending cpu profiling\n");
+  if (connection != nullptr) {
     connection->End();
   }
 
   connection = env->heap_profiler_connection();
-  if (connection != nullptr && !connection->ending()) {
-    Debug(env, DebugCategory::INSPECTOR_PROFILER, "Ending heap profiling\n");
+  if (connection != nullptr) {
     connection->End();
   }
 
   connection = env->coverage_connection();
-  if (connection != nullptr && !connection->ending()) {
-    Debug(
-        env, DebugCategory::INSPECTOR_PROFILER, "Ending coverage collection\n");
+  if (connection != nullptr) {
     connection->End();
   }
 }
@@ -469,13 +489,30 @@ static void SetSourceMapCacheGetter(const FunctionCallbackInfo<Value>& args) {
   env->set_source_map_cache_getter(args[0].As<Function>());
 }
 
+static void TakeCoverage(const FunctionCallbackInfo<Value>& args) {
+  Environment* env = Environment::GetCurrent(args);
+  V8CoverageConnection* connection = env->coverage_connection();
+
+  Debug(
+    env,
+    DebugCategory::INSPECTOR_PROFILER,
+    "TakeCoverage, connection %s nullptr\n",
+    connection == nullptr ? "==" : "!=");
+
+  if (connection != nullptr) {
+    Debug(env, DebugCategory::INSPECTOR_PROFILER, "taking coverage\n");
+    connection->TakeCoverage();
+  }
+}
+
 static void Initialize(Local<Object> target,
                        Local<Value> unused,
                        Local<Context> context,
                        void* priv) {
   Environment* env = Environment::GetCurrent(context);
   env->SetMethod(target, "setCoverageDirectory", SetCoverageDirectory);
   env->SetMethod(target, "setSourceMapCacheGetter", SetSourceMapCacheGetter);
+  env->SetMethod(target, "takeCoverage", TakeCoverage);
 }
 
 }  // namespace profiler

src/inspector_profiler.h

@@ -7,6 +7,7 @@
 #error("This header can only be used when inspector is enabled")
 #endif
 
+#include <unordered_set>
 #include "inspector_agent.h"
 
 namespace node {
@@ -39,7 +40,9 @@ class V8ProfilerConnection {
   // The optional `params` should be formatted in JSON.
   // The strings should be in one byte characters - which is enough for
   // the commands we use here.
-  size_t DispatchMessage(const char* method, const char* params = nullptr);
+  uint32_t DispatchMessage(const char* method,
+                           const char* params = nullptr,
+                           bool is_profile_request = false);
 
   // Use DispatchMessage() to dispatch necessary inspector messages
   // to start and end the profiling.
@@ -58,12 +61,19 @@ class V8ProfilerConnection {
   // which will be then written as a JSON.
   virtual v8::MaybeLocal<v8::Object> GetProfile(
       v8::Local<v8::Object> result) = 0;
-  virtual void WriteProfile(v8::Local<v8::String> message);
+  virtual void WriteProfile(v8::Local<v8::Object> result);
+
+  bool HasProfileId(uint32_t id) const {
+    return profile_ids_.find(id) != profile_ids_.end();
+  }
+
+  void RemoveProfileId(uint32_t id) { profile_ids_.erase(id); }
 
  private:
-  size_t next_id() { return id_++; }
+  uint32_t next_id() { return id_++; }
   std::unique_ptr<inspector::InspectorSession> session_;
-  size_t id_ = 1;
+  uint32_t id_ = 1;
+  std::unordered_set<uint32_t> profile_ids_;
 
  protected:
   Environment* env_ = nullptr;
@@ -82,8 +92,9 @@ class V8CoverageConnection : public V8ProfilerConnection {
   std::string GetDirectory() const override;
   std::string GetFilename() const override;
   v8::MaybeLocal<v8::Object> GetProfile(v8::Local<v8::Object> result) override;
-  void WriteProfile(v8::Local<v8::String> message) override;
+  void WriteProfile(v8::Local<v8::Object> result) override;
   void WriteSourceMapCache();
+  void TakeCoverage();
 
  private:
   std::unique_ptr<inspector::InspectorSession> session_;

test/fixtures/v8-coverage/interval.js

@@ -0,0 +1,14 @@
+'use strict';
+let counter = 0;
+let result;
+const TEST_INTERVALS = parseInt(process.env.TEST_INTERVALS) || 1;
+
+const i = setInterval(function interval() {
+  counter++;
+  if (counter < TEST_INTERVALS) {
+    result = 1;
+  } else {
+    result = process.hrtime();
+    clearInterval(i);
+  }
+}, 100);

test/fixtures/v8-coverage/take-coverage.js

@@ -0,0 +1,10 @@
+'use strict';
+const v8 = require('v8');
+
+setTimeout(() => {
+  v8.takeCoverage();
+}, 1000);
+
+setTimeout(() => {
+  v8.takeCoverage();
+}, 2000);

test/parallel/test-v8-take-coverage-noop.js

@@ -0,0 +1,32 @@
+'use strict';
+
+if (!process.features.inspector) return;
+
+require('../common');
+const fixtures = require('../common/fixtures');
+const tmpdir = require('../common/tmpdir');
+const assert = require('assert');
+const fs = require('fs');
+const { spawnSync } = require('child_process');
+
+tmpdir.refresh();
+
+// v8.takeCoverage() should be a noop if NODE_V8_COVERAGE is not set.
+const intervals = 40;
+{
+  const output = spawnSync(process.execPath, [
+    '-r',
+    fixtures.path('v8-coverage', 'take-coverage'),
+    fixtures.path('v8-coverage', 'interval'),
+  ], {
+    env: {
+      ...process.env,
+      NODE_DEBUG_NATIVE: 'INSPECTOR_PROFILER',
+      TEST_INTERVALS: intervals
+    },
+  });
+  console.log(output.stderr.toString());
+  assert.strictEqual(output.status, 0);
+  const coverageFiles = fs.readdirSync(tmpdir.path);
+  assert.strictEqual(coverageFiles.length, 0);
+}

test/parallel/test-v8-take-coverage.js

@@ -0,0 +1,85 @@
+'use strict';
+
+if (!process.features.inspector) return;
+
+require('../common');
+const fixtures = require('../common/fixtures');
+const tmpdir = require('../common/tmpdir');
+const assert = require('assert');
+const fs = require('fs');
+const path = require('path');
+const { spawnSync } = require('child_process');
+
+tmpdir.refresh();
+const intervals = 40;
+// Outputs coverage when v8.takeCoverage() is invoked.
+{
+  const output = spawnSync(process.execPath, [
+    '-r',
+    fixtures.path('v8-coverage', 'take-coverage'),
+    fixtures.path('v8-coverage', 'interval'),
+  ], {
+    env: {
+      ...process.env,
+      NODE_V8_COVERAGE: tmpdir.path,
+      NODE_DEBUG_NATIVE: 'INSPECTOR_PROFILER',
+      TEST_INTERVALS: intervals
+    },
+  });
+  console.log(output.stderr.toString());
+  assert.strictEqual(output.status, 0);
+  const coverageFiles = fs.readdirSync(tmpdir.path);
+
+  let coverages = [];
+  for (const coverageFile of coverageFiles) {
+    const coverage = require(path.join(tmpdir.path, coverageFile));
+    for (const result of coverage.result) {
+      if (result.url.includes('/interval')) {
+        coverages.push({
+          file: coverageFile,
+          func: result.functions.find((f) => f.functionName === 'interval'),
+          timestamp: coverage.timestamp
+        });
+      }
+    }
+  }
+
+  coverages = coverages.sort((a, b) => { return a.timestamp - b.timestamp; });
+  // There should be two coverages taken, one triggered by v8.takeCoverage(),
+  // the other by process exit.
+  console.log('Coverages:', coverages);
+  assert.strictEqual(coverages.length, 3);
+
+  let blockHitsTotal = 0;
+  for (let i = 0; i < coverages.length; ++i) {
+    const { ranges } = coverages[i].func;
+    console.log('coverage', i, ranges);
+
+    if (i !== coverages.length - 1) {
+      // When the first two coverages are taken:
+      assert.strictEqual(ranges.length, 2);
+      const blockHits = ranges[0].count;
+      // The block inside interval() should be hit at least once.
+      assert.notStrictEqual(blockHits, 0);
+      blockHitsTotal += blockHits;
+      // The else branch should not be hit.
+      const elseBranchHits = ranges[1].count;
+      assert.strictEqual(elseBranchHits, 0);
+    } else {
+      // At process exit:
+      assert.strictEqual(ranges.length, 3);
+      const blockHits = ranges[0].count;
+      // The block inside interval() should be hit at least once more.
+      assert.notStrictEqual(blockHits, 0);
+      blockHitsTotal += blockHits;
+      // The else branch should be hit exactly once.
+      const elseBranchHits = ranges[2].count;
+      assert.strictEqual(elseBranchHits, 1);
+      const ifBranchHits = ranges[1].count;
+      assert.strictEqual(ifBranchHits, blockHits - elseBranchHits);
+    }
+  }
+
+  // The block should be hit `intervals` times in total.
+  assert.strictEqual(blockHitsTotal, intervals);
+}