尾部延迟四步排除与阻塞抓栈定位法

一、适用场景

• 服务"中位很好、偶发秒级卡"：QA 判分用中位/p95（甚至多轮取最小值），抓不到尾部周期性簇，
  于是缺陷长期潜伏（本例尖峰率约 0.9%，此前所有 QA 均未捕获）。
• 已知症状但归因失败：改了缓存、改了压缩、调了 PRAGMA 都没用，需要一个能证伪的排查顺序。
• 需要在不动产品代码的前提下验证修复收益（原型 monkeypatch + DB 快照副本）。

二、操作步骤

第 0 步·先把口径立对：判分必须同时看 中位 / p95 / p99 / max / 超标计数，不许只看中位。
可用附包体检器：python scripts/tail_latency_check.py --samples samples.txt（见第五节实测）。

第一步·长时采样看分布（不猜）：跑满 ≥2 个后台维护周期（每周期 300s），同时采 WAL 大小，
判定尖峰是否与维护周期相关。锚点 .workbuddy/diag_tail_latency.py L63 main()、
L100-103 每秒 WAL 采样、L117 pct() 分位计算。

第二步·服务端逐段计时，把"慢在哪一段"切出来：给 db.connect 包一层 ConnWrap 累计 SQL/commit 耗时，
再给 gzip 包一层，按请求输出 sql_ms / gz_ms。锚点 .workbuddy/diag_slow_attribution.py
L76 class ConnWrap、L102 execute、L112 commit、L139 gzip_wrapped、L158 do_get_wrapped。
本步结论：慢请求 sql_ms≈0、gz_ms 1–3ms → 卡点不在 SQL 也不在压缩。

第三步·不在 DB 就抓阻塞现场线程栈：对"已耗时 >400ms 且仍活跃"的请求线程取栈，
锚点 .workbuddy/diag_block_stack.py L64-65 stack_of() 用 sys._current_frames()、L95 watcher()。
本步结论：尖峰时栈一律停在 do_GET → _cache_ver_sync → db.get_setting → db.connect，
即"线程级连接复用"的前提（线程常驻）在"每连接一线程"模型下不成立——每请求都新建连接。

第四步·原型 A/B 验证收益（零产品改动）：同脚本、同 DB 快照副本、同 warmup + maintenance、
同采样间隔、各 300s 对照。锚点 .workbuddy/diag_fix_pool.py L130-137 用 PoolHFMS(app.HFMServer)
覆写 process_request 提交到线程池（仅验证用，落地另说）。

贯穿全程的铁律：

• 禁止先入为主归因——本例连续排除三个错误假设：GC STW（diag_gc_stw.py：82 次 GC 累计 176ms、最大 40ms，与时间无关联）、
  CPU 争抢（diag_stw_cpu.py：慢窗口进程 CPU 仅 3–14%）、PRAGMA journal_mode 锁竞争（diag_journal_busy.py：8 线程 A/B 差异 0.11ms）。
• 压测必须避开启动后 30s 的预热窗口——否则测量被预热线程抢 CPU 污染，会把有效改进误判为"无效且恶化"。
• 假设被证伪就回退——本例中"预建搜索语料"实测首查仍 729–1205ms（改进前 842–1083ms），未改善即把 SEARCH_CORPUS_TTL 默认置 0 走原路径，只保留真实有效的那一段。

三、注意边界

• 全程只诊断、不落地：结构性改动（HTTP 服务器模型）属重大变更，须用户点头后再动。
• 任何探测都跑在 DB 快照副本上，绝不碰线上库；读真实库一律 mode=ro。
• 采样时长要盖住后台维护周期，短采样只能看到"随机噪声"，看不到"周期性簇"。
• 分位数要标注样本量；样本 <20 时脚本拒绝下结论（INFO），这是有意为之。
• 抓栈只抓"仍活跃且已超阈值"的线程，别无差别全量 dump，否则日志自己把磁盘撑爆。

