朕喜技术(ZhenxiJS)
2026.10.08
1 分钟阅读

归档刷写「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                           # 逐条落盘

契约对「一次交付算不算落地」写得很清楚:

一次交付被判为「已落地」的唯一充分条件:

  1. 记账文件的 mtime 严格晚于 数据文件的 mtime
  2. 记账文件里的每一行都能被 json.loads 解析
  3. 记账文件里最后一条声明的 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

六、经验与避坑

  1. 「记账」是先写还是后写,决定了「记账存在」能不能证明「数据在盘上」。 先把记账落盘再写数据,会让「幂等 / 补写」逻辑以为这一条已经落地、从而跳过重写,崩溃时数据就永远丢了。 正确顺序:write(data) → fsync(data) → write(ack) → fsync(ack)。
  2. 先看事实文件,再看自述字段。 顺序是 outbox/*.ndjson 真实字节 → *.ack.json 的 mtime 与内容 → 最后才看 reports/report.json。自述字段永远只是「写入方声称」。
  3. mtime 是最便宜的崩溃一致性证据。 「记账 mtime > 数据 mtime」⇔「记账确实发生在落盘之后」, 比任何自述字段都可信。
  4. 「复用已有记账」是危险的省事。 它让记账行数与交付次数脱钩,从此「记账里有 N 行」 不再等于「交付了 N 次」。
  5. 摘要必须从真实字节重算,不能是「将来会变成的值」;否则幂等 / 补写会永久丢掉数据。
  6. 自述字段必须是算出来的。 ok: true / self_consistent: true 若来自 「拿自己的 delivered 计数器比自己的 records 计数器」,则同源必相等、永远为真。
  7. BAD_FIELDS = () 空判据表 + main() 无条件 return 0,比没有检查更危险 —— 它对任何异常都报 degraded:false,静默地骗人。
  8. 「判不了」≠「没问题」(fail-closed)。 拿不到事实(契约缺失 / 目录不存在 / 报告缺失)必须非 0。
  9. 改完 app/*.py 必须 rm -rf app/__pycache__,否则旧字节码会把「已改」掩盖成「没改」。
  10. 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 校验;Kafka acks=all 与 ISR 位点。
  • 一切「先记账再干活」的幂等 / 去重 / 断点续传逻辑。
  • 一切 os.replace 原子发布的临时文件与目标文件顺序。
  • 一切「自述字段自证 + 空判据表 + 退出码恒 0」的假绿健康检查与巡检脚本。

版权声明

本文为博主原创文章,遵循 CC BY-NC-SA 4.0 许可协议。 转载请注明出处:http://localhost/blogs/2026-10-08-1600-fsync-mtime-0

分享这篇文章