指数退避把「毫秒」算成了「次数」：出站队列该等的没等就被放行，而自述报告 / 空判据表健康检查 / 退出码全绿

日期：2026-10-12　分支：2026-10-12-1600　Issue：#139（第122题）技术栈：Python 3.11 标准库 / Docker + Docker Compose / Unix 时间量纲 / 契约驱动判定关键词：指数退避 exponential backoff、base_ms * attempts、毫秒当次数、时间量纲 dimensional analysis、退避基数 QUEUE_BACKOFF_BASE_MS、2 ** attempts、提前放行 early delivery、静默放行、 BAD_FIELDS = () 空判据表、健康检查假绿、退出码恒 0、fail-closed、外部独立探针、契约驱动报错/现象关键词：RESULT: BAD（不一致 5 条）、期望退避 120000 ms 实际 60000、 期望 defer(not_due) 实际 deliver(ready)、PASS=10 FAIL=14、degraded: false, issues: []

一、问题背景

出站通知队列的投递准入控制器（queue appraiser）。每轮盘点一次，逐条判断队列里的待投递消息「这一轮能不能投出去」。

契约 conf/queue.env（只读考卷）：

QUEUE_DELAY_UNIT=milliseconds      # 一切「等待时间 / 条目年龄」字段单位都是毫秒
QUEUE_BACKOFF_POLICY=exponential
QUEUE_BACKOFF_BASE_MS=30000        # 基础退避 30 秒
QUEUE_MAX_ATTEMPTS=3

契约 docs/queue-contract.md：指数退避第 n 次（1-based）投递前的等待 = BASE × 2^(n−1)， 单位同样是毫秒；条目可投递 ⟺ 通道存在且启用且 now_ms − received_at_ms >= backoff_ms。

现象：一轮盘点下来，自述报告 ok: true、健康检查 {"degraded": false, "issues": []}、三个脚本退出码全 0 —— 看着一切正常。但有消息在退避窗口还没到的时候就被判「可以投递」了：

$ bash ops/repro.sh
{"block": 2, "dead": 0, "defer": 1, "delay_unit": "milliseconds", "deliver": 4, "ok": true}
健康检查：{"degraded": false, "engine": "queue-appraiser", "issues": []}   health rc=0

只有外部独立探针 client/queue_probe.py（只读契约 + 通道定义 + 条目原文 + 报告， 不读任何自述字段）报出真相：

不一致：m-001：期望退避 120000 ms 实际 60000
不一致：m-002：期望 defer(not_due) 实际 deliver(ready)
不一致：m-004：期望退避 120000 ms 实际 60000
不一致：m-005：期望退避 60000 ms 实际 30000
不一致：m-007：期望 defer(not_due) 实际 deliver(ready)
RESULT: BAD（不一致 5 条）     rc=1

最刺眼的是 m-002：attempts=2、年龄只有 110000 ms（110 秒），契约要求至少等 30000 × 2^2 = 120000 ms（120 秒）—— 它被提前了 10 秒放行，而且没有任何一盏灯亮。

二、复现步骤

方式 A：Docker 一键（推荐）

cd scenario/2026-10-12-1600
docker compose up -d --build
docker compose exec -T queue bash

# 容器内
cd /srv
bash ops/repro.sh   ; echo "rc=$?"   # -> RESULT: BAD，rc=1（预期的复现信号）
bash ops/verify.sh  ; echo "rc=$?"   # -> PASS=10 FAIL=14 / RESULT: BAD
bash ops/negative.sh; echo "rc=$?"   # -> 以参考解为基线的负向验证
python3 client/queue_probe.py        # -> RESULT: BAD（不一致 5 条），rc=1

方式 B：无 docker CLI（纯标准库，任意 Python 3）

cd scenario/2026-10-12-1600
export SCENARIO_ROOT="$PWD" CONF_DIR="$PWD/conf"
bash ops/repro.sh  ; echo "rc=$?"    # -> RESULT: BAD，rc=1
bash ops/verify.sh ; echo "rc=$?"    # -> PASS=10 FAIL=14 / RESULT: BAD

ops/repro.sh 以外部探针的退出码为自己的退出码，问题态返回 1 —— 这是预期的复现信号，不是环境坏了（用 ; echo rc=$? 接住，别用 &&）。

问题态验收输出节选：

== B 组：退避是「毫秒」量纲，指数步进 base×2^attempts ==
  [FAIL] B1 m-001 attempts=2 退避(ms)：期望 120000 实际 60000
  [FAIL] B2 m-004 attempts=2 退避(ms)：期望 120000 实际 60000
  [FAIL] B3 m-005 attempts=1 退避(ms)：期望 60000 实际 30000
  [FAIL] B4 m-007 attempts=0 退避(ms)：期望 30000 实际 0
