问题描述
代码主要功能是获取分析需求,查询MongoDB并打印分析结果,使用PyMongo访问MongoDB。代码中最后一行输出代码执行完毕,正确打印出数据,但进程不退出,不能回到terminal,需等待5分钟左右进程才退出。
调试过程方法
此类不退出问题的可能原因:
- 使用了多进程库,但最后有进程未关闭。
- 运行的线程未关闭。
代码中未使用多进程,查看是不是有线程未关闭导致进程不能关闭,两种方法查看线程状态,使用top命令实时查看线程的开关情况;在代码的最后增加打印线程信息。
- 使用top命令:
首先top命令查看进程的PID,然后运行
top -H -p your_pid
可以实时查看thread运行情况,如下所示,可以看到共5个线程,主线程是运行状态,其他4个线程是sleep状态。
(其他查看线程方法如htop,ps等请参考How to view threads of a process on Linux)
2. python中打印线程信息
在Python代码最后打印进程的状态:
import sys, traceback
for thread_id, frame in sys._current_frames().items():
print('Stack for thread {}'.format(thread_id))
traceback.print_stack(frame)
print('')
业务代码执行完毕后,线程状态如下:
Stack for thread 140353262769920
File "/opt/tljh/user/lib/python3.7/threading.py", line 885, in _bootstrap
self._bootstrap_inner()
File "/opt/tljh/user/lib/python3.7/threading.py", line 917, in _bootstrap_inner
self.run()
File "/opt/tljh/user/lib/python3.7/threading.py", line 865, in run
self._target(*self._args, **self._kwargs)
File "/opt/tljh/user/lib/python3.7/site-packages/pymongo/periodic_executor.py", line 131, in _run
time.sleep(self._min_interval)
Stack for thread 140353254377216
File "/opt/tljh/user/lib/python3.7/threading.py", line 885, in _bootstrap
self._bootstrap_inner()
File "/opt/tljh/user/lib/python3.7/threading.py", line 917, in _bootstrap_inner
self.run()
File "/opt/tljh/user/lib/python3.7/threading.py", line 865, in run
self._target(*self._args, **self._kwargs)
File "/opt/tljh/user/lib/python3.7/site-packages/pymongo/periodic_executor.py", line 131, in _run
time.sleep(self._min_interval)
Stack for thread 140353212430080
File "/opt/tljh/user/lib/python3.7/threading.py", line 885, in _bootstrap
self._bootstrap_inner()
File "/opt/tljh/user/lib/python3.7/threading.py", line 917, in _bootstrap_inner
self.run()
File "/opt/tljh/user/lib/python3.7/threading.py", line 865, in run
self._target(*self._args, **self._kwargs)
File "/opt/tljh/user/lib/python3.7/site-packages/pymongo/periodic_executor.py", line 131, in _run
time.sleep(self._min_interval)
Stack for thread 140353204037376
File "/opt/tljh/user/lib/python3.7/threading.py", line 885, in _bootstrap
self._bootstrap_inner()
File "/opt/tljh/user/lib/python3.7/threading.py", line 917, in _bootstrap_inner
self.run()
File "/opt/tljh/user/lib/python3.7/threading.py", line 865, in run
self._target(*self._args, **self._kwargs)
File "/opt/tljh/user/lib/python3.7/site-packages/pymongo/periodic_executor.py", line 131, in _run
time.sleep(self._min_interval)
Stack for thread 140354598987584
File "test_query.py", line 34, in <module>
traceback.print_stack(frame)
可以看出是由于periodic_executor没有关闭导致的,periodic executor是pymongo中检测数据库游标cursor的线程,在初始化连接时打开,我们的程序中使用find方法来获取数据,但获取完数据后cursor会自动关闭。所以需要查看为什么仍有cursor未关闭的情况。
尝试的解决办法:
- 主动关闭mongoclient(官方文档解释client不需要主动关闭),但进程仍旧不能正确退出。
- 直接调用sys.exit(),不能退出。
- 因为客户新报告的这个issue,之前一直没有问题,这次唯一区别是find返回的数据量比较 大,一千万条数据。所以怀疑跟数据量有关系,可能是pymongo的find返回大数据量时候 有bug,所以针对不能的数据量级别做如下测试
可以看出pymongodb的线程处理有bug,但find返回大数据量时候不能及时关闭线程。
4. 升级Python版本,考虑到Python3.8增强了线程管理(Add a newthreading.excepthook()
function which handles uncaughtthreading.Thread.run()
exception),尝试在Python3.8测试,进程能正常返回。
方案总结
建议客户使用Python3.8,临时修复这个问题。PyMongo在3.7版本当find返回大数据量(>5 million)时候线程管理存在bug,后续查看源代码并report issue给pymongo开发团队。
相关链接
why-do-pymongo-scripts-take-a-minimum-of-500ms-to-execute
Pymongo abandoned “pymongo_kill_cursors_thread” after client exit