Dincolo de cProfil: Alegerea instrumentului potrivit pentru optimizarea performanței

Nota: Acest articol se bazează pe o prezentare pe care am susținut-o la PyGotham 2019. Puteți viziona videoclipul aici.

Programul dvs. Python este prea lent.Poate că aplicația dvs. web nu poate ține pasul, sau anumite interogări durează mult timp.Poate că aveți un program batch care are nevoie de ore sau chiar zile pentru a rula.

Cum accelerați?

Procesul de bază pe care probabil îl veți urma este:

1. Alegeți instrumentul potrivit pentru a măsura viteza.
2. Utilizați instrumentul pentru a vă da seama care este gâtul de îmbulzeală.
3. Reparați gâtul de îmbulzeală.

Acest articol se va concentra pe primul pas: alegerea instrumentului potrivit. și, în special, va acoperi:

• cProfil: Profilatorul determinist al bibliotecii standard Python.
• Pyinstrument: Un profiler de eșantionare.
• Eliot: O bibliotecă de logare.

Nu voi intra într-o cantitate uriașă de detalii despre modul de utilizare a acestor instrumente, deoarece scopul este de a vă ajuta să îl alegeți pe cel potrivit. Dar voi explica ce fac aceste instrumente și când și de ce ați alege unul în detrimentul celuilalt.

cProfile: Un profiler determinist

Profilerul cProfile este încorporat în Python, așa că probabil ați auzit de el și este posibil să fie instrumentul implicit pe care îl utilizați.Funcționează prin urmărirea fiecărui apel de funcție dintr-un program.De aceea este un profiler determinist: dacă îl rulați cu aceleași intrări, va da același rezultat.

În mod implicit, cProfile măsoară CPU-ul procesului – cât de mult CPU a folosit procesul dumneavoastră până acum.Ar trebui să întrebați întotdeauna ce măsoară profilerul dumneavoastră, deoarece diferite măsuri pot detecta probleme diferite.Măsurarea CPU înseamnă că nu puteți detecta încetineala cauzată de alte cauze, cum ar fi așteptarea unui răspuns de la o interogare a unei baze de date.

În timp ce cProfile este întotdeauna disponibil în instalația dumneavoastră Python, acesta are și unele probleme – și după cum veți vedea, de cele mai multe ori nu doriți să-l utilizați.

Utilizarea cProfile

Utilizarea cProfile este destul de ușoară.Dacă aveți un script pe care de obicei îl rulați direct, astfel:

$ python benchmark.py7855 messages/sec

Apoi puteți pur și simplu prefixa python -m cProfile pentru a-l rula sub profiler:

Există, de asemenea, un API de profilare Python, astfel încât să puteți face profilul anumitor funcții într-un prompt al interpretorului Python sau într-un caiet Jupyter.

Formatul de ieșire este un tabel, care nu este ideal: fiecare rând este un apel de funcție care s-a executat în intervalul de timp profilat, dar nu știți cum este legat acel apel de funcție de alte apeluri de funcție.Deci, dacă aveți o funcție la care se poate ajunge din mai multe căi de cod, poate fi dificil să vă dați seama care cale de cod a fost responsabilă pentru apelarea funcției lente.

Ce vă poate spune cProfile

Dacă vă uitați la tabelul de mai sus, puteți vedea că:

• _output.py(__call__) a fost apelată de 50.000 de ori. Este un număr par deoarece acesta este un script de referință care rulează același cod într-o buclă de 10.000 de ori.Dacă nu ați apelat în mod deliberat o funcție de mai multe ori, acest lucru poate fi util pentru a depista numărul mare de apeluri este util pentru a identifica buclele interne ocupate.
• _output.py(send) a folosit 0,618 secunde CPU (inclusiv timpul CPU al funcțiilor pe care le-a apelat) și 0,045 secunde CPU (fără a include funcțiile pe care le-a apelat).

Utilizând aceste informații puteți identifica funcțiile lente pe care le puteți optimiza – lente în ceea ce privește CPU, oricum.

Cum funcționează

cProfile măsoară fiecare apel de funcție. în special, fiecare apel de funcție din execuție este înfășurat astfel:

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

Profilerul înregistrează timpul CPU la început și la sfârșit, iar diferența este alocată în contul acelei funcții.

