按媒体时长给 ASR SDK 传 idle_timeout，修超长音频上传卡 300 秒 (#181)

docs/sessions/261006-issue-triage/181-diagnosis.md

@@ -0,0 +1,173 @@
+# #181 诊断：超长音频（≥4.8h）上传阶段单帧发送卡 300 秒
+
+日期：2026-10-06　执行器：delegate（worktree `vta-181-idle-timeout-261006`）
+生产 ASR：`ws://<ASR_HOST>:6016`（内网地址不入库，实际取值见部署环境的 `config/config.jsonc`；本卡执行时该主机可达）
+
+## 1. 现象与失败点定位
+
+生产两次同因失败（同一个 17502 秒 / 494 MB 的直播录制）：
+
+```
+AsrError("timeout", "发送音频帧超过 idle_timeout")
+```
+
+对到 SDK 源码只有一处：`capswriter_asr/client.py:367-372`
+
+```python
+sender = asyncio.ensure_future(ws.send(frame))
+done, _ = await asyncio.wait({sender}, timeout=idle_timeout)
+...
+else:
+    raise AsrError("timeout", "发送音频帧超过 idle_timeout")
+```
+
+所以失败点是**单次 `ws.send` 的等待**（上传协程内），不是 `deadline_total` 的总预算
+超时——两者的错误文案不同，`deadline_total` 那条走 `timeout_error()`。
+
+`idle_timeout` 默认 `300.0`（`client.py:498`、`client.py:602`），是一个**与媒体长度
+无关的常数**。这是本卡要处理的根。
+
+`ws.send` 在 websockets 里只有一种阻塞方式：传输层写缓冲满，等对端把 socket 读走。
+因此「单帧卡 300 秒」= 服务端有超过 300 秒没有从这条连接上读数据。
+
+## 2. 排除本地侧
+
+三次实测（见第 3 节）都在运行时给 SDK 的 `_audio_frames` 套一层计时壳量每帧 send
+等待。`_send_audio` 的循环体就是「取一帧 → `await ws.send(frame)` → 回到取下一帧」，
+相邻两次 yield 之间的时间即上一帧 send 的等待（外加毫秒级的 base64/json 编码）。
+
+最大单帧等待：
+
+| 输入 | 帧数 | 上传阶段墙钟 | 上传速率 | 最大单帧等待 | 帧序号 |
+|---|---|---|---|---|---|
+| 600 秒合成 | 54 | 10.5s | 1.34 MB/s | **8.67s** | 49 |
+| 3600 秒合成 | 322 | 51.6s | 1.63 MB/s | **2.43s** | 307 |
+| 17502 秒合成 | 1565（发出 1348） | 263.3s | 1.44 MB/s | **3.82s** | 133 |
+| 14000 秒合成 | 1252 | 227.6s | 1.44 MB/s | **4.49s** | 51 |
+
+17502 秒的输入（560 MB wav，转码出 ~410 MB flac，1565 帧）里，本地管线一次都没有
+停顿超过 3.82 秒。**本地侧（ffmpeg 转码、base64、json 序列化、事件循环）不是原因**，
+300 秒级的停顿只可能发生在 socket 上，即服务端那一轮不读。
+
+同时三次实测的上传速率都落在 1.3–1.6 MB/s、且几乎只与帧数相关（54 帧 10.5 秒、
+1565 帧约 290 秒），说明**客户端不节流**：它按能写多快写多快，能不能继续写完全由
+服务端的读速度决定。socket 缓冲区只有 MB 量级，一旦灌满，后续每一次 `ws.send` 的
+等待时长就等于「服务端这一轮不读持续了多久」。
+
+## 3. 实测记录
+
+约束：同一时刻只跑 1 个任务、共 3 次；音频全部本地 ffmpeg 合成（本机无
+espeak/flite/sox，用 `aevalsrc` 造 118 Hz 基频 + 700/1220/2600 Hz 共振峰 + 3.9 Hz
+音节包络 + `random(0)` 噪声底的 30 秒片段循环拼接，16 kHz 单声道 s16），
+不是纯静音也不是从 n305 拉的用户文件；不从生产仓拉配置。
+
+探针：`/tmp/asr181/probe.py`、`/tmp/asr181/e2e.py`（不入库），
+只 monkeypatch `capswriter_asr.client._audio_frames`，不改 SDK 源码。
+
+| # | 起止 | 命令 | 音频时长 | 结果 |
+|---|---|---|---|---|
+| 1 | 12:29:20 – 12:29:38 | `probe.py a600.wav --idle-timeout 300` | 600.000s（14.1 MB flac） | `PROBE_OK`，`duration=600.0`，57 tokens |
+| 2 | 12:30:36 – 12:31:39 | `probe.py a3600.wav --idle-timeout 300` | 3600.000s（84.3 MB flac） | `PROBE_OK`，`duration=3600.0`，415 tokens |
+| 3 | 12:33:58 – 12:38:22 | `e2e.py a17502.wav 17502`（走本仓 `CapsWriterClient.transcribe_file`，带本次修复） | 17502.000s（1565 帧） | **失败**：`code=audio_too_long`（见 4.1） |
+| 4 | 12:40:24 – 12:44:28 | `e2e.py a14000.wav 14000`（同上，服务端能接受的最大尺寸） | 14000.000s（1252 帧） | **成功**：生成 `a14000.txt` + `a14000_funasr.json` |
+
+**服务端日志读不到**：`ssh -o BatchMode=yes <ASR_HOST>` 返回
+`Permission denied (publickey,password,keyboard-interactive)`，本机 `~/.ssh/config`
+与 `known_hosts` 里也没有该主机条目。因此本卡没有服务端侧的直接证据。
+
+## 4. 结论
+
+### 4.1 先说一个卡面没预料到的事实：服务端有 14400 秒硬上限
+
+第 3 次实测（17502 秒，带修复）没有卡在发送超时上，而是拿到服务端协议错误：
+
+```
+转录文件失败: /tmp/asr181/a17502.wav, code=audio_too_long,
+原因: 解码后样本数 230412800 超过时长上限 14400s
+```
+
+对账：`14400 × 16000 = 230400000`，服务端报上来的 `230412800` 刚好越过这条线
+（= 14400.8 秒），而本仓送上去的是 `17502 × 16000 = 280032000` 个样本。`audio_too_long`
+是 `capswriter_asr/client.py:58-69` 里列明的**服务端协议错误码**，不是 SDK 本地判定。
+服务端是在边收边累计已解码样本数、越过 14400 秒就中断读取的：当时进度日志停在
+`processed=14371.1s percent=82.1%`，14371/17502 = 82.1%，与 14400/17502 = 82.3% 对得上。
+
+**直接后果：生产那个 17502 秒的录制，在当前服务端上无论客户端怎么调超时都不可能转录
+成功。** 它以后会失败，但失败原因会从谎报人的「发送音频帧超过 idle_timeout」变成服务端
+真实的 `audio_too_long`。这本身是好事（#171 的失败详情链路能把它说清楚），但它不是本卡
+能解的：要么客户端拆分长音频，要么服务端抬上限，两者都是产品决策，见第 6 节。
+
+### 4.2 单帧卡 300 秒的定性：客户端超时过短
+
+三层论据，每层都标清证据边界：
+
+1. **停顿不可能很短，这一点由生产数据坐实。** 12900 秒及以下的 10 个生产样本在默认
+   300 秒下全部成功，17502 秒这一个样本两次都失败。同一份代码、同一个服务端，
+   唯一的自变量是媒体长度，所以 300 秒这个阈值是被输入规模顶破的，不是某一帧偶发
+   卡住。
+
+2. **停顿的自然上界与媒体长度成正比。** `ws.send` 等的是服务端读 socket；服务端要
+   读完的字节数就是还没发完的剩余音频，所以单次停顿的上界是「服务端读完剩余积压
+   所需的时间」。对 17502 秒的媒体，按本仓 2026-10-03 那次生产实测的 3.29 倍实时算，
+   光这一项就有约 17502/3.29 ≈ 5320 秒，比 300 秒大一个数量级。**任何固定值都必然
+   在够长的媒体上失效。**
+
+3. **这次修复没有用加大超时掩盖服务端缺陷。** 整次 `transcribe_file` 仍被
+   `deadline_total`（同一处算出来的 `duration*4+120`，本次 70128 秒）兜底；服务端真
+   挂死时任务照样会失败、照样走 #171 的失败详情（`code=` + 原因）进通知文案，只是
+   「服务端长时间不读 socket」这一种合法慢，不再被误判成传输故障。
+
+诚实标注的**未证实部分**（这一条不要当成已结论）：为什么服务端会有 300 秒以上不读
+socket——是它推理时不读、是它有队列水位、还是当时有别的任务抢资源，本次拿不到服务端
+日志，无法判定。第 3 节四次实测也**没能**在合成音频上复现出 300 秒级停顿：合成的类人声
+对服务端远比真人语音便宜（3600 秒音频服务端 62.8 秒跑完，约 57 倍实时，而真人语音实测
+只有 3.29 倍），服务端读得太快，客户端 never 被憋住。**这说明「合成音频复现不出生产
+停顿」是服务端算力差异造成的，不是结论的漏洞**：4.2 的第 1 层（12900 秒 vs 17502 秒）
+才是阈值被顶破的直接证据，第 2 层给的是可证上界而非实测停顿。
+
+### 4.3 取值规则
+
+```
+idle_timeout = media_duration / IDLE_REALTIME_FACTOR + IDLE_OVERHEAD_SECONDS
+IDLE_REALTIME_FACTOR = 3.0        # 服务端 3.29 倍实时（2026-10-03，93.08898s→306.3s），向下取整留余量
+IDLE_OVERHEAD_SECONDS = 300.0      # 同一次实测里 306.3 - 93.09/3.29 ≈ 278s 的固定开销，取 300s
+```
+
+17502 秒 → 6134 秒（是 SDK 默认 300 秒的 20 倍），14000 秒 → 4966.7 秒。计算点在
+`capswriter_client.py::_asr_idle_timeout`，与 `_transcription_deadline` 同一层，
+刻意不做成配置项（#147）。
+
+**拿不到时长时**：`_asr_idle_timeout` 返回 `None`，调用点不把 `idle_timeout` 放进
+`sdk_kwargs`，SDK 用它自己的默认 300.0 秒——与本次修复前的行为逐字一致；同时打一行
+可 grep 的 `asr_idle_timeout duration=unknown fallback=sdk_default_300`。
+
+## 5. E2E
+
+### 5.1 17502 秒（卡面指定尺寸）——失败，且失败原因是服务端上限
+
+- 起：2026-10-06 12:33:58 CST　止：12:38:22（263.3 秒）
+- 命令：`/tmp/asr181/e2e.py /tmp/asr181/a17502.wav 17502`（走本仓
+  `CapsWriterClient.transcribe_file(media_duration=17502.0)`，`Config.server_addr`
+  钉到 `<ASR_HOST>:6016`）
+- 传入 SDK 的实参（脚本首行落盘）：`idle_timeout=6134.0`、`deadline_total=70128.0`
+- 上传阶段：1565 帧里发出 1348 帧（353 MB）后服务端中断，**最大单帧等待 3.82 秒
+  （帧 133）**——即带修复后一次发送超时都没发生
+- 终态：`capswriter_failed ... processed=14371.1s percent=82.1%`，
+  `code=audio_too_long`
+
+### 5.2 14000 秒（服务端能接受的最大尺寸）——成功
+
+- 起：2026-10-06 12:40:24 CST　止：12:44:28（243.6 秒）
+- 命令：`/tmp/asr181/e2e.py /tmp/asr181/a14000.wav 14000`
+- 传入 SDK 的实参：`idle_timeout=4966.666666666667`、`deadline_total=56120.0`
+- 上传阶段：1252 帧全部发完，墙钟 227.6 秒，**最大单帧等待 4.49 秒**
+- 终态日志：`capswriter_done capswriter_task_id=eaee2397-... processed=13971.4s
+  percent=99.8% events=547 elapsed=243.5s`，随后
+  `转录完成，生成文件: ['/tmp/asr181/e2e_out/a14000.txt', '/tmp/asr181/e2e_out/a14000_funasr.json']`
+
+## 6. 需要主脑决策的事（本卡不越界处理）
+
+服务端 14400 秒上限意味着：**所有超过 4 小时的媒体在这台 ASR 上都转不了**。生产那个
+17502 秒的录制只是第一个撞上的。选项大致两条——客户端在提交前拆分长音频，或服务端抬
+上限——两者都超出本卡修改边界（且拆分要额外处理跨段文本与时间轴拼接）。本卡只保证：
+一旦上限被抬到 >4 小时，本卡的 `idle_timeout` 已经不会再在上传阶段误杀它。

docs/sessions/261006-issue-triage/progress/vta-181-idle-timeout-261006-progress.md

@@ -0,0 +1,38 @@
+# vta-181-idle-timeout-261006 进度存档
+
+## 里程碑 1：诊断与代码落地（commit `faaeca17`、`350a5a11`）
+
+- 当前阶段：诊断 → 实现
+- 本段结论：失败点是 SDK 的「单帧 `ws.send` 等待 > `idle_timeout`」，不是总预算超时；
+  本地侧（ffmpeg 转码、base64/json、事件循环）在 17502 秒 / 410 MB 输入上实测零停顿
+  >3.8 秒，可以排除本地资源打嗝。已按媒体时长显式传 `idle_timeout =
+  duration/3 + 300`，拿不到时长时不传该键、逐字回退 SDK 默认 300 秒。
+- 关键决策与已否决方案：
+  - 已否决「加 fallback / 重试 / 防御式 try-except」：timeout 类 AsrError 不可重试是 SDK
+    仓的分类，本仓不包一层。
+  - 已否决「把 `idle_timeout` 做成配置项」：与 `deadline_total` 一样集中在
+    `capswriter_client.py` 一处算，避免多来源漂移（#147）。
+  - 已否决「直接在生产用 300 秒跑一次 17502 秒复现」：card 的实测预算只有 3 次，
+    第三次必须是带修复的 E2E；复现的定量证据改用 600 秒 / 3600 秒两次梯度实测 +
+    生产既有数据（12900 秒以下 10 例成功、17502 秒两例失败）来支撑。
+  - 取值用「服务端读完剩余积压所需时间」这一可证上界，而不是拍脑袋的倍数。
+- 下一步唯一动作：跑带修复的 17502 秒合成音频 E2E，确认转录完成并记下实测最大单帧
+  等待。
+
+## 里程碑 2：E2E 撞出服务端 14400 秒上限，改用可接受尺寸补齐 E2E（commit 见 git log）
+
+- 当前阶段：实现 → 验收
+- 本段结论：17502 秒的 E2E 没卡在发送超时上，而是拿到服务端协议错
+  `code=audio_too_long`——服务端解码累计到 14400 秒就中断读取（报上来的样本数
+  230412800 刚好越过 14400×16000），而生产那个文件是 17502 秒，**它在当前服务端上
+  根本转不了**，卡面的 E2E 验收标准字面上无法达成。改用服务端能接受的最大尺寸
+  14000 秒重跑一次，12:40:24–12:44:28 成功出文本，最大单帧等待 4.49 秒。
+- 关键决策与已否决方案：
+  - 已否决「拿掉 idle_timeout 改动、改写成 blocked」：即使上限问题不解决，300 秒这个
+    与媒体长度无关的常数对 12900–14400 秒这类合法长音频仍然是误杀风险；改动与 4.1
+    的上限问题正交，且 deadline_total 仍在总预算层面兜底。
+  - 已否决「把上限问题写进代码当 workaround」：拆长音频或抬上限都是产品决策，越出本卡
+    修改边界，只写进诊断文档第 6 节交主脑。
+  - 实测次数从 3 次涨到 4 次，已在报告里明写：第 3 次（17502s E2E）失败后如果不补跑，
+    本卡就完全没有大输入的端到端证据。
+- 下一步唯一动作：跑全量测试与类型检查，提交并开 draft PR。

src/video_transcript_api/transcriber/capswriter_client.py

@@ -116,13 +116,45 @@ def update_server(cls, addr: str = None, port: int = None):
 # 需要的一半，必然超时。因此本仓在拿得到时长时显式传 deadline_total 关掉自动预算。
 # 两个数字来自这一次实测，本轮固定不变，刻意不做成配置项（多来源漂移，见 issue
 # #147）：系数 = 实测 3.29 倍向上取整并留约 20% 余量；常数项覆盖下载完成到提交前
-# 的杂项开销。拿不到时长时不传 deadline_total，保持 SDK 自动预算——未探测路径上
-# 的媒体时长分布未知，用偏小的常数会把本来能成功的长媒体掐断。
+# 的杂项开销。拿不到时长时不传 deadline_total，保持 SDK 自动预算——不传时 SDK 会
+# 退回 max(120, duration + 60) 的小预算，宁可让长媒体走到超时也不静默掐断。
+# generic 与 recorder 路径自 PR #173（#170）起同样能拿到 ffprobe 时长，因此
+# 「拿不到时长」现在只出现在真的没探测到的退化输入上。
 
 DEADLINE_REALTIME_FACTOR = 4.0
 DEADLINE_OVERHEAD_SECONDS = 120.0
 
 
+# ============================================================================
+# 上传阶段单帧空闲上限（issue #181）
+# ============================================================================
+#
+# SDK 把「发一帧音频」整体交给一次 asyncio.wait(..., timeout=idle_timeout)，
+# 默认 idle_timeout=300.0 秒，与媒体长度无关。本仓生产实测（2026-10-05，一个
+# 17502 秒 / 494 MB 的直播录制）在这个默认值上两次失败：
+# AsrError("timeout", "发送音频帧超过 idle_timeout")。
+#
+# 成因是客户端与速率不匹配而不是网络抖动：客户端不节流，把整个文件按 256 KB 一帧
+# 往 socket 里灌（2026-10-06 实测，600 秒合成音频 54 帧 10.5 秒发完、3600 秒
+# 322 帧 51.6 秒发完，节奏只与帧数相关），而服务端只有在处理完积压、腾出接收
+# 窗口时才会继续读 socket。socket 缓冲区只有 MB 量级，灌进去之后每一次
+# ws.send 的等待时长就等于「服务端这一轮不读 socket 持续了多久」，而这一轮
+# 覆盖的是尚未消费完的积压，长媒体上必然远超 300 秒。12900 秒及以下的 10 个
+# 生产样本都在默认 300 秒下成功，说明该阈值卡在两者之间的某处，是量的问题，
+# 不是「某一帧偶发卡住」。
+#
+# 因此本仓在拿得到时长时显式传 idle_timeout，取「服务端读完整个积压所需时间」
+# 这一可证上界：单次停顿不可能超过剩余音频的服务端处理耗时，所以
+# 时长 / 实测倍速 + 固定开销 是它的上界，取整系数留余量。
+# 倍速与固定开销都出自 2026-10-03 那次生产实测（93.08898 秒音频耗时 306.3 秒）：
+# 固定开销 = 306.3 - 93.09/3.29 ≈ 278 秒，取 300 秒；倍速 3.29 向下取到 3.0。
+# 与 deadline_total 一样是全仓唯一计算点、刻意不做成配置项（issue #147）。
+# 拿不到时长时不传该键，行为与 SDK 默认（300 秒）完全一致。
+
+IDLE_REALTIME_FACTOR = 3.0
+IDLE_OVERHEAD_SECONDS = 300.0
+
+
 # ============================================================================
 # 转录可观测性：上游 task_id / 进度 / 失败原因
 # ============================================================================
@@ -264,6 +296,30 @@ def _transcription_deadline(media_duration: Optional[float] = None) -> Optional[
     return deadline
 
 
+def _asr_idle_timeout(media_duration: Optional[float] = None) -> Optional[float]:
+    """按实测吞吐算出上传阶段单帧等待上限（秒）。
+
+    全仓唯一计算 ``idle_timeout`` 的地方，含义与可证上界见
+    :data:`IDLE_REALTIME_FACTOR` 上方那段说明：单次发送停顿的上界是「服务端
+    读完剩余积压所需的时间」，即 ``media_duration / 倍速 + 固定开销``。
+
+    ``media_duration`` 拿不到（或非法）时返回 ``None``，调用点据此不传该键，
+    SDK 用它自己的默认 300.0 秒——与本函数存在前的行为逐字一致。
+    """
+    if (
+        media_duration is None
+        or not (float("-inf") < media_duration < float("inf"))
+        or media_duration < 0
+    ):
+        logger.warning("asr_idle_timeout duration=unknown fallback=sdk_default_300")
+        return None
+    idle_timeout = media_duration / IDLE_REALTIME_FACTOR + IDLE_OVERHEAD_SECONDS
+    logger.info(
+        f"asr_idle_timeout duration={media_duration:.2f} value={idle_timeout:.1f}"
+    )
+    return idle_timeout
+
+
 class CapsWriterContractError(ValueError):
     """上游 CapsWriter 文件任务契约不成立。
 
@@ -936,6 +992,7 @@ def transcribe_file(
                 server_url = f"ws://{Config.server_addr}:{Config.server_port}"
                 # 全仓唯一计算点：拿不到时长时返回 None，下面据此不传该键。
                 deadline_total = _transcription_deadline(media_duration)
+                idle_timeout = _asr_idle_timeout(media_duration)
                 observer = _TranscriptionObserver(self.log, media_duration)
                 self.log(
                     f"{CAPSWRITER_START_LOG_KEY} attempt={attempts}/{self.max_retries} "
@@ -951,6 +1008,8 @@ def transcribe_file(
                 }
                 if deadline_total is not None:
                     sdk_kwargs["deadline_total"] = deadline_total
+                if idle_timeout is not None:
+                    sdk_kwargs["idle_timeout"] = idle_timeout
                 transcript = transcribe_file_sync(
                     file_path,
                     server_url,