From 687e5ad78e68a9f7b9b8c4502c9e3c6617eae918 Mon Sep 17 00:00:00 2001 From: Jason Madden Date: Wed, 15 Jan 2020 09:21:57 -0600 Subject: [PATCH] Include traceback in threadpool logging. Hoping to find where test__subprocess_interrupted is failing on Py2 --- src/gevent/_fileobjectposix.py | 2 +- .../tests/test__subprocess_interrupted.py | 7 ++-- src/gevent/threadpool.py | 33 +++++++++++++++---- 3 files changed, 33 insertions(+), 9 deletions(-) diff --git a/src/gevent/_fileobjectposix.py b/src/gevent/_fileobjectposix.py index 0c7cafbab..bd923da02 100644 --- a/src/gevent/_fileobjectposix.py +++ b/src/gevent/_fileobjectposix.py @@ -311,7 +311,7 @@ def __init__(self, *args, **kwargs): descriptor = GreenOpenDescriptor(*args, **kwargs) # This attribute is documented as available for non-blocking reads. self.fileio, buffered_fobj = descriptor.open_raw_and_wrapped() - super(FileObjectPosix, self).__init__(buffered_fobj, descriptor.closefd) + FileObjectBase.__init__(self, buffered_fobj, descriptor.closefd) def _do_close(self, fobj, closefd): try: diff --git a/src/gevent/tests/test__subprocess_interrupted.py b/src/gevent/tests/test__subprocess_interrupted.py index 049aba840..3b0566479 100644 --- a/src/gevent/tests/test__subprocess_interrupted.py +++ b/src/gevent/tests/test__subprocess_interrupted.py @@ -18,7 +18,7 @@ out, err = subprocess.Popen([sys.executable, '-W', 'ignore', __file__, 'runtestcase'], stderr=subprocess.PIPE).communicate() - # We've seen three. unexpected forms out output. + # We've seen a few unexpected forms of output. # # The first involves 'refs'; I don't remember what that was # about, but I think it had to do with debug builds of Python. @@ -27,7 +27,10 @@ # started by \nsys.excepthook is missing\nlost sys.stderr". # This is a race condition between closing sys.stderr and # writing buffered data to a pipe that hasn't been read. We - # only see this using GEVENT_FILE=thread (which makes sense). + # only see this using GEVENT_FILE=thread (which makes sense); + # likewise, on Python 2 with thread, we can sometimes get + # `super() argument 1 must be type, not None`; this happens on module + # cleanup. # # The third is similar to the second: "AssertionError: # ...\nIOError: close() called during concurrent operation on diff --git a/src/gevent/threadpool.py b/src/gevent/threadpool.py index 5b7a834af..291e4b74f 100644 --- a/src/gevent/threadpool.py +++ b/src/gevent/threadpool.py @@ -6,6 +6,7 @@ import os import sys + from greenlet import greenlet as RawGreenlet from gevent import monkey @@ -117,6 +118,20 @@ def __fixup_hub_before_block(self): hub.periodic_monitoring_thread.ignore_current_greenlet_blocking() self._hub_of_worker = hub + @staticmethod + def __print_tb(tb, stderr): + # Extracted from traceback to avoid accessing any module + # globals (these sometimes happen during interpreter shutdown; + # see test__subprocess_interrupted) + while tb is not None: + f = tb.tb_frame + lineno = tb.tb_lineno + co = f.f_code + filename = co.co_filename + name = co.co_name + print(' File "%s", line %d, in %s' % (filename, lineno, name), + file=stderr) + def __run_task(self, func, args, kwargs, thread_result): try: thread_result.set(func(*args, **kwargs)) @@ -128,25 +143,31 @@ def __run_task(self, func, args, kwargs, thread_result): def run(self): # pylint:disable=too-many-branches task = None + exc_info = sys.exc_info + fixup_hub_before_block = self.__fixup_hub_before_block + task_queue_get = self._task_queue.get + run_task = self.__run_task + task_queue_done = self._task_queue.task_done try: while 1: # tiny bit faster than True on Py2 - self.__fixup_hub_before_block() + fixup_hub_before_block() - task = self._task_queue.get() + task = task_queue_get() try: if task is None: return - self.__run_task(*task) + run_task(*task) finally: task = None - self._task_queue.task_done() + task_queue_done() except Exception as e: # pylint:disable=broad-except print( - "Failed to run worker thread. Task=%r Exception=%s%r" % ( - task, e, e + "Failed to run worker thread. Task=%r Exception=%r" % ( + task, e ), file=self._stderr) + self.__print_tb(exc_info()[-1], self._stderr) finally: # Re-check for the hub in case the task created it but then # failed.