src,test: ensure that V8 fast APIs are called

Adds a debug-only macro that can be used to track when a V8 fast API is
called. A map of counters is maintained in in thread-local storage and
an internal API can be called to get the total count associated with
a call id.
Specific tests are added and `crypto.timingSafeEqual` as well as
internal documentation are updated to show how to use the macro
and test fast API calls without running long loops.

Author: targos

doc/contributing/adding-v8-fast-api.md

@@ -29,6 +29,12 @@ for example, they may not trigger garbage collection.
 * To test fast APIs, make sure to run the tests in a loop with a decent
   iterations count to trigger relevant optimizations that prefer the fast API
   over the slow one.
+* In debug mode (`--debug` or `--debug-node` flags), the fast API calls can be
+  tracked using the `TRACK_V8_FAST_API_CALL("key")` macro. This can be used to
+  count how many times fast paths are taken during tests. The key is a global
+  identifier and should be unique across the codebase.
+  Use `"binding_name.function_name"` or `"binding_name.function_name.suffix"` to
+  ensure uniqueness.
 * The fast callback must be idempotent up to the point where error and fallback
   conditions are checked, because otherwise executing the slow callback might
   produce visible side effects twice.
@@ -77,6 +83,7 @@ A typical function that communicates between JavaScript and C++ is as follows.
 * On the C++ side:
 
   ```cpp
+  #include "node_debug.h"
   #include "v8-fast-api-calls.h"
 
   namespace node {
@@ -102,9 +109,11 @@ A typical function that communicates between JavaScript and C++ is as follows.
                            const int32_t b,
                            v8::FastApiCallbackOptions& options) {
     if (b == 0) {
+      TRACK_V8_FAST_API_CALL("custom_namespace.divide.error");
       options.fallback = true;
       return 0;
     } else {
+      TRACK_V8_FAST_API_CALL("custom_namespace.divide.ok");
       return a / b;
     }
   }
@@ -148,3 +157,42 @@ A typical function that communicates between JavaScript and C++ is as follows.
                                                       const int32_t b,
                                                       v8::FastApiCallbackOptions& options);
   ```
+
+* In the unit tests:
+
+  Since the fast API function uses `TRACK_V8_FAST_API_CALL`, we can ensure that
+  the fast paths are taken and test them by writing tests that force
+  V8 optimizations and check the counters.
+
+  ```js
+  // Flags: --expose-internals --no-warnings --allow-natives-syntax
+  'use strict';
+  const common = require('../common');
+
+  const { internalBinding } = require('internal/test/binding');
+  // We could also require a function that uses the internal binding internally.
+  const { divide } = internalBinding('custom_namespace');
+
+  if (common.isDebug) {
+    const { getV8FastApiCallCount } = internalBinding('debug');
+
+    // The function that will be optimized. It has to be a function written in
+    // JavaScript. Since `divide` comes from the C++ side, we need to wrap it.
+    function testFastPath(a, b) {
+      return divide(a, b);
+    }
+
+    eval('%PrepareFunctionForOptimization(testFastPath)');
+    // This call will let V8 know about the argument types that the function expects.
+    assert.strictEqual(testFastPath(6, 3), 2);
+
+    eval('%OptimizeFunctionOnNextCall(testFastPath)');
+    assert.strictEqual(testFastPath(8, 2), 4);
+    assert.throws(() => testFastPath(1, 0), {
+      code: 'ERR_INVALID_STATE',
+    });
+
+    assert.strictEqual(getV8FastApiCallCount('custom_namespace.divide.ok'), 1);
+    assert.strictEqual(getV8FastApiCallCount('custom_namespace.divide.error'), 1);
+  }
+  ```

node.gyp

@@ -107,6 +107,7 @@
       'src/node_constants.cc',
       'src/node_contextify.cc',
       'src/node_credentials.cc',
+      'src/node_debug.cc',
       'src/node_dir.cc',
       'src/node_dotenv.cc',
       'src/node_env_var.cc',
