Python / OpenCV 应用程序卡死问题

Question

我的 Python 应用程序在一个 64 核的 Linux 机器上通常能正常运行。然后，在随机的一段时间后（通常是约 0.5 到 1.5 天），我突然开始出现频繁的暂停/锁定，持续超过 10 秒钟！在这些锁定期间，系统 CPU 时间（即内核中的时间）可能超过 90%（是的：所有 64 个核心中的 90%，而不仅仅是一个 CPU 的 90%）。

我的应用程序经常在一天中重新启动。重新启动应用程序无法解决问题。但是，重启机器可以。

问题 1：什么会导致系统 CPU 时间达到 10 秒的 90%？所有系统 CPU 时间都在我的父 Python 进程中，而不是通过 Python 的 multiprocessing 或其他进程创建的子进程中。因此，大约有 60 多个线程花费了 10 多秒钟在内核中。我甚至不确定这是 Python 问题还是 Linux 内核问题。

问题 2：重启解决了问题必须是导致问题的一个很大的线索。在我的应用程序重新启动之间，但在重启之间，可能会使系统资源耗尽，从而导致此问题被卡住的 Linux 资源是什么？

我已经尝试解决/找出问题的方法

下面我将经常提到 multiprocessing。这是因为应用程序在一个循环中运行，并且 multiprocessing 仅在循环的某一部分中使用。高 CPU 几乎总是发生在所有 multiprocessing 调用完成后之后。我不确定这是问题的原因或者只是干扰。

• 我的应用程序运行一个线程，每0.5秒使用psutil记录进程和系统的CPU统计信息。我已经通过top独立确认它的报告。
• 我已将我的应用程序从Python 2.7转换到Python 3.4，因为Python 3.2有了新的GIL实现，而3.4重写了多处理模块。虽然这改善了一些问题，但并没有解决问题（请参见我的以前的SO问题，我仍然保留它，因为它仍然是一个有用的答案，即使不是完全的答案）。
• 我曾更换过操作系统。最初是Ubuntu 12 LTS，现在是CentOS 7。没有区别。
• 事实证明，在Python/Linux中，多线程和多进程会发生冲突，并且不建议同时使用，Python 3.4现在具有forkserver和spawn多进程上下文。我尝试过它们，没有任何区别。
• 我检查了/dev/shm，以查看是否用尽了共享内存（Python 3.4使用它来管理多进程），没有任何问题。
• lsof输出显示了所有资源的列表
• 在其他计算机上进行测试很困难，因为我运行了59个子进程的多进程池，而我没有任何其他64核心机器。
• 我无法使用线程而不是进程来运行它，因为由于GIL的缘故，它不能运行得足够快（这也是我首选多进程的原因）。
• 我尝试在只有一个运行缓慢的线程上使用strace（无法跨越所有线程运行，因为它会使应用程序变得非常缓慢）。以下是我获得的结果，这并没有告诉我太多信息。
• ltrace无法工作，因为不能对线程ID使用-p。即使仅对主线程运行它（没有-f），应用程序也会变得非常缓慢，使问题不会出现。
• 问题与负载无关。它有时会在完全负载下运行良好，然后稍后在半负载下，它会突然出现这个问题。
• 即使我每晚重新启动机器，问题每隔几天就会重新出现。

环境/注释：

• 使用从源代码编译的Python 3.4.3
• CentOS 7完全更新。 uname -a: Linux 3.10.0-229.4.2.el7.x86_64 #1 SMP Wed May 13 10:06:09 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux （尽管此内核更新仅于今天应用）
• 机器有128GB内存，并且有足够的空闲内存
• 我使用链接到ATLAS的numpy。 我知道OpenBLAS与Python multiprocessing冲突，但ATLAS不会，而且这种冲突由Python 3.4的forkserver和spawn解决，我已经尝试过了。
• 我使用还执行了大量并行工作的OpenCV
• 我使用 ctypes 访问由相机制造商提供的C .so库
• 应用程序以root身份运行（我链接到一个C库的要求）
• Python multiprocessing Pool 在由if __name__ ==“__main__”：保护的代码中创建，并在主线程中创建

更新的strace结果

有几次我设法跟踪运行在100％“system”CPU上的线程。 但是只有一次我得到了任何有意义的结果。 请参见以下在10:24:12.446614进行的调用，需要1.4秒钟。 鉴于它是大多数其他调用中看到的相同ID（0x7f05e4d1072c），我的猜测是这是Python的GIL同步。 如果是这样，那么问题是等待为什么要花费1.4秒钟？ 有人没有释放GIL吗？

10:24:12.375456 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <0.000823>
10:24:12.377076 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <0.002419>
10:24:12.379588 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <0.001898>
10:24:12.382324 sched_yield()           = 0 <0.000186>
10:24:12.382596 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <0.004023>
10:24:12.387029 sched_yield()           = 0 <0.000175>
10:24:12.387279 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <0.054431>
10:24:12.442018 sched_yield()           = 0 <0.000050>
10:24:12.442157 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <0.003902>
10:24:12.446168 futex(0x7f05e4d1022c, FUTEX_WAKE, 1) = 1 <0.000052>
10:24:12.446316 futex(0x7f05e4d11cac, FUTEX_WAKE, 1) = 1 <0.000056>
10:24:12.446614 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <1.439739>
10:24:13.886513 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <0.002381>
10:24:13.889079 sched_yield()           = 0 <0.000016>
10:24:13.889135 sched_yield()           = 0 <0.000049>
10:24:13.889244 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <0.032761>
10:24:13.922147 sched_yield()           = 0 <0.000020>
10:24:13.922285 sched_yield()           = 0 <0.000104>
10:24:13.923628 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <0.002320>
10:24:13.926090 sched_yield()           = 0 <0.000018>
10:24:13.926244 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <0.000265>
10:24:13.926667 sched_yield()           = 0 <0.000027>
10:24:13.926775 sched_yield()           = 0 <0.000042>
10:24:13.926964 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable) <0.000117>
10:24:13.927241 futex(0x7f05e4d110ac, FUTEX_WAKE, 1) = 1 <0.000099>
10:24:13.927455 futex(0x7f05e4d11d2c, FUTEX_WAKE, 1) = 1 <0.000186>
10:24:13.931318 futex(0x7f05e4d1072c, FUTEX_WAIT, 2, NULL) = 0 <0.000678>

- Damon Maria

---

使用ipcs -us指令，我发现我的信号量数组不足。增加限制只能让我再有一些时间，直到我再次用完数组。起初，我认为信号量与Python多进程相关，但事实证明，通过ctypes.CDLL（...）链接相机.so文件（如上所述），必须使相机驱动程序分配信号量数组。这种链接在每个子进程中都会发生，因此会分配很多数组。我目前正在调查是否这是问题的原因。 - Damon Maria

虽然信号量不足是一个问题，但这并不是答案。我有一个测试套件，连续运行时显示高CPU问题。即使未连接到相机驱动程序并且有可用的信号量数组，测试套件仍然显示问题。 - Damon Maria

感谢@linuxfan。我肯定正在使用受此错误影响的CentOS版本，它听起来在正确的区域内，但讨论表明症状应该是低CPU（线程在不应该等待时等待）而不是我看到的100％CPU。所以我不确定这是否是问题所在。我很想尝试修复，但CentOS还没有提供解决方案，而且我以前从未编译过Linux内核。 - Damon Maria

由于输出内容较多，这里提供 lsof 命令的输出链接：http://pastebin.com/1nebcamY - Damon Maria

机器有128GB的内存，并且有足够的空闲。请分享更多关于您如何得出这个结论的信息。首先，可以查看Python进程的RSS/VSZ。 - Brian Cain

Answer 1

我已经成功从gdb获取了线程转储，就在40多个线程显示100％“系统”CPU时间的地方。

这是每个线程都相同的回溯：

#0  0x00007fffebe9b407 in cv::ThresholdRunner::operator()(cv::Range const&) const () from /usr/local/lib/libopencv_imgproc.so.3.0
#1  0x00007fffecfe44a0 in tbb::interface6::internal::start_for<tbb::blocked_range<int>, (anonymous namespace)::ProxyLoopBody, tbb::auto_partitioner const>::execute() () from /usr/local/lib/libopencv_core.so.3.0
#2  0x00007fffe967496a in tbb::internal::custom_scheduler<tbb::internal::IntelSchedulerTraits>::local_wait_for_all(tbb::task&, tbb::task*) () from /lib64/libtbb.so.2
#3  0x00007fffe96705a6 in tbb::internal::arena::process(tbb::internal::generic_scheduler&) () from /lib64/libtbb.so.2
#4  0x00007fffe966fc6b in tbb::internal::market::process(rml::job&) () from /lib64/libtbb.so.2
#5  0x00007fffe966d65f in tbb::internal::rml::private_worker::run() () from /lib64/libtbb.so.2
#6  0x00007fffe966d859 in tbb::internal::rml::private_worker::thread_routine(void*) () from /lib64/libtbb.so.2
#7  0x00007ffff76e9df5 in start_thread () from /lib64/libpthread.so.0
#8  0x00007ffff6d0e1ad in clone () from /lib64/libc.so.6

我的原始问题将Python和Linux放在了首位，但问题似乎出现在TBB和/或OpenCV上。由于使用带有TBB的OpenCV非常普遍，我认为它也必须涉及与我的特定环境的相互作用。也许是因为这是一台64核机器？

我已经重新编译了关闭TBB的OpenCV，并且问题到目前为止还没有再次出现。但是我的应用程序现在运行得更慢了。

我已经将此问题发布为OpenCV的错误，并将根据任何结果更新此答案。

- Damon Maria