Problemele cu cProfile

În timp ce cProfile este întotdeauna disponibil în orice instalare Python, el suferă, de asemenea, de unele probleme semnificative.

Problema #1: Overhead ridicat și rezultate distorsionate

După cum vă puteți imagina, efectuarea de muncă suplimentară pentru fiecare apel de funcție are unele costuri:

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

Observați cât de mult mai lentă este rularea cProfile.Și ceea ce este mai rău, încetinirea nu este uniformă în întregul program: deoarece este legată de numărul de apeluri de funcții, părțile codului dvs. cu mai multe apeluri de funcții vor fi mai încetinite. deci acest cost suplimentar poate denatura rezultatele.

Problema nr. 2: Prea multă informație

Dacă vă amintiți ieșirea cProfile pe care am văzut-o mai sus, aceasta include un rând pentru fiecare funcție care a fost apelată în timpul rulării programului.Majoritatea acestor apeluri de funcții sunt irelevante pentru problema noastră de performanță: ele se execută rapid și doar o dată sau de două ori.

Atunci, când citiți ieșirea cProfile, aveți de-a face cu o mulțime de zgomot suplimentar care maschează semnalul.

Problema nr. 3: Măsurarea offline a performanței

De foarte multe ori, programul dvs. va fi lent doar atunci când se execută în condiții reale, cu intrări din lumea reală.Poate doar anumite interogări de la utilizatori încetinesc aplicația dvs. web și nu știți care interogări.Poate că programul dvs. batch este lent doar cu date reale.

Dar cProfile, așa cum am văzut, încetinește destul de mult programul dvs. și, astfel, probabil că nu doriți să îl rulați în mediul de producție.Deci, în timp ce încetineala este reproductibilă doar în producție, cProfile vă ajută doar în mediul de dezvoltare.

Problema nr. 4: Performanța este măsurată doar pentru funcții

cProfile vă poate spune „slowfunc() este lent”, unde face o medie a tuturor intrărilor la acea funcție.Și asta este în regulă dacă funcția este întotdeauna lentă.

Dar uneori aveți un cod algoritmic care este lent doar pentru anumite intrări.Este foarte posibil ca:

• slowfunc(100) să fie rapid.
• slowfunc(0) este lent.

cProfile nu va putea să vă spună ce intrări au cauzat lentoarea, ceea ce poate face mai dificilă diagnosticarea problemei.

cProfile: De obicei insuficient

Ca urmare a acestor probleme, cProfile nu ar trebui să fie instrumentul dumneavoastră de performanță preferat. în schimb, în continuare vom vorbi despre două alternative:

• Pyinstrument rezolvă problemele #1 și #2.
• Eliot rezolvă problemele #3 și #4.

Pyinstrument: un profiler de eșantionare

Pyinstrument rezolvă două dintre problemele pe care le-am acoperit mai sus:

• Are un overhead mai mic decât cProfile și nu distorsionează rezultatele.
• Filtrează apelurile irelevante ale funcțiilor, astfel încât există mai puțin zgomot.

Pyinstrument măsoară timpul scurs în wallclock, nu timpul CPU, astfel încât poate detecta lentoarea cauzată de solicitările de rețea, scrierile pe disc, contenția de blocare și așa mai departe.

Cum îl folosiți

Utilizarea Pyinstrument este similară cu cProfile; trebuie doar să adăugați un prefix la scriptul dvs.:

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

Observați că are o oarecare suprasolicitare, dar nu la fel de mare ca cProfile – iar suprasolicitarea este uniformă.

Pyinstrument are, de asemenea, un API Python, astfel încât îl puteți utiliza pentru a realiza profilul anumitor bucăți de cod într-un interpretor interactiv Python sau într-un caiet Jupyter.

Scopul de ieșire

Scopul de ieșire al Pyinstrument este un arbore de apeluri, măsurând timpul ceasului de perete:

Spre deosebire de rândul pe funcție al cProfile, Pyinstrument vă oferă un arbore de apeluri de funcții, astfel încât să puteți vedea contextul încetinirii. o funcție poate apărea de mai multe ori dacă încetineala este cauzată de mai multe căi de cod.