@@ -229,6 +230,7 @@
       'src/node_constants.h',
       'src/node_context_data.h',
       'src/node_contextify.h',
+      'src/node_debug.h',
       'src/node_dir.h',
       'src/node_dotenv.h',
       'src/node_errors.h',

src/crypto/crypto_timing.cc

@@ -1,9 +1,10 @@
 #include "crypto/crypto_timing.h"
 #include "crypto/crypto_util.h"
 #include "env-inl.h"
+#include "node.h"
+#include "node_debug.h"
 #include "node_errors.h"
 #include "v8.h"
-#include "node.h"
 
 #include <openssl/crypto.h>
 
@@ -57,10 +58,12 @@ bool FastTimingSafeEqual(Local<Value> receiver,
   uint8_t* data_b;
   if (a.length() != b.length() || !a.getStorageIfAligned(&data_a) ||
       !b.getStorageIfAligned(&data_b)) {
+    TRACK_V8_FAST_API_CALL("crypto.timingSafeEqual.error");
     options.fallback = true;
     return false;
   }
 
+  TRACK_V8_FAST_API_CALL("crypto.timingSafeEqual.ok");
   return CRYPTO_memcmp(data_a, data_b, a.length()) == 0;
 }
 

src/node_binding.cc

@@ -20,6 +20,12 @@
 #define NODE_BUILTIN_PROFILER_BINDINGS(V)
 #endif
 
+#ifdef DEBUG
+#define NODE_BUILTIN_DEBUG_BINDINGS(V) V(debug)
+#else
+#define NODE_BUILTIN_DEBUG_BINDINGS(V)
+#endif
+
 // A list of built-in bindings. In order to do binding registration
 // in node::Init(), need to add built-in bindings in the following list.
 // Then in binding::RegisterBuiltinBindings(), it calls bindings' registration
@@ -96,6 +102,7 @@
   NODE_BUILTIN_OPENSSL_BINDINGS(V)                                             \
   NODE_BUILTIN_ICU_BINDINGS(V)                                                 \
   NODE_BUILTIN_PROFILER_BINDINGS(V)                                            \
+  NODE_BUILTIN_DEBUG_BINDINGS(V)                                               \
   NODE_BUILTIN_QUIC_BINDINGS(V)
 
 // This is used to load built-in bindings. Instead of using

src/node_debug.cc

