classification
Title: FileIO destructor imports indirectly the io module at exit
Type: Stage:
Components: Versions: Python 3.3, Python 3.4
process
Status: closed Resolution: not a bug
Dependencies: Superseder:
Assigned To: Nosy List: Arfrever, brett.cannon, martin.panter, pitrou, python-dev, vstinner
Priority: normal Keywords: patch

Created on 2013-10-28 12:49 by vstinner, last changed 2014-10-10 13:44 by martin.panter. This issue is now closed.

Files
File name Uploaded Description Edit
traceback_finalize.patch vstinner, 2013-10-28 17:50 review
import_finalization.patch vstinner, 2013-10-28 18:43 review
Messages (16)
msg201532 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-10-28 12:49
Since Python 3.3, when an unclosed file is destroyed, a warning is emitted. Good.

The problem is when the warning is emitted after the io has been unloaded: in this case, the warning will try to reload the io module to display the Python line where the warning occurred. _Py_DisplaySourceLine() starts with:

   io = PyImport_ImportModuleNoBlock("io");

For example, I got the issue while the warning was emitted during PyImport_Cleanup(), see the full gdb backtrace below (the assertion failure was caused by a local modification, it's unrelated to this issue).

show_warning() and/or _Py_DisplaySourceLine() should not try to display the Python line while Python is exiting. There is for example the flag _Py_Finalizing.

If we really want to display the Python line/traceback, the io module should be kept alive until all warnings are emitted. But I don't think that it is possible. Or Python should try to unload other modules before the io module?


(gdb) where
#0  0x00000037f4835ba5 in raise () from /lib64/libc.so.6
#1  0x00000037f4837358 in abort () from /lib64/libc.so.6
#2  0x00000037f482e972 in __assert_fail_base () from /lib64/libc.so.6
#3  0x00000037f482ea22 in __assert_fail () from /lib64/libc.so.6
#4  0x00000000004bddbd in PyObject_Repr (v='builtins') at Objects/object.c:457
#5  0x0000000000506161 in unicode_fromformat_arg (writer=0x7fffffffb780, f=0x68b073 "R halted; None in sys.modules", vargs=0x7fffffffb7c0)
    at Objects/unicodeobject.c:2669
#6  0x00000000005065ca in PyUnicode_FromFormatV (format=0x68b068 "import of %R halted; None in sys.modules", vargs=0x7fffffffb810)
    at Objects/unicodeobject.c:2734
#7  0x000000000050679f in PyUnicode_FromFormat (format=0x68b068 "import of %R halted; None in sys.modules") at Objects/unicodeobject.c:2785
#8  0x00000000005c8a9a in PyImport_ImportModuleLevelObject (name='builtins', given_globals=0x0, locals=0x0, given_fromlist=0x0, level=0)
    at Python/import.c:1410
#9  0x00000000005c98eb in PyImport_ImportModuleLevel (name=0x68aa45 "builtins", globals=0x0, locals=0x0, fromlist=0x0, level=0) at Python/import.c:1560
#10 0x00000000005c9ba7 in PyImport_Import (module_name='io') at Python/import.c:1639
#11 0x00000000005c7e00 in PyImport_ImportModule (name=0x65084a "io") at Python/import.c:1141
#12 0x00000000005c7e8e in PyImport_ImportModuleNoBlock (name=0x65084a "io") at Python/import.c:1158
#13 0x0000000000432f85 in _Py_DisplaySourceLine (f=<_io.TextIOWrapper at remote 0x7ffff1b97898>, filename='sys', lineno=1, indent=2)
    at Python/traceback.c:243
#14 0x00000000005542fa in show_warning (filename='sys', lineno=1, text="unclosed file <_io.TextIOWrapper name='x.py' mode='r' encoding='UTF-8'>", category=
    <type at remote 0x8f60a0>, sourceline=0x0) at Python/_warnings.c:287
#15 0x000000000055487a in warn_explicit (category=<type at remote 0x8f60a0>, message=
    ResourceWarning("unclosed file <_io.TextIOWrapper name='x.py' mode='r' encoding='UTF-8'>",), filename='sys', lineno=1, module='sys', registry={}, 
    sourceline=0x0) at Python/_warnings.c:409
#16 0x0000000000555b88 in do_warn (message="unclosed file <_io.TextIOWrapper name='x.py' mode='r' encoding='UTF-8'>", category=<type at remote 0x8f60a0>, 
    stack_level=1) at Python/_warnings.c:614
#17 0x00000000005561dd in warn_unicode (category=<type at remote 0x8f60a0>, message=
    "unclosed file <_io.TextIOWrapper name='x.py' mode='r' encoding='UTF-8'>", stack_level=1) at Python/_warnings.c:732
#18 0x0000000000556336 in PyErr_WarnFormat (category=<type at remote 0x8f60a0>, stack_level=1, format=0x6a3e8b "unclosed file %R") at Python/_warnings.c:755
#19 0x000000000061cff5 in fileio_dealloc_warn (self=0x7ffff1a04368, source=<_io.TextIOWrapper at remote 0x7ffff1b97dc0>) at ./Modules/_io/fileio.c:79
#20 0x00000000004b961d in PyCFunction_Call (func=<built-in method _dealloc_warn of _io.FileIO object at remote 0x7ffff1a04368>, arg=
    (<_io.TextIOWrapper at remote 0x7ffff1b97dc0>,), kw=0x0) at Objects/methodobject.c:120
#21 0x000000000045b5d3 in PyObject_Call (func=<built-in method _dealloc_warn of _io.FileIO object at remote 0x7ffff1a04368>, arg=
    (<_io.TextIOWrapper at remote 0x7ffff1b97dc0>,), kw=0x0) at Objects/abstract.c:2085
#22 0x000000000045b76d in call_function_tail (callable=<built-in method _dealloc_warn of _io.FileIO object at remote 0x7ffff1a04368>, args=
    (<_io.TextIOWrapper at remote 0x7ffff1b97dc0>,)) at Objects/abstract.c:2122
#23 0x000000000045ba90 in callmethod (func=<built-in method _dealloc_warn of _io.FileIO object at remote 0x7ffff1a04368>, format=0x6a4af1 "O", va=
    0x7fffffffd288, is_size_t=1) at Objects/abstract.c:2189
#24 0x000000000045bf63 in _PyObject_CallMethodId_SizeT (o=<_io.FileIO at remote 0x7ffff1a04368>, name=0x936e80 <PyId__dealloc_warn>, format=0x6a4af1 "O")
    at Objects/abstract.c:2278
#25 0x0000000000621e4e in buffered_dealloc_warn (self=0x7ffff1ae4838, source=<_io.TextIOWrapper at remote 0x7ffff1b97dc0>) at ./Modules/_io/bufferedio.c:456
#26 0x00000000004b961d in PyCFunction_Call (func=<built-in method _dealloc_warn of _io.BufferedReader object at remote 0x7ffff1ae4838>, arg=
    (<_io.TextIOWrapper at remote 0x7ffff1b97dc0>,), kw=0x0) at Objects/methodobject.c:120
#27 0x000000000045b5d3 in PyObject_Call (func=<built-in method _dealloc_warn of _io.BufferedReader object at remote 0x7ffff1ae4838>, arg=
    (<_io.TextIOWrapper at remote 0x7ffff1b97dc0>,), kw=0x0) at Objects/abstract.c:2085
#28 0x000000000045b76d in call_function_tail (callable=<built-in method _dealloc_warn of _io.BufferedReader object at remote 0x7ffff1ae4838>, args=
    (<_io.TextIOWrapper at remote 0x7ffff1b97dc0>,)) at Objects/abstract.c:2122
#29 0x000000000045ba90 in callmethod (func=<built-in method _dealloc_warn of _io.BufferedReader object at remote 0x7ffff1ae4838>, format=0x6a57e5 "O", va=
    0x7fffffffd4f8, is_size_t=1) at Objects/abstract.c:2189
#30 0x000000000045bf63 in _PyObject_CallMethodId_SizeT (o=<_io.BufferedReader at remote 0x7ffff1ae4838>, name=0x938fe0 <PyId__dealloc_warn>, format=
    0x6a57e5 "O") at Objects/abstract.c:2278
#31 0x000000000063446c in textiowrapper_close (self=0x7ffff1b97dc0, args=0x0) at ./Modules/_io/textio.c:2581
#32 0x00000000004b956d in PyCFunction_Call (func=<built-in method close of _io.TextIOWrapper object at remote 0x7ffff1b97dc0>, arg=(), kw=0x0)
    at Objects/methodobject.c:106
#33 0x000000000045b5d3 in PyObject_Call (func=<built-in method close of _io.TextIOWrapper object at remote 0x7ffff1b97dc0>, arg=(), kw=0x0)
    at Objects/abstract.c:2085
#34 0x000000000045c254 in PyObject_CallMethodObjArgs (callable=<built-in method close of _io.TextIOWrapper object at remote 0x7ffff1b97dc0>, name='close')
    at Objects/abstract.c:2326
#35 0x000000000061abdf in iobase_finalize (self=<_io.TextIOWrapper at remote 0x7ffff1b97dc0>) at ./Modules/_io/iobase.c:228
#36 0x00000000004bd715 in PyObject_CallFinalizer (self=<_io.TextIOWrapper at remote 0x7ffff1b97dc0>) at Objects/object.c:272
#37 0x00000000004bd789 in PyObject_CallFinalizerFromDealloc (self=<_io.TextIOWrapper at remote 0x7ffff1b97dc0>) at Objects/object.c:289
#38 0x000000000061aca8 in _PyIOBase_finalize (self=<_io.TextIOWrapper at remote 0x7ffff1b97dc0>) at ./Modules/_io/iobase.c:252
#39 0x000000000062d116 in textiowrapper_dealloc (self=0x7ffff1b97dc0) at ./Modules/_io/textio.c:1138
---Type <return> to continue, or q <return> to quit---
#40 0x00000000004c12b3 in _Py_Dealloc (op=<_io.TextIOWrapper at remote 0x7ffff1b97dc0>) at Objects/object.c:1876
#41 0x00000000004a86d4 in free_keys_object (keys=0xa13980) at Objects/dictobject.c:364
#42 0x00000000004ab8b4 in dict_dealloc (mp=0x7ffff1b582f8) at Objects/dictobject.c:1386
#43 0x00000000004c12b3 in _Py_Dealloc (op=
    {'f': <_io.TextIOWrapper at remote 0x7ffff1b97dc0>, '__loader__': <SourceFileLoader(name='__main__', path='x.py') at remote 0x7ffff19ffa18>, '__doc__': None, '__cached__': None, '__package__': None, '__name__': '__main__', '__builtins__': <module at remote 0x7ffff1b6b358>}) at Objects/object.c:1876
#44 0x00000000004bc067 in module_dealloc (m=0x7ffff1aff7d8) at Objects/moduleobject.c:391
#45 0x00000000004c12b3 in _Py_Dealloc (op=<module at remote 0x7ffff1aff7d8>) at Objects/object.c:1876
#46 0x00000000004a9ea2 in insertdict (mp=0x7ffff1be77c8, key='__main__', hash=-7010304633138094468, value=None) at Objects/dictobject.c:818
#47 0x00000000004aafaf in PyDict_SetItem (op=
    {'_weakrefset': None, 'marshal': None, 'sysconfig': None, '_sitebuiltins': None, 'io': None, 'encodings.utf_8': None, 'sys': None, 'encodings.latin_1': None, '_sysconfigdata': None, 'encodings.aliases': None, 'os': None, 'codecs': None, 'errno': None, '_collections_abc': None, '_weakref': None, 'site': None, 'zipimport': None, 'posixpath': None, '_io': None, 'abc': None, '_locale': None, 'encodings': None, 'builtins': None, 'os.path': None, '_warnings': None, '_stat': None, '_bootlocale': None, 'signal': None, '_frozen_importlib': None, 'stat': None, '_imp': None, 'posix': None, '__main__': None, 'genericpath': <module at remote 0x7ffff1a922d8>, '_codecs': <module at remote 0x7ffff1b20b58>, '_thread': <module at remote 0x7ffff1aff658>}, key='__main__', value=None)
    at Objects/dictobject.c:1202
