Printing RecursionError results in RecursionError

[vlad17]

BPO	43048
Nosy	@terryjreedy, @ambv, @iritkatriel, @vlad17
PRs	[3.9] bpo-43048: RecursionError traceback RecursionError bugfix for cpy3.9 (GH-24460) #24460
Superseder	bpo-42848: asyncio produces an unexpected traceback with recursive getattribute
Files	exc.py: minimal python file reconstruction

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2021-07-12.16:01:52.543>
created_at = <Date 2021-01-28.01:45:37.359>
labels = ['easy', 'type-bug', 'library', '3.9']
title = 'Printing RecursionError results in RecursionError'
updated_at = <Date 2021-07-12.16:01:52.543>
user = 'https://github.com/vlad17'

bugs.python.org fields:

activity = <Date 2021-07-12.16:01:52.543>
actor = 'lukasz.langa'
assignee = 'none'
closed = True
closed_date = <Date 2021-07-12.16:01:52.543>
closer = 'lukasz.langa'
components = ['Library (Lib)']
creation = <Date 2021-01-28.01:45:37.359>
creator = 'vlad2'
dependencies = []
files = ['49769']
hgrepos = []
issue_num = 43048
keywords = ['patch', 'easy']
message_count = 11.0
messages = ['385828', '385847', '385938', '385949', '385991', '386082', '386125', '386127', '386132', '386154', '397333']
nosy_count = 4.0
nosy_names = ['terry.reedy', 'lukasz.langa', 'iritkatriel', 'vlad2']
pr_nums = ['24460']
priority = 'normal'
resolution = 'duplicate'
stage = 'resolved'
status = 'closed'
superseder = '42848'
type = 'behavior'
url = 'https://bugs.python.org/issue43048'
versions = ['Python 3.9']

[vlad17]

Python's standard logger provides an exception() method, which is to be called from except blocks to log out exception traces by pulling from sys.exc_info().

Per https://github.com/python/cpython/blob/3.9/Lib/logging/__init__.py#L617 , logger.exception('my message') eventually boils down to something like traceback.print_exception(ei[0], ei[1], ei[2], None, some_buffer) where ei is the sys.exc_info().

However, the traceback code generates that printout by constructing a TracebackException recursively for every except context.

In turn, if a RecursionError was generated from an exception thrown across many except blocks, the TracebackException construction itself will have a RecursionError. This is particularly bad in cases where you'd want to capture this failure information, such as when you're printing the exception, since you'll never find out about the originating error.

Certain (well-used) libraries rely on try/except for control flow, and occasionally do recurse in their except blocks, so such exceptions are not hypothetical.

A solution to this might be to avoid constructing a TracebackException, and instead unwind traceback context using a while loop.

[iritkatriel]

This looks like a duplicate of bpo-42848 which was fixed in 3.10.

[terryjreedy]

With 3.9, exc.py produces for me

Traceback (most recent call last):
  File "F:\Python\a\tem3.py", line 3, in f
    raise ValueError('hello')
ValueError: hello

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "F:\Python\a\tem3.py", line 3, in f
    raise ValueError('hello')