@@ -0,0 +1,103 @@
+#include "node_debug.h"
+
+#ifdef DEBUG
+#include "node_binding.h"
+
+#include "env-inl.h"
+#include "util.h"
+#include "v8-fast-api-calls.h"
+#include "v8.h"
+
+#include <string_view>
+#include <unordered_map>
+#endif  // DEBUG
+
+namespace node {
+namespace debug {
+
+#ifdef DEBUG
+using v8::Context;
+using v8::FastApiCallbackOptions;
+using v8::FunctionCallbackInfo;
+using v8::Local;
+using v8::Number;
+using v8::Object;
+using v8::String;
+using v8::Value;
+
+thread_local std::unordered_map<std::string_view, int> v8_fast_api_call_counts;
+
+void TrackV8FastApiCall(std::string_view key) {
+  v8_fast_api_call_counts[key]++;
+}
+
+int GetV8FastApiCallCount(std::string_view key) {
+  return v8_fast_api_call_counts[key];
+}
+
+void GetV8FastApiCallCount(const FunctionCallbackInfo<Value>& args) {
+  Environment* env = Environment::GetCurrent(args);
+  if (!args[0]->IsString()) {
+    env->ThrowError("getV8FastApiCallCount must be called with a string");
+    return;
+  }
+  Local<String> key = args[0].As<String>();
+  Utf8Value utf8_key(env->isolate(), key);
+  args.GetReturnValue().Set(GetV8FastApiCallCount(utf8_key.ToString()));
+}
+
+void SlowIsEven(const FunctionCallbackInfo<Value>& args) {
+  Environment* env = Environment::GetCurrent(args);
+  if (!args[0]->IsNumber()) {
+    env->ThrowError("isEven must be called with a number");
+    return;
+  }
+  int64_t value = args[0].As<Number>()->Value();
+  args.GetReturnValue().Set(value % 2 == 0);
+}
+
+bool FastIsEven(Local<Value> receiver,
+                const int64_t value,
+                // NOLINTNEXTLINE(runtime/references)
+                FastApiCallbackOptions& options) {
+  TRACK_V8_FAST_API_CALL("debug.isEven");
+  return value % 2 == 0;
+}
+
+void SlowIsOdd(const FunctionCallbackInfo<Value>& args) {
+  Environment* env = Environment::GetCurrent(args);
+  if (!args[0]->IsNumber()) {
+    env->ThrowError("isOdd must be called with a number");
+    return;
+  }
+  int64_t value = args[0].As<Number>()->Value();
+  args.GetReturnValue().Set(value % 2 != 0);
+}
+
+bool FastIsOdd(Local<Value> receiver,
+               const int64_t value,
+               // NOLINTNEXTLINE(runtime/references)
+               FastApiCallbackOptions& options) {
+  TRACK_V8_FAST_API_CALL("debug.isOdd");
+  return value % 2 != 0;
+}
+
+static v8::CFunction fast_is_even(v8::CFunction::Make(FastIsEven));
+static v8::CFunction fast_is_odd(v8::CFunction::Make(FastIsOdd));
+
+void Initialize(Local<Object> target,
+                Local<Value> unused,
+                Local<Context> context,
+                void* priv) {
+  SetMethod(context, target, "getV8FastApiCallCount", GetV8FastApiCallCount);
+  SetFastMethod(context, target, "isEven", SlowIsEven, &fast_is_even);
+  SetFastMethod(context, target, "isOdd", SlowIsOdd, &fast_is_odd);
+}
+#endif  // DEBUG
+
+}  // namespace debug
+}  // namespace node
+
+#ifdef DEBUG
+NODE_BINDING_CONTEXT_AWARE_INTERNAL(debug, node::debug::Initialize)
+#endif  // DEBUG

src/node_debug.h

@@ -0,0 +1,24 @@
+#pragma once
+
+#if defined(NODE_WANT_INTERNALS) && NODE_WANT_INTERNALS
+
+#ifdef DEBUG
+#include <string_view>
+#endif  // DEBUG
+
+namespace node {
+namespace debug {
+
+#ifdef DEBUG
+void TrackV8FastApiCall(std::string_view key);
+int GetV8FastApiCallCount(std::string_view key);
+
+#define TRACK_V8_FAST_API_CALL(key) node::debug::TrackV8FastApiCall(key)
+#else  // !DEBUG
+#define TRACK_V8_FAST_API_CALL(key)
+#endif  // DEBUG
+
+}  // namespace debug
+}  // namespace node
+
+#endif  // defined(NODE_WANT_INTERNALS) && NODE_WANT_INTERNALS

test/benchmark/test-benchmark-napi.js

@@ -10,7 +10,7 @@ if (!common.isMainThread) {
   common.skip('addons are not supported in workers');
 }
 
