Skip to content

Include the creation stack trace in the "RPC stub/result was not disposed properly" warning #6879

Description

@danieltroger

Problem

The undisposed-stub warnings emitted from src/workerd/api/worker-rpc.c++ (~JsRpcStub() and the RpcStubDisposalGroup GC path) are static strings:

An RPC result was not disposed properly. One of the RPC calls you made expects you to call dispose() on the return value, but you didn't do so. …

For any non-trivial Worker this is effectively undiagnosable:

  • The message carries no information about which RPC call produced the leaked stub/result.
  • It fires at GC time, arbitrarily far from the leak, so attribution via request context is misleading — the warning gets blamed on whatever invocation happens to be running when GC fires.
  • logWarningOnce() dedupes per unique message per isolate lifetime (io-context.h:353), so one logged warning can represent thousands of leaks across multiple distinct call sites — and after fixing a suspected site you can't tell whether the remaining warnings are the same leak or a different one.

Real-world case: one of our production Workers (Workflows + several Durable Objects, dozens of RPC call sites) logs ~4.5k of these per day. We spent a while trying to attribute them and failed: code review produced a plausible-but-wrong suspect (env.<WORKFLOW>.create() results — which turn out to be plain InstanceImpl wrappers around a Fetcher, not stubs, and don't warn), and a purpose-built minimal worker that leaked ~450 RPC results produced zero warnings (GC timing + IoContext::tryCurrent() + once-per-isolate dedup make the warning nearly unreproducible on demand). We still don't know which call site leaks.

What happens today

At warning time, the logging layer (with the inspector attached) captures the current stack — logWarningOnce()logMessage()stackTraceToCDP()v8::StackTrace::CurrentStackTrace(). That stack is:

  1. the wrong stack — it points at whatever JS happened to be executing/allocating when the GC that collected the stub ran, not at the code that made the RPC call; and
  2. the trigger of JsRpcStub destructor crashes workerd via CaptureDetailedStackTrace during V8 GC epilogue (SIGTRAP) #6842CaptureDetailedStackTrace inside a GC epilogue callback hits a fatal V8 assertion (SIGTRAP) and kills workerd.

Proposal

Capture the stack (or even just the top application frame, script:line) at creation of the disposable — when a JsRpcStub is constructed / when an RPC result carrying stubs is returned to the app — store it on the stub or its disposal group, and include it in the warning at destruction time.

  • Creation happens during normal JS execution, where stack capture is safe. The GC-time path would then only concatenate a pre-captured string — no V8 stack APIs inside the GC epilogue, which also removes the crash trigger in JsRpcStub destructor crashes workerd via CaptureDetailedStackTrace during V8 GC epilogue (SIGTRAP) #6842.
  • If per-call capture is too expensive to do unconditionally, gate it: dev/preview only, inspector-attached only, behind a flag (à la Node's --trace-warnings), or sampled. Even dev-only capture would make the warning actionable, since leaky call sites are generally the same in dev and prod.

The existing TODO(cleanup) in ~JsRpcStub() about logging at IoContext teardown instead of GC time is adjacent but orthogonal: deterministic timing would be nice, but without a creation site the warning still can't be attributed to a call site. Creation-site capture helps regardless of when the warning is logged.

Related: #6842 (crash caused by the current at-warning-time stack capture).

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions