Uh oh!
There was an error while loading. Please reload this page.
telemetry: stream flush span + otel load diagnostics - #2891
Conversation
…batch Complements the existing workflow.stream.read TTFC span: each flushed batch emits a back-dated CLIENT span covering the app-perceived write latency (buffer dwell + RPC), with buffer_dwell_ms / chunks / bytes attributes so client-side batching cost (flush timer, turbo run-ready barrier) can be told apart from network/server time. Failed flushes keep the batch's original t0 so a retried batch reports its full dwell. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
🦋 Changeset detectedLatest commit: ff6017b The changes in this PR will be included in the next version bump. This PR includes changesets to release 17 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 |
📊 Workflow Benchmarkscommit Backend:
📜 Previous results (2)363bb4fMon, 13 Jul 2026 02:28:18 GMT · run logs
271499aMon, 13 Jul 2026 00:38:17 GMT · run logs
Avg deltas compare against the most recent benchmark run on Metrics — TTFS: time to first step body execution · STSO: step-to-step overhead (gap between consecutive step bodies) · WO: workflow overhead (time outside step bodies, client start → last step body exit) · SL: stream latency (first chunk write → visible to the reader) Scenarios — stream: one step that streams chunks back to the client; no hooks, so the run stays in turbo mode · hook + stream: registers a hook before the same streaming step, which exits turbo mode · 1020 steps: 1020 trivial sequential steps; STSO is measured between consecutive steps in the given step ranges 🟢/🔴 mark percentiles within/above target. Targets (p75/p90/p99, ms) — TTFS 200/300/600 · SL 50/60/125 · STSO (1-20) 20/30/60 · STSO (101-120) 30/45/90 · STSO (1001-1020) 40/60/120 TTFS/WO compare client vs deployment clocks and SL compares the step runner’s clock vs the client’s (NTP-synced in CI). WO ends at the last step body exit, the closest observable proxy for the final step-completion request. |
🧪 E2E Test Results✅ All tests passed Summary
Details by Category✅ ▲ Vercel Production
✅ 💻 Local Development
✅ 📦 Local Production
✅ 🐘 Local Postgres
✅ 🪟 Windows
✅ 📋 Other
|
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
TooTallNate
left a comment
There was a problem hiding this comment.
Reviewed the flush-span mechanics, the failure-path bookkeeping, and the diagnostic; ran both suites. Approving.
The batch-t0 bookkeeping is the subtle part and it's correct. I traced the interleavings:
- t0 stamps at
write()entry before the backpressure wait, so queueing behind an in-flight flush counts toward the next batch's dwell — matching the stated "app-perceived" semantics. - A write arriving during an in-flight flush stamps a fresh t0 pre-wait while its chunk lands in the next batch post-wait — so the timestamp and the chunk travel together.
- The failure path's
Math.minrestore handles the tricky case (flush fails after a concurrent write already stamped a newer t0): the retried, merged batch correctly reports from the oldest unflushed write. Error propagation is unchanged — the new try/catch only restores state and rethrows. - The span emits only after a successful settle, with
dispatchAtcaptured before the RPC, sobuffer_dwell_mscleanly isolates the pre-dispatch share.
Consistency checks: the fire-and-forget void (async ...) shape matches the existing workflow.stream.read call site from #2857 exactly, and the OTEL import is latch-caught so the no-OTEL path is a cheap null check per flush. The flush vs write span naming split (client-perceived batch vs per-request RPC) is the right taxonomy and the docs table makes the decomposition clear. The DEBUG gate on the world-vercel load-failure log matches the existing workflow:/* convention in the HTTP debug logging, and logging the reason while still returning null is the right diagnostic-without-behavior-change move.
Verified locally: core 1451/1451 (including the 4 new InMemorySpanExporter tests: per-batch attributes, one-span-per-cycle, barrier-hold-as-dwell, no-span-on-empty-close), world-vercel 235/235.
CI: the 3 failures are Windows-lane: the unit failure is streamer.test.ts > scopes chunk listing to the stream — a test from the already-merged chunk-sharding PR (#2807) timing out at ~12s on windows-latest, nothing to do with this diff (which doesn't touch world-local). Flagging it separately as a likely Windows fs-timing issue worth a look by whoever owns that test; the E2E Windows lane and the required-check aggregator are the usual baseline.
Two non-blocking notes:
- The failure-restore path (
Math.mint0 retention across a failed flush → full-dwell reporting on retry) is the trickiest logic in the diff and the one path without a test — a test that fails the firstwriteMultiand asserts the retry span's back-dated start would pin it. - Both this and the #2857 read-span call sites
voidan async IIFE without a.catch; a misbehaving third-party tracer that throws fromstartSpan/endwould surface as an unhandled rejection. Vanishingly unlikely, but a shared.catch(() => {})wrapper for both would close it — fine as a follow-up.
Uh oh!
There was an error while loading. Please reload this page.
Backport to To resolve manually, push a backport branch and open a PR against git fetch origin stable
git checkout -b backport/pr-2891-to-stable origin/stable
git cherry-pick -S 4a43e39fec61519a2756f4f5e7bae5ccdac6f662 # -S signs the commit# Fix conflicts, then:
git add -A
git cherry-pick --continue
git push -u origin backport/pr-2891-to-stable
gh pr create --base stable --head backport/pr-2891-to-stable \
--title "Backport #2891: <original PR title>" \
--body "Manual backport of #2891 (cherry-pick 4a43e39fec61) to \`stable\`." |
Summary
Stream reads already have a client-observed span (
workflow.stream.read+read.ttfc_ms, #2857). This adds the missing write-side piece — the client-side buffering that no server measurement can see — plus a diagnostic for a gap found while validating #2857 in production.workflow.stream.flushspan (core)Each flushed batch from
WorkflowServerWritableStreamemits a back-dated CLIENT span whose duration is the app-perceived latency of the batch (firstwrite()→ server write settled), with:workflow.stream.flush.buffer_dwell_ms— firstwrite()of the batch → RPC dispatch. Captures the flush-timer wait and the turbo run-ready barrier hold on a stream's first write.workflow.stream.flush.chunks/.bytes— batch shape.workflow.run.id/workflow.stream.name/workflow.stream.operation: flush.Named
workflow.stream.flush(not.write) because #2857 already usesworkflow.stream.writefor the per-request RPC span (chunk_rtt) — in a trace the flush span sits above the RPC span, decomposing a write into dwell vs network/server. Failed flushes keep the batch's original t0 so a retried batch reports its full dwell; emission is fire-and-forget and no-ops without OTEL; empty closes emit nothing. Documented in the tracing docs alongside #2857's spans.DEBUG log for world-vercel OTEL load failure (world-vercel)
While validating #2857's spans in production we found its core-emitted span flows but its world-vercel-emitted spans (
workflow.stream.write,workflow.stream.read.connect) don't appear from deployed apps, despite the same code emitting correctly in local tests — pointing at an environment-specific@opentelemetry/apiload/resolution issue. world-vercel'simport('@opentelemetry/api').catch(() => null)silently latches the failure, making that indistinguishable from "app has no OTEL". This PR logs the failure reason underDEBUG=workflow:*so the root cause is diagnosable from a deployment; the actual fix will follow once a deployment surfaces the reason.Testing
writable-stream-telemetry.test.ts(InMemorySpanExporter): span kind/attributes per batch, one span per flush cycle, run-ready-barrier hold counted as dwell, no span on empty close.trace-propagation+http-coresuites pass (18 tests).pnpm test(packages/core): 1451 passed;pnpm typecheckpasses; biome clean on changed files.🤖 Generated with Claude Code