Issue 21925: ResourceWarning sometimes doesn't display

It seems that ResouceWarning about unclosed file handles with '-W all' option sometimes doesn't display.
Is this behaviour normal?

$ uname -a
Linux ashrose 3.2.0-65-generic #99-Ubuntu SMP Fri Jul 4 21:03:29 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux
$ python3.4 --version
Python 3.4.1
$ touch spam.txt
$ echo 'a = open("spam.txt")' >test_warning.py
$
$ python3.4 -W all test_warning.py
$ python3.4 -W all test_warning.py
sys:1: ResourceWarning: unclosed file <_io.TextIOWrapper name='spam.txt' mode='r' encoding='UTF-8'>
$ python3.4 -W all test_warning.py
sys:1: ResourceWarning: unclosed file <_io.TextIOWrapper name='spam.txt' mode='r' encoding='UTF-8'>
$ python3.4 -W all test_warning.py
$ python3.4 -W all test_warning.py
$ python3.4 -W all test_warning.py
$ python3.4 -W all test_warning.py
$ python3.4 -W all test_warning.py
sys:1: ResourceWarning: unclosed file <_io.TextIOWrapper name='spam.txt' mode='r' encoding='UTF-8'>
$

I believe this is an artifact of hash randomization which affects the order of how objects are destroyed during shutdown.  If you run your test using different values of the PYTHONHASHSEED environment variable, you'll probably see predictable results.  For example, with a particular build of Python 3.4.1, if I set PYTHONHASHSEED set to 0, thereby disabling hash randomization, I never see the warning:

PYTHONHASHSEED=0 python3.4 -W all test_warning.py

With it set to 1, I always see the warning.  With 2, no warning. With no PYTHONHASHSEED, I see random behavior similar to your results.

I don't think there is anything to be done here as Python makes no promises about when and in what order objects are collected.

https://docs.python.org/3/using/cmdline.html#envvar-PYTHONHASHSEED

The problem is tricky.

The modules are deleted in a random order at exit. The problem is that showing the warning requires to import the linecache module. But during Python finalization, we may or may not be able to import modules.

Py_Finalize() calls PyImport_Cleanup() which starts by setting sys.path and sys.meta_path to None. The _find_spec() function of importlib._bootstrap fails because sys.meta_path is None. In fact, find_spec() starts by emiting a warning which calls formatwarning() which tries to import linecache again... and then importlib emits again a warning... "import linecache" is tried twice and then everything fails.

A workaround would be to unload the __main__ module first, before clearing sys attributes.

Another workaround would be to not try to import modules in warnings.formatwarning() if Python is exiting.

The tricky exit code was already discussed in the issue #19421 ("FileIO destructor imports indirectly the io module at exit"). See also my more general issue #21788 ("Rework Python finalization").

New changeset 047da19efdab by Victor Stinner in branch '3.4':
Issue #21925: PyImport_Cleanup(): Remove unused parameter in
http://hg.python.org/cpython/rev/047da19efdab

New changeset b255ecb175c4 by Victor Stinner in branch 'default':
(Merge 3.4) Issue #21925: PyImport_Cleanup(): Remove unused parameter in
http://hg.python.org/cpython/rev/b255ecb175c4

I don't know if it's the best trick, but here is a patch to unload the __main__ module first in PyImport_Cleanup().

Well, it's unclear to me why we would want to remove the __main__ module first, rather than last.

May be save the timestamp for module importing and then clean up modules them in reversed order?

It looks like the warnings is logged when the C implemention is used. When the Python implementation is used, "import linecache" or "linecache.getline()" fail, and so the warnings is skipped.

Attached patch makes the Python implementation safer when Python is shutting down. Add "try/except Exception" to ignore exceptions on import, linecache and tracemalloc.

See also the issue #26637: "importlib: better error message when import fail during Python shutdown".

It looks like logging a warning at Python exit always works on Python 2.7:
---
import _warnings

class Bla:
    def __del__(self, w=_warnings):
        w.warn_explicit('message', DeprecationWarning, 'x.py', 5)

bla = Bla()
---

It looks like it uses the Python implementation and linecache.getline() always works. Maybe the warning is emitted earlier that the Python 3 code emitting ResourceWarning. I see that warnings.py of Python 2 imports linecache at top level, whereas the Python 3 code imports the module at the first use in showwarning(). I recall that imports at top level are avoided to get faster startup time.

New changeset 1de90a7065ba by Victor Stinner in branch '3.5':
warnings.formatwarning(): catch exceptions
https://hg.python.org/cpython/rev/1de90a7065ba

New changeset 36be356f6253 by Victor Stinner in branch 'default':
Merge 3.5
https://hg.python.org/cpython/rev/36be356f6253

I fixed warnings.formatwarning(). I don't expect the code to be perfect (Python shutdown process is complex and fragile), but the fix is quite simple and it's enough to fix the bug described in the initial message. I even added an unit test for it.

I didn't try to force when the __main__ module is unloaded, I didn't see any consensus around that.

Thanks for the bug report, it's now fixed ;-) Sorry for the delay. We had to fix a million of other subtle issues to make the Python shutdown process and the stdlib stronger.

New changeset 307ba4afd0a6 by Victor Stinner in branch 'default':
Issue #21925: Fix test_warnings for release mode
https://hg.python.org/cpython/rev/307ba4afd0a6

New changeset f474898ef6de by Victor Stinner in branch '3.5':
Issue #21925: Fix test_warnings for release mode
https://hg.python.org/cpython/rev/f474898ef6de

versions: + Python 3.6, - Python 3.4

messages: + msg262353

versions: + Python 3.5