问题现象

公司项目通过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:

  1. https://stackoverflow.com/a/64616828/9188030
  2. https://docs.docker.com/config/containers/resource_constraints/#cpu
  3. https://www.796t.com/article.php?id=81347
  4. 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：

  1. https://jira.mongodb.org/browse/MOTOR-800?jql=project%20in%20(PYTHON%2C%20MOTOR)%20ORDER%20BY%20created%20DESC

解决方案：

对cpu个数获取不正确的问题，决定之后版本中写死MOTOR_MAX_WORKERS环境变量，每一次更新api deployment时，若部署的cpu配置发生更改则对应地更改该环境变量。

对to_list导致过多缓存的问题，根据上文jira的建议修改为对大结果集查询，分batch取出结果。

定位过程：

通过观察grafana监控面板确认该问题规律性出现。

通过发送大请求把内存快速打满确认该问题和请求体有关系，但无法复现容器因OOM停止运行。

怀疑是日志系统问题，在线上环境下运行完全屏蔽logging handler的灰度版本，未解决问题。

之后寻找线上内存将要被撑满的机器，通过cat /proc/self/smaps确认实际占用内存（rss mem）的地址区间（区别于十几G占用的虚拟内存），找出rss mem占用较大（十几m到二十多m）的地址区间，之后通过gdb对该区间内存做dump，下载至本地，通过二进制查看器查看什么内容占用了如此多的内存。

通过查看后，对比代码中的字段，大致确认是pymongo读写缓存时产生的问题。但未能定位具体产生该问题的代码区段。

通过阅读motor相关的启动代码和issue提问，最终锁定问题原因。