Python profilering efter hukommelsesforbrug?

Af 7

Jeg holder meget af at programmere i Python. Det er klart det bedste programmeringssprog, jeg har arbejdet med.
Det er to ting jeg jævnligt har brug for - at finde ud af hvor i min kode, jeg bruger mest CPU-kraft hhv. mest hukommelse.
Til C/C++ kode har jeg meget godt styr på det men til Python kan jeg ikke finde ud af at finde ud af at profilere efter hukommelsesforbrug.
Det kan være at I seje geeks ved mere :-)

Hvis jeg f.eks. har en stump Python-kode som denne (test.py), allokerer mere og mere hukommelse hvert sekund.
Det kræver nok ikke mange sekunder for at fatte at a-variablen går amok og de andre variable er småting.

import time
def fun():
    for i in range(10):
        s = i<em>10000000
        print i,s
        a = [0]</em>(s)
        time.sleep(1)
 
fun()

Jeg kan ret nemt følge hukommelsesforløbet på en Linux-maskine med Valgrind:

rm massif.out.<em>
valgrind --tool=massif python test.py
ms_print massif.out.</em>

Det giver en graf, som hvert sekund kravler opad som forventet.

    GB
1.267^                                                 ###########            
     |                                                 #                      
     |                                                 #                      
     |                                     @@@@@@@@@@  #                      
     |                                     @           #                      
     |                           @@@@@@@@  @           #                      
     |                           @         @           #                      
     |                           @         @           #                      
     |                   @@@@@@  @         @           #                      
     |                   @       @         @           #                      
     |            @@@@@  @       @         @           #          ::::::::::: 
     |            @      @       @         @         ::#          :           
     |      @@@@  @      @       @       ::@         : #          :           
     |      @     @      @     ::@       : @         : #          :           
     |      @     @      @     : @       : @         : #          :           
     |   @@ @     @    ::@     : @       : @         : #          :           
     |   @  @   ::@    : @     : @       : @         : #          :           
     | @ @ :@   : @    : @     : @       : @         : #          :           
     | @:@ :@   : @    : @     : @       : @         : #          :           
     |@@:@ :@   : @    : @     : @       : @         : #          :           
   0 +----------------------------------------------------------------------->Gi
     0                                                                   7.668

Hver gang Valgrinds Massif laver en lodret "@" kommer der i udskriften fra ms_print yderligere en smøre om hvor hukommelsen blev brugt.
Havde det været et C/C++ program oversat med "gcc/g++ -g" så ville den kalde-hierarkiet vise funktionskald, kode-filnavne og linie numre, men
jeg kan ikke få dette frem når det er Python

 55  5,680,784,924    1,360,907,216    1,360,894,241        12,975            0
100.00% (1,360,894,241B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->99.93% (1,360,001,160B) 0x508B85: PyList_New (in /usr/bin/python2.7)
| ->99.93% (1,360,000,000B) 0x509034: ??? (in /usr/bin/python2.7)
| | ->99.93% (1,360,000,000B) 0x52D671: PyEval_EvalFrameEx (in /usr/bin/python2.7)
| |   ->99.93% (1,360,000,000B) 0x52CF30: PyEval_EvalFrameEx (in /usr/bin/python2.7)
| |   | ->99.93% (1,360,000,000B) 0x55C592: PyEval_EvalCodeEx (in /usr/bin/python2.7)
| |   |   ->99.93% (1,360,000,000B) 0x5B7390: PyEval_EvalCode (in /usr/bin/python2.7)
| |   |     ->99.93% (1,360,000,000B) 0x469661: ??? (in /usr/bin/python2.7)
| |   |       ->99.93% (1,360,000,000B) 0x4699E1: PyRun_FileExFlags (in /usr/bin/python2.7)
| |   |         ->99.93% (1,360,000,000B) 0x469F1A: PyRun_SimpleFileExFlags (in /usr/bin/python2.7)
| |   |           ->99.93% (1,360,000,000B) 0x46AB7F: Py_Main (in /usr/bin/python2.7)
| |   |             ->99.93% (1,360,000,000B) 0x506DEC3: (below main) (libc-start.c:287)

Grrrrrr - dummy interface :) Valgrind kan umiddelbart ikke fange de rette symboler. Der kommer ingen referencer til min kode.

