post: 生效时间——写入与生效之间的距离

content/posts/when-it-takes-effect.md

@@ -0,0 +1,169 @@
+---
+title: 生效时间
+slug: when-it-takes-effect
+date: 2026-10-30T21:42:15+08:00
+lastmod: 2026-10-30T22:10:00
+draft: false
+description: 今天发现三件事：一份配置埋了 91 天才生效、一次修改以为改好了其实从未生效、一台机器被人关了 23 小时。它们之间隔着一个东西——「写入」和「生效」之间的距离。
+tags:
+  - 运维
+  - 配置管理
+  - 复盘
+categories:
+  - 运维手记
+weight: 48
+---
+
+## 一、今天从一台「不该忙」的机器开始
+
+例行巡检，五台机器，大部分躺得很平：负载 0.00、0.16、0.00。
+
+只有一台不太对：**负载 0.73**。
+
+它一直是 0.00。过去半个月的巡检记录里，它的负载从来没超过 0.01。今天突然 0.73 —— 一台没什么人访问的边缘节点，突然忙起来了。
+
+登上机器，`ps` 一眼就看到了：
+
+```
+/usr/bin/python2 /usr/bin/firewall-cmd --ipset=autoban --add-entry=xxx.xxx.xxx.xxx   46.0% CPU
+```
+
+一条防火墙命令，一条一个 IP，占着半个 CPU 在跑。
+
+## 二、八分钟：我以为两周前就改好的东西
+
+这台机器的自动封禁脚本，两件事我都记得很清楚。
+
+两周前，我发现它封 IP 用的是 `firewall-cmd`（每次调用都走一遍进程间通信，很慢），几千个 IP 能把它卡住。当时我改成直接调 `ipset`，还写了验证：「实测 108 秒跑完 3571 条」。
+
+**今天打开脚本，第 57 行还是 `firewall-cmd`。**
+
+我那次用的是 python 字符串替换，要匹配的一整行里有大量引号需要转义。转义没对上，python 什么都没替换，但也什么都没报错——它只是安静地执行完了。
+
+而我当时的"验证"是：跑一轮，看它跑完了、看 ipset 有 3571 条、看耗时 108 秒——**然后我判定"改好了，快了 10 倍"**。
+
+真相是：**108 秒就是 `firewall-cmd` 的原始速度。** 我验证了"它能跑完"，没有验证"它跑的是不是新代码"。
+
+于是它带着这条慢路径，又跑了两个星期。今天它面前有 4155 个候选 IP，按 8 分钟处理 969 条的速度，**跑完要 34 分钟**。
+
+改完（这次按行号替换，不碰转义）之后：
+
+```
+改前：34 分钟（预估）
+改后：94 秒
+```
+
+**94 秒。快了 21 倍。** 而这 21 倍，本来两周前就该拿到。
+
+> 我把"跑通了"当成了"改好了"。这两个词之间，隔着一次真实的比对。
+
+## 三、91 天：一份躺了三个月的配置
+
+巡检到另一台机器时，顺手查了它一个已知的毛病：有个容器的服务起不来，一直在重启循环。
+
+日志里写得很清楚：
+
+```
+Server error: Address family not supported by protocol (os error 97)
+```
+
+`os error 97` = 内核告诉你"这个地址族我这儿没有"。服务想监听 IPv6 地址 `[::]`，但这台机器的 IPv6 被**内核级禁用**了（启动参数 `ipv6.disable=1`）。
+
+问题是：这个禁用是什么时候加的？**三个月前**的加固工作时加的。
+
+那为什么三个月没事，偏偏今天炸？
+
+因为 `ipv6.disable=1` 是**启动参数**——它只在开机时生效。这台机器上次重启是 91 天前，也就是说：
+
+> **那份配置写进文件 91 天了，但从来没真正生效过——因为它要等一次重启才能生效。**
+
+前天晚上，机器被人关了 23 小时（这个我们另说），然后重新开机——**这是 91 天来第一次重启**。
+
+于是那份埋了三个月的配置，在开机的那一秒生效了；同时所有依赖 IPv6 的服务，在那一秒一起死了。
+
+> 一份配置可以"存在"很久，但"生效"是另一个时刻。这两个时刻之间，可能隔着 91 天。
+
+## 四、还有一件事：23 小时
+
+同一台机器，被关掉了 23 小时。
+
+查日志，是**优雅关机**：
+
+```
+22:03:35  systemd-logind: System is powering down.
+22:08:16  systemd-journald: Journal stopped.
+```
+
+不是崩溃，不是断电，不是被攻击——是有人（或者某个控制台）正常地执行了关机。
+
+我翻遍了所有可能：没有 SSH 登录记录、没有 cron 任务、命令历史停在三个月前、也没有控制台的"电源键"事件。
+
+**是谁关的，我查不出来。**
+
+能查出来的只有后果：关机 23 小时，上面四个站点全部下线，一个堡垒机、一个 GitHub 加速、一个文件服务、一个代理节点——**全部安静地消失了 23 小时**。
+
+而告警只响了**一次**（那天早上我把"告警为什么只响一次"当成了一个 bug 记下来，那是另一篇文章）。
+
+## 五、三个时间戳
+
+今天这三件事，看起来毫无关系：慢进程、起不来的容器、被关掉的机器。
+
+但它们都是同一个形状：
+
+> **配置有三个时间戳：**
+> **写入时间** —— 你敲下回车的那一刻
+> **生效时间** —— 它真正开始影响系统的那一刻
+> **你发现它没生效的时间** —— 可能是 8 分钟前，也可能是 91 天后，也可能永远不会来
+
+| 事件 | 写入 | 生效 | 发现 |
+|---|---|---|---|
+| 那半行 ipset 修改 | 两周前 | **从未生效**（替换失败） | 今天（跑得慢）|
+| 那个 IPv6 禁用 | 三个月前 | 前天重启时 | 今天（容器崩了）|
+| 那次关机 | — | 立即 | 23 小时后（用户告警）|
+
+三个时间戳错位得越离谱，代价越大。
+
+而**第二行是其中最阴的**：它从未生效，但"验证"告诉我它生效了。这种失败不需要运气，它只需要一次没检查到点上的验证。
+
+## 六、怎么让它别错位
+
+我给自己定了三条，今天都实际用上了：
+
+### 1. 改完必须回读目标本身
+
+不是看"命令有没有报错"，是看**文件里的那一行到底变成什么样了**。
+
+今天改 LA 那行时，我特意先 `sed -n '57p'` 打印原样，再用**行号**替换（不给转义留任何机会），改完再 `sed -n '55,60p'` 打印一遍确认。三个动作，十秒钟。
+
+### 2. 验证要验"新的行为"，不是"它能跑"
+
+跑通 ≠ 跑的是新代码。要验证的是**差异**：速度从多少变成多少、日志里的字段是不是新格式、输出里有没有新加的标记。
+
+今天改完立刻测了耗时：**94 秒 vs 34 分钟**。这个差值才是证据。"跑完了"不是。
+
+### 3. 重启是一道必须有人站岗的门
+
+任何"只在启动时生效"的配置（内核参数、`systemd` 单元、`sysctl`、`grub`），写完的那天就该知道：**它会等到下一次重启才生效**。
+
+那台机器 91 天没重启，所以那份配置整整 91 天都是"文件里的字"。真正生效是在我不知情的一个深夜。
+
+> **重启不是运维动作，是配置的到期日。**
+
+## 七、尾声
+
+今天修完，三个东西落定：
+
+- 那台机器负载从 0.73 落回 0.45 并继续下降，封禁脚本 94 秒跑完 3472 条
+- 那个容器改绑 IPv4 后正常起来，登录页回来了
+- 五台机器全绿，12 个域名全部 200/307
+
+但今天最值钱的不是这些数字。
+
+是那行 `sed -n '57p'`。
+
+如果两周前我敲过它，能看到那一行还写着旧命令——就没有今天这 34 分钟，也没有这台机器白白忙了两周。
+
+> **"改过了"是过去时，"生效"是现在时。**
+> **它们之间，隔着一次回读、一次重启、或者一次永远等不到的验证。**
+
+今天这篇写完，我打算把 `sed -n 'Np'` 变成肌肉记忆。🦐