From e341d3e4589e5fdf4e0bc2368fa1a4824eadb694 Mon Sep 17 00:00:00 2001 From: Rui Figueira Date: Sun, 6 Sep 2026 00:09:47 +0100 Subject: [PATCH] Avoid inspector stack capture in RPC GC finalizers Skip V8 stack collection for RPC disposal warnings emitted during GC. Add an inspector-enabled regression covering optimized string flattening and explicit disposal. --- src/workerd/api/tests/BUILD.bazel | 9 +++ .../rpc-stub-gc-warning-inspector-test.js | 60 ++++++++++++++++ ...rpc-stub-gc-warning-inspector-test.wd-test | 38 ++++++++++ .../rpc-stub-gc-warning-inspector-trigger.js | 70 +++++++++++++++++++ src/workerd/api/worker-rpc.c++ | 6 +- src/workerd/io/io-context.c++ | 10 +-- src/workerd/io/io-context.h | 6 +- src/workerd/io/worker.c++ | 29 +++++--- src/workerd/io/worker.h | 21 ++++-- 9 files changed, 226 insertions(+), 23 deletions(-) create mode 100644 src/workerd/api/tests/rpc-stub-gc-warning-inspector-test.js create mode 100644 src/workerd/api/tests/rpc-stub-gc-warning-inspector-test.wd-test create mode 100644 src/workerd/api/tests/rpc-stub-gc-warning-inspector-trigger.js diff --git a/src/workerd/api/tests/BUILD.bazel b/src/workerd/api/tests/BUILD.bazel index 2af14468d5a..859a591314f 100644 --- a/src/workerd/api/tests/BUILD.bazel +++ b/src/workerd/api/tests/BUILD.bazel @@ -186,6 +186,15 @@ wd_test( ], ) +wd_test( + src = "rpc-stub-gc-warning-inspector-test.wd-test", + args = ["--experimental"], + data = [ + "rpc-stub-gc-warning-inspector-test.js", + "rpc-stub-gc-warning-inspector-trigger.js", + ], +) + # Test to validate timing semantics for JSRPC streaming responses. # This test verifies that Return events occur when the handler returns, # NOT when the stream is fully consumed. diff --git a/src/workerd/api/tests/rpc-stub-gc-warning-inspector-test.js b/src/workerd/api/tests/rpc-stub-gc-warning-inspector-test.js new file mode 100644 index 00000000000..18c191c45f8 --- /dev/null +++ b/src/workerd/api/tests/rpc-stub-gc-warning-inspector-test.js @@ -0,0 +1,60 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 +import assert from 'node:assert'; + +const WARNING_PREFIXES = [ + 'An RPC stub was not disposed properly', + 'An RPC result was not disposed properly', +]; +const TIMEOUT_MS = 5000; +const POLL_MS = 10; + +let fetchOutcomes = 0; +const warnings = []; + +export default { + tailStream(onset) { + const isFetch = onset.event.info?.type === 'fetch'; + return (event) => { + if ( + event.event.type === 'log' && + event.event.level === 'warn' && + WARNING_PREFIXES.some((prefix) => + event.event.message?.[0]?.startsWith(prefix) + ) + ) { + warnings.push(event.event.message[0]); + } + if (isFetch && event.event.type === 'outcome') { + fetchOutcomes++; + } + }; + }, +}; + +async function waitForFetchOutcome(count) { + const deadline = Date.now() + TIMEOUT_MS; + while (fetchOutcomes < count && Date.now() < deadline) { + await scheduler.wait(POLL_MS); + } + assert.strictEqual( + fetchOutcomes, + count, + `fetch outcome ${count} was not tailed` + ); +} + +export const test = { + async test(ctrl, env) { + let response = await env.TRIGGER.fetch('http://example.com/?dispose'); + assert.strictEqual(await response.text(), 'disposed'); + await waitForFetchOutcome(1); + assert.deepStrictEqual(warnings, []); + + response = await env.TRIGGER.fetch('http://example.com/'); + assert.match(await response.text(), /^leaked: /); + await waitForFetchOutcome(2); + assert.strictEqual(warnings.length, 1); + }, +}; diff --git a/src/workerd/api/tests/rpc-stub-gc-warning-inspector-test.wd-test b/src/workerd/api/tests/rpc-stub-gc-warning-inspector-test.wd-test new file mode 100644 index 00000000000..07dee3dc422 --- /dev/null +++ b/src/workerd/api/tests/rpc-stub-gc-warning-inspector-test.wd-test @@ -0,0 +1,38 @@ +using Workerd = import "/workerd/workerd.capnp"; + +# The test entrypoint is the streaming tail worker: it drives the trigger worker and asserts on +# the leaked-stub warnings that reach it. The trigger runs with the inspector enabled so that the +# warning path also attempts to capture a JS stack trace for the DevTools console. +const unitTests :Workerd.Config = ( + services = [ + ( name = "trigger", + worker = ( + modules = [ + (name = "worker", esModule = embed "rpc-stub-gc-warning-inspector-trigger.js") + ], + compatibilityFlags = [ + "nodejs_compat", + "enable_nodejs_inspector_local_dev", + "experimental", + ], + bindings = [ + (name = "MyService", service = ( + name = "trigger", + entrypoint = "MyService")), + ], + streamingTails = ["rpc-stub-gc-warning-inspector-test"], + ) + ), + ( name = "rpc-stub-gc-warning-inspector-test", + worker = ( + modules = [ + (name = "worker", esModule = embed "rpc-stub-gc-warning-inspector-test.js") + ], + compatibilityFlags = ["nodejs_compat", "experimental"], + bindings = [ + (name = "TRIGGER", service = "trigger"), + ], + ), + ), + ], +); diff --git a/src/workerd/api/tests/rpc-stub-gc-warning-inspector-trigger.js b/src/workerd/api/tests/rpc-stub-gc-warning-inspector-trigger.js new file mode 100644 index 00000000000..1c9863bbda2 --- /dev/null +++ b/src/workerd/api/tests/rpc-stub-gc-warning-inspector-trigger.js @@ -0,0 +1,70 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 +import { RpcTarget, WorkerEntrypoint } from 'cloudflare:workers'; + +class Counter extends RpcTarget { + increment() { + return 1; + } +} + +export class MyService extends WorkerEntrypoint { + getCounter() { + return new Counter(); + } +} + +const chunk = 'x'.repeat(4096); + +function buildConsString() { + let result = chunk; + for (let i = 0; i < 16; i++) result += chunk; + return result; +} + +// charCodeAt() flattens the ConsString. Once V8 optimizes this function, an allocation failure +// can start a minor GC from a runtime call whose optimized frame has no deoptimization metadata. +// If a leaked-stub finalizer runs in that GC and tries to capture a JS stack trace for the +// inspector, V8 aborts the process. +function scan(str) { + let hash = 0; + for (let i = 0; i < str.length; i += 4093) { + hash = (hash * 31 + str.charCodeAt(i)) | 0; + } + return hash; +} + +export default { + async fetch(request, env) { + const dispose = new URL(request.url).searchParams.has('dispose'); + + if (dispose) { + let stub = await env.MyService.getCounter(); + stub[Symbol.dispose](); + stub = null; + gc(); + gc(); + return new Response('disposed'); + } + + let hash = 0; + for (let i = 0; i < 30000; i++) hash = (hash + scan(buildConsString())) | 0; + + let stubs = []; + for (let i = 0; i < 32; i++) { + const stub = await env.MyService.getCounter(); + await stub.increment(); + stubs.push(stub); + } + stubs = null; + + // Allocation-driven collections in scan() exercise the original crash. Explicit collections + // ensure that the warning is emitted even when heap sizing does not trigger one in this loop. + for (let i = 0; i < 20000; i++) hash = (hash + scan(buildConsString())) | 0; + gc(); + gc(); + + return new Response(`leaked: ${hash}`); + }, +}; diff --git a/src/workerd/api/worker-rpc.c++ b/src/workerd/api/worker-rpc.c++ index 4c48c5709f1..653a4b0385d 100644 --- a/src/workerd/api/worker-rpc.c++ +++ b/src/workerd/api/worker-rpc.c++ @@ -849,7 +849,8 @@ JsRpcStub::~JsRpcStub() noexcept(false) { "let the other side know that you are no longer using them. You cannot rely on " "the garbage collector for this because it may take arbitrarily long before actually " "collecting unreachable objects. As a shortcut, calling dispose() on the result of " - "an RPC call disposes all stubs within it."_kj); + "an RPC call disposes all stubs within it."_kj, + CaptureInspectorStackTrace::NO); } } @@ -885,7 +886,8 @@ RpcStubDisposalGroup::~RpcStubDisposalGroup() noexcept(false) { "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. You cannot rely on " "the garbage collector for this because it may take arbitrarily long before actually " - "collecting unreachable objects."_kj); + "collecting unreachable objects."_kj, + CaptureInspectorStackTrace::NO); } } } else { diff --git a/src/workerd/io/io-context.c++ b/src/workerd/io/io-context.c++ index 278e72ade9f..710db761e31 100644 --- a/src/workerd/io/io-context.c++ +++ b/src/workerd/io/io-context.c++ @@ -420,12 +420,14 @@ bool IoContext::hasWarningHandler() { ::kj::_::Debug::shouldLog(::kj::LogSeverity::INFO); } -void IoContext::logWarning(kj::StringPtr description) { - KJ_REQUIRE_NONNULL(currentLock).logWarning(description); +void IoContext::logWarning( + kj::StringPtr description, CaptureInspectorStackTrace captureStackTrace) { + KJ_REQUIRE_NONNULL(currentLock).logWarning(description, captureStackTrace); } -void IoContext::logWarningOnce(kj::StringPtr description) { - KJ_REQUIRE_NONNULL(currentLock).logWarningOnce(description); +void IoContext::logWarningOnce( + kj::StringPtr description, CaptureInspectorStackTrace captureStackTrace) { + KJ_REQUIRE_NONNULL(currentLock).logWarningOnce(description, captureStackTrace); } void IoContext::logErrorOnce(kj::StringPtr description) { diff --git a/src/workerd/io/io-context.h b/src/workerd/io/io-context.h index 189adf9b464..36de74b4bd2 100644 --- a/src/workerd/io/io-context.h +++ b/src/workerd/io/io-context.h @@ -391,11 +391,13 @@ class IoContext final: public kj::Refcounted, private kj::TaskSet::ErrorHandler // Log a warning. Emits to the Chrome DevTools inspector (if connected), stderr, and to the // streaming tail worker tracer (if active). - void logWarning(kj::StringPtr description); + void logWarning(kj::StringPtr description, + CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES); // Log a warning, deduplicating so that each unique message is only logged once for the lifetime // of an isolate. Emits to the same destinations as logWarning(). - void logWarningOnce(kj::StringPtr description); + void logWarningOnce(kj::StringPtr description, + CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES); // Log an internal error message. Deduplicates log messages such that a single unique message will // only be logged once for the lifetime of an isolate. diff --git a/src/workerd/io/worker.c++ b/src/workerd/io/worker.c++ index a2ee914b8cf..f4a778b538d 100644 --- a/src/workerd/io/worker.c++ +++ b/src/workerd/io/worker.c++ @@ -2532,14 +2532,16 @@ bool Worker::Lock::isInspectorEnabled() { return worker.script->isolate->impl->inspector != kj::none; } -void Worker::Lock::logWarning(kj::StringPtr description) { +void Worker::Lock::logWarning( + kj::StringPtr description, CaptureInspectorStackTrace captureStackTrace) { // const_cast OK because we are a lock on this isolate. - const_cast(worker.getIsolate()).logWarning(description, *this); + const_cast(worker.getIsolate()).logWarning(description, *this, captureStackTrace); } -void Worker::Lock::logWarningOnce(kj::StringPtr description) { +void Worker::Lock::logWarningOnce( + kj::StringPtr description, CaptureInspectorStackTrace captureStackTrace) { // const_cast OK because we are a lock on this isolate. - const_cast(worker.getIsolate()).logWarningOnce(description, *this); + const_cast(worker.getIsolate()).logWarningOnce(description, *this, captureStackTrace); } void Worker::Lock::logErrorOnce(kj::StringPtr description) { @@ -3572,10 +3574,11 @@ void Worker::Isolate::disconnectInspector() { impl->inspectorClient->resetChannel(); } -void Worker::Isolate::logWarning(kj::StringPtr description, Lock& lock) { +void Worker::Isolate::logWarning( + kj::StringPtr description, Lock& lock, CaptureInspectorStackTrace captureStackTrace) { if (impl->inspector != kj::none) { JSG_WITHIN_CONTEXT_SCOPE(lock, lock.getContext(), [&](jsg::Lock& js) { - logMessage(js, static_cast(cdp::LogType::WARNING), description); + logMessage(js, static_cast(cdp::LogType::WARNING), description, captureStackTrace); }); } @@ -3608,9 +3611,10 @@ void Worker::Isolate::logWarning(kj::StringPtr description, Lock& lock) { } } -void Worker::Isolate::logWarningOnce(kj::StringPtr description, Lock& lock) { +void Worker::Isolate::logWarningOnce( + kj::StringPtr description, Lock& lock, CaptureInspectorStackTrace captureStackTrace) { impl->warningOnceDescriptions.findOrCreate(description, [&] { - logWarning(description, lock); + logWarning(description, lock, captureStackTrace); return kj::str(description); }); } @@ -3622,7 +3626,10 @@ void Worker::Isolate::logErrorOnce(kj::StringPtr description) { }); } -void Worker::Isolate::logMessage(jsg::Lock& js, uint16_t type, kj::StringPtr description) { +void Worker::Isolate::logMessage(jsg::Lock& js, + uint16_t type, + kj::StringPtr description, + CaptureInspectorStackTrace captureStackTrace) { if (impl->inspector != kj::none) { // We want to log a warning to the devtools console, as if `console.warn()` were called. // However, the only public interface to call the real `console.warn()` is via JavaScript, @@ -3653,7 +3660,9 @@ void Worker::Isolate::logMessage(jsg::Lock& js, uint16_t type, kj::StringPtr des params.initArgs(1)[0].initString().setValue(description); params.setExecutionContextId(v8_inspector::V8ContextInfo::executionContextId(js.v8Context())); params.setTimestamp(impl->inspectorClient->currentTimeMS()); - stackTraceToCDP(js, params.initStackTrace()); + if (captureStackTrace) { + stackTraceToCDP(js, params.initStackTrace()); + } auto notification = getCdpJsonCodec().encode(event); KJ_IF_SOME(i, currentInspectorSession) { diff --git a/src/workerd/io/worker.h b/src/workerd/io/worker.h index 9ce9f3f4e77..0a6c90096d3 100644 --- a/src/workerd/io/worker.h +++ b/src/workerd/io/worker.h @@ -42,6 +42,8 @@ namespace workerd { WD_STRONG_BOOL(StructuredLogging); WD_STRONG_BOOL(ProcessStdioPrefixed); +// Inspector stack capture enters V8 and is unsafe from GC finalizers. +WD_STRONG_BOOL(CaptureInspectorStackTrace); namespace api { class DurableObjectState; @@ -461,11 +463,15 @@ class Worker::Isolate: public kj::AtomicRefcounted { kj::WebSocket& webSocket) const; // Log a warning to the inspector if attached, and log an INFO severity message. - void logWarning(kj::StringPtr description, Worker::Lock& lock); + void logWarning(kj::StringPtr description, + Worker::Lock& lock, + CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES); // logWarningOnce() only logs the warning if it has not already been logged for this // worker instance. - void logWarningOnce(kj::StringPtr description, Worker::Lock& lock); + void logWarningOnce(kj::StringPtr description, + Worker::Lock& lock, + CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES); // Log an ERROR severity message, if it has not already been logged for this worker instance. void logErrorOnce(kj::StringPtr description); @@ -570,7 +576,10 @@ class Worker::Isolate: public kj::AtomicRefcounted { // Log a message as if with console.{log,warn,error,etc}. `type` must be one of the cdp::LogType // enum, which unfortunately we cannot forward-declare, ugh. - void logMessage(jsg::Lock& js, uint16_t type, kj::StringPtr description); + void logMessage(jsg::Lock& js, + uint16_t type, + kj::StringPtr description, + CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES); class SubrequestClient; class ResponseStreamWrapper; @@ -728,8 +737,10 @@ class Worker::Lock { v8::Local getContext(); bool isInspectorEnabled(); - void logWarning(kj::StringPtr description); - void logWarningOnce(kj::StringPtr description); + void logWarning(kj::StringPtr description, + CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES); + void logWarningOnce(kj::StringPtr description, + CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES); void logErrorOnce(kj::StringPtr description);