classification
Title: Recursive logging crashes Interpreter in Python 3
Type: crash Stage: resolved
Components: Library (Lib) Versions: Python 3.8, Python 3.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: Saim Raza, brett.cannon, remi.lapeyre, vinay.sajip, xtreak
Priority: normal Keywords: patch

Created on 2019-03-12 14:47 by Saim Raza, last changed 2019-03-18 14:26 by vinay.sajip. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 12312 merged remi.lapeyre, 2019-03-13 22:06
PR 12339 closed miss-islington, 2019-03-15 06:54
PR 12391 merged miss-islington, 2019-03-18 03:21
Messages (10)
msg337747 - (view) Author: Saim Raza (Saim Raza) Date: 2019-03-12 14:47
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.
msg337748 - (view) Author: Karthikeyan Singaravelan (xtreak) * (Python triager) Date: 2019-03-12 14:56
I am not sure this is related to logging and looks similar to issue35542 except stack (depends on OS) is exhausted without setrecursionlimit(). What does below return?

def rec():
    rec()

rec()
msg337842 - (view) Author: Saim Raza (Saim Raza) Date: 2019-03-13 10:41
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
msg337843 - (view) Author: Rémi Lapeyre (remi.lapeyre) * Date: 2019-03-13 11:19
I'm not sure issue35542. 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.
msg337844 - (view) Author: Rémi Lapeyre (remi.lapeyre) * Date: 2019-03-13 11:32
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)
msg337845 - (view) Author: Karthikeyan Singaravelan (xtreak) * (Python triager) Date: 2019-03-13 11:49
> 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.
msg337879 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2019-03-13 22:02
Limiting the version scope to 3.6 until someone reproduces on 3.7 and/or 3.8.
msg337880 - (view) Author: Rémi Lapeyre (remi.lapeyre) * Date: 2019-03-13 22:07
Hi Brett, I confirm the test case breaks both Python3.7 and 3.8. I opened a PR to fix the problem.
msg337971 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2019-03-15 06:53
New changeset 65f64b1903ae85b97a30f514bbc1b7ce940c3af2 by Vinay Sajip (Rémi Lapeyre) in branch 'master':
bpo-36272: Logging now propagates RecursionError (GH-12312)
https://github.com/python/cpython/commit/65f64b1903ae85b97a30f514bbc1b7ce940c3af2
msg338227 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2019-03-18 14:22
New changeset 6a7a9f1d83cef628d2bacd71ee568b93f53fd6b4 by Vinay Sajip (Miss Islington (bot)) in branch '3.7':
bpo-36272: Logging now propagates RecursionError (GH-12312) (GH-12391)
https://github.com/python/cpython/commit/6a7a9f1d83cef628d2bacd71ee568b93f53fd6b4
History
Date User Action Args
2019-03-18 14:26:24vinay.sajipsetstatus: open -> closed
stage: patch review -> resolved
resolution: fixed
versions: - Python 3.6
2019-03-18 14:22:46vinay.sajipsetmessages: + msg338227
2019-03-18 03:21:44miss-islingtonsetpull_requests: + pull_request12346
2019-03-15 06:54:28miss-islingtonsetpull_requests: + pull_request12307
2019-03-15 06:53:39vinay.sajipsetmessages: + msg337971
2019-03-13 22:07:53remi.lapeyresetmessages: + msg337880
versions: + Python 3.7, Python 3.8
2019-03-13 22:06:56remi.lapeyresetkeywords: + patch
stage: patch review
pull_requests: + pull_request12287
2019-03-13 22:02:08brett.cannonsetnosy: + brett.cannon

messages: + msg337879
versions: - Python 3.7, Python 3.8
2019-03-13 11:49:01xtreaksetmessages: + msg337845
2019-03-13 11:32:54remi.lapeyresetmessages: + msg337844
2019-03-13 11:20:00remi.lapeyresetnosy: + remi.lapeyre

messages: + msg337843
versions: + Python 3.7, Python 3.8
2019-03-13 10:41:03Saim Razasetmessages: + msg337842
2019-03-12 15:47:25xtreaksetnosy: + vinay.sajip
2019-03-12 14:56:30xtreaksetnosy: + xtreak
messages: + msg337748
2019-03-12 14:47:03Saim Razacreate