[3.6] bpo-31970: Reduce performance overhead of asyncio debug mode. (GH-4314) (#4322)

* bpo-31970: Reduce performance overhead of asyncio debug mode..
(cherry picked from commit 921e9432a1461bbf312c9c6dcc2b916be6c05fa0)

diff --git a/Lib/asyncio/base_events.py b/Lib/asyncio/base_events.py
index a4967b854c5e68d9d689d0a446ba091aee0e2ba6..8cc655c79f8b5868cba55c9aab1c48bc348b3475 100644 (file)
--- a/Lib/asyncio/base_events.py
+++ b/Lib/asyncio/base_events.py
@@ -1222,6 +1222,11 @@ class BaseEventLoop(events.AbstractEventLoop):
         handler is set, and can be called by a custom exception
         handler that wants to defer to the default behavior.
 
+        This default handler logs the error message and other
+        context-dependent information.  In debug mode, a truncated
+        stack trace is also appended showing where the given object
+        (e.g. a handle or future or task) was created, if any.
+
         The context parameter has the same meaning as in
         `call_exception_handler()`.
         """

diff --git a/Lib/asyncio/constants.py b/Lib/asyncio/constants.py
index f9e123281e2e3b204dbae6f09f6b22fe06ed06e5..e74209e149d7ce17901470820345db314630c2c2 100644 (file)
--- a/Lib/asyncio/constants.py
+++ b/Lib/asyncio/constants.py
@@ -5,3 +5,8 @@ LOG_THRESHOLD_FOR_CONNLOST_WRITES = 5
 
 # Seconds to wait before retrying accept().
 ACCEPT_RETRY_DELAY = 1
+
+# Number of stack entries to capture in debug mode.
+# The large the number, the slower the operation in debug mode
+# (see extract_stack() in events.py)
+DEBUG_STACK_DEPTH = 10

diff --git a/Lib/asyncio/coroutines.py b/Lib/asyncio/coroutines.py
index b2adaadfc2cd6d120eec1748068a9f1b048485f7..520a309f846049e9b9bb719037e0a54f34798ace 100644 (file)
--- a/Lib/asyncio/coroutines.py
+++ b/Lib/asyncio/coroutines.py
@@ -10,6 +10,7 @@ import traceback
 import types
 
 from . import compat
+from . import constants
 from . import events
 from . import base_futures
 from .log import logger
@@ -91,7 +92,7 @@ class CoroWrapper:
         assert inspect.isgenerator(gen) or inspect.iscoroutine(gen), gen
         self.gen = gen
         self.func = func  # Used to unwrap @coroutine decorator
-        self._source_traceback = traceback.extract_stack(sys._getframe(1))
+        self._source_traceback = events.extract_stack(sys._getframe(1))
         self.__name__ = getattr(gen, '__name__', None)
         self.__qualname__ = getattr(gen, '__qualname__', None)
 
@@ -183,8 +184,9 @@ class CoroWrapper:
             tb = getattr(self, '_source_traceback', ())
             if tb:
                 tb = ''.join(traceback.format_list(tb))
-                msg += ('\nCoroutine object created at '
-                        '(most recent call last):\n')
+                msg += (f'\nCoroutine object created at '
+                        f'(most recent call last, truncated to '
+                        f'{constants.DEBUG_STACK_DEPTH} last lines):\n')
                 msg += tb.rstrip()
             logger.error(msg)
 

diff --git a/Lib/asyncio/events.py b/Lib/asyncio/events.py
index d41f3f5b7559d26be739dee29d33fe4b7302e6f9..05dc8969f44a6a9b526117f82b1a42458f78e8c2 100644 (file)
--- a/Lib/asyncio/events.py
+++ b/Lib/asyncio/events.py
@@ -19,7 +19,8 @@ import sys
 import threading
 import traceback
 
-from asyncio import compat
+from . import compat
+from . import constants
 
 
 def _get_function_source(func):
@@ -77,6 +78,23 @@ def _format_callback_source(func, args):
     return func_repr
 
 
+def extract_stack(f=None, limit=None):
+    """Replacement for traceback.extract_stack() that only does the
+    necessary work for asyncio debug mode.
+    """
+    if f is None:
+        f = sys._getframe().f_back
+    if limit is None:
+        # Limit the amount of work to a reasonable amount, as extract_stack()
+        # can be called for each coroutine and future in debug mode.
+        limit = constants.DEBUG_STACK_DEPTH
+    stack = traceback.StackSummary.extract(traceback.walk_stack(f),
+                                           limit=limit,
+                                           lookup_lines=False)
+    stack.reverse()
+    return stack
+
+
 class Handle:
     """Object returned by callback registration methods."""
 
@@ -90,7 +108,7 @@ class Handle:
         self._cancelled = False
         self._repr = None
         if self._loop.get_debug():
-            self._source_traceback = traceback.extract_stack(sys._getframe(1))
+            self._source_traceback = extract_stack(sys._getframe(1))
         else:
             self._source_traceback = None
 

diff --git a/Lib/asyncio/futures.py b/Lib/asyncio/futures.py
index 511a14b97bce240e1f87f91792f56dbb5775c091..047b132fcbb81904e6a1282f70ddd96ea7fe29ee 100644 (file)
--- a/Lib/asyncio/futures.py
+++ b/Lib/asyncio/futures.py
@@ -159,7 +159,7 @@ class Future:
             self._loop = loop
         self._callbacks = []
         if self._loop.get_debug():
-            self._source_traceback = traceback.extract_stack(sys._getframe(1))
+            self._source_traceback = events.extract_stack(sys._getframe(1))
 
     _repr_info = base_futures._future_repr_info
 

diff --git a/Lib/test/test_asyncio/test_tasks.py b/Lib/test/test_asyncio/test_tasks.py
index 243faf6b04995875f2a76ca8040635c06a086b44..42da1fa19548f1c54458dfec824526ebf0b7b7e6 100644 (file)
--- a/Lib/test/test_asyncio/test_tasks.py
+++ b/Lib/test/test_asyncio/test_tasks.py
@@ -1918,7 +1918,7 @@ class BaseTaskTests:
 
         regex = (r'^<CoroWrapper %s\(?\)? .* at %s:%s, .*> '
                     r'was never yielded from\n'
-                 r'Coroutine object created at \(most recent call last\):\n'
+                 r'Coroutine object created at \(most recent call last, truncated to \d+ last lines\):\n'
                  r'.*\n'
                  r'  File "%s", line %s, in test_coroutine_never_yielded\n'
                  r'    coro_noop\(\)$'

diff --git a/Misc/NEWS.d/next/Library/2017-11-07-14-20-09.bpo-31970.x4EN_9.rst b/Misc/NEWS.d/next/Library/2017-11-07-14-20-09.bpo-31970.x4EN_9.rst
new file mode 100644 (file)
index 0000000..d0c0fb4
--- /dev/null
+++ b/Misc/NEWS.d/next/Library/2017-11-07-14-20-09.bpo-31970.x4EN_9.rst
@@ -0,0 +1 @@
+Reduce performance overhead of asyncio debug mode.