ValueError: hello
...
During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "F:\Python\a\tem3.py", line 11, in <module>
    f()
  File "F:\Python\a\tem3.py", line 5, in f
    f()
  File "F:\Python\a\tem3.py", line 5, in f
    f()
  File "F:\Python\a\tem3.py", line 5, in f
    f()
  [Previous line repeated 992 more times]
  File "F:\Python\a\tem3.py", line 3, in f
    raise ValueError('hello')
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:\Programs\Python310\lib\runpy.py", line 197, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "C:\Programs\Python310\lib\runpy.py", line 87, in _run_code
    exec(code, run_globals)
  File "F:\Python\a\tem3.py", line 14, in <module>
    print_exception(exc_info[0], exc_info[1], exc_info[2], None)
  File "C:\Programs\Python310\lib\traceback.py", line 113, in print_exception
    for line in TracebackException(
  File "C:\Programs\Python310\lib\traceback.py", line 503, in __init__
    context = TracebackException(
  File "C:\Programs\Python310\lib\traceback.py", line 503, in __init__
    context = TracebackException(
  File "C:\Programs\Python310\lib\traceback.py", line 503, in __init__
    context = TracebackException(
  [Previous line repeated 494 more times]
RecursionError: maximum recursion depth exceeded

This ends the same way as in bpo-42848.

The patch in bpo-42848 will appear in 3.10.0a5 in March. Guido and Irit decided not to backport at the patch is as much a refactoring as a fix.

On a fresh repository build, exc.py ends with

Traceback (most recent call last):
  File "f:\python\a\tem3.py", line 3, in f
    raise ValueError('hello')
ValueError: hello

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "f:\python\a\tem3.py", line 11, in <module>
    f()
  File "f:\python\a\tem3.py", line 5, in f
    f()
  File "f:\python\a\tem3.py", line 5, in f
    f()
  File "f:\python\a\tem3.py", line 5, in f
    f()
  [Previous line repeated 995 more times]
  File "f:\python\a\tem3.py", line 3, in f
    raise ValueError('hello')
RecursionError: maximum recursion depth exceeded while calling a Python object
got to the finish line!

I believe this is the expected improvement.

[vlad17]

I agree with both the duplicate classification and am glad the fix works in 3.10. Thanks all for the responses.

Given the issue can be triggered with a fairly benign setup (pandas triggers such an error, and logger.exception is idiomatic), I do think backport should be worth consideration, but maybe I'm overindexing on the frequency of such exceptions in the wild.

[iritkatriel]

Maybe it is worth doing something less invasive in 3.9, such as catching the recursion error and truncating the output?

[vlad17]

A simple catch may not work (the very first TracebackException is the one
that gets the RecursionError during initialization of its __context__), but
one thing I was thinking about was walking the __context__ pointers and
nulling out anything past the sys.getrecursionlimit() with a warning.

On Sat, Jan 30, 2021 at 10:00 AM Irit Katriel <report@bugs.python.org>
wrote:

Change by Irit Katriel <iritkatriel@yahoo.com>:

----------
keywords: +easy

---

Python tracker <report@bugs.python.org>
<https://bugs.python.org/issue43048\>

---

[iritkatriel]

I meant to catch the exception in the constructor’s recursive call, and if necessary then the same again in format (if there are more function calls per exception in format, it will be necessary. The unit test from the 3.10 patch will tell).

Would that not work?

[vlad17]

Oh, yes, I suppose, that'll truncate to just the first TracebackException.

On Mon, Feb 1, 2021 at 4:38 PM Irit Katriel <report@bugs.python.org> wrote:

Irit Katriel <iritkatriel@yahoo.com> added the comment:

I meant to catch the exception in the constructor’s recursive call, and if
necessary then the same again in format (if there are more function calls
per exception in format, it will be necessary. The unit test from the 3.10
patch will tell).

Would that not work?

----------

---

Python tracker <report@bugs.python.org>
<https://bugs.python.org/issue43048\>

---

[iritkatriel]

It should truncate at the call that raised the recursion error, not the first one. Do you want to create a patch?

[vlad17]

Yep, you're right. I'd be happy to (but I've never done it before, so
please give me some time).

On Tue, Feb 2, 2021 at 12:35 AM Irit Katriel <report@bugs.python.org> wrote:

Irit Katriel <iritkatriel@yahoo.com> added the comment:

It should truncate at the call that raised the recursion error, not the
first one. Do you want to create a patch?

----------

---

Python tracker <report@bugs.python.org>
<https://bugs.python.org/issue43048\>

---

[ambv]

New changeset 489c273 by Vladimir Feinberg in branch '3.9':
[3.9] bpo-43048: RecursionError traceback RecursionError bugfix for cpy3.9 (GH-24460) (bpo-24460)
489c273