Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 9 additions & 0 deletions src/workerd/api/tests/BUILD.bazel
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
60 changes: 60 additions & 0 deletions src/workerd/api/tests/rpc-stub-gc-warning-inspector-test.js
Original file line number Diff line number Diff line change
@@ -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);
},
};
Original file line number Diff line number Diff line change
@@ -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"),
],
),
),
],
);
70 changes: 70 additions & 0 deletions src/workerd/api/tests/rpc-stub-gc-warning-inspector-trigger.js
Original file line number Diff line number Diff line change
@@ -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}`);
},
};
6 changes: 4 additions & 2 deletions src/workerd/api/worker-rpc.c++
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
}

Expand Down Expand Up @@ -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 {
Expand Down
10 changes: 6 additions & 4 deletions src/workerd/io/io-context.c++
Original file line number Diff line number Diff line change
Expand Up @@ -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) {
Expand Down
6 changes: 4 additions & 2 deletions src/workerd/io/io-context.h
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
29 changes: 19 additions & 10 deletions src/workerd/io/worker.c++
Original file line number Diff line number Diff line change
Expand Up @@ -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<Isolate&>(worker.getIsolate()).logWarning(description, *this);
const_cast<Isolate&>(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<Isolate&>(worker.getIsolate()).logWarningOnce(description, *this);
const_cast<Isolate&>(worker.getIsolate()).logWarningOnce(description, *this, captureStackTrace);
}

void Worker::Lock::logErrorOnce(kj::StringPtr description) {
Expand Down Expand Up @@ -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<uint16_t>(cdp::LogType::WARNING), description);
logMessage(js, static_cast<uint16_t>(cdp::LogType::WARNING), description, captureStackTrace);
});
}

Expand Down Expand Up @@ -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);
});
}
Expand All @@ -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,
Expand Down Expand Up @@ -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) {
Expand Down
21 changes: 16 additions & 5 deletions src/workerd/io/worker.h
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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);
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -728,8 +737,10 @@ class Worker::Lock {
v8::Local<v8::Context> 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);

Expand Down
Loading