classification
Title: Hunt memory allocations in addition to reference leaks
Type: resource usage Stage: resolved
Components: Interpreter Core, Tests Versions: Python 3.4
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: Trundle, benjamin.peterson, dmalcolm, haypo, jcea, meador.inge, ncoghlan, neologix, pitrou, python-dev, skrah, techtonik, tim.peters
Priority: normal Keywords: patch

Created on 2011-11-12 23:24 by pitrou, last changed 2012-12-17 22:07 by python-dev. This issue is now closed.

Files
File name Uploaded Description Edit
debugblocks.patch pitrou, 2011-11-12 23:24 review
debugblocks2.patch pitrou, 2011-11-13 16:52 review
debugblocks3.patch pitrou, 2011-11-13 16:52 review
debugblocks5.patch pitrou, 2012-12-05 19:59 review
debugblocks6.patch pitrou, 2012-12-06 20:07 review
Messages (31)
msg147531 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) 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, issue13389 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.
msg147539 - (view) Author: Nick Coghlan (ncoghlan) * (Python committer) 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.
msg147555 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) 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.
msg147561 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2011-11-13 16:53
And the latest patch (debugblocks3.patch) adds said heuristic.
msg147656 - (view) Author: Charles-Fran├žois Natali (neologix) * (Python committer) 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 :-).
msg147661 - (view) Author: Nick Coghlan (ncoghlan) * (Python committer) 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.
msg147672 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) 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.
msg148731 - (view) Author: Charles-Fran├žois Natali (neologix) * (Python committer) 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 ;-)
msg148734 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) 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).
msg148750 - (view) Author: STINNER Victor (haypo) * (Python committer) 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?)
msg148769 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) 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 :-)).
msg148776 - (view) Author: Meador Inge (meador.inge) * (Python committer) 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.
msg148944 - (view) Author: Meador Inge (meador.inge) * (Python committer) 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.
msg148945 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) 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.
msg149308 - (view) 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?
msg149309 - (view) Author: STINNER Victor (haypo) * (Python committer) 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?).
msg149311 - (view) 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.
msg177005 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) 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
msg177053 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2012-12-06 19:59
As it turns out, ctypes does leak memory: see issue 16628.
msg177054 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2012-12-06 20:07
Updated patch with doc. If noone objects, I will commit soon.
msg177055 - (view) Author: Dave Malcolm (dmalcolm) (Python committer) Date: 2012-12-06 20:19
Minor bikeshedding/spelling nit: should
  "_Py_AllocedBlocks"
be changed to
  "_Py_AllocatedBlocks"

(and s/_Py_GetAllocedBlocks/_Py_GetAllocatedBlocks/)?
msg177152 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) 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.
msg177214 - (view) 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
msg177215 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2012-12-09 13:30
Committed and pushed!
msg177628 - (view) Author: Stefan Krah (skrah) * (Python committer) 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
msg177639 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) 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 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

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?
msg177640 - (view) Author: STINNER Victor (haypo) * (Python committer) 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) ;-)
msg177642 - (view) 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.
msg177646 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) 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.
msg177647 - (view) Author: Stefan Krah (skrah) * (Python committer) 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.
msg177672 - (view) 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
2012-12-17 22:07:47python-devsetmessages: + msg177672
2012-12-17 13:08:19skrahsetmessages: + msg177647
2012-12-17 12:52:20pitrousetmessages: + msg177646
2012-12-17 11:22:17techtoniksetmessages: + msg177642
2012-12-17 09:16:21hayposetmessages: + msg177640
2012-12-17 08:17:07pitrousetmessages: + msg177639
2012-12-16 21:15:28skrahsetnosy: + skrah
messages: + msg177628
2012-12-09 13:30:47pitrousetstatus: open -> closed
resolution: fixed
messages: + msg177215

stage: patch review -> resolved
2012-12-09 13:29:58python-devsetnosy: + python-dev
messages: + msg177214
2012-12-08 10:15:59pitrousetmessages: + msg177152
2012-12-06 20:19:06dmalcolmsetmessages: + msg177055
2012-12-06 20:07:50pitrousetfiles: + debugblocks6.patch

messages: + msg177054
2012-12-06 19:59:10pitrousetmessages: + msg177053
2012-12-05 20:00:00pitrousetfiles: + debugblocks5.patch
nosy: + benjamin.peterson
messages: + msg177005

2012-12-05 19:41:29pitrousetversions: + Python 3.4, - Python 3.3
2011-12-12 15:19:47techtoniksetmessages: + msg149311
2011-12-12 15:15:42jceasetnosy: + jcea
2011-12-12 15:11:38hayposetmessages: + msg149309
2011-12-12 14:57:34techtoniksetnosy: + techtonik
messages: + msg149308
2011-12-06 23:45:31pitrousetmessages: + msg148945
2011-12-06 23:41:42meador.ingesetmessages: + msg148944
2011-12-02 21:38:49meador.ingesetnosy: + meador.inge
messages: + msg148776
2011-12-02 18:12:06pitrousetmessages: + msg148769
2011-12-02 17:59:57dmalcolmsetnosy: + dmalcolm
2011-12-02 01:11:57hayposetnosy: + haypo
messages: + msg148750
2011-12-01 18:34:20pitrousetmessages: + msg148734
2011-12-01 17:55:55neologixsetmessages: + msg148731
2011-11-15 14:22:27pitrousetmessages: + msg147672
2011-11-15 09:23:27ncoghlansetmessages: + msg147661
2011-11-15 08:11:38neologixsetnosy: + neologix
messages: + msg147656
2011-11-13 16:53:23pitrousetmessages: + msg147561
2011-11-13 16:52:45pitrousetfiles: + debugblocks3.patch
2011-11-13 16:52:29pitrousetfiles: + debugblocks2.patch
2011-11-13 16:27:29pitrousetmessages: + msg147555
2011-11-13 01:06:26ncoghlansetmessages: + msg147539
2011-11-12 23:47:15Trundlesetnosy: + Trundle
2011-11-12 23:24:29pitroucreate