-
-
Notifications
You must be signed in to change notification settings - Fork 29.9k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
bpo-31970: Reduce performance overhead of asyncio debug mode. #4314
Conversation
Never mind, I saw the explanation in the issue. |
Lib/asyncio/events.py
Outdated
# This is heuristically the max number of entries we're gonna pop + 1 | ||
# (we're only interested in displaying the top of stack) | ||
# If this is too small, tests will fail. | ||
limit = 4 |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Can we bump this to 10? It's a debug mode after all, and seeing only 2-3 lines in traceback is sometimes not enough.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The traceback is never displayed. It's only used for Future.__repr__
, which prints the line at which the future was created (i.e. the top-of-stack).
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
IIRC Task.__del__
and CoroWrapper
pass it to the loop's logger to print some debug info. In which case the full traceback would be printed to the user, no?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Oh, yes, you're right. I agree with bumping to 10 then.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Can you add it as a constant to asyncio/constants.py
? Also, we need to update loop.default_exception_handler()
method to say that we only display 10 topmost frames.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'd only bump 4 to 10.
Depends on your usage :-) With a small stack it is 2x faster. With a 50-deep stack it is 10x faster. Here is a snippet: |
+1 for 10. Or maybe at least 7. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Can you add it as a constant to asyncio/constants.py
? Also, we need to update loop.default_exception_handler()
method to say that we only display 10 topmost frames.
A Python core developer has requested some changes be made to your pull request before we can consider merging it. If you could please address their requests along with any other requests in other reviews from core developers that would be appreciated. Once you have made the requested changes, please leave a comment on this pull request containing the phrase |
@Mariatta I think I just saw a tiny bug in bedevere-bot:
The label should only be removed when all reviewers clear the PR. |
@1st1 are you ok with backporting to 3.6 as well? |
Yeah, I think it's fine. |
Lib/test/test_asyncio/test_tasks.py
Outdated
@@ -1981,7 +1981,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, maybe truncated\):\n' |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Can we replace "maybe truncated" to "truncated to {} last lines"?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
"truncated to {DEBUG_STACK_DEPTH} frames" if I understood correctly
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
If I understand correctly, getting the previous behaviour is as simple as "asyncio.constants.DEBUG_STACK_DEPTH = None". Right?
Maybe mention this constant in Doc/library/asyncio-dev.rst to explain how to not get truncated tracebacks.
Lib/test/test_asyncio/test_tasks.py
Outdated
@@ -1981,7 +1981,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, maybe truncated\):\n' |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
"truncated to {DEBUG_STACK_DEPTH} frames" if I understood correctly
|
||
# 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) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
You may document that this value is passed to the limit parameter of traceback.extract_stack(), or maybe just document that None means "no limit".
If you document the constant, I'm ok to merge this change. |
I'm not sure the constant should be documented. Other constants are not. They don't seem meant to be changed by users. |
I don't think we need to document every constant we have any asyncio. Those who debug super problematic cases can always go and look at the implementation and bump the number to 10000 themselves. For an average asyncio user all these little details about debug mode and its constants in the documentation is just noise. |
I'm not proposing to document all constants. I asked you to document the constant since you change the behaviour of the debug mode of asyncio. It can be surprising to upgrade Python and suddenly tracebacks are truncated: how are you supposed to deal with this? Dig into asyncio source code to understand? |
Read the error message? It clearly says the traceback is truncated :-) |
-1 for constant documenting |
I think so. Try maybe yourself by truncating to 1 frame: are you always able to find the bug? :-) Anyway, in case of doubt, I prefer to document the option. Note: I'm planning to make faulthandler configurable to allow to display more than 100 frames, 100 threads and strings longer than 500 characters... But nobody complained. Maybe 100 frames is enough for everyone, or people who hit such limitations are able to modify CPython and recompile it :-) Well, 100 frames is much higher than 10 frames :-) I was going to say that my tracemalloc module was also limited to 100 frames, but I see that I removed this limitation to use a dynamically allocated array :-) |
Thank you @Haypo :-) |
Thanks @pitrou for the PR 🌮🎉.. I'm working now to backport this PR to: 3.6. |
Sorry, @pitrou, I could not cleanly backport this to |
GH-4322 is a backport of this pull request to the 3.6 branch. |
…ythonGH-4314) * bpo-31970: Reduce performance overhead of asyncio debug mode.. (cherry picked from commit 921e943)
…#4314) * bpo-31970: Reduce performance overhead of asyncio debug mode.
https://bugs.python.org/issue31970