async_hooks: skip runtime checks when disabled

PR-URL: #15454
Ref: #14387
Ref: #14722
Ref: #14717
Ref: #15448
Reviewed-By: Refael Ackermann <refack@gmail.com>
Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>

Author: AndreasMadsen

doc/api/cli.md

@@ -215,6 +215,14 @@ added: v2.1.0
 Prints a stack trace whenever synchronous I/O is detected after the first turn
 of the event loop.
 
+### `--force-async-hooks-checks`
+<!-- YAML
+added: REPLACEME
+-->
+
+Enables runtime checks for `async_hooks`. These can also be enabled dynamically
+by enabling one of the `async_hooks` hooks.
+
 ### `--trace-events-enabled`
 <!-- YAML
 added: v7.7.0

doc/node.1

@@ -152,6 +152,11 @@ Write process warnings to the given file instead of printing to stderr.
 Print a stack trace whenever synchronous I/O is detected after the first turn
 of the event loop.
 
+.TP
+.BR \-\-force\-async\-hooks\-checks
+Enables runtime checks for `async_hooks`. These can also be enabled dynamically
+by enabling one of the `async_hooks` hooks.
+
 .TP
 .BR \-\-trace\-events\-enabled
 Enables the collection of trace event tracing information.

lib/_http_outgoing.js

@@ -262,7 +262,15 @@ function _writeRaw(data, encoding, callback) {
       this._flushOutput(conn);
     } else if (!data.length) {
       if (typeof callback === 'function') {
-        nextTick(this.socket[async_id_symbol], callback);
+        let socketAsyncId = this.socket[async_id_symbol];
+        // If the socket was set directly it won't be correctly initialized
+        // with an async_id_symbol.
+        // TODO(AndreasMadsen): @trevnorris suggested some more correct
+        // solutions in:
+        // https://github.com/nodejs/node/pull/14389/files#r128522202
+        if (socketAsyncId === undefined) socketAsyncId = null;
+
+        nextTick(socketAsyncId, callback);
       }
       return true;
     }

lib/async_hooks.js

@@ -61,7 +61,7 @@ const active_hooks = {
 // async execution. These are tracked so if the user didn't include callbacks
 // for a given step, that step can bail out early.
 const { kInit, kBefore, kAfter, kDestroy, kTotals, kPromiseResolve,
-        kExecutionAsyncId, kTriggerAsyncId, kAsyncIdCounter,
+        kCheck, kExecutionAsyncId, kTriggerAsyncId, kAsyncIdCounter,
         kInitTriggerAsyncId } = async_wrap.constants;
 
 // Symbols used to store the respective ids on both AsyncResource instances and
@@ -157,8 +157,10 @@ class AsyncHook {
         hook_fields[kPromiseResolve] += +!!this[promise_resolve_symbol];
     hooks_array.push(this);
 
-    if (prev_kTotals === 0 && hook_fields[kTotals] > 0)
+    if (prev_kTotals === 0 && hook_fields[kTotals] > 0) {
       enablePromiseHook();
+      hook_fields[kCheck] += 1;
+    }
 
     return this;
   }
@@ -181,8 +183,10 @@ class AsyncHook {
         hook_fields[kPromiseResolve] -= +!!this[promise_resolve_symbol];
     hooks_array.splice(index, 1);
 
-    if (prev_kTotals > 0 && hook_fields[kTotals] === 0)
+    if (prev_kTotals > 0 && hook_fields[kTotals] === 0) {
       disablePromiseHook();
+      hook_fields[kCheck] -= 1;
+    }
 
     return this;
   }
@@ -244,6 +248,15 @@ function triggerAsyncId() {
   return async_id_fields[kTriggerAsyncId];
 }
 
+function validateAsyncId(asyncId, type) {
+  // Skip validation when async_hooks is disabled
+  if (async_hook_fields[kCheck] <= 0) return;
+
+  if (!Number.isSafeInteger(asyncId) || asyncId < -1) {
+    fatalError(new errors.RangeError('ERR_INVALID_ASYNC_ID', type, asyncId));
+  }
+}
+
 
 // Embedder API //
 
@@ -349,10 +362,16 @@ function setInitTriggerId(triggerAsyncId) {
 
 
 function emitInitScript(asyncId, type, triggerAsyncId, resource) {
+  validateAsyncId(asyncId, 'asyncId');
+  if (triggerAsyncId !== null)
+    validateAsyncId(triggerAsyncId, 'triggerAsyncId');
+  if (async_hook_fields[kCheck] > 0 &&
+      (typeof type !== 'string' || type.length <= 0)) {
+    throw new errors.TypeError('ERR_ASYNC_TYPE', type);
+  }
+
   // Short circuit all checks for the common case. Which is that no hooks have
   // been set. Do this to remove performance impact for embedders (and core).
-  // Even though it bypasses all the argument checks. The performance savings
-  // here is critical.
   if (async_hook_fields[kInit] === 0)
     return;
 
@@ -366,18 +385,6 @@ function emitInitScript(asyncId, type, triggerAsyncId, resource) {
     async_id_fields[kInitTriggerAsyncId] = 0;
   }
 
-  if (!Number.isSafeInteger(asyncId) || asyncId < -1) {
-    throw new errors.RangeError('ERR_INVALID_ASYNC_ID', 'asyncId', asyncId);
-  }
-  if (!Number.isSafeInteger(triggerAsyncId) || triggerAsyncId < -1) {
-    throw new errors.RangeError('ERR_INVALID_ASYNC_ID',
-                                'triggerAsyncId',
-                                triggerAsyncId);
-  }
-  if (typeof type !== 'string' || type.length <= 0) {
-    throw new errors.TypeError('ERR_ASYNC_TYPE', type);
-  }
-
   emitInitNative(asyncId, type, triggerAsyncId, resource);
 }
 
@@ -423,15 +430,8 @@ function emitBeforeScript(asyncId, triggerAsyncId) {
   // Validate the ids. An id of -1 means it was never set and is visible on the
   // call graph. An id < -1 should never happen in any circumstance. Throw
   // on user calls because async state should still be recoverable.
-  if (!Number.isSafeInteger(asyncId) || asyncId < -1) {
-    fatalError(
-      new errors.RangeError('ERR_INVALID_ASYNC_ID', 'asyncId', asyncId));
-  }
-  if (!Number.isSafeInteger(triggerAsyncId) || triggerAsyncId < -1) {
-    fatalError(new errors.RangeError('ERR_INVALID_ASYNC_ID',
-                                     'triggerAsyncId',
-                                     triggerAsyncId));
-  }
+  validateAsyncId(asyncId, 'asyncId');
+  validateAsyncId(triggerAsyncId, 'triggerAsyncId');
 
   pushAsyncIds(asyncId, triggerAsyncId);
 
@@ -441,10 +441,7 @@ function emitBeforeScript(asyncId, triggerAsyncId) {
 
 
 function emitAfterScript(asyncId) {
-  if (!Number.isSafeInteger(asyncId) || asyncId < -1) {
-    fatalError(
-      new errors.RangeError('ERR_INVALID_ASYNC_ID', 'asyncId', asyncId));
-  }
+  validateAsyncId(asyncId, 'asyncId');
 
   if (async_hook_fields[kAfter] > 0)
     emitAfterNative(asyncId);
@@ -454,10 +451,7 @@ function emitAfterScript(asyncId) {
 
 
 function emitDestroyScript(asyncId) {
-  if (!Number.isSafeInteger(asyncId) || asyncId < -1) {
-    fatalError(
-      new errors.RangeError('ERR_INVALID_ASYNC_ID', 'asyncId', asyncId));
-  }
+  validateAsyncId(asyncId, 'asyncId');
 
   // Return early if there are no destroy callbacks, or invalid asyncId.
   if (async_hook_fields[kDestroy] === 0 || asyncId <= 0)

lib/internal/process/next_tick.js

@@ -281,7 +281,7 @@ function setupNextTick() {
     if (process._exiting)
       return;
 
-    if (!Number.isSafeInteger(triggerAsyncId) || triggerAsyncId <= 0) {
+    if (triggerAsyncId === null) {
       triggerAsyncId = async_hooks.initTriggerId();
     }
 

src/async-wrap.cc

@@ -526,6 +526,7 @@ void AsyncWrap::Initialize(Local<Object> target,
   SET_HOOKS_CONSTANT(kDestroy);
   SET_HOOKS_CONSTANT(kPromiseResolve);
   SET_HOOKS_CONSTANT(kTotals);
+  SET_HOOKS_CONSTANT(kCheck);
   SET_HOOKS_CONSTANT(kExecutionAsyncId);
   SET_HOOKS_CONSTANT(kTriggerAsyncId);
   SET_HOOKS_CONSTANT(kAsyncIdCounter);

src/env-inl.h

@@ -129,10 +129,19 @@ inline v8::Local<v8::String> Environment::AsyncHooks::provider_string(int idx) {
   return providers_[idx].Get(isolate_);
 }
 
+inline void Environment::AsyncHooks::force_checks() {
+  // fields_ does not have the += operator defined
+  fields_[kCheck] = fields_[kCheck] + 1;
+}
+
 inline void Environment::AsyncHooks::push_async_ids(double async_id,
                                               double trigger_async_id) {
-  CHECK_GE(async_id, -1);
-  CHECK_GE(trigger_async_id, -1);
+  // Since async_hooks is experimental, do only perform the check
+  // when async_hooks is enabled.
+  if (fields_[kCheck] > 0) {
+    CHECK_GE(async_id, -1);
+    CHECK_GE(trigger_async_id, -1);
+  }
 
   async_ids_stack_.push({ async_id_fields_[kExecutionAsyncId],
                     async_id_fields_[kTriggerAsyncId] });
@@ -145,9 +154,11 @@ inline bool Environment::AsyncHooks::pop_async_id(double async_id) {
   // stack was multiple MakeCallback()'s deep.
   if (async_ids_stack_.empty()) return false;
 
-  // Ask for the async_id to be restored as a sanity check that the stack
+  // Ask for the async_id to be restored as a check that the stack
   // hasn't been corrupted.
-  if (async_id_fields_[kExecutionAsyncId] != async_id) {
+  // Since async_hooks is experimental, do only perform the check
+  // when async_hooks is enabled.
+  if (fields_[kCheck] > 0 && async_id_fields_[kExecutionAsyncId] != async_id) {
     fprintf(stderr,
             "Error: async hook stack has become corrupted ("
             "actual: %.f, expected: %.f)\n",
@@ -185,7 +196,9 @@ inline Environment::AsyncHooks::InitScope::InitScope(
     Environment* env, double init_trigger_async_id)
         : env_(env),
           async_id_fields_ref_(env->async_hooks()->async_id_fields()) {
-  CHECK_GE(init_trigger_async_id, -1);
+  if (env_->async_hooks()->fields()[AsyncHooks::kCheck] > 0) {
+    CHECK_GE(init_trigger_async_id, -1);
+  }
   env->async_hooks()->push_async_ids(
     async_id_fields_ref_[AsyncHooks::kExecutionAsyncId],
     init_trigger_async_id);

src/env.h

@@ -387,6 +387,7 @@ class Environment {
       kDestroy,
       kPromiseResolve,
       kTotals,
+      kCheck,
       kFieldsCount,
     };
 
@@ -408,6 +409,8 @@ class Environment {
 
     inline v8::Local<v8::String> provider_string(int idx);
 
+    inline void force_checks();
+
     inline void push_async_ids(double async_id, double trigger_async_id);
     inline bool pop_async_id(double async_id);
     inline size_t stack_size();

src/node.cc

@@ -169,6 +169,7 @@ static bool syntax_check_only = false;
 static bool trace_deprecation = false;
 static bool throw_deprecation = false;
 static bool trace_sync_io = false;
+static bool force_async_hooks_checks = false;
 static bool track_heap_objects = false;
 static const char* eval_string = nullptr;
 static std::vector<std::string> preload_modules;
@@ -1448,8 +1449,10 @@ void InternalCallbackScope::Close() {
 
   // Make sure the stack unwound properly. If there are nested MakeCallback's
   // then it should return early and not reach this code.
-  CHECK_EQ(env_->execution_async_id(), 0);
-  CHECK_EQ(env_->trigger_async_id(), 0);
+  if (env_->async_hooks()->fields()[AsyncHooks::kTotals]) {
+    CHECK_EQ(env_->execution_async_id(), 0);
+    CHECK_EQ(env_->trigger_async_id(), 0);
+  }
 
   Local<Object> process = env_->process_object();
 
@@ -1458,8 +1461,10 @@ void InternalCallbackScope::Close() {
     return;
   }
 
-  CHECK_EQ(env_->execution_async_id(), 0);
-  CHECK_EQ(env_->trigger_async_id(), 0);
+  if (env_->async_hooks()->fields()[AsyncHooks::kTotals]) {
+    CHECK_EQ(env_->execution_async_id(), 0);
+    CHECK_EQ(env_->trigger_async_id(), 0);
+  }
 
   if (env_->tick_callback_function()->Call(process, 0, nullptr).IsEmpty()) {
     failed_ = true;
@@ -3853,6 +3858,8 @@ static void PrintHelp() {
          "                             stderr\n"
          "  --trace-sync-io            show stack trace when use of sync IO\n"
          "                             is detected after the first tick\n"
+         "  --force-async-hooks-checks\n"
+         "                             enables checks for async_hooks\n"
          "  --trace-events-enabled     track trace events\n"
          "  --trace-event-categories   comma separated list of trace event\n"
          "                             categories to record\n"
@@ -3979,6 +3986,7 @@ static void CheckIfAllowedInEnv(const char* exe, bool is_env,
     "--trace-warnings",
     "--redirect-warnings",
     "--trace-sync-io",
+    "--force-async-hooks-checks",
     "--trace-events-enabled",
     "--trace-events-categories",
     "--track-heap-objects",
@@ -4117,6 +4125,8 @@ static void ParseArgs(int* argc,
       trace_deprecation = true;
     } else if (strcmp(arg, "--trace-sync-io") == 0) {
       trace_sync_io = true;
+    } else if (strcmp(arg, "--force-async-hooks-checks") == 0) {
+      force_async_hooks_checks = true;
     } else if (strcmp(arg, "--trace-events-enabled") == 0) {
       trace_enabled = true;
     } else if (strcmp(arg, "--trace-event-categories") == 0) {
@@ -4754,6 +4764,10 @@ inline int Start(Isolate* isolate, IsolateData* isolate_data,
 
   env.set_abort_on_uncaught_exception(abort_on_uncaught_exception);
 
+  if (force_async_hooks_checks) {
+    env.async_hooks()->force_checks();
+  }
+
   {
     Environment::AsyncCallbackScope callback_scope(&env);
     env.async_hooks()->push_async_ids(1, 0);

test/async-hooks/test-emit-init.js

@@ -2,13 +2,10 @@
 
 const common = require('../common');
 const assert = require('assert');
+const spawnSync = require('child_process').spawnSync;
 const async_hooks = require('async_hooks');
 const initHooks = require('./init-hooks');
 
-// Verify that if there is no registered hook, then those invalid parameters
-// won't be checked.
-assert.doesNotThrow(() => async_hooks.emitInit());
-
 const expectedId = async_hooks.newUid();
 const expectedTriggerId = async_hooks.newUid();
 const expectedType = 'test_emit_init_type';
@@ -25,24 +22,40 @@ const hooks1 = initHooks({
 
 hooks1.enable();
 
-assert.throws(() => {
-  async_hooks.emitInit();
-}, common.expectsError({
-  code: 'ERR_INVALID_ASYNC_ID',
-  type: RangeError,
-}));
-assert.throws(() => {
-  async_hooks.emitInit(expectedId);
-}, common.expectsError({
-  code: 'ERR_INVALID_ASYNC_ID',
-  type: RangeError,
-}));
-assert.throws(() => {
-  async_hooks.emitInit(expectedId, expectedType, -2);
-}, common.expectsError({
-  code: 'ERR_INVALID_ASYNC_ID',
-  type: RangeError,
-}));
+switch (process.argv[2]) {
+  case 'test_invalid_async_id':
+    async_hooks.emitInit();
+    return;
+  case 'test_invalid_trigger_id':
+    async_hooks.emitInit(expectedId);
+    return;
+  case 'test_invalid_trigger_id_negative':
+    async_hooks.emitInit(expectedId, expectedType, -2);
+    return;
+}
+assert.ok(!process.argv[2]);
+
+
+const c1 = spawnSync(process.execPath, [__filename, 'test_invalid_async_id']);
+assert.strictEqual(
+  c1.stderr.toString().split(/[\r\n]+/g)[0],
+  'RangeError [ERR_INVALID_ASYNC_ID]: Invalid asyncId value: undefined');
+assert.strictEqual(c1.status, 1);
+
+const c2 = spawnSync(process.execPath, [__filename, 'test_invalid_trigger_id']);
+assert.strictEqual(
+  c2.stderr.toString().split(/[\r\n]+/g)[0],
+  'RangeError [ERR_INVALID_ASYNC_ID]: Invalid triggerAsyncId value: undefined');
+assert.strictEqual(c2.status, 1);
+
+const c3 = spawnSync(process.execPath, [
+  __filename, 'test_invalid_trigger_id_negative'
+]);
+assert.strictEqual(
+  c3.stderr.toString().split(/[\r\n]+/g)[0],
+  'RangeError [ERR_INVALID_ASYNC_ID]: Invalid triggerAsyncId value: -2');
+assert.strictEqual(c3.status, 1);
+
 
 async_hooks.emitInit(expectedId, expectedType, expectedTriggerId,
                      expectedResource);

test/async-hooks/test-force-checks-flag.js

@@ -0,0 +1,25 @@
+'use strict';
+const common = require('../common');
+const assert = require('assert');
+const async_hooks = require('async_hooks');
+const spawnSync = require('child_process').spawnSync;
+
+// disabling this way will just decrement the kCheck counter. It won't actually
+// disable the checks, because they were enabled with the flag.
+common.revert_force_async_hooks_checks();
+
+switch (process.argv[2]) {
+  case 'test_invalid_async_id':
+    async_hooks.emitInit();
+    return;
+}
+assert.ok(!process.argv[2]);
+
+
+const c1 = spawnSync(process.execPath, [
+  '--force-async-hooks-checks', __filename, 'test_invalid_async_id'
+]);
+assert.strictEqual(
+  c1.stderr.toString().split(/[\r\n]+/g)[0],
+  'RangeError [ERR_INVALID_ASYNC_ID]: Invalid asyncId value: undefined');
+assert.strictEqual(c1.status, 1);

test/async-hooks/test-internal-nexttick-default-trigger.js

@@ -26,11 +26,6 @@ internal.nextTick(null, common.mustCall(function() {
   assert.strictEqual(async_hooks.triggerAsyncId(), rootAsyncId);
 }));
 
-// internal default
-internal.nextTick(undefined, common.mustCall(function() {
-  assert.strictEqual(async_hooks.triggerAsyncId(), rootAsyncId);
-}));
-
 // internal
 internal.nextTick(rootAsyncId + 1, common.mustCall(function() {
   assert.strictEqual(async_hooks.triggerAsyncId(), rootAsyncId + 1);

test/async-hooks/test-no-assert-when-disabled.js

@@ -0,0 +1,26 @@
+'use strict';
+// Flags: --expose-internals
+const common = require('../common');
+
+const async_hooks = require('async_hooks');
+const internal = require('internal/process/next_tick');
+
+// In tests async_hooks dynamic checks are enabled by default. To verify
+// that no checks are enabled ordinarily disable the checks in this test.
+common.revert_force_async_hooks_checks();
+
+// When async_hooks is diabled (or never enabled), the checks
+// should be disabled as well. This is important while async_hooks is
+// experimental and there are still critial bugs to fix.
+
+// Using undefined as the triggerAsyncId.
+// Ref: https://github.com/nodejs/node/issues/14386
+// Ref: https://github.com/nodejs/node/issues/14381
+// Ref: https://github.com/nodejs/node/issues/14368
+internal.nextTick(undefined, common.mustCall());
+
+// Negative asyncIds and invalid type name
+async_hooks.emitInit(-1, null, -1, {});
+async_hooks.emitBefore(-1, -1);
+async_hooks.emitAfter(-1);
+async_hooks.emitDestroy(-1);

test/common/index.js

@@ -63,6 +63,17 @@ exports.projectDir = path.resolve(__dirname, '..', '..');
 
 exports.buildType = process.config.target_defaults.default_configuration;
 
+// Always enable async_hooks checks in tests
+{
+  const async_wrap = process.binding('async_wrap');
+  const { kCheck } = async_wrap.constants;
+  async_wrap.async_hook_fields[kCheck] += 1;
+
+  exports.revert_force_async_hooks_checks = function() {
+    async_wrap.async_hook_fields[kCheck] -= 1;
+  };
+}
+
 // If env var is set then enable async_hook hooks for all tests.
 if (process.env.NODE_TEST_WITH_ASYNC_HOOKS) {
   const destroydIdsList = {};

test/sequential/test-inspector-async-hook-teardown-at-debug-end.js

@@ -7,23 +7,12 @@ const spawn = require('child_process').spawn;
 
 const script = `
 const assert = require('assert');
+const async_wrap = process.binding('async_wrap');
+const { kTotals } = async_wrap.constants;
 
-// Verify that inspector-async-hook is registered
-// by checking that emitInit with invalid arguments
-// throw an error.
-// See test/async-hooks/test-emit-init.js
-assert.throws(
-  () => async_hooks.emitInit(),
-  'inspector async hook should have been enabled initially');
-
+assert.strictEqual(async_wrap.async_hook_fields[kTotals], 4);
 process._debugEnd();
-
-// Verify that inspector-async-hook is no longer registered,
-// thus emitInit() ignores invalid arguments
-// See test/async-hooks/test-emit-init.js
-assert.doesNotThrow(
-  () => async_hooks.emitInit(),
-  'inspector async hook should have beend disabled by _debugEnd()');
+assert.strictEqual(async_wrap.async_hook_fields[kTotals], 0);
 `;
 
 const args = ['--inspect', '-e', script];