问题现象
公司项目通过tornado框架实现,依赖pymongo+motor作为数据库访问driver,实质通过docker部署的api应用出现稳定、缓慢的内存增长。在给予docker容器4G硬限的前提下,从开始运行起,经过2-7天出现进程因OOM被强制结束运行的问题。
问题原因:
- 容器内运行镜像时硬限的语义和python中os.cpu_count()的语义不同问题 根据ref 1和2所提到的定义,当使用–cpus flag限制docker容器运行时使用的cpu时,其实质是限制了一个容器可以使用的cpu tick占一段时间内cpu tick的百分比。举例说明,如果一台机器cpu为4核,使用–cpus 1.5参数指定容器运行,则限制了该容器可以使用的cpu tick为1.5/4,即37.5%的cpu tick(等价为cpu算力)。出现问题的motor代码片段附加如下:
if 'MOTOR_MAX_WORKERS' in os.environ: max_workers = int(os.environ['MOTOR_MAX_WORKERS']) else: max_workers = multiprocessing.cpu_count() * 5 _EXECUTOR = ThreadPoolExecutor(max_workers=max_workers)
易用python3 -c "import multiprocessing as mp; import os; print(os.cpu_count() is mp.cpu_count())"
运行结果为True
验证multiprocessing.cpu_count()
和os.cpu_count()
为同一函数。os.cpu_count()
进而使用如下的代码片段在linux运行环境下获得cpu核数:
ncpu = sysconf(_SC_NPROCESSORS_ONLN);
该系统调用会获取系统硬件有多少cpu核。docker命令限制的是cpu tick使用占比,不可能改变硬件层面上有多少cpu核在使用,故该python调用返回硬件层面上的cpu核数也是合理的。 回到上方motor启动时的代码片段。一般一台宿主机上会有很多cpu核,跑不同docker管理下下运行的容器。而启动代码里的multiprocessing.cpu_count()
调用获取到的是宿主机的cpu核数,所以启动了远远超过期望的motor worker数量。
ref:
- https://stackoverflow.com/a/64616828/9188030
- https://docs.docker.com/config/containers/resource_constraints/#cpu
- https://www.796t.com/article.php?id=81347
- https://man7.org/linux/man-pages/man3/get_nprocs_conf.3.html
- 使用motor为pymongo的driver时未分页导致单个worker内存占用过高的问题 在修正内存问题之前,取用mongo数据的伪代码如下:
cursor = TABLE.find({...}) # or cursor = TABLE.find({...}).sort(...) return cursor.to_list(None)
cursor是lazy evaluated的。执行to_list
后才会尝试从数据库中取数据,逐个放进返回的列表中,最后返回结果列表。伪代码所示的to_list
用法没有限制一次读入数据的条数,故当一次筛选出大量数据后(典型例子如“问题现象出现时间”所提到的commit),则单个worker会在完成取用数据后缓存该次查询的结果,直到下一次由该worker进行该次条件的查询时,再刷新其缓存的数据。单个worker缓存了过大查询结果,和之前提到的worker数量过多的问题叠加,造成了api deployment规律性因OOM而被强制结束运行的问题。
ref:
解决方案:
对cpu个数获取不正确的问题,决定之后版本中写死MOTOR_MAX_WORKERS
环境变量,每一次更新api deployment时,若部署的cpu配置发生更改则对应地更改该环境变量。
对to_list导致过多缓存的问题,根据上文jira的建议修改为对大结果集查询,分batch取出结果。
定位过程:
通过观察grafana监控面板确认该问题规律性出现。
通过发送大请求把内存快速打满确认该问题和请求体有关系,但无法复现容器因OOM停止运行。
怀疑是日志系统问题,在线上环境下运行完全屏蔽logging handler的灰度版本,未解决问题。
之后寻找线上内存将要被撑满的机器,通过cat /proc/self/sma
确认实际占用内存(rss mem)的地址区间(区别于十几G占用的虚拟内存),找出rss mem占用较大(十几m到二十多m)的地址区间,之后通过gdb对该区间内存做dump,下载至本地,通过二进制查看器查看什么内容占用了如此多的内存。 ps
通过查看后,对比代码中的字段,大致确认是pymongo读写缓存时产生的问题。但未能定位具体产生该问题的代码区段。
通过阅读motor相关的启动代码和issue提问,最终锁定问题原因。