Issue 13390: Hunt memory allocations in addition to reference leaks (original) (raw)
Created on 2011-11-12 23:24 by pitrou, last changed 2022-04-11 14:57 by admin. This issue is now closed.
Messages (31)
Author: Antoine Pitrou (pitrou) * 
Date: 2011-11-12 23:24
This patch adds a counting of the number of allocated memory blocks (through the PyObject_Malloc API). Together with -R, it can help chase those memory leaks which aren't reference leaks (see c6dafa2e2594).
The sys.getallocedblocks() function is also available in non-debug mode. This is meant to help 3rd party extension writers, who rarely have access to debug builds.
To avoid too many false positives, is a prerequisite (at least for the "test -R" part of the patch). Even after it, there are still a couple "test -R" failures; we'd have to investigate them.
Author: Alyssa Coghlan (ncoghlan) *
Date: 2011-11-13 01:06
I added some review comments to the patch, but I'm not sure how usable this is going to be in practice. References generally stay fairly stable while using the interactive interpreter, but the new block accounting jumps around all over the place due to the internal free lists (which don't count in for 'gettotalrefcounts', but do count in the new block accounting). The following interpreter session has both this patch and the #13389 patch applied:
a = sys.getallocedblocks() [76652 refs, 21773 blocks] a 21779 [76652 refs, 21774 blocks] x = [None]*10000 [76652 refs, 21776 blocks] del x [66650 refs, 21775 blocks] gc.collect(); gc.collect(); gc.collect() 0 0 0 [66650 refs, 21756 blocks] b = sys.getallocedblocks() [66652 refs, 21772 blocks] b - a -2 [66652 refs, 21772 blocks]
So, generally +1 on the idea, but I think we should hide at least the initial implementation behind PY_REF_DEBUG until we're sure we've worked the kinks out of it.
Author: Antoine Pitrou (pitrou) *
Date: 2011-11-13 16:27
Thanks for the comments, here is a new patch addressing them. I've kept the C API available in all builds (since it's private), but sys.getallocatedblocks() is only available in debug builds.
As for the memory leak run results, I think we may have to devise a heuristic where results like [1,0,1] (or similar variation of 0s, 1s, and -1s) are considered a success, but others like [1,1,1] are a failure.
Author: Antoine Pitrou (pitrou) *
Date: 2011-11-13 16:53
And the latest patch (debugblocks3.patch) adds said heuristic.
Author: Charles-François Natali (neologix) *
Date: 2011-11-15 08:11
Together with -R, it can help chase those memory leaks which aren't reference leaks (see c6dafa2e2594).
Valgrind does a much better job at this: it will also show you where the leaked blocks were allocated. OTOH, Valgrind is Linux-only and slow, but since I haven't used the '-R' option much, I don't know how usable this will be in practice (detecting memory leaks is one thing, identifying them is even better :-).
Author: Alyssa Coghlan (ncoghlan) *
Date: 2011-11-15 09:23
This will likely be a decent "you have a problem" indicator, but you may still need tools like Valgrind to actually track down the cause of that problem.
Author: Antoine Pitrou (pitrou) *
Date: 2011-11-15 14:22
Valgrind does a much better job at this: it will also show you where the leaked blocks were allocated. OTOH, Valgrind is Linux-only and slow, but since I haven't used the '-R' option much, I don't know how usable this will be in practice (detecting memory leaks is one thing, identifying them is even better :-).
Yes, Valgrind is much more exhaustive and precise, but you have to build Python --with-valgrind, to find the correct options to pass to Valgrind, and also to parse the output. For example, OpenSSL seems to cause lots of errors such as:
==20599== Conditional jump or move depends on uninitialised value(s) ==20599== at 0xA2BB0B3: BN_div (in /usr/lib64/libcrypto.so.1.0.0) ==20599== by 0xA2C125E: BN_nnmod (in /usr/lib64/libcrypto.so.1.0.0) ==20599== by 0xA2C15CD: BN_mod_mul (in /usr/lib64/libcrypto.so.1.0.0) ==20599== by 0xA2C37F0: BN_BLINDING_convert_ex (in /usr/lib64/libcrypto.so.1.0.0) ==20599== by 0xA2E15D6: ??? (in /usr/lib64/libcrypto.so.1.0.0) ==20599== by 0x9FE6363: ssl3_get_client_key_exchange (in /usr/lib64/libssl.so.1.0.0) ==20599== by 0x9FE83A7: ssl3_accept (in /usr/lib64/libssl.so.1.0.0) ==20599== by 0xF804190: PySSL_SSLdo_handshake (_ssl.c:390) ==20599== by 0x47C0E9: PyEval_EvalFrameEx (ceval.c:3985) ==20599== by 0x47CAC3: PyEval_EvalCodeEx (ceval.c:3376) ==20599== by 0x47B3F1: PyEval_EvalFrameEx (ceval.c:4099) ==20599== by 0x47C1DB: PyEval_EvalFrameEx (ceval.c:4089)
Right now this patch will allow to enrich the daily refleak runs (those that send an e-mail to python-checkins). If someone finds a way to sanitize Valgrind output, a daily Valgrind run would be cool as well.
Author: Charles-François Natali (neologix) *
Date: 2011-12-01 17:55
If someone finds a way to sanitize Valgrind output,
Did you use the valgrind suppression file (Misc/valgrind-python.supp)? If yes, then one could simply use --gen-suppressions=yes to add those spurious warning to the suppression file.
a daily Valgrind run would be cool as well.
Daily, or rather weakly, since running under valgrind is so much slower ;-)
Author: Antoine Pitrou (pitrou) *
Date: 2011-12-01 18:34
If someone finds a way to sanitize Valgrind output,
Did you use the valgrind suppression file (Misc/valgrind-python.supp)?
Ah, I hadn't. But using it doesn't seem to make much of a difference. Also, the suppressions file seems quite inflexible (it has hardcoded library version numbers for third-party libs).
Author: STINNER Victor (vstinner) *
Date: 2011-12-02 01:11
The overhead on PyObject_Malloc() is just an increment on an integer, so it is very low (or null).
The feature is interesting, but I'm not convinced that a very simple counter is enough to track memory leaks. It may help the CPython test suite, but what about real world application?
I think we should hide at least the initial implementation behind PY_REF_DEBUG until we're sure we've worked the kinks out of it.
Programs not always behave exactly the same in debug or in release mode. Sometimes, bugs disappear in debug mode :-(
If the feature is written to track memory leaks in the CPython test suite, it's ok to only expose the function in debug mode.
Right now this patch will allow to enrich the daily refleak runs
Did you already found real leaks using your hack^Wpatch? (was c6dafa2e2594 found by your tool?)
Author: Antoine Pitrou (pitrou) *
Date: 2011-12-02 18:12
The feature is interesting, but I'm not convinced that a very simple counter is enough to track memory leaks. It may help the CPython test suite, but what about real world application?
Good question. A simple counter is the only thing we can enable by default, though. Anything else would require recompiling Python, which is probably a barrier for most users.
Did you already found real leaks using your hack^Wpatch? (was c6dafa2e2594 found by your tool?)
yes, c6dafa2e2594 was found with this patch. It's the only one, though (there's also a leak in test_ctypes but I don't want to investigate :-)).
Author: Meador Inge (meador.inge) *
Date: 2011-12-02 21:38
On Fri, Dec 2, 2011 at 12:12 PM, Antoine Pitrou <report@bugs.python.org> wrote:
yes, c6dafa2e2594 was found with this patch. It's the only one, though (there's also a leak in test_ctypes but I don't want to investigate :-)).
I'll take a look at the ctypes leak.
Author: Meador Inge (meador.inge) *
Date: 2011-12-06 23:41
I looked at the 'ctypes' "leak" a bit. I haven't determined exactly what is going on, but the leak has something to do with a change in the patch that runs 'dash_R_cleanup' twice instead of once. The new behavior can be reduced to something like:
import sys, ctypes, gc
ctypes._reset_cache() gc.collect()
for i in range(0, 5): ctypes._reset_cache() gc.collect() print("%d: start refs = %s" % (i, sys.gettotalrefcount())) proto = ctypes.CFUNCTYPE(ctypes.POINTER(ctypes.c_char)) ctypes._reset_cache() gc.collect() print("%d: after refs = %s" % (i, sys.gettotalrefcount()))
which prints:
0: start refs = 71395 0: after refs = 71462 1: start refs = 71463 1: after refs = 71493 2: start refs = 71465 2: after refs = 71494 3: start refs = 71465 3: after refs = 71494 4: start refs = 71465 4: after refs = 71494
Note that the start/after refs converge on a difference of 29 references.
The existing version 'regrtest.py' does something like:
import sys, ctypes, gc
ctypes._reset_cache() gc.collect()
for i in range(0, 5): print("%d: start refs = %s" % (i, sys.gettotalrefcount())) proto = ctypes.CFUNCTYPE(ctypes.POINTER(ctypes.c_char)) ctypes._reset_cache() gc.collect() print("%d: after refs = %s" % (i, sys.gettotalrefcount()))
which prints:
0: start refs = 71391 0: after refs = 71458 1: start refs = 71458 1: after refs = 71489 2: start refs = 71489 2: after refs = 71490 3: start refs = 71490 3: after refs = 71490 4: start refs = 71490 4: after refs = 71490
This one converges on a difference of zero.
So, I am not sure whether there really is a leak, if this is just a very senstive area of 'regrtest.py', or something else I am missing.
Author: Antoine Pitrou (pitrou) *
Date: 2011-12-06 23:45
So, I am not sure whether there really is a leak, if this is just a very senstive area of 'regrtest.py', or something else I am missing.
Well, test_ctypes seems to be the only test exhibiting that behaviour. And since your script reproduces it, it's probably not regrtest.py in itself.
Author: anatoly techtonik (techtonik)
Date: 2011-12-12 14:57
How different is the performance cost of this solution compared to inserting DTrace probe for the same purpose?
Author: STINNER Victor (vstinner) *
Date: 2011-12-12 15:11
How different is the performance cost of this solution compared to inserting DTrace probe for the same purpose?
DTrace is only available on some platforms (Solaris and maybe FreeBSD?).
Author: anatoly techtonik (techtonik)
Date: 2011-12-12 15:19
On Mon, Dec 12, 2011 at 6:11 PM, STINNER Victor <report@bugs.python.org>wrote:
STINNER Victor <victor.stinner@haypocalc.com> added the comment:
How different is the performance cost of this solution compared to inserting DTrace probe for the same purpose?
DTrace is only available on some platforms (Solaris and maybe FreeBSD?).
Solaris <http://en.wikipedia.org/wiki/Solaris_(operating_system)>, Mac OS X<http://en.wikipedia.org/wiki/Mac_OS_X> , FreeBSD <http://en.wikipedia.org/wiki/FreeBSD>, NetBSD<http://en.wikipedia.org/wiki/NetBSD> , Oracle Linux <http://en.wikipedia.org/wiki/Oracle_Linux> according to http://en.wikipedia.org/wiki/DTrace#Supported_platforms, but that doesn't relate to the question.
Author: Antoine Pitrou (pitrou) *
Date: 2012-12-05 19:59
Here is an updated patch. test_ctypes still leaks memory blocks with it:
$ ./python -m test -R 3:8 test_ctypes [1/1] test_ctypes beginning 11 repetitions 12345678901 ........... test_ctypes leaked [2, 2, 1, 1, 1, 1, 1, 1] memory blocks, sum=10
Author: Antoine Pitrou (pitrou) *
Date: 2012-12-06 19:59
As it turns out, ctypes does leak memory: see issue 16628.
Author: Antoine Pitrou (pitrou) *
Date: 2012-12-06 20:07
Updated patch with doc. If noone objects, I will commit soon.
Author: Dave Malcolm (dmalcolm)
Date: 2012-12-06 20:19
Minor bikeshedding/spelling nit: should "_Py_AllocedBlocks" be changed to "_Py_AllocatedBlocks"
(and s/_Py_GetAllocedBlocks/_Py_GetAllocatedBlocks/)?
Author: Antoine Pitrou (pitrou) *
Date: 2012-12-08 10:15
Minor bikeshedding/spelling nit: should "_Py_AllocedBlocks" be changed to "_Py_AllocatedBlocks" (and s/_Py_GetAllocedBlocks/_Py_GetAllocatedBlocks/)?
Right indeed. I'll do the change.
Author: Roundup Robot (python-dev) 
Date: 2012-12-09 13:29
New changeset c40f4c19d20b by Antoine Pitrou in branch 'default':
Issue #13390: New function :func:sys.getallocatedblocks() returns the number of memory blocks currently allocated.
http://hg.python.org/cpython/rev/c40f4c19d20b
Author: Antoine Pitrou (pitrou) *
Date: 2012-12-09 13:30
Committed and pushed!
Author: Stefan Krah (skrah) *
Date: 2012-12-16 21:15
``./configure --without-pymalloc'' fails here:
gcc -pthread -Xlinker -export-dynamic -o python Modules/python.o libpython3.4.a -lpthread -ldl -lutil -lm
libpython3.4.a(sysmodule.o): In function sys_getallocatedblocks': /home/stefan/hg/cpython/./Python/sysmodule.c:900: undefined reference to _Py_GetAllocatedBlocks'
collect2: error: ld returned 1 exit status
make: *** [python] Error 1
Author: Antoine Pitrou (pitrou) *
Date: 2012-12-17 08:17
``./configure --without-pymalloc'' fails here:
gcc -pthread -Xlinker -export-dynamic -o python Modules/python.o libpython3.4.a -lpthread -ldl -lutil -lm
libpython3.4.a(sysmodule.o): In functionsys_getallocatedblocks': /home/stefan/hg/cpython/./Python/sysmodule.c:900: undefined reference to_Py_GetAllocatedBlocks' collect2: error: ld returned 1 exit status make: *** [python] Error 1
Hmm, interesting. When built --without-pymalloc, we could make sys.getallocatedblocks() always return 0, or we could not define it all (which would make like a bit harder for regrtest). What do you think?
Author: STINNER Victor (vstinner) *
Date: 2012-12-17 09:16
sys.gettotalrefcount() is only defined when Python is compiled in debug mode. sys.getallocatedblocks() should only be available when the right debug option is present. This function is specific to CPython anyway, Python module should not rely on this (too much) ;-)
Author: anatoly techtonik (techtonik)
Date: 2012-12-17 11:22
Memory control over the stuff that Python creates is a practical feature that compensates OS disability for tracking memory usage. If all Python scripts could measure their memory usage, we could see more memory effective and adaptive programs around.
Author: Antoine Pitrou (pitrou) *
Date: 2012-12-17 12:52
sys.gettotalrefcount() is only defined when Python is compiled in debug mode. sys.getallocatedblocks() should only be available when the right debug option is present. This function is specific to CPython anyway, Python module should not rely on this (too much) ;-)
On the contrary, the aim is precisely to provide a memory statistics function which is available for everyone, not only CPython developers. It is simply not practical right now for a C extension developer to check for memory leaks.
Author: Stefan Krah (skrah) *
Date: 2012-12-17 13:08
Antoine Pitrou <report@bugs.python.org> wrote:
Hmm, interesting. When built --without-pymalloc, we could make sys.getallocatedblocks() always return 0, or we could not define it all (which would make like a bit harder for regrtest). What do you think?
Given the name getallocatedblocks(), it would seem reasonable to return 0 in this case and document the fact. I don't think many people use --without-pymalloc anyhow.
I'm using the option only for Valgrind testing, that's how I found the build error.
Author: Roundup Robot (python-dev)
Date: 2012-12-17 22:07
New changeset a85673b55177 by Antoine Pitrou in branch 'default': Following issue #13390, fix compilation --without-pymalloc, and make sys.getallocatedblocks() return 0 in that situation. http://hg.python.org/cpython/rev/a85673b55177
History
Date
User
Action
Args
2022-04-11 14:57:23
admin
set
github: 57599
2012-12-17 22:07:47
python-dev
set
messages: +
2012-12-17 13:08:19
skrah
set
messages: +
2012-12-17 12:52:20
pitrou
set
messages: +
2012-12-17 11:22:17
techtonik
set
messages: +
2012-12-17 09:16:21
vstinner
set
messages: +
2012-12-17 08:17:07
pitrou
set
messages: +
2012-12-16 21:15:28
skrah
set
nosy: + skrah
messages: +
2012-12-09 13:30:47
pitrou
set
status: open -> closed
resolution: fixed
messages: +
stage: patch review -> resolved
2012-12-09 13:29:58
python-dev
set
nosy: + python-dev
messages: +
2012-12-08 10:15:59
pitrou
set
messages: +
2012-12-06 20:19:06
dmalcolm
set
messages: +
2012-12-06 20:07:50
pitrou
set
files: + debugblocks6.patch
messages: +
2012-12-06 19:59:10
pitrou
set
messages: +
2012-12-05 20:00:00
pitrou
set
files: + debugblocks5.patch
nosy: + benjamin.peterson
messages: +
2012-12-05 19:41:29
pitrou
set
versions: + Python 3.4, - Python 3.3
2011-12-12 15:19:47
techtonik
set
messages: +
2011-12-12 15:15:42
jcea
set
nosy: + jcea
2011-12-12 15:11:38
vstinner
set
messages: +
2011-12-12 14:57:34
techtonik
set
nosy: + techtonik
messages: +
2011-12-06 23:45:31
pitrou
set
messages: +
2011-12-06 23:41:42
meador.inge
set
messages: +
2011-12-02 21:38:49
meador.inge
set
nosy: + meador.inge
messages: +
2011-12-02 18:12:06
pitrou
set
messages: +
2011-12-02 17:59:57
dmalcolm
set
nosy: + dmalcolm
2011-12-02 01:11:57
vstinner
set
nosy: + vstinner
messages: +
2011-12-01 18:34:20
pitrou
set
messages: +
2011-12-01 17:55:55
neologix
set
messages: +
2011-11-15 14:22:27
pitrou
set
messages: +
2011-11-15 09:23:27
ncoghlan
set
messages: +
2011-11-15 08:11:38
neologix
set
nosy: + neologix
messages: +
2011-11-13 16:53:23
pitrou
set
messages: +
2011-11-13 16:52:45
pitrou
set
files: + debugblocks3.patch
2011-11-13 16:52:29
pitrou
set
files: + debugblocks2.patch
2011-11-13 16:27:29
pitrou
set
messages: +
2011-11-13 01:06:26
ncoghlan
set
messages: +
2011-11-12 23:47:15
Trundle
set
nosy: + Trundle
2011-11-12 23:24:29
pitrou
create