feat: record call observability columns and terminal failure rows

Grow the telemetry contract from 26 to 36 fields and give every logical call a failure terminal row, so SQL can finally answer "how many calls failed" and "why did the whole pool die". Schema and port move together with the emitter writes in one commit: splitting them would ship columns that nothing populates. - schema: append 10 nullable columns (scope, operation, logical_call_id, event_kind, http_status_code, error_type, cause_type, error_body, attempts, total_latency_ms) to all five definition sites in one order - ports: 10 keyword-only parameters without defaults; the protocol signature is now the single source the assembly gate derives from - emitter: take domain exception objects instead of pre-flattened text and pin down the diagnostics in one helper; a relabelled 503 stays 503 and success rows leave all five columns NULL - emitter: reject recorders whose record_llm_call cannot accept the current field shape at assembly time, since _record would otherwise swallow the TypeError and drop every row while calls keep succeeding - clients: write at most one terminal row per logical call through a single shared exit, deduplicated by the call context; TelemetryMW stops writing terminals so the two sites cannot double count - clients: cancellation stays best effort and propagates, non-domain exceptions get no terminal row and keep their classification - transports: give _status_to_error an explicit operation and fix the historically mislabelled embedding HTTP failures - structured: promote the bounded error formatter so the reask feedback and the terminal explanation share one set of limits Terminal rows carry no cost and no tokens, so cost aggregation is unchanged; failure counts must now filter on event_kind.
2026-09-09 11:27:52 -04:00
parent 87c261bf73
commit 393f2bf617
19 changed files with 1628 additions and 194 deletions
@@ -2,13 +2,19 @@

 Emitter 是全库**唯一**调用 `record_llm_call` 的地方(三项目 4 处逐字复制
 15 参调用的教训)。分工: RetryMW 经 Emitter 逐次记录每次尝试;TelemetryMW
-(最外层)只记尝试层看不见的事件——缓存命中、scope 级失败、取消;
-RequestRejected/ResultInvalid 已被尝试层记录,最外层放行不重复记。
+(最外层)只记尝试层看不见的缓存命中;而**终态失败行**由三个 client 的公开
+边界经 `emit_terminal_once` 统一写出(1.3.5)——两处同时写就会双计。
+
+一行遥测属于三类事件之一(`event_kind`): `attempt`(一次尝试)、`cache_hit`
+(未产生网关调用)、`terminal_failure`(一次**逻辑调用**的失败终态)。后两者与
+前者**不是重复事实**,故统计失败调用次数只能取 `terminal_failure`,
+不得按 `error IS NOT NULL` 跨两类直接计数(设计 §6/§8)。
 """

 from __future__ import annotations

 import asyncio
+import inspect
 import json
 import time
 import uuid
@@ -17,12 +23,10 @@ from typing import TYPE_CHECKING

 from loguru import logger

-from polygateway.errors import (
-    GatewayUnavailableError,
-    GovernanceBackendError,
-    SourceNotConfiguredError,
-)
+from polygateway.errors import PolyGatewayError, ResultInvalidError
 from polygateway.middleware.cache import digest_messages
+from polygateway.middleware.structured import MAX_ERROR_CHARS, format_bounded_errors
+from polygateway.ports import TelemetryRecorder
 from polygateway.thinking import effective_effort
 from polygateway.types import Effort, ThinkingObservation, canonical_sampling_json, merge_sampling

@@ -30,9 +34,17 @@ if TYPE_CHECKING:
    from collections.abc import Callable, Mapping
    from typing import Any

-    from polygateway.ports import CallNext, TelemetryRecorder
+    from polygateway.ports import CallNext
    from polygateway.pricing import PricingTable
-    from polygateway.types import ChatRequest, LLMResponse, SourceConfig
+    from polygateway.types import (
+        CallOperation,
+        CallStats,
+        ChatRequest,
+        EventKind,
+        LLMResponse,
+        SourceConfig,
+        _CallContext,
+    )


 def _canonical_meta_json(meta: Mapping[str, Any]) -> str:
@@ -225,26 +237,159 @@ class _AttemptUsage:
        )


+@dataclass(frozen=True)
+class _ErrorFields:
+    """一行遥测的错误列;未知一律 `None`。
+
+    存在的理由是把"三种入参形态 × 两类行"的定型规则收敛到**一处**:
+    改前调用方先 `str(exc)` 压平,状态码、底层异常类型与网关正文全部丢失。
+    """
+
+    error: str | None = None
+    error_type: str | None = None
+    cause_type: str | None = None
+    http_status_code: int | None = None
+    error_body: str | None = None
+
+
+def _structured_detail(exc: ResultInvalidError) -> str:
+    """结构化阶梯耗尽的**有界**说明(设计 §5 C2)。
+
+    `ResultInvalidError("结构化输出阶梯耗尽")` 的 message 不含校验与修复错误,而该
+    失败发生在 StructuredMW 之上——RetryMW 侧的 attempt 行全是**成功行**,终态行是
+    唯一记录。故把说明并入现有 `error` 串。
+
+    **不含 `raw_text`**: 它是模型正文,attempt 行的 `response` 列已按 `text_cap` 记过
+    一份;再存一份等于绕过既有的正文预算。条数与限长复用 `structured.py` 的同一
+    套常量(重问反馈与本说明同一口径),数值只有一份。
+    """
+    parts: list[str] = []
+    if exc.repair_error:
+        parts.append(f"repair={exc.repair_error[:MAX_ERROR_CHARS]}")
+    if exc.validation_errors:
+        parts.append(f"validation={format_bounded_errors(exc.validation_errors)}")
+    return " | ".join(parts)
+
+
+def _error_fields(
+    error: PolyGatewayError | str | None,
+    *,
+    event_kind: EventKind,
+    class_prefixed: bool,
+) -> _ErrorFields:
+    """三种入参形态的唯一定型点(设计 §5/§6)。
+
+    - `None` → 全 None(成功行不统一填 200: 那会让"有状态码"不再等价于"失败了")。
+    - `str`(取消路径的 `"cancelled"`)→ 原样落 `error`,**不解析字符串猜诊断**。
+    - 领域异常 → 只读它既有的属性,不遍历任意对象、不猜正文。
+
+    **终态行的三列恒为 NULL(C1 红线)**: `GatewayUnavailableError` 家族从不携带
+    状态码与响应体,NULL 正是它自身的真实状态——把最后一次 attempt 的状态码与正文
+    搬上来,就是拿最后一个源冒充整池归因。逐源现场由同一 `logical_call_id` 的
+    attempt 行给出。
+    """
+    if error is None:
+        return _ErrorFields()
+    if isinstance(error, str):
+        return _ErrorFields(error=error)
+    name = type(error).__name__
+    # 空 `str()` 退回类名(httpx 的 Connect/Read/Write/PoolTimeout 文案就是空的);
+    # `class_prefixed` 是 OCR 的既有口径(按类名归组的 metric),故逐字保留它的拼法
+    text = f"{name}: {error}" if class_prefixed else (str(error) or name)
+    if event_kind == "terminal_failure":
+        if isinstance(error, ResultInvalidError):
+            detail = _structured_detail(error)
+            if detail:
+                text = f"{text} | {detail}"
+        return _ErrorFields(error=text, error_type=name)
+    cause = error.__cause__
+    return _ErrorFields(
+        error=text,
+        error_type=name,
+        cause_type=type(cause).__name__ if cause is not None else None,
+        # getattr 而非直读: 本函数在 `_record` 的降级 try **之外**求值,
+        # 一个非领域异常误传进来不得把一次真实失败换成 AttributeError
+        http_status_code=getattr(error, "status_code", None),
+        # 空串归 None: 既有 `body_text` 的缺省就是空串,而本列的语义是"未知"
+        error_body=getattr(error, "body_text", "") or None,
+    )
+
+
+def _assert_recorder_shape(recorder: TelemetryRecorder) -> None:
+    """装配期一次 `signature.bind` 形状校验: 不执行写入,只证明该形状能被接受。
+
+    `_record` 的 `except Exception` 会把旧 recorder 的 `TypeError` 吞成 warning,
+    后果是自定义 recorder 在下游升级后**100% 丢遥测且调用照常成功**——正是
+    "遥测必录"要防的形态,而文档级迁移清单挡不住它。故在装配期当场报错
+    (不是 warning: 降级方向的铁律管的是**运行期写失败**,不是装配错误)。
+
+    参数名从 `TelemetryRecorder.record_llm_call` 的协议签名**派生**(不手抄第四份
+    字段清单),绑定用哨兵 `None`,不读任何真实请求数据;`**kwargs`
+    (VAR_KEYWORD)自动通过。不可 inspect(C 实现等)同样按配置错误报错——宁可
+    装配不起来,不进入"运行期静默丢行"。
+
+    边界诚实声明: 它只证明该形状能被接受,**不能证明函数体真的落这些列**。
+
+    Raises:
+        ValueError: 签名不符、不可 inspect,或协议本身不可 inspect。
+    """
+    try:
+        # 模块全局查找而非常量快照: 协议改了,闸就跟着改(测试可据此机械验证)
+        protocol = inspect.signature(TelemetryRecorder.record_llm_call).parameters
+    except (TypeError, ValueError) as exc:  # pragma: no cover - 协议一向可 inspect
+        raise ValueError(f"TelemetryRecorder.record_llm_call 签名不可读取: {exc}") from exc
+    sentinels = {name: None for name in protocol if name != "self"}
+    label = type(recorder).__name__
+    method = getattr(recorder, "record_llm_call", None)
+    if method is None:
+        # 连方法都没有: 比旧签名更明确的配置错误。不让它以裸 AttributeError
+        # 逆流而上——那不属错误四分类,且现场离"注错了东西"这个真因很远
+        raise ValueError(
+            f"注入的遥测 recorder {label} 没有 record_llm_call 方法,不满足 TelemetryRecorder 端口"
+        )
+    try:
+        signature = inspect.signature(method)
+    except (TypeError, ValueError) as exc:
+        raise ValueError(
+            f"遥测 recorder {label} 的 record_llm_call 不可 inspect(如 C 实现),"
+            "无法在装配期确认它接受当前字段形状;请换成 Python 实现或包一层"
+        ) from exc
+    try:
+        signature.bind(**sentinels)
+    except TypeError as exc:
+        raise ValueError(
+            f"遥测 recorder {label} 的 record_llm_call 签名与 TelemetryRecorder 不符"
+            f"(当前 {len(sentinels)} 个字段): {exc}。"
+            "这一条故意在装配期报错——放行的后果是每行遥测都被降级成 warning 后丢弃"
+        ) from exc
+
+
 class TelemetryEmitter:
-    """从请求与结果组装 26 字段并写入 recorder;一切写失败降级 warning。"""
+    """从请求与结果组装 36 字段并写入 recorder;一切写失败降级 warning。"""

    def __init__(
        self,
        recorder: TelemetryRecorder,
        *,
+        scope: str,
        pricing: PricingTable | None = None,
        text_cap: int | None,
    ) -> None:
-        """`text_cap` 无默认值是有意的: 它是关键行为参数,漏传即静默改变落库正文。
+        """`text_cap` 与 `scope` 无默认值是有意的: 两者都是关键行为参数。

+        `text_cap` 漏传即静默改变落库正文;`scope` 漏传则三类行都失去池名
+        ——终态失败可能根本没选出源,但 scope 始终已知,不拿 `source_name` 顶替。
        本类是库内部类,唯一构造者是三个公共 Client,必填能保证没有一处漏传。
-        同理,值域校验也放在这一处: 三个 Client 的 `text_cap` 全部汇流到这里,
+
+        同理,值域校验与**装配闸**都放在这一处: 三个 Client 全部汇流到这里,
        `GatewaySettings` 那道只管 env 一条路,而直接构造 Client 是库承诺的另一
-        条公共装配路——`text_cap=0` 会让每条正文只剩一个省略标记(P5 不得静默)。
+        条公共装配路(`text_cap=0` 会让每条正文只剩一个省略标记;P5 不得静默)。
        """
        if text_cap is not None and text_cap <= 0:
            raise ValueError(f"text_cap 必须 > 0(不截断请传 None): {text_cap}")
+        _assert_recorder_shape(recorder)
        self._recorder = recorder
+        self._scope = scope
        self._pricing = pricing
        self._text_cap = text_cap

@@ -256,8 +401,10 @@ class TelemetryEmitter:
        call_id: str,
        latency_ms: int,
        response: LLMResponse | None,
-        error: str | None,
+        error: PolyGatewayError | str | None,
        reasoning_applies: bool,
+        operation: CallOperation,
+        class_prefixed_error: bool = False,
    ) -> None:
        """逐次尝试记录(三个 Client 的重试层调用);失败尝试无用量可言,记 0 并标 unavailable。

@@ -266,7 +413,11 @@ class TelemetryEmitter:
        共用同一个 `SourceConfig` 类型,一个误配了 `ENABLE_THINKING` 的 embedding 源
        会让下面的回落算出 `auto`,给一次从来不带推理参数的调用挂上一个从未发出过的
        档。**不设默认值**: 与 `TelemetryRecorder` 同一约定,库外无第三方调用者,漏传
-        当场 TypeError,好过被静默当成"没表态"。
+        当场 TypeError,好过被静默当成"没表态"。`operation` 同理且另有一层:
+        它只能由调用点给定,**绝不读 `exc.operation`**(后者是 HTTP 子操作)。
+
+        `error` 收**领域异常对象**而非预先 `str()` 压平的文本: 状态码/底层异常类型/
+        网关正文在此提取成四列(设计 §5)。取消路径仍传既有字符串 `"cancelled"`。
        """
        usage = _AttemptUsage.of(response)
        await self._record(
@@ -284,7 +435,7 @@ class TelemetryEmitter:
            ttft_ms=usage.ttft_ms,
            max_inter_token_ms=usage.max_inter_token_ms,
            cache_hit=False,
-            error=error,
+            errors=_error_fields(error, event_kind="attempt", class_prefixed=class_prefixed_error),
            cached_prompt_tokens=usage.cached_prompt_tokens,
            model_reported=usage.model_reported,
            reasoning_tokens=usage.reasoning_tokens,
@@ -296,10 +447,19 @@ class TelemetryEmitter:
            reasoning_effort=_attempt_effort(
                request=request, source=source, response=response, applies=reasoning_applies
            ),
+            operation=operation,
+            event_kind="attempt",
+            attempts=None,
+            total_latency_ms=None,
        )

-    async def emit_cache_hit(self, *, request: ChatRequest, response: LLMResponse) -> None:
-        """缓存命中记录: cache_hit=True、latency_ms=0(VT 同款)。"""
+    async def emit_cache_hit(
+        self, *, request: ChatRequest, response: LLMResponse, operation: CallOperation
+    ) -> None:
+        """缓存命中记录: cache_hit=True、latency_ms=0(VT 同款)。
+
+        逻辑计数两列恒 NULL: 本行描述的是"一次命中",不是一次逻辑调用的终态。
+        """
        await self._record(
            request=request,
            call_id=response.call_id,
@@ -315,7 +475,7 @@ class TelemetryEmitter:
            ttft_ms=None,
            max_inter_token_ms=None,
            cache_hit=True,
-            error=None,
+            errors=_ErrorFields(),
            # 决策 B1: 与 model/prompt_tokens 同一口径,原样回放历史值。
            # 统计供应商缓存命中率必须带 WHERE cache_hit = false,否则重复计数。
            cached_prompt_tokens=response.cached_prompt_tokens,
@@ -334,12 +494,28 @@ class TelemetryEmitter:
            # 与 sampling 同一口径: 命中行没有选中源,源级档位与 `nearest` 映射
            # 都无从谈起,只记调用方这次要的档(response 里那个是历史那次实发的)
            reasoning_effort=_normalize_effort(request.reasoning_effort),
+            operation=operation,
+            event_kind="cache_hit",
+            attempts=None,
+            total_latency_ms=None,
        )

    async def emit_terminal_failure(
-        self, *, request: ChatRequest, call_id: str, latency_ms: int, error: str
+        self,
+        *,
+        request: ChatRequest,
+        call_id: str,
+        error: PolyGatewayError | str,
+        operation: CallOperation,
+        stats: CallStats,
+        class_prefixed_error: bool = False,
    ) -> None:
-        """scope 级失败/取消记录: 无具体源,溯源字段置空标记。"""
+        """一次**逻辑调用**的失败终态: 无具体源,溯源字段置空标记。
+
+        `latency_ms` 与 `total_latency_ms` 同取**同一份冻结快照**,避免双时钟微差;
+        故本方法不再收 `latency_ms`。token 与 cost 一律不从 attempt 行复制
+        (费用聚合仍只由 attempt / cache_hit 行决定,口径不变)。
+        """
        await self._record(
            request=request,
            call_id=call_id,
@@ -351,11 +527,13 @@ class TelemetryEmitter:
            prompt_tokens=0,
            completion_tokens=0,
            usage_source="unavailable",
-            latency_ms=latency_ms,
+            latency_ms=stats.total_latency_ms,
            ttft_ms=None,
            max_inter_token_ms=None,
            cache_hit=False,
-            error=error,
+            errors=_error_fields(
+                error, event_kind="terminal_failure", class_prefixed=class_prefixed_error
+            ),
            cached_prompt_tokens=None,
            model_reported=None,
            reasoning_tokens=None,
@@ -368,6 +546,10 @@ class TelemetryEmitter:
            meta=request.meta,
            # 可能根本没选出源,故与 sampling 同样只取请求档
            reasoning_effort=_normalize_effort(request.reasoning_effort),
+            operation=operation,
+            event_kind="terminal_failure",
+            attempts=stats.attempts,
+            total_latency_ms=stats.total_latency_ms,
        )

    async def _record(
@@ -387,7 +569,9 @@ class TelemetryEmitter:
        ttft_ms: float | None,
        max_inter_token_ms: float | None,
        cache_hit: bool,
-        error: str | None,
+        # 1.3.5: 错误四列已由 `_error_fields` 定型(三种入参形态 × 两类行的唯一规则所有者),
+        # 本方法只搬运——拆成五个平铺参数就是把"一处定型"换回"三处各自拼"
+        errors: _ErrorFields,
        cached_prompt_tokens: int | None,
        model_reported: str | None,
        sampling: str | None,
@@ -403,6 +587,11 @@ class TelemetryEmitter:
        # 注释),本方法只搬运——把定型放这里就得再传一遍 response/source,等于把
        # "唯一 record_llm_call 调用点"换成"两处口径判断",那正是要避免的复制
        reasoning_effort: str | None,
+        # —— 1.3.5: 行形态与逻辑调用快照 ——
+        operation: CallOperation,
+        event_kind: EventKind,
+        attempts: int | None,
+        total_latency_ms: int | None,
    ) -> None:
        try:
            # 成本换算(M2 §6): 成功行按单价换算;缓存命中 0.0(未产生新调用);
@@ -413,7 +602,7 @@ class TelemetryEmitter:
                # 用量不可得: 宁可算不出成本,也不算错成本(解耦设计 §3.1 不变式)。
                # 必须排在 cache_hit 之后——缓存命中未产生新调用,0.0 是事实而非未知
                cost = None
-            elif error is None and model and self._pricing is not None:
+            elif errors.error is None and model and self._pricing is not None:
                cost = self._pricing.cost(
                    model, prompt_tokens, completion_tokens, cached_prompt_tokens
                )
@@ -425,6 +614,7 @@ class TelemetryEmitter:
                _cap_messages(digest_messages(request.messages), self._text_cap),
                ensure_ascii=False,
            )
