Skip to content

error: recover async stack frames dropped under AsyncLocalStorage - #35772

Closed
robobun wants to merge 5 commits into
mainfrom
farm/e9e0550c/als-async-stack-frames
Closed

error: recover async stack frames dropped under AsyncLocalStorage#35772
robobun wants to merge 5 commits into
mainfrom
farm/e9e0550c/als-async-stack-frames

Conversation

@robobun

@robobun robobun commented Jul 25, 2026

Copy link
Copy Markdown
Collaborator

Fixes #24003.

Problem

When an AsyncLocalStorage store is active, error.stack for errors created deep in an await chain drops every at async <fn> frame:

import { AsyncLocalStorage } from "node:async_hooks";
const als = new AsyncLocalStorage();
async function fn3() { await 0; throw new Error("boom"); }
async function fn2() { await fn3(); }
async function fn1() { await fn2(); }
try { await als.run({}, () => fn1()); } catch (e) { console.log(e.stack); }
Node at fn3at async fn2at async fn1
Bun (before) at fn3
Bun (after) at fn3at async fn2at async fn1

The same chain without ALS already shows the full trace.

Cause

Under USE(BUN_JSC_ADDITIONS), JSPromise::resolveWithInternalMicrotaskForAsyncAwait wraps the awaiting generator in an InternalFieldTuple(generator, asyncContext) whenever an async context is active, and stores that tuple as the reaction context so the context can be restored when the microtask resumes.

Interpreter::getAsyncStackTrace walks the await chain by reading the reaction context via asyncStackTraceContext() and casting it with dynamicDowncast<JSAsyncFunctionGenerator>. On a tuple that cast (and the combinator/promise fallbacks) fails, so the walk returns nothing and every async frame is dropped.

Fix

oven-sh/WebKit#347 unwraps the tuple inside getContextValueFromPromise, which every branch of getParentGenerator flows through. That is the complete fix (direct await, Promise.all/allSettled/any, Promise.race) with no extra per-Error work.

Until WEBKIT_VERSION moves past that change, this PR installs a VM::onAppendStackTrace hook that replicates getParentGenerator with tuple unwrapping. The hook is registered lazily from jsSetAsyncHooksEnabled the first time AsyncLocalStorage turns tracking on, so code that never touches ALS pays nothing. To avoid duplicating frames JSC does find (when ALS was inactive at some hop), the hook runs the unwrapped and non-unwrapped walks in lockstep and only starts appending once the non-unwrapped walk stops.

Known limitations of the interim hook

  • Promise.all/allSettled/any under ALS still stop at the combinator hop; JSPromiseCombinatorsGlobalContext is a private JSC header. getAsyncStackTrace: unwrap InternalFieldTuple in reaction context WebKit#347 covers this.
  • Under a nested VM entry that has visible JS frames below the async origin (e.g. node:vm with microtaskMode: "afterEvaluate"), the recovered at async frames land after those outer frames instead of directly after JSC's async block. The frames are still present (they were absent before).

Tests

test/regression/issue/24003.test.ts covers als.run(), als.enterWith(), Promise.race under ALS, the no-ALS baselines (no duplication, direct and via Promise.race), and a mid-chain ALS entry where JSC's walk finds one frame and the hook supplies the rest.

Existing test/js/bun/test/stack.test.ts, test/js/node/v8/capture-stack-trace.test.js, and test/js/node/async_hooks/AsyncLocalStorage.test.ts all pass unchanged.

Related

Supersedes #29619.


[review] gate passed · iteration 2 · 4 files touched

fails on main (without fix)
ASAN without fix: 4 FAILED
$ BUN_DEBUG_QUIET_LOGS=1 bun scripts/build.ts --profile=debug --quiet test "--reporter=junit" "--reporter-outfile=/tmp/mechgate.xml" "test/regression/issue/24003.test.ts"
bun test v1.4.0 (ca5c60b1a)

