一行正则跑满 CPU:灾难性回溯复盘

·约 1700 字 · 故障复盘正则Python

10 月 29 日下午两点四十,日志清洗服务的四个 Pod 在两分钟内先后被 CPU 限流打到不可用。上游积压,告警一路串到值班群。这篇是那次故障的复盘。

现象

特征很怪:

  • CPU 100%,但内存平稳,GC 正常。
  • QPS 没有上涨,反而因为处理不过来在下降。
  • 重启后恢复几分钟,然后再次打满。
  • 四个 Pod 不是同时挂的,间隔几十秒。

「重启后恢复一段时间又复发」通常指向两类原因:资源泄漏,或者某类特定输入触发了慢路径。内存平稳排除了前者,所以重点转向后者。

定位

第一步是确认 CPU 花在哪个线程上:

top -H -p $(pgrep -f cleaner.py)

结果是单个工作线程吃满一个核。接着用 py-spy 直接对运行中的进程采样,不需要改代码、不需要重启:

py-spy dump --pid 1 --locals
py-spy record --pid 1 --duration 30 --output flame.svg

dump 的输出把问题指得清清楚楚:

Thread 0x7F2A (active)
    _compile_and_match (re/__init__.py:190)
    extract_ua (cleaner/parsers.py:88)
    Locals:
        pattern: '^(\\w+[\\s/]*)+\\(([^)]*)\\)$'
        line: 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 KHTML like Gecko ...'

栈几乎不动,一直停在同一个 re.match 上。这就是灾难性回溯。

py-spy 需要 SYS_PTRACE 能力才能读取目标进程内存。在 Kubernetes 里可以用 kubectl debug 起一个带该能力的临时容器,共享目标 Pod 的进程命名空间,不必给业务容器长期开这个权限。

为什么会指数级

罪魁是 (\w+[\s/]*)+ 这种嵌套量词:一个可重复的组,里面还有可重复、且能匹配空串的部分。

Python 的 re(以及 Java、JavaScript、PCRE)用的是回溯式引擎。匹配失败时,它会退回上一个分支点换一种切分方式再试。对于 (\w+)+ 这样的结构,字符串 aaaa 可以被切成 a|a|a|aaa|a|aaa|aaaaa|aaaaa……n 个字符有 2n-1 种切分方式。只要整体最终匹配失败,引擎就会把这些方式全部试一遍

在这次故障里,末尾的 \(([^)]*)\)$ 要求以右括号结尾。绝大多数 UA 字符串括号在中间,结尾是版本号,于是必然失败——每一条这样的日志都会触发一次完整的指数级搜索。

写个脚本量化一下:

import re, time

pattern = re.compile(r'^(\w+[\s/]*)+\(([^)]*)\)$')

for n in range(18, 30):
    s = 'a' * n + '!'          # 末尾字符保证匹配失败
    t0 = time.perf_counter()
    pattern.match(s)
    print(f'{n:3d} 字符  {time.perf_counter() - t0:.3f}s')
 18 字符  0.011s
 20 字符  0.043s
 22 字符  0.172s
 24 字符  0.688s
 26 字符  2.751s
 28 字符  11.004s

每多两个字符,耗时翻两番。一条 120 字符的 UA 意味着这个进程再也不会返回了。

那为什么之前一直没事?因为这个正则跑了一年多,一直只处理内部埋点上报的 UA,格式固定。故障当天上游接了一个新数据源,UA 来自真实浏览器,长度和结构都不一样。代码没变,输入变了。

三种修法

一、重写正则,消除歧义

最彻底的办法。原意是「若干个由空白或斜杠分隔的词,后面跟一个括号内容」,可以写成没有歧义的形式:

# 有歧义:\w+ 和 [\s/]* 的边界可以有多种划分
r'^(\w+[\s/]*)+\(([^)]*)\)$'

# 无歧义:分隔符必须至少出现一次,且两部分字符集不重叠
r'^\w+(?:[\s/]+\w+)*\s*\(([^)]*)\)$'

关键在于让每个字符只可能属于一个部分。\w[\s/] 本来就不重叠,问题出在 * 允许分隔符为空,导致「一个词」和「两个词中间零个分隔符」无法区分。改成 + 就断掉了这条歧义。

二、换一个不回溯的引擎

Python 的 regex 第三方库支持原子组和占有量词,匹配失败后不再回退:

import regex
pattern = regex.compile(r'^(?>\w+[\s/]*)+\(([^)]*)\)$')

Go 和 Rust 的标准正则库用 RE2 类算法,时间复杂度对输入长度线性,天然免疫这类问题——代价是不支持反向引用和前后瞻。如果服务是纯文本处理且不需要这些特性,选型时就该优先考虑。

三、加护栏

前两条修的是这一处,护栏防的是下一处。我们加了两层:

MAX_UA_LEN = 512

def extract_ua(line: str):
    if len(line) > MAX_UA_LEN:
        return None                      # 超长直接放弃,记一次指标
    return pattern.match(line)

以及在进程级别加了超时。Python 的 re 不支持匹配超时,只能靠信号(仅主线程可用)或者把解析放进独立进程池并设 timeout:

from concurrent.futures import ProcessPoolExecutor, TimeoutError

with ProcessPoolExecutor(max_workers=4) as pool:
    fut = pool.submit(extract_ua, line)
    try:
        result = fut.result(timeout=0.2)
    except TimeoutError:
        slow_regex_counter.inc()
        result = None

进程池的额外好处是失控的匹配可以被真正杀掉;线程池做不到,因为 re 在匹配期间不释放 GIL,也不响应中断。

怎么在上线前发现

事后我们在 CI 里加了两道检查。

一是静态扫描。Semgrep 有现成规则,也可以用 dlint;对于 JavaScript 项目,ESLint 的 no-unsafe-regex 或者 eslint-plugin-redos 更成熟。

二是对项目里所有正则做一次模糊测试,用递增长度的构造串测耗时:

import re, time, pytest
from cleaner import parsers

FUZZ_CHARS = ['a', 'a ', 'a/', '(', 'aa\t']

@pytest.mark.parametrize('name,pat', parsers.ALL_PATTERNS.items())
def test_no_catastrophic_backtracking(name, pat):
    for ch in FUZZ_CHARS:
        s = ch * 40 + '!'
        t0 = time.perf_counter()
        re.compile(pat).match(s)
        elapsed = time.perf_counter() - t0
        assert elapsed < 0.05, f'{name} 在 {ch!r}*40 上耗时 {elapsed:.3f}s'

这个测试跑得很快,而且当场就抓出了另外两个有同样问题的正则——都在少用的分支里,暂时没被触发而已。

几条结论

  1. 看到 (X+)+(X*)*(X|Y)+ 且 X 与 Y 有交集,就要警惕。
  2. 回溯只在匹配失败时爆炸。测试用例里必须包含不匹配的输入,只测正例发现不了问题。
  3. 「代码没改过所以不可能是它」是这次排查里最大的思维阻碍。输入分布的变化和代码变更一样是变更。
  4. 处理外部输入的正则一律要有长度上限,这是成本最低的一道防线。

← 返回首页