Ca rezultat, ieșirea lui Pyinstrument este mult mai ușor de interpretat și vă oferă o înțelegere mult mai bună a structurii de performanță a programului dumneavoastră decât ieșirea implicită a lui cProfile.

Cum funcționează (ediția pisică)

Imaginați-vă că aveți o pisică. doriți să știți cum își petrece timpul acea pisică.

Ați putea să-i spionați fiecare moment, dar asta ar însemna multă muncă. în schimb, decideți să luați mostre: la fiecare 5 minute vă băgați capul în camera în care se află pisica și notați ce face.

De exemplu:

• 12:00: Doarme 💤
• 12:05: Doarme 💤
• 12:10: Mănâncă 🍲
• 12:15: Folosește litiera 💩
• 12:20: Doarme 💤
• 12:25: Dormind 💤
• 12:30: Dormind 💤

Câteva zile mai târziu puteți rezuma observațiile:

• 80%: Dormit 💤
• 10%: Mâncare 🍲
• 9%: Folosirea litierei 💩
• 1%: Privește lung prin fereastră păsările 🐦

Cât de precis este acest rezumat?În măsura în care scopul dvs. este de a măsura unde și-a petrecut pisica cea mai mare parte a timpului, probabil că este precis.Și cu cât sunt mai frecvente observațiile (==eșantioane) și cu cât sunt mai multe observații pe care le faceți, cu atât mai precis este rezumatul.

Dacă pisica dvs. își petrece cea mai mare parte a timpului dormind, v-ați aștepta ca majoritatea observațiilor eșantionate să arate că doarme. și da, veți rata unele activități rapide și rare – dar în scopul „la ce și-a petrecut pisica cea mai mare parte a timpului” aceste activități rapide și rare sunt irelevante.

Cum funcționează (ediția software)

La fel ca pisica noastră, Pyinstrument eșantionează comportamentul unui program Python la intervale de timp: la fiecare 1ms verifică ce funcție rulează în acel moment.Asta înseamnă:

• Dacă o funcție este cumulativ lentă, va apărea des.
• Dacă o funcție este cumulativ rapidă, de obicei nu o vom vedea deloc.

Aceasta înseamnă că rezumatul nostru de performanță are mai puțin zgomot: funcțiile care sunt abia folosite vor fi în cea mai mare parte sărite.Dar, în general, rezumatul este destul de precis în ceea ce privește modul în care programul și-a petrecut timpul, atâta timp cât am luat suficiente eșantioane.

Eliot: O bibliotecă de logare

Ultimul instrument pe care îl vom acoperi în detaliu este Eliot, o bibliotecă de logare pe care am scris-o. Aceasta rezolvă celelalte două probleme pe care le-am văzut cu cProfile:

• Logarea poate fi folosită în producție.
• Logarea poate înregistra argumentele funcțiilor.

După cum veți vedea, Eliot oferă unele capabilități unice care îl fac mai bun la înregistrarea performanțelor decât bibliotecile normale de logare. acestea fiind spuse, cu ceva muncă suplimentară puteți obține aceleași beneficii și de la alte biblioteci de logare.

Adaugarea logării la codul existent

Considerați următoarea schiță a unui program:

Potem lua acest cod și să-i adăugăm niște logări:

În mod specific, facem două lucruri:

1. Să-i spunem lui Eliot unde să scoată mesajele de logare (în acest caz, un fișier numit „out.log”).
2. Decorăm funcțiile cu un decorator @log_call.Acesta va consemna faptul că funcția a fost apelată, argumentele sale și valoarea de retur (sau excepția ridicată).

Eliot are alte API-uri mai fine, dar @log_call este suficient pentru a demonstra beneficiile logării.

Eliot’s output

După ce rulăm programul, ne putem uita la jurnale folosind un instrument numit eliot-tree:

Rețineți că, un pic ca Pyinstrument, ne uităm la un arbore de acțiuni.Am simplificat puțin ieșirea – inițial pentru a putea încăpea pe un diapozitiv pe care l-am folosit în versiunea de prezentare a acestui articol – dar chiar și într-un articol în proză ne permite să ne concentrăm asupra aspectului de performanță.

