[Python-Dev] Discussion related to memory leaks requested
Trent Nelson
trent at trent.me
Wed Jan 13 22:47:15 EST 2016
Gflags/umdh is pretty useful on Windows, I used it to track down a few quirky PyParallel memory leaks. Steps:
1. Enable global flags: gflags –i python.exe +ust
2. Launch Python.
3. Enable the umdh tracer: umdh –p:<python.exe pid> -f:d1.log
4. Kill it after a short run.
5. Re-launch Python.
6. Enable it again: umdh –p:<python.exe pid> -f:d2.log
7. Let it run for longer – long enough to make sure it’s leaking memory.
8. Kill it, then generate a dump file: umdh –d d1.log d2.log > dump.txt
(Those steps were pretty specific to my particular situation, but it should at least be a reasonable starting point for what to google to find out more.)
Here are two sample outputs that pin-pointed the exact leak path:
+ 49116 ( 49116 - 0) 6 allocs BackTrace9763CA0
+ 6 ( 6 - 0) BackTrace9763CA0 allocations
ntdll!RtlpCallInterceptRoutine+40
ntdll!RtlAllocateHeap+79846
SQLSRV32!SQLAllocateMemory+26
markSQLSRV32!SQLAllocConnect+F6
SQLSRV32!SQLAllocHandle+83
ODBC32!RetcodeDriverInit+2D9
ODBC32!SQLInternalDriverConnectW+2F
ODBC32!CDispenser::CreateResource+DB
comsvcs!CHolder::SafeDispenserDriver::CreateResource+43
comsvcs!CHolder::AllocResource+24D
ODBC32!CDispenser::TryAllocResource+6E
ODBC32!CDispenser::GetActiveConnection+72
ODBC32!SQLDriverConnectW+9D4
pyodbc!Connect+14F (c:\users\trent\home\src\pyparallel\contrib\pyodbc\src\connection.cpp, 85)
pyodbc!Connection_New+CD (c:\users\trent\home\src\pyparallel\contrib\pyodbc\src\connection.cpp, 166)
pyodbc!mod_connect+579 (c:\users\trent\home\src\pyparallel\contrib\pyodbc\src\pyodbcmodule.cpp, 378)
python33!PyCFunction_Call+F3 (c:\users\trent\home\src\pyparallel\objects\methodobject.c, 84)
python33!call_function+371 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4130)
python33!PyEval_EvalFrameEx+356C (c:\users\trent\home\src\pyparallel\python\ceval.c, 2745)
python33!fast_function+113 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4219)
python33!call_function+529 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4152)
python33!PyEval_EvalFrameEx+356C (c:\users\trent\home\src\pyparallel\python\ceval.c, 2745)
python33!fast_function+113 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4219)
python33!call_function+529 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4152)
python33!PyEval_EvalFrameEx+356C (c:\users\trent\home\src\pyparallel\python\ceval.c, 2745)
python33!PyEval_EvalCodeEx+B4D (c:\users\trent\home\src\pyparallel\python\ceval.c, 3500)
python33!function_call+1BB (c:\users\trent\home\src\pyparallel\objects\funcobject.c, 639)
python33!PyObject_Call+7C (c:\users\trent\home\src\pyparallel\objects\abstract.c, 2036)
python33!method_call+F9 (c:\users\trent\home\src\pyparallel\objects\classobject.c, 353)
python33!PyObject_Call+7C (c:\users\trent\home\src\pyparallel\objects\abstract.c, 2036)
python33!PyEval_CallObjectWithKeywords+16C (c:\users\trent\home\src\pyparallel\python\ceval.c, 4011)
python33!PxSocket_IOLoop+1249 (c:\users\trent\home\src\pyparallel\python\pyparallel.c, 9128)
+ 48432 ( 48432 - 0) 6 allocs BackTrace97635E0
+ 6 ( 6 - 0) BackTrace97635E0 allocations
ntdll!RtlpCallInterceptRoutine+40
ntdll!RtlAllocateHeap+79846
SQLSRV32!SQLAllocateMemory+26
SQLSRV32!SQLAllocConnect+4D
SQLSRV32!SQLAllocHandle+83
ODBC32!RetcodeDriverInit+2D9
ODBC32!SQLInternalDriverConnectW+2F
ODBC32!CDispenser::CreateResource+DB
comsvcs!CHolder::SafeDispenserDriver::CreateResource+43
comsvcs!CHolder::AllocResource+24D
ODBC32!CDispenser::TryAllocResource+6E
ODBC32!CDispenser::GetActiveConnection+72
ODBC32!SQLDriverConnectW+9D4
pyodbc!Connect+14F (c:\users\trent\home\src\pyparallel\contrib\pyodbc\src\connection.cpp, 85)
pyodbc!Connection_New+CD (c:\users\trent\home\src\pyparallel\contrib\pyodbc\src\connection.cpp, 166)
pyodbc!mod_connect+579 (c:\users\trent\home\src\pyparallel\contrib\pyodbc\src\pyodbcmodule.cpp, 378)
python33!PyCFunction_Call+F3 (c:\users\trent\home\src\pyparallel\objects\methodobject.c, 84)
python33!call_function+371 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4130)
python33!PyEval_EvalFrameEx+356C (c:\users\trent\home\src\pyparallel\python\ceval.c, 2745)
python33!fast_function+113 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4219)
python33!call_function+529 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4152)
python33!PyEval_EvalFrameEx+356C (c:\users\trent\home\src\pyparallel\python\ceval.c, 2745)
python33!fast_function+113 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4219)
python33!call_function+529 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4152)
python33!PyEval_EvalFrameEx+356C (c:\users\trent\home\src\pyparallel\python\ceval.c, 2745)
python33!PyEval_EvalCodeEx+B4D (c:\users\trent\home\src\pyparallel\python\ceval.c, 3500)
python33!function_call+1BB (c:\users\trent\home\src\pyparallel\objects\funcobject.c, 639)
python33!PyObject_Call+7C (c:\users\trent\home\src\pyparallel\objects\abstract.c, 2036)
python33!method_call+F9 (c:\users\trent\home\src\pyparallel\objects\classobject.c, 353)
python33!PyObject_Call+7C (c:\users\trent\home\src\pyparallel\objects\abstract.c, 2036)
python33!PyEval_CallObjectWithKeywords+16C (c:\users\trent\home\src\pyparallel\python\ceval.c, 4011)
python33!PxSocket_IOLoop+1249 (c:\users\trent\home\src\pyparallel\python\pyparallel.c, 9128)
You can see that the leak is coming from SQLAllocateMemory in this case, which we trace back to pyodbc Connection_New(). In this particular case, we were continually creating new connections, but never deallocating them.
Another example:
+ 9420800 ( 9420800 - 0) 2300 allocs BackTrace8E96BE0
+ 2300 ( 2300 - 0) BackTrace8E96BE0 allocations
ntdll!RtlpCallInterceptRoutine+40
ntdll!RtlAllocateHeap+79846
python33!_PyTLSHeap_Init+9E (c:\users\trent\home\src\pyparallel\python\pyparallel.c, 3040)
python33!_PyTLSHeap_Malloc+B0 (c:\users\trent\home\src\pyparallel\python\pyparallel.c, 3124)
python33!_PyHeap_Malloc+55 (c:\users\trent\home\src\pyparallel\python\pyparallel.c, 3170)
python33!PyUnicode_New+149 (c:\users\trent\home\src\pyparallel\objects\unicodeobject.c, 1051)
python33!PyUnicode_DecodeUTF8Stateful+D2 (c:\users\trent\home\src\pyparallel\objects\unicodeobject.c, 4910)
python33!PyUnicode_InternFromString+16 (c:\users\trent\home\src\pyparallel\objects\unicodeobject.c, 14505)
python33!PyObject_GetAttrString+2E (c:\users\trent\home\src\pyparallel\objects\object.c, 881)
pyodbc!lowercase+18 (c:\users\trent\home\src\pyparallel\contrib\pyodbc\src\pyodbcmodule.h, 69)
pyodbc!execute+772 (c:\users\trent\home\src\pyparallel\contrib\pyodbc\src\cursor.cpp, 869)
pyodbc!Cursor_execute+D4 (c:\users\trent\home\src\pyparallel\contrib\pyodbc\src\cursor.cpp, 945)
python33!PyCFunction_Call+12D (c:\users\trent\home\src\pyparallel\objects\methodobject.c, 117)
python33!call_function+371 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4130)
python33!PyEval_EvalFrameEx+356C (c:\users\trent\home\src\pyparallel\python\ceval.c, 2745)
python33!fast_function+113 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4219)
python33!call_function+529 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4152)
python33!PyEval_EvalFrameEx+356C (c:\users\trent\home\src\pyparallel\python\ceval.c, 2745)
python33!fast_function+113 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4219)
python33!call_function+529 (c:\users\trent\home\src\pyparallel\python\ceval.c, 4152)
python33!PyEval_EvalFrameEx+356C (c:\users\trent\home\src\pyparallel\python\ceval.c, 2745)
python33!PyEval_EvalCodeEx+B4D (c:\users\trent\home\src\pyparallel\python\ceval.c, 3500)
python33!function_call+1BB (c:\users\trent\home\src\pyparallel\objects\funcobject.c, 639)
python33!PyObject_Call+7C (c:\users\trent\home\src\pyparallel\objects\abstract.c, 2036)
python33!method_call+F9 (c:\users\trent\home\src\pyparallel\objects\classobject.c, 353)
python33!PyObject_Call+7C (c:\users\trent\home\src\pyparallel\objects\abstract.c, 2036)
python33!PyEval_CallObjectWithKeywords+16C (c:\users\trent\home\src\pyparallel\python\ceval.c, 4011)
python33!PxSocket_IOLoop+1249 (c:\users\trent\home\src\pyparallel\python\pyparallel.c, 9128)
python33!PxSocket_IOCallback+295 (c:\users\trent\home\src\pyparallel\python\pyparallel.c, 10612)
KERNEL32!BasepTpIoCallback+59
ntdll!TppIopExecuteCallback+182
ntdll!TppWorkerThread+8B4
We can trace this leak back to lowercase(), which was interning a string. At this point, we were intercepting string interning and making it thread local allocation, but those allocations were never being freed.
From: Python-Dev [mailto:python-dev-bounces+trent=snakebite.org at python.org] On Behalf Of Matthew Paulson
Sent: Wednesday, January 13, 2016 7:18 PM
To: Andrew Barnert <abarnert at yahoo.com>
Cc: Python Dev <python-dev at python.org>; Gary F. Desrochers <desrochers at busiq.com>
Subject: Re: [Python-Dev] Discussion related to memory leaks requested
Hi Andrew:
These are all good points, and I defer to your experience -- I am new to python internals, but the fact remains that after multiple iterations of our embedded test case, we are seeing continued allocations (DS2015) and growth of the working set (windows task manager). If your are pooling resources on the free list, wouldn't you expect these items to get reused and for things to stabilize after a while? We're not seeing that.
I think Victor's suggestion of a very simple test case is probably the best idea. I'll try to put that together in the next few days and if it also demonstrates the problem, then I'll submit it here.
Thanks for your time and help.
Best,
Matt
On 1/13/2016 6:45 PM, Andrew Barnert wrote:
On Jan 13, 2016, at 14:49, Matthew Paulson <paulson at busiq.com<mailto:paulson at busiq.com>> wrote:
Hi Victor:
No, I'm using the new heap analysis functions in DS2015.
Isn't that going to report any memory that Python's higher level allocators hold in their freelists as leaked, even though it isn't leaked?
We think we have found one issue. In the following sequence, dict has no side effects, yet it is used -- unless someone can shed light on why dict is used in this case:
Where do you see an issue here? The dict will have one ref, so the decref at the end should return it to the freelist.
Also, it looks like there _is_ a side effect here. When you add a bunch of elements to a dict, it grows. When you delete a bunch of elements, it generally doesn't shrink. But when you clear the dict, it does shrink. So, copying it to a temporary dict, clearing it, updating it from the temporary dict, and then releasing the temporary dict should force it to shrink.
So, the overall effect should be that you have a smaller hash table for the builtins dict, and a chunk of memory sitting on the freelists ready to be reused. If your analyzer is showing the freelists as leaked, this will look like a net leak rather than a net recovery, but that's just a problem in the analyzer.
Of course I could be wrong, but I think the first step is to rule out the possibility that you're measuring the wrong thing...
/* Clear the modules dict. */
PyDict_Clear(modules);
/* Restore the original builtins dict, to ensure that any
user data gets cleared. */
dict = PyDict_Copy(interp->builtins);
if (dict == NULL)
PyErr_Clear();
PyDict_Clear(interp->builtins);
if (PyDict_Update(interp->builtins, interp->builtins_copy))
PyErr_Clear();
Py_XDECREF(dict);
And removing dict from this sequence seems to have fixed one of the issues, yielding 14k per iteration.
Simple program: Good idea. We will try that -- right now it's embedded in a more complex environment, but we have tried to strip it down to a very simple sequence.
The next item on our list is memory that is not getting freed after running simple string. It's in the parsertok sequence -- it seems that the syntax tree is not getting cleared -- but this opinion is preliminary.
Best,
Matt
On 1/13/2016 5:10 PM, Victor Stinner wrote:
Hi,
2016-01-13 20:32 GMT+01:00 Matthew Paulson <paulson at busiq.com><mailto:paulson at busiq.com>:
I've spent some time performing memory leak analysis while using Python in an embedded configuration.
Hum, did you try tracemalloc?
https://docs.python.org/dev/library/tracemalloc.html
https://pytracemalloc.readthedocs.org/
Is there someone in the group that would like to discuss this topic. There seems to be other leaks as well. I'm new to Python-dev, but willing to help or work with someone who is more familiar with these areas than I.
Are you able to reproduce the leak with a simple program?
Victor
--
<MattSig.JPG>
_______________________________________________
Python-Dev mailing list
Python-Dev at python.org<mailto:Python-Dev at python.org>
https://mail.python.org/mailman/listinfo/python-dev
Unsubscribe: https://mail.python.org/mailman/options/python-dev/abarnert%40yahoo.com
--
[cid:image001.jpg at 01D14E51.93AED0C0]
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.python.org/pipermail/python-dev/attachments/20160114/718f888d/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image001.jpg
Type: image/jpeg
Size: 38491 bytes
Desc: image001.jpg
URL: <http://mail.python.org/pipermail/python-dev/attachments/20160114/718f888d/attachment-0001.jpg>
More information about the Python-Dev
mailing list