Python 代码执行沙盒CPU占用率直线上升排查过程
初始代码对于python代码在本地执行我们会设置一个内存占用上限def _limit_memory(): # 基于 RLIMIT_DATA 的内存限制, 仅类 Unix 有效, Windows 下无效但不影响执行。 try: import resource _bytes int(os.environ.get(MEMORY_LIMIT_MB, 700)) * 1024 * 1024 resource.setrlimit(resource.RLIMIT_RS, (_bytes, _bytes)) except Exception: pass根据AI说的,这个RLIMIT_RS 会限制堆 和 mmap的区域,因为当python执行 numpy脚本的时候,是通过mmap申请出来的,没有在堆上.然后我就上线了,之后就cpu报警了报警top命令中显示 python脚本执行cpu占用超高,但是res(实际使用内存):20M左右 内存申请接近700M. 然后cpu的使用时间 system使用时间非常多 user使用时间非常少经过AI的一顿分析,说可能是虚拟内存接近700M,所以触发频繁的gc所以既然这么说,那就暂时放弃RLIMIT_RS 的方式,改成 RLIMIT_DATA的方式(期间调研了cgroup 当时,但是需要linux ,k8s 的支持,所以作罢)RLIMIT_DATA 二次上线好了,本次我把代码改成RLIMIT_DATA 限制,这样就在线上灰度一台机器看看什么情况本来是等着无事发生,这个任务就完成了,因为最开始的代码是DATA限制,同事还说启用过这个代码,但是.上线不久cpu就再次沾满了,天啊我再次上线进行排查top - 18:11:11 up 952 days, 2 min, 0 users, load average: 24.20, 17.29, 17.31 Threads: 61 total, 5 running, 56 sleeping, 0 stopped, 0 zombie%Cpu(s): 15.7 us, 16.4 sy, 0.0 ni, 65.4 id, 0.0 wa, 0.0 hi, 2.4 si, 0.0 st KiB Mem : 13151299total, 1454260 free, 68860152 used, 61198584 buff/cacheKiB Swap: 0 total, 0 free, 0 used. 22433540 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME COMMAND 8329 root 20 0 1559004 20756 10296 S 24.3 0.0 0:09.92 /opt/miniconda3.9/bin/python /tmp/tmpkd21ej54.py 8313 root 20 0 1624540 20756 10296 S 24.0 0.0 0:09.96 /opt/miniconda3.9/bin/python /tmp/tmpkd21ej54.py 8318 root 20 0 1493468 20756 10296 S 24.0 0.0 0:09.89 /opt/miniconda3.9/bin/python /tmp/tmpkd21ej54.py 8321 root 20 0 1493468 20756 10296 S 24.0 0.0 0:09.96 /opt/miniconda3.9/bin/python /tmp/tmpkd21ej54.py 8323 root 20 0 1493468 20756 10296 R 24.0 0.0 0:10.04 /opt/miniconda3.9/bin/python /tmp/tmpkd21ej54.py 8325 root 20 0 1624540 20756 10296 R 24.0 0.0 0:10.01 /opt/miniconda3.9/bin/python /tmp/tmpkd21ej54.py 8326 root 20 0 1559004 20756 10296 R 24.0 0.0 0:10.05 /opt/miniconda3.9/bin/python /tmp/tmpkd21ej54.py 8314 root 20 0 1493468 20756 10296 S 23.7 0.0 0:09.99 /opt/miniconda3.9/bin/python /tmp/tmpkd21ej54.py 8324 root 20 0 1559004 20756 10296 S 23.7 0.0 0:09.91 /opt/miniconda3.9/bin/python /tmp/tmpkd21ej54.py 8328 root 20 0 1624540 20756 10296 R 23.7 0.0 0:09.97 /opt/miniconda3.9/bin/python /tmp/tmpkd21ej54.py看着还是和第一步的top 的故障现象是一样一样.啊??明明已经改了啊.然后我又扔给ai进行分析是什么原因ai说RLIMIT_DATA 还是可能限制mmap的…我当时就吐了.我追问了ai, RLIMIT_DATA是不限制mmap的然后ai回答你记得的是旧 Linux 语义。准确地说 Linux 4.6 及以前RLIMIT_DATA 主要限制 brk/sbrk不限制 mmap。 Linux 4.7 起也限制计入 VmData 的 mmap超限返回 ENOMEM。 不是所有 mmap 都算通常是私有、可写的数据映射只读库映射等不一定计入。 内核参数 ignore_rlimit_data 还可以关闭这项检查。Linux getrlimit(2)没错,当我查了linux 手册之后,确实,4.7版本之后RLIMIT_DATA 也是限制mmap的.所以这里面出现了第一个问题,ai回答的答案也是错的,因为不同版本的依赖的服务语义是有改变的.这也是context7这类的项目,为什么文档库必须是有版本标志的.问题继续排查既然DATA限制也不行,那我要排查出具体的问题是什么了.因为当时正好在事故现场然后我问AI,你需要什么信息,把命令发给我,我来执行.ai首先确认了我系统的版本和是否接受那从限制,大家可以问下ai下面的语句和返回是什么意思.rootagent-/home# uname -r 4.14.105-19-0021 rootagent:/home# cat /sys/module/kernel/parameters/ignore_rlimit_data 2/dev/null || echo 参数不存在 N第二步ai确定了,线程的存在时间ootagent:/home# P$(pgrep -o -f [t]mpkd21ej54.py) rootagent:/home# echo PID$P PID8302 rootagent:/home# rootagent:/home# ps -T -p $P -o pid,spid,ppid,nlwp,stat,psr,pcpu,rss,vsz,etime,comm PID SPID PPID NLWP STAT PSR %CPU RSS VSZ ELAPSED COMMAND 8302 8302 21 11 Sl 37 0.0 20756 1624540 10:34 python 8302 8313 21 11 Sl 26 24.1 20756 1624540 10:34 python 8302 8314 21 11 Sl 10 24.0 20756 1559004 10:34 python 8302 8318 21 11 Rl 16 23.9 20756 1493468 10:34 python 8302 8321 21 11 Sl 30 24.1 20756 1493468 10:34 python 8302 8323 21 11 Rl 36 24.2 20756 1493468 10:34 python 8302 8324 21 11 Sl 38 24.0 20756 1559004 10:34 python 8302 8325 21 11 Rl 32 24.1 20756 1493468 10:34 python 8302 8326 21 11 Sl 22 24.0 20756 1493468 10:34 python 8302 8328 21 11 Sl 12 24.1 20756 1493468 10:34 python 8302 8329 21 11 Sl 20 24.0 20756 1493468 10:34 python在这里面,ai发现了两个重要事情限制是 716800 KiB实际 VmData708772 KiB只剩约 7.8MiB。 VSZ 在采样中以 65536 KiB 为步长变化正好是 64MiB。ai猜测的因果链是设置 RLIMIT_DATA700MiB → 导入 pandas/NumPy → OpenBLAS 等 native 库按 CPU 核数创建工作线程 → glibc 为线程分配约 64MiB 的虚拟 malloc arena → 创建 10 个后 VmData 达到约 700MiB → 后续匿名 mmap/malloc 失败 → native 线程池初始化卡在忙等待 → 10 个线程持续消耗约 240% CPUai第三步是确定哪个库rootagent:/home# P8302 rootagent:/home# rootagent:/home# grep -Ei openblas|blas|mkl|libgomp|libomp|numexpr /proc/$P/maps \ | awk {print $NF} | sort -u /opt/miniconda3.9/lib/python3.9/site-packages/numpy.libs/libopenblas64_p-r0-15028c96.3.21.so rootagent:/home#这里确定了是openbla而且是3.12版本证据能够精确对应 10 个 OpenBLAS 工作线程 × 64MiB arena ≈ 640MiB Python/NumPy 基础 VmData ≈ 68MiB 总 VmData 708772KiB RLIMIT_DATA 716800KiB 剩余 ≈ 7.8MiB OpenBLAS继续创建工作线程时新的私有匿名映射无法通过 RLIMIT_DATA 检查线程池停留在异常的初始化/调度路径已有10个线程持续运行造成约240% CPU。RSS很低是因为这些64MiB arena主要是虚拟地址预留。追问接着我追问,为什么我不加RLIMIT_DATA限制的时候,这个脚本执行没有问题呢?ai根据源码回答OpenBLAS 0.3.21 的源码证实了这条路径 blas_thread_init() 按 CPU 数循环创建线程。 每个线程启动后立即执行 blas_memory_alloc(2)。 RLIMIT_DATA 使 mmap/malloc 返回 ENOMEM。 blas_memory_alloc() 使用无退出条件的循环反复申请直到成功。 所以线程卡在申请内存的忙循环中永远到不了休眠逻辑。 对应源码 线程创建及失败处理 工作线程首先申请内存 申请失败后无限重试 因此行为是 不限制 创建线程 → 内存申请成功 → 线程休眠/程序很快结束 限制 RLIMIT_DATA 创建线程 → 内存申请失败 → 无限重试 同时主线程继续创建其他工作线程 → 线程数升高、CPU持续升高、程序无法结束 你看到的10个高CPU线程就是成功创建、但卡在 blas_memory_alloc() 中的线程事情到了这里应该是能确定的,我明天限制一下线程数量再发布一下看看是否可以

相关新闻