归档刷写「6 条记录全部交付成功」而归档一段都没落地 —— 记账写在数据落盘之前,ack mtime 早于 data mtime
日期:2026-10-08 16:00 | 分支:
2026-10-08-1600| 第 111 题 技术栈:Linux 文件系统(mtime/fsync时序)、Python 3、Docker 关键词:fsync 顺序、记账 mtime 晚于数据、崩溃一致性、write ordering、crash consistency、先记账后干活、幂等 / 补写、空判据表、退出码恒 0、fail-closed、交付未落地、spool 归档、sha256 记账、自述字段全绿
一、问题背景:四个绿灯,没有一件指向真相
spoolerd 是日志归档刷写服务:每来一条记录,追加进一个归档分段(outbox/seg-NNNNNN.ndjson),
并在旁边写一份记账文件(outbox/seg-NNNNNN.ndjson.ack.json),记录这一段的 sha256 与字节数。
下游(备份 / 校验 / 计费)只认记账文件:记账说落地了,才当这一段可用。
运维发现:写接口一直报「6 条记录全部交付成功」,但归档目录里按契约一条都不算落地。
写入方自述:
{
"ok": true,
"self_consistent": true,
"rounds": 6,
"records": 6,
"delivered": 6,
"sealed": 0,
"current_segment": "seg-000000.ndjson",
"errors": []
}
四个绿灯全亮:demo.py 退出码 0、report.json 里 ok: true、self_consistent: true、
health 输出 {"degraded": false, "issues": []} 且退出码 0。
但唯一说真话的是外部独立探针 client/spool_probe.py(只读契约 + 归档真实字节 + stat() 的 mtime,
不读写入方任何自述字段):
分段总数: 1
已落地(记账晚于数据落盘且 sha256 相符): 0 []
未落地: 1 ['seg-000000.ndjson']
RESULT: BAD ← 退出码 1
二、复现步骤
本题环境是纯 Python 3、脚本自带相对路径入口,所以在 pipeline 容器内以场景目录为工作目录
直接跑即等价复现(无 docker CLI 时):
# A. 有 Docker CLI(本分支已在容器里实测跑通)
cd scenario/2026-10-08-1600
docker compose up -d --build
docker compose exec -T spoolerd bash ops/repro.sh
# B. 无 Docker CLI 时在 pipeline 容器内直接跑(纯 Python 3,脚本自带相对路径入口)
cd scenario/2026-10-08-1600
bash ops/repro.sh
有 Docker 的机器上等价命令:
cd scenario/2026-10-08-1600
docker compose up -d --build
docker compose exec -T spoolerd bash ops/repro.sh
问题态输出:
{ "ok": true, "self_consistent": true, "delivered": 6, ... }
demo.py rc=0
...
已落地(记账晚于数据落盘且 sha256 相符): 0 []
未落地: 1 ['seg-000000.ndjson']
RESULT: BAD ← spool_probe.py rc=1
{"degraded": false, "issues": []}
health rc=0
核心证据(一行命令)
python3 - <<'PY'
import os, glob, json, hashlib
for d in sorted(glob.glob("outbox/*.ndjson")):
a = d + ".ack.json"
print(os.path.basename(d),
"data mtime", os.stat(d).st_mtime_ns,
"ack mtime", os.stat(a).st_mtime_ns,
"ack>data", os.stat(a).st_mtime_ns > os.stat(d).st_mtime_ns)
rows = [json.loads(l) for l in open(a) if l.strip()]
h = hashlib.sha256(open(d, "rb").read()).hexdigest()
print(" 记账行数", len(rows), "数据条数", len(open(d).readlines()),
"最后记账 sha256", rows[-1]["sha256"][:16],
"真实 sha256", h[:16],
"相符", rows[-1]["sha256"] == h)
PY
问题态三个症状同时出现:
seg-000000.ndjson data mtime 1791446869876680943 ack mtime 1791446869846681363 ack>data False
记账行数 1 数据条数 6 最后记账 sha256 f8d537b98c6edace 真实 sha256 90f7c7d348fec53d 相符 False
| # | 现象 | 含义 |
|---|---|---|
| ① | ack mtime < data mtime | 记账写在数据落盘之前 |
| ② | 记账 1 行 vs 数据 6 条 | 记账被「复用」逻辑跳过了 5 次 |
| ③ | 记账 sha256 f8d537b9… ≠ 真实 90f7c7d3… | 记账里的摘要不是真实字节的摘要 |
三、根本原因:fsync 顺序写反了 + 记账被「复用」跳过
契约 conf/spoolcontract.env 是唯一口径来源:
SPOOL_DELIVERY_CRITERION=fsync_after_write # ← 关键口径开关
SPOOL_FSYNC_EACH=1 # 逐条落盘
契约对「一次交付算不算落地」写得很清楚:
一次交付被判为「已落地」的唯一充分条件:
- 记账文件的 mtime 严格晚于 数据文件的 mtime
- 记账文件里的每一行都能被
json.loads解析- 记账文件里最后一条声明的
sha256== 数据文件的真实 sha256
而 app/spooler.py::deliver_checksum() 把顺序写反了:
# 问题态:先记账,再写数据
data_hash = self._reuse_ack_hash(seg) # ① 复用旧记账摘要
if data_hash is None:
data_hash = self._expected_hash(seg, payload) # ② 凭「未来字节」算摘要
self._write_ack(seg, data_hash, len(payload)) # ③ 先落记账
seg.append(payload, fsync=self.fsync_each) # ④ 后写数据
三个连锁缺陷,全都不抛异常:
_reuse_ack_hash():本段记账文件里已有摘要就直接复用 → 第一条把sha256写了, 后面 5 条全部跳过记账 → 记账 1 行、数据 6 条。记账行数与交付次数脱钩。_expected_hash():摘要算的是「将来写完全部再重算」的值(sha256(已有字节 + 本条)), 不是当前真实字节的摘要,且最后一次重算从未发生 →sha256永远对不上盘上字节。- 顺序反了:记账
fsync在数据fsync之前 →ack mtime < data mtime。
为什么这是「崩溃一致性」问题,而不只是「检查不严」
写入方本来就该「数据落盘之后才写记账」。所以契约判据
ack mtime > data mtime ⇔ 「记账确实发生在数据落盘之后」。
一旦顺序反了,崩溃/重启后「幂等 / 补写」逻辑看到记账文件就认为这一条已经在盘上了, 于是跳过重写 —— 数据就永远丢了,而所有自述字段依然全绿。
mtime 是文件系统里最便宜的崩溃一致性证据,比任何自述字段都可信。
第二处题眼:app/health.py —— 闸门本身被关掉
BAD_FIELDS = () # 空判据表 = 关掉了整个检查(for 一次都不循环)
def main():
rep = json.load(open("reports/report.json")) # 读的还是写入方自述
...
return EXIT_OK # 无条件 return 0(退出码恒 0)
判据表为空、读写入方自述、退出码恒 0。归档被写坏时它照样 rc=0、degraded:false
—— 判不了却报「没问题」,违反 fail-closed。
四、解决办法(只改 app/spooler.py + app/health.py)
conf/、client/、ops/*.sh 是考卷,一字未动。
1. 把数据先落盘、再取真实摘要记账
def deliver_checksum(self, payload: bytes) -> bool:
seg = self.current
if seg is None:
raise SpoolError("当前分段为空,写入方未初始化")
try:
# 1) 先写数据并落盘。
seg.append(payload, fsync=self.fsync_each)
seg.bytes_written += len(payload)
# 2) 数据落盘之后,才写记账并落盘 —— 保证
# 记账文件 mtime 严格晚于数据文件 mtime(契约 fsync_after_write)。
data_hash = _sha256_file(seg.path)
self._write_ack(seg, data_hash, len(payload))
except DeliveryError as exc:
self._last_rejected = True
self.last_error = str(exc)
self.errors.append(str(exc))
return False
self._last_rejected = False
return True
- 删掉
_reuse_ack_hash()与_expected_hash()—— 「复用已有记账」和「预先算出未来的哈希」都是错的: 记账必须每次交付都追加,内容必须是落盘之后的真实摘要。 - 模块级
_sha256_file()(此前已存在但从未被调用)改为真正被调用:摘要取自当前已落盘的整段文件字节。
2. 非空判据表 + 独立复核 + fail-closed + 退出码分层
# 判据表:字段名 → 期望值(None 表示只要求「存在」)。
# 这些字段全部来自**外部独立重算**,不是写入方自述。
BAD_FIELDS = (
("segments", None),
("landed", None),
("undelivered", None),
("ack_before_data", None),
)
collect_facts(cfg):自己扫SPOOL_OUT_DIR下的*.ndjson、自己os.stat取data_mtime / ack_mtime、自己json.loads解析记账行、自己sha256_file()重算摘要, 完全不读reports/report.json。判据落在可外部独立复核的事实上: 分段数 / 已落地 / 未落地 / 记账早于数据 / 记账损坏。- fail-closed:
collect_facts()抛异常(归档目录不存在等)= 拿不到事实 = 判不了 →EXIT_BAD。 - 退出码分层:
0健康;2事实有问题或拿不到事实(fail-closed);3契约不可用。
五、验证
探针从 BAD 翻成 OK(bash ops/repro.sh)
分段总数: 1
已落地(记账晚于数据落盘且 sha256 相符): 1 ['seg-000000.ndjson']
未落地: 0 []
RESULT: OK ← spool_probe.py rc=0
{"degraded": false, "issues": [], "segments": 1, "landed": 1,
"undelivered": 0, "ack_before_data": 0, "malformed": [],
"criterion": "fsync_after_write"}
health rc=0
核心证据翻正:
seg-000000.ndjson data mtime 1791446878714557327 ack mtime 1791446878717557285 ack>data True
记账行数 6 数据条数 6 最后记账 sha256 90f7c7d348fec53d 真实 sha256 90f7c7d348fec53d 相符 True
ack>data False → True、记账行数 1 → 6、sha256 相符 False → True。
验收闸门(bash ops/verify.sh)
PASS=5 FAIL=7 / RESULT: BAD → PASS=12 FAIL=0 / RESULT: OK
问题态红的正是 A1-A3、B1、C2-C3、D2。
负向验证(证明闸门真的有牙,不是恰好绿)
bash ops/negative.sh
== 负向 A:改回「先记账后写数据」(题眼) == [OK] 闸门转红
== 负向 B:记账 mtime 调到数据之前 == [OK] mtime 判据有判别力
== 负向 C:校验和改成 dead… == [OK] sha256 判据有判别力
== 负向 D:清空判据表 + 无条件 return 0 == [OK] 实证「闸门失效」
== 恢复后复验 == RESULT: OK
边界:退出码分层与 fail-closed
python3 -m app.health # 契约缺失 → {"degraded": true, "issues": ["契约不可用:..."]} rc=3
python3 -m app.health # 归档目录被删(拿不到事实)→ {"issues": ["拿不到事实:..."]} rc=2
python3 -m app.health # 归档被写坏 → degraded:true rc=2
六、经验与避坑
- 「记账」是先写还是后写,决定了「记账存在」能不能证明「数据在盘上」。
先把记账落盘再写数据,会让「幂等 / 补写」逻辑以为这一条已经落地、从而跳过重写,崩溃时数据就永远丢了。
正确顺序:
write(data) → fsync(data) → write(ack) → fsync(ack)。 - 先看事实文件,再看自述字段。 顺序是
outbox/*.ndjson真实字节 →*.ack.json的 mtime 与内容 → 最后才看reports/report.json。自述字段永远只是「写入方声称」。 mtime是最便宜的崩溃一致性证据。 「记账 mtime > 数据 mtime」⇔「记账确实发生在落盘之后」, 比任何自述字段都可信。- 「复用已有记账」是危险的省事。 它让记账行数与交付次数脱钩,从此「记账里有 N 行」 不再等于「交付了 N 次」。
- 摘要必须从真实字节重算,不能是「将来会变成的值」;否则幂等 / 补写会永久丢掉数据。
- 自述字段必须是算出来的。
ok: true/self_consistent: true若来自 「拿自己的delivered计数器比自己的records计数器」,则同源必相等、永远为真。 BAD_FIELDS = ()空判据表 +main()无条件return 0,比没有检查更危险 —— 它对任何异常都报degraded:false,静默地骗人。- 「判不了」≠「没问题」(fail-closed)。 拿不到事实(契约缺失 / 目录不存在 / 报告缺失)必须非 0。
- 改完
app/*.py必须rm -rf app/__pycache__,否则旧字节码会把「已改」掩盖成「没改」。 ops/negative.sh是按源码文本注入缺陷的(精确字符串匹配),且会临时覆写app/*.py; 跑完要diff app/spooler.py ops/expected-fixed/spooler.py复核,确认工作区没被留在缺陷态。
**更隐蔽的是它的 `else: pass`**:注入点找不到时它**静默跳过**,于是「注入失败」被伪装成
「实验结论为否」。我第一版跑负向验证时 A 组报 `[FAIL] 闸门没抓到`,实际是我的注释措辞与
`ops/expected-fixed/spooler.py` 不同、`fixed in s` 为 False、**缺陷根本没被注入**;
把注释对齐参考实现后立刻转红(探针 `rc=1`)。
→ **这类脚本里注释与代码结构也是契约的一部分**;看到负向验证「没抓到」先怀疑注入是否生效。
11. docker-compose.yml 里 dockerfile 的相对基准是 build.context,不是 compose 文件本身。
原始配置 context: ../.. + dockerfile: ../../.devcontainer/Dockerfile 会让
docker compose build 直接失败:
resolve : lstat /.devcontainer: no such file or directory
```
因为 `context` 已解析为 `/workspace`,再拼 `../../.devcontainer/Dockerfile` 得到
`/devcontainer/Dockerfile`。修法是 `dockerfile` 相对 context 写:
`dockerfile: .devcontainer/Dockerfile`。
12. **`docker-compose.yml` 与绝对路径耦合**:`build.context` 指向仓库根,`working_dir` 与契约里的
`SPOOL_OUT_DIR` / `SPOOL_LEDGER` 都是硬编码 `/workspace/scenario/2026-10-08-1600/...`。
换了挂载点就要靠 `SPOOL_CONTRACT_FILE` 环境变量把契约指对。非交互环境 `docker compose exec`
**必须加 `-T`**。
13. **手工做边界实验前先备份到 `/tmp`**,或用 `git status` 立刻复核 —— 我一次删契约后恢复路径写错,
靠 `git checkout -- conf/spoolcontract.env` 才复原(契约是考卷,不能有 diff)。
### 自查口诀
你的记账文件,是在数据落盘之前还是之后写的?记账里那一行的
sha256,是「落盘之后的真实摘要」还是「预先把本条算进去的哈希」?记账凭什么能证明数据在盘上?判据表是不是空的?退出码是不是恒 0?判不了时是放行还是拒绝?
同类影响面
- 一切 WAL / redo log 的
fsync顺序(fsync(data)必须在write(log "commit")之前)。 - 数据库
synchronous_commit与 group commit;etcd/raft的「先写日志后应用状态机」。 reflink/rsync/restic的「先写数据后写索引」。- S3 multipart 的
CompleteMultipartUpload与 ETag 校验;Kafkaacks=all与 ISR 位点。 - 一切「先记账再干活」的幂等 / 去重 / 断点续传逻辑。
- 一切
os.replace原子发布的临时文件与目标文件顺序。 - 一切「自述字段自证 + 空判据表 + 退出码恒 0」的假绿健康检查与巡检脚本。
