A cProfilon túl:

start = process_time()try: f()finally: elapsed = process_time() - start

A profiler rögzíti a CPU-időt az induláskor és a befejezéskor, és a különbséget az adott függvény számlájára írja.

A cProfile problémái

A cProfile ugyan mindig elérhető bármely Python telepítésben, de néhány jelentős problémával is küzd.

Probléma #1: Nagy rezsiköltség és torz eredmények

Amint azt elképzelhetjük, minden egyes függvényhívásnál többletmunkát végezni némi költséggel jár:

$ python benchmark.py7855 messages/sec$ python -m cProfile benchmark.py5264 messages/sec... cProfile output ...

Figyeljük meg, mennyivel lassabb a cProfile futtatása.És ami még rosszabb, a lassulás nem egyenletes az egész programodban: mivel a függvényhívások számához van kötve, a kódod azon részei, amelyekben több függvényhívás van, jobban lelassulnak. így ez a többletköltség torzíthatja az eredményeket.

2. probléma: Túl sok információ

Ha emlékszik a fentebb látott cProfile kimenetre, az tartalmaz egy sort minden egyes függvényről, amelyet a program futása során meghívtak. ezeknek a függvényhívásoknak a többsége irreleváns a teljesítményproblémánk szempontjából: gyorsan futnak, és csak egyszer vagy kétszer.

A cProfile kimenet olvasásakor tehát sok extra zajjal van dolgunk, amely elfedi a jelet.

Probléma #3: A teljesítmény offline mérése

Nagyon gyakran a programod csak akkor lesz lassú, ha valós körülmények között, valós bemenetekkel futsz.Lehet, hogy csak a felhasználók bizonyos lekérdezései lassítják a webes alkalmazásodat, és nem tudod, hogy mely lekérdezések.Lehet, hogy a kötegelt programod csak valós adatokkal lassú.

De a cProfile, mint láttuk, eléggé lelassítja a programodat, és ezért valószínűleg nem akarod futtatni a termelési környezetedben. így míg a lassúság csak a termelésben reprodukálható, a cProfile csak a fejlesztési környezetedben segít neked.

4. probléma: A teljesítményt csak függvényekre mérik

A cProfile meg tudja mondani, hogy “slowfunc() lassú”, ahol átlagolja az adott függvény összes bemenetét.És ez rendben is van, ha a függvény mindig lassú.

De néha van olyan algoritmikus kódod, amely csak bizonyos bemenetekre lassú.Nagyon is lehetséges, hogy:

• slowfunc(100) gyors.
• slowfunc(0) lassú.

cProfile nem fogja tudni megmondani, hogy mely bemenetek okozták a lassúságot, ami megnehezítheti a probléma diagnosztizálását.

cProfile:

• A Pyinstrument megoldja az #1 és #2 problémákat.
• Az Eliot megoldja a 3. és 4. problémát.

Pyinstrument: egy mintavételi profilozó

A Pyinstrument a fentebb tárgyalt problémák közül kettőt old meg:

• Kisebb overheaddel rendelkezik, mint a cProfile, és nem torzítja az eredményeket.
• Kiszűri az irreleváns függvényhívásokat, így kevesebb a zaj.

A Pyinstrument az eltelt falióraidőt méri, nem a CPU-időt, így elkapja a hálózati kérések, lemezes írások, lock contention stb. okozta lassúságot.

Hogyan használd

A Pyinstrument használata hasonló a cProfile-hoz; csak egy előtagot kell hozzáadni a szkriptedhez:

$ python benchmark.py7561 messages/sec$ python -m pyinstrument benchmark.py6760 messages/sec... pyinstrument output ...

Megjegyezzük, hogy van némi overheadje, de nem annyi, mint a cProfile-nak – és a overhead egyenletes.

A Pyinstrumentnek van egy Python API-ja is, így használhatja bizonyos kódrészletek profilozására egy Python interaktív interpreterben vagy egy Jupyter notebookban.

A kimenet

A Pyinstrument kimenete egy hívásokból álló fa, amely a falióra-időt méri:

A cProfile funkciónkénti sorszámozásával ellentétben a Pyinstrument egy függvényhívásokból álló fát ad, így láthatjuk a lassúság kontextusát.Egy függvény többször is megjelenhet, ha a lassúságot több kódútvonal okozza.

