classification
Title: ResourceWarning: Use tracemalloc to display the traceback where an object was allocated when a ResourceWarning is emitted
Type: Stage:
Components: Versions: Python 3.6
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: haypo, python-dev, serhiy.storchaka, yselivanov
Priority: normal Keywords: patch

Created on 2016-03-15 13:15 by haypo, last changed 2016-03-20 11:25 by haypo. This issue is now closed.

Files
File name Uploaded Description Edit
warnings_tracemalloc.patch haypo, 2016-03-15 13:15 review
Messages (11)
msg261812 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2016-03-15 13:15
Python emits ResourceWarning when an object using limited resource is destroyed without being explicitly closed: files, sockets, etc. The problem is that it's hard to find where the object comes from, since the warning can occur very late, in the garbage collector, etc.

I propose to reuse tracemalloc.get_object_traceback() to show were the object was allocated, when tracemalloc traces memory allocations. In practice, I propose to add a new "source" parameter to warnings.showwarning().

Attached patch:

* Add a new keyword-only source parameter to warnings.showwarning()
* Add C function PyErr_ResourceWarning() to pass source
* showwarning() uses tracemalloc.get_object_traceback() to get the traceback were the object was allocated
* Modify socket.socket, io.FileIO and os.scandir destructor to use PyErr_ResourceWarning()


Backward-compatibility problem: The C function PyErr_ResourceWarning() always call warnings.showwarning() with the keyword parameter source. If an application replaces the warnings.showwarning() function, it will probably fail because it doesn't know the source parameter.

I don't know how to handle this backward compatibility issue.


The patch is incomplete, it's not possible yet to emit a warning in pure Python with a source parameter.


x.py script used for examples below:
-----------------
import warnings
import os
import socket

def func2():
    #f=open("/etc/issue")
    #f=os.scandir('.')
    f=socket.socket()
    f=None

def func():
    func2()

func()
-----------------


Output with Python 3.5:
-----
x.py:9: ResourceWarning: unclosed <socket.socket fd=3, ...>
  f=None
-----


Output with -X tracemalloc=5 command line option and patched Python 3.6:
-----
x.py:9: ResourceWarning: unclosed <socket.socket fd=3, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=0, laddr=('0.0.0.0', 0)>
  f=None
Object allocated at (most recent call first):
  File "x.py", lineno 8
    f=socket.socket()
  File "x.py", lineno 12
    func2()
  File "x.py", lineno 14
    func()
-----

It's much easier to understand where the warning comes from, no? At x.py:8, line "f=socket.socket()".

Note: the traceback doesn't contain the function name, since tracemalloc only stores filename and line number.


See also the issue #26564 "Malloc debug hooks: display memory block traceback on error".


For Python < 3.6, I wrote "res_warn.py" script which monkey-patches io.FileIO and socket.socket to implement something similar. The script is a fragile hack. I would prefer to have the feature built-in Python.

https://bitbucket.org/haypo/misc/src/0a40f27360424145bad0f9b62c9e9148ffdbb169/python/res_warn.py
msg261815 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2016-03-15 14:32
> Backward-compatibility problem: The C function PyErr_ResourceWarning() always call warnings.showwarning() with the keyword parameter source. If an application replaces the warnings.showwarning() function, it will probably fail because it doesn't know the source parameter.

I proposed the issue #26568 "Add a new warnings.showmsg() function taking a warnings.WarningMessage object" to fix this issue.
msg261907 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2016-03-17 11:08
I used this patch to identify a ResourceWarning in test_faulthandler when the test is interrupted by CTRL+c: it's really efficient!

I will be very useful to identify all ResourceWarning that I saw in test_asyncio, like the ones seen on the AIX buildbot.
msg262007 - (view) Author: Roundup Robot (python-dev) Date: 2016-03-19 00:23
New changeset 2428d794b0e1 by Victor Stinner in branch 'default':
On ResourceWarning, log traceback where the object was allocated
https://hg.python.org/cpython/rev/2428d794b0e1
msg262012 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2016-03-19 01:25
It looks like io.FileIO has a strong implementation of the destructor. If the object becomes alive again because of random code called in the destructor, the object is not removed.

socket and os.scandir have a classical unsafe destructor.

Moreover, I'm no more sure about the chosen design. When warnings.catch_warnings() is used and an unclosed io.FileIO is destroyed, the object is kept alive because it is stored in the "source" attribute of a warnings.WarningMessage.

I don't know if keeping WarningMessaging alive longer than the call to showwarning() (or _showarnmsg) is a common use case or not. The issue #26568 wants to promote the WarningMessage class, so some users may start to keep it alive.

An alternative is to format the object traceback and pass the traceback to WarningMessage. It requires to decide the format of the traceback (list of ..., string, something else?).
msg262013 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2016-03-19 01:28
When warnings._showwarnmsg(), the io.FileIO object is not closed yet, so all attributes are accessible, which can be useful. Hopefully, the file is closed even if it is kept alive by the warning logger. So maybe it's ok to keep the Python object alive, if the underlying resource (the file descriptor) is released. I mean, it's not a big deal.
msg262015 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2016-03-19 01:31
For socket & scandir, I opened the issue #26590: "socket destructor: implement finalizer".
msg262016 - (view) Author: Roundup Robot (python-dev) Date: 2016-03-19 01:52
New changeset b8acf98beca9 by Victor Stinner in branch 'default':
Try to fix test_warnings on Windows
https://hg.python.org/cpython/rev/b8acf98beca9
msg262029 - (view) Author: Roundup Robot (python-dev) Date: 2016-03-19 09:01
New changeset 543639cdfdb9 by Victor Stinner in branch 'default':
Try again to fix test_warnings on Windows
https://hg.python.org/cpython/rev/543639cdfdb9
msg262030 - (view) Author: Roundup Robot (python-dev) Date: 2016-03-19 09:33
New changeset 691fba640266 by Victor Stinner in branch 'default':
Issue #26567: enhance ResourceWarning example
https://hg.python.org/cpython/rev/691fba640266
msg262067 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2016-03-20 11:25
Cool, test_warnings, test_logging, etc. pass again on Windows buildbots. I close the issue.

As I wrote, I opened a second issue for socket & os.scandir.
History
Date User Action Args
2016-03-20 11:25:42hayposetstatus: open -> closed
resolution: fixed
messages: + msg262067
2016-03-19 09:33:45python-devsetmessages: + msg262030
2016-03-19 09:01:06python-devsetmessages: + msg262029
2016-03-19 01:52:05python-devsetmessages: + msg262016
2016-03-19 01:31:33hayposetmessages: + msg262015
2016-03-19 01:28:47hayposetmessages: + msg262013
2016-03-19 01:25:59hayposetmessages: + msg262012
2016-03-19 00:23:49python-devsetnosy: + python-dev
messages: + msg262007
2016-03-17 11:08:30hayposetmessages: + msg261907
2016-03-15 14:32:49hayposetmessages: + msg261815
2016-03-15 13:17:49hayposettitle: Use tracemalloc to display the traceback where an object was allocated when a ResourceWarning is emitted -> ResourceWarning: Use tracemalloc to display the traceback where an object was allocated when a ResourceWarning is emitted
2016-03-15 13:15:16haypocreate