Skip to content
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

Recursive logging crashes Interpreter in Python 3 #80453

Closed
SaimRaza mannequin opened this issue Mar 12, 2019 · 10 comments
Closed

Recursive logging crashes Interpreter in Python 3 #80453

SaimRaza mannequin opened this issue Mar 12, 2019 · 10 comments
Labels
3.7 (EOL) end of life 3.8 only security fixes stdlib Python modules in the Lib dir type-crash A hard crash of the interpreter, possibly with a core dump

Comments

@SaimRaza
Copy link
Mannequin

SaimRaza mannequin commented Mar 12, 2019

BPO 36272
Nosy @brettcannon, @vsajip, @remilapeyre, @tirkarthi
PRs
  • bpo-36272: Logging ignore recursion error #12312
  • [3.6] bpo-36272: Logging now propagates RecursionError (GH-12312) #12339
  • [3.7] bpo-36272: Logging now propagates RecursionError (GH-12312) #12391
  • 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 2019-03-18.14:26:24.455>
    created_at = <Date 2019-03-12.14:47:03.120>
    labels = ['3.8', '3.7', 'library', 'type-crash']
    title = 'Recursive logging crashes Interpreter in Python 3'
    updated_at = <Date 2019-03-18.14:26:24.455>
    user = 'https://bugs.python.org/SaimRaza'

    bugs.python.org fields:

    activity = <Date 2019-03-18.14:26:24.455>
    actor = 'vinay.sajip'
    assignee = 'none'
    closed = True
    closed_date = <Date 2019-03-18.14:26:24.455>
    closer = 'vinay.sajip'
    components = ['Library (Lib)']
    creation = <Date 2019-03-12.14:47:03.120>
    creator = 'Saim Raza'
    dependencies = []
    files = []
    hgrepos = []
    issue_num = 36272
    keywords = ['patch']
    message_count = 10.0
    messages = ['337747', '337748', '337842', '337843', '337844', '337845', '337879', '337880', '337971', '338227']
    nosy_count = 5.0
    nosy_names = ['brett.cannon', 'vinay.sajip', 'remi.lapeyre', 'xtreak', 'Saim Raza']
    pr_nums = ['12312', '12339', '12391']
    priority = 'normal'
    resolution = 'fixed'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = 'crash'
    url = 'https://bugs.python.org/issue36272'
    versions = ['Python 3.7', 'Python 3.8']

    @SaimRaza
    Copy link
    Mannequin Author

    SaimRaza mannequin commented Mar 12, 2019

    Following code logs an error and calls itself leading to stack overflow and eventually core dump in Python 3.6.

    >>> import logging
    >>> def rec():
    ...     logging.error("foo")
    ...     rec()
    >>> rec()

    [1] 101641 abort (core dumped) python3
    FTR, this doesn't crash Python 2.7.

    Attaching the error (condensed) in Python 3.6:

    ERROR:root:foo
    ...
    --- Logging error ---

    Traceback (most recent call last):
    ...
    RecursionError: maximum recursion depth exceeded in comparison
    ...
    Fatal Python error: Cannot recover from stack overflow.
    ...
    [1]    101641 abort (core dumped)  python3
    Python 2.7:

    RuntimeError: maximum recursion depth exceeded
    But no core dump in Python 2.7.

    FTR, the error above with Python 3.6 will come into play if the log level is set to logging.ERROR. Similarly for other log levels.

    @SaimRaza SaimRaza mannequin added stdlib Python modules in the Lib dir type-crash A hard crash of the interpreter, possibly with a core dump labels Mar 12, 2019
    @tirkarthi
    Copy link
    Member

    I am not sure this is related to logging and looks similar to bpo-35542 except stack (depends on OS) is exhausted without setrecursionlimit(). What does below return?

    def rec():
        rec()
    
    rec()

    @SaimRaza
    Copy link
    Mannequin Author

    SaimRaza mannequin commented Mar 13, 2019

    Stack exhaustion doesn't seem to be due to be the root cause. A simple recursive function doesn't crash the interpreter in Python 3.6.

    >>> def rec(): rec()
    >>> rec()
    Traceback (most recent call last):
      File "<stdin>", line 1, in <module>
      File "<stdin>", line 1, in rec
      File "<stdin>", line 1, in rec
      File "<stdin>", line 1, in rec
      [Previous line repeated 995 more times]
    RecursionError: maximum recursion depth exceeded

    @remilapeyre
    Copy link
    Mannequin

    remilapeyre mannequin commented Mar 13, 2019

    I'm not sure bpo-35542. I think this happens because while logging the recursion limit is hit which calls https://github.com/python/cpython/blob/master/Python/ceval.c#L535-L539.

    The RecursionError is then handled by https://github.com/python/cpython/blob/master/Lib/logging/__init__.py#L1000 and cleared.

    On subsequent calls the exception is not set anymore because tstate->overflowed equals 1 so we exit early before setting the exception again at https://github.com/python/cpython/blob/master/Python/ceval.c#L531.

    This goes on until the condition on https://github.com/python/cpython/blob/master/Python/ceval.c#L531 pass which abort the interpreter.

    I think there is two ways to solve the issue, either handle RecursionError explicitly in the logging module so we don't clear it inadvertently as there is no way to recover from it anyway or check if the exception has been cleared at https://github.com/python/cpython/blob/master/Python/ceval.c#L531 and set it again.

    Handling it explictly in the logging module would not help for code doing this elsewhere:

    def rec():
        try:
            rec()
        except:
            rec()
    rec()

    I can submit a patch if you want.

    @remilapeyre remilapeyre mannequin added 3.7 (EOL) end of life 3.8 only security fixes labels Mar 13, 2019
    @remilapeyre
    Copy link
    Mannequin

    remilapeyre mannequin commented Mar 13, 2019

    The following patch fixes the issue and raise RecursionError as expecting without core dump:

    diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py
    index b4659af7cc..7457549cb9 100644
    --- a/Lib/logging/__init__.py
    +++ b/Lib/logging/__init__.py
    @@ -1094,6 +1094,8 @@ class StreamHandler(Handler):
                 # issue 35046: merged two stream.writes into one.
                 stream.write(msg + self.terminator)
                 self.flush()
    +        except RecursionError as e:
    +            raise
             except Exception:
                 self.handleError(record)

    @tirkarthi
    Copy link
    Member

    Stack exhaustion doesn't seem to be due to be the root cause. A simple recursive function doesn't crash the interpreter in Python 3.6.

    Yes, sorry I got misleaded. I have added logging module author, @vinay.sajip to the issue.

    @brettcannon
    Copy link
    Member

    Limiting the version scope to 3.6 until someone reproduces on 3.7 and/or 3.8.

    @brettcannon brettcannon removed 3.7 (EOL) end of life 3.8 only security fixes labels Mar 13, 2019
    @remilapeyre
    Copy link
    Mannequin

    remilapeyre mannequin commented Mar 13, 2019

    Hi Brett, I confirm the test case breaks both Python3.7 and 3.8. I opened a PR to fix the problem.

    @remilapeyre remilapeyre mannequin added 3.7 (EOL) end of life 3.8 only security fixes labels Mar 13, 2019
    @vsajip
    Copy link
    Member

    vsajip commented Mar 15, 2019

    New changeset 65f64b1 by Vinay Sajip (Rémi Lapeyre) in branch 'master':
    bpo-36272: Logging now propagates RecursionError (GH-12312)
    65f64b1

    @vsajip
    Copy link
    Member

    vsajip commented Mar 18, 2019

    New changeset 6a7a9f1 by Vinay Sajip (Miss Islington (bot)) in branch '3.7':
    bpo-36272: Logging now propagates RecursionError (GH-12312) (GH-12391)
    6a7a9f1

    @vsajip vsajip closed this as completed Mar 18, 2019
    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    3.7 (EOL) end of life 3.8 only security fixes stdlib Python modules in the Lib dir type-crash A hard crash of the interpreter, possibly with a core dump
    Projects
    None yet
    Development

    No branches or pull requests

    3 participants