这是我今年排查时间最长的一个问题,前后大概花了四天,其中有两天完全走在错误的方向上。按时间顺序记一下,主要是给未来的自己看。
第一天:现象
运维在群里说,有个 Python 服务最近每隔一天半就要被 kill 一次。我拉了监控图看,进程 RSS 从启动时的 380MB 一路匀速爬升,大概 40 小时后到 3.2GB 撞上容器内存上限,被 OOM Killer 干掉,然后编排系统自动重启,曲线归零重来一遍,像心电图一样规整。
「匀速」这个词很重要。它意味着泄漏和请求量强相关,而且是每次请求都漏一点,不是某个偶发路径。当时我对着 QPS 曲线和内存曲线做了个粗略除法,大概是每个请求漏 300 字节左右。
第二天:走错的方向
我先入为主地认为是数据库连接没释放。因为一周前刚有人改过一段 ORM 代码,用了原生 SQL。我花了整整一天读那部分代码,加了连接数监控,甚至在测试环境跑了半天压测——连接数稳稳地维持在连接池上限,没有任何泄漏迹象。
现在回想,问题在于我从「最近改了什么」出发,而不是从「内存里到底存了什么」出发。前者是猜,后者是查。
第三天:上工具
换思路,直接看堆里有什么。我在服务里挂了一个只有内网能访问的调试端点,触发时执行:
import objgraph
objgraph.show_growth(limit=20)间隔十分钟采两次,对比增量。第一次输出里 dict 和 str 涨得最多,这没什么信息量——万物皆 dict。但第三次采样时我注意到一个自定义类 OrderContext,实例数从 12 万涨到了 19 万。这就有意思了,这个类是每个请求里创建的临时对象,正常情况下请求结束就该被回收。
接着用 objgraph.show_backrefs 画了一张引用链图,顺着往上找,最后指向一个模块级变量。
真凶
代码大概长这样(简化过):
_processed = set()
def handle(ctx):
if ctx.order_no in _processed:
return
_processed.add(ctx.order_no)
...一个模块级的 set,用来做订单号去重,防止重复处理。写这段代码的同事本意是好的,但这个集合从来没有任何清理逻辑。服务跑得越久,集合越大,永远不会释放。
更糟的是后面还有一行,把整个 ctx 对象也塞进了另一个 dict 里做「最近处理记录」,而 ctx 里持有请求体、响应体和一份用户信息快照。所以每个请求实际泄漏的不是一个字符串,而是好几 KB。这也解释了为什么 3.2GB 撑不到两天。
修复
去重这个需求本身是合理的,只是不该用一个无界的进程内集合来做。最终改成了 Redis 的 SETNX,带 24 小时过期。改动只有五行,上线后内存曲线立刻变成一条平线,稳定在 420MB 左右。
顺手做的两件事:一是给所有模块级的可变容器加了代码检查规则,评审时必须说明清理策略;二是把 RSS 持续上涨超过 6 小时 加成了告警项,而不是等 OOM 之后才知道。
事后想到的几点
- 内存泄漏在有 GC 的语言里,几乎总是「有人还引用着它」,而不是「内存没被释放」。所以问题永远是:谁在引用?
- 先看数据再看代码。我第二天读代码读得很投入,但那是在猜谜,不是在排查。
- 模块级的 set、dict、list,是 Python 服务里最常见的泄漏源,没有之一。lru_cache 装饰在实例方法上是第二名,它会把 self 一起缓存住。
- 调试端点这种东西,平时看着没用,出事时能救命。我现在新项目都会默认带一个。