Skip to content

Move tracing to OpenTelemetry + Logfire, and let reasoning through - #2

Open
Alex979 wants to merge 3 commits into
mainfrom
logfire-otel-telemetry
Open

Move tracing to OpenTelemetry + Logfire, and let reasoning through#2
Alex979 wants to merge 3 commits into
mainfrom
logfire-otel-telemetry

Conversation

@Alex979

@Alex979 Alex979 commented Aug 7, 2026

Copy link
Copy Markdown
Owner

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:

  1. thinking.display defaults 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.
  2. The tracing described model calls by hand. Every span was hand-built, so tool loops, per-step turns, and per-tool executions were invisible — implementCard's view_component loop 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/otel emits GenAI-semantic-convention spans for every model call, step and tool execution (invoke_agentstep Nchat / execute_tool). telemetry.ts keeps 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 what telemetry.ts rule 3 was written to avoid (SSE handlers and Promise.all fan-outs are where ambient context goes wrong). Rather than give up explicit parenting everywhere, activate opens the ambient context around a single model call and closes it again. Logfire's startSpan takes a parentSpan, so every other span stays explicitly parented and rule 3 survives.

Reasoning is now returned. Generation sends thinking: { type: "adaptive", display: "summarized" }. SKILLCARD_GENERATE_THINKING overrides (omitted restores the old hidden-but-running behavior, disabled turns 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 / grade services 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/otel was chosen over @langfuse/vercel-ai-sdk so the model-call spans are standard GenAI semconv. The Logfire-specific surface is confined to telemetry.tsconfigure(), startSpan, serializeAttributes, and the logfire.level_num / logfire.msg keys inside toAttributes(). Swapping backends is a change to one function, not to the ~30 call sites.

Verification

  • bun run typecheck clean; bun test 175 pass / 0 fail; bun run build clean.
  • Telemetry exercised both ways: the disabled path (no 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.
  • Span nesting verified against a mock model with a two-step tool loop. All 7 spans landed in a single trace: card-implementation → invoke_agent → step 1 → {chat, execute_tool} and step 2 → chat. The per-step and per-tool spans nest correctly even though they are created during stream consumption, long after streamText() returns — the one thing I wasn't sure of going in.
  • Confirmed working against real Logfire on a live deck generation.

Notes for review

  • ai was bumped 7.0.52 → 7.0.56 because @ai-sdk/otel pins it exactly; a duplicate nested install made the SDK's types structurally incompatible until deduped.
  • @langfuse/otel, @langfuse/tracing and @opentelemetry/sdk-node are removed — logfire.configure() sets up the OTel SDK itself.
  • Single-turn calls now show invoke_agent → step 1 → chat for 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.

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.
@cursor

cursor Bot commented Aug 7, 2026

Copy link
Copy Markdown

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.
@Alex979

Alex979 commented Aug 7, 2026

Copy link
Copy Markdown
Owner Author

Pushed c1ee22d — fixes token/cost double-counting found in review.

Logfire aggregates gen_ai.usage.* over a span's whole subtree. Since this port, every observation wrapping a model call has an invoke_agent span from @ai-sdk/otel nested 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 beneath it.

Counts now go out under skillcard.usage.*, which nothing aggregates. @ai-sdk/otel is authoritative for tokens and cost.

Also dropped gen_ai.operation.name from generations — they wrap a model call rather than being one, and with usage gone the tag only made them render as a second, token-less LLM call.

New telemetry.test.ts covers the attribute mapping (182 pass / 0 fail, typecheck clean) so the usage-name rule fails a test rather than silently doubling a bill.

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.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant