Skip to content

feat(tracing): add request and first-token timestamps - #1190

Merged
yaozheng-fang merged 2 commits into
mainfrom
feat/first-token-timestamps
Oct 28, 2026
Merged

yaozheng-fang merged 2 commits into
mainfrom
feat/first-token-timestamps

Conversation

@wujiaming-ai

@wujiaming-ai wujiaming-ai commented Oct 28, 2026 •

Copy link
Copy Markdown
Collaborator

Model traces currently lose the first generated delta's receipt time, preventing A360 from separating request preprocessing from model first-output latency. This change adds request-start, model SDK request-start, and first-token timestamps to model spans and existing trace exports/dumps.

  • Capture request start at VeADK HTTP ASGI ingress or direct Runner execution, with isolated context propagation and an explicit source.
  • Observe LiteLLM Chat and Ark Responses raw SDK streams before ADK aggregation. Record the first nonempty text, reasoning, or tool-call delta once, using UTC Unix nanoseconds and a child span for each SDK request.
  • Distinguish the actual SDK streaming mode: non-streaming responses have no first-token timestamp; no-output and unsupported paths expose explicit status. Preserve attempt evidence through retries, errors, cancellation, and stream closure.
  • Document timing definitions/scopes in bilingual component specifications and tracing documentation. Client-render timing and TTFT/TPOT histogram recording remain outside this requirement.

Validation

  • Changed executable production-line coverage: 100% (208/208) against 23014771; no added coverage exclusions.
  • 244 affected tests passed, including 55 focused timing/adapter cases. Re-ran the affected suite and all applicable pre-commit hooks after fetching/rebasing onto the unchanged origin/main.
  • 6/6 real cloud E2E cases passed in cn-beijing using doubao-seed-2-1-pro-260628: Chat and Responses streaming/non-streaming, plus concurrent Chat/Responses streaming. All nine changed production files matched the deployed branch wheel's SHA256. Verified exported timestamps, SDK mode/status, parent relationships and request isolation. The isolated Runtime was deleted.
  • Documentation type checking and production build passed; bilingual identifiers/links and diff whitespace checks passed.
  • Default parallel regression after test stabilization: 7,942 passed, 0 failed, 42 skipped, 4 xfailed, plus 6 passing subtests. The original Sidecar baseline failure is resolved by isolating the fake runtime from parent upstream environment variables.
  • CI repair: exercise both Sandbox inspection orders, assert exact call multiplicities, and wait for both cached model states to appear in /web/system-info. This fixes an order-dependent test while preserving production concurrency and every existing state/endpoint assertion. Three targeted cases and all 189 affected cases passed; production code and the cloud-validated source hashes are unchanged. See the bilingual CI repair design and evidence.

Design and verification (English) · 需求与验证结论(中文)

@yaozheng-fang
yaozheng-fang merged commit c1d4096 into main Oct 28, 2026
30 checks passed
@feng-95

feng-95 commented Oct 30, 2026 •

Copy link
Copy Markdown
Contributor

@wujiaming-ai @yaozheng-fang 请按 APMPlus 规范补齐下面的属性和指标:

位置 名称 类型 / 单位
LLM Span 流式标记 gen_ai.request.stream bool,实际模型 SDK 请求是否流式
LLM Span TTFT 属性 gen_ai.chat_completions.streaming_time_to_first_token double,秒
TTFT 指标 gen_ai.chat_completions.streaming_time_to_first_token Histogram,单位 s

TTFT 是单次 LLM 流式请求开始到首个输出 token 到达的耗时。可以基于本次采集的模型请求开始时间和首 Token 时间计算:(first_token_time_unix_ns - model_start_time_unix_ns) / 1e9。Span 属性应填写这个秒级耗时,不能直接填绝对时间戳,也不能用整个 Agent 请求或 LLM Loop 的耗时代替。

目前只记录了 veadk.* 时间戳,portal_metrics.py 中 TTFT 的 .record() 仍是 TODO。请同时写入上述 Span 属性并实际记录同名 Histogram;每次 LLM 请求取得观测值时记录一次。非流式或没有首 Token 观测值时省略,不用 0 占位。现有自定义时间戳可以作为附加信息保留,并补充属性值、单位和指标记录的测试。

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.

3 participants