#48 0x00000000005c5b33 in PyImport_Cleanup () at Python/import.c:369
#49 0x000000000041dd8e in Py_Finalize () at Python/pythonrun.c:592
#50 0x0000000000439854 in Py_Main (argc=2, argv=0x95d020) at Modules/main.c:800
#51 0x0000000000419f25 in main (argc=2, argv=0x7fffffffdf28) at ./Modules/python.c:69
msg201534 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-10-28 12:56
By the way, the filename of the warning is not really useful. Example script test.py:
---------------------
f = open(__file__)
---------------------

At exit, Python displays:
---------------------
sys:1: ResourceWarning: unclosed file <_io.TextIOWrapper name='test.py' mode='r' encoding='UTF-8'>
---------------------

"sys" is not a real file, _Py_DisplaySourceLine() would not be able to display the Python line (the correct filename is test.py).

Python traceback when the warning is emitted, according to gdb:
---------------------
(gdb) py-bt
Traceback (most recent call first):
  <built-in method _dealloc_warn of _io.FileIO object at remote 0x7ffff1a04368>
  <built-in method _dealloc_warn of _io.BufferedReader object at remote 0x7ffff1ae4838>
  <built-in method close of _io.TextIOWrapper object at remote 0x7ffff1b97dc0>
---------------------

We are in PyImport_Cleanup(), called by Py_Finalize().
msg201537 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-10-28 12:59
"show_warning() and/or _Py_DisplaySourceLine() should not try to display the Python line while Python is exiting. There is for example the flag _Py_Finalizing."

Or PyImport_Import() should fail with an ImportError("block importing 'io' when python is exiting") (or a better message) when Python is exiting (if _Py_Finalizing is 1).
msg201544 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2013-10-28 14:46
Can you explain what the actual cause of the crash is?
Surely failing to import the "io" module shouldn't produce a fatal error.
msg201547 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-10-28 14:49
> Can you explain what the actual cause of the crash is?