test/regression/issue/24003.test.ts:
(pass) issue #24003 > async stack frames are not duplicated when no AsyncLocalStorage store is active [558.13ms]
(pass) issue #24003 > async stack frames through Promise.race are not duplicated when no AsyncLocalStorage store is active [576.22ms]
37 |       catch (e) { console.log(e.stack); }
38 |     }
39 |     main();
40 |   `);
41 |     expect(stdout).toContain("at fn3");
42 |     expect(asyncFrames(stdout)).toEqual(["at async fn2", "at async fn1", "at async main"]);
                                     ^
error: expect(received).toEqual(expected)

- [
-   "at async fn2",
-   "at async fn1",
-   "at async main",
- ]
+ []

- Expected  - 5
+ Received  + 1

      at <anonymous> (/workspace/bun/test/regression/issue/24003.test.ts:42:33)
(fail) issue #24003 > async stack frames under AsyncLocalStorage.run() [986.14ms]
51 |     async function outer() { await inner(); }
52 |     async function main() { await outer(); }
53 |     main();
54
... (truncated)

release without fix: all passed
bun test v1.4.0-canary.1 (9f710c780)

test/regression/issue/24003.test.ts:
(pass) issue #24003 > async stack frames under AsyncLocalStorage.run() [18.22ms]
(pass) issue #24003 > async stack frames under AsyncLocalStorage.enterWith() [11.21ms]
(pass) issue #24003 > async stack frames through Promise.race under AsyncLocalStorage [11.60ms]
(pass) issue #24003 > async stack frames are not duplicated when no AsyncLocalStorage store is active [11.23ms]
(pass) issue #24003 > async stack frames through Promise.race are not duplicated when no AsyncLocalStorage store is active [10.70ms]
(pass) issue #24003 > async stack frames when AsyncLocalStorage is entered mid-chain [10.26ms]

 6 pass
 0 fail
 24 expect() calls
Ran 6 tests across 1 file. [359.00ms]
__F:0:S:0
passes on PR (with fix)
ASAN with fix: all passed
$ BUN_DEBUG_QUIET_LOGS=1 bun scripts/build.ts --profile=debug --quiet test "--reporter=junit" "--reporter-outfile=/tmp/mechgate.xml" "test/regression/issue/24003.test.ts"
bun test v1.4.0 (ca5c60b1a)

test/regression/issue/24003.test.ts:
(pass) issue #24003 > async stack frames are not duplicated when no AsyncLocalStorage store is active [745.39ms]
(pass) issue #24003 > async stack frames through Promise.race are not duplicated when no AsyncLocalStorage store is active [784.45ms]
(pass) issue #24003 > async stack frames under AsyncLocalStorage.run() [989.98ms]
(pass) issue #24003 > async stack frames under AsyncLocalStorage.enterWith() [959.38ms]
(pass) issue #24003 > async stack frames through Promise.race under AsyncLocalStorage [1358.88ms]
(pass) issue #24003 > async stack frames when AsyncLocalStorage is entered mid-chain [910.39ms]

 6 pass
 0 fail
 24 expect() calls
Ran 6 tests across 1 file. [5.91s]
__F:0:S:0

release with fix: all passed
$ bun scripts/build.ts --profile=release
[configured] bun-profile → bun (stripped) in 1138ms (unchanged)
ninja: Entering directory `/workspace/bun/build/release'
[1/10] gen cpp.rs (cppbind)
[1/10] cargo bun_bin → libbun_rust.a (--target x86_64-unknown-linux-gnu)

  nightly-2026-07-20-x86_64-unknown-linux-gnu unchanged - rustc 1.99.0-nightly (9f36de775 2026-07-19)