+            context = request.call_context
            await self._recorder.record_llm_call(
                call_id=call_id,
                parent_call_id=request.parent_call_id,
@@ -442,7 +632,7 @@ class TelemetryEmitter:
                ttft_ms=ttft_ms,
                max_inter_token_ms=max_inter_token_ms,
                cache_hit=cache_hit,
-                error=error,
+                error=errors.error,
                cost=cost,
                cached_prompt_tokens=cached_prompt_tokens,
                model_reported=model_reported,
@@ -457,6 +647,19 @@ class TelemetryEmitter:
                # Postgres 那一路悄悄少一列数据
                thinking_observation=_normalize_observation(thinking_observation),
                reasoning_effort=reasoning_effort,
+                # —— 1.3.5 十列 ——
+                scope=self._scope,
+                # 调用点给定的公开方法四值,**绝不读 `exc.operation`**(设计 §5 I1/I2)
+                operation=operation,
+                # 上下文缺席(库内现场构造的 ChatRequest)→ NULL,**不造 ID**(I5)
+                logical_call_id=None if context is None else context.logical_call_id,
+                event_kind=event_kind,
+                http_status_code=errors.http_status_code,
+                error_type=errors.error_type,
+                cause_type=errors.cause_type,
+                error_body=errors.error_body,
+                attempts=attempts,
+                total_latency_ms=total_latency_ms,
            )
        except asyncio.CancelledError:
            raise
@@ -464,8 +667,45 @@ class TelemetryEmitter:
            logger.warning("遥测记录失败(降级不冒泡): {}", exc)


+async def emit_terminal_once(
+    emitter: TelemetryEmitter | None,
+    *,
+    request: ChatRequest,
+    context: _CallContext,
+    error: PolyGatewayError | str,
+    operation: CallOperation,
+    class_prefixed_error: bool = False,
+) -> None:
+    """三个 client 共用的**终态唯一出口**: 去重 + 同步冻结快照 + best effort 写入。
+
+    去重由 `claim_terminal()` 承担(每逻辑调用至多一条终态行);`emitter is None`
+    或已写过 → 直接返回。写入侧异常按既有降级只落 warning(在 `_record` 内)。
+
+    **`CancelledError` 原样传播**(取消优先,不 shield、不开后台任务): 这一次
+    `await` 本身就是新的取消点,外部取消落在它上时调用方会看到 `CancelledError`
+    而非领域错误——与 TelemetryMW 的历史行为同款,已经人类批准(设计 §6/§10)。
+    快照冻结是**同步**动作,故终态行不含它自身的写入耗时。
+    """
+    if emitter is None or not context.claim_terminal():
+        return
+    stats = context.snapshot()
+    await emitter.emit_terminal_failure(
+        request=request,
+        call_id=str(uuid.uuid4()),
+        error=error,
+        operation=operation,
+        stats=stats,
+        class_prefixed_error=class_prefixed_error,
+    )
+
+
 class TelemetryMW:
-    """洋葱最外层: 观测尝试层看不见的路径,任何路径都留痕(遥测必录)。"""
+    """洋葱最外层: 只观测尝试层看不见的**缓存命中**。
+
+    1.3.5 起不再在此写终态失败行: 终态由 `GatewayClient.chat` 的公开边界经
+    `emit_terminal_once` 统一写出。两处同时写会让同一次失败出两条终态行,
+        而下游正是按 `event_kind = 'terminal_failure'` 计失败调用次数的。
+    """

    def __init__(
        self, emitter: TelemetryEmitter, now: Callable[[], float] = time.monotonic
@@ -474,26 +714,7 @@ class TelemetryMW:
        self._now = now

    async def __call__(self, request: ChatRequest, call_next: CallNext) -> LLMResponse:
-        started = self._now()
-        try:
-            response = await call_next(request)
-        except (GatewayUnavailableError, GovernanceBackendError, SourceNotConfiguredError) as exc:
-            await self._emitter.emit_terminal_failure(
-                request=request,
-                call_id=str(uuid.uuid4()),
-                latency_ms=int((self._now() - started) * 1000),
-                error=str(exc),
-            )
-            raise
-        except asyncio.CancelledError:
-            # 尽力而为: 取消也留痕(§5.1 约定④);随后立即重抛
-            await self._emitter.emit_terminal_failure(
-                request=request,
-                call_id=str(uuid.uuid4()),
-                latency_ms=int((self._now() - started) * 1000),
-                error="cancelled",
-            )
-            raise
+        response = await call_next(request)
        if response.cache_hit:
-            await self._emitter.emit_cache_hit(request=request, response=response)
+            await self._emitter.emit_cache_hit(request=request, response=response, operation="chat")
        return response