classification
Title: In developer mode (-X dev), ResourceWarning is only emited once per line numbers
Type: Stage: resolved
Components: Versions: Python 3.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: ncoghlan, pitrou, serhiy.storchaka, vstinner
Priority: normal Keywords: patch

Created on 2017-11-20 14:57 by vstinner, last changed 2017-11-27 11:14 by vstinner. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 4482 merged vstinner, 2017-11-20 23:43
PR 4584 merged vstinner, 2017-11-27 09:44
Messages (14)
msg306548 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-20 14:57
The -X dev mode currently *hides* some ResourceWarning warnings:

$ cat x.py 
def func():
    open('/etc/issue')

func()
func()

$ ./python x.py 
x.py:2: ResourceWarning: unclosed file <_io.TextIOWrapper name='/etc/issue' mode='r' encoding='UTF-8'>
  open('/etc/issue')
x.py:2: ResourceWarning: unclosed file <_io.TextIOWrapper name='/etc/issue' mode='r' encoding='UTF-8'>
  open('/etc/issue')

haypo@selma$ ./python -X dev x.py 
x.py:2: ResourceWarning: unclosed file <_io.TextIOWrapper name='/etc/issue' mode='r' encoding='UTF-8'>
  open('/etc/issue')


The problem is that the "-W default" inserted by -X dev overrides the final filter on ResourceWarning:

$ ./python -X dev -c 'import warnings, pprint; pprint.pprint(warnings.filters)'
[('default',
  re.compile('', re.IGNORECASE),
  <class 'Warning'>,
  re.compile(''),
  0),
 ('ignore', None, <class 'BytesWarning'>, None, 0),
 ('always', None, <class 'ResourceWarning'>, None, 0)]
msg306603 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-21 00:42
Attached PR 4482 fixes warnings filters:

haypo@selma$ ./python -X dev -c 'import warnings, pprint; pprint.pprint(warnings.filters)'
[('ignore', None, <class 'BytesWarning'>, None, 0),
 ('always', None, <class 'ResourceWarning'>, None, 0),
 ('default', None, <class 'Warning'>, None, 0)]
msg306609 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-21 01:32
New changeset 09f3a8a1249308a104a89041d82fe99e6c087043 by Victor Stinner in branch 'master':
bpo-32089: Fix warnings filters in dev mode (#4482)
https://github.com/python/cpython/commit/09f3a8a1249308a104a89041d82fe99e6c087043
msg306635 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2017-11-21 11:38
I don't agree with this.  You're comparing "-X dev" with a pydebug build of Python, not with a normal Python.

Your example shows the problem.  If a program calls func() 1000 times in a row, they will show the same warning 1000 times.  What does it bring to have the exact same warning (and line number) displayed 1000 times instead of once?  Nothing.  There is a reason the filter "default" isn't the same as "always", and it's that "always" can be completely overwhelming.
msg306637 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-21 13:46
> If a program calls func() 1000 times in a row, they will show the same warning 1000 times.  What does it bring to have the exact same warning (and line number) displayed 1000 times instead of once? Nothing.  There is a reason the filter "default" isn't the same as "always", and it's that "always" can be completely overwhelming.

I don't know the rationale of the "always" action rather than "default". The choice was made 7 years ago, when Georg Brandl implemented the new ResourceWarning category: commit 08be72d0aa0112118b79d271479598c218adfd23.

The problem of ResourceWarning is that the warning logs where the last reference to the resource was cleared, or where the a garbage collection was triggered. Multiple resources can be created from different places, but all "die" at the same place.

In Python 3.6, I enhanced ResourceWarning to log also the traceback where the leaked resource has been created, if the tracemalloc is tracing memory allocations. When tracemalloc is used, it's useful to log ResourceWarning multiple times even if the warning itself is logged multipletimes. Well, that's an unusual usage of the ResourceWarning, we can also suggest to use -W always::ResourceWarning in that case.


> I don't agree with this.  You're comparing "-X dev" with a pydebug build of Python, not with a normal Python.

In general, I would like to offer the same experience in "development mode" (-X dev) and with a pydebug build.

For ResourceWarning, your rationale only concerns pydebug build, no?
msg306638 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2017-11-21 13:50
Le 21/11/2017 à 14:46, STINNER Victor a écrit :
> 
> I don't know the rationale of the "always" action rather than "default".

Neither do I.  But I don't think it matters a lot.  pydebug builds are
almost only used by Python core developers.  "developer mode" is target
at every Python developer.

> The problem of ResourceWarning is that the warning logs where the last reference to the resource was cleared, or where the a garbage collection was triggered. Multiple resources can be created from different places, but all "die" at the same place.

If they have different names, they will be logged separately.

>>> def f(fname):
...     open(fname)
...
>>> f('setup.py')
__main__:2: ResourceWarning: unclosed file <_io.TextIOWrapper
name='setup.py' mode='r' encoding='UTF-8'>
>>> f('setup.py')
>>> f('LICENSE.txt')
__main__:2: ResourceWarning: unclosed file <_io.TextIOWrapper
name='LICENSE.txt' mode='r' encoding='UTF-8'>
>>> f('LICENSE.txt')
>>>

> For ResourceWarning, your rationale only concerns pydebug build, no?

Why?  I'm talking about "-X dev", not pydebug builds.
msg306639 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2017-11-21 13:51
I forgot: the snippet above was made with "python -Wdefault::ResourceWarning".
msg306641 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2017-11-21 14:09
See also issue27535.
msg306646 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-21 14:48
Antoine:
> If they have different names, they will be logged separately.

Oh wow, nice behaviour, I like it :-)

