classification
Title: [REGRESSION] test_gc fails in non-debug mode.
Type: behavior Stage: resolved
Components: Library (Lib), Tests Versions: Python 3.1, Python 3.2, Python 2.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: benjamin.peterson, brett.cannon, donmez, georg.brandl, pitrou, vstinner
Priority: high Keywords: patch

Created on 2010-11-09 10:05 by donmez, last changed 2010-11-10 17:08 by pitrou. This issue is now closed.

Files
File name Uploaded Description Edit
warnboot.patch pitrou, 2010-11-09 18:07
import_warnings_error.patch vstinner, 2010-11-09 18:20
Messages (8)
msg120854 - (view) Author: Ismail Donmez (donmez) * Date: 2010-11-09 10:05
py3k r86351,


======================================================================
FAIL: test_garbage_at_shutdown (__main__.GCTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "./Lib/test/test_gc.py", line 500, in test_garbage_at_shutdown
    b"shutdown; use", stderr)
AssertionError: b'ResourceWarning: gc: 2 uncollectable objects at shutdown; use' not found in b''

----------------------------------------------------------------------
Ran 28 tests in 0.226s

FAILED (failures=1)
restoring automatic collection
Traceback (most recent call last):
  File "./Lib/test/test_gc.py", line 682, in <module>
    test_main()
  File "./Lib/test/test_gc.py", line 669, in test_main
    run_unittest(GCTests, GCTogglingTests)
  File "/Users/cartman/Sources/py3k/Lib/test/support.py", line 1141, in run_unittest
    _run_suite(suite)
  File "/Users/cartman/Sources/py3k/Lib/test/support.py", line 1124, in _run_suite
    raise TestFailed(err)
test.support.TestFailed: Traceback (most recent call last):
  File "./Lib/test/test_gc.py", line 500, in test_garbage_at_shutdown
    b"shutdown; use", stderr)
AssertionError: b'ResourceWarning: gc: 2 uncollectable objects at shutdown; use' not found in b''
msg120874 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2010-11-09 16:08
For some reason, this starts happening with the Lib/tokenize.py change in r86346. Resource warnings don't get enabled by -Wd:

With r86345:
$ ./python -Wd -c "open('LICENSE')"
-c:1: ResourceWarning: unclosed file <_io.TextIOWrapper name='LICENSE' encoding='UTF-8'>

With r86346:
$ ./python -Wd -c "open('LICENSE')"

But enabling warnings programmatically still works:

$ ./python -c "import warnings; warnings.simplefilter('default'); open('LICENSE')"
-c:1: ResourceWarning: unclosed file <_io.TextIOWrapper name='LICENSE' encoding='UTF-8'>
msg120877 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2010-11-09 16:22
Weirdly, this patch fixes the issue, but I'm unable to say why:


diff -r cd1de1ff2657 Lib/tokenize.py
--- a/Lib/tokenize.py   Tue Nov 09 02:08:59 2010 +0100
+++ b/Lib/tokenize.py   Tue Nov 09 17:16:21 2010 +0100
@@ -24,12 +24,12 @@ __author__ = 'Ka-Ping Yee <ping@lfw.org>
 __credits__ = ('GvR, ESR, Tim Peters, Thomas Wouters, Fred Drake, '
                'Skip Montanaro, Raymond Hettinger, Trent Nelson, '
                'Michael Foord')
+import io
 import re
 import sys
 from token import *
 from codecs import lookup, BOM_UTF8
 import collections
-from io import TextIOWrapper
 cookie_re = re.compile("coding[:=]\s*([-\w.]+)")
 
 import token
@@ -336,16 +336,14 @@ def detect_encoding(readline):
     return default, [first, second]
 
 
-_builtin_open = open
-
 def open(filename):
     """Open a file in read only mode using the encoding detected by
     detect_encoding().
     """
-    buffer = _builtin_open(filename, 'rb')
+    buffer = io.open(filename, 'rb')
     encoding, lines = detect_encoding(buffer.readline)
     buffer.seek(0)
-    text = TextIOWrapper(buffer, encoding, line_buffering=True)
+    text = io.TextIOWrapper(buffer, encoding, line_buffering=True)
     text.mode = 'r'
     return text
msg120879 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2010-11-09 16:34
One observation is that when the -W option is used, the "warnings" module gets loaded very early and itself imports linecache which then imports tokenize. At this point, the standard IO streams have not been initialized (_io is imported later) and the builtin "open" may not exist at all. So when tokenize references "open", it is a NameError at that point (which explains why the "weird fix" above is actually correct).

As an additional annoyance, when importing Lib/warnings.py fails (for example if you sneak in a "1/0" at the beginning of the file), the exception gets silenced: the NameError above doesn't get printed.
msg120884 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2010-11-09 18:07
Here is a patch. It moves warnings initialization after io initialization (the latter being arguably more critical than the former). Also adds two tests.
msg120887 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2010-11-09 18:20
Oh, I also wrote a patch for the warnings error silently ignored: import_warnings_error.patch.
msg120917 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2010-11-10 13:54
> Here is a patch. It moves warnings initialization after 
> io initialization (the latter being arguably more critical 
> than the former). Also adds two tests.

initstdio() and initmain() may emit warnings. Eg. issue #8766 (which now have a test in test_warnings).

It's possible to initialize warnings before initstdio() by rewriting more warnings functions in C (into _warnings). But I don't think that it would solve all issues: emit a warning may write text into stderr, and if stderr is not ready yet, it doesn't work anyway. So I'm ok to exchange initstdio() and warnings initialization: we may loose some warnings, but at least, the warnings machinery will be operational.

But Antoine, could you please add a comment to explain why warnings is initialized after initstdio()?
msg120924 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2010-11-10 17:08
Committed in r86395 (3.x); I've only backported the tests to 2.7 and 3.1.
History
Date User Action Args
2010-11-10 17:08:21pitrousetstatus: open -> closed
resolution: fixed
messages: + msg120924

stage: patch review -> resolved
2010-11-10 13:54:01vstinnersetmessages: + msg120917
2010-11-09 18:20:52vstinnersetfiles: + import_warnings_error.patch

messages: + msg120887
2010-11-09 18:07:47pitrousetfiles: + warnboot.patch
versions: + Python 3.1, Python 2.7
messages: + msg120884

assignee: vstinner ->
keywords: + patch
stage: needs patch -> patch review
2010-11-09 16:34:43pitrousetnosy: + brett.cannon, benjamin.peterson
messages: + msg120879
2010-11-09 16:22:41pitrousetmessages: + msg120877
2010-11-09 16:08:39pitrousetpriority: normal -> high

assignee: vstinner
components: + Library (Lib)
title: [REGRESSION] test_gc fails on Mac OSX 10.6 -> [REGRESSION] test_gc fails in non-debug mode.
nosy: + georg.brandl, vstinner, pitrou

messages: + msg120874
stage: needs patch
2010-11-09 10:05:48donmezcreate