[Python-checkins] [3.6] bpo-31970: Reduce performance overhead of asyncio debug mode. (GH-4314) (#4322)
Antoine Pitrou
webhook-mailer at python.org
Tue Nov 7 11:50:53 EST 2017
https://github.com/python/cpython/commit/d8d218ffda6b7569625ff9edadbbc9a2b1055e32
commit: d8d218ffda6b7569625ff9edadbbc9a2b1055e32
branch: 3.6
author: Antoine Pitrou <pitrou at free.fr>
committer: GitHub <noreply at github.com>
date: 2017-11-07T17:50:48+01:00
summary:
[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)
files:
A Misc/NEWS.d/next/Library/2017-11-07-14-20-09.bpo-31970.x4EN_9.rst
M Lib/asyncio/base_events.py
M Lib/asyncio/constants.py
M Lib/asyncio/coroutines.py
M Lib/asyncio/events.py
M Lib/asyncio/futures.py
M Lib/test/test_asyncio/test_tasks.py
diff --git a/Lib/asyncio/base_events.py b/Lib/asyncio/base_events.py
index a4967b854c5..8cc655c79f8 100644
--- a/Lib/asyncio/base_events.py
+++ b/Lib/asyncio/base_events.py
@@ -1222,6 +1222,11 @@ def default_exception_handler(self, context):
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 f9e123281e2..e74209e149d 100644
--- a/Lib/asyncio/constants.py
+++ b/Lib/asyncio/constants.py
@@ -5,3 +5,8 @@
# 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 b2adaadfc2c..520a309f846 100644
--- a/Lib/asyncio/coroutines.py
+++ b/Lib/asyncio/coroutines.py
@@ -10,6 +10,7 @@
import types
from . import compat
+from . import constants
from . import events
from . import base_futures
from .log import logger
@@ -91,7 +92,7 @@ def __init__(self, gen, func=None):
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 @@ def __del__(self):
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 d41f3f5b755..05dc8969f44 100644
--- a/Lib/asyncio/events.py
+++ b/Lib/asyncio/events.py
@@ -19,7 +19,8 @@
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 @@ def __init__(self, callback, args, loop):
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 511a14b97bc..047b132fcbb 100644
--- a/Lib/asyncio/futures.py
+++ b/Lib/asyncio/futures.py
@@ -159,7 +159,7 @@ def __init__(self, *, loop=None):
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 243faf6b049..42da1fa1954 100644
--- a/Lib/test/test_asyncio/test_tasks.py
+++ b/Lib/test/test_asyncio/test_tasks.py
@@ -1918,7 +1918,7 @@ def coro_noop():
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
index 00000000000..d0c0fb45e3e
--- /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.
More information about the Python-checkins
mailing list