-if (process.features.debug) {
+if (common.isDebug) {
   common.skip('benchmark does not work with debug build yet');
 }
 const runBenchmark = require('../common/benchmark');

test/common/index.js

@@ -143,6 +143,7 @@ const isOpenBSD = process.platform === 'openbsd';
 const isLinux = process.platform === 'linux';
 const isMacOS = process.platform === 'darwin';
 const isASan = process.config.variables.asan === 1;
+const isDebug = process.features.debug;
 const isPi = (() => {
   try {
     // Normal Raspberry Pi detection is to find the `Raspberry Pi` string in
@@ -280,7 +281,7 @@ function platformTimeout(ms) {
   const multipliers = typeof ms === 'bigint' ?
     { two: 2n, four: 4n, seven: 7n } : { two: 2, four: 4, seven: 7 };
 
-  if (process.features.debug)
+  if (isDebug)
     ms = multipliers.two * ms;
 
   if (exports.isAIX || exports.isIBMi)
@@ -998,6 +999,7 @@ const common = {
   invalidArgTypeHelper,
   isAlive,
   isASan,
+  isDebug,
   isDumbTerminal,
   isFreeBSD,
   isLinux,

test/parallel/test-debug-v8-fast-api.js

@@ -0,0 +1,59 @@
+// Flags: --expose-internals --no-warnings --allow-natives-syntax
+'use strict';
+const common = require('../common');
+
+const assert = require('assert');
+const { internalBinding } = require('internal/test/binding');
+
+if (!common.isDebug) {
+  assert.throws(() => internalBinding('debug'), {
+    message: 'No such binding: debug'
+  });
+  return;
+}
+
+const {
+  getV8FastApiCallCount,
+  isEven,
+  isOdd,
+} = internalBinding('debug');
+
+assert.throws(() => getV8FastApiCallCount(), {
+  message: 'getV8FastApiCallCount must be called with a string',
+});
+
+function testIsEven() {
+  for (let i = 0; i < 10; i++) {
+    assert.strictEqual(isEven(i), i % 2 === 0);
+  }
+}
+
+function testIsOdd() {
+  for (let i = 0; i < 20; i++) {
+    assert.strictEqual(isOdd(i), i % 2 !== 0);
+  }
+}
+
+// Should return 0 by default for any string.
+assert.strictEqual(getV8FastApiCallCount(''), 0);
+assert.strictEqual(getV8FastApiCallCount('foo'), 0);
+assert.strictEqual(getV8FastApiCallCount('debug.isEven'), 0);
+assert.strictEqual(getV8FastApiCallCount('debug.isOdd'), 0);
+
+eval('%PrepareFunctionForOptimization(testIsEven)');
+testIsEven();
+eval('%PrepareFunctionForOptimization(testIsOdd)');
+testIsOdd();
+
+// Functions should not be optimized yet.
+assert.strictEqual(getV8FastApiCallCount('debug.isEven'), 0);
+assert.strictEqual(getV8FastApiCallCount('debug.isOdd'), 0);
+
+eval('%OptimizeFunctionOnNextCall(testIsEven)');
+testIsEven();
+eval('%OptimizeFunctionOnNextCall(testIsOdd)');
+testIsOdd();
+
+// Functions should have been optimized and fast path taken.
+assert.strictEqual(getV8FastApiCallCount('debug.isEven'), 10);
+assert.strictEqual(getV8FastApiCallCount('debug.isOdd'), 20);

test/sequential/test-crypto-timing-safe-equal.js

@@ -1,3 +1,4 @@
+// Flags: --expose-internals --no-warnings --allow-natives-syntax
 'use strict';
 const common = require('../common');
 if (!common.hasCrypto)
@@ -91,3 +92,25 @@ assert.throws(
     name: 'TypeError',
   }
 );
+
+if (common.isDebug) {
+  const { internalBinding } = require('internal/test/binding');
+  const { getV8FastApiCallCount } = internalBinding('debug');
+
+  const foo = Buffer.from('foo');
+  const bar = Buffer.from('bar');
+  const longer = Buffer.from('longer');
+  function testFastPath(buf1, buf2) {
+    return crypto.timingSafeEqual(buf1, buf2);
+  }
+  eval('%PrepareFunctionForOptimization(testFastPath)');
+  assert.strictEqual(testFastPath(foo, bar), false);
+  eval('%OptimizeFunctionOnNextCall(testFastPath)');
+  assert.strictEqual(testFastPath(foo, bar), false);
+  assert.strictEqual(testFastPath(foo, foo), true);
+  assert.throws(() => testFastPath(foo, longer), {
+    code: 'ERR_CRYPTO_TIMING_SAFE_EQUAL_LENGTH',
+  });
+  assert.strictEqual(getV8FastApiCallCount('crypto.timingSafeEqual.ok'), 2);
+  assert.strictEqual(getV8FastApiCallCount('crypto.timingSafeEqual.error'), 1);
+}