成功运行py.test后出现模块'threading'中的KeyError错误

68

我正在使用py.test运行一组测试。它们通过了。太好了!但我收到了以下消息:

Exception KeyError: KeyError(4427427920,) in <module 'threading' from '/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.pyc'> ignored

我应该如何追踪其源头?(我没有直接使用线程,但在使用gevent。)

3个回答

221
我发现了一个类似的问题,并决定查看具体情况 - 让我描述一下我的发现。希望有人会觉得有用。

简短的故事

这确实与monkey-patching threading模块有关。实际上,我可以通过在猴子补丁线程之前导入线程模块来轻松触发异常。以下2行就足够了:

import threading
import gevent.monkey; gevent.monkey.patch_thread()

执行时,它会输出有关被忽略的 KeyError 的消息:
(env)czajnik@autosan:~$ python test.py 
Exception KeyError: KeyError(139924387112272,) in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored

如果您交换导入行,问题就会消失。
长话短说
我可以在这里停止调试,但我决定值得了解问题的确切原因。
第一步是找到打印有关被忽略异常消息的代码。对我来说有点困难(使用“Exception.*ignored”进行全局搜索没有产生任何结果),但是在 CPython 源代码中搜索时,我最终在Python/error.c中找到了一个名为void PyErr_WriteUnraisable(PyObject *obj)的函数,并附有非常有趣的注释:
/* Call when an exception has occurred but there is no way for Python
   to handle it.  Examples: exception in __del__ or during GC. */

我决定用 gdb 的帮助来查看是谁在调用它,以获取以下的 C 级别堆栈跟踪:

#0  0x0000000000542c40 in PyErr_WriteUnraisable ()
#1  0x00000000004af2d3 in Py_Finalize ()
#2  0x00000000004aa72e in Py_Main ()
#3  0x00007ffff68e576d in __libc_start_main (main=0x41b980 <main>, argc=2,
    ubp_av=0x7fffffffe5f8, init=<optimized out>, fini=<optimized out>, 
    rtld_fini=<optimized out>, stack_end=0x7fffffffe5e8) at libc-start.c:226
#4  0x000000000041b9b1 in _start ()

现在我们可以清楚地看到,异常是在Py_Finalize执行时抛出的 - 这个调用负责关闭Python解释器、释放分配的内存等。它会在退出之前调用。
接下来的步骤是查看Py_Finalize()代码(它在Python/pythonrun.c中)。它所做的第一个调用是wait_for_thread_shutdown() - 值得一看,因为我们知道问题与线程有关。这个函数又调用了threading模块中的_shutdown可调用对象。好的,现在我们可以回到Python代码了。
查看threading.py,我发现了以下有趣的部分:
class _MainThread(Thread):

    def _exitfunc(self):
        self._Thread__stop()
        t = _pickSomeNonDaemonThread()
        if t:
            if __debug__:
                self._note("%s: waiting for other threads", self)
        while t:
            t.join()
            t = _pickSomeNonDaemonThread()
        if __debug__:
            self._note("%s: exiting", self)
        self._Thread__delete()

# Create the main thread object,
# and make it available for the interpreter
# (Py_Main) as threading._shutdown.

_shutdown = _MainThread()._exitfunc

显然,threading._shutdown() 的责任是加入所有非守护线程并删除主线程(无论确切意义如何)。我决定对 threading.py 进行一些修补 - 用 try/except 包装整个 _exitfunc() 主体,并使用 traceback 模块打印堆栈跟踪。这给出了以下跟踪:

Traceback (most recent call last):
  File "/usr/lib/python2.7/threading.py", line 785, in _exitfunc
    self._Thread__delete()
  File "/usr/lib/python2.7/threading.py", line 639, in __delete
    del _active[_get_ident()]
KeyError: 26805584

现在我们知道异常抛出的确切位置 - 在Thread.__delete()方法内部。
阅读了一段时间的threading.py之后,故事的其余部分就很明显了。 _active字典将线程ID(由_get_ident()返回)映射到所有已创建线程的Thread实例。当加载threading模块时,_MainThread类的一个实例总是会被创建并添加到_active中(即使没有明确创建其他线程)。
问题在于,gevent的monkey-patching修补程序之一是_get_ident()方法 - 原始方法映射到thread.get_ident(),monkey-patching将其替换为green_thread.get_ident()。显然,这两个调用返回主线程的不同ID。
现在,如果在猴子补丁之前加载了threading模块,则_get_ident()调用在创建并添加到_active_MainThread实例时返回一个值,在调用_exitfunc()时返回另一个值 - 因此在del _active[_get_ident()]中发生KeyError
相反,如果在加载threading之前进行了猴子补丁,则一切都很好 - 在将_MainThread实例添加到_active时,_get_ident()已经被打补丁,因此在清理时返回相同的线程ID。 就是这样!
为了确保我按正确顺序导入模块,我在猴子补丁调用之前添加了以下片段到我的代码中:
import sys
if 'threading' in sys.modules:
        raise Exception('threading module loaded before patching!')
import gevent.monkey; gevent.monkey.patch_thread()

我希望你会发现我的调试故事很有用 :)


5
回答很好,但简而言之就是:你的导入顺序不正确,请确保你的第一个导入是 import gevent.monkey; gevent.monkey.patch_all(),然后再导入其他内容。 - cerberos
10
这就是我之前所说的——导入顺序很重要。 - Code Painters

19

你可以使用这个:

import sys
if 'threading' in sys.modules:
    del sys.modules['threading']
import gevent
import gevent.socket
import gevent.monkey
gevent.monkey.patch_all()

我喜欢这种静默的方式。但是请记得在代码片段上方加入 import sys :) - casey
我曾想过尝试稍后加载gevent这样的事情。像http://justus.science/blog/2015/04/19/sys.modules-is-dangerous.html这样的东西。 - btown

1

我曾经遇到过一个与gevent原型脚本类似的问题。

Greenlet回调函数执行得很好,我通过g.join()将其与主线程同步。对于我的问题,我不得不调用gevent.shutdown()来关闭(我认为是)Hub。在我手动关闭事件循环之后,程序可以正常终止而没有出现错误。


2
+1 -- 但我询问的是如何追踪问题的源头,而不是如何掩盖问题。 - kkurian
2
当我使用nose运行测试时,我也遇到了使用gevent的相同问题。奇怪的是,当所有测试都通过时,我不会看到错误,但是当测试失败时我会看到它。我正在使用monkey.patch_all()。值得注意的是,当我执行monkey.patch_all(thread=False)时,错误消失了。 - millerdev
追踪错误可能相当困难。如果我理解这个问题,它与正在运行的后台线程有关。似乎问题来自于主循环在后台线程完成任务之前终止。主线程终止的中断必须导致程序抛出异常。我认为解决这个问题的最佳方法是确保所有线程在关闭主进程之前都已完成处理。 - Kris
@Kris 我同意困难和可能导致问题的原因。但对我来说不清楚的是:是什么触发了线程,线程在做什么,以及为什么它们没有正确地结束。我想我只能假设它是gevent中的某些东西,在此做的一切都很好,并且gevent.shutdown()会做正确的事情。感谢你的帮助! - kkurian
@Daniel:你可能想看一下我的帖子:http://blog.codepainters.com/2012/11/20/gevent-monkey-patching-versus-sniffer-nose/ - Code Painters

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接