Issue42848
This issue tracker has been migrated to GitHub,
and is currently read-only.
For more information,
see the GitHub FAQs in the Python's Developer Guide.
Created on 2021-01-07 02:10 by asleep-cult, last changed 2022-04-11 14:59 by admin. This issue is now closed.
| Pull Requests | |||
|---|---|---|---|
| URL | Status | Linked | Edit |
| PR 24158 | merged | iritkatriel, 2021-01-08 00:42 | |
| Messages (14) | |||
|---|---|---|---|
| msg384551 - (view) | Author: asleep-cult (asleep-cult) | Date: 2021-01-07 02:10 | |
The code below produces an unexpected traceback format that makes the source of an error very hard to find, this more than likely happens in less specific situations but this is how I came across it. I'm also not sure if this is an issue with asyncio, logging or the traceback module.
import asyncio
class Bar:
def __init__(self):
self.y = None
class Foo:
def __init__(self):
self._bar = Bar()
self.y
def __getattribute__(self, name):
try:
attr = super().__getattribute__(name)
except AttributeError as e:
try:
attr = self.ooops_spelled_bar_wrong.__getattribute__(name)
except AttributeError:
raise e
return attr
async def foo():
Foo()
loop = asyncio.get_event_loop()
loop.create_task(foo())
loop.run_forever()
Traceback:
Exception in default exception handler
Traceback (most recent call last):
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\asyncio\base_events.py", line 1733, in call_exception_handler self.default_exception_handler(context)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\asyncio\base_events.py", line 1707, in default_exception_handler
logger.error('\n'.join(log_lines), exc_info=exc_info)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 1471, in error
self._log(ERROR, msg, args, **kwargs)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 1585, in _log
self.handle(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 1595, in handle
self.callHandlers(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 1665, in callHandlers
lastResort.handle(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 950, in handle
self.emit(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 1081, in emit
msg = self.format(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 925, in format
return fmt.format(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 672, in format
record.exc_text = self.formatException(record.exc_info)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 622, in formatException
traceback.print_exception(ei[0], ei[1], tb, None, sio)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 103, in print_exception
for line in TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
[Previous line repeated 488 more times]
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 476, in __init__
_seen.add(id(exc_value))
RecursionError: maximum recursion depth exceeded while calling a Python object
```
The code below procures the expected traceback
import traceback
class Bar:
def __init__(self):
self.y = None
class Foo:
def __init__(self):
self._bar = Bar()
self.y
def __getattribute__(self, name):
try:
attr = super().__getattribute__(name)
except AttributeError as e:
try:
attr = self.ooops_spelled_bar_wrong.__getattribute__(name)
except AttributeError:
raise e
return attr
try:
Foo()
except:
traceback.print_exc()
Traceback:
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "c:/Development/test/test.py", line 15, in __getattribute__
attr = super().__getattribute__(name)
AttributeError: 'Foo' object has no attribute 'ooops_spelled_bar_wrong'
# The part above is repeated hundreds of times
Traceback (most recent call last):
File "c:/Development/test/test.py", line 24, in <module>
Foo()
File "c:/Development/test/test.py", line 11, in __init__
self.y
File "c:/Development/test/test.py", line 18, in __getattribute__
attr = self.ooops_spelled_bar_wrong.__getattribute__(name)
File "c:/Development/test/test.py", line 18, in __getattribute__
attr = self.ooops_spelled_bar_wrong.__getattribute__(name)
File "c:/Development/test/test.py", line 18, in __getattribute__
attr = self.ooops_spelled_bar_wrong.__getattribute__(name)
[Previous line repeated 992 more times]
File "c:/Development/test/test.py", line 15, in __getattribute__
attr = super().__getattribute__(name)
RecursionError: maximum recursion depth exceeded while calling a Python object
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "c:/Development/test/test.py", line 26, in <module>
traceback.print_exc()
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 163, in print_exc
print_exception(*sys.exc_info(), limit=limit, file=file, chain=chain)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 103, in print_exception
for line in TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
[Previous line repeated 495 more times]
RecursionError: maximum recursion depth exceeded
|
|||
| msg384553 - (view) | Author: Guido van Rossum (gvanrossum) * ![]() |
Date: 2021-01-07 02:32 | |
Is there anything specific about __getattribute__ here? Wouldn't you have the same issue for *any* function that raises RecursionError called inside an async def? |
|||
| msg384554 - (view) | Author: asleep-cult (asleep-cult) | Date: 2021-01-07 03:03 | |
I did test it with a simple recursive function but a more realistic test confirms that its not just __getattribute__ (which makes sense)
import asyncio
class Test(Exception):
...
def x():
raise Test('Hello World!')
def bar():
try:
x()
except Test as e:
try:
bar()
except Test as e:
raise e
async def foo():
bar()
loop = asyncio.get_event_loop()
loop.create_task(foo())
loop.run_forever()
Traceback:
Exception in default exception handler
Traceback (most recent call last):
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\asyncio\base_events.py", line 1733, in call_exception_handler self.default_exception_handler(context)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\asyncio\base_events.py", line 1707, in default_exception_handler
logger.error('\n'.join(log_lines), exc_info=exc_info)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 1471, in error
self._log(ERROR, msg, args, **kwargs)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 1585, in _log
self.handle(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 1595, in handle
self.callHandlers(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 1665, in callHandlers
lastResort.handle(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 950, in handle
self.emit(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 1081, in emit
msg = self.format(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 925, in format
return fmt.format(record)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 672, in format
record.exc_text = self.formatException(record.exc_info)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\logging\__init__.py", line 622, in formatException
traceback.print_exception(ei[0], ei[1], tb, None, sio)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 103, in print_exception
for line in TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
[Previous line repeated 488 more times]
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 476, in __init__
_seen.add(id(exc_value))
RecursionError: maximum recursion depth exceeded while calling a Python object
The Test('Hello World') exception is suppressed entirely
try:
bar()
except:
traceback.print_exc()
but when running it this way the traceback looks like this:
File "c:/Development/test/test.py", line 7, in x
raise Test('Hello World!')
RecursionError: maximum recursion depth exceeded while calling a Python object
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "c:/Development/test/test.py", line 21, in <module>
traceback.print_exc()
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 163, in print_exc
print_exception(*sys.exc_info(), limit=limit, file=file, chain=chain)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 103, in print_exception
for line in TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
[Previous line repeated 495 more times]
RecursionError: maximum recursion depth exceeded
|
|||
| msg384555 - (view) | Author: asleep-cult (asleep-cult) | Date: 2021-01-07 03:10 | |
Didn't show enough of the traceback to show that the latter does not suppress the Test exception
Traceback (most recent call last):
File "c:/Development/test/test.py", line 11, in bar
x()
File "c:/Development/test/test.py", line 7, in x
raise Test('Hello World!')
__main__.Test: Hello World!
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "c:/Development/test/test.py", line 19, in <module>
bar()
File "c:/Development/test/test.py", line 14, in bar
bar()
File "c:/Development/test/test.py", line 14, in bar
bar()
File "c:/Development/test/test.py", line 14, in bar
bar()
[Previous line repeated 994 more times]
File "c:/Development/test/test.py", line 11, in bar
x()
File "c:/Development/test/test.py", line 7, in x
raise Test('Hello World!')
RecursionError: maximum recursion depth exceeded while calling a Python object
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "c:/Development/test/test.py", line 21, in <module>
traceback.print_exc()
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 163, in print_exc
print_exception(*sys.exc_info(), limit=limit, file=file, chain=chain)
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 103, in print_exception
for line in TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
File "C:\Users\User\AppData\Local\Programs\Python\Python38\lib\traceback.py", line 493, in __init__
context = TracebackException(
[Previous line repeated 495 more times]
RecursionError: maximum recursion depth exceeded
|
|||
| msg384556 - (view) | Author: Guido van Rossum (gvanrossum) * ![]() |
Date: 2021-01-07 03:17 | |
The recursion error is actually inside the traceback module. The reason is that the code there calls itself recursively for each level of context. Since bar() builds up an endless chain of contexts as it calls itself recursively, that chain is very long. Given that, do you feel comfortable trying to come up with a fix and submit a PR? |
|||
| msg384557 - (view) | Author: asleep-cult (asleep-cult) | Date: 2021-01-07 03:33 | |
I'm not sure I have a deep enough understanding of how this works, so no |
|||
| msg384558 - (view) | Author: Guido van Rossum (Guido.van.Rossum) | Date: 2021-01-07 03:52 | |
No problem. Riot, are you interested in this? |
|||
| msg384559 - (view) | Author: Guido van Rossum (Guido.van.Rossum) | Date: 2021-01-07 03:53 | |
I meant Irit. Silly autocorrect. |
|||
| msg384574 - (view) | Author: Irit Katriel (iritkatriel) * ![]() |
Date: 2021-01-07 10:47 | |
Yes I'll have a look. |
|||
| msg384626 - (view) | Author: Irit Katriel (iritkatriel) * ![]() |
Date: 2021-01-08 00:41 | |
So, we have a contact chain of length almost equal to the recursion limit, which is too much to process recursively in python (in c it does work, hence the difference between the outputs of the OP's two scripts). The PR removes recursion from TracebackException (in constructor as well as in format()). The code is less readable and I'm not sure this case is worth that. Should we instead truncate the output, ie add a limit on the recursion depth? (note that in this case this would remove the last "recursion depth exceeded" exception and show only some of the repetitive ones). |
|||
| msg384841 - (view) | Author: Irit Katriel (iritkatriel) * ![]() |
Date: 2021-01-11 15:18 | |
I've simplified the format() code in the PR, based on the observation that only one chained exception is ever emitted. I think it's reasonably simple now. |
|||
| msg384980 - (view) | Author: Guido van Rossum (gvanrossum) * ![]() |
Date: 2021-01-12 22:14 | |
New changeset 6dfd1734f5b230bb8fbd2a9df806c1333b6652a8 by Irit Katriel in branch 'master': bpo-42848: remove recursion from TracebackException (GH-24158) https://github.com/python/cpython/commit/6dfd1734f5b230bb8fbd2a9df806c1333b6652a8 |
|||
| msg384990 - (view) | Author: Guido van Rossum (gvanrossum) * ![]() |
Date: 2021-01-13 00:35 | |
Will be fixed in 3.10. I prefer not to backport the solution (Irit, do you agree?) |
|||
| msg385008 - (view) | Author: Irit Katriel (iritkatriel) * ![]() |
Date: 2021-01-13 08:38 | |
Yes, I agree this is more of a refactor than a bugfix. |
|||
| History | |||
|---|---|---|---|
| Date | User | Action | Args |
| 2022-04-11 14:59:39 | admin | set | github: 87014 |
| 2021-01-28 12:54:15 | iritkatriel | link | issue43048 superseder |
| 2021-01-13 08:38:49 | iritkatriel | set | messages:
+ msg385008 versions: + Python 3.10, - Python 3.8 |
| 2021-01-13 00:35:43 | gvanrossum | set | status: open -> closed resolution: fixed messages: + msg384990 stage: patch review -> resolved |
| 2021-01-12 22:14:35 | gvanrossum | set | messages: + msg384980 |
| 2021-01-11 17:59:10 | iritkatriel | set | nosy:
+ rbcollins |
| 2021-01-11 15:18:15 | iritkatriel | set | messages: + msg384841 |
| 2021-01-08 00:42:38 | iritkatriel | set | keywords:
+ patch stage: patch review pull_requests: + pull_request22986 |
| 2021-01-08 00:41:45 | iritkatriel | set | messages: + msg384626 |
| 2021-01-07 10:47:41 | iritkatriel | set | messages: + msg384574 |
| 2021-01-07 03:53:22 | Guido.van.Rossum | set | messages: + msg384559 |
| 2021-01-07 03:52:38 | Guido.van.Rossum | set | nosy:
+ iritkatriel, Guido.van.Rossum messages: + msg384558 |
| 2021-01-07 03:33:06 | asleep-cult | set | messages: + msg384557 |
| 2021-01-07 03:17:39 | gvanrossum | set | messages: + msg384556 |
| 2021-01-07 03:10:25 | asleep-cult | set | messages: + msg384555 |
| 2021-01-07 03:03:07 | asleep-cult | set | messages: + msg384554 |
| 2021-01-07 02:32:53 | gvanrossum | set | nosy:
+ gvanrossum messages: + msg384553 |
| 2021-01-07 02:10:12 | asleep-cult | create | |
