fix(swift): anchor realtime answer-generation span to response.created#577
Conversation
The `response` (single) and `presenter`/direct (grounded) generation spans were created AND ended in the same synchronous block at `response.done`, so their exported latency was ~0 — in LangSmith the realtime LLM calls all showed 0.00s, while the non-realtime `llm.completion` spans (opened around the actual call) showed real durations. The OpenAI Realtime API sends no server-side timing (no timestamps on events, nothing in response.done/usage/ status_details), so the duration can only be measured client-side from the `response.created` → `response.done` receive-times. Backdate the generation's start to the response's `created` receive-time: - Tracing: add a defaulted `SpanHandle.generation(_:model:input:startedAt:)` overload (default ignores it and stamps now, so every existing conformer — OSLogTracer, test doubles, consumer custom tracers — keeps compiling); ProcessedSpan overrides it and threads `startedAt` through `child(...)`. - OpenAIVoiceAssistant: record `responseStartedAt[id]` at `.responseCreated`, pass it to the `response` generation, clear it in `resetTurn`. - OpenAIGroundedVoiceAssistant: record `presenterStartedAt` when the presenter/direct response is created, pass it to the `presenter` generation, clear on finish/fail. The generation now measures the true synthesis latency; tool time still shows as sibling `tool.*` spans and the `voice.turn` root keeps its full duration. Tests: RecordingTracer captures per-span start/end and the new overload; ProcessingTracerTests proves the backdate survives export; each assistant has a test that a real gap between response.created and response.done is reflected in the generation's duration (response, presenter, and direct paths). Co-authored-by: Claude <claude@anthropic.com>
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 9dd2b42193
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| presenterId = nil | ||
| presenterActive = false | ||
| truncation.reset() // clean finish — nothing left to truncate | ||
| defer { presenterStartedAt = nil } |
There was a problem hiding this comment.
Clear presenter start before awaiting persistence
When a grounded voice session has a store and persist suspends, this defer does not run until after the await persist(...) below. Because Swift actors are reentrant at that await, a new turn can process its presenter/direct response.created and set presenterStartedAt; when the old persist returns, this defer then clears the new turn's timestamp, causing the next presenter generation to fall back to Date() and record ~0 latency again.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Good catch — fixed in 0fce739. The defer ran at scope exit, i.e. after await persist(...); actor reentrancy at that await let the next turn's presenter response.created set presenterStartedAt during the suspension, and the deferred clear then wiped the new turn's timestamp (→ ~0 latency again). Now cleared synchronously before the await, matching the existing pendingUserText/replyText cleanup that already guards the same reentrancy window.
Codex review (PR #577): the `defer { presenterStartedAt = nil }` in the grounded clean-finish block runs at scope exit — AFTER `await persist(...)`. Actors are reentrant at that await, so a next turn can process its presenter/direct response.created and set `presenterStartedAt` during the suspension; the deferred clear then wipes the NEW turn's timestamp, and its presenter generation falls back to Date() → ~0 latency again. Clear it synchronously before the await instead, matching the existing pendingUserText/replyText cleanup that guards the same reentrancy window. Co-authored-by: Claude <claude@anthropic.com>
Closes #578
Problem
In LangSmith, every realtime
response/presenterLLM-call span shows Latency 0.00s, while the non-realtimellm.completionspans show real durations (e.g. 2.60s).Root cause: the realtime answer generation is created and ended in the same synchronous block at
response.done(OpenAIVoiceAssistant.swift:275,OpenAIGroundedVoiceAssistant.swift:265), soendedAt − startedAt ≈ 0. The non-realtimeAgent.callModel(Agent.swift:157) opens itsllm.completionspan around the actualmodel.complete()call, which is why it measures correctly — this fix makes the realtime path do the same.The OpenAI Realtime API provides no server-side timing (no timestamps on
response.created/response.done, nothing inresponse.usage/status_details), so latency can only be measured client-side from theresponse.created→response.donereceive-times.Fix
Backdate the generation's start to the response's
createdreceive-time:SpanHandle.generation(_:model:input:startedAt:)overload. The default ignoresstartedAtand stamps now, so every existing conformer (OSLogTracer, test doubles, any consumer customSpanHandle) keeps compiling unchanged.ProcessedSpanoverrides it and threadsstartedAtthroughchild(...).responseStartedAt[id]at.responseCreated, pass it to theresponsegeneration, clear inresetTurn.presenterStartedAtwhen the presenter/direct response is created, pass it to thepresentergeneration, clear on finish/fail.The generation now measures the true synthesis latency; tool time still shows as sibling
tool.*spans, and thevoice.turnroot keeps its full duration.Tests
RecordingTracercaptures per-span start/end and implements the new overload.ProcessingTracerTests.generationBackdatesStartedAtToTheGivenTime— the backdate survives finalize/export.response,presenter,direct): a real gap betweenresponse.createdandresponse.doneis reflected in the generation's duration. Verified stable across repeated runs.Full suite green (394 tests). No public breaking change (additive, defaulted).
🤖 Generated with Claude Code