Skip to content

Commit e341d3e

Browse files
committed
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.
1 parent dd8133e commit e341d3e

9 files changed

Lines changed: 226 additions & 23 deletions

src/workerd/api/tests/BUILD.bazel

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -186,6 +186,15 @@ wd_test(
186186
],
187187
)
188188

189+
wd_test(
190+
src = "rpc-stub-gc-warning-inspector-test.wd-test",
191+
args = ["--experimental"],
192+
data = [
193+
"rpc-stub-gc-warning-inspector-test.js",
194+
"rpc-stub-gc-warning-inspector-trigger.js",
195+
],
196+
)
197+
189198
# Test to validate timing semantics for JSRPC streaming responses.
190199
# This test verifies that Return events occur when the handler returns,
191200
# NOT when the stream is fully consumed.
Lines changed: 60 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,60 @@
1+
// Copyright (c) 2026 Cloudflare, Inc.
2+
// Licensed under the Apache 2.0 license found in the LICENSE file or at:
3+
// https://opensource.org/licenses/Apache-2.0
4+
import assert from 'node:assert';
5+
6+
const WARNING_PREFIXES = [
7+
'An RPC stub was not disposed properly',
8+
'An RPC result was not disposed properly',
9+
];
10+
const TIMEOUT_MS = 5000;
11+
const POLL_MS = 10;
12+
13+
let fetchOutcomes = 0;
14+
const warnings = [];
15+
16+
export default {
17+
tailStream(onset) {
18+
const isFetch = onset.event.info?.type === 'fetch';
19+
return (event) => {
20+
if (
21+
event.event.type === 'log' &&
22+
event.event.level === 'warn' &&
23+
WARNING_PREFIXES.some((prefix) =>
24+
event.event.message?.[0]?.startsWith(prefix)
25+
)
26+
) {
27+
warnings.push(event.event.message[0]);
28+
}
29+
if (isFetch && event.event.type === 'outcome') {
30+
fetchOutcomes++;
31+
}
32+
};
33+
},
34+
};
35+
36+
async function waitForFetchOutcome(count) {
37+
const deadline = Date.now() + TIMEOUT_MS;
38+
while (fetchOutcomes < count && Date.now() < deadline) {
39+
await scheduler.wait(POLL_MS);
40+
}
41+
assert.strictEqual(
42+
fetchOutcomes,
43+
count,
44+
`fetch outcome ${count} was not tailed`
45+
);
46+
}
47+
48+
export const test = {
49+
async test(ctrl, env) {
50+
let response = await env.TRIGGER.fetch('http://example.com/?dispose');
51+
assert.strictEqual(await response.text(), 'disposed');
52+
await waitForFetchOutcome(1);
53+
assert.deepStrictEqual(warnings, []);
54+
55+
response = await env.TRIGGER.fetch('http://example.com/');
56+
assert.match(await response.text(), /^leaked: /);
57+
await waitForFetchOutcome(2);
58+
assert.strictEqual(warnings.length, 1);
59+
},
60+
};
Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,38 @@
1+
using Workerd = import "/workerd/workerd.capnp";
2+
3+
# The test entrypoint is the streaming tail worker: it drives the trigger worker and asserts on
4+
# the leaked-stub warnings that reach it. The trigger runs with the inspector enabled so that the
5+
# warning path also attempts to capture a JS stack trace for the DevTools console.
6+
const unitTests :Workerd.Config = (
7+
services = [
8+
( name = "trigger",
9+
worker = (
10+
modules = [
11+
(name = "worker", esModule = embed "rpc-stub-gc-warning-inspector-trigger.js")
12+
],
13+
compatibilityFlags = [
14+
"nodejs_compat",
15+
"enable_nodejs_inspector_local_dev",
16+
"experimental",
17+
],
18+
bindings = [
19+
(name = "MyService", service = (
20+
name = "trigger",
21+
entrypoint = "MyService")),
22+
],
23+
streamingTails = ["rpc-stub-gc-warning-inspector-test"],
24+
)
25+
),
26+
( name = "rpc-stub-gc-warning-inspector-test",
27+
worker = (
28+
modules = [
29+
(name = "worker", esModule = embed "rpc-stub-gc-warning-inspector-test.js")
30+
],
31+
compatibilityFlags = ["nodejs_compat", "experimental"],
32+
bindings = [
33+
(name = "TRIGGER", service = "trigger"),
34+
],
35+
),
36+
),
37+
],
38+
);
Lines changed: 70 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,70 @@
1+
// Copyright (c) 2026 Cloudflare, Inc.
2+
// Licensed under the Apache 2.0 license found in the LICENSE file or at:
3+
// https://opensource.org/licenses/Apache-2.0
4+
import { RpcTarget, WorkerEntrypoint } from 'cloudflare:workers';
5+
6+
class Counter extends RpcTarget {
7+
increment() {
8+
return 1;
9+
}
10+
}
11+
12+
export class MyService extends WorkerEntrypoint {
13+
getCounter() {
14+
return new Counter();
15+
}
16+
}
17+
18+
const chunk = 'x'.repeat(4096);
19+
20+
function buildConsString() {
21+
let result = chunk;
22+
for (let i = 0; i < 16; i++) result += chunk;
23+
return result;
24+
}
25+
26+
// charCodeAt() flattens the ConsString. Once V8 optimizes this function, an allocation failure
27+
// can start a minor GC from a runtime call whose optimized frame has no deoptimization metadata.
28+
// If a leaked-stub finalizer runs in that GC and tries to capture a JS stack trace for the
29+
// inspector, V8 aborts the process.
30+
function scan(str) {
31+
let hash = 0;
32+
for (let i = 0; i < str.length; i += 4093) {
33+
hash = (hash * 31 + str.charCodeAt(i)) | 0;
34+
}
35+
return hash;
36+
}
37+
38+
export default {
39+
async fetch(request, env) {
40+
const dispose = new URL(request.url).searchParams.has('dispose');
41+
42+
if (dispose) {
43+
let stub = await env.MyService.getCounter();
44+
stub[Symbol.dispose]();
45+
stub = null;
46+
gc();
47+
gc();
48+
return new Response('disposed');
49+
}
50+
51+
let hash = 0;
52+
for (let i = 0; i < 30000; i++) hash = (hash + scan(buildConsString())) | 0;
53+
54+
let stubs = [];
55+
for (let i = 0; i < 32; i++) {
56+
const stub = await env.MyService.getCounter();
57+
await stub.increment();
58+
stubs.push(stub);
59+
}
60+
stubs = null;
61+
62+
// Allocation-driven collections in scan() exercise the original crash. Explicit collections
63+
// ensure that the warning is emitted even when heap sizing does not trigger one in this loop.
64+
for (let i = 0; i < 20000; i++) hash = (hash + scan(buildConsString())) | 0;
65+
gc();
66+
gc();
67+
68+
return new Response(`leaked: ${hash}`);
69+
},
70+
};

src/workerd/api/worker-rpc.c++

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -849,7 +849,8 @@ JsRpcStub::~JsRpcStub() noexcept(false) {
849849
"let the other side know that you are no longer using them. You cannot rely on "
850850
"the garbage collector for this because it may take arbitrarily long before actually "
851851
"collecting unreachable objects. As a shortcut, calling dispose() on the result of "
852-
"an RPC call disposes all stubs within it."_kj);
852+
"an RPC call disposes all stubs within it."_kj,
853+
CaptureInspectorStackTrace::NO);
853854
}
854855
}
855856

@@ -885,7 +886,8 @@ RpcStubDisposalGroup::~RpcStubDisposalGroup() noexcept(false) {
885886
"An RPC result was not disposed properly. One of the RPC calls you made expects you "
886887
"to call dispose() on the return value, but you didn't do so. You cannot rely on "
887888
"the garbage collector for this because it may take arbitrarily long before actually "
888-
"collecting unreachable objects."_kj);
889+
"collecting unreachable objects."_kj,
890+
CaptureInspectorStackTrace::NO);
889891
}
890892
}
891893
} else {

src/workerd/io/io-context.c++

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -420,12 +420,14 @@ bool IoContext::hasWarningHandler() {
420420
::kj::_::Debug::shouldLog(::kj::LogSeverity::INFO);
421421
}
422422

423-
void IoContext::logWarning(kj::StringPtr description) {
424-
KJ_REQUIRE_NONNULL(currentLock).logWarning(description);
423+
void IoContext::logWarning(
424+
kj::StringPtr description, CaptureInspectorStackTrace captureStackTrace) {
425+
KJ_REQUIRE_NONNULL(currentLock).logWarning(description, captureStackTrace);
425426
}
426427

427-
void IoContext::logWarningOnce(kj::StringPtr description) {
428-
KJ_REQUIRE_NONNULL(currentLock).logWarningOnce(description);
428+
void IoContext::logWarningOnce(
429+
kj::StringPtr description, CaptureInspectorStackTrace captureStackTrace) {
430+
KJ_REQUIRE_NONNULL(currentLock).logWarningOnce(description, captureStackTrace);
429431
}
430432

431433
void IoContext::logErrorOnce(kj::StringPtr description) {

src/workerd/io/io-context.h

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -391,11 +391,13 @@ class IoContext final: public kj::Refcounted, private kj::TaskSet::ErrorHandler
391391

392392
// Log a warning. Emits to the Chrome DevTools inspector (if connected), stderr, and to the
393393
// streaming tail worker tracer (if active).
394-
void logWarning(kj::StringPtr description);
394+
void logWarning(kj::StringPtr description,
395+
CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES);
395396

396397
// Log a warning, deduplicating so that each unique message is only logged once for the lifetime
397398
// of an isolate. Emits to the same destinations as logWarning().
398-
void logWarningOnce(kj::StringPtr description);
399+
void logWarningOnce(kj::StringPtr description,
400+
CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES);
399401

400402
// Log an internal error message. Deduplicates log messages such that a single unique message will
401403
// only be logged once for the lifetime of an isolate.

src/workerd/io/worker.c++

Lines changed: 19 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -2532,14 +2532,16 @@ bool Worker::Lock::isInspectorEnabled() {
25322532
return worker.script->isolate->impl->inspector != kj::none;
25332533
}
25342534

2535-
void Worker::Lock::logWarning(kj::StringPtr description) {
2535+
void Worker::Lock::logWarning(
2536+
kj::StringPtr description, CaptureInspectorStackTrace captureStackTrace) {
25362537
// const_cast OK because we are a lock on this isolate.
2537-
const_cast<Isolate&>(worker.getIsolate()).logWarning(description, *this);
2538+
const_cast<Isolate&>(worker.getIsolate()).logWarning(description, *this, captureStackTrace);
25382539
}
25392540

2540-
void Worker::Lock::logWarningOnce(kj::StringPtr description) {
2541+
void Worker::Lock::logWarningOnce(
2542+
kj::StringPtr description, CaptureInspectorStackTrace captureStackTrace) {
25412543
// const_cast OK because we are a lock on this isolate.
2542-
const_cast<Isolate&>(worker.getIsolate()).logWarningOnce(description, *this);
2544+
const_cast<Isolate&>(worker.getIsolate()).logWarningOnce(description, *this, captureStackTrace);
25432545
}
25442546

25452547
void Worker::Lock::logErrorOnce(kj::StringPtr description) {
@@ -3572,10 +3574,11 @@ void Worker::Isolate::disconnectInspector() {
35723574
impl->inspectorClient->resetChannel();
35733575
}
35743576

3575-
void Worker::Isolate::logWarning(kj::StringPtr description, Lock& lock) {
3577+
void Worker::Isolate::logWarning(
3578+
kj::StringPtr description, Lock& lock, CaptureInspectorStackTrace captureStackTrace) {
35763579
if (impl->inspector != kj::none) {
35773580
JSG_WITHIN_CONTEXT_SCOPE(lock, lock.getContext(), [&](jsg::Lock& js) {
3578-
logMessage(js, static_cast<uint16_t>(cdp::LogType::WARNING), description);
3581+
logMessage(js, static_cast<uint16_t>(cdp::LogType::WARNING), description, captureStackTrace);
35793582
});
35803583
}
35813584

@@ -3608,9 +3611,10 @@ void Worker::Isolate::logWarning(kj::StringPtr description, Lock& lock) {
36083611
}
36093612
}
36103613

3611-
void Worker::Isolate::logWarningOnce(kj::StringPtr description, Lock& lock) {
3614+
void Worker::Isolate::logWarningOnce(
3615+
kj::StringPtr description, Lock& lock, CaptureInspectorStackTrace captureStackTrace) {
36123616
impl->warningOnceDescriptions.findOrCreate(description, [&] {
3613-
logWarning(description, lock);
3617+
logWarning(description, lock, captureStackTrace);
36143618
return kj::str(description);
36153619
});
36163620
}
@@ -3622,7 +3626,10 @@ void Worker::Isolate::logErrorOnce(kj::StringPtr description) {
36223626
});
36233627
}
36243628

3625-
void Worker::Isolate::logMessage(jsg::Lock& js, uint16_t type, kj::StringPtr description) {
3629+
void Worker::Isolate::logMessage(jsg::Lock& js,
3630+
uint16_t type,
3631+
kj::StringPtr description,
3632+
CaptureInspectorStackTrace captureStackTrace) {
36263633
if (impl->inspector != kj::none) {
36273634
// We want to log a warning to the devtools console, as if `console.warn()` were called.
36283635
// 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
36533660
params.initArgs(1)[0].initString().setValue(description);
36543661
params.setExecutionContextId(v8_inspector::V8ContextInfo::executionContextId(js.v8Context()));
36553662
params.setTimestamp(impl->inspectorClient->currentTimeMS());
3656-
stackTraceToCDP(js, params.initStackTrace());
3663+
if (captureStackTrace) {
3664+
stackTraceToCDP(js, params.initStackTrace());
3665+
}
36573666

36583667
auto notification = getCdpJsonCodec().encode(event);
36593668
KJ_IF_SOME(i, currentInspectorSession) {

src/workerd/io/worker.h

Lines changed: 16 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,8 @@ namespace workerd {
4242

4343
WD_STRONG_BOOL(StructuredLogging);
4444
WD_STRONG_BOOL(ProcessStdioPrefixed);
45+
// Inspector stack capture enters V8 and is unsafe from GC finalizers.
46+
WD_STRONG_BOOL(CaptureInspectorStackTrace);
4547

4648
namespace api {
4749
class DurableObjectState;
@@ -461,11 +463,15 @@ class Worker::Isolate: public kj::AtomicRefcounted {
461463
kj::WebSocket& webSocket) const;
462464

463465
// Log a warning to the inspector if attached, and log an INFO severity message.
464-
void logWarning(kj::StringPtr description, Worker::Lock& lock);
466+
void logWarning(kj::StringPtr description,
467+
Worker::Lock& lock,
468+
CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES);
465469

466470
// logWarningOnce() only logs the warning if it has not already been logged for this
467471
// worker instance.
468-
void logWarningOnce(kj::StringPtr description, Worker::Lock& lock);
472+
void logWarningOnce(kj::StringPtr description,
473+
Worker::Lock& lock,
474+
CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES);
469475

470476
// Log an ERROR severity message, if it has not already been logged for this worker instance.
471477
void logErrorOnce(kj::StringPtr description);
@@ -570,7 +576,10 @@ class Worker::Isolate: public kj::AtomicRefcounted {
570576

571577
// Log a message as if with console.{log,warn,error,etc}. `type` must be one of the cdp::LogType
572578
// enum, which unfortunately we cannot forward-declare, ugh.
573-
void logMessage(jsg::Lock& js, uint16_t type, kj::StringPtr description);
579+
void logMessage(jsg::Lock& js,
580+
uint16_t type,
581+
kj::StringPtr description,
582+
CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES);
574583

575584
class SubrequestClient;
576585
class ResponseStreamWrapper;
@@ -728,8 +737,10 @@ class Worker::Lock {
728737
v8::Local<v8::Context> getContext();
729738

730739
bool isInspectorEnabled();
731-
void logWarning(kj::StringPtr description);
732-
void logWarningOnce(kj::StringPtr description);
740+
void logWarning(kj::StringPtr description,
741+
CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES);
742+
void logWarningOnce(kj::StringPtr description,
743+
CaptureInspectorStackTrace captureStackTrace = CaptureInspectorStackTrace::YES);
733744

734745
void logErrorOnce(kj::StringPtr description);
735746

0 commit comments

Comments
 (0)