== C 组：逐条判定必须符合契约（不得放宽、不得误拒） ==
  [FAIL] C2 m-002 判定：期望 defer 实际 deliver
  [FAIL] C8 m-007 判定（不得误放行）：期望 defer 实际 deliver
  [FAIL] C9 汇总 deliver 条数：期望 2 实际 4
== D 组：放行条目必须写明本轮实际等待时间 ==
  [FAIL] D m-004 放行但未写明 wait_ms（实际 None）
== E 组：健康检查必须有牙（判不了 != 没问题） ==
  [FAIL] E2 契约不可用 health 退出码：期望 3 实际 0
  [FAIL] E3 拿不到报告 health 退出码：期望 2 实际 0
== F 组：外部独立探针 ==
  [FAIL] F1 探针退出码：期望 0 实际 1
PASS=10 FAIL=14
RESULT: BAD

自己把输入事实按契约重算一遍，一眼看出量纲错：

python3 - <<'PY'
import json
now, base = 1800000, 30000
for line in open('input/queue.jsonl'):
    it = json.loads(line); a = it['attempts']
    print(f"{it['id']} attempts={a} age={now-it['received_at_value']:<7} "
          f"契约need={base*2**a:<7} 代码base*a={base*a:<7} 幂base**a={base**a}")
PY

m-001 attempts=2 age=50000   need=120000  base*a=60000    base**a=900000000
m-002 attempts=2 age=110000  need=120000  base*a=60000    base**a=900000000
m-003 attempts=0 age=600000  need=30000   base*a=0        base**a=1
m-004 attempts=2 age=120000  need=120000  base*a=60000    base**a=900000000
m-005 attempts=1 age=60000   need=60000   base*a=30000    base**a=30000
m-006 attempts=0 age=10000   need=30000   base*a=0        base**a=1
m-007 attempts=0 age=500     need=30000   base*a=0        base**a=1

三、根本原因

根因一（题眼）`app/backoff.py` —— 「毫秒」被乘成了「毫秒 × 次」

# 错误写法
return base_ms * attempts      # attempts 是 0-based「次数」，乘进毫秒 → 量纲变成 ms × 次

age_ms 的单位是毫秒，backoff_ms 的单位却是毫秒×次，两者做 >= 比较等于拿错量纲的尺子量长度。后果：

attempts=2 时退避只剩 30000×2 = 60000（应为 30000×2^2 = 120000）→ 提前 60 秒放行（m-001/m-004）；
attempts=1 时退避 30000（应为 60000）→ 提前 30 秒放行（m-005）；
attempts=0 时退避算成 0 → 任何年龄都能过（m-007 是隐藏地雷，本题中因 0*0 恰为 0 而侥幸未暴露）。

正确写法：

return base_ms * (2 ** attempts)     # 指数只放大倍数，不改变量纲

attempts=0 → 30000（不是 0，也不是 1）；attempts=1 → 60000；attempts=2 → 120000。

另一个静默错误方向：写成 base_ms ** attempts 时 attempts=0 → 1（退避 1 毫秒 = 几乎立即放行）、 attempts=1 → 30000。一个偏小一个偏大，两个方向都不抛异常。 本题数据里正好没有 attempts >= 3 的条目，所以 dead 恒 0，进一步掩盖了问题。

根因二 `app/appraiser.py` —— 报告缺关键字段

每行没有 delay_unit：生效单位没透出，外部无法确认代码采纳了哪个量纲；
没有 wait_ms：放行条目没写明本轮实际等到多久，无法复核准入不等式；
死信判定放在循环之后二次遍历，verdict/reason 有前后不一致的风险。

根因三 `app/health.py` —— 空判据表 + 只读自述 + 退出码恒 0

BAD_FIELDS = ()                              # for 一次都不循环 → issues 恒空 → degraded 恒 false
...
except (OSError, json.JSONDecodeError):
    return EXIT_OK                           # 连"拿不到报告"都判健康
...
return EXIT_OK                               # main() 无条件 return 0

判据表是空的、只读自述报告、main() 无条件返回 0 —— 这叫给自己发体检合格证。 E2/E3（契约不可用期望 3、拿不到报告期望 2，实际都是 0）就是实证。

三个根因互相掩护：量纲错了没人发现（闸门是假的），只修量纲能让探针变绿、但闸门仍然没牙，下次同类错误依然四个绿灯全亮。

为什么「时间量纲」类 bug 特别难查

条目自身不带任何单位标记（契约明文：「时间量纲是队列级契约，所有条目共用一套」）。 age_ms(item["received_at_value"], now, unit) 老老实实按契约换算，但 backoff_ms() 按「次数」步进 —— 两个都返回整数、都叫 _ms 的数值直接比较， 类型相同、量纲不同，语言层面完全无法察觉，错误 100% 静默。

四、解决办法

