classification
Title: Using logging or warnings during Python finalization does crash Python
Type: Stage: resolved
Components: Interpreter Core Versions: Python 3.10
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: corona10, miss-islington, vstinner
Priority: normal Keywords: patch

Created on 2020-10-30 14:57 by vstinner, last changed 2020-10-31 00:33 by vstinner. This issue is now closed.

Files
File name Uploaded Description Edit
logging.patch vstinner, 2020-10-30 14:57
crash.py vstinner, 2020-10-30 14:57
Pull Requests
URL Status Linked Edit
PR 23038 merged vstinner, 2020-10-30 15:29
PR 23040 merged vstinner, 2020-10-30 16:23
PR 23041 merged vstinner, 2020-10-30 16:49
PR 23043 merged vstinner, 2020-10-30 20:24
PR 23044 merged vstinner, 2020-10-30 20:50
PR 23047 merged miss-islington, 2020-10-30 22:16
PR 23049 merged miss-islington, 2020-10-30 22:17
PR 23050 merged vstinner, 2020-10-30 22:56
PR 23052 merged vstinner, 2020-10-31 00:07
Messages (11)
msg379974 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-10-30 14:57
If you apply attached logging.patch, Python crash using attached crash.py:

$ echo|./python -i crash.py
>>>
>>> 
python: Python/_warnings.c:872: setup_context: Assertion `globals != NULL' failed.
Abandon (core dumped)


Attached logging.patch is a fix for bpo-26789: logging.FileHandler keeps a reference to the builtin open() function.

Attached crash.py does crash because of an unclosed file. It happens after PyInterpreterState_Clear(), in finalize_interp_clear():

    /* Last explicit GC collection */
    _PyGC_CollectNoFail();

setup_context() of Python/_warings.c does crash because tstate->interp->sysdict is NULL at this point.

Moreover, _io.TextIOWrapper.__init__() fails to import the locale module (to call locale.getpreferredencoding(), since the encoding is None) and picks the "ascii" encoding.

Moreover, even if I work around all these issues, _warnings.showwarnings() logs "lost sys.stderr" into stderr because, again, tstate->interp->sysdict is NULL at this point (and so sys.stderr no longer exists).

It looks like a bug in finalize_interp_clear() which triggers a garbage collection, whereas Python is no longer usable.

--

The logging module does automatically close files at exit using:

   atexit.register(shutdown)

But crash.py, a new file is opened by a logging handler after logging.shutdown() is called. Maybe another problem is that the logging module does not clear logger handlers, or prevent handlers to log more message, after shutdown() is called.
msg379978 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-10-30 16:00
New changeset 8b3414818f5289eac530bf38bcfbd7b2b851805c by Victor Stinner in branch 'master':
bpo-42208: Pass tstate to _PyGC_CollectNoFail() (GH-23038)
https://github.com/python/cpython/commit/8b3414818f5289eac530bf38bcfbd7b2b851805c
msg379987 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-10-30 17:03
New changeset dff1ad509051f7e07e77d1e3ec83314d53fb1118 by Victor Stinner in branch 'master':
bpo-42208: Move _PyImport_Cleanup() to pylifecycle.c (GH-23040)
https://github.com/python/cpython/commit/dff1ad509051f7e07e77d1e3ec83314d53fb1118
msg379996 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-10-30 20:09
New changeset b9ee4af4c643a323779fd7076e80b29d611f2709 by Victor Stinner in branch 'master':
bpo-42208: Fix test_gdb for gc_collect_main() name (GH-23041)
https://github.com/python/cpython/commit/b9ee4af4c643a323779fd7076e80b29d611f2709
msg379997 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-10-30 20:24
> bpo-42208: Pass tstate to _PyGC_CollectNoFail() (GH-23038)
> https://github.com/python/cpython/commit/8b3414818f5289eac530bf38bcfbd7b2b851805c

This change renames collect() to gc_collect_main(). It broke test_gdb on buildbots, whereas test_gdb passed on Travis CI on my PR 23038. Also, test_gdb is skipped on the Ubuntu job of GitHub Action since gdb is not installed. I created https://github.com/python/core-workflow/issues/383 to add gdb to Ubuntu dependencies. My PR 23043 adds gdb dependency.
msg380001 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-10-30 21:51
New changeset eba5bf2f5672bf4861c626937597b85ac0c242b9 by Victor Stinner in branch 'master':
bpo-42208: Call GC collect earlier in PyInterpreterState_Clear() (GH-23044)
https://github.com/python/cpython/commit/eba5bf2f5672bf4861c626937597b85ac0c242b9
msg380005 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-10-30 22:16
New changeset 09c6120be8c70366495b027ae3daa213609de3ed by Miss Skeleton (bot) in branch '3.9':
 bpo-42208: GitHub Action: Add gdb to posix dependencies (GH-23043) (GH-23047)
https://github.com/python/cpython/commit/09c6120be8c70366495b027ae3daa213609de3ed
msg380015 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-10-30 23:53
> This change renames collect() to gc_collect_main(). It broke test_gdb on buildbots, whereas test_gdb passed on Travis CI on my PR 23038. Also, test_gdb is skipped on the Ubuntu job of GitHub Action since gdb is not installed. I created https://github.com/python/core-workflow/issues/383 to add gdb to Ubuntu dependencies. My PR 23043 adds gdb dependency.

Fixed by:

commit 6e03c0ad156797cd6e9132e895d55dac0344d340 (upstream/master, master)
Author: Victor Stinner <vstinner@python.org>
Date:   Fri Oct 30 22:52:30 2020 +0100

    GitHub Action: Add gdb to posix dependencies (GH-23043)
    
    Sort also dependencies and remove duplicates (liblzma-dev).
msg380017 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-10-31 00:02
New changeset 710e82630775774dceba5e8f24b1b10e6dfaf9b7 by Victor Stinner in branch 'master':
bpo-42208: Add _Py_GetLocaleEncoding() (GH-23050)
https://github.com/python/cpython/commit/710e82630775774dceba5e8f24b1b10e6dfaf9b7
msg380019 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-10-31 00:32
New changeset b62bdf71ea0cd52041d49691d8ae3dc645bd48e1 by Victor Stinner in branch 'master':
bpo-42208: Add _locale._get_locale_encoding() (GH-23052)
https://github.com/python/cpython/commit/b62bdf71ea0cd52041d49691d8ae3dc645bd48e1
msg380020 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-10-31 00:33
I fixed all issues which prevented to fix bpo-26789, I close thie issue.
History
Date User Action Args
2020-10-31 00:49:24vstinnerlinkissue42211 superseder
2020-10-31 00:33:13vstinnersetstatus: open -> closed
resolution: fixed
messages: + msg380020

stage: patch review -> resolved
2020-10-31 00:32:14vstinnersetmessages: + msg380019
2020-10-31 00:07:05vstinnersetpull_requests: + pull_request21971
2020-10-31 00:02:16vstinnersetmessages: + msg380017
2020-10-30 23:53:40vstinnersetmessages: + msg380015
2020-10-30 22:56:23vstinnersetpull_requests: + pull_request21969
2020-10-30 22:17:04miss-islingtonsetpull_requests: + pull_request21968
2020-10-30 22:16:26vstinnersetmessages: + msg380005
2020-10-30 22:16:06miss-islingtonsetnosy: + miss-islington
pull_requests: + pull_request21967
2020-10-30 21:51:05vstinnersetmessages: + msg380001
2020-10-30 20:50:21vstinnersetpull_requests: + pull_request21963
2020-10-30 20:24:21vstinnersetpull_requests: + pull_request21962
2020-10-30 20:24:12vstinnersetmessages: + msg379997
2020-10-30 20:09:55vstinnersetmessages: + msg379996
2020-10-30 17:03:35vstinnersetmessages: + msg379987
2020-10-30 16:49:44vstinnersetpull_requests: + pull_request21960
2020-10-30 16:23:45vstinnersetpull_requests: + pull_request21959
2020-10-30 16:00:08vstinnersetmessages: + msg379978
2020-10-30 15:29:35vstinnersetstage: patch review
pull_requests: + pull_request21957
2020-10-30 15:13:09corona10setnosy: + corona10
2020-10-30 14:57:24vstinnersetfiles: + crash.py
2020-10-30 14:57:17vstinnercreate