最近公司的 Python 后端服务内存占用偏高,所以花了一些时间分析后端的内存占用。也梳理了一些比较好用的工具和分析方法。

在我们的场景下,我们发现内存占用异常是在服务运行了一段时间以后,所以下面的工具链更偏向于分析应用运行时的内存占用长期持续增长趋势

# tracemalloc

提到 Python 内存分析,一定会有 tracemalloc,毕竟是内置的内存追踪工具。

但是实际体验下来比较一般,它只能追踪到 pymalloc 分配的 Python 对象,对于 C 扩展(比如 numpy、PIL)这种库申请的内存是无法追踪的。结果就是进程内存已经占用几个 GB 了,但是 tracemalloc 只追踪到了 50 MB 的内存分配。

下面是 tracemalloc 的一个 demo。

import tracemalloc

# 开始追踪内存分配
tracemalloc.start()

def create_list():
    # 创建一个大的列表
    return [i for i in range(1000000)]

def create_dict():
    # 创建一个大的字典
    return {i: str(i) for i in range(100000)}

# 调用函数,分配内存
large_list = create_list()
large_dict = create_dict()

# 获取当前内存快照
snapshot = tracemalloc.take_snapshot()

# 分析内存分配
top_stats = snapshot.statistics('lineno')

print("[Top 10 Memory Usage]")
for stat in top_stats[:10]:
    print(stat)

# 停止追踪内存分配
tracemalloc.stop()

对于 Django 后端项目,可以把这段代码放到中间件里。

from django.conf import settings

class MemoryUsageMiddleware:
    def __init__(self, get_response):
        self.get_response = get_response

    def __call__(self, request):
        if settings.DEBUG:  # 仅在 DEBUG 模式下启用
            tracemalloc.start()

        response = self.get_response(request)

        if settings.DEBUG:
            snapshot = tracemalloc.take_snapshot()
            tracemalloc.stop()

            top_stats = snapshot.statistics('lineno')
            for stat in top_stats[:10]:
                print(stat)  # 或记录到日志中

        return response

总的来说,tracemalloc 可以试试,但是效果不一定好,而且会有一定性能影响,不太好放在时延敏感的后端项目的生产环境上跑,tracemalloc 的统计数据也会占用运行内存。

# psutil

psutil 获取进程的信息,它拿到的数据和系统的 top 命令是一样的,不会存在 tracemalloc 这种统计偏小的问题。

在我们的项目中,对后端和 Celery Worker(一个任务执行服务)分别做了内存分析,两者的使用方法有一点差异。

# psutil 统计后端内存使用

也是推荐把代码放到中间件里,在请求开始前后分别获取内存占用,做个减法。

import psutil
import logging

logger = logging.getLogger(__name__)

class MemoryUsageMiddleware:
    def __init__(self, get_response):
        self.get_response = get_response

    def __call__(self, request):
        # 获取当前进程的内存信息(请求开始前)
        process = psutil.Process()
        memory_before = process.memory_info().rss  # 常驻内存(单位:字节)

        # 处理请求
        response = self.get_response(request)

        # 获取当前进程的内存信息(请求结束后)
        memory_after = process.memory_info().rss  # 常驻内存(单位:字节)

        # 计算内存使用差值
        memory_diff = memory_after - memory_before

        # 将内存使用信息记录到日志中
        logger.info(f"[Memory Usage] Before: {memory_before / 1024 / 1024:.2f} MB, "
                    f"After: {memory_after / 1024 / 1024:.2f} MB, "
                    f"Diff: {memory_diff / 1024 / 1024:.2f} MB")
        return response

正常情况下请求前后的内存值是不会有变化的,如果某个请求以后内存值总是有增加,就说明这个请求可能有内存泄漏。

需要注意的是:

  1. 由于后端一个进程会同时处理多个请求,所以出现内存上升也需要注意是否可能是其他请求引起的。
  2. 内存增加有可能是没有及时 GC 导致的。由于 GC 需要拿到 GIL,不建议在后端中间件里直接 GC,所以出现内存增长也不能断定一定有内存泄漏,需要结合代码逻辑综合判断。

实际业务场景下,发现有两个 healthz 请求之间内存上升了 200M(第一个 healthz 请求前后内存 400M,第二个 healthz 请求前后内存 600M,中间没有任何别的请求),后来发现是因为在初始化翻译模型导致的。

# psutil 统计 Celery Worker 内存使用

Celery Worker 中使用 psutil 的方法也一样,在任务执行前后获取内存占用,做个减法。需要基于 celery 提供的 signals 来在任务开始前和结束后插入代码。

import gc
import psutil
import logging
from celery import signals

logger = logging.getLogger(__name__)

@signals.task_prerun.connect
def record_memory_before_task(sender=None, task_id=None, task=None, args=None, kwargs=None, **extras):
    """
    在任务开始前记录内存使用,并存储到 sender 的属性中。
    """
    process = psutil.Process()
    memory_before = process.memory_info().rss  # 获取当前进程的常驻内存(字节)
    
    # 将内存使用记录到 sender 的属性中
    sender.memory_before = memory_before
    
    logger.info(f"[Task {sender.name}] Memory before: {memory_before / 1024 / 1024:.2f} MB")


@signals.task_postrun.connect
def record_memory_after_task(sender=None, task_id=None, task=None, args=None, kwargs=None, retval=None, state=None, **extras):
    """
    在任务结束后记录内存使用,并计算差值。
    """
    gc.collect()  # 强制进行垃圾回收,清理内存
    process = psutil.Process()
    memory_after = process.memory_info().rss  # 获取当前进程的常驻内存(字节)

    # 从 sender 的属性中读取任务开始前的内存使用
    memory_before = getattr(sender, 'memory_before', None)

    if memory_before is not None:
        memory_diff = memory_after - memory_before
        logger.info(f"[Task {sender.name}] Memory after: {memory_after / 1024 / 1024:.2f} MB, "
                    f"Diff: {memory_diff / 1024 / 1024:.2f} MB")
    else:
        logger.warning(f"[Task {sender.name}] Memory usage before task not found.")

Celery Worker 内存监控时需要注意几个点:

  1. Celery Worker 可以使用 prefork 模式执行(celery worker --pool=processes),虽然这会带来一定内存上升(每个 worker process 都需要加载库、拥有一份全局变量),但是 prefork 模式下每个 worker process 是串行执行的,所以任务的内存使用量是隔离的,统计值不会受到其它任务的影响。
  2. Celery Worker 场景下时延不敏感,所以在任务执行前后直接 GC 是可以的,这样统计的内存波动更准确。
  3. Celery Worker 的默认并发数为 CPU 数,在 Docker 和 K8s 环境中,系统获取的 CPU 是宿主机的 CPU 数量,而非 requests 或 limit,prefork 模式下使用默认值数会创建过多的进程,导致。所以强烈建立显式执行并发数(--concurrency=4)。

实际业务场景中,确实有任务在处理以后多占用了 1.5G 的空间,后来分析发现是因为处理大量数据的时候没有做分批处理,改为分批处理以后内存量就下降了。

# objgraph

参考:填坑总结:python内存泄漏排查小技巧 - 知乎 (opens new window)。这部分有现成的博客可以参考,就不多赘述了。

objgraph 和 tracemalloc 类似,都是 Python 内置的内存分析工具,分析 pymalloc 分配的内存。objgraph 的好处是自带增量分析,可以分析对象之间的引用关系。

import objgraph

objgraph.show_growth(limit=30)

运行一段时间后,发现某个不常见对象的数量一直在少量增长,怀疑是这个对象造成的。

将这些对象的引用关系输出到 dot 文件里,然后使用 graphviz 可视化。

gth = objgraph.growth(limit=20)
for gt in gth:
    logger.info("growth type:%s, count:%s, growth:%s" % (gt[0], gt[1], gt[2]))
    if gt[2] > 100 or gt[1] > 300:
        continue
    objgraph.show_backrefs(objgraph.by_type(gt[0])[0], max_depth=10, too_many=5,
                           filename="./dots/%s_backrefs.dot" % gt[0])
    objgraph.show_refs(objgraph.by_type(gt[0])[0], max_depth=10, too_many=5,
                       filename="./dots/%s_refs.dot" % gt[0])
    objgraph.show_chain(
        objgraph.find_backref_chain(objgraph.by_type(gt[0])[0], objgraph.is_proper_module),
        filename="./dots/%s_chain.dot" % gt[0]
    )
dot -Tpng xxx_chain.dot -o xxx_chain.png

就可以定位到这个对象的引用关系了。

# WSS 偏高

WSS 也是一个很有趣的话题,之前用 K8s 的时候有注意过这个概念,但并没有太理解。最近遇到了 WSS 异常高的问题,深入了解后才明白了 WSS 和 RSS 的区别。

  • RSS (Resident set size): RSS 是主内存中不对应于磁盘上任何内容的物理内存。RSS 包括栈、堆和匿名内存映射。
  • WSS (Working set size): WSS 是一个进程在一段时间内工作所需的内存。

初看这两个概念非常抽象。但是下面会引入两个新的概念和一个公式,两者就好理解多了。

  • RSS 这个值可以理解成程序申请了并且在使用的内存,不能被外界清理,等于 top 里的 RES,也等于 Python psutil 里的 RSS。
  • 除了程序申请的内存,程序还会读取文件,系统会将文件缓存到操作系统中。其中,频繁读取的(读取了两次及以上的)文件会放到 active_file;读取了一次,或者一段时间没有再使用的文件会放到 inactive_file。这个设计思想是合理的,就和 Python、JS 的多级 GC 一样,先把不常用的文件降级,GC 的时候优先清理不常用的文件。
  • WSS = RSS + active_file。也就是说 WSS 会把 active_file 也算上,但不计算 inactive_file

