Profilarea Python folosind cProfile: un caz concret

Scrierea de programe este distractivă, dar a le face rapide poate fi o pacoste. Programele Python nu fac excepție de la acest lucru, dar lanțul de instrumente de profilare de bază nu este de fapt atât de complicat de utilizat. Aici, aș dori să vă arăt cum puteți să vă profilați și să vă analizați rapid codul Python pentru a găsi ce parte a codului ar trebui să optimizați.

Profilarea unui program Python constă în efectuarea unei analize dinamice care măsoară timpul de execuție al programului și a tot ceea ce îl compune. Asta înseamnă măsurarea timpului petrecut în fiecare dintre funcțiile sale. Acest lucru vă va oferi date despre unde își petrece timpul programul dumneavoastră și ce zonă ar merita să fie optimizată.

Este un exercițiu foarte interesant. Mulți oameni se concentrează pe optimizări locale, cum ar fi determinarea, de exemplu, care dintre funcțiile Python range sau xrange va fi mai rapidă. Se pare că a ști care dintre ele este mai rapidă s-ar putea să nu fie niciodată o problemă în programul dumneavoastră și că timpul câștigat de una dintre funcțiile de mai sus s-ar putea să nu merite timpul pe care îl petreceți cercetând acest lucru sau certându-vă pe această temă cu colegul dumneavoastră.

Încercarea de a optimiza orbește un program fără a măsura unde își petrece de fapt timpul este un exercițiu inutil. Să vă urmați doar instinctul nu este întotdeauna suficient.

Există multe tipuri de profilare, așa cum există multe lucruri pe care le puteți măsura. În acest exercițiu, ne vom concentra pe profilarea utilizării CPU, adică timpul petrecut de fiecare funcție executând instrucțiuni. Evident, am putea face mult mai multe tipuri de profilare și optimizări, cum ar fi profilarea memoriei, care ar măsura memoria utilizată de fiecare bucată de cod – ceva despre care vorbesc în The Hacker’s Guide to Python.

cProfile

De la Python 2.5, Python oferă un modul C numit cProfile, care are o suprasolicitare rezonabilă și oferă un set de caracteristici suficient de bun. Utilizarea de bază se rezumă la:

Deși puteți, de asemenea, să rulați un script cu el, care se dovedește a fi util:

Acesta tipărește toate funcțiile apelate, cu timpul petrecut în fiecare și numărul de ori de câte ori au fost apelate.

Vizualizare avansată cu KCacheGrind

Deși este util, formatul de ieșire este foarte elementar și nu facilitează preluarea cunoștințelor pentru programe complete. Pentru o vizualizare mai avansată, mă folosesc de KCacheGrind. Dacă ați făcut programare și profilare în C în ultimii ani, este posibil să îl fi folosit, deoarece este conceput în primul rând ca front-end pentru call-graph-urile generate de Valgrind.

Pentru a-l utiliza, trebuie să generați un fișier rezultat cProfile, apoi să îl convertiți în formatul KCacheGrind. Pentru a face asta, eu folosesc pyprof2calltree.

$ python -m cProfile -o myscript.cprof myscript.py$ pyprof2calltree -k -i myscript.cprof

Și fereastra KCacheGrind apare ca prin minune!

Caz concret: Optimizarea Carbonara

Eram curios în legătură cu performanțele Carbonara, mica bibliotecă de serii de timp pe care am scris-o pentru Gnocchi. Am decis să fac câteva profilări de bază pentru a vedea dacă există vreo optimizare evidentă de făcut.

Pentru a face profilul unui program, trebuie să îl rulați. Dar rularea întregului program în modul de profilare poate genera o mulțime de date care nu vă interesează și adaugă zgomot la ceea ce încercați să înțelegeți. Din moment ce Gnocchi are mii de teste unitare și câteva pentru Carbonara în sine, am decis să profilez codul folosit de aceste teste unitare, deoarece este o bună reflectare a caracteristicilor de bază ale bibliotecii.

Rețineți că aceasta este o strategie bună pentru o primă trecere curioasă și naivă de profilare.
Nu aveți cum să vă asigurați că punctele critice pe care le veți vedea în testele unitare sunt punctele critice reale pe care le veți întâlni în producție. Prin urmare, o profilare în condiții și cu un scenariu care imită ceea ce se vede în producție este adesea o necesitate dacă trebuie să împingeți optimizarea programului mai departe și doriți să obțineți un câștig perceptibil și valoros.

Am activat cProfile folosind metoda descrisă mai sus, creând un obiect cProfile.Profile în jurul testelor mele (de fapt, am început să implementez asta în testtools). Apoi am rulat KCacheGrind așa cum am descris mai sus. Folosind KCacheGrind, am generat următoarele cifre.

Testul pe care l-am profilat aici se numește test_fetch și este destul de ușor de înțeles: pune datele într-un obiect timeserie, iar apoi preia rezultatul agregat. Lista de mai sus arată că 88 % din ticuri sunt petrecute în set_values (44 de ticuri peste 50). Această funcție este utilizată pentru a introduce valori în timeserie, nu pentru a prelua valorile. Aceasta înseamnă că este foarte lentă pentru a insera date și destul de rapidă pentru a le prelua efectiv.

Citerea restului listei indică faptul că mai multe funcții își împart restul ticurilor, update, _first_block_timestamp, _truncate, _resample, etc. Unele dintre funcțiile din listă nu fac parte din Carbonara, deci nu are rost să căutăm să le optimizăm. Singurul lucru care poate fi optimizat este, uneori, numărul de ori de câte ori sunt apelate.

Graficul de apelare îmi oferă ceva mai multe informații despre ceea ce se întâmplă aici. Folosind cunoștințele mele despre cum funcționează Carbonara, nu cred că întreaga stivă din stânga pentru _first_block_timestamp are prea mult sens. Această funcție ar trebui să găsească primul timestamp pentru un agregat, de exemplu, cu un timestamp de 13:34:45 și o perioadă de 5 minute, funcția ar trebui să returneze 13:30:00. Modul în care funcționează în prezent este prin apelarea funcției resample din Pandas pe o timeserie cu un singur element, dar acest lucru pare să fie foarte lent. Într-adevăr, în prezent, această funcție reprezintă 25 % din timpul petrecut de set_values (11 ticuri pe 44).

Din păcate, am adăugat recent o mică funcție numită _round_timestamp care face exact ceea ce are nevoie _first_block_timestamp care fără a apela nicio funcție Pandas, deci fără resample. Așa că am sfârșit prin a rescrie acea funcție în felul următor:

Și apoi am rulat din nou exact același test pentru a compara ieșirea din cProfile.

Lista de funcții pare destul de diferită de data aceasta. Numărul de timp petrecut folosit de set_values a scăzut de la 88 % la 71 %.

Stiva de apeluri pentru set_values arată destul de bine acest lucru: nici măcar nu putem vedea funcția _first_block_timestamp, deoarece este atât de rapidă încât a dispărut complet de pe ecran. Acum este considerată nesemnificativă de către profiler.

Așa că tocmai am accelerat întregul proces de inserție a valorilor în Carbonara cu un frumos 25 % în câteva minute. Nu este atât de rău pentru o primă trecere naivă, nu-i așa?

Dacă doriți să știți mai multe, am scris un întreg capitol despre optimizarea codului în Scaling Python. Verificați-l!

Lasă un răspuns

Adresa ta de email nu va fi publicată.