--- type: finding node_id: finding:2026-09-09-135-call-observability-validation title: "1.3.5 T2/T3/T4 验收证据:36 列遥测、失败终态、PG 存储兼容与变异矩阵" date: 2026-09-09 --- # 1.3.5 T2/T3 验收证据 > 范围:**仅 T2(遥测 10 列 / 诊断保真 / scope+operation / 装配闸)与 T3(终态行 / 取消 / 统一出口)**, > 外加计划 T4 中"签名与列数机械迁移"那一片(与 schema 同批完成,避免先提交 schema 却留写入缺键)。 > **不含** T4 的 PG 集成、变异矩阵与文档同步——另任务承接,缺口见 §5。 > 设计:`designs/2026-09-09-135-call-observability-design.md`;计划:`plans/2026-09-09-135-call-observability.md`。 > 基线 HEAD `87c261b`(T1 已提交,1419 unit 全绿)。全部命令在 `PolyGateway` conda 环境执行。 ## 1. 红绿证据链 TDD 纪律要求"先失败后通过",且红必须是**行为红**而非 import 红。下表每行都对应本会话的真实工具输出。 | # | 阶段 | 命令 | 结果 | | --- | --- | --- | --- | | 0 | 基线 | `pytest tests/unit -q` | **1419 passed**(对照底) | | 1 | 红(T2/T3 目标行为) | `pytest tests/unit/test_telemetry.py -k "RowLevelObservability or RecorderShapeGate"` | **26 failed**,证据 `tests/outputs/135/red-01-emitter-rows.txt` | | 2 | 实现后全量红面 | `pytest tests/unit -q` | **137 failed / 1308 passed**(机械迁移面暴露),`red-02-after-impl.txt` | | 3 | 迁移中 | 同上 | 60 → 25 → 8 → 4 failed(`red-03`/`red-04`/`red-05`) | | 4 | 绿 | `pytest tests/unit -q` | **1467 passed, 0 failed** | | 5 | 静态门 | `make check`(ruff lint+format + import-linter) | **Contracts: 1 kept, 0 broken** | 第 1 步的红是行为红而非 import 红:新用例调用的是**已存在**的 `TelemetryEmitter`, 失败形态是"缺 `scope=`/`operation=`/`stats=` 关键字"与"断言的列不存在",不是模块导不进来。 补测阶段另有两次真实红(均由 conda 实跑暴露、当场修正,非噪音): `test_client.py` 的 `NameError: ResultInvalidError / ChatRequest`(漏 import)、 `TestTerminalRowSqlSemantics` 的 `'coroutine' object has no attribute 'execute'`(async helper 漏 await)。 ## 2. 核心要求逐条对应 ### 2.1 36 列与 Emitter 完整一致(不留"schema 有列、写入缺键") 一次性同批改完五处列定义 + 端口签名 + Emitter 写入,故不存在中间态。 | 判据 | 证据 | | --- | --- | | `len(COLUMNS) == 36`、物理列 37 | `test_telemetry.py::TestSchemaModule::test_columns_and_ddl_are_frozen`;`TestSQLiteSchemaMode` 断言 23 → 37 | | 五处列序一致(DDL/BACKFILL×2/COLUMNS) | 新建库与 ALTER 追加列序同为 `_EXPECTED_COLUMNS` | | 端口实测 36 字段、10 新参 keyword-only 且无默认值 | `test_ports.py::TestTelemetryRecorderSignature`(`inspect.signature` 实测,不凭记忆) | | **Emitter 实参键集合 == `schema.COLUMNS`** | `TestEmitterRecorderContract` 三入口逐个断言 `set(rows[0]) == set(COLUMNS)` | | 1.2.1 冻结 INSERT 未被改写 | 按 `_PRE_135_COLUMNS`(26 列)重现原文;全量 36 列另按占位符个数断言 | 装配闸(C3):`_assert_recorder_shape` 在 `TelemetryEmitter.__init__` 做一次 `signature.bind`, 参数名**从协议签名派生**而非手抄第四份清单——`test_gate_derives_parameter_names_from_the_protocol` 用 monkeypatch 换掉协议后闸自动跟随,证明没有硬编码。旧签名 recorder / 无该方法 / 不可 inspect 一律装配期 `ValueError`(不是 warning:降级铁律管的是运行期写失败,不是配置错误)。 ### 2.2 三个 client 的**真实链路**失败终态 不是只测 Emitter,而是驱动真实 client + MockTransport 到落库。 | 链路 | 用例 | 断言 | | --- | --- | --- | | chat 重试耗尽 | `TestChatTerminalFailureRows::test_retry_exhaustion_writes_exactly_one_terminal_row` | 3 条 attempt + **恰 1 条**终态;终态 `attempts == 3` | | chat 结构化耗尽 | `test_structured_exhaustion_writes_the_only_failure_row` | attempt 行**全是成功行**,终态是唯一失败记录;error 含有界 `validation=`/`repair=` 且 < 1200 字符、不含 raw_text | | chat 400 直拒 | `test_request_rejected_now_has_both_an_attempt_and_a_terminal_row` | 尝试行 + 终态行**各 1**(已批准的行数翻倍);两行共享同一 `logical_call_id` | | embedding | `test_embedding.py::TestReasonlessTelemetryContract::test_failed_attempts_still_have_null_effort` | attempt 数 == 脚本长度,终态恰 1 | | OCR 两方法 | `test_ocr_client.py` 同名用例(参数化 `recognize_text`/`parse_layout`) | 终态恰 1,且 `operation` 为**公开方法名** | 去重:`test_terminal_row_is_written_once_per_logical_call` 连调出口 3 次,SQL 可见仍 1 条(`claim_terminal`)。 非领域异常:`test_non_domain_exception_writes_no_terminal_row` —— `KeyError` 原样传播、**0 条**终态、分类不被改写。 **双写已消除**:`TelemetryMW` 的两个终态分支删除,改由三个 client 的公开边界经 `emit_terminal_once` 统一写出;`TestTelemetryMW::test_scope_level_failure_is_not_written_here_anymore` 与 `test_cancellation_is_not_written_here_anymore` 锁死"本层不再写终态",防回归双计。 ### 2.3 取消口径 - chat 取消:`test_cancellation_writes_at_most_one_terminal_row` —— 恰 1 条,`error == "cancelled"`, 且 `error_type` 为 NULL(**字符串不解析猜诊断**)。 - 三链路同策略"尽力写一条、允许 0";`emit_terminal_once` **不 shield、不开后台任务**, 快照冻结是同步动作;写入 await 上再被取消则 `CancelledError` 原样传播(与 TelemetryMW 历史行为同款)。 ### 2.4 SQL 不双计(按真实 SQLite 落库断言) `TestTerminalRowSqlSemantics` 用真实 `SQLiteRecorder` 驱动一次失败 chat 后直接查表: | 迁移影响 | 断言 | | --- | --- | | 失败计数判据 | `error IS NOT NULL` 得 **3**(2 尝试 + 1 终态),`event_kind='terminal_failure'` 得 **1** | | 费用不双计 | 终态行 `cost IS NOT NULL` 计数为 **0**;且 `usage_source='unavailable'`、token 全 0 | | 时延分组 | 终态 `latency_ms` ≥ 任何单次尝试(含退避),故看板必须按 `event_kind` 分组 | | 双时钟微差 | 终态 `latency_ms == total_latency_ms`(同一份冻结快照) | | 逻辑两列归属 | 尝试行 `attempts`/`total_latency_ms` 恒 NULL | | §5 归因查询 | 同一 `logical_call_id` 同时给出整池 reason 文案与逐源 503 现场;终态 `http_status_code` 为 NULL(C1 不冒充) | ### 2.5 诊断保真与 operation 修正 - 中转把 529 改写成 503 → **记 503 不猜回 529**;直接 529 记 529。 - 空 `str()` 的 Connect/Read/Write/PoolTimeout → `cause_type` 落对应 httpx 类名,`error` 退回类名。 - 成功行五列全 NULL(**不统一填 200**)。 - `_status_to_error` 增 keyword `operation`:`embed()` 非 200 改传 `"embedding"`(修正历史误标), 流式与非流式 chat 两处仍 `"chat"`(按实施计划 §2 归属表,未按设计行号误标)。 - 新列 `operation` 恒为公开方法四值,**绝不读 `exc.operation`**: `test_operation_is_given_by_the_call_site_not_the_exception` 用 `exc.operation="download_result"` 反证。 - OCR `"类名: msg"` 前缀由出口的显式策略参数 `class_prefixed_error` 承载,不再三处各拼一遍。 ## 3. 有界 validation 说明的单一所有者 `structured.py` 的 `_MAX_FEEDBACK_ERRORS`/`_MAX_ERROR_CHARS`/`_format_errors` 改名为 公开的 `MAX_FEEDBACK_ERRORS`/`MAX_ERROR_CHARS`/`format_bounded_errors`, 由"重问反馈"与"终态结构化说明"两个消费者共同引用,**数值只有一份**。 行为逐字不变(`test_structured.py` 22 项全绿,含反馈文案用例)。 ## 4. 未改动确认(防越界) `errors.py`、`admission.py`、`ratelimit.py`、`breaker.py`、`sources.py`、`thinking.py`、 `providers.py`、`telemetry/sqlite.py`、`telemetry/postgres.py`、`transports/monkey_ocr.py` 一字未动——两个 recorder 靠 `**fields` + `schema.COLUMNS` 自动吃到新列。 缓存 key 公式、重试预算与退避、429 免预算、stall 算法、取消结算、推理能力表均未触碰。 唯一顺带修正:`RetryMW.__init__` 的 `emitter` 注解由 `object | None` 收紧为 `TelemetryEmitter | None`(TYPE_CHECKING 导入,同层不破分层契约),因本轮改了它的 `_emit`。 ## 5. T4 验收(PG 存储兼容、变异矩阵、文档同步) 基线 HEAD `393f2bf`(1467 unit 全绿),全部命令在 `PolyGateway` conda 环境执行。 ### 5.1 PG 存储兼容(真实实验室 Postgres,复用 `pg_sandbox`) 机械迁移:`_EXPECTED_COLUMNS` 27 → 37 列、`_record_minimal` 字段字典补 10 键(与单测同款)、 `_PRE_TENANT_COLUMNS` 的缺列集由4 列扩到 14 列。新十列一律由 `_CALL_OBSERVABILITY_COLUMNS` 派生, 两处 manual 档告警的逐字断言改成按 `COLUMNS` 序派生的 `_PRE_TENANT_MISSING_NOTICE`—— 另抄一份列名必然漂移,而漂移的表现是“manual 档没补列”这条断言假绿。 | 阶段 | 命令 | 结果 | | --- | --- | --- | | 机械迁移前(已知必红) | `pytest tests/integration/test_postgres_telemetry.py -q -x` | **1 failed / 18 passed**:manual 档列序断言 `Right contains 10 more items, first extra item: 'scope'` | | 机械迁移后 | 同上(无 `-x`) | **27 passed**,EXIT=0,`tests/outputs/135/pg-telemetry-after-mechanical.log` | | 新增四项验收后 | 同上 | **30 passed**,EXIT=0,`tests/outputs/135/pg-telemetry-new-cases.log` | 新增 `TestCallObservabilityColumnsAcceptance`(对应计划 T4 的 PG 四项),共用一张 27 列的 1.3.4 形态旧表(`pre_135_schema`): | 验收项 | 用例与关键断言 | | --- | --- | | auto 追加 10 列 + 旧行 NULL | `test_pre_135_table_gains_the_ten_columns_and_old_rows_stay_null`:物理列 27 → 37 且列序 == `_EXPECTED_COLUMNS`;attempt 行与 terminal 行十列取值**整体比对**(不是逐条 in);历史行 `dict.fromkeys(...)` 十列全 NULL | | manual 缺列裁剪 | `test_manual_trims_the_insert_on_a_pre_135_table`:表结构逐字不动(== `_PRE_135_COLUMNS`);裁剪后 26 列逐列等于提交值(防整体错位);恰 1 条告警且含可直接粘贴的首/末列 ALTER;无“写入失败”/“补列失败”,`degraded is False` | | 新旧进程混写 | `test_old_and_new_writers_share_one_table`:新版建表写 36 列 → 旧版进程用 `insert_sql("postgres", 26 列集)` 写入 → 新版再写;三行共存、表结构不变、旧行新列全 NULL、无写入失败 warning | | 下游口径验收 | 同上用例尾部:`WHERE event_kind = 'terminal_failure'` 计得 1;`event_kind IS NULL` 计得 1(混写期旧行既不误计成失败也不误计成成功) | 纪律:未引用 `assert_no_leftovers`(它是 `test_pg_sandbox.py` 的模块级 fixture,对本文件不可见,上提它要改 `conftest.py`); 未新建沙箱设施、未碰共享表 `llm_calls`、未读或打印 DSN。新增的只有一个 `_execute_args`(带参数单语句)与 `_minimal_fields`(从 `_record_minimal` 拆出的字段字典,供“旧进程”复用同一份取值)。 ### 5.2 变异矩阵(仓库外副本,主工作区生产代码零改动) 驱动脚本 `/tmp/pgw-135-mut/run_mutations.py`;每项“还原副本 → 施加单点变异(断言替换命中)→ 跑指定节点 → 还原”。 完整日志 `tests/outputs/135/mutations.log`,脚本总退出码 **EXIT=0**。 | # | 变异 | exit | 被杀断言(节选) | | --- | --- | --- | --- | | M1 | `register_attempt()` 挪到 transport 成功之后 | 1 | `test_failed_retries_are_counted`、`test_budget_free_429_still_counts_as_an_attempt`、`test_retry_exhausted_counts_every_attempt` | | M2 | `ChatRequest` 每次 `replace` 复制出新上下文 | 1 | `TestLogicalCallStats` 4 项 + `test_retry_exhaustion_writes_exactly_one_terminal_row` | | M3 | `_rehydrate` 去掉 `call_stats=None` 覆盖 | 1 | `test_historic_dict_never_impersonates_call_stats` | | M4 | Emitter 入口提前 `str(exc)` 压平 | 1 | 529/503 保真、4 个空超时文案 `cause_type`、类名前缀策略、结构化有界说明等 9 项 | | M5 | 终态行复制最后一次 attempt 的 token/cost | 1 | `test_terminal_rows_never_contribute_to_cost`、`test_terminal_row_costs_nothing` | | M6 | 去掉 `claim_terminal` 去重 | 1 | `test_terminal_row_is_written_once_per_logical_call`、`test_claim_terminal_is_true_once` | | M7 | 装配闸改为捕获 `TypeError` 后 warning | 1 | `test_old_signature_recorder_is_refused_at_assembly`、`test_uninspectable_recorder_is_a_configuration_error` | 还原校验:副本 `.py` 文件集合散列与纯净态**逐字一致**(`66b58b9a…`),还原后同一批节点 **172 passed**。 > **方法论陷阱(影响本仓所有变异证据的有效性)**:只设 `PYTHONPATH=<副本>/src` 是**无效的**—— > `pyproject.toml` 的 `[tool.pytest.ini_options] pythonpath = ["src"]` 会把**仓库内**的 `src` 抢先塞进 `sys.path[0]`, > 于是测的仍是原代码。首轮实跑七项变异**全部“存活”(exit=0)**就是这个坑; > 改用 `-o pythonpath=<副本>` 覆盖后七项全部被杀。今后做变异必须先证“副本真的被导入”, > 否则“变异存活”会被误读成“测试不够强”,而真相是变异根本没生效。 ### 5.3 文档同步(字段数一律 `inspect` 实测,不凭记忆) 实测值:`len(inspect.signature(TelemetryRecorder.record_llm_call).parameters) - 1 == 36`,`len(COLUMNS) == 36`,物理列 37。 | 位置 | 改了什么 | | --- | --- | | `README.md` 能力表 | “必录 26 字段” → 36 字段 + 三类行与诊断列;新增“逻辑调用统计”一行 | | `README.md` 新小节 | 《1.3.5 逻辑调用统计与失败诊断》:`call_stats` 读法、**SQL 迁移五项**、归因查询、存储侧升级 | | `README.md` cap 覆盖面 | 补“`error_body` 沿用 `summarize_body` 上限、结构化说明自带限长,**两者都不在 cap 覆盖内**” | | `ARCHITECTURE.md` §7.8 | 必录字段 26 → 36(十列逐个列出);新增“逻辑调用十列”段(列语义表 + 不变量 I3/I4 + `operation` vs `exc.operation` 两个语义 + 装配闸);cap 段补两处诊断文本不在覆盖面 | | `CHANGELOG.md` | 新建《未发布》:公共面四项变更表 + 下游必须做的事(点名 `WHERE event_kind` 与装配期报错) | | `.env.example` | `PGW_TELEMETRY_TEXT_CAP` 块补 1.3.5 覆盖面例外 | | `schemas/llm-calls.md` | 标题 26 → 36 字段;十列逐行登记;新增《三类行与失败归因口径》(含归因 SQL 与迁移四条) | | `metrics/call-telemetry-coverage.md` | 新增《1.3.5 三类行与逻辑调用覆盖》;live 基线列**不写伪百分比** | 版本号与发布步骤**未动**(任务边界);`pyproject.toml` / `__init__.py` 仍为 1.3.4。 ### 5.4 本轮收口验证 | 检查 | 命令 | 结果 | | --- | --- | --- | | 静态 | `make check`(ruff format+lint + import-linter) | 见 §7 实跑记录 | | 全量单测 | `pytest tests/unit -q` | 见 §7 | | 目标集成 | `pytest tests/integration/test_postgres_telemetry.py -q` | **30 passed** | ## 6. 剩余缺口(不归本任务,不自称已关) | 缺口 | 说明 | | --- | --- | | 独立验证 | 未派全新上下文 verifier(合并前硬门,由父会话前台派) | | slow / e2e | 未跑,属发布清单第 4 步(CLAUDE §4.4.1) | | live 覆盖基线 | `metrics/call-telemetry-coverage.md` 的实际基线列仍待首次生产运行填入 | | 下游自建 recorder | 装配闸只能证明形状可被接受,证不了函数体真的落这些列(已写进 README/CHANGELOG) | ## 7. 环境噪音记录(不是缺陷) 自动检查器用**系统解释器 Python 3.13.9**(无 `redis`/`pydantic`/`httpx`/`loguru`/`asyncpg` 等依赖), 持续报 `test_client.py` 2 项失败与大量 "Import could not be resolved"、`StrEnum is unknown import symbol`。 已核实为环境问题、非本轮引入: - 失败根因是 `ModuleNotFoundError: No module named 'redis'`(optional extra),本轮 diff 对 redis 零改动; - 在**未改动的 HEAD** 上用同一系统解释器复跑,同样 2 failed / 90 passed; - 项目强制环境 `conda run -n PolyGateway`(Python 3.12.13)下:`test_client.py` 98 passed、全量 1467 passed。 判据以 CLAUDE.md §2 规定的 conda 环境与 `make check` 为准。 **T4 轮次同样现象(已逐项复现并关闭)**:检查器报 `tests/integration/test_postgres_telemetry.py` “2/3 failed” 与 6 处 `Import "asyncpg" could not be resolved`。根因与上同:`asyncpg>=0.29` 是 optional extra (`pyproject.toml:25` 的 `postgres`),检查器解释器里没装。已做确定性复现: - 那 3 条恰是本文件**仅有的不依赖真实 PG 的用例**,其中 2 条要造 `PostgresRecorder`; - 用 `/home/iomgaa/miniconda3/bin/python`(无 asyncpg)跑这 3 条:**2 failed / 1 passed / 0.09s**,与检查器报告逐字吹合; - 同 3 条在 `conda run -n PolyGateway` 下:**3 passed**;整文件 **30 passed**(真实 PG); - 被标记的 6 行均为**本轮未触及的旧行**,本轮只新增 1 处同款函数内 `import asyncpg`。 未为此修改代码:给旧行加 type-ignore 属任务外改动(反 gold-plating),且并非真修复。