Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
florentx mannequin opened this issue Jul 6, 2013 · 34 comments
Closed

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

florentx mannequin opened this issue Jul 6, 2013 · 34 comments
Assignees
Labels
tests Tests in the Lib/test dir type-bug An unexpected behavior, bug, or error

Comments

@florentx
Copy link
Mannequin

florentx mannequin commented Jul 6, 2013

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
    Copy link
    Mannequin Author

    florentx mannequin commented Jul 6, 2013

    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 florentx mannequin added tests Tests in the Lib/test dir type-bug An unexpected behavior, bug, or error labels Jul 6, 2013
    @florentx
    Copy link
    Mannequin Author

    florentx mannequin commented Jul 6, 2013

    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
    Copy link
    Mannequin Author

    florentx mannequin commented Jul 6, 2013

    This patch fixes the issue.

    @ezio-melotti
    Copy link
    Member

    LGTM

    @serhiy-storchaka
    Copy link
    Member

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

    @ashkop
    Copy link
    Mannequin

    ashkop mannequin commented Mar 2, 2015

    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
    Copy link
    Member

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

    @ashkop
    Copy link
    Mannequin

    ashkop mannequin commented Apr 6, 2015

    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
    Copy link
    Member

    vadmium commented Apr 9, 2015

    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
    Copy link
    Mannequin

    ashkop mannequin commented Apr 9, 2015

    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
    Copy link
    Member

    vadmium commented Apr 12, 2015

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

    @ashkop
    Copy link
    Mannequin

    ashkop mannequin commented Apr 14, 2015

    Removed unnecessary assertWarns() contexts and fixed spelling errors.

    @ashkop
    Copy link
    Mannequin

    ashkop mannequin commented Apr 28, 2015

    *ping*

    @ashkop
    Copy link
    Mannequin

    ashkop mannequin commented May 12, 2015

    Please, review the patch.

    @vadmium
    Copy link
    Member

    vadmium commented Jun 18, 2015

    FWIW there is a new message currently being triggered by test___all__. The patch here also stops this message.

    $ hg update 4335d898be59
    $ ./python -bWall -m test test___all__
    [1/1] test___all__
    Warning -- warnings.filters was modified by test___all__
    1 test altered the execution environment:
        test___all__

    @berkerpeksag
    Copy link
    Member

    Here is an updated patch (against 3.4 branch). I've just made some small cosmetic changes and split the test into two parts (filterwarnings and simplefilter). Patch looks reasonable to me, but it would be nice to get a second opinion.

    @ashkop
    Copy link
    Mannequin

    ashkop mannequin commented Jul 31, 2015

    Looking at this patch again, I'm wondering if it is correct to remove duplicate filter if append=True. Perhaps in this case it is more correct to leave the filter in place and do not append new one?

    @rbtcollins
    Copy link
    Member

    @ashkop so append=True could be clearer as 'atend=True' - both forms of call are expected to add the filter, but one adds to the front, one to the end.

    Looking at warn_explicit, its takes the first matching filter, and then acts on its action.

    So the following:
    simplefilter("ignore")
    simplefilter("error", append=True)
    simplefilter("ignore", append=True)

    will ignore all warnings today.

    With this patch it will error on all warnings.

    So at *best* I think this is a breaking API change.

    Old:
    >>> from warnings import simplefilter, warn
    >>> simplefilter("ignore")
    >>> simplefilter("error", append=True)
    >>> simplefilter("ignore", append=True)
    >>> warn("boo")
    >>> 
    
    With this patch:
    >>> from warnings import simplefilter, warn
    >>> simplefilter("ignore")
    >>> simplefilter("error", append=True)
    >>> simplefilter("ignore", append=True)
    >>> warn("boo")
    Traceback (most recent call last):
      File "<stdin>", line 1, in <module>
    UserWarning: boo
    >>> 

    Now, perhaps its desirable to make this change. I haven't decided yet about the tastefulness of the new API, but if we do we're going to need docstring updates, and API doc changes to match it.

    Since the goal here is to fix module reloads, I think the right way to do that is to only change the module initialisation code.

    e.g. add an optional 'no_duplicate' parameter to simplefilter and use that from the module initialisation. Thats backwards compatible and opt-in. If we don't think it should be public, make it a _ prefixed parameter. I think it would be fine to be public though.

    @ashkop
    Copy link
    Mannequin

    ashkop mannequin commented Aug 13, 2015

    @rbcollins that is exactly what was trying to say in previous comment. We can make a change to current patch that won't affect behavior. In old API in this sequence of filters last filter was never used:

    simplefilter("ignore")
    simplefilter("error", append=True)
    simplefilter("ignore", append=True)  # never used

    So I suggest that new patch should work like this:

    simplefilter("error")
    simplefilter("ignore", append=True)  # appends new filter to the end
    
    simplefilter("ignore")
    simplefilter("error", append=True)
    simplefilter("ignore", append=True)  # does nothing since same filter is present.

    This way filtering will work in the same way it worked before patch and we won't have duplicates.

    I'll update the patch as soon as I will get to my computer.

    @ashkop
    Copy link
    Mannequin

    ashkop mannequin commented Aug 14, 2015

    This is updated patch that doesn't alter warn_explicit behavior.

    So the following:
    simplefilter("ignore")
    simplefilter("error", append=True)
    simplefilter("ignore", append=True)

    will ignore all warnings with this patch and no duplicates are inserted to warnings.filters. Also added a test for that case.

    @vadmium
    Copy link
    Member

    vadmium commented Aug 26, 2015

    Florent’s manual reproducer is fixed by issue18383_34_2.diff, as is test___all__. And I think the new logic for changing the priority of the filter entries might be sound now. But it does seem like we are adding unnecessary complexity to the implementation just to avoid a quirk of the test suite. Maybe it would be better to save and restore the original filters in the test suite, with a comment explaining why. Or perhaps set a _warnings._options_processed flag to prevent the double initialization?

    FTR Alex already hinted at this, but I only now realize issue18383_assert_warns_and_dups_v2.patch contains extra fixes for assertWarns() that are only applicable to 3.5+. They are basically a followup of bpo-16382 and bpo-23027, rather than the original issue here, although the symptom is almost the same.

    @vadmium
    Copy link
    Member

    vadmium commented Sep 2, 2015

    Revision c1396d28c440 looks like it may help. Possibly with the 3.5+ assertWarns() half of the problem; I’ll have to have a closer look later.

    @vstinner
    Copy link
    Member

    vstinner commented Sep 2, 2015

    Revision c1396d28c440 looks like it may help. Possibly with the 3.5+ assertWarns() half of the problem; I’ll have to have a closer look later.

    Oh, I wasn't aware of this issue. Good to know that I contributed to it :-)

    @vadmium
    Copy link
    Member

    vadmium commented Sep 3, 2015

    Okay so I take back my first proposal of restoring the filters in the test suite, which would bring us back to <https://bugs.python.org/issue18383#msg232451\>.

    Also, my second proposal of setting a flag doesn’t look so easy either. The “_warnings” C module caches the filters list in a static variable between module reloads, so it is not so easy to keep a flag recording whether the “warnings” Python module needs to initialize it. I started on a patch, but discovered I would have to make uncomfortable changes to the C module.

    So unless anyone has any better ideas, I think Alex’s patch is as good and practical enough. And yes Victor’s change does fix the other half of the problem.

    @vadmium
    Copy link
    Member

    vadmium commented May 22, 2016

    I am inclined to go with Alex’s patch. I am uploading a new version of it, issue18383_avoid_dups_3.diff, which resolves conflicts with recent changes.

    @vadmium
    Copy link
    Member

    vadmium commented May 22, 2016

    Forgot to refresh my patch

    @berkerpeksag
    Copy link
    Member

    LGTM

    @serhiy-storchaka
    Copy link
    Member

    $ ./python -We::UserWarning -m test.regrtest test_warnings
    Run tests sequentially
    0:00:00 [1/1] test_warnings
    /home/serhiy/py/cpython/Lib/test/test_warnings/__init__.py:108: UserWarning: FilterTests.test_ignore_after_default
      self.module.warn(message, UserWarning)
    /home/serhiy/py/cpython/Lib/test/test_warnings/__init__.py:108: UserWarning: FilterTests.test_ignore_after_default
      self.module.warn(message, UserWarning)
    test test_warnings failed -- multiple errors occurred; run in verbose mode for details
    test_warnings failed
    1 test failed:
        test_warnings
    Total duration: 0:00:02

    @vadmium
    Copy link
    Member

    vadmium commented May 26, 2016

    New patch with common _add_filters() function, and added resetwarnings() calls to avoid the conflict with pre-defined filters.

    @serhiy-storchaka
    Copy link
    Member

    LGTM, except that initial_len is now always 0.

    @python-dev
    Copy link
    Mannequin

    python-dev mannequin commented May 26, 2016

    New changeset f57f4e33ba5e by Martin Panter in branch '3.5':
    Issue bpo-18383: Avoid adding duplicate filters when warnings is reloaded
    https://hg.python.org/cpython/rev/f57f4e33ba5e

    New changeset 90bb91be6f3b by Martin Panter in branch 'default':
    Issue bpo-18383: Merge warnings fix from 3.5
    https://hg.python.org/cpython/rev/90bb91be6f3b

    @vadmium
    Copy link
    Member

    vadmium commented May 26, 2016

    I eliminated initial_len from my final version.

    @vadmium vadmium closed this as completed May 26, 2016
    @vstinner
    Copy link
    Member

    Note: My issue bpo-26742 has been marked as a duplicate of this one.

    I confirm that "./python -Wd -m test -j0 test_warnings" doesn't complain "1 test altered the execution environment: test_warnings" anymore. Thanks for the fix.

    @python-dev
    Copy link
    Mannequin

    python-dev mannequin commented Nov 21, 2016

    New changeset 5e8ef1493843 by Victor Stinner in branch '3.6':
    Implement rich comparison for _sre.SRE_Pattern
    https://hg.python.org/cpython/rev/5e8ef1493843

    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    tests Tests in the Lib/test dir type-bug An unexpected behavior, bug, or error
    Projects
    None yet
    Development

    No branches or pull requests

    6 participants