I modified locally my Python source code (I worked on a patch for PyFrame_LocalsToFast(), issue #18408), the crash was a bug in my code, it's unrelated to the issue.

I opened an issue because I'm surprised that Python tries to import a module which was just unloaded, during its finalization procedure.
msg201552 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2013-10-28 16:11
Ok, then I don't think it's really a bug. We might want to define import rules at shutdown but "fixing" this particular case doesn't sound important.
msg201559 - (view) Author: Roundup Robot (python-dev) (Python triager) Date: 2013-10-28 17:48
New changeset 1bbedfb20932 by Victor Stinner in branch 'default':
Issue #19421: fix a check in warnings.warn() to be able to use it during Python
http://hg.python.org/cpython/rev/1bbedfb20932
msg201560 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-10-28 17:50
Here is a patch to not import again the io module in _Py_DisplaySourceLine() if the module was unloaded.

A simpler patch is to just return (don't check sys.modules) if _Py_Finalizing is set.

Note: I also created issue #19424 to avoid conversion from/to UTF-8.
msg201562 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-10-28 17:53
> New changeset 1bbedfb20932 by Victor Stinner in branch 'default':
> Issue #19421: fix a check in warnings.warn() to be able to use it during Python
> http://hg.python.org/cpython/rev/1bbedfb20932

Without this fix, the following script crashs with an assertion error (Objects/typeobject.c:740: type_call: Assertion `!PyErr_Occurred()' failed.):
-------------
import warnings
warn = warnings.warn

class A:
    def __del__(self):
        warn("bla")

a=A()
-------------
msg201565 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2013-10-28 18:10
Again, I don't think this is a good patch. If you want to disable module imports during shutdown, it should be done inside the import machinery, not duplicated at every call site.
(but I don't necessarily agree that it's a good idea, either)
msg201567 - (view) Author: Roundup Robot (python-dev) (Python triager) Date: 2013-10-28 18:21
New changeset 2d802765d31f by Victor Stinner in branch 'default':
Issue #19421: add an unit test for warnings.warn() during finalization
http://hg.python.org/cpython/rev/2d802765d31f
msg201568 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-10-28 18:43
"Again, I don't think this is a good patch. If you want to disable module imports during shutdown, it should be done inside the import machinery, 
not duplicated at every call site."

Ah sorry, I misunderstood your previous comment. I agree that  traceback_finalize.patch is very specific.

Here is a new patch "import_finalization.patch", which block importing new modules (and import again unloaded modules) during finalization.

The full test suite pass with the patch, so at least no unit test tries to import a module during finalization.

> (but I don't necessarily agree that it's a good idea, either)

I'm opening a thread on python-dev to discuss this tricky question.
msg201569 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-10-28 18:46
+            PyErr_SetString(PyExc_ImportError, "__import__ blocked Python finalization");

Oops, I forgot "during" word before Python finalization. "import" is maybe less surprising than "__import__".
msg201698 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-10-29 23:38
Trying to reimport the io module is not the only issue of emitting warnings during Python shutdown. I just found a new issue after fixing an unrelated bug in the warnings module (issue #19424): issue #19442 "Python crashes when a warning is emitted during shutdown".
msg201867 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-11-01 01:09
I misunderstood the gdb traceback. Display a warning does not reload the io module: in fact, the io module was unloaded and PyImport_ImportModuleLevelObject() already raises an ImportError in this case: ImportError("import of 'io' halted; None in sys.modules"). So nothing else need to be done, I'm now closing the issue.

I created more specific issues about warnings, see issues #19442 and #19466.
msg228998 - (view) Author: Martin Panter (martin.panter) * (Python committer) Date: 2014-10-10 13:44
For the record, the python-dev thread about blocking imports is at <https://mail.python.org/pipermail/python-dev/2013-October/129907.html>. It sounded like the conclusion was that there shouldn’t be a problem importing a module at finalization.

I am investigating Issue 21049, and finding sys.meta_path is set to None at finalization, which is not handled well by the import code.
History
Date User Action Args
2014-10-10 13:44:26martin.pantersetnosy: + martin.panter
messages: + msg228998
2013-11-01 01:09:45vstinnersetstatus: open -> closed
resolution: not a bug
messages: + msg201867
2013-10-29 23:38:56vstinnersetmessages: + msg201698
2013-10-28 23:09:55Arfreversetnosy: + Arfrever
2013-10-28 18:46:38vstinnersetmessages: + msg201569
2013-10-28 18:43:54vstinnersetfiles: + import_finalization.patch

messages: + msg201568
2013-10-28 18:21:38python-devsetmessages: + msg201567
2013-10-28 18:10:48pitrousetmessages: + msg201565
2013-10-28 17:53:48vstinnersetmessages: + msg201562
2013-10-28 17:50:20vstinnersetfiles: + traceback_finalize.patch
keywords: + patch
messages: + msg201560
2013-10-28 17:48:06python-devsetnosy: + python-dev
messages: + msg201559
2013-10-28 16:11:36pitrousetmessages: + msg201552
2013-10-28 14:49:04vstinnersetmessages: + msg201547
2013-10-28 14:46:08pitrousetmessages: + msg201544
2013-10-28 12:59:07vstinnersetnosy: + brett.cannon
messages: + msg201537
2013-10-28 12:56:45vstinnersetmessages: + msg201534
2013-10-28 12:49:55vstinnercreate