�[1m�[92m   Compiling�[0m bun_core v0.0.0 (/workspace/bun/src/bun_core)
�[1m�[92m   Compiling�[0m bun_errno v0.0.0 (/workspace/bun/src/errno)
�[1m�[92m   Compiling�[0m bun_ptr v0.0.0 (/workspace/bun/src/ptr)
�[1m�[92m   Compiling�[0m bun_boringssl_sys v0.0.0 (/workspace/bun/src/boringssl_sys)
�[1m�[92m   Compiling�[0m bun_safety v0.0.0 (/workspace/bun/src/safety)
�[1m�[92m   Compiling�[0m bun_zlib_sys v0.0.0 (/workspace/bun/src/zlib_sys)
�[1m�[92m   Compiling�[0m bun_cares_sys v0.0.0 (/workspace/bun/src/cares_sys)
�[1m�[92m   Compiling�[0m bun_zstd v0.0.0 (/workspace/bun/src/zstd)
�[1m�[92m   Compiling�[0m bun_picohttp v0.0.0 (/workspace/bun/src/picohttp)
�[1m�[92m   Compiling�[0m bun_output v0.0.0 (/workspace/bun/src/output)
�[1m�[92m   Compiling�[0m bun_clap v0.0.0 (/workspace/bun/src/clap)
�[1m�[92m
... (truncated)
diff hotspot
src/jsc/bindings/AsyncStackTrace.cpp | 179 +++++++++++++++++++++++++----------
 src/jsc/bindings/AsyncStackTrace.h   |   8 ++
 src/jsc/bindings/NodeAsyncHooks.cpp  |   7 +-
 test/regression/issue/24003.test.ts  | 133 ++++++++++++++++++++++++++
 4 files changed, 278 insertions(+), 49 deletions(-)

gate history · 3 passed · 1 rejected · iteration 2

evidence per changed file
file                                  reads  edits  tests
src/jsc/bindings/AsyncStackTrace.cpp      5      6      0
src/jsc/bindings/AsyncStackTrace.h        1      1      0
src/jsc/bindings/NodeAsyncHooks.cpp       1      1      0
test/regression/issue/24003.test.ts       3      8      0

When an AsyncLocalStorage store is active at an await point,
JSPromise::resolveWithInternalMicrotaskForAsyncAwait wraps the awaiting
generator in an InternalFieldTuple(generator, asyncContext) and stores
that as the reaction context. Interpreter::getAsyncStackTrace reads the
reaction context and casts it with dynamicDowncast<JSAsyncFunctionGenerator>,
which fails on the tuple, so every 'at async <fn>' frame is dropped
from error.stack.

Install a VM::onAppendStackTrace hook that replicates getParentGenerator
with tuple unwrapping and appends the frames JSC's walk misses. The hook
runs the unwrapped and non-unwrapped walks in lockstep so frames JSC
does find (when ALS was inactive at some hop) are not duplicated.

Fixes #24003.
@coderabbitai

coderabbitai Bot commented Jul 25, 2026

Copy link
Copy Markdown
Contributor

Warning

Review limit reached

@robobun, you've reached your PR review limit, so we couldn't start this review.

Next review available in: 18 minutes

Enable usage-based reviews in Billing to review now. Otherwise, wait until the next included review is available.
You're only billed for reviews past your plan's rate limits ($0.25/file).

How can I continue?

After more reviews become available, a review can be triggered using the @coderabbitai review command as a PR comment. Alternatively, push new commits to this PR.

To avoid repeated limits, reduce automatic review volume by pausing incremental auto-reviews earlier, using label-based review opt-in, excluding WIP or generated PR titles, or requesting reviews manually when the PR is ready. If your team needs uninterrupted high-volume reviews, an organization admin can enable usage-based reviews.

How do review limits work?

CodeRabbit enforces per-developer PR review limits for each organization. Most developers receive the normal plan review availability.

For paid Pro and Pro+ PR reviews, CodeRabbit uses adaptive limits for sustained high-volume activity. When a developer's recent PR review activity reaches the 95th percentile or higher among CodeRabbit users, additional reviews become available more gradually as earlier reviews age out of the rolling window.

Please refer docs for additional details.

Review details
⚙️ Run configuration

Configuration used: Path: .coderabbit.yaml

Review profile: ASSERTIVE

Plan: Pro

Run ID: c29b7e35-a578-4fe7-bc09-ab780a30a980

📥 Commits

Reviewing files that changed from the base of the PR and between 04bb5c4 and ca5c60b.

📒 Files selected for processing (4)
  • src/jsc/bindings/AsyncStackTrace.cpp
  • src/jsc/bindings/AsyncStackTrace.h
  • src/jsc/bindings/NodeAsyncHooks.cpp
  • test/regression/issue/24003.test.ts

Comment @coderabbitai help to get the list of available commands.

@robobun

robobun commented Jul 25, 2026

Copy link
Copy Markdown
Collaborator Author
Updated 2:08 PM PT - Jul 25th, 2026

@robobun, your commit 9f710c7 is building: #81467

Comment thread src/jsc/bindings/AsyncStackTrace.cpp Outdated
Comment thread src/jsc/bindings/AsyncStackTrace.cpp Outdated
Comment thread src/jsc/bindings/AsyncStackTrace.cpp Outdated
Comment thread src/jsc/bindings/AsyncStackTrace.cpp Outdated
Comment thread src/jsc/bindings/AsyncStackTrace.h
Comment thread src/jsc/bindings/AsyncStackTrace.cpp
Comment thread src/jsc/bindings/AsyncStackTrace.cpp
Comment thread src/jsc/bindings/AsyncStackTrace.cpp
Comment thread src/jsc/bindings/AsyncStackTrace.cpp
Comment thread src/jsc/bindings/AsyncStackTrace.cpp
@robobun
robobun force-pushed the farm/e9e0550c/als-async-stack-frames branch from ddf954c to 57c5923 Compare July 25, 2026 20:39
The hook is now registered the first time AsyncLocalStorage turns tracking on,
so code that never touches ALS pays nothing at error-capture time. Also point
at oven-sh/WebKit#347, which unwraps the tuple inside getAsyncStackTrace and
will make this hook unnecessary once WEBKIT_VERSION moves past it.
@robobun
robobun force-pushed the farm/e9e0550c/als-async-stack-frames branch from 57c5923 to 052714f Compare July 25, 2026 20:44

@claude claude Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Additional findings (outside current diff — PR may have been updated during review):

  • 🔴 src/install/lockfile/Package/Scripts.rs:140-144 — This one-line change (self.preinstallself.postinstall) is a real behavioral fix — packages with binding.gyp + a postinstall script previously had their postinstall silently replaced with an empty string — but it's completely unrelated to async stack traces, isn't mentioned in the PR title/description/commits, and ships with no test. Per REVIEW.md every behavioral change ships an automated test in the same PR; this looks like a stray edit from another branch and should be split into its own PR with coverage in test/cli/install/, or at minimum acknowledged in the description with a test added here.

    Extended reasoning...

    What the change does

    get_script_entries in Scripts.rs builds the ordered array of lifecycle scripts to run for a package. When add_node_gyp_rebuild_script is true, it hardcodes "node-gyp rebuild" into the install slot (index 1), then — if self.postinstall is non-empty — populates the postinstall slot (index 2). Before this PR that slot was filled with self.preinstall.slice(lockfile_buf); after, with self.postinstall.slice(lockfile_buf).

    Why this is a real behavioral fix, not a no-op

    Both callers only set add_node_gyp_rebuild_script = true when self.install.is_empty() && self.preinstall.is_empty():

    • get_list() (Scripts.rs:296-299): self.install.is_empty() && self.preinstall.is_empty() gates the binding.gyp existence check.
    • create_from_package_json() (Scripts.rs:371-373): same predicate.

    So inside the add_node_gyp_rebuild_script branch, self.preinstall is guaranteed empty. The old code therefore stored Some(Box::from(&[][..])) — an empty script — in the postinstall slot, while the guard immediately above it (if !self.postinstall.is_empty()) and the comment (// missing install and preinstall, only need to check postinstall) both make clear postinstall was the intended field. The new code stores the actual postinstall script.

    Step-by-step proof of the behavior change

    Take a package with binding.gyp, no install/preinstall, and "postinstall": "node ./verify.js":

    1. get_list() sees install and preinstall empty, binding.gyp exists → add_node_gyp_rebuild_script = true.
    2. get_script_entries enters the add_node_gyp_rebuild_script branch. script_index=1 gets "node-gyp rebuild". script_index advances to 2.
    3. !self.postinstall.is_empty() is true, so slot 2 is populated.
    4. Before: slot 2 = self.preinstall.slice(...) = b"" → the lifecycle runner executes an empty command for postinstall; ./verify.js never runs.
    5. After: slot 2 = self.postinstall.slice(...) = b"node ./verify.js" → postinstall runs as authored.

    This is user-visible: any native addon that relies on a postinstall step after node-gyp rebuild (verification, file copying, prebuild fallback cleanup) was silently skipping it during bun install.

    Why it doesn't belong in this PR as-is

    This PR is titled "error: recover async stack frames dropped under AsyncLocalStorage" and the description exhaustively covers the AsyncStackTrace.cpp / NodeAsyncHooks.cpp changes without a single word about Scripts.rs or lifecycle scripts. The only test added (24003.test.ts) exercises async stack traces exclusively. REVIEW.md is explicit on both counts:

    • "Every behavioral change ships an automated test in the same PR. 'Verified manually', unnamed 'existing tests', and benchmarks don't count, even for one-liners." This one-liner changes what bun install executes for a whole class of native packages and has zero coverage.
    • "don't ride file-wide standardization on a focused bugfix" — the same principle applies to riding an unrelated bugfix on a focused bugfix. If this regresses, git bisect will point at an async-stack-trace PR, and nobody reviewing async stack traces is scrutinizing lockfile lifecycle-script assembly.

    The most likely explanation is a stray commit from another branch that got picked up in a rebase — the change is correct but orphaned.

    How to fix

    Preferred: drop this hunk from the PR and open a separate PR with a test in test/cli/install/ that installs a fixture package containing binding.gyp + a postinstall that writes a marker file, then asserts the marker exists. Alternatively, if the author wants to keep it here: add that test to this PR and mention the fix in the PR description so reviewers know it's intentional.

Comment thread test/regression/issue/24003.test.ts Outdated
Constructing an AsyncLocalStorage without entering a store installs the
onAppendStackTrace hook (via jsSetAsyncHooksEnabled) while leaving every
await context unwrapped, so the lockstep walk runs and must append nothing.
@robobun

robobun commented Jul 25, 2026

Copy link
Copy Markdown
Collaborator Author

The Scripts.rs hunk was a stray edit that leaked into the worktree during review and was picked up by git add -A; it was dropped in 052714f and is not in the current diff. d3cfcea on main (#35748) already landed the intended preinstall/postinstall fix with coverage.

@claude claude Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Both earlier findings are addressed (nested-VM ordering is now called out as a known limitation in the PR body, and 9f710c7 makes the no-store baseline tests actually install the hook). No new issues from this pass, but this replicates JSC-private getParentGenerator logic and installs a VM-level onAppendStackTrace hook as an interim workaround pending oven-sh/WebKit#347 — worth a maintainer look at the design tradeoff (land the hook now vs. wait for the WebKit bump).

What was reviewed:

  • Lockstep dedup loop — jscStopped transitions once, current advances on both branches, 256-hop cap bounds pathological chains.
  • cellAs empty-JSValue guard vs. asyncStackTraceContext() returning empty on JSVALUE64.
  • Lazy hook install in jsSetAsyncHooksEnabled — no other onAppendStackTrace consumer to conflict with; reached only from ALS/AsyncResource constructors.
  • Refactored appendGeneratorFrame/computeGeneratorBytecodeIndex are byte-for-byte moves of the prior lambdas.
Extended reasoning...

Overview

Adds Bun::appendAsyncLocalStorageStackFrames as a VM::onAppendStackTrace hook that recovers at async <fn> frames dropped when AsyncLocalStorage wraps await-reaction contexts in an InternalFieldTuple. The hook walks VM entry frames to find the origin JSAsyncFunctionGenerator, then replicates JSC's private getParentGenerator walk twice in lockstep (with and without tuple unwrapping) so it appends only the frames JSC's own walk misses. Refactors two existing lambdas (computeBytecodeIndex, appendFrame) into file-static helpers reused by both the existing promise-chain walker and the new hook. Installs the hook lazily from jsSetAsyncHooksEnabled so code that never touches ALS pays nothing. Adds six subprocess regression tests.

Security risks

None. This is diagnostic-only (error stack formatting); it reads JSC-internal fields under AssertNoGC and never calls into user JS. No untrusted-input parsing, allocation sizing, or FFI boundary is touched.

Level of scrutiny

High. The change reaches into JSC internals not normally touched from Bun's side — VMEntryRecord::m_context, JSAsyncFunctionGenerator internal fields, asyncStackTraceContext() — and duplicates logic from a private JSC function that will drift when WebKit updates. It is explicitly framed as an interim workaround with documented limitations (combinator hops still stop under ALS; frame ordering diverges under nested VM entries), and the real fix lives in oven-sh/WebKit#347. Whether to land the interim hook or hold for the WebKit bump is a maintainer call.

Other factors

Both of my earlier inline findings were addressed: the nested-VM-entry ordering caveat is now in the PR body's Known limitations, and 9f710c7 prepends an ALS constructor to the two no-store baseline subprocesses so the lockstep-dedup path is actually exercised. The comment-cop flags were resolved by trimming the block comments. Test coverage is solid (fails on main, passes with fix, covers run/enterWith/Promise.race/mid-chain/no-store baselines). I confirmed onAppendStackTrace has no other consumer in the tree, so the !vm.onAppendStackTrace() guard is just an idempotency check. The refactored helpers are behavior-preserving moves of the previous lambdas.

@robobun

robobun commented Jul 26, 2026

Copy link
Copy Markdown
Collaborator Author

CI is stalled on infra for this branch: #81467 had two step-failed-outside-runner build lanes (also failing on main) and everything downstream went to waiting_failed; the retrigger #81600 has sat 2h with only the :pipeline: job complete, linux-x64 build-cpp and freebsd-aarch64 build-cpp expired in the queue without starting, and nothing running.

No lane that built the code has failed a test. The earlier run on 0c8a853 passed debian-13-x64-asan-test-bun and windows-11-aarch64-test-bun before the push cancellations, and the diff since (lazy hook install + the test tweak in 9f710c7) passes bun bd test test/regression/issue/24003.test.ts, test/js/bun/test/stack.test.ts, test/js/node/v8/capture-stack-trace.test.js, and test/js/node/async_hooks/AsyncLocalStorage.test.ts locally.

Ready for a maintainer to re-run or merge. oven-sh/WebKit#347 has the in-tree unwrap (preview autobuild published at autobuild-preview-pr-347-2a259d26) that will replace this hook on the next WebKit bump.

@robobun

robobun commented Aug 12, 2026

Copy link
Copy Markdown
Collaborator Author

Closing: the in-tree fix this hook was standing in for (oven-sh/WebKit#347, unwrapping the InternalFieldTuple inside getAsyncStackTrace) reached main with the WebKit bump in #35246, and #24003 has been closed as fixed.

Verified on current main (165dc9f) by applying test/regression/issue/24003.test.ts from this PR to a plain main build: all 6 tests pass (als.run(), als.enterWith(), Promise.race under ALS, both no-ALS duplication baselines, and the mid-chain entry case). The Promise.all case listed here as a known limitation of the interim hook also shows the full at async chain on main, so nothing in this PR is still needed.

@robobun robobun closed this Aug 12, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Async stack traces not produced within AsyncLocalStorage

1 participant