A Pyinstrument kimenete így sokkal könnyebben értelmezhető, és sokkal jobban megérti a program teljesítményszerkezetét, mint a cProfile alapértelmezett kimenete.

Hogyan működik (macskás kiadás)

Képzelje el, hogy van egy macskája. szeretné tudni, hogyan tölti az idejét.

Kémlelhetnéd minden pillanatát, de az rengeteg munka lenne.Így inkább úgy döntesz, hogy mintákat veszel: 5 percenként bedugod a fejed abba a szobába, ahol a macska van, és felírod, mit csinál.

Például:

• 12:00: Alszik 💤
• 12:05: Alszik 💤
• 12:10: Eszik 🍲
• 12:15: Használja az alomtálat 💩
• 12:20: Alszik 💤
• 12:25: Alszik 💤
• 12:30: Alszik 💤

Pár nappal később összegezheted a megfigyeléseidet:

• 80%: Alszik 💤
• 10%: Evés 🍲
• 9%: Az alomtálca használata 💩
• 1%: Vágyakozva bámulja az ablakon keresztül a madarakat 🐦

Tehát mennyire pontos ez az összegzés?Amennyiben az a célod, hogy felmérd, hol töltötte a macska a legtöbb időt, valószínűleg pontos. és minél gyakoribbak a megfigyelések (==minták) és minél több megfigyelést végzel, annál pontosabb az összegzés.

Ha a macskád az ideje nagy részét alvással tölti, akkor elvárhatod, hogy a legtöbb mintavételezett megfigyelés azt mutassa, hogy alszik.És igen, kihagysz néhány gyors és ritka tevékenységet – de a “mivel töltötte a macska az ideje nagy részét” céljai szempontjából ezek a gyors és ritka tevékenységek lényegtelenek.

Hogyan működik (szoftveres kiadás)

A macskánkhoz hasonlóan a Pyinstrument is időközönként mintavételezi a Python program viselkedését: 1ms-enként ellenőrzi, hogy éppen milyen függvény fut.Ez azt jelenti:

• Ha egy függvény halmozottan lassú, akkor gyakran fog megjelenni.
• Ha egy függvény halmozottan gyors, általában egyáltalán nem fogjuk látni.

Ez azt jelenti, hogy a teljesítmény-összefoglalónk kevesebb zajt tartalmaz: az alig használt függvények többnyire kimaradnak.De összességében az összegzés elég pontos a program időtöltését illetően, feltéve, hogy elegendő mintát vettünk.

Eliot: A naplózó könyvtár

Az utolsó eszköz, amellyel részletesen foglalkozunk, az Eliot, egy általam írt naplózó könyvtár, amely megoldja a másik két problémát, amit a cProfile-nál láttunk:

• A naplózás használható a termelésben.
• A naplózás rögzítheti a függvények argumentumait.

Amint látni fogjuk, az Eliot néhány olyan egyedi képességet biztosít, amelyek jobbá teszik a teljesítmény rögzítését, mint a normál naplózó könyvtárak.Ennek ellenére némi plusz munkával ugyanezeket az előnyöket más naplózó könyvtárakkal is elérhetjük.

Naplózás hozzáadása meglévő kódhoz

Nézzük a következő programvázlatot:

Vegyük ezt a kódot, és adjunk hozzá némi naplózást:

Közelebbről két dolgot teszünk:

1. Megmondjuk az Eliotnak, hogy hova adja ki a naplóüzeneteket (ebben az esetben egy “out.log”).
2. A függvényeket egy @log_call dekorátorral díszítjük.Ez naplózza a függvény meghívásának tényét, az argumentumait és a visszatérési értéket (vagy a kiváltott kivételt).

Eliotnak vannak más, finomabb API-jai is, de a @log_call elégséges a naplózás előnyeinek bemutatásához.

Eliot kimenete

Amint lefuttattuk a programot, az eliot-tree nevű eszközzel megnézhetjük a naplókat:

Megjegyezzük, hogy egy kicsit a Pyinstrumenthez hasonlóan egy akciókból álló fát nézünk.Kicsit leegyszerűsítettem a kimenetet – eredetileg azért, hogy elférjen egy dián, amit ennek a cikknek az előadásváltozatában használtam -, de még egy prózai cikkben is lehetővé teszi, hogy a teljesítmény szempontjára koncentráljunk.