四、反例避雷

• ✗ 只看中位 / 多轮取最小值判分 → 尾部簇整批漏判，缺陷带病上线。
• ✗ 先入为主归因（本次一开始归因于"逐份读 75 份制度 Word"）→ 实测该段仅 7.9ms，白做一整轮。
  修法：先逐段计时证因，再动手。
• ✗ 在启动后立即压测 → 预热线程抢 CPU，结论被污染。
• ✗ 原型用 ThreadPoolExecutor 就直接落地 → 它的线程非 daemon，进程退出时被 join，
  处理 keep-alive 连接的线程会让进程退不掉。落地应用自建 mini pool（daemon 常驻线程 + Queue），
  并给队列投递加超时。（本例 A/B 只用于验证收益，落地形态另选。）
• ✗ 把原型脚本里"收益显著"当成"可以顺手改产品代码" → 越权；结构性改动必须先确认。
• ✗ 探测本身引入新负载（如用 bash 探测反引号、用探测命令抢 CPU）→ 测到的就是自己的探测开销。

五、代码锚点 / 实战战绩

锚点：

• .workbuddy/diag_tail_latency.py —— L63 主循环、L100-103 WAL 逐秒采样、L117 分位。
• .workbuddy/diag_slow_attribution.py —— L76 ConnWrap、L102/112 SQL 与 commit 计时、L139 gzip 计时、L158 请求包装。
• .workbuddy/diag_block_stack.py —— L64-65 sys._current_frames() 取栈、L95 watcher 按 >400ms 活跃筛选。
• .workbuddy/diag_fix_pool.py —— L130-137 PoolHFMS + process_request 提交线程池（A/B 原型）。
• 旁证脚本：diag_gc_stw.py / diag_stw_cpu.py / diag_journal_busy.py / diag_connect_cost.py / diag_fix_http11.py。

战绩（2026-10-13，同脚本同快照同口径，各 300s）：

诚实声明：尖峰占约 0.9%（>1s 23/2512），中位体验未受影响——正因如此此前所有 QA 都没抓到。

附包体检器（只读、不连库、不起服务）：

python scripts/tail_latency_check.py --samples samples.txt # 每行一个耗时 ms

强制输出 中位/p95/p99/max + >300ms、>1000ms 计数 + p99/中位 倍率；
命中任一条件（秒级尖峰 / 倍率 >3× / 超标占比 >1%）即判 FAIL 并指向四步排除法。
实测：构造 thread 档样本（注入 16 个尖峰）→ FAIL（p99/中位 25.7×，秒级 9 次）；
构造 pool 档样本（无尖峰）→ PASS（p99/中位 1.3×）；样本 <20 时只出 INFO，不硬造结论。

六、关联笔记

• 05-测试-Web端点性能剖面定位法：那是单请求剖面（"这个接口为什么慢"），
  本技能是长时尾部定位（"为什么偶尔集体卡一下"），两者互补，别混用。
• 05-测试-QA测量环境隔离与失真排除法：所有性能数字必须先隔离（DB 快照副本 + 无并行负载）再谈归因。
• 02-技术-服务端常驻线程池并发改造法：本技能的修复本体（自建 daemon 线程 + Queue），
  诊断归诊断、修复归修复，两个包分工明确。
• 02-技术-跨进程页面缓存与SWR陈旧宽容法：_cache_ver_sync 正是本例抓栈抓到的卡点所在，
  缓存层的写放大与 WAL 治理见该包。
• 05-测试-全页面回归冒烟法：改完必跑；强杀进程后立即重启若报 disk I/O error 属瞬时错误，先 integrity_check 再原样重试。

七、版本记录

• v1.0.0（2026-10-18）：首版。据 2026-10-13「偶发秒级卡顿真因定位」专项实战固化；
  含四步排除法、三条证伪记录、尾部判分口径与只读体检器。