edit | blame | history | raw

2026-07-01 识别变慢复盘

用户目标

用户反馈“关于慢的问题也有好几天了”,要求汇总 PrivateVoice 日志并判断是否有需要改进的地方。

当前起点

  • 日志文件:/Users/ar/Library/Application Support/PrivateVoice Input/app.log
  • 日志范围包含 2026-06-272026-07-01
  • 完整 PERF 样本数:377 次
  • 当前主模型:SenseVoice · CoreML (Apple Neural Engine)

日志统计结论

全部样本:

  • total_ms:平均 966ms,p50 619ms,p90 1541ms,p95 2393ms,最大 14473ms
  • recognize_ms:平均 586ms,p50 257ms,p90 1151ms,p95 2008ms,最大 13394ms
  • paste_ms:平均 3ms,p50 1ms,p95 12ms,最大 78ms
  • history_ms:平均 10ms,p95 28ms,最大 81ms
  • tail_ms:通常固定 300ms
  • hotkey_wait_ms:通常固定 50-51ms
  • engine_lock_wait_ms:始终 0ms

慢样本分布:

  • total_ms <= 700ms:230 次
  • 701-1000ms:63 次
  • 1001-2000ms:59 次
  • 2001-4000ms:17 次
  • >4000ms:8 次

按天:

  • 2026-06-29:56 次,p50 652ms,p95 2353ms,最大 5734ms
  • 2026-06-30:87 次,p50 696ms,p95 3440ms,最大 5329ms
  • 2026-07-01:234 次,p50 583ms,p95 1660ms,最大 14473ms

慢峰值集中时段:

  • 2026-06-30 12 点:39 次,slow > 2s 有 10 次,recognize_ms 最大 4842ms
  • 2026-06-30 18 点:6 次,slow > 2s 有 3 次,recognize_ms 最大 3625ms
  • 2026-07-01 17 点:25 次,slow > 2s 有 3 次,recognize_ms 最大 13394ms
  • 2026-07-01 18 点:12 次,slow > 2s 有 4 次,recognize_ms 最大 6222ms

根因判断

  1. 上屏/剪贴板不是主要瓶颈。paste_ms 平均 3ms,p95 12ms,最大 78ms。
  2. 历史写入不是主要瓶颈。history_ms 平均 10ms,最大 81ms。
  3. 互斥锁不是瓶颈。engine_lock_wait_ms 始终为 0ms。
  4. 固定延迟确实存在:尾音保护约 300ms,热键释放稳定等待约 50ms,合计约 350ms。
  5. 真正导致“很慢”的主要因素是 recognize_ms 抖动,尤其在系统负载极高时被拖到 2-14 秒。
  6. 音频长度与识别耗时相关性很弱,粗略相关系数约 0.053;短音频也可能出现 13 秒识别,说明慢不是单纯因为说得长。
  7. 2026-07-01 17:40 的系统只读诊断显示整机负载异常:load average 193 / 124 / 59,Codex、WindowServer、Computer Use、Spotlight、spindump 等占用明显;与 17-18 点慢峰值高度吻合。

可改进方向

P0 外部环境治理:

  • 先做 Codex 本地状态维护和项目工作区瘦身,避免 Codex、git、Spotlight、WindowServer 长时间抢 CPU/磁盘/GPU。
  • 该项不改 PrivateVoice 代码,但对识别稳定性影响最大。

P1 产品内性能告警:

  • 当单次 recognize_ms > 2000total_ms > 2500 时,在日志中增加慢识别摘要,并记录当前模型、音频长度、系统负载近似信息。
  • 目的:后续不用人工猜测是否系统负载导致。

P2 固定等待优化:

  • 目前每次成功识别前固定增加约 350ms:300ms 尾音保护 + 50ms 热键稳定等待。
  • SenseVoice 离线模型是否需要 300ms 尾音保护需要重新确认;现有代码显示 ReleaseTailCaptureEngine 主要由 X-ASR 实现,普通 sherpaEngine 理论上不应请求尾音窗口,但日志中仍有 300ms,需进一步定位实际配置来源。

P3 识别推理防抖:

  • 对 CoreML 推理慢峰值做系统负载感知:负载过高时可以在浮窗显示“系统繁忙,识别中”,避免用户误以为软件卡死。
  • 不建议在没有更多证据前盲目改 NumThreads 或模型 provider。

下一步建议

  1. 先处理 Codex / 工作区 / Spotlight 的外部负载问题。
  2. 再加一轮更细的慢识别日志:系统负载、provider、模型 ID、音频长度、recognize_ms 分级。
  3. 单独排查为什么 SenseVoice 当前日志仍显示 300ms release_tail_wait_done,确认是否是历史诊断版本、分支差异或引擎能力判断有偏差。

已落地实现

按用户确认意见完成代码落地:

  • 新增 PERF slow_recognition 日志:
  • 触发条件:recognize_ms > 2000total_ms > 2500
  • 记录字段:reason、model_id、language_id、engine、audio_ms、samples、recognize_ms、total_ms
  • macOS 额外记录 load1/load5/load15
  • 非 macOS 记录 load_unavailable=true
  • 尾音保护策略改为按引擎声明:
  • SenseVoice:100ms
  • X-ASR:300ms
  • 其他 sherpa 离线模型:0ms,避免误伤 Qwen3-ASR、Moonshine、Parakeet、Zipformer 等模型
  • Windows/Linux 当前 sherpa SenseVoice 引擎也声明 100ms,避免平台行为不一致
  • 新增/更新测试:
  • 默认 plain engine 不再被 App 层兜底加尾音保护
  • SenseVoice 请求 100ms 尾音保护
  • X-ASR 保持 300ms 尾音保护
  • 其他 sherpa 模型不请求尾音保护
  • 慢识别 reason 阈值判断

验证:

  • gofmt
  • git diff --check -- privatevoice.src/app.go privatevoice.src/app_live_caption_test.go privatevoice.src/system_load_darwin.go privatevoice.src/system_load_other.go privatevoice.src/internal/engine/engine_darwin.go privatevoice.src/internal/engine/engine_darwin_test.go
  • go test ./...

验证结论:测试通过;仅存在既有 macOS 链接版本 warning。