Antoine:
>> For ResourceWarning, your rationale only concerns pydebug build, no?
> Why?  I'm talking about "-X dev", not pydebug builds.

Oops sorry, typo (brain error), I mean: "also concerns".

Serhiy:
> See also issue27535.

Oh, not leaking memory in warnings registies is a nice side effect of the "always" action :-)

--

It's much more complicated than what I expected to get the "correct behaviour" for warnings :-/
msg306868 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-24 01:22
Antoine: What do you think of using the "default" action for pydebug build and -X dev?
msg306905 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2017-11-24 16:55
> Antoine: What do you think of using the "default" action for pydebug build and -X dev?

That would be fine with me.
msg306946 - (view) Author: Nick Coghlan (ncoghlan) * (Python committer) Date: 2017-11-25 05:12
+1 from me for using "default" instead of "always" for ResourceWarning.

Folks can always combine "-X tracemalloc" with "-W always::ResourceWarning" if want to ensure they see absolutely every resource warning, rather than only representative ones.
msg307049 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-27 11:11
New changeset 21c7730761e2a768e33b89b063a095d007dcfd2c by Victor Stinner in branch 'master':
bpo-32089: Use default action for ResourceWarning (#4584)
https://github.com/python/cpython/commit/21c7730761e2a768e33b89b063a095d007dcfd2c
msg307050 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-27 11:14
The "default warning filters" are documented, but only for Python compiled in release mode:
https://docs.python.org/dev/library/warnings.html#default-warning-filters

So I didn't touch this documentation.

The initial issue is now fixed: the development mode (-X dev) now behaves as the debug mode (pydebug build) for the default warning filters.

The second issue, Antoine's complain about the "always" action, was also fixed.

I close the issue. At the end, we should get a better debug experience ;-)
History
Date User Action Args
2017-11-27 11:14:41vstinnersetstatus: open -> closed
resolution: fixed
messages: + msg307050

stage: patch review -> resolved
2017-11-27 11:11:57vstinnersetmessages: + msg307049
2017-11-27 09:44:40vstinnersetstage: resolved -> patch review
pull_requests: + pull_request4507
2017-11-25 05:12:51ncoghlansetmessages: + msg306946
2017-11-24 16:55:55pitrousetmessages: + msg306905
2017-11-24 01:22:43vstinnersetmessages: + msg306868
2017-11-21 14:48:10vstinnersetmessages: + msg306646
2017-11-21 14:09:56serhiy.storchakasetmessages: + msg306641
2017-11-21 13:51:47pitrousetmessages: + msg306639
2017-11-21 13:50:47pitrousetmessages: + msg306638
2017-11-21 13:46:03vstinnersetmessages: + msg306637
2017-11-21 11:38:16pitrousetstatus: closed -> open
resolution: fixed -> (no value)
messages: + msg306635
2017-11-21 01:35:24vstinnersetstatus: open -> closed
resolution: fixed
stage: patch review -> resolved
2017-11-21 01:32:42vstinnersetmessages: + msg306609
2017-11-21 00:42:26vstinnersetnosy: + pitrou
2017-11-21 00:42:16vstinnersetmessages: + msg306603
2017-11-20 23:43:51vstinnersetkeywords: + patch
stage: patch review
pull_requests: + pull_request4419
2017-11-20 14:57:20vstinnercreate