一个空格让服务器 CPU 爆了 3 天:排查用到 perf 和火焰图,结果真相让人沉默

4 阅读4分钟

就在上周,我们的生产服务器毫无征兆地开始发疯。

没有任何新版本上线,流量没涨,日志没报错,但所有机器的 CPU 使用率齐刷刷地飙到 90% 以上,持续了整整三天。告警像除夕的烟花一样噼里啪啦,运维群里从“是不是又有人在搞事”一路进化到“有没有考虑过换一份工作”的哲学讨论。

我作为当晚的值班开发,抱着“先重启再说”的信条,把服务滚了一遍。没用。CPU 依然像刚领到年终奖的打工人一样亢奋。这绝不是简单的内存泄漏或者死循环,这个 bug 有自己的脾气。

没办法,只能上重型武器:perf

我先用 perf top 看了一眼实时热点,排名第一的函数让我有点恍惚——__strcmp_avx2,一个字符串比较函数,吃掉了接近 60% 的 CPU。旁边还有一个 re2::DFA::Search,正则匹配引擎,占了 15%。

好家伙,难道是哪里在疯狂比较字符串?我们系统里最近加过的字符串处理,无非就是新来的那位同事写的一个 URL 路径过滤模块,用来屏蔽一些恶意请求。代码很精简,看着人畜无害,就是拿请求路径和一个配置好的黑名单做匹配。

我找到那段代码,用了 perf record -g 抓了 30 秒调用栈,用火焰图一看,整个上半身都烧在 match_blacklist 这个函数里。火焰图像一根通红的大烟囱,从 request_handler 一路笔直烧到正则匹配引擎内部。

问题明确了,现在需要知道它到底在匹配什么。我把日志级别调成 trace,重新上线,然后等着。日志输出的一瞬间,我差点把咖啡喷到屏幕上。原来那个用来做黑名单匹配的正则表达式,是这样的:

.*(evil|hack|inject).*

而这个表达式是被写在配置中心里的。那天下午,另一位同事为了让配置看起来更“整齐”,顺手在值的末尾敲了一个空格

没错,就是一个空格。配置变成了:

".*(evil|hack|inject).* "

就这一个空格,让这个正则不再匹配“以这些恶意词结尾”的路径,而变成了必须匹配“路径结尾还有一个空格”的请求。然而问题是,普通的 HTTP 请求路径里几乎永远不会带一个尾随空格。于是这个正则就陷入了一种绝望的死循环——每一行请求它都拼尽全力去匹配,然后因为那个不存在的空格而匹配失败,但正则引擎已经把自己累死在回溯里。

Re2 是 Google 的正则库,号称线性时间复杂度,不会出现灾难性回溯。但它依然要遍历整个字符串,并且 DFA 在构建状态时,由于空格的存在,导致状态机变得异常复杂,每次匹配都要耗尽状态表和 CPU 周期。简单来说,它没回溯,它只是把所有的力气都花在“拼命证明自己不匹配”这件事上。

真相让人沉默。一个空格,让二十台 32 核服务器烧了三天,额外电费花掉四位数的钱。而这个空格,在 UI 界面上完全不可见,在代码审查里也轻易地隐匿。直到火焰图上那个红到发黑的方块,才把这个沉默的凶手揪出来。

现在,这段代码被改成了 strings.TrimSpace 之后再编译正则,配置中心也加上了自动去除首尾空格的规则。但我每次路过那台机柜,都感觉还能听见 CPU 风扇在呜咽,呜咽里带着一句话:

“你们人类,能不能注意一下空格。”


后记 & 排查小贴士

如果你也遇到类似的无名 CPU 飙升,可以这样排查:

  1. 先用 tophtop 看是哪个进程,确认 CPU 亲和性,排除是系统进程或奇奇怪怪的挖矿脚本。
  2. perf top -p <PID> 实时看进程内热点函数。如果热点集中在某个用户态函数,八九不离十就是代码逻辑问题。
  3. perf record -g -p <PID> -- sleep 30 抓采样,然后用火焰图生成 SVG 看调用栈。火焰图红的地方就是你钱包流血的地方。
  4. 如果看到字符串比较、正则匹配、深拷贝等函数占大头,第一时间怀疑输入数据格式配置项,而不是算法本身。往往一个不可见字符就能把 CPU 送进 ICU。
  5. 任何外部配置,尤其是要编译成正则或表达式的字符串,请务必做好 trim 操作。别让空格成为压垮服务器的最后一根稻草。

那个空格至今还在同事的键盘上,没有人敢按下它。