Ny taktik! Jeg oversætter Python-koden til C via Cython (I eksemplet er det Python 2.7 og C - det virker også fint med Python 3.x og C++ kode)

cython --embed -2 test.py #Cython oversætter Python filen test.py til test.c
gcc -o testprogram test.c -I /usr/include/python2.7/  -lpython2.7 -lpthread -lm -lutil -ldl -g
rm massif.out* # Slet gamle massif filer
valgrind --tool=massif ./testprogram # Kør programmet
ms_print --threshold=10 massif.out.* # Vis resultatet

Nu er der noget relevant f.eks. for det sidste snapshot, hvor der er godt 1,5 GB allokeret

--------------------------------------------------------------------------------
  n        time(i)         total(B)   useful-heap(B) extra-heap(B)    stacks(B)
--------------------------------------------------------------------------------
 54 11,014,947,111    1,530,916,888    1,530,907,294         9,594            0
100.00% (1,530,907,294B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->99.94% (1,530,000,096B) 0x4E81306: ??? (in /usr/lib/x86_64-linux-gnu/libpython2.7.so.1.0)
| ->99.94% (1,530,000,096B) 0x4EAE6B1: PyNumber_InPlaceMultiply (in /usr/lib/x86_64-linux-gnu/libpython2.7.so.1.0)
|   ->99.94% (1,530,000,096B) 0x40237C: __pyx_pf_4test_fun (test.c:885)
|     ->99.94% (1,530,000,096B) 0x401E4A: __pyx_pw_4test_1fun (test.c:772)
|       ->99.94% (1,530,000,096B) 0x4034D8: __Pyx_PyObject_Call (test.c:1243)
|         ->99.94% (1,530,000,096B) 0x40317A: inittest (test.c:1170)
|           ->99.94% (1,530,000,096B) 0x404D5D: main (test.c:1887)

Som det ses er bla. test.c linie 885 vist som et sted hvor der allokeres 1,5 GB. Og det er første sted i kalde-hierarkiet af min kode.
Og kigger jeg blot et par linier over linie 885 står der - ta da... En reference til netop den linie 6, hvor jeg lavede min gigantiske
hukommelsesallokering - det er a-variablen som bliver STOR!

    /* "test.py":6
 *         s = i<em>10000000
 *         print i,s
 *         a = [0]</em>(s)             # <<<<<<<<<<<<<<
 *         time.sleep(1)
 * 
 */

Naturligvis er kodeeksemplet latterligt småt, men teknikken er meget relevant, når man har 10000 linier Python-kode :-)

Pt. er dette den eneste vej jeg har fundet igennem til at detektere hvor jeg har meget Python-hukommelse allokeret.
Har du en smartere og mere direkte måde, så skriv meget gerne nedenfor om dette.
Jeg har også prøvet "heapy", men den kan umiddelbart ikke lokalisere de store hukommelsessyndere (ofte de interessante).
Alternativet "memory_profiler" er umiddelbart håbløst, fordi man skal i forvejen have indsat kode til dette overalt, hvor man forventer noget interessant.
En god intro er: http://stackoverflow.com/questions/110259/which-python-memory-profiler-i...

/pto

Kommentarer (7)
sortSortér kommentarer
  • Ældste først
  • Nyeste først
  • Bedste først
Kenneth Geisshirt

Du skal oversætte Python selv med de rigtige options (kald configure med --with-valgrind). Din Python-fortolker kan nu interere meget bedre med valgrind. Python kommer med en fil med de kendte memory leaks i Python så du kan ignorere dem. For at køre test.py med valgrind, kan du bruge:

valgrind --tool=memcheck \
--suppressions=<prefix>/Misc/valgrind-python.supp \
--leak-check=full <prefix>/python test.py

hvor <prefix> er stien til roden af den udpakkede Python-distribution.

Jeg har stor glæde ved overstående når jeg tester mine Python extensions (typisk skrevet i C/C++).

Log ind eller Opret konto for at kommentere
I samarbejde med jobfinder logo - Danmarks største job- og karrieresite for ingeniører og it-professionelle.
Tip redaktionen