Programokat írni jó móka, de gyorsabbá tenni őket fájdalmas lehet. A Python programok sem kivételek ez alól, de az alapvető profilozási eszköztárat valójában nem is olyan bonyolult használni. Itt szeretném megmutatni, hogyan lehet gyorsan profilozni és elemezni a Python kódot, hogy megtaláljuk, a kód mely részét érdemes optimalizálni.
A Python program profilozása egy dinamikus elemzés elvégzése, amely méri a program és minden, ami azt alkotja, végrehajtási idejét. Ez azt jelenti, hogy megmérjük az egyes függvényekben eltöltött időt. Ez adatokat szolgáltat arról, hogy a programod hol tölt időt, és melyik területet érdemes optimalizálni.
Ez egy nagyon érdekes feladat. Sokan a helyi optimalizálásokra koncentrálnak, például annak meghatározására, hogy a Python range vagy xrange függvények közül melyik lesz gyorsabb. Kiderül, hogy az, hogy melyik a gyorsabb, talán soha nem is lesz kérdés a programodban, és a fenti függvények valamelyikével nyert idő nem biztos, hogy megéri azt az időt, amit azzal töltesz, hogy ezt kutatod, vagy vitatkozol róla a kollégáddal.
A program vakon történő optimalizálásának kísérlete anélkül, hogy mérnéd, hogy valójában hol tölti az idejét, haszontalan gyakorlat. Ha csak a megérzéseidre hallgatsz, az nem mindig elegendő.
A profilalkotásnak sok fajtája van, ahogyan sok mindent lehet mérni. Ebben a gyakorlatban a CPU-kihasználtság profilozására fogunk koncentrálni, vagyis arra az időre, amit az egyes függvények az utasítások végrehajtásával töltenek. Nyilvánvalóan sok másfajta profilozást és optimalizálást is végezhetünk, például memóriaprofilozást, amely az egyes kódrészletek által használt memóriát mérné – erről a The Hacker’s Guide to Python című könyvben beszélek.
cProfile
A Python 2.5 óta a Python biztosít egy cProfile nevű C modult, amely ésszerű overheaddel rendelkezik, és elég jó funkciókészletet kínál. Az alapvető használat a következőre megy le:
Bár egy szkriptet is futtathatunk vele, ami hasznosnak bizonyul:
Ez kiírja az összes meghívott függvényt, az egyes függvényekre fordított idővel és a meghívások számával együtt.
Hosszabb vizualizáció a KCacheGrinddel
Noha hasznos, a kimeneti formátum nagyon egyszerű, és nem teszi könnyűvé a teljes programokhoz való ismeretszerzést. A fejlettebb vizualizációhoz a KCacheGrindot használom ki. Ha az elmúlt években bármilyen C programozást és profilozást végeztél, talán használtad, mivel elsősorban a Valgrind által generált hívásgrafikonok front-endjének készült.
A használatához cProfile eredményfájlt kell generálnod, majd KCacheGrind formátumba konvertálnod. Ehhez a pyprof2calltree-t használom.
$ python -m cProfile -o myscript.cprof myscript.py$ pyprof2calltree -k -i myscript.cprofÉs a KCacheGrind ablak varázslatosan megjelenik!
Konkrét eset: Carbonara optimalizálás
Kíváncsi voltam a Carbonara, a Gnocchihoz írt kis idősoros könyvtáram teljesítményére. Úgy döntöttem, hogy elvégzek néhány alapvető profilalkotást, hogy lássam, van-e valami nyilvánvaló optimalizálnivaló.
Azért, hogy egy programot profilozni tudjunk, le kell futtatni. De az egész program futtatása profilozási módban rengeteg olyan adatot generálhat, ami nem érdekel, és zajjal egészíti ki azt, amit meg akarsz érteni. Mivel a Gnocchi több ezer egységtesztet tartalmaz, és néhányat magához a Carbonarához, úgy döntöttem, hogy az ezen egységtesztek által használt kódot profilozom, mivel ez jól tükrözi a könyvtár alapvető jellemzőit.
Megjegyzem, hogy ez egy jó stratégia a kíváncsi és naiv első menetben történő profilozáshoz.
Nem lehetsz biztos abban, hogy a forró pontok, amelyeket az egységtesztekben látsz, azok a tényleges forró pontok, amelyekkel a termelésben találkozol. Ezért a termelésben látottakat utánzó körülmények között és forgatókönyvvel végzett profilozás gyakran szükségszerű, ha a programoptimalizálást tovább kell vinni, és érzékelhető és értékes nyereséget akarunk elérni.
A cProfile-t a fent leírt módszerrel aktiváltam, létrehozva egy cProfile.Profile objektumot a tesztjeim körül (ezt tulajdonképpen a testtoolsban kezdtem el megvalósítani). Ezután futtatom a KCacheGrind-ot a fent leírtak szerint. A KCacheGrind használatával a következő ábrákat generáltam.
A teszt, amit itt profiloztam, a test_fetch nevet viseli, és elég könnyen érthető: adatokat helyez el egy timeserie objektumba, majd lekérdezi az összesített eredményt. A fenti listából látható, hogy a tickek 88%-a a set_values-ben telik el (44 tick 50 felett). Ez a függvény arra szolgál, hogy értékeket helyezzen be a timeserie-be, nem pedig arra, hogy lekérje az értékeket. Ez azt jelenti, hogy nagyon lassú az adatok beszúrása, és elég gyors a tényleges lekérdezésük.
A lista többi részét olvasva kiderül, hogy több függvény osztozik a többi kullancson, update, _first_block_timestamp, _truncate, _resample stb. A listában szereplő függvények egy része nem része a Carbonarának, így nincs értelme az optimalizálásukat keresni. Az egyetlen dolog, amit optimalizálni lehet, az néha a meghívásuk száma.
A hívási grafikon egy kicsit több rálátást ad arra, hogy mi folyik itt. A Carbonara működésével kapcsolatos ismereteimet felhasználva nem hiszem, hogy a _first_block_timestamp esetében a bal oldalon lévő teljes veremnek sok értelme van. Ennek a függvénynek egy aggregátum első időbélyegét kellene megtalálnia, pl. 13:34:45 időbélyeg és 5 perc időtartam esetén a függvénynek 13:30:00-t kellene visszaadnia. Jelenleg úgy működik, hogy a Pandas resample függvényét hívja meg egy csak egy elemet tartalmazó idősorozaton, de ez nagyon lassúnak tűnik. Valóban, jelenleg ez a függvény a set_values által eltöltött idő 25%-át teszi ki (11 tick on 44).
Szerencsére nemrég hozzáadtam egy kis _round_timestamp nevű függvényt, amely pontosan azt teszi, amire a _first_block_timestamp-nak szüksége van, anélkül, hogy bármilyen Pandas függvényt meghívna, így nincs resample. Így végül ezt a függvényt így írtam át:
Aztán újra lefuttattam pontosan ugyanazt a tesztet, hogy összehasonlítsam a cProfile kimenetét.
A függvények listája ezúttal egészen másnak tűnik. A set_values által felhasznált idő felhasználásának száma 88%-ról 71%-ra csökkent.
A set_values híváshalmaza elég jól mutatja ezt: még a _first_block_timestamp függvényt sem látjuk, mivel az olyan gyors, hogy teljesen eltűnt a kijelzőről. A profiler most már jelentéktelennek tekinti.
Az egész értékek beillesztési folyamatát a Carbonarába tehát csak néhány perc alatt szép 25 %-kal gyorsítjuk fel. Nem is olyan rossz egy első naiv passzushoz képest, nem?
Ha többet szeretnél tudni, írtam egy egész fejezetet a kód optimalizálásáról a Scaling Pythonban. Nézd meg!