Az Eliotban minden akciónak van egy kezdete és egy vége, és más akciókat is indíthat – így az eredményül kapott fa.Mivel tudjuk, hogy az egyes naplózott akciók mikor kezdődnek és mikor fejeződnek be, azt is tudjuk, hogy mennyi ideig tartottak.

Ebben az esetben minden akció egy-egy függvényhívásnak felel meg.És van néhány különbség a Pyinstrument kimenetéhez képest:

1. A több függvényhívás kombinálása helyett minden egyes hívást külön-külön látunk.
2. Láthatja az egyes hívások argumentumait és visszatérési eredményét.
3. Láthatja az egyes műveletek eltelt wallclock idejét.

Láthatja például, hogy a multiplysum() 10 másodpercet vett igénybe, de az idő túlnyomó részét a multiply()-ben töltötte, a 3 és 4 bemenetekkel.Így azonnal tudja, hogy a teljesítmény optimalizálásához a multiply()-re kell összpontosítania, és van néhány kezdő bemenet (3 és 4), amivel játszadozhat.

A naplózás korlátai

A naplózás önmagában nem elegendő a teljesítményre vonatkozó információk forrásaként.

Először is, csak olyan kódból kap információt, amelyhez kifejezetten naplózási hívásokat adott.Egy profiler bármely tetszőleges kódrészleten lefuthat előzetes előkészítés nélkül, de a naplózással előre el kell végezni némi munkát.

Ha nem adtál hozzá naplózó kódot, akkor nem kapsz semmilyen információt.Az Eliot ezt egy kicsit jobbá teszi, mivel a műveletfa struktúrája ad némi támpontot, hogy mire ment el az idő, de ez még mindig nem elegendő, ha a naplózás túl ritka.

Második, nem adhatsz hozzá naplózást mindenhova, mert az lelassítja a programodat.A naplózás nem olcsó – nagyobb a rezsije, mint a cProfilnak.Tehát megfontoltan kell hozzáadni, a kulcsfontosságú pontokon, ahol maximalizálja az általa nyújtott információt anélkül, hogy a teljesítményt befolyásolná.

A megfelelő eszközök kiválasztása

Mikor érdemes használni az egyes eszközöket?

Mindig adj hozzá naplózást

Minden nem triviális programnak valószínűleg szüksége van némi naplózásra, már csak a hibák és hibák kiszűrése miatt is.És ha már naplózást adsz hozzá, akkor veheted a fáradságot, hogy a teljesítmény hibakereséshez szükséges információkat is naplózd.

Az Eliot megkönnyíti ezt, mivel a műveletek naplózása eleve megadja az eltelt időt, de némi plusz munkával ezt bármelyik naplózó könyvtárral megteheted.

A naplózás segíthet kiszúrni azt a konkrét helyet, ahol a programod lassú, és legalább néhány lassúságot okozó bemenetet, de ez gyakran nem elegendő.A következő lépés tehát egy profiler használata, különösen egy olyan mintavételes profileré, mint a Pyinstrument:

• Alacsony overheaddel rendelkezik, és ami még fontosabb, nem torzítja az eredményeket.
• A wallclock időt méri, tehát nem feltételezi, hogy a CPU a szűk keresztmetszet.
• Csak a lassabb függvényeket adja ki, kihagyva a lényegtelen gyors függvényeket.

Használja a cProfile-t, ha egyéni költségmetrikára van szüksége

Ha valaha is egyéni profiler írására van szüksége, a cProfile lehetővé teszi, hogy különböző költségfüggvényeket illesszen be, így egyszerű eszköz a szokatlanabb metrikák mérésére.

Mérheti:

• Nem-CPU, a nem-CPU eseményekre várakozással töltött összes időt.
• Az önkéntes kontextusváltások számát, azaz a sokáig tartó rendszerhívások számát.
• A memóriafoglalásokat.
• Tágabb értelemben minden olyan számlálót, amely felfelé megy.

TL;DR

A teljesítményoptimalizálási eszközök jó kiindulópontjaként azt javaslom, hogy:

1. Naplózza a legfontosabb be- és kimeneteket, valamint a legfontosabb műveletek eltelt idejét az Eliot vagy más naplózó könyvtár segítségével.
2. A Pyinstrument-t – vagy más mintavételes profilozót – használja alapértelmezett profilozóként.
3. A cProfile-t használja, ha egyéni profilozóra van szüksége.