test_warnings modifies warnings.filters when running with "-W default"

[florentx]

BPO	18383
Nosy	@vstinner, @rbtcollins, @ezio-melotti, @florentx, @berkerpeksag, @vadmium, @serhiy-storchaka, @ashkop
Files	issue18383_test_warnings_filters.diff issue18383_remove_dups.patch issue18383_remove_dups_and_test.patch issue18383_assert_warns_and_dups.patch issue18383_assert_warns_and_dups_v2.patch issue18383_34.diff issue18383_34_2.diff issue18383_avoid_dups_3.diff issue18383_avoid_dups_4.diff

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = 'https://github.com/berkerpeksag'
closed_at = <Date 2016-05-26.12:07:45.473>
created_at = <Date 2013-07-06.13:36:14.450>
labels = ['type-bug', 'tests']
title = 'test_warnings modifies warnings.filters when running with "-W default"'
updated_at = <Date 2016-11-21.15:39:26.872>
user = 'https://github.com/florentx'

bugs.python.org fields:

activity = <Date 2016-11-21.15:39:26.872>
actor = 'python-dev'
assignee = 'berker.peksag'
closed = True
closed_date = <Date 2016-05-26.12:07:45.473>
closer = 'martin.panter'
components = ['Tests']
creation = <Date 2013-07-06.13:36:14.450>
creator = 'flox'
dependencies = []
files = ['30817', '38301', '38841', '38876', '38982', '40073', '40178', '42938', '43005']
hgrepos = []
issue_num = 18383
keywords = ['patch']
message_count = 34.0
messages = ['192441', '192442', '192443', '194567', '232451', '237050', '240055', '240147', '240314', '240324', '240523', '240846', '242171', '242966', '245454', '247719', '247737', '248479', '248499', '248559', '249179', '249581', '249583', '249599', '266047', '266049', '266076', '266087', '266399', '266410', '266423', '266427', '266433', '281366']
nosy_count = 9.0
nosy_names = ['vstinner', 'rbcollins', 'ezio.melotti', 'flox', 'python-dev', 'berker.peksag', 'martin.panter', 'serhiy.storchaka', 'ashkop']
pr_nums = []
priority = 'low'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue18383'
versions = ['Python 3.5', 'Python 3.6']

[florentx]

Running the test suite with -Wd, we got the warning:

[247/375] test_warnings
Warning -- warnings.filters was modified by test_warnings

This is how to reproduce:

./python -Wd

import warnings
from test import support

saved = warnings.filters.copy()

c_warnings = support.import_fresh_module('warnings', fresh=['_warnings'])

saved == warnings.filters
# --> False

[florentx]

Much simpler:

$ ./python -Wd

import warnings
import sys
saved = warnings.filters.copy()

del sys.modules['warnings']
import warnings

assert warnings.filters != saved
assert warnings.filters.pop(0) = warnings.filters[0]
assert warnings.filters == saved

Explanation: the "default" filter is duplicated on each reload of the warnings module.

[florentx]

This patch fixes the issue.

[ezio-melotti]

LGTM

[serhiy-storchaka]

The patch fixes symptoms. It would be better to fix the cause of the issue -- warnings.filters shouldn't duplicate after module reloading.

[ashkop]

The issue occurs only if C implementation of _warnings is available. It is caused by re-use of global filters variable from _warnings when warnings is being re-imported.
So warnings modifies _warnings.filters on first import. Then, when you import warnings again it uses already modified version of _warnings.filters and adds same filter for the second time.

I attach a simple patch that prevents duplicates in filters. I'm not sure if this is a best way to fix the problem, but it works. It certainly affects performance of filterwarnings(), but there shouldn't be a lot of filters anyway.

Making filters a set() will solve the problem also, but will require API changes. Although I didn't find anywhere in documentation that warnings.filters should be a list, someone might rely on its .append() method.

[berkerpeksag]

issue18383_remove_dups.patch looks good to me. A test would be nice.

[ashkop]

When caller adds duplicate filter maybe we should promote his filter to the beginning of filters list? This feels more correct to me. So if user adds duplicate filter everything will work as if we added it.

[vadmium]

I tried issue18383_remove_dups_and_test.patch, but it doesn’t seem to fix the problem, and causes new test failures and warnings. Let me know if you want more info. Existing messages that I thought this was meant to fix:

[372/393/5] test_warnings
/media/disk/home/proj/python/cpython/Lib/test/test_warnings.py:100: UserWarning: FilterTests.test_ignore_after_default
self.module.warn(message, UserWarning)
/media/disk/home/proj/python/cpython/Lib/test/test_warnings.py:100: UserWarning: FilterTests.test_ignore_after_default
self.module.warn(message, UserWarning)
Warning -- warnings.filters was modified by test_warnings
[. . .]
1 test altered the execution environment:
test_warnings

Three new failures:

[ 12/393/1] test___all__
test test___all__ failed -- Traceback (most recent call last):
  File "/media/disk/home/proj/python/cpython/Lib/test/test___all__.py", line 105, in test_all
    self.check_all(modname)
  File "/media/disk/home/proj/python/cpython/Lib/test/test___all__.py", line 28, in check_all
    raise FailedImport(modname)
  File "/media/disk/home/proj/python/cpython/Lib/contextlib.py", line 66, in __exit__
    next(self.gen)
  File "/media/disk/home/proj/python/cpython/Lib/test/support/__init__.py", line 1124, in _filterwarnings
    raise AssertionError("unhandled warning %s" % reraise[0])
AssertionError: unhandled warning {message : DeprecationWarning('stat_float_times() is deprecated',), category : 'DeprecationWarning', filename : '/media/disk/home/proj/python/cpython/Lib/test/test_os.py', lineno : 75, line : None}
[. . .]
[147/393/3] test_global
test test_global failed -- multiple errors occurred; run in verbose mode for details
[. . .]
[240/393/5] test_pkgutil
test test_pkgutil failed -- Traceback (most recent call last):
  File "/media/disk/home/proj/python/cpython/Lib/test/test_pkgutil.py", line 327, in test_importer_deprecated
    x = pkgutil.ImpImporter("")
  File "/media/disk/home/proj/python/cpython/Lib/contextlib.py", line 66, in __exit__
    next(self.gen)
  File "/media/disk/home/proj/python/cpython/Lib/test/support/__init__.py", line 1124, in _filterwarnings
    raise AssertionError("unhandled warning %s" % reraise[0])
AssertionError: unhandled warning {message : PendingDeprecationWarning("the imp module is deprecated in favour of importlib; see the module's documentation for alternative uses",), category : 'PendingDeprecationWarning', filename : '/media/disk/home/proj/python/cpython/Lib/importlib/_bootstrap.py', lineno : 321, line : None}
[. . .]
5 tests failed:
    test___all__ test_distutils test_gdb test_global test_pkgutil

(Ignore distutils and GDB; they normally fail for me.) New warnings, though I suspect they may be a side effect and not entirely the fault of the patch:

[ 18/393/1] test_unittest
[163/393/4] test_imp
[169/393/4] test_importlib
[205/393/4] test_modulefinder
[220/393/4] test_os
[241/393/5] test_platform
[329/393/5] test_threaded_import
[354/393/5] test_unicode

[ashkop]

So, there are actually two issues, both of them causing the original warning.

First issue was pointed out by Florent Xicluna. warnings.filterwarnings() method can create duplicates in warnings.filters.

Second issue is that assertWarns() works incorrectly in test_warnings.py due to use of import_fresh_module(). This produced original warning even without -Wd flag.

I attached a patch that fixes both issues for review. It includes a fix of previous patch, so no new warnings are produced. But perhaps we should separate these issues and create two patches.

[vadmium]

issue18383_assert_warns_and_dups.patch fixes all my new test suite complaints, and removes the message about altering warnings.filters.

[ashkop]

Removed unnecessary assertWarns() contexts and fixed spelling errors.