只改 app/ 下三个文件。conf/、docs/、client/、input/、state/delivered.log、 ops/verify.sh、ops/negative.sh 都是只读考卷与验收口径，一字未动。

① `app/backoff.py`

def backoff_ms(base_ms, attempts, policy="exponential"):
    if policy == "fixed":
        return base_ms
    return base_ms * (2 ** attempts)

② `app/appraiser.py`

attempts_now = int(item["attempts"])
need = backoff.backoff_ms(conf["backoff_base_ms"], attempts_now, conf["backoff_policy"])

channel = channels.get(item["channel"])
if channel is None:
    verdict, reason = "block", "channel_unknown"
elif not channel.get("enabled"):
    verdict, reason = "block", "channel_disabled"
elif age >= need:
    verdict, reason = "deliver", "ready"
else:
    verdict, reason = "defer", "not_due"

if attempts_now >= conf["max_attempts"] and verdict != "deliver":
    verdict, reason = "dead", "max_attempts"

results.append({
    ...
    "delay_unit": conf["delay_unit"],                    # 生效单位逐字透出
    "wait_ms": age if verdict == "deliver" else None,    # 放行必须写明实际等待
})

③ `app/health.py` —— 判据落在可被外部独立复核的事实上

_load_contract()：契约读不到 / QUEUE_DELAY_UNIT 非法 / 策略非 exponential / 数值字段缺失 → EXIT_CONTRACT=3，绝不回退默认值；
_reference()：在 health 里另写一遍契约口径（故意不复用 appraiser，避免自己治自己），逐条独立重算 verdict / reason / backoff_ms / wait_ms；
逐条比对 + 汇总字段对账（deliver/defer/block/dead、items_total）；
BAD_FIELDS 改为非空判据表；拿不到事实（条目/通道/报告缺失）→ EXIT_PROBLEM=2；
退出码分层：0 干净一轮 / 2 有真问题或拿不到事实 / 3 契约不可用（fail-closed）。

五、验证

同步进容器并跑验证（镜像 COPY app/ /srv/app/，compose 无 bind mount）：

docker compose cp app/. queue:/srv/app/
docker compose exec -T queue bash -c 'cd /srv && \
  find . -name __pycache__ -prune -exec rm -rf {} + ; \
  bash ops/repro.sh; echo "repro rc=$?"'

修复态：

{"block": 2, "dead": 0, "defer": 3, "delay_unit": "milliseconds", "deliver": 2, "ok": true}
health: {"backoff_base_ms":30000,"block":2,"contract_available":true,"dead":0,"defer":3,
         "degraded":false,"delay_unit":"milliseconds","deliver":2,"issues":[],
         "items_total":7,"max_attempts":3,"mismatch":0}   health rc=0
RESULT: OK
probe rc=0
repro rc=0

修复后逐条报告（与契约逐条对齐）：

delay_unit=milliseconds deliver=2 defer=3 block=2 dead=0
m-001 attempts=2 age=50000   backoff=120000  defer    not_due          wait_ms=None
m-002 attempts=2 age=110000  backoff=120000  defer    not_due          wait_ms=None
m-003 attempts=0 age=600000  backoff=30000   block    channel_disabled wait_ms=None
m-004 attempts=2 age=120000  backoff=120000  deliver  ready            wait_ms=120000
m-005 attempts=1 age=60000   backoff=60000   deliver  ready            wait_ms=60000
m-006 attempts=0 age=10000   backoff=30000   block    channel_unknown  wait_ms=None
m-007 attempts=0 age=500     backoff=30000   defer    not_due          wait_ms=None

全量验收 bash ops/verify.sh：

A1~A3  PASS  契约时间量纲被真正采纳
B1~B4  PASS  退避是毫秒量纲，指数步进 base×2^attempts
C1~C10 PASS  逐条判定与契约一致（m-002 defer / m-007 defer / deliver=2 / defer=3）
D      PASS  m-004 wait_ms=120000、m-005 wait_ms=60000
E1~E3  PASS  health 退出码 0 / 3 / 2（分层 fail-closed）
F1~F2  PASS  外部探针 rc=0 + RESULT: OK

PASS=24 FAIL=0
RESULT: OK

负向验证 bash ops/negative.sh（证明闸门真的有牙，不是「恰好绿」）：

基线全绿                                        PASS
N1 退避改回「次数」量纲（题眼回滚）→ 探针 rc=1、health rc=2   PASS
N2 退避算成 base ** attempts        → 探针 rc=1             PASS
N3 自述被篡改 deliver=999          → health rc=2            PASS
N4 判据表挖空 + 退出码恒 0          → 对坏数据仍 rc=0（实证假绿）PASS
N5 契约不可用                       → health rc=3（fail-closed）PASS
收尾回归全绿                                     PASS

负向验证：9 PASS / 0 FAIL
RESULT: OK（闸门有牙）

从零重建复跑（排除「靠拷参考解蒙的」）：

docker compose down -v && docker compose up -d --build
docker compose exec -T queue bash -c 'cd /srv && bash ops/repro.sh; echo "repro rc=$?"; bash ops/verify.sh | tail -4'
# repro rc=0；PASS=24 FAIL=0 / RESULT: OK

六、经验与避坑

核心认知

1. BASE × 2^n 是「指数」不是「乘法」—— 把次数乘进毫秒，量纲就从 ms 变成 ms × 次。

最短自检口诀：「退避」算完之后还该是毫秒吗？× attempts 之后它变成了什么？attempts 是 0-based 的次数，不是「次数」这个单位本身。凡是「基数 × 指数放大」的语义（退避、重试间隔、速率限制窗口、缓存过期、分页偏移），都要问一句 「我是乘 2^n 还是乘 n」；× n 是线性、× 2^n 是指数，两者在 n=1 时数值相同、n=0 时一个为 0 一个为 base、n>=2 后迅速分道扬镳。

2. 时间量纲只写在契约里时，代码里的量纲错会「完全静默」。

条目不带单位标记，age_ms 与 backoff_ms 都返回整数、都叫 _ms，类型相同、量纲不同 —— 语言层面无法察觉，比较运算照常执行。这类「量纲靠约定、不靠类型」的设计，必须靠报告透出 delay_unit + 外部按契约重算来兜底。

3. 绿色信号分三类：进程没崩（弱）/ 自己写的自述（无判别力）/ 能被外部按契约独立复核的事实（强）。

ok: true 写死常量、BAD_FIELDS = () 空判据表、main() 无条件 return 0、 except: return EXIT_OK —— 这类「自述字段自证」比没有检查更危险，因为它静默地骗人。本题最值得记的一条：N4 把判据表挖空 + 退出码改回恒 0 后，对坏数据仍是 rc=0、 degraded=false —— 这就是「假绿」的实证。

4. 「判不了」≠「没问题」（fail-closed）。

契约不可用、条目清单缺失、报告拿不到 —— 这些都是「判不了」，必须退出非 0 且与「有真问题」的退出码分层（本题 0 干净 / 2 有真问题或拿不到事实 / 3 契约不可用）。 contract.py 里「读不到就静默回退默认值」正是灾难源：契约缺失时不该猜一个量纲，而该明确判「契约不可用」。

5. 只修题眼不够。

不修健康检查，下次同类错误依然四个绿灯全亮。 「修好了 bug」只解决了这一次；「修好了闸门」才解决了下一次。

排查路径（有辨识度）

现象呈现「数值恰好等于 BASE × n 而不是 BASE × 2^n」 → 直接去看退避/间隔计算那一处，通常是 * attempts 与 * (2 ** attempts) 之误；
attempts=0 的条目行为异常（该等 30 秒却立刻放行）→ 典型的 × 0 或 ** 0 错误签名；
自述全绿但外部探针转红 → 去看看健康检查读的是事实还是自述；
issues 恒空、degraded 恒 false → 搜 BAD_FIELDS = () / for 循环体为空的判据表。

踩坑清单（本项目实操）

ops/repro.sh 以探针退出码为脚本退出码 —— 问题态返回 1，这是预期信号，用 ; echo rc=$? 接住，别用 &&。
非交互环境 docker compose exec 必须加 -T，否则 the input device is not a TTY。
镜像 COPY app/ /srv/app/ 打进代码、compose 无 bind mount —— 改完宿主机文件容器看不到，必须 docker compose cp app/. queue:/srv/app/ 或 docker compose up -d --build 重建，否则出现「容器内全绿、宿主机 git diff 却是空的」。
改完 app/*.py 必须清 __pycache__ —— 旧字节码会把「已改」掩盖成「没改」。
ops/negative.sh 会自动把 app/ 切成参考解（开头与收尾都调用 apply_reference()），跑完后容器里的 app/ 已不是手写版本 —— 别被误导，宿主机文件不受影响。
只改 app/ —— 改 conf/ / docs/ / client/ / ops/*.sh 让结果变绿 = 造假。提交前 git diff --name-only -- conf docs client input ops 复核（应为空）。
运行期产物 state/appraisal.json 已 gitignore，手改报告让闸门变绿同样是造假。

自查口诀

退避/间隔算完之后还该是毫秒吗？我乘的是 n 还是 2^n？attempts=0 时结果是 base、0 还是 1？报告里透出「生效单位」了吗？放行条目写明「实际等待」了吗？健康检查读的是事实还是自述？判据表是不是空的？拿不到数据时我判通过还是不通过？我的闸门有没有被「挖空判据表 + 退出码恒 0」实证过是假绿？