Skip to content

About

Reproducer: dd-trace-js retains express.middleware spans unbounded (AsyncLocalStorage frame capture) -> OOM

Resources

Stars

0 stars

Watchers

0 watching

Forks

Repository files navigation

dd-trace-js express.middleware span memory leak → OOM — reproducer

TL;DR

With dd-trace enabled, an express service under sustained traffic accumulates express.middleware spans in the heap strictly without bound and eventually crashes with FATAL ERROR: ... JavaScript heap out of memory. Post-GC retained heap climbs monotonically with request count — no plateau — until OOM (reproduce.sh). The identical load with dd-trace disabled stays bounded and survives indefinitely. Because the climb never plateaus, a larger heap cap only delays the crash (time-to-OOM scales ~linearly with the cap), which is the signature of a real leak rather than an under-provisioned working set.

Root cause

dd-trace activates the current span with AsyncLocalStorage.enterWith({ ...store, span }) (not run()) — see packages/dd-trace/src/plugins/tracing.js (legacyStorage.enterWith), packages/dd-trace/src/plugins/plugin.js (enter()), and the express/router middleware activation in packages/datadog-plugin-router/src/index.js. enterWith mutates the current async-context frame in place to point at the middleware span. Because express runs the whole middleware chain synchronously on the frame established when the request began, that frame ends up holding the middleware span (and, via each span's _store, the entire ~20-deep parent chain).

The strictly-unbounded part: any async resource created during request handling that is never released snapshots that frame — and therefore the whole middleware span chain — and pins it for the life of the process, independent of the HTTP socket. Under AsyncContextFrame (Node's default AsyncLocalStorage backend), an AsyncResource/Promise/timer created in request scope captures the current frame at creation. Real request handlers create such never-released handles constantly: a sharedb document/query subscription, a global event-bus listener, a queued callback on a long-lived object. Each such request permanently retains ~a full middleware span chain, so retained spans grow linearly with request count, forever — no plateau — until the heap is exhausted and the process OOMs.

This matches production: the prod service climbs to its 3072 MiB ceiling and crashes with JavaScript heap out of memory over ~a day, with ~87 k retained spans at 12 h — far more than the number of concurrent connections (the tell-tale sign it is request-count driven, not socket-bound). ~93 % of the leaked spans are express.middleware.

The reproducer models this with one never-destroyed AsyncResource per request kept in a module-level array (server.js, LEAK_MODE=listener). (An earlier variant used a long-lived timer; that only produces a large-but-bounded working set that plateaus and releases when the timers fire — it is not a true leak. The never-destroyed AsyncResource is.)

Retainer chain (proven; verify-retainer.js)

The load driver fires requests over keep-alive sockets and then closes the sockets; after GC, the surviving DatadogSpan objects are still anchored — one per request, via the never-destroyed AsyncResource, not by any socket and not by a timer. Walking forward from an AsyncResource to the span (top RETAINS bottom):

AsyncResource        [Symbol(context_frame)]   the frame snapshotted at creation
  -> AsyncContextFrame
  -> <array>         [internal table]
  -> Object          [internal 6]              the { ...store, span } store
  -> DatadogSpan     [property: span]          the pinned express.middleware span

verify-retainer.js reports 205 never-destroyed AsyncResource anchors (one per request in the probe), each holding a DatadogSpan through its captured AsyncContextFrame. The spans survive socket close, confirming the anchor is the never-destroyed resource, not the socket or a timer.

On Node 18 the same store is reached through a legacy async_hooks handle (Symbol(kResourceStore) + dd-trace's stores WeakMap; see datadog-core/src/storage.js). The leak reproduces on both Node 18 and Node 24, so --no-async-context-frame does not fix it.

Versions

Component Version
dd-trace 5.110.0
express 5.2.1 (^5)
node 24.16.0 (also reproduced on 18.20.8)

Reproduce the OOM

npm install
export NODE_BIN=~/.nvm/versions/node/v24.16.0/bin/node   # any Node 24 (or 18) binary
./reproduce.sh

reproduce.sh runs dd-trace ON at two heap caps (it OOMs at both; the larger cap OOMs later → proof it never plateaus) and the dd-trace OFF control at both caps (survives past the ON crash times). The server has 40 trivial (req,res,next)=>next() middlewares and, per request, creates an AsyncResource that is never destroyed and kept in a module-level array (LEAK_MODE=listener) — standing in for a real prod handle that is registered per request and never cleaned up (a sharedb subscription, a global-bus listener, a queued callback). oom-load.js fires requests over a small keep-alive pool and periodically closes + recreates the pool, proving the accumulation is not socket-bound.

1. dd-trace amplifies the per-request leak ~407× (the decisive proof)

measure-per-request.js fires fixed batches of 20 000 requests and measures the post-GC retained-heap growth per request, dd-trace ON vs OFF (40 middlewares). The ON per-request cost is constant across every batch — the definition of strictly linear, no-plateau accumulation:

dd-trace ON:
  after  20000 reqs: postGC heapUsed= 717.5MB  (+700.7MB = 36737 B/req)
  after  40000 reqs: postGC heapUsed=1418.4MB  (+700.9MB = 36748 B/req)
  after  60000 reqs: postGC heapUsed=2119.2MB  (+700.8MB = 36741 B/req)
  after  80000 reqs: postGC heapUsed=2820.1MB  (+700.8MB = 36745 B/req)
  after 100000 reqs: postGC heapUsed=3520.6MB  (+700.6MB = 36730 B/req)
dd-trace OFF:
  after  20000 reqs: postGC heapUsed=  10.7MB  (+2.6MB   =   135 B/req)
  after 100000 reqs: postGC heapUsed=  17.6MB  (+1.6MB   =    83 B/req)

  ON  : 36739 bytes/request retained     OFF : 90 bytes/request retained
  => dd-trace amplifies the per-request leak by ~407x.

The ~36.7 KB/request is the ~40 DatadogSpan middleware objects + trace context pinned via the never-destroyed AsyncResource's captured async-context frame. With dd-trace OFF the same AsyncResource captures an empty frame → ~90 bytes. 407× is the leak.

2. Strictly monotonic post-GC climb — no plateau

Post-GC retained heapUsed (GC forced before each sample), dd-trace ON, 40 middlewares. Every sample strictly greater than the last, dead-linear (~70 MB/s here), no plateau:

[heap] t=2s  heapUsed=  16.8MB     [heap] t=18s heapUsed=1378.7MB
[heap] t=4s  heapUsed= 146.3MB     [heap] t=23s heapUsed=1632.1MB
[heap] t=8s  heapUsed= 614.7MB     [heap] t=27s heapUsed=1847.8MB
[heap] t=12s heapUsed= 968.7MB     [heap] t=31s heapUsed=2067.8MB
[heap] t=14s heapUsed=1102.9MB     [heap] t=33s heapUsed=2191.0MB   (still climbing)

3. "The cap only delays it" — OOM at two caps

dd-trace ON crashes with the V8 fatal error at both caps; the larger cap OOMs later. A bounded working set would plateau below the larger cap and never crash there — this does crash.

heap cap (--max-old-space-size) time-to-OOM (leak phase) result
256 MB 16 s FATAL ERROR: Ineffective mark-compacts near heap limit ... JavaScript heap out of memory
512 MB 22 s FATAL ERROR: Ineffective mark-compacts near heap limit ... JavaScript heap out of memory

Crash output (V8 fatal error + native stack, from /tmp/oom-A-small.log):

<--- Last few GCs --->
... Mark-Compact ... MB ... allocation failure; scavenge might not succeed
FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
----- Native stack trace -----
 1: ... node::OOMErrorHandler(char const*, v8::OOMDetails const&)

4. Control (dd-trace OFF) survives

Same load and same caps, DD_TRACE_ENABLED=false: no spans are pinned, so the process survives ~9× the ON crash time at the same cap without OOM (measured: crashed=0 at both 256 and 512 MB over a 142 s window; the residual ~90 B/req climb is 407× slower and stays far from the ceiling).

WHY BOTH ON AND OFF USE the never-destroyed AsyncResource: strict unboundedness requires an unbounded registry of frame-capturing handles (that is the real prod pattern). The handle objects themselves are tiny (~90 B); what makes dd-trace ON a leak is that each handle also pins a whole middleware span chain (~36.7 KB). The 407× per-request ratio (section 1) isolates dd-trace as the cause independent of the harness.

The mitigation control (A/B/C/D)

run-all.sh isolates the mechanism with the churn probe (churn-probe.js): batches of idle keep-alive sockets, one request each. Post-GC heapUsed / retained DatadogSpan count per idle socket:

idle sockets A: dd-trace ON B: dd-trace OFF C: middleware tracing OFF D: keep-alive OFF
0 16.8MB / 1 8.0MB / 0 16.8MB / 1 16.8MB / 1
100 18.9MB / 2301 8.6MB / 0 17.1MB / 101 16.8MB / 1
200 21.3MB / 4601 8.8MB / 0 17.7MB / 201 17.0MB / 1
300 22.4MB / 6901 8.3MB / 0 17.1MB / 301 15.9MB / 1
  • C (DD_TRACE_MIDDLEWARE_TRACING_ENABLED=false, or express plugin middleware:false) removes the express.middleware spans: ~96 % fewer retained spans (1 root web.request span per unit instead of ~23). This is the fix.
  • B (dd-trace off) is the zero-leak baseline.
  • D (keep-alive disabled) shows the socket-pinned working set disappears when sockets are fresh per request — but note the true OOM driver above is not socket-pinned; it is the per-request captured frame, which is why reproduce.sh OOMs even while churning/closing sockets.

Span-name breakdown of the retained set (count-span-names.js): 95.5 % express.middleware (router.middleware), 4.5 % web.request — matching prod's ~93 %.

Files

  • mock-agent.js — agent on 127.0.0.1:8126 that 200s everything (so trace flushes SUCCEED; the flush buffer is not what leaks).
  • tracer.js — require('dd-trace').init({ startupLogs:false, flushInterval:1000 }).
  • server.js — express app, 40 trivial middlewares + route. LEAK_MODE=listener keeps one never-destroyed AsyncResource per request (the frame-capturing handle). HEAP_LOG_MS logs heapUsed (HEAP_LOG_NOGC=1 = raw, else post-GC). A separate raw-http control endpoint (:3001) runs global.gc() and reports post-GC heapUsed + retained DatadogSpan count via a snapshot.
  • oom-load.js — continuous load driver that churns + closes its keep-alive pool.
  • measure-per-request.js — measures post-GC retained bytes/request, dd-trace ON vs OFF (the ~407× amplification; the core proof).
  • reproduce.sh — the OOM proof: dd-trace ON OOMs at two caps, OFF control survives both.
  • verify-retainer.js — walks a heap snapshot to print the AsyncResource → AsyncContextFrame → store → DatadogSpan chain (after sockets are closed).
  • run-all.sh + churn-probe.js — the A/B/C/D mitigation table.
  • count-span-names.js — tallies operation names of the retained spans.
  • harness.js / load.js — continuous-load variant (shows the bounded socket working set).
  • Investigation probes (kept for reference): probe-churn-close.js, probe-server-timeout.js, probe-abort.js, probe-longtimer.js — they show that simple churn+close, server-idle-close, and aborted requests all RELEASE the spans (bounded); only a never-released captured frame is unbounded.

Notes

  • The leak is request-count driven and strictly unbounded, not bounded by concurrent sockets. A fixed keep-alive pool with no never-released per-request resource only pins a bounded working set (the socket frame is overwritten each request). The unbounded, OOM-causing path is a never-released async resource created in request scope capturing the middleware span's frame — which is what real handlers do constantly (subscriptions, listeners, queued callbacks).
  • Simple connection churn+close, server-side idle-timeout close, and aborted requests all RELEASE the spans (verified) — they are bounded and do not OOM on their own.
  • Reproduced on Node 24.16.0 (AsyncContextFrame) and Node 18.20.8 (legacy async_hooks).
  • Fix: DD_TRACE_MIDDLEWARE_TRACING_ENABLED=false (or middleware:false on the express plugin) removes ~93–96 % of the leaked spans.

About

Reproducer: dd-trace-js retains express.middleware spans unbounded (AsyncLocalStorage frame capture) -> OOM

Resources

Stars

0 stars

Watchers

0 watching

Forks

Releases

Packages

Contributors

Languages