Repository navigation
fix(opencode): log prep_ms and ttft_step on turn.done - #23
PierrotAWB wants to merge 2 commits into
Conversation
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
|
Thanks for your contribution! This PR doesn't have a linked issue. All PRs must reference an existing issue. Please:
See CONTRIBUTING.md for details. |
|
This PR doesn't fully meet our contributing guidelines and PR template. What needs to be fixed:
Please edit this PR description to address the above within 2 hours, or it will be automatically closed. If you believe this was flagged incorrectly, please let a maintainer know. |
|
The following comment was made by an LLM, it may be inaccurate: |
There was a problem hiding this comment.
All reported issues were addressed across 2 files
Reply with feedback, questions, or to request a fix.
Re-trigger cubic
…ry backoff Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
There was a problem hiding this comment.
All reported issues were addressed across 3 files (changes from recent commits).
Reply with feedback, questions, or to request a fix.
Re-trigger cubic
|
Consolidated into #29 (one commit per concern there; review history for the prep_ms retry semantics is on this PR's threads). |
The
turn.donemetric's derived overhead (ttft_ms − provider_ttft_ms) is only valid when both timestamps come from the same step, butfirstTokenAtis set only onreasoning-start/text-start— nevertool-input-start— and the processor handle resets per step. On tool-first turns the pair captures from a later step and the subtraction silently absorbs tool execution wall-clock. Production sample (n=282): single-step turns show overhead p90 1.97s; multi-step turns show p90 59.8s with a worst case of 192.2s "overhead" on a 217.9s turn (88% of wall clock). 20% of turns report a bogus overhead >10s.This is additive — no existing field changes:
prep_ms: turnStart → the turn's FIRST provider request start, captured unconditionally (not gated on a token arriving). The harness-prep metric, correct by construction;undefinedif no request ever started.ttft_step: the 1-based step index the ttft pair was captured from, so consumers can detect and discard cross-step pairs.Follow-up worth a product decision, not implemented here: setting
firstTokenAtontool-input-startwould redefinettft_msas "time to first thing the user sees" — arguably more correct, but it changes an existing metric's meaning.Test: scripted two-step turn (tool-only step 1 → text step 2) through the TestLLMServer harness, asserting
ttft_step === 2andprep_mspresent and ≤ttft_msvia a capture logger at Debug level. Fail-first: both fields are absent on dev.Verified:
bun run typecheckclean,bun run lint0 errors,packages/opencodesuite 3129 pass / 1 flake (pty + truncate tests, pass 2/2 in isolation, unrelated surfaces),prompt.test.ts61/61.🤖 Generated with Claude Code
Summary by cubic
Log prep_ms and ttft_step on turn.done so TTFT-derived overhead is accurate on tool-first and multi-step turns, and stamp the first provider request start once so prep_ms excludes retry backoff. Previously the TTFT pair could come from a later step, inflating overhead with tool wall-clock.
firstRequestStartAtto theHandleand processor context; expose viahandle.firstRequestStartAt.Written for commit 82ad220. Summary will update on new commits.