python - py.test 运行成功后，模块 'threading' 中的 KeyError

Question

我正在使用 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。)

Answer 1

我观察到了一个类似的问题，并决定看看到底发生了什么——让我描述一下我的发现。我希望有人会觉得它有用。

短篇故事

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

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 源代码周围找到了一个名为 void PyErr_WriteUnraisable(PyObject *obj) 的函数。在 Python/error.c ，有一个非常有趣的评论:

/* 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 executes - 这个调用负责关闭 Python 解释器，释放分配的内存等。它在退出之前被调用。

下一步是看 Py_Finalize()代码(在 Python/pythonrun.c 中)。它调用的第一个电话是 wait_for_thread_shutdown() - 值得一看，因为我们知道问题与线程有关。该函数依次调用 _shutdown可在 threading 中调用模块。好的，我们现在可以回到 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一点 - 包裹整个 _exitfunc() body 与 try/ except并使用 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 修补的方法之一的猴子补丁是 _get_ident() - 原版映射到 thread.get_ident() , 猴子补丁将其替换为 green_thread.get_ident() .显然，这两个调用为主线程返回不同的 ID。

现在，如果 threading模块在猴子补丁之前加载， _get_ident()当 _MainThread 时调用返回一个值实例已创建并添加到 _active ，以及当时的另一个值 _exitfunc()被称为 - 因此 KeyError在 del _active[_get_ident()] .

相反，如果在 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()

我希望你觉得我的调试故事有用:)