Move tracing to OpenTelemetry + Logfire, and let reasoning through - #2
Move tracing to OpenTelemetry + Logfire, and let reasoning through#2Alex979 wants to merge 3 commits into
Conversation
Replaces the hand-rolled Langfuse instrumentation with two layers that meet
in one trace tree: @ai-sdk/otel emits GenAI-semconv spans for every model
call, step and tool execution, and telemetry.ts keeps describing the
pipeline stages the SDK knows nothing about.
The AI SDK integration has no way to be handed a parent -- it reads the
active OTel context -- which is exactly what telemetry.ts rule 3 was written
to avoid. Rather than give up explicit parenting, TraceSpan gains activate():
it opens the ambient context around a single model call and closes it again.
Logfire's startSpan takes a parentSpan, so every other span stays explicit.
Verified against a mock model: the per-step `chat` spans and per-tool
`execute_tool` spans nest correctly even though they are created during
stream consumption, long after the call returns.
Reasoning was never missing because of the tracing. Extended thinking is
already on at the Opus/Sonnet tier and billed as output tokens, but the API
defaults to display: "omitted", which returns thinking blocks with empty
text. Generation now sends { type: "adaptive", display: "summarized" };
SKILLCARD_GENERATE_THINKING overrides it, and the existing knob-fallback
drops the parameter for models that reject it. Visibility only -- no change
to token counts or cost. The runtime llm/grade services stay on their native
default: 1024 tokens against a rubric is not worth the round trip, and that
path has no fallback machinery.
There is no separate "thinking tokens" count to report anywhere -- the API
folds them into output_tokens.
|
Bugbot is not enabled for your account, so this pull request was not reviewed. Enable Bugbot in the Cursor dashboard to get automatic reviews on future PRs. |
Logfire aggregates `gen_ai.usage.*` over a span's whole subtree. Since the OTel port, every observation that wraps a model call has an `invoke_agent` span from @ai-sdk/otel nested directly inside it, reporting that same call's usage -- so a parent emitting the counts itself made the subtree sum them twice. `deck-orchestrator` showed 4.38K/9.83K and $0.2677 for a call that used 2.19K/4.92K and cost $0.1338, with nothing else underneath it. Before the port this was correct: the hand-built span was the only record of usage. It is now a duplicate of a more detailed one a level down. The counts stay on the span under `skillcard.usage.*`, which nothing aggregates. They are the app's normalized view (uncached input, per normalizeUsage) and the same numbers a card sees on /api/llm's `done` event, so keeping them is what lets the two be checked against each other. @ai-sdk/otel is authoritative for tokens and cost. Generations also no longer set `gen_ai.operation.name`. They wrap a model call rather than being one, and with usage gone the tag only made the backend render them as a second LLM call reporting no tokens. That leaves `child` and `generation` building an identical span; they stay separate on the interface because the call sites mean different things by them. Adds telemetry.test.ts covering the attribute mapping, so the usage-name rule fails a test rather than silently doubling a bill.
|
Pushed Logfire aggregates Counts now go out under Also dropped New |
The hand-written instrumentation existed because nothing else described model calls. `@ai-sdk/otel` does that now -- and in more detail than the wrapper ever did -- so most of telemetry.ts was describing, by hand and worse, what was already on the span nested directly inside it. telemetry.ts goes 435 -> 192 lines and the module drops from six concepts to one. `traced(name, attributes, fn)` opens a span for the callback and that is the whole surface. Gone: TraceSpan, startTrace, child/generation, update/fail/end, noopTrace, the toAttributes mapper, and activate(). activate() is the clearest case. It existed only to hand an explicit parent to code that reads ambient context. With pipeline spans on ambient context like everything else in OpenTelemetry, nesting is automatic and the method has nothing left to do. The `trace` parameter threaded through writeBrief, planDeck, implementCard, implementAndCheck and viewComponentTool goes with it -- nine signatures that only existed to carry a parent by hand. Spans that only restated an SDK span are deleted rather than ported: - view_component: `@ai-sdk/otel` emits `execute_tool view_component` with the arguments and the returned source already. - static-checks kept its span; it is real work the SDK cannot see. - llm-stream and grade-answer's generation span: the model call describes itself. `/api/llm` keeps one short span so a card's requestId/cardId still has somewhere to live. normalizeUsage moves to llm.ts next to wireUsage, its only caller, and usageDetails is deleted -- it existed to put token counts on a span, and @ai-sdk/otel is authoritative for those now. Fixes a bug found while verifying: `traced` caught the callback's own throw, logged it as a tracer failure, and re-ran the callback -- a duplicate API call on every synchronous failure. Async call sites reject rather than throw synchronously so none were affected in practice. Verified: 183 pass / 0 fail, typecheck clean. Against a mock model, four concurrently-built cards each kept their model call under their own card span in one trace tree -- the fan-out case explicit parenting was there to protect against. smoke-llm.ts now captures spans through an in-memory exporter instead of a fake TraceSpan, so it tests the real pipeline. Does not address the invoke_agent/chat cost double-count; that is upstream and unchanged by any of this.
Replaces the hand-rolled Langfuse instrumentation with OpenTelemetry, exported to Pydantic Logfire, and makes the model's reasoning visible in traces for the first time.
Why
Two separate things were hiding reasoning:
thinking.displaydefaults to"omitted". Extended thinking was already running and already billed as output tokens at the Opus/Sonnet tier, but the API returns thinking blocks with empty text unless asked otherwise. There was nothing in the response to trace.implementCard'sview_componentloop showed as one opaque generation.There is no separate "thinking tokens" count to surface anywhere; the API folds them into
output_tokens.What changed
Two layers, one trace tree.
@ai-sdk/otelemits GenAI-semantic-convention spans for every model call, step and tool execution (invoke_agent→step N→chat/execute_tool).telemetry.tskeeps describing the pipeline stages the SDK knows nothing about. In AI SDK 7 telemetry is opt-out once an integration is registered, so registration happens once at boot and nothing needs a per-call flag.TraceSpan.activate()is the bridge. The AI SDK integration has no way to be handed a parent — it reads the active OTel context, which is exactly whattelemetry.tsrule 3 was written to avoid (SSE handlers andPromise.allfan-outs are where ambient context goes wrong). Rather than give up explicit parenting everywhere,activateopens the ambient context around a single model call and closes it again. Logfire'sstartSpantakes aparentSpan, so every other span stays explicitly parented and rule 3 survives.Reasoning is now returned. Generation sends
thinking: { type: "adaptive", display: "summarized" }.SKILLCARD_GENERATE_THINKINGoverrides (omittedrestores the old hidden-but-running behavior,disabledturns thinking off), and the existing knob-fallback drops the parameter for models that reject it. Visibility only — no change to token counts or cost.The runtime
llm/gradeservices deliberately stay on their native default: 1024 tokens against a rubric isn't worth the round trip, and that path has no retry machinery to survive a model rejecting the parameter.Vendor-neutral on purpose.
@ai-sdk/otelwas chosen over@langfuse/vercel-ai-sdkso the model-call spans are standard GenAI semconv. The Logfire-specific surface is confined totelemetry.ts—configure(),startSpan,serializeAttributes, and thelogfire.level_num/logfire.msgkeys insidetoAttributes(). Swapping backends is a change to one function, not to the ~30 call sites.Verification
bun run typecheckclean;bun test175 pass / 0 fail;bun run buildclean.LOGFIRE_TOKEN) logs once and no-ops; the enabled path creates spans, and a failing export degraded to a warning rather than taking the request down — rule 2 holds.card-implementation → invoke_agent → step 1 → {chat, execute_tool}andstep 2 → chat. The per-step and per-tool spans nest correctly even though they are created during stream consumption, long afterstreamText()returns — the one thing I wasn't sure of going in.Notes for review
aiwas bumped 7.0.52 → 7.0.56 because@ai-sdk/otelpins it exactly; a duplicate nested install made the SDK's types structurally incompatible until deduped.@langfuse/otel,@langfuse/tracingand@opentelemetry/sdk-nodeare removed —logfire.configure()sets up the OTel SDK itself.invoke_agent → step 1 → chatfor what is one model call. That is inherent to GenAI semconv and there is no supported way to suppress those spans; they earn their keep on the multi-step card implementation calls.