În Eliot, fiecare acțiune are un început și un sfârșit și poate începe alte acțiuni – de aici și arborele rezultat.Deoarece știm când începe și când se termină fiecare acțiune înregistrată, știm, de asemenea, cât timp a durat.

În acest caz, fiecare acțiune se mapează unu-la-unu cu un apel de funcție. și există câteva diferențe față de ieșirea lui Pyinstrument:

1. În loc de a combina mai multe apeluri de funcție, vedeți fiecare apel individual separat.
2. Puteți vedea argumentele și rezultatul de întoarcere al fiecărui apel.
3. Puteți vedea timpul scurs de ceas de perete al fiecărei acțiuni.

De exemplu, puteți vedea că multiplysum() a durat 10 secunde, dar marea majoritate a timpului a fost petrecut în multiply(), cu intrările 3 și 4.Deci știți imediat că pentru optimizarea performanței doriți să vă concentrați pe multiply(), și aveți niște intrări de pornire (3 și 4) cu care să vă jucați.

Limitele logării

Logarea nu este suficientă de una singură ca sursă de informații despre performanță.

În primul rând, obțineți informații doar din codul în care ați adăugat în mod explicit apeluri de logare.Un profiler poate rula pe orice bucată arbitrară de cod fără nicio pregătire prealabilă, dar cu jurnalizarea trebuie să faceți ceva muncă în avans.

Dacă nu ați adăugat cod de jurnalizare, nu veți obține nicio informație.Eliot face acest lucru un pic mai bine, deoarece structura arborelui de acțiuni vă dă o idee despre unde a fost cheltuit timpul, dar tot nu este suficient dacă jurnalizarea este prea puțină.

În al doilea rând, nu puteți adăuga jurnalizarea peste tot, deoarece acest lucru vă va încetini programul.Jurnalizarea nu este ieftină – este mai mare decât cProfile.Așa că trebuie să o adăugați în mod judicios, în puncte cheie unde va maximiza informațiile pe care le oferă fără a afecta performanța.

Alegerea instrumentelor potrivite

Atunci când ar trebui să folosiți fiecare instrument?

Întotdeauna adăugați logging

Care program non-trivial are probabil nevoie de ceva logging, fie și numai pentru a detecta bug-uri și erori.Și dacă adăugați deja logging, vă puteți lua osteneala de a înregistra și informațiile de care aveți nevoie pentru a face depanarea performanței.

Eliot face acest lucru mai ușor, deoarece înregistrarea acțiunilor vă oferă în mod inerent timpul scurs, dar puteți, cu ceva muncă suplimentară, să faceți acest lucru cu orice bibliotecă de logare.

Logarea vă poate ajuta să identificați locul specific în care programul dvs. este lent și, cel puțin, unele intrări care cauzează lentoarea, dar este adesea insuficientă.Așadar, următorul pas este să folosiți un profiler și, în special, un profiler de eșantionare, cum ar fi Pyinstrument:

• Aceasta are o suprasolicitare redusă și, mai important, nu denaturează rezultatele.
• Măsurează timpul wallclock, deci nu presupune că CPU este gâtul de îmbulzeală.
• Ea scoate doar funcțiile mai lente, omițând funcțiile rapide irelevante.

Utilizați cProfile dacă aveți nevoie de o metrică de cost personalizată

Dacă veți avea vreodată nevoie să scrieți un profiler personalizat, cProfile vă permite să introduceți diferite funcții de cost, făcându-l un instrument ușor pentru măsurarea unor metrici mai neobișnuite.

Puteți măsura:

• Not-CPU, tot timpul petrecut în așteptarea unor evenimente non-CPU.
• Numărul de schimbări voluntare de context, adică numărul de apeluri de sistem care durează mult timp.
• Alocațiile de memorie.
• În sens mai larg, orice contor care crește.

TL;DR

Ca un bun punct de plecare în ceea ce privește instrumentele de optimizare a performanței, vă sugerez să:

1. Înregistrați intrările și ieșirile cheie, precum și timpul scurs de acțiuni cheie, folosind Eliot sau o altă bibliotecă de logare.
2. Utilizați Pyinstrument – sau un alt profiler de eșantionare – ca profiler implicit.
3. Utilizați cProfile când dacă aveți nevoie de un profiler personalizat.

.