py.test运行成功后，模块“线程化"中的KeyError [英] KeyError in module 'threading' after a successful py.test run

问题描述

我正在使用py.test运行一组测试.他们通过了.耶皮！但我收到此消息:

I'm running a set of tests with py.test. They pass. Yippie! But I'm getting this message:

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

我应该如何追踪其来源? (我不是直接使用线程，而是在使用gevent.)

How should I go about tracking down the source of that? (I'm not using threading directly, but am using gevent.)

推荐答案

我观察到一个类似的问题，并决定确切地了解正在发生的事情-让我描述一下我的发现.我希望有人会发现它有用.

I observed a similar issue and decided to see what's going on exactly - let me describe my findings. I hope someone will find it useful.

它确实与猴子修补threading模块有关.实际上，通过在猴子修补线程之前导入线程模块，我可以轻松触发异常.以下两行就足够了:

It is indeed related to monkey-patching the threading module. In fact, I can easily trigger the exception by importing the threading module before monkey-patching threads. The following 2 lines are enough:

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

执行时，它会吐出有关被忽略的KeyError的消息:

When executed it spits the message about ignored KeyError:

(env)czajnik@autosan:~$ python test.py 
Exception KeyError: KeyError(139924387112272,) in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored

如果交换导入行，问题就消失了.

If you swap the import lines, the problem is gone.

我可以在这里停止调试，但是我认为值得了解问题的确切原因.

I could stop my debugging here, but I decided it's worth to understand the exact cause of the problem.

第一步是找到打印有关被忽略异常的消息的代码.我很难找到它(对Exception.*ignored进行尝试没有产生任何结果)，但是围绕CPython源代码进行了grepping，我最终在void PyErr_WriteUnraisable(PyObject *obj)的函数.org/projects/python/tags/r27/Python/errors.c> Python/error.c ，上面有一个非常有趣的注释:

First step was to find the code that prints the message about ignored exception. It was a little hard for me to find it (grepping for Exception.*ignored yielded nothing), but grepping around CPython source code I've eventually found a function called void PyErr_WriteUnraisable(PyObject *obj) in Python/error.c, with a very interesting comment:

/* 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级堆栈跟踪:

I decided to check who's calling it, with a little help from gdb, just to get the following C-level stack trace:

#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解释器，释放分配的内存等.它在退出之前被调用.

Now we can clearly see that the exception is thrown while Py_Finalize executes - this call is responsible for shutting down the Python interpreter, freeing allocated memory, etc. It's called just before exitting.

下一步是查看Py_Finalize()代码(位于 Python/pythonrun中. c ).它引起的第一个调用是wait_for_thread_shutdown()-值得研究，因为我们知道问题与线程有关.该函数依次调用threading模块中可调用的_shutdown.好，我们现在可以回到python代码.

Next step was to look at Py_Finalize() code (it's in Python/pythonrun.c). The very first call it makes is wait_for_thread_shutdown() - worth looking at, as we know the problem is related to threading. This function in turn calls _shutdown callable in the threading module. Good, we can go back to python code now.

看着threading.py，我发现了以下有趣的部分:

Looking at threading.py I've found the following interesting parts:

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()主体，并使用

Clearly, the responsibility of threading._shutdown() call is to join all non-daemon threads and delete main thread (whatever that means exactly). I decided to patch threading.py a bit - wrap the whole _exitfunc() body with try/except and print the stack trace with traceback module. This gave the following trace:

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()方法内部.

Now we know the exact place where the exception is thrown - inside Thread.__delete() method.

在阅读threading.py一段时间后，故事的其余部分显而易见.对于创建的所有线程，_active词典将线程ID(由_get_ident()返回)映射到Thread实例.加载threading模块时，总是创建_MainThread类的实例并将其添加到_active(即使未显式创建其他线程).

The rest of the story is obvious after reading threading.py for a while. The _active dictionary maps thread IDs (as returned by _get_ident()) to Thread instances, for all threads created. When threading module is loaded, an instance of _MainThread class is always created and added to _active (even if no other threads are explicitly created).

问题在于，gevent的猴子修补程序修补的方法之一是_get_ident()-原始方法映射到thread.get_ident()，猴子修补程序将其替换为green_thread.get_ident().显然，两个调用都为主线程返回不同的ID.

The problem is that one of the methods patched by gevent's monkey-patching is _get_ident() - original one maps to thread.get_ident(), monkey-patching replaces it with green_thread.get_ident(). Obviously both calls return different IDs for main thread.

现在，如果在猴子修补之前加载了threading模块，则在创建_MainThread实例并将其添加到_active时，_get_ident()调用将返回一个值，而在_exitfunc()时将调用另一个值-因此del _active[_get_ident()]中的KeyError.

Now, if threading module is loaded before monkey-patching, _get_ident() call returns one value when _MainThread instance is created and added to _active, and another value at the time _exitfunc() is called - hence KeyError in del _active[_get_ident()].

相反，如果在threading加载之前完成了猴子补丁，那么一切都很好-在将_MainThread实例添加到_active时，已经对_get_ident()进行了补丁，并且具有相同的线程ID在清理时返回.就是这样！

On the contrary, if monkey-patching is done before threading is loaded, all is fine - at the time _MainThread instance is being added to _active, _get_ident() is already patched, and the same thread ID is returned at cleanup time. That's it!

为确保以正确的顺序导入模块，我在猴子补丁调用之前将以下代码段添加到了我的代码中:

To make sure I import modules in the right order, I added the following snippet to my code, just before monkey-patching call:

import sys
if 'threading' in sys.modules:
        raise Exception('threading module loaded before patching!')
import gevent.monkey; gevent.monkey.patch_thread()

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

I hope you find my debugging story useful :)

这篇关于py.test运行成功后，模块“线程化"中的KeyError的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！