Psaní programů je zábava, ale jejich zrychlení může být otrava. Programy v jazyce Python nejsou výjimkou, ale základní řetězec profilovacích nástrojů ve skutečnosti není tak složitý na použití. Zde bych vám rád ukázal, jak můžete rychle profilovat a analyzovat svůj kód v jazyce Python a zjistit, kterou část kódu byste měli optimalizovat.
Profilování programu v jazyce Python je provádění dynamické analýzy, která měří dobu provádění programu a všeho, co jej tvoří. To znamená měření času stráveného v jednotlivých jeho funkcích. Získáte tak údaje o tom, kde váš program tráví čas a kterou oblast by stálo za to optimalizovat.
Je to velmi zajímavé cvičení. Mnoho lidí se zaměřuje na lokální optimalizace, jako je např. určení, která z funkcí Pythonu range nebo xrange bude rychlejší. Ukazuje se, že vědět, která z nich je rychlejší, nemusí být ve vašem programu nikdy problém a že čas získaný jednou z výše uvedených funkcí nemusí stát za čas, který strávíte jejím zkoumáním nebo dohadováním se o ní s kolegou.
Snažit se slepě optimalizovat program, aniž byste změřili, kde vlastně tráví svůj čas, je zbytečné cvičení. Řídit se pouze instinktem není vždy dostačující.
Existuje mnoho typů profilování, stejně jako existuje mnoho věcí, které můžete měřit. V tomto cvičení se zaměříme na profilování využití procesoru, což znamená čas, který jednotlivé funkce stráví prováděním instrukcí. Samozřejmě bychom mohli provádět mnoho dalších druhů profilování a optimalizací, například profilování paměti, které by měřilo paměť využitou každou částí kódu – o tom mluvím v knize The Hacker’s Guide to Python.
cProfile
Od verze Python 2.5 poskytuje Python modul jazyka C s názvem cProfile, který má rozumnou režii a nabízí dostatečně dobrou sadu funkcí. Základní použití se omezuje na:
Můžete s ním také spustit skript, což se ukazuje jako užitečné:
Vypíše všechny volané funkce s časem stráveným v každé z nich a počtem jejich volání.
Pokročilá vizualizace pomocí KCacheGrind
Je sice užitečný, ale výstupní formát je velmi základní a neumožňuje snadno získat znalosti pro kompletní programy. Pro pokročilejší vizualizaci využívám KCacheGrind. Pokud jste v posledních letech programovali a profilovali v jazyce C, možná jste jej používali, protože je primárně určen jako front-end pro grafy volání generované Valgrindem.
Pro použití je třeba vygenerovat výsledný soubor cProfile a poté jej převést do formátu KCacheGrind. K tomu používám pyprof2calltree.
$ python -m cProfile -o myscript.cprof myscript.py$ pyprof2calltree -k -i myscript.cprofA okno KCacheGrindu se zázračně objeví!“
Konkrétní případ: Optimalizace Carbonary
Zajímaly mě výkony Carbonary, malé knihovny časových řad, kterou jsem napsal pro Gnocchi. Rozhodl jsem se provést základní profilování, abych zjistil, zda není zřejmé, že je třeba provést nějakou optimalizaci.
Aby bylo možné program profilovat, je třeba ho spustit. Ale spuštění celého programu v režimu profilování může generovat spoustu dat, která vás nezajímají, a přidává šum k tomu, co se snažíte pochopit. Protože Gnocchi má tisíce jednotkových testů a několik testů pro samotnou Carbonaru, rozhodl jsem se profilovat kód používaný těmito jednotkovými testy, protože dobře odráží základní vlastnosti knihovny.
Všimněte si, že toto je dobrá strategie pro zvědavé a naivní profilování na první pokus.
Neexistuje způsob, jak si můžete být jisti, že horká místa, která uvidíte v jednotkových testech, jsou skutečná horká místa, na která narazíte v produkci. Proto je profilování v podmínkách a se scénářem, který napodobuje to, co je vidět v produkci, často nutností, pokud potřebujete optimalizaci programu posunout dál a chcete dosáhnout vnímatelného a hodnotného zisku.
Aktivoval jsem cProfile výše popsaným způsobem a vytvořil kolem svých testů objekt cProfile.Profile (vlastně jsem to začal implementovat v testtools). Poté jsem spustil KCacheGrind způsobem popsaným výše. Pomocí KCacheGrindu jsem vygeneroval následující čísla:
Test, který jsem zde profiloval, se jmenuje test_fetch a je celkem snadno pochopitelný: vkládá data do objektu timeserie a poté načte agregovaný výsledek. Z výše uvedeného seznamu vyplývá, že 88 % tiků je stráveno v set_values (44 tiků nad 50). Tato funkce slouží k vložení hodnot do timeserie, nikoli k jejich načtení. To znamená, že je opravdu pomalá při vkládání dat a docela rychlá při jejich skutečném načítání.
Přečtení zbytku seznamu ukazuje, že o zbytek tiků se dělí několik funkcí: update, _first_block_timestamp, _truncate, _resample atd. Některé funkce v seznamu nejsou součástí Carbonary, takže nemá smysl hledat jejich optimalizaci. Jediné, co lze optimalizovat, je někdy počet jejich volání.
Graf volání mi dává trochu více informací o tom, co se zde děje. S využitím svých znalostí o tom, jak funguje Carbonara, si myslím, že celý zásobník vlevo pro _first_block_timestamp nedává moc smysl. Tato funkce má najít první časové razítko pro agregát, např. při časovém razítku 13:34:45 a periodě 5 minut by funkce měla vrátit 13:30:00 hod. V současné době to funguje tak, že se volá funkce resample z Pandas na timeserii s pouze jedním prvkem, ale to se zdá být velmi pomalé. V současné době totiž tato funkce představuje 25 % času stráveného set_values (11 tiků na 44).
Naštěstí jsem nedávno přidal malou funkci _round_timestamp, která dělá přesně to, co _first_block_timestamp potřebuje, že bez volání jakékoliv funkce Pandas, takže žádná resample. Takže jsem nakonec tu funkci přepsal takto:
A pak jsem znovu spustil úplně stejný test, abych porovnal výstup cProfile.
Seznam funkcí tentokrát vypadá úplně jinak. Počet spotřebovaného času funkce set_values klesl z 88 % na 71 %.
Zásobník volání pro set_values to ukazuje docela dobře: funkci _first_block_timestamp ani nevidíme, protože je tak rychlá, že ze zobrazení úplně zmizela. Profiler ji nyní považuje za bezvýznamnou.
Takže celý proces vkládání hodnot do Carbonaru jsme právě zrychlili o pěkných 25 % během několika minut. Na první naivní průchod to není tak špatné, ne?“
Pokud chcete vědět víc, napsal jsem o optimalizaci kódu celou kapitolu v knize Scaling Python. Podívejte se na ni!