引子
2026-07-29 周三下午 3 点，我正在写 security-monitor 的 Phase 44 收尾文档，部署机发来一段 80 行的 `update.sh` 输出日志。最后一行赫然写着：
[OK] security-monitor.service 已重启
但部署机的 `systemctl status` 显示主服务仍在崩溃循环——restart counter 已经累到 158，一直在反复 `start → fail → restart`。
更狠的是前面那句：
[OK] 冒烟测试通过 ✓
Traceback (most recent call last):
File "/opt/security-monitor/src/cli.py", line 17, in
from config import get_config, LOG_DIR, STATE_DIR, CACHE_DIR
File "/opt/security-monitor/src/config.py", line 8, in
import yaml
Traceback 之后紧跟"冒烟测试通过"。这 4 小时内，我在 4 个不同的位置修了 4 个互相串谋的"假成功"：Phase 42 截图脚本的 bash `[[: 0` 语法错误、Phase 43 隐式导入 `logging.handlers` 的 AttributeError、Phase 44 的 `update.sh` 渲染顺序倒置，以及最深的——`run()` 失败后无条件打 `[OK]`。
整个修复链里，最关键的不是任何一个具体 bug，而是意识到：update.sh 的「成功」从未真实存在。
问题：4 个「假成功」互相串谋
部署机跑 `sudo bash update.sh` 的输出，乍一看全是绿色对勾：
[OK] systemd unit 已渲染部署
[OK] systemd 数据库已重载
[OK] security-monitor.service 已重启
[OK] security-monitor-health.timer 已启用
[OK] security-monitor-monthly.timer 已启用
[OK] security-monitor-report.timer 已启用
[OK] security-monitor-rulegen.timer 已启用
[OK] security-monitor-weekly.timer 已启用
[OK] security-monitor-api.service 已重启
底部还贴心附上：
═════════════════════════════════════════════
✅ security-monitor 更新完成！
═════════════════════════════════════════════
但部署机的 `systemctl status security-monitor.service` 是这样：
● security-monitor.service - Security Monitor Service
Loaded: loaded (/etc/systemd/system/security-monitor.service; enabled)
Active: activating (auto-restart) (Result: exit-code) since ...
Invocation: 76ad6869c165414c97547d951c92d0c2
TriggeredBy: × security-monitor.timer
Process: 696073 ExecStart=/opt/security-monitor/venv/bin/python /opt/security-monitor/src/main.py --daemon (code=exited, status=1/FAILURE)
主服务已经连续失败 158 次，restart counter 没降过 0。
为了把"假成功"全部归位，我花了大约 4 小时，从最浅的 bash 错误一路挖到最深的部署顺序设计问题。每一个"假成功"看似独立，但它们实际组成了一个完整的失败叙事：
| 编号 | 阶段 | 假成功 | 真实失败 |
|---|---|---|---|
| 1 | Phase 42 截图 | `[[: 0` 语法错误淹没在输出 | `grep -c` 退出码 1 + `|| echo 0` 双 0 输出 |
| 2 | 主服务启动 | "冒烟测试通过 ✓" | `logging.handlers` AttributeError |
| 3 | `install_units.sh` 渲染 | `[OK] unit 已渲染部署` | 在 restart 之后才渲染（顺序倒置） |
| 4 | restart 失败 | `[OK] security-monitor.service 已重启` | `run()` 捕获失败，但调用方无条件 success |
下面我按排查顺序把每一层都讲清楚。
调查：从 4 个失败里反推
第一层：bash 截图脚本的双 0 语法错误
症状：部署日志里有：
update.sh: line 178: [[: 0
0: syntax error in expression (error token is "0")
这是 Phase 42 的"部署机项目快照"脚本，原本想统计 systemd unit 文件里还残留多少个 `${SECURITY_MONITOR_XXX}` 占位符。代码长这样：
residue=$(grep -c '\${SECURITY_MONITOR_' "$fp" 2>/dev/null || echo 0)
if [[ "$residue" -gt 0 ]]; then
echo " ⚠ $unit: 含 \${SECURITY_MONITOR_XXX} 残留 ($residue 处)"
else
echo " ✓ $unit: 已渲染 (无 \${VAR})"
fi
问题在 `grep -c` 的退出码语义：
- 找到匹配 → 打印计数 + exit 0
- 找不到匹配 → 打印 `0` + exit 1
我把 `|| echo 0` 接上去，结果反而两个 `0` 都被赋给 residue：
$ grep -c 'foo' /nonexistent 2>/dev/null || echo 0
0 ← grep 自己的 0
0 ← || echo 0 的 0
$ echo $?
0 ← 命令链最终是 0（echo 成功）
`$residue` 变成 `"0\n0"`（两行）。`[[ "$residue" -gt 0 ]]` 看到第一行 `0` 后还在等第二行，bash 把它当成两个表达式，硬塞进算术，触发 `[[: 0\n0: syntax error`。
修法（一句，但不能简化）：
residue=$(grep -c '\${SECURITY_MONITOR_' "$fp" 2>/dev/null || true)
residue=${residue:-0}
`|| true` 让 `grep` 的失败不再触发 fallback（因为 `grep -c` 已经把 `0` 印出来了），然后用 `${residue:-0}` 兜空。单值 `0`，算术对比就稳了。
但这只是最浅的一层。
第二层：logging.handlers 的隐式 AttributeError
部署机里真正让主服务崩溃的是这条 traceback：
File "/opt/security-monitor/src/main.py", line 118, in setup_logging
logging.handlers.WatchedFileHandler(log_file),
^^^^^^^^^^^^^^^^
AttributeError: module 'logging' has no attribute 'handlers'. Did you mean: 'Handler'?
`src/main.py` 第 12 行只有：
import logging
没有 `import logging.handlers`。开发环境能跑是因为 pytest 在 import `main` 之前碰巧已经 import 过 `logging.handlers`（来自别的测试模块）—— 子模块就被"挂"在 `sys.modules['logging']` 下面。但生产环境是冷启动，第一个 import 的就是 `main`，`logging.handlers` 子模块从未被加载过。
为什么我之前一直没踩到？回看 `test_watched_file_handler.py`：
import logging
import logging.handlers # ← 测试文件里写过
测试套件一定先跑过这个文件，`logging.handlers` 已经热了。测试环境和生产环境的"冷启动顺序差"完美地掩盖了 import 漏洞。
修法（一句话，但需要预防回归）：
import logging
import logging.handlers # ← Phase 43 加的这一行
为了避免"测试全过但生产还炸"再发生，我加了一条生产冷启动回归测试——AST 检查 `main.py` 的 import 列表必须含 `logging.handlers`，否则 fail。这条测试在开发环境（测试套件本身已经隐式 import 了 logging.handlers）下也会先 fail（因为 import 缺失），逼出修复。
# tests/test_phase43_logging_handlers_import.py
import ast
def test_main_explicitly_imports_logging_handlers():
tree = ast.parse(MAIN.read_text())
imported = {
alias.name
for node in ast.walk(tree)
if isinstance(node, ast.Import)
for alias in node.names
}
assert "logging.handlers" in imported
第三层：update.sh 渲染顺序倒置
修完 logging.handlers 后，主服务能起来了，但 `update.sh` 的部署链路仍然不对。
之前 `update.sh` 的部署流程是：
run systemctl restart security-monitor.service ← 在这里 restart
success "systemd unit 已渲染部署" ← 然后才渲染
success "systemd 数据库已重载"
success "security-monitor.service 已重启"
`install_units.sh` 的"强制渲染"是在 restart 之后才跑的。结果：先用旧 unit 文件尝试启动主服务，失败了，才去渲染新 unit 文件，但渲染后没再 restart 一次。
部署机看到的现象就是：unit 文件确实被更新了，但主服务仍在用旧的（坏的）unit 路径跑。
正确顺序（Phase 44 改的）：
step "Phase 38/39 — install_units.sh 渲染并部署 systemd unit..."
if env SECURITY_MONITOR_HOME=... bash install_units.sh --no-backup; then
success "systemd unit 已渲染部署"
else
warn "install_units.sh 部署失败，停止服务重启"
exit 1 ← 渲染失败不继续
fi
run systemctl daemon-reload ← 渲染后才重载
if run systemctl restart security-monitor.service; then
success "security-monitor.service 已重启"
else
error "security-monitor.service 重启失败" ← 真实失败状态
fi
注意 `if run systemctl restart ...; then success; else error; fi` —— 这就是第四层的修法。
第四层：`run()` 失败后无条件 success
这是最深的 bug。`update.sh` 里有一个 `run()` 包装函数，Phase 40 加的：
run() {
"$@"
return 0 # 不让 set -e 提前退出
}
这个函数解决了"非关键命令失败让整个脚本退出"的问题，但调用方还在无条件 success：
run systemctl restart security-monitor.service
success "security-monitor.service 已重启" ← 永远打这个
日志里就出现：
Job for security-monitor.service failed because the control process exited with error code.
See "systemctl status security-monitor.service" ...
[WARN] command failed (set +e): systemctl restart security-monitor.service
[OK] security-monitor.service 已重启 ← 但 success 仍然打了
修法就是用 `if run ...; then`：
if run systemctl restart security-monitor.service; then
success "security-monitor.service 已重启"
else
error "security-monitor.service 重启失败"
fi
为了让"假成功"在脚本最后被彻底排除，再加一道最终门控：
if systemctl is-active security-monitor.service &>/dev/null; then
success "security-monitor.service 最终状态 active"
else
error "security-monitor.service 最终状态非 active"
fi
不管前面怎么报，最后真实 active 才算成功。
解决：5 项硬要求 + 4 阶段顺序
把 4 层修法 + 顺序重组写成 5 项硬要求，作为 `update.sh` 部署的不可破坏契约：
1. install_units.sh 渲染 → daemon-reload → restart → 最终 is-active
2. 渲染失败立即退出，不进 restart
3. restart 失败必须报 error，不能 success
4. 冒烟测试用项目 venv 的 python（不依赖系统 python3）
5. 冒烟测试的真实 exit code 保留（不能 || true 抹掉）
实际改完后，部署机再次跑 `update.sh` 的输出长这样：
[OK] systemd unit 已渲染部署
[OK] systemd 数据库已重载
[OK] security-monitor.service 已重启 ← 真的重启
[OK] security-monitor-api.service 已重启
[OK] security-monitor.service 最终状态 active
[OK] security-monitor-api.service 最终状态 active
加上 `journalctl -u security-monitor.service -n 10` 验证：
Active: active (running) since Wed 2026-07-29 17:16:13 HKT
Main PID: 697532 (python)
Tasks: 3
Memory: 82.1M
主进程 `697532` 稳定存在，restart counter 终于清零。
验证：13 个专项 + 553 个全量 + 真实部署
为了不让自己再被"假成功"骗一次，我写了 5 个专项回归测试（`tests/test_phase44_update_reliability.py`）：
def test_residue_count_does_not_emit_two_zero_lines():
"""grep -c || echo 0 双 0 语法错误不再出现"""
assert "grep -c '${SECURITY_MONITOR_' \"$fp\" 2>/dev/null || echo 0" not in text
def test_render_happens_before_main_service_restart():
"""unit 渲染必须在 restart 主服务之前"""
render = text.find('step "Phase 38/39 — install_units.sh')
restart = text.find('run systemctl restart security-monitor.service')
assert render < restart, "渲染必须在 restart 之前"
def test_restart_success_is_conditional():
"""restart 失败时不能无条件报 success"""
restart = text.find('run systemctl restart security-monitor.service')
success = text.find('success "security-monitor.service 已重启"', restart)
between = text[max(0, restart - 20):success]
assert "if run " in between
def test_installer_does_not_recommend_nonexistent_report_service():
"""手动启用指引里不能有 security-monitor-report.service（不存在）"""
assert 'security-monitor-report \\' not in text
assert "security-monitor-report.timer" in text
def test_final_verification_checks_main_and_api_services():
"""脚本末尾必须有 is-active 门控"""
assert "systemctl is-active security-monitor.service" in text
assert "systemctl is-active security-monitor-api.service" in text
跑完专项 + 全量：
Phase 41/42/44 专项测试: 13 passed
pytest tests/ 全量: 553 passed, 0 failed
部署机再跑一次：
git pull
sudo bash update.sh
同步完成: 安装 11 个, 跳过 0 个
Phase 33/34 验证: 5 PASS, 0 FAIL
✅ security-monitor 更新完成！
systemctl is-active security-monitor.service → active
systemctl is-active security-monitor-api.service → active
这次是真的。
反思：3 个反直觉的洞察
第一，"假成功"最危险的不是单个 bug，而是 bug 之间的"互证"。每个 `[OK]` 单独看都很合理（"我运行了命令，命令没让脚本退出，所以成功"），但当它们堆在一起时，构成了一个"我以为已经搞定"的叙事。这次 4 个假成功依次是：bash 错误被 `[OK]` 覆盖 → 冒烟测试报成功但 traceback 在跑 → 渲染顺序倒置但渲染仍然打印成功 → restart 失败但 success 仍然打。如果只看 `[OK]`，根本看不出问题。唯一可靠的不是"成功日志"，而是"最终状态查询"`（`systemctl is-active`），这次加的就是这个。
第二，测试环境和生产环境的"冷启动顺序差"会掩盖 import 漏洞。开发里 `import logging` 不写 `logging.handlers` 也能跑——因为 `pytest` 跑过别的模块已经热过 `sys.modules['logging']`。生产是冷启动，import 顺序完全不受测试套件影响。凡是使用 `parent.child` 模块路径的代码，必须显式 import 父 + 子（或者 `from parent.child import X`，这会自动加载）。这条经验适用于 Python、Node（`require('foo/bar')` 不会自动 require `foo`）、Go（即使是同一个 package，import 路径要写清楚）—— 任何有"模块树"概念的语言。
第三，"防御性忽略" 是技术债的最大藏身处。`run()` 函数的设计初衷是"不让 set -e 让脚本提前退出"——这本身没问题。但它把"失败"和"非关键"混在了一起：调用方写 `run cmd; success msg` 时，默认 cmd 一定成功，因为 `run` 把失败吞了。真正可读的做法是 `run cmd || warn` 或 `if run cmd; then success; else error; fi`——失败语义必须在调用现场显式表达，不能让 `run` 替你"想"。
整个过程耗时：4 小时、5 个 commit（`7ec4635`、`37d429c`、`c25282a`、`378fb7e`、`00d8ef8`）、553 + 5 = 558 个测试、4 处独立 bug 修复。从"看起来跑完了"到"真跑完了"，中间差了大约 160 行的 update.sh 改造、4 行 main.py import 修复、和 5 个我以前没想过的测试。
以后再写任何带 `run` 包装的脚本，调用方必须显式处理成功/失败两个分支。 这条规矩会写进 `bash-script-authoring-pitfalls` skill 的下一版。
本文为虚构故事，代码与事故经过基于实际部署日志改写。
评论区