Skip to content

vm: timeout during an afterEvaluate microtask checkpoint corrupts the async hook stackΒ #66439

Description

@mbackschat

Version

v27.0.0-nightly20261001cede7e6740 (also v26.10.0, v24.21.0, v24.18.0)

Platform

Darwin 27.0.0 arm64

Subsystem

vm, async_hooks

What steps will reproduce the bug?

const async_hooks = require('node:async_hooks');
const vm = require('node:vm');

async_hooks.createHook({ init() {} }).enable();

const context = vm.createContext({}, { microtaskMode: 'afterEvaluate' });
try {
  vm.runInContext('Promise.resolve().then(() => { while (true); })', context, { timeout: 5 });
} catch (error) {
  console.log('caught:', error.code);
}
setImmediate(() => console.log('survived'));

Run it with node repro.js. The explicit hook only arms Node's async-stack check. node --test arms the same check, so the snippet also fails without the hook when its body runs inside test().

How often does it reproduce? Is there a required condition?

Every run: 3 of 3 on each listed version. It requires a context created with microtaskMode: 'afterEvaluate', a timeout (or breakOnSigint) that fires while a microtask runs during the post-evaluation checkpoint, and an enabled async hook. Without an enabled hook the process survives.

What is the expected behavior? Why is that the expected behavior?

caught: ERR_SCRIPT_EXECUTION_TIMEOUT
survived

The timeout is documented to throw ERR_SCRIPT_EXECUTION_TIMEOUT to the caller, and the caller does catch it. Afterwards the process should continue normally.

What do you see instead?

The timeout is caught, then the process exits with status 1 at the next callback scope:

caught: ERR_SCRIPT_EXECUTION_TIMEOUT
Error: async hook stack has become corrupted (actual: 3, expected: 1)
----- Native stack trace -----

 1: node::AsyncHooks::FailWithCorruptedAsyncStack(double)
 2: node::AsyncHooks::pop_async_context(double)
 3: node::InternalCallbackScope::Close()
 4: node::InternalCallbackScope::~InternalCallbackScope()
 5: node::StartExecution(...)

Other placements fail with execution_async_id() == 0 or the same corruption message.

Additional information

In ContextifyScript::EvalMachine, PerformCheckpoint for an afterEvaluate context runs inside the watchdog scope. When the watchdog terminates a promise job, the job's async-hook before callback has already pushed its async context, but its after callback never pops it. CancelTerminateExecution then returns with the async-id stack deeper than it was at entry to EvalMachine.

This is the mechanism analysed in #38503. That issue was closed by 4f844f4 (repl: use inspector over vm), which removed the REPL trigger. The vm defect itself is still present on main, as the nightly above shows.

A possible fix: record the stack length on entry and, after cancelling this invocation's own termination, pop contexts back to that length. Contexts of an enclosing timed evaluation stay intact.

--- a/src/node_contextify.cc
+++ b/src/node_contextify.cc
@@ -1298,6 +1298,10 @@
   MaybeLocal<Value> result;
   bool timed_out = false;
   bool received_signal = false;
+  // A watchdog termination can interrupt a promise job between its async-hook
+  // `before` and `after` callbacks, leaving that job's context on the stack.
+  const uint32_t async_stack_length =
+      env->async_hooks()->fields()[AsyncHooks::kStackLength];
   {
     auto wd = timeout != -1 ? std::make_optional<Watchdog>(
                                   env->isolate(), timeout, &timed_out)
@@ -1316,6 +1320,12 @@
     if (!env->is_main_thread() && env->is_stopping())
       return false;
     env->isolate()->CancelTerminateExecution();
+    // Drop only contexts entered during this evaluation; outer ones stay valid.
+    AsyncHooks* async_hooks = env->async_hooks();
+    while (async_hooks->fields()[AsyncHooks::kStackLength] >
+           async_stack_length) {
+      async_hooks->pop_async_context(env->execution_async_id());
+    }
     // It is possible that execution was terminated by another timeout in
     // which this timeout is nested, so check whether one of the watchdogs
     // from this invocation is responsible for termination.

The diff is against v24.18.0 and applies to main (cede7e6) with a 12-line offset. With it applied to a v24.18.0 build, the reproducer prints both lines above in 3 of 3 runs. After the timeout, the caller's executionAsyncId(), its AsyncLocalStorage store and later microtasks are unchanged, and the tools/test.py selection parallel/test-vm-*, parallel/test-async-hooks-*, parallel/test-async-local-storage-*, sequential/test-vm-* and async-hooks/* passes (241 of 241). I have not tested Linux or Windows.

I found this through the Temporal TypeScript SDK, which runs each Workflow activation in an afterEvaluate context with a timeout. Under node --test, one activation timeout terminates the whole test process. temporalio/sdk-typescript#939 reports the same message from a Worker on a Workflow Task timeout.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions