Repository navigation
Conversation
This comment was marked as resolved.
This comment was marked as resolved.
First step of the async trace core: a standalone crate with no callers yet. It holds the stateful half of the design, which is unit-testable without V8: - IsolateState: per-isolate resource ID allocation and stack deduplication. - Tracker: one per IoContext. Tracks the execution scope stack, turns and their causes (the default trigger for resources created during a turn, which attributes work after `await` without promise hooks), live resources, and the adoption of a binding operation by the awaitIo bridge that resumes it. Caller mistakes are counted in ContextStats rather than panicking. - Sink trait with an NDJSON sink (format v1, one shared writer per process, per-tracker buffering so lines never interleave) and a recording sink for tests. - A cxx bridge exposing opaque Isolate, Tracker and Writer types. Kinds and outcomes cross as u8. No JavaScript-visible API change.
Prepares the crate for the C++ facade: - CppSink forwards events to a C++ AsyncTraceListener (listener.h, in this package so the bridge has no library cycle). The inline shims catch listener exceptions, which would otherwise become Rust panics. - turn_begin() takes a default cause (typically the current request). set_turn_cause() replaces it, closing its scope; a second explicit cause is still rejected. - ContextStats gains foreign_thread, for events the C++ wrapper drops because they came from another thread; reported as foreignThread in ctx_end. - Strings from C++ cross as bytes and are decoded lossily, because cxx's rust::Str constructor throws on invalid UTF-8. The writer path must still be UTF-8.
//src/workerd/io:async-trace wraps the async-trace Rust crate: - AsyncTraceIsolate: per-isolate ID allocation and stack dedup. - AsyncTraceWriter: a process-wide NDJSON output file. - AsyncTraceSinks: listeners and writers collected for one context. - AsyncTracker: per-context tracker, held by kj::Arc. Methods are const and may be called from any thread; calls off the creating thread are dropped and counted. - AsyncResource: move-only handle that keeps its tracker alive and reports destroy on release if the resource never settled. Inert (null Arc, zero ID) when tracing is off. - TurnScope / CallbackScope: RAII turn and callback brackets, no-ops without a tracker. - OwnedAsyncTracker: closes the tracker when its owner goes away. Nothing uses it yet.
IsolateObserver gains two hooks, both no-ops by default: - getAsyncTraceConfig(), called once when the Worker::Isolate is created. A config makes the isolate own an AsyncTraceIsolate. - addAsyncTraceSinks(sinks, worker, actorId), called once per IoContext. The context is traced only if a sink is added. It takes names rather than Worker& and Worker::Actor& because observer.h cannot include worker.h. With tracing on, the IoContext owns a tracker (declared before its task sets, so their resources are released before it closes), each IncomingRequest records a REQUEST resource on delivery (named by the delivering function) and settles it on destruction, and runImpl() brackets each entry into JavaScript in a TurnScope from before the lock until after the microtask drain, with the current request as the default cause. When tracing is off, which is always the case unless an embedder overrides the hooks, each site costs one null check and no Rust call. TestFixture accepts an isolateObserver.
- adopt_operation() makes the bridge a second holder of the operation. destroy() forgets a resource (reporting destroy if unsettled) only when its last holder releases it. A binding's span is attached to the KJ promise and ends before the bridge's continuation runs; until now that left the bridge reporting under an ID the tracker had forgotten. - A turn's default cause is entered lazily: only when the turn creates a resource, enters a scope, or starts a nested turn before an explicit cause is set. A turn resumed by a bridge no longer reports a zero-length before/after for the request. The C++ tests' expected sequences change accordingly.
- AsyncTracker::adoptOrCreate() replaces adoptOperation(): it returns an owning handle on the adopted operation (a second holder), or a new resource. A bare ID from adoption could outlive the operation. - AsyncResource's methods are inline, so an inert handle costs one null check and no call. settle(), annotate() and enterAsTurnCause() are const: they change the tracker's record, not the handle, and handles captured in JS closures can call them.
With async tracing on: - awaitIo() adopts the turn's pending operation or creates a KJ_TO_JS resource, settles it when the KJ promise completes (error if it rejected), and makes it the cause of the turn that resumes JavaScript. Code after an `await` on I/O is thereby triggered by that I/O, without promise hooks. - awaitJs() creates a JS_TO_KJ resource, settled when the JavaScript promise settles. - Timers are traced centrally in TimeoutManagerImpl, so every caller is covered: setTimeout, setInterval, setImmediate, scheduler.wait and AbortSignal.timeout, each named accordingly. A one-shot timer settles when the KJ timer fires, before its turn, so settle-to-before is the scheduling delay. Each firing causes a turn. Clearing a timer reports destroy; an interval never settles. - queueMicrotask() creates a MICROTASK resource that nests in the turn running it, and releases it after the callback rather than at GC. When tracing is off, each site costs one inline null check: awaitIo captures an inert handle, timers and microtasks skip creation. No compatibility flag: nothing observable to Workers changes.
When a TraceContext is created during a traced turn, TraceContextParent::newChild() creates an OPERATION resource named after the span, whether or not the spans are observed. That covers KV, R2, DO storage, SQL, cache, JSRPC and fetch with no per-site changes. The next awaitIo() in the turn adopts it, so the bridge reports under the binding's operation. - newChild() finds the tracker through AsyncTracker::inTurn(), a thread-local that every TurnScope sets (null for untraced turns, so a nested untraced context hides an enclosing traced one). :trace sits below :io and cannot reach the IoContext. - Destroying a TraceContext settles its operation; overwriting one by move-assignment settles the old operation first. setTag() annotates it. - TraceContext::detachAsync() takes the operation out of consideration for adoption, for spans that outlive the call without being attached to the next awaitIo()'s promise. When tracing is off, newChild() costs a thread-local read and a null check, and TurnScope two thread-local writes per turn.
From an audit of the 61 TraceContext creation sites: 39 bind to the next awaitIo(), 7 end synchronously, and these could otherwise be adopted by an unrelated awaitIo() later in the turn: - IoContext::getSubrequestNoChecks() parks the span on the returned client (DO and facet subrequests, Hyperdrive, writeLogfwdr, fetch_default, and the outer span of the DO fetch paths). Detached. Queue and WebSocket sends, which were bound only by recency, get their own bridge resource instead. - IoContext::attachSpans() attaches spans to a promise that is already awaited or already resolved (DO storage cache hits, transaction()). It detaches attached TraceContexts. - Fetcher::getClientForOneCall(): the session span was alive next to the jsRpcCall span (ambiguous). Detached. - Server-side jsRpcCall: owned by the dispatch promise, so the method's own awaits could adopt it. Detached. - Cache::put(): the output-lock awaitIo() would adopt it. Detached. - r2GetClient() (unused): lives as long as the client. Detached. Only affects async tracing; spans are unchanged.
flush() writes buffered events to the file, for embedders that exit without running destructors. Sinks already flush at the end of each outermost turn, so this only matters for the last turn's events. Failing to create the file now reports the path.
Writes an async activity trace of every worker to <path> as NDJSON (one event per line, format v1): requests, turns, timers, microtasks, I/O bridges and binding operations, and what triggered what. For local debugging of async behaviour: what a request is waiting on, which I/O resumed which code, and where turns spend time. - The option is parsed in args.rs and passed through ServeOrTestOptions. CliMain opens the file (declared before the Server, which refers to it) and flushes it before exiting, since context.exit() doesn't run destructors. - When the option is set, Server::makeWorkerIsolate() uses an AsyncTraceIsolateObserver, which enables tracing for the isolate and adds the shared NDJSON sink to each IoContext. Without it, isolates get the plain IsolateObserver and nothing changes. - server/tests/async-trace runs a worker under --async-trace, then checks the file from a second worker via a disk service: the causal chain (request -> timer -> fetch -> body read), the subrequest's context, balanced scopes, per-context time order and zero error stats. Not observable to Workers; operator configuration, so no compatibility flag or autogate.
A new Perfetto category, workerd.async, records async activity next to
the existing workerd slices:
workerd test config.wd-test \
--perfetto-trace=out.pftrace=workerd,workerd.async
Layout: a track per IoContext with a slice per turn (and a nested lock
slice for the time spent waiting for locks), and under it a track per
resource. A resource's slice spans from creation until it settles;
"run" slices span its callbacks; annotations are instants. Flows link
the creating callback to each new resource, and a resource's
settlement to its next callback, so the scheduling delay is visible.
- The sink keeps no per-resource state: track and flow IDs are hashed
from (isolate, id), and track descriptors are erased when a resource
settles or is destroyed, so the SDK's track registry doesn't grow.
- Turns are reported when they end, with times on the tracker's clock;
they are mapped onto the trace clock through the turn's end.
- The category is recorded only when listed; "workerd" alone doesn't
enable it. When it is being recorded as an isolate is created, the
isolate gets async trace state even without --async-trace, and each
IoContext gets the Perfetto sink. A session started later doesn't
see existing isolates.
Builds without Perfetto report the category as disabled.
Tested by running a worker under --perfetto-trace with and without the
category and checking for the interned names. The structure (tracks,
nesting, flows, no unfinished slices) was checked with trace_processor,
which the test can't depend on.
TurnScope::end() ends the turn early, as the destructor would. IoContext::runImpl() calls it after the microtask drain, inside the lock scope, rather than when the TurnScope is destroyed after the lock is released. Ending a turn closes its cause's callback scope (reporting `after`), and a sink that calls into V8, such as the inspector's, must see that while the isolate is locked. Turn end times now exclude releasing the lock.
DevTools async stack traces now continue across timers, microtasks, I/O bridges and binding operations, not only promises. With workerd --inspector-addr (and so wrangler dev), a callback scheduled with setTimeout or queueMicrotask pauses with an async stack showing where it was scheduled. Local development only: an inspector exists only outside multi-tenant processes, and production doesn't attach the inspector. - Every IoContext of an isolate with an inspector gets the sink, and the isolate gets async trace state. - Creating a resource schedules a V8 async task, capturing the current stack; each callback runs as that task; destroying an unsettled resource cancels it. Keys are even, because V8 keys its own promise tasks with odd values. Only setInterval is recurring. awaitJs resources are skipped: they never run a callback. - V8 is called only while the isolate is current and locked. Started tasks are mirrored on a stack so starts and finishes always pair, including when the tracker discards unbalanced scopes. - V8 ignores all of it unless a session set an async call stack depth, and bounds the stacks it keeps. Tested in server/tests/inspector: pausing in setTimeout and queueMicrotask callbacks yields async stacks naming them and the function that scheduled them. Both cases fail without the sink.
An AsyncTraceIsolate can be given an AsyncStackCapturer, implemented by whoever can reach V8 (this layer can't). AsyncTracker::create() then has it walk the current stack into an AsyncStackBuilder, which feeds the existing Rust interning: stacks are deduplicated per isolate on (scriptId, line, column) and the init event carries the stack's ID. - Tracker::accepts_resources() lets create() skip the capture, the expensive part, when the tracker is closed or at its live cap. - C++ listeners get stack events: AsyncTraceListener::onStack(isolate, id, frames), before the first onInit() that refers to the stack. Frames cross the bridge one call at a time and are buffered thread-locally by the shim, since a shared struct of frames would have to be defined before cxx generates it.
Records up to <frames> (1-64) frames of the JavaScript stack that
created each async resource: timers, microtasks, I/O bridges, binding
operations. For example, a fetch operation's stack points at the
fetch() call, so a trace shows where each operation came from, not just
what triggered it.
- AsyncTraceConfig::stackDepth enables capture for an isolate. The V8
capturer (io/async-trace-stacks.c++) walks the stack with
StackTrace::CurrentStackTrace only while its isolate is current and
locked; a resource created with no JavaScript on the stack gets no
stack.
- The option applies to every output: `stack` lines in the
--async-trace file, and a `stack` arg ("fn (script:line:col)" per
line) on each resource's slice in the workerd.async Perfetto
category. It can be used without --async-trace.
- It is a separate option, rather than a suffix on --async-trace's
path, because a path can contain commas.
Each capture costs a stack walk per resource created, so it is off by
default.
Tracker::create_unowned() records a resource that nothing will release, such as a JavaScript promise: it is forgotten when it settles (with no destroy), or when the tracker closes. A callback running when it settles still reports `after`, since scopes are tracked separately. Tracker::knows() tells whether an ID is one of the tracker's live resources. AsyncTracker gets the promise hook's entry points: createPromise() (an unowned JS_PROMISE, triggered by its parent promise or the turn's cause, never with a creation stack), knows(), and enterPromise(), exitPromise() and settlePromise() by ID.
With --async-trace-promises, each promise created during a traced turn becomes a JS_PROMISE resource, through V8's promise hook, so a trace follows async functions and promise chains, not only timers and I/O: - init: triggered by the promise it derives from, if traced by the same context, else by the turn's cause. - before/after: its reaction runs as a callback, so resources created after an `await` show that reaction as their execution context. - resolve: settled, ERROR if rejected. Installing a promise hook permanently sends the isolate's promise operations through V8's slow path, so the hook is installed only on isolates configured for it (AsyncTraceConfig::promises), at creation, and never in a multi-tenant process (logged and skipped). - Promise IDs live on the promise under a per-isolate private symbol. The hook finds that state through SET_DATA_ISOLATE, and does nothing outside traced turns. It catches everything, since V8 calls it. - A reaction's promise usually settles during the reaction, so `after` is matched to the current scope rather than to a live resource. - The Inspector sink ignores promises: V8 tracks their async stacks. Tested by recording the scenario with and without the option: with it, the code after `await new Promise((r) => setTimeout(r, 1))` runs as a reaction derived from the awaited promise, which the timer's callback settles, and every context's stats are clean; without it, no promises are traced.
IoContext::AwaitIoOperation, wrapped around one awaitIo() call, makes that bridge an OPERATION with the given name instead of a generic `awaitIo` bridge, bound so that no other bridge adopts it. It is used for I/O that has no trace span: - Internal (KJ-backed) streams: stream_read, stream_write (the sink write, not the output-lock wait), stream_pipe, stream_close. - Sockets: socket_connect, socket_start_tls, socket_disconnect (the wait for the peer), datagram_receive, datagram_send. A trace now shows, for example, that the handler was resumed by a stream read rather than by "awaitIo". Standard (JavaScript-backed) streams do no I/O and get no operation; with --async-trace-promises their promises are traced. Settling an operation from the promise returned to JavaScript was rejected: attaching a reaction marks the promise handled, which would suppress unhandledrejection only while tracing. Tested at the IoContext level (the first bridge in the scope is named; a named bridge neither adopts a span's operation nor makes its adoption ambiguous) and end to end with an IdentityTransformStream read and write in the scenario. connect-handler-test, run by hand under --async-trace, produces the socket and stream operations with clean stats.
IncomingRequest::delivered() gains an overload taking the event type, which names the request's async trace resource: fetch, connect, scheduled, alarm, test, queue, jsrpc, trace, tail_stream, hibernatable_websocket, restore, restore_rpc_stub, udp_connect. Previously the resource was named after the delivering function (requestImpl, run, ...), which said little and was the same for every custom event. The old overload remains, for callers outside this repository, and still falls back to the function name.
A request delivered synchronously from another context's turn, such as
a service binding or SELF fetch, now records what caused it there: a
`link` event naming that turn's latest operation (typically the fetch
span's operation, adopted or detached), or else its running resource.
Resource IDs are per isolate, so the link names the source's isolate
and context rather than being a trigger:
{"e":"link","ctx":8,"id":12,"fromIso":1,"fromCtx":7,"fromId":11}
- IncomingRequest::delivered() calls AsyncTracker::linkFromCallerTurn(),
which links only when AsyncTracker::inTurn() is another tracker, so
asynchronous delivery (or delivery from the network) gets no link.
- C++ listeners get AsyncTraceListener::onLink(). Perfetto draws a flow
from the caller's resource track to the request, naming the caller's
tracks from the IDs alone.
Tested in Rust (link source selection, link reporting), in the facade
(only during another tracker's turn, naming its latest operation), and
end to end: the scenario's subrequest links to the caller's fetch.
…details Span tags (URLs, storage keys, ...) are written verbatim, and creation stacks name source locations.
An operation created within another's span, through TraceContext::getSpanParents() (a fetch attempt within the fetch, a jsRpcCall within its session, actor calls), now names the enclosing operation as its parent. TraceContextParent carries the async trace operation of the TraceContext it came from, and newChild() passes it to AsyncTracker::createChild(). The parent is structural, unlike the trigger, which stays the turn's cause, so it is a separate field: `parent` on `init` lines (omitted when 0), AsyncInitEvent::parent for C++ listeners, and a Perfetto arg. It may name an operation that has already settled. Parents taken from getSpanParentsIfObserved() exist only when spans are observed, so those sites lose the edge when they aren't.
The scenario's fetch now POSTs a JavaScript ReadableStream body (read by the handler after its wait). This checks that the body pump does not take over the fetch operation: the response still resumes under it, and no adoption is ambiguous. It didn't, as suspected it might.
getSubrequestNoChecks() detaches the span it parks on the client, because the client may outlive the call and the caller's next awaitIo() may await something else. For queue sends, queue metrics and WebSocket opens, though, the next awaitIo() awaits exactly that subrequest, so their I/O showed up as a generic awaitIo bridge instead. These callers now pass SpanAwaitedNext::YES to getHttpClient() (SubrequestOptions::spanAwaitedNext). The span is then not detached, and when the context is traced it is kept with the client even if unobserved, since dropping it would settle the operation before it can be adopted. The span's own lifetime does not change. Tested at the IoContext level with a stub client (adopted with YES, detached by default). By hand under --async-trace, queue-test now shows queue_send and queue_metrics resuming the handler, and the WebSocket tests that connect show websocket_open doing so.
workerd exits through context.exit(), which skips destructors, so
contexts still open at that point never got a ctx_end, and a consumer
could not tell them from a truncated file.
The NDJSON writer now tracks the contexts whose ctx line has been
produced but not their ctx_end. AsyncTraceWriter::finish(), which
cli-main calls instead of flush() before context.exit(), writes a last
line listing them, and flushes; later lines are dropped:
{"e":"exit","at":2480000,"open":[9]}
With KJ_CLEAN_SHUTDOWN, destructors run and contexts end normally, so
cli-main only flushes. Killing workerd by signal still bypasses this.
The scenario checker requires the exit line, last, with no open
contexts; a Rust test covers a context left open.
docs/async-trace.md explains what async tracing is for, how to enable it (--async-trace, --async-trace-stacks, --async-trace-promises, the workerd.async Perfetto category, the inspector), the concepts (contexts, resources, turns and causes, triggers, operation adoption, parents, cross-context links), the NDJSON format with a worked example, the Perfetto and inspector outputs, completeness statistics, limitations, the architecture, and how to instrument new runtime code.
Replace the rhetorical question list, bold-lead bullets and pseudo- headings, colon-led setups and filler phrasing with plain statements, paragraphs and real subheadings. No content changes.
A new section explains how the two differ in purpose and audience, model (a tree of intervals versus a causal graph of resources and turns), coverage, causality, timing and cost, how async tracing builds on spans without changing them, and when to use each.
listener_stack_frame() allocated outside any exception handling, but its extern "C++" bridge signature is infallible, so an allocation failure would have become an unhandleable Rust panic. It now catches the exception, logs it, and marks the pending stack broken; listener_stack_end() then drops that stack rather than deliver it truncated. Building the frame views in listener_stack_end() moved inside callListener() for the same reason. listener_stack_end() also handed the listener views into the thread-local pending buffer. A listener that caused another tracker on the same thread to report a stack would clear that buffer while the views were in use. The frames are now moved out of the buffer before the listener is called. A new test covers this; ASAN reports a heap-use-after-free without the fix. AsyncTraceListener now states that a listener must not call back into the tracker calling it, and that onStack() may be skipped.
The inspector sink skips promises, js_to_kj resources and resources created while the isolate is not locked (such as requests) in onInit(), but onBefore() still called asyncTaskStarted() for them. V8 handles a task it was never told about by pushing an empty async parent, which hides the async stack of the V8 task (such as a promise reaction) it runs inside. The sink now remembers which resources it scheduled, and only starts, finishes and cancels those. Like V8, it forgets a non-recurring task once it finishes, so the set holds only tasks still pending.
Every distinct creation stack was kept for the isolate's lifetime, and dynamically compiled code gets new script IDs, so a worker could grow the table without bound while stack capture was on. IsolateState now keeps at most 10,000 stacks or about 16 MiB (frames, keys and strings, approximately). Past either limit intern_stack() returns None for a new stack, so resources created at new sites have no stack; stacks already kept still resolve.
The scenario sends a queue message, routed back to the same worker (another worker would add an isolate, and the checker assumes one). check.js asserts that queue_send causes the turn that resumes the handler, which holds only because queue.c++ passes SpanAwaitedNext::YES, and that the delivered message links back to the send. With that call site set to NO, the check fails.
The test checks that a moved-from AsyncResource is inert, which the workerd-use-after-move clang-tidy check reports as an error.
The inspector sink keeps each task it schedules until the task runs or is canceled. A resource can settle and lose its last handle without running a callback (the operation of a detached span, for example), and a settled resource gets no destroy event, so its task stayed in the sink until the context ended. A Durable Object's context lives as long as the actor, so these accumulated. Sinks now get release(id) (AsyncTraceListener::onRelease()) when the tracker forgets a resource: after its settle or destroy, whichever is last. The inspector sink cancels and forgets any task it still has scheduled for it, forgetting it even when the isolate is not current and V8 cannot be told. The NDJSON and Perfetto sinks ignore release, so the trace format is unchanged.
The test checks that a listener's stack stays valid while the listener causes another tracker to report a stack. Both captures produced the same frames, so with the old shared buffer the refilled frames matched and the test passed except under ASAN. The captures now differ, and without the fix the outer listener reads the nested stack's text.
With KJ_CLEAN_SHUTDOWN set (as in the ASAN and coverage builds), workerd only flushed the trace, so it had no exit line and the end-to-end check failed. The writer now finishes after the server is destroyed, when its contexts have ended, so both shutdown paths end the trace the same way.
The test uses nothing from it, and it brought kj-async-os's kj::UnixEventPort into a binary that also links setup-async-io's, an ODR violation that fails the test under ASAN.
Bare uint is a glibc typedef, so async-trace-test.c++ did not compile on Windows.
The writer test built its file path by dropping TEST_TMPDIR's first character and prepending '/', which assumes a POSIX path: on Windows, C:/tmp/... became /:/tmp/.... It now passes the native path to the writer and reads the file back through evalNative(). The bad-path test matched the POSIX error text; it now matches the path, which the error names on every platform.
The exit line must follow every ctx_end. In workerd test runs every context ends before shutdown, so moving the clean-shutdown finish() back before the server is destroyed went unnoticed by the existing tests. A new test keeps a Durable Object's context open past the test and checks both shutdown paths: without KJ_CLEAN_SHUTDOWN, the exit line lists the context as open; with it, the context ends first and the exit line lists none.
The clean-shutdown check compared only the total numbers of contexts and ctx_end lines, so a trace that dropped the Durable Object's end but ended the request context twice would pass. It now checks that every context, the actor's included, ends exactly once.
The example elided awaitIo()'s continuation with '...'. It now uses the two-argument overload.
00ad8ea to
09f1fc1
Compare
guybedford
left a comment
There was a problem hiding this comment.
Checked this out and ran the full set locally (async-trace_test, async-trace-test@, async-trace-io-test@, the three server e2e tests and both inspector tests), plus the scenario by hand: all contexts end with all-zero stats and a clean exit line.
This is well put together. The tracker never panics on caller mistakes and self-reports them, the off-path really is a null check per site, the lifetime ordering (asyncTracker vs. task sets in IoContext, TimeoutState, the KJ_DEFER(turnScope.end()) placement before the microtask drain) is careful, and the owner-thread/foreignThread story is coherent. The doc matches the code.
A few points inline, none blocking. One process note: a number of the 43 commits are fixups by title ("mark a test's moved-from checks as intentional", "use kj::uint in the async-trace tests", "make the NDJSON writer tests portable to Windows", "give the nested-stack test distinct frames"); these should be squashed into their logical commits before merge.
Minor, no action needed: TraceContext grows by 16 bytes and gains a non-trivial dtor/move-assign, and each awaitIoImpl lambda grows by 16 bytes; and ~TraceContext always settles OK, so an operation that fails without an adopted bridge reports ok.
| // A Perfetto session recording "workerd.async" also needs the isolate's state (only sessions | ||
| // already running when the isolate is created see its contexts), and so does an inspector. | ||
| auto asyncTraceConfig = metrics->getAsyncTraceConfig(); | ||
| if (asyncTraceConfig != kj::none || isAsyncTracePerfettoEnabled() || |
There was a problem hiding this comment.
This makes --inspector-addr alone turn tracking on for every IoContext in the isolate (the inspector sink is added unconditionally in makeAsyncTracker()), so every request under wrangler dev now pays the per-resource bookkeeping on each awaitIo(), timer and span: HashMap insert, pending_ops, sink virtual calls, scheduled.upsert. V8 itself does nothing in asyncTaskScheduled() unless a session has called setAsyncCallStackDepth, so most of that work is wasted when DevTools isn't attached.
The doc does say this, but is default-on under the inspector the intent? It would be good to either have a number for the per-request cost, or gate the inspector sink on an active session.
|
|
||
| inline TraceContext TraceContextParent::newChild(kj::ConstString operationName) { | ||
| AsyncResource asyncTraceResource; | ||
| KJ_IF_SOME(tracker, AsyncTracker::inTurn()) { |
There was a problem hiding this comment.
This attributes the operation to whichever tracker's turn is ambient on the thread rather than to the owning context. IoContext::makeUserTraceSpan() has tryGetAsyncTracker() available and could pass it into TraceContextParent explicitly, leaving the thread-local only for the getSpanParents() paths that genuinely can't reach the context.
As written, a span created for context B synchronously inside context A's turn but outside B's own TurnScope lands in A's tracker with A's isolate's IDs. I don't see a workerd delivery path that does this today, but embedder delivery paths may.
| previous(context.awaitIoOperationName) { | ||
| context.awaitIoOperationName = name; | ||
| } | ||
| ~AwaitIoOperation() noexcept(false) { |
There was a problem hiding this comment.
First-bridge-wins with no feedback: if anything inside the wrapped expression creates a bridge first, the name silently lands on the wrong one, and if nothing consumes it the scope just drops it. Since the tracker already self-reports ambiguousBindings, it would be cheap to count an unconsumed name here too (awaitIoOperationName != kj::none at scope exit) so instrumentation drift shows up in ctx_end.
| isolate(isolate) {} | ||
|
|
||
| ~InspectorSink() noexcept(false) { | ||
| finishAll(); |
There was a problem hiding this comment.
This runs from ~IoContext via close(), where the isolate lock is not necessarily held and another thread may hold it for a different context of the same isolate, so asyncTaskFinished() can race with V8. It's only reachable when started is already unbalanced, but a data race seems worse than an unbalanced inspector task stack; suggest checking isCurrent() here (and in onAfter's finish loop) and otherwise just clearing.
Revisting the old #5842 prototype. This PR adds the async trace internal mechanisms. See the doc for details.
Planning to use this to help evaluate TS streams and other API optimizations.