所以,如果 RSS 正常,WSS 偏高,可以判断是 active_file 占用过高。

在 Pod 里可以查询 cgroup 下 rssactive_file 的大小。

$ cat /sys/fs/cgroup/memory/memory.stat

cache 6980935680
rss 3365285888
rss_huge 0
mapped_file 36864
swap 0
pgpgin 37141945
pgpgout 34616012
pgfault 38453850
pgmajfault 4
inactive_anon 45056
active_anon 3365224448
inactive_file 4316774400
active_file 2664116224
unevictable 0
hierarchical_memory_limit 17179869184
hierarchical_memsw_limit 17179869184
total_cache 6980935680
total_rss 3365285888
total_rss_huge 0
total_mapped_file 36864
total_swap 0
total_pgpgin 0
total_pgpgout 0
total_pgfault 0
total_pgmajfault 0
total_inactive_anon 45056
total_active_anon 3365224448
total_inactive_file 4316774400
total_active_file 2664116224
total_unevictable 0

这里的 rss 大小为 3.1G,active_file 大小为 2.5G,WSS = 3.1G + 2.5G = 5.6G。可以使用 K8s 的 kubectl top pod 命令查看 WSS 和 RSS 的大小进行验证。


那么下一个问题是,定位到 active_file 偏高后,如何定位到加载了什么文件呢?

系统并没有提供枚举内存中 active_file 对应了哪些文件。

有一个工具 vmtouch 命令可以传入文件列表,查询这里面有多少被加载进了内存,但需要我们提前知道哪些文件可能被加入到内存中。

可以先使用 lsof 命令来查看当前进程打开的文件列表(部分输出已省略)。

$ lsof -p 181
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
uvicorn 181 root cwd DIR 0,496 4096 2108472 /src
uvicorn 181 root rtd DIR 0,496 4096 2108464 /
uvicorn 181 root txt REG 0,496 18400 21366419 /usr/local/bin/python3.8
uvicorn 181 root mem REG 253,16 21366419 /usr/local/bin/python3.8 (path dev=0,496)
uvicorn 181 root mem REG 253,16 24644260 /usr/local/lib/python3.8/site-packages/rpds/rpds.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24643051 /usr/local/lib/python3.8/site-packages/ray/thirdparty_files/setproctitle.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24515449 /usr/local/lib/python3.8/site-packages/ray/_raylet.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24381158 /usr/local/lib/python3.8/site-packages/gevent/_gevent_c_imap.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
...
uvicorn 181 root mem REG 253,16 24381203 /usr/local/lib/python3.8/site-packages/gevent/libev/corecext.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24118626 /usr/local/lib/python3.8/site-packages/Crypto/Cipher/_raw_aesni.abi3.so (path dev=0,496)
...
uvicorn 181 root mem REG 253,16 24118635 /usr/local/lib/python3.8/site-packages/Crypto/Cipher/_raw_ecb.abi3.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 21367099 /usr/local/lib/python3.8/lib-dynload/_elementtree.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1864875 /usr/local/lib/python3.8/site-packages/google/_upb/_message.abi3.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24381068 /usr/local/lib/python3.8/site-packages/frozenlist/_frozenlist.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24120243 /usr/local/lib/python3.8/site-packages/aiohttp/_websocket.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24120239 /usr/local/lib/python3.8/site-packages/aiohttp/_http_parser.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24120241 /usr/local/lib/python3.8/site-packages/aiohttp/_http_writer.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24120236 /usr/local/lib/python3.8/site-packages/aiohttp/_helpers.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24646390 /usr/local/lib/python3.8/site-packages/yarl/_quoting_c.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24383932 /usr/local/lib/python3.8/site-packages/multidict/_multidict.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1870845 /usr/local/lib/python3.8/site-packages/regex/_regex.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 21367140 /usr/local/lib/python3.8/lib-dynload/mmap.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1869864 /usr/local/lib/python3.8/site-packages/psutil/_psutil_posix.abi3.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 20709986 /lib/x86_64-linux-gnu/libnss_dns-2.31.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 20709988 /lib/x86_64-linux-gnu/libnss_files-2.31.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 21106628 /usr/lib/x86_64-linux-gnu/libmariadb.so.3 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1869863 /usr/local/lib/python3.8/site-packages/psutil/_psutil_linux.abi3.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1854269 /usr/local/lib/python3.8/site-packages/MySQLdb/_mysql.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1871693 /usr/local/lib/python3.8/site-packages/safetensors/_safetensors_rust.abi3.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1879741 /usr/local/lib/python3.8/site-packages/tokenizers/tokenizers.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1871713 /usr/local/lib/python3.8/site-packages/sentencepiece/_sentencepiece.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 21367136 /usr/local/lib/python3.8/lib-dynload/cmath.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1869171 /usr/local/lib/python3.8/site-packages/nvidia/nvjitlink/lib/libnvJitLink.so.12 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1869157 /usr/local/lib/python3.8/site-packages/nvidia/nccl/lib/libnccl.so.2 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1868850 /usr/local/lib/python3.8/site-packages/nvidia/cublas/lib/libcublasLt.so.12 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1868849 /usr/local/lib/python3.8/site-packages/nvidia/cublas/lib/libcublas.so.12 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1869107 /usr/local/lib/python3.8/site-packages/nvidia/curand/lib/libcurand.so.10 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1890830 /usr/local/lib/python3.8/site-packages/torch/lib/libcusparseLt-f8b4a9fb.so.0 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1869076 /usr/local/lib/python3.8/site-packages/nvidia/cufft/lib/libcufft.so.11 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1869142 /usr/local/lib/python3.8/site-packages/nvidia/cusparse/lib/libcusparse.so.12 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1868898 /usr/local/lib/python3.8/site-packages/nvidia/cuda_cupti/lib/libcupti.so.12 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1869053 /usr/local/lib/python3.8/site-packages/nvidia/cudnn/lib/libcudnn.so.8 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1890827 /usr/local/lib/python3.8/site-packages/torch/lib/libc10.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1890828 /usr/local/lib/python3.8/site-packages/torch/lib/libc10_cuda.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1890835 /usr/local/lib/python3.8/site-packages/torch/lib/libtorch_cuda.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1890834 /usr/local/lib/python3.8/site-packages/torch/lib/libtorch_cpu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1890833 /usr/local/lib/python3.8/site-packages/torch/lib/libtorch.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1890832 /usr/local/lib/python3.8/site-packages/torch/lib/libshm.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1890838 /usr/local/lib/python3.8/site-packages/torch/lib/libtorch_python.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1879798 /usr/local/lib/python3.8/site-packages/torch/_C.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 1890831 /usr/local/lib/python3.8/site-packages/torch/lib/libgomp-a34b3233.so.1 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1869207 /usr/local/lib/python3.8/site-packages/nvidia/nvtx/lib/libnvToolsExt.so.1 (path dev=0,496)
uvicorn 181 root mem REG 253,16 1869022 /usr/local/lib/python3.8/site-packages/nvidia/cuda_runtime/lib/libcudart.so.12 (path dev=0,496)
uvicorn 181 root mem REG 253,16 24512873 /usr/local/lib/python3.8/site-packages/pillow.libs/libXau-154567c4.so.6.0.0 (path dev=0,496)
...
uvicorn 181 root mem REG 253,16 24512884 /usr/local/lib/python3.8/site-packages/pillow.libs/libtiff-0a86184d.so.6.0.2 (path dev=0,496)
uvicorn 181 root mem REG 253,16 24119318 /usr/local/lib/python3.8/site-packages/PIL/_imaging.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
uvicorn 181 root mem REG 253,16 24385120 /usr/local/lib/python3.8/site-packages/numpy/random/_generator.cpython-38-x86_64-linux-gnu.so (path dev=0,496)
...

可以发现大部分都是依赖,比如 cudatorchnumpyPIL 等等。从直觉上来说 torchcuda 可能会很大,所以我们使用 vmtouch 来看一下 cudatorch 有多少被加载到了内存里。

$ vmtouch /usr/local/lib/python3.8/site-packages/nvidia/**/*
Files: 300
Directories: 66
Resident Pages: 729487/729487 2G/2G 100%
Elapsed: 0.068292 seconds

$ vmtouch /usr/local/lib/python3.8/site-packages/torch/**/*
           Files: 11773
     Directories: 629
  Resident Pages: 381258/387864  1G/1G  98.3%
         Elapsed: 0.1744 seconds

可以看到 torch 的大部分文件和 nvidia 的所有文件都加载进了内存,而且占用都很高,一共占用了 3G 多的内存。所以 WSS 偏高是因为加载了 cuda 和 torch 的依赖。

不过需要注意的是 vmtouch 的结果可能会大于 active_file 的大小,一是因为 vmtouch 只知道文件被加载进内存与否,不区分 active_file 还是 inactive_file。二是因为 vmtouch 查询的是整个宿主机的加载情况,而 active_file 只查询了当前 cgroup 的加载情况。如果当前 cgroup 以外的进程已经把这部分文件加载进内存,那么当前 cgroup 可能就不会把这部分文件计算到 active_file 里。

所以,实际情况怎么样,还是需要通过对照实验(起一个不包含这些依赖的镜像)来证明确实是这些依赖导致的。