Make local observability capture much cheaper per request - #15015
Open
nickpatt wants to merge 4 commits into
Open
Make local observability capture much cheaper per request#15015nickpatt wants to merge 4 commits into
nickpatt wants to merge 4 commits into
Conversation
…vent Each tail event was its own Durable Object call, so a request cost two or three round-trips per span — on a module-heavy Vite app that dominated dev request latency (reported as 4-10x). Buffer rows and write them in batches instead. The root span is still written immediately, so an invocation shows up in the trace list while it's running, and a burst crossing FLUSH_THRESHOLD flushes early so long invocations stay visible. Also stop capturing the Vite plugin's router, asset and proxy workers via a new per-worker unsafeExcludeFromObservability option. Their traces were noise the Observability views already filtered out, so capturing them was pure cost.
🦋 Changeset detectedLatest commit: 9763b4a The changes in this PR will be included in the next version bump. This PR includes changesets to release 8 packages
Not sure what this means? Click here to learn what changesets are. Click here if you're a maintainer who wants to add another changeset to this PR |
workers-devprod
requested review from
a team and
dario-piotrowicz
and removed request for
a team
August 4, 2026 13:36
Contributor
|
Codeowners approval required for this PR:
Show detailed file reviewers
|
@cloudflare/autoconfig
@cloudflare/build-output-utils
@cloudflare/config
create-cloudflare
@cloudflare/deploy-helpers
@cloudflare/kv-asset-handler
miniflare
@cloudflare/pages-functions
@cloudflare/pages-shared
@cloudflare/unenv-preset
@cloudflare/vite-plugin
@cloudflare/vitest-pool-workers
@cloudflare/workers-auth
@cloudflare/workers-editor-shared
@cloudflare/workers-utils
wrangler
commit: |
![devin-ai-integration[bot]](https://avatars.githubusercontent.com/in/811515?s=60&v=4){kind=small}
This comment was marked as resolved.
This comment was marked as resolved.
Sorry, something went wrong.
Batching only flushed at 64 buffered rows or at the end, so an invocation that emits fewer than that showed only its root span until it finished — and lost the buffer entirely if the outcome event never arrived. That in-flight visibility is the reason the module wrote through per event in the first place. Logs and exceptions now flush as they happen (they're what you read while watching a request that hasn't finished), anything else flushes once 100ms has passed since the last write, and the size threshold drops to 16. Timing comes from tail-event timestamps rather than Date.now(), which a Worker only advances on I/O.
This comment was marked as resolved.
This comment was marked as resolved.
Sorry, something went wrong.
spanClose only marked the buffered row dirty, so a span that finished and was then followed by a quiet period sat in the store with a NULL duration — which the UI reads as still running. It now runs the same flush check as the other events. The interval is driven by tail-event timestamps, not a timer, so an invocation that goes completely quiet genuinely can't flush before it ends. Reworded the comment and changeset to say that rather than claim a 100ms guarantee.
This comment was marked as resolved.
This comment was marked as resolved.
Sorry, something went wrong.
Batched writes re-send a span row on every flush it's dirty for (open, attribute merges, close), and `persist` used INSERT OR REPLACE, which deletes the row before re-inserting. That re-stamped the `created_at` default with the time of the latest flush. The trace list renders the root span's `created_at`, and the root is re-sent when the invocation closes, so the displayed time showed when a request finished rather than when it started. Upsert instead, leaving `created_at` alone — matching what the write-through path did with INSERT ... DO NOTHING followed by UPDATE. Also correct the FLUSH_INTERVAL_MS comment: closing spans are buffered like any other row, so only logs and exceptions are written as they arrive.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fixes #15014.
Local observability capture was costing 4–10x on every dev request under the Vite plugin, and the cost grew with app size. The report is unusually careful — bisected to the exact plugin version, with medians rather than single samples.
What was happening
Every tail event was written to the trace store as its own Durable Object call, and the invocation waited for all of them. Opening a span was one call, merging its attributes another, closing it another.
One request on a four-line worker produces 14 spans. That's about 30 round-trips per request, in sequence. On macOS each is cheap and it costs a few milliseconds; on Windows they're far more expensive, which is why the reporter saw ~130ms. And the more modules and routes an app has, the more spans per request, so the cost scales with the app — matching the 10.6x they measured on a real one.
Two changes
Batch the writes. Rows are now buffered and written together, so a request makes a couple of calls instead of thirty. Attribute merges and span closes update the buffered row rather than making a call each.
There's a reason it was written through one event at a time: it's how an invocation shows up in the trace store while it's still running, which matters for long-running work — an agent waiting on a model, a streamed response. That's kept. The root span is written immediately, console logs and exceptions go out as they arrive, and a span's completion is written on the next event once 100ms has passed. Verified by sampling the store 200ms into a 250ms request: its child spans and logs are already there, and finished spans already show a duration rather than looking like they're still running.
One honest limit: the flush is driven by tail events, not a timer, so an invocation that goes completely quiet writes nothing further until it ends. The comments and changeset say that rather than claiming a flat 100ms guarantee.
Stop capturing the Vite plugin's own workers. Its router, asset and proxy workers were being traced, and the Observability views then hid those traces again. Capturing them was pure cost, so they're now skipped at the source via a new per-worker option. Spans per request drop from 14 to 5.
A nice side effect: a trace's root is now your Worker instead of
__router-worker__.Measured
Median of 20 sequential in-process requests after 3 warmups, same playground app, macOS:
Measured back to back in one sitting, since machine load moves these numbers around more than the change does — an earlier set of readings I took while builds were running in the background was misleading. In round-trips, which is the thing that actually scales, a request goes from roughly 30 calls to 3.
macOS understates the win — the whole point is that round-trips are cheap here and expensive on Windows. A ~10x cut in round-trips should bring the reporter's +133 ms down a long way, but I can't reproduce their platform, so it would be good to have them confirm.
Nothing about what gets captured changes: your Worker's spans, subrequests, and every
console.*level are all still recorded.Still open from that issue
"observability": { "enabled": false }inwrangler.jsoncdoesn't disable local capture — only the environment variable does. That's a fair expectation to have, and a separate fix.