LLMResponse 答不出「这次调用总共等了多久、试了几次」 #23

Closed
opened 2026-09-07 16:45:39 +08:00 by iomgaa · 1 comment
Owner

现象

LLMResponse.latency_ms 是单次成功尝试的耗时,不是整条逻辑调用的耗时。失败尝试的耗时、
退避时长、尝试次数,一个都不交给调用方。

代码位置(polygateway 1.3.3):

  • middleware/retry.py:279 —— started = self._now() 在 _attempt 内部,每次尝试各自计时
  • middleware/retry.py:385 —— _build_response 用这个 started 算 latency_ms
  • middleware/retry.py:400-425 —— _emit 是逐次尝试发的,所以这些数据在库内部是有的,
    只是不出现在交回调用方的 LLMResponse 上

为什么这是个问题

库的边界是「决定要不要再试一次」。既然重试归库管,那么「试了几次、总共等了多长」就只有
库答得出——调用方看到的是一条逻辑调用,它没有任何途径知道里面发生过什么。

现在下游要拿到这个数,唯一的办法是记下自己发起调用的时刻,再用相邻两次调用的时间差去反推。
那是逆向工程,不是观测,而且有两个硬伤:只在「调用严格串行」时成立;反推出来的是两次模型
调用之间发生的一切
,把网关的重试等待和调用方自己干的活混在一堆里,拆不开。

实测:这段时间有多大

一次真实实验的一个 seed(终端任务 benchmark,共 89 道题,这一批跑其中 30 道;每道题有墙钟
预算,ReAct 循环内严格串行):

  • 1073 次逻辑调用,latency_ms 合计 20436 秒
  • 按题分组、组内按时间排序,用相邻调用 started_at 之差减去 latency_ms,得到 8476 秒
    没有被任何字段记住
  • 这 8476 秒里有一部分是调用方自己在跑东西(我们的 agent 在容器里执行 shell 命令),拆出来
    之后,剩下约 4800 秒归在网关这一侧

我们没法把这个拆分做干净,因为拆不干净正是这个 issue 说的事。 举个具体的例子:那批间隙里
有 14 次落在 300–600 秒区间,我们一开始以为它们全是「第一次尝试挂满 300 秒超时、重试才成功」
——因为我们给那个源配的 TIMEOUT_S 正好是 300。后来把每个间隙映射回轨迹才发现,其中 11 次
是我们自己的命令跑满了另一个也配成 300 秒的超时
,只有 3 次可能是网关那侧。两个不相干的
300 撞在一起,而我们手上没有任何字段能把它们分开,只能靠翻日志一条条对。

要是 LLMResponse 直接给出 attempts 和 total_latency_ms,这件事就是一次减法。

在墙钟受限的 benchmark 上,这段时间直接从任务预算里扣掉、导致任务超时失败,而失败原因在数据
里查不出来——看上去就是「agent 没做完」。

建议

LLMResponse 增加:

  • attempts: int —— 这条逻辑调用总共尝试了几次
  • total_latency_ms: int —— 从进入 retry 中间件到返回的总耗时,含失败尝试与退避

可选(如果不嫌字段多):

  • attempt_latencies_ms: list[int]
  • attempt_errors: list[str | None] —— 每次失败的归类,复用 _failure_reason 的取值

前两个就够用:有了 attempts > 1 和 total_latency_ms,调用方就能把「等待」这一项如实落盘,
也能在监控里发现某个源正在系统性地挂请求。

环境

polygateway 1.3.3,Python 3.12,OpenAI 兼容 transport,非流式。

## 现象 `LLMResponse.latency_ms` 是**单次成功尝试**的耗时,不是整条逻辑调用的耗时。失败尝试的耗时、 退避时长、尝试次数,一个都不交给调用方。 代码位置(polygateway 1.3.3): - `middleware/retry.py:279` —— `started = self._now()` 在 `_attempt` 内部,每次尝试各自计时 - `middleware/retry.py:385` —— `_build_response` 用这个 `started` 算 `latency_ms` - `middleware/retry.py:400-425` —— `_emit` 是逐次尝试发的,所以**这些数据在库内部是有的**, 只是不出现在交回调用方的 `LLMResponse` 上 ## 为什么这是个问题 库的边界是「决定要不要再试一次」。既然重试归库管,那么「试了几次、总共等了多长」就只有 库答得出——调用方看到的是一条逻辑调用,它没有任何途径知道里面发生过什么。 现在下游要拿到这个数,唯一的办法是记下自己发起调用的时刻,再用相邻两次调用的时间差去反推。 那是逆向工程,不是观测,而且有两个硬伤:只在「调用严格串行」时成立;反推出来的是**两次模型 调用之间发生的一切**,把网关的重试等待和调用方自己干的活混在一堆里,拆不开。 ## 实测:这段时间有多大 一次真实实验的一个 seed(终端任务 benchmark,共 89 道题,这一批跑其中 30 道;每道题有墙钟 预算,ReAct 循环内严格串行): - 1073 次逻辑调用,`latency_ms` 合计 20436 秒 - 按题分组、组内按时间排序,用相邻调用 `started_at` 之差减去 `latency_ms`,得到 **8476 秒** 没有被任何字段记住 - 这 8476 秒里有一部分是调用方自己在跑东西(我们的 agent 在容器里执行 shell 命令),拆出来 之后,剩下约 4800 秒归在网关这一侧 **我们没法把这个拆分做干净,因为拆不干净正是这个 issue 说的事。** 举个具体的例子:那批间隙里 有 14 次落在 300–600 秒区间,我们一开始以为它们全是「第一次尝试挂满 300 秒超时、重试才成功」 ——因为我们给那个源配的 `TIMEOUT_S` 正好是 300。后来把每个间隙映射回轨迹才发现,**其中 11 次 是我们自己的命令跑满了另一个也配成 300 秒的超时**,只有 3 次可能是网关那侧。两个不相干的 300 撞在一起,而我们手上没有任何字段能把它们分开,只能靠翻日志一条条对。 要是 `LLMResponse` 直接给出 `attempts` 和 `total_latency_ms`,这件事就是一次减法。 在墙钟受限的 benchmark 上,这段时间直接从任务预算里扣掉、导致任务超时失败,而失败原因在数据 里查不出来——看上去就是「agent 没做完」。 ## 建议 `LLMResponse` 增加: - `attempts: int` —— 这条逻辑调用总共尝试了几次 - `total_latency_ms: int` —— 从进入 retry 中间件到返回的总耗时,含失败尝试与退避 可选(如果不嫌字段多): - `attempt_latencies_ms: list[int]` - `attempt_errors: list[str | None]` —— 每次失败的归类,复用 `_failure_reason` 的取值 前两个就够用:有了 `attempts > 1` 和 `total_latency_ms`,调用方就能把「等待」这一项如实落盘, 也能在监控里发现某个源正在系统性地挂请求。 ## 环境 polygateway 1.3.3,Python 3.12,OpenAI 兼容 transport,非流式。
Author
Owner

本 issue 由 1.3.5 关闭(main ab00aa44576bd4cd47d0680d107d5191679dc1ee,tag v1.3.5,已上传 registry)。

治理单位从「一次尝试」补齐到「一次逻辑调用」:新导出 frozen dataclass polygateway.CallStats(logical_call_id / attempts / total_latency_ms),LLMResponse、EmbeddingResponse、OcrTextResult、OcrLayoutResult 末尾各追加 call_stats: CallStats | None = None(按位置解包这四个类型的代码需要检查)。失败侧同样可答:重试耗尽、结构化耗尽、无源与准入拒绝、取消都会写恰一条 event_kind='terminal_failure' 行,带 attempts 与 total_latency_ms;此前结构化耗尽与 embedding/OCR 的无源、准入拒绝一条遥测行都没有。

下游必须做的迁移(不做会静默出错)

动作 说明
自建 TelemetryRecorder 补 10 个 keyword-only 参数(26 → 36),或改成 **fields 装配期当场 ValueError,不是运行期静默丢行。旧签名 recorder 升级后会在 TelemetryEmitter 构造时被拒
PG manual 档自行补列 telemetry_schema_sql("postgres") 自取;不补则这 10 维按现有列裁剪后不落库(库发一条点名警告)
计失败调用改 WHERE event_kind = 'terminal_failure' 一次逻辑调用恰一条终态行。沿用 error IS NOT NULL 会跨尝试行与终态行,升级后计数变大(400 密集负载下错误行翻倍,是已批准的可见变化)
AVG(latency_ms) 按 event_kind 分组 终态行的 latency_ms 是整次逻辑调用总耗时,与单次尝试不同量纲

口径澄清(避免误读)

  • 新增的失败统计列与 terminal_failure 行是常规遥测口径变更,不是"异常字段":它们对每次逻辑调用恒定产生,下游按新口径统计即可,不应当成偶发脏数据过滤掉。
  • 费用口径不变:终态行 cost IS NULL、usage_source='unavailable'、token 为 0,不参与 SUM(cost),不会双计。
  • http_status_code 不可当成败判据:MonkeyOCR 的 success != true 就是 200 下的失败;终态行该列为 NULL(不冒充某一次尝试的状态码)。
  • 新列全部可空、追加在末列之后、旧行不回填(NULL 表达"补列之前根本没记过这件事"),滚动升级期新旧进程可写同一张表。

验证范围声明

已跑:合并后 make lint(import-linter 1 kept / 0 broken)、全套件 make test(1605 passed / 23 skipped / 108 deselected / 95%)、真实网关 e2e 冒烟 4 节点、Redis 时间语义 slow 18 项、真实 Postgres 列兼容 30 项,以及从 registry 独立安装后的离线真链路复核(3 条 attempt + 恰 1 条 terminal_failure、诊断列记真实 503、终态 cost 为 NULL)。
未做全模型矩阵与全渠道验证:本版未触碰推理路径,沿用 1.3.4 的型号级结论及其 FAIL/UNKNOWN/不可达例外,不代表所有模型或所有上游渠道都已验证可用。

本 issue 由 **1.3.5** 关闭(main `ab00aa44576bd4cd47d0680d107d5191679dc1ee`,tag `v1.3.5`,已上传 registry)。 治理单位从「一次尝试」补齐到「一次逻辑调用」:新导出 frozen dataclass `polygateway.CallStats`(`logical_call_id` / `attempts` / `total_latency_ms`),`LLMResponse`、`EmbeddingResponse`、`OcrTextResult`、`OcrLayoutResult` **末尾**各追加 `call_stats: CallStats | None = None`(按位置解包这四个类型的代码需要检查)。失败侧同样可答:重试耗尽、结构化耗尽、无源与准入拒绝、取消都会写恰一条 `event_kind='terminal_failure'` 行,带 `attempts` 与 `total_latency_ms`;此前结构化耗尽与 embedding/OCR 的无源、准入拒绝**一条遥测行都没有**。 ### 下游必须做的迁移(不做会静默出错) | 动作 | 说明 | | --- | --- | | 自建 `TelemetryRecorder` 补 10 个 keyword-only 参数(26 → 36),或改成 `**fields` | **装配期当场 `ValueError`**,不是运行期静默丢行。旧签名 recorder 升级后会在 `TelemetryEmitter` 构造时被拒 | | PG manual 档自行补列 | `telemetry_schema_sql("postgres")` 自取;不补则这 10 维按现有列裁剪后不落库(库发一条点名警告) | | 计失败调用改 `WHERE event_kind = 'terminal_failure'` | 一次逻辑调用恰一条终态行。沿用 `error IS NOT NULL` 会跨尝试行与终态行,升级后计数变大(400 密集负载下错误行翻倍,是已批准的可见变化) | | `AVG(latency_ms)` 按 `event_kind` 分组 | 终态行的 `latency_ms` 是整次逻辑调用总耗时,与单次尝试不同量纲 | ### 口径澄清(避免误读) - 新增的失败统计列与 `terminal_failure` 行是**常规遥测口径变更,不是"异常字段"**:它们对每次逻辑调用恒定产生,下游按新口径统计即可,不应当成偶发脏数据过滤掉。 - 费用口径不变:终态行 `cost IS NULL`、`usage_source='unavailable'`、token 为 0,不参与 `SUM(cost)`,不会双计。 - `http_status_code` **不可当成败判据**:MonkeyOCR 的 `success != true` 就是 200 下的失败;终态行该列为 NULL(不冒充某一次尝试的状态码)。 - 新列全部可空、追加在末列之后、**旧行不回填**(NULL 表达"补列之前根本没记过这件事"),滚动升级期新旧进程可写同一张表。 ### 验证范围声明 已跑:合并后 `make lint`(import-linter 1 kept / 0 broken)、全套件 `make test`(1605 passed / 23 skipped / 108 deselected / 95%)、真实网关 e2e 冒烟 4 节点、Redis 时间语义 slow 18 项、真实 Postgres 列兼容 30 项,以及从 registry 独立安装后的离线真链路复核(3 条 attempt + 恰 1 条 terminal_failure、诊断列记真实 503、终态 `cost` 为 NULL)。 **未做**全模型矩阵与全渠道验证:本版未触碰推理路径,沿用 1.3.4 的型号级结论及其 FAIL/UNKNOWN/不可达例外,**不代表所有模型或所有上游渠道都已验证可用**。
Sign in to join this conversation.
No Label
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: iomgaa/PolyGateway#23