Pythonin profilointi cProfilen avulla: konkreettinen tapaus

Ohjelmien kirjoittaminen on hauskaa, mutta niiden nopeuttaminen voi olla hankalaa. Python-ohjelmat eivät ole tästä poikkeus, mutta perusprofilointityökaluketju ei itse asiassa ole kovin monimutkainen käyttää. Tässä haluan näyttää, miten voit nopeasti profiloida ja analysoida Python-koodisi löytääksesi, mitä osaa koodista sinun pitäisi optimoida.

Python-ohjelman profilointi on dynaamisen analyysin tekemistä, jossa mitataan ohjelman ja kaiken sen muodostavan suoritusaika. Tämä tarkoittaa, että mitataan sen jokaisessa funktiossa käytetty aika. Näin saat tietoa siitä, mihin ohjelmasi käyttää aikaa ja mitä aluetta kannattaisi ehkä optimoida.

Se on erittäin mielenkiintoinen harjoitus. Monet keskittyvät paikallisiin optimointeihin, kuten esimerkiksi sen määrittämiseen, kumpi Python-funktioista range tai xrange on nopeampi. Osoittautuu, että sen tietäminen, kumpi on nopeampi, ei ehkä koskaan ole ohjelmassasi ongelma, ja että jommankumman edellä mainitun funktion voittama aika ei ehkä ole sen ajan arvoista, jonka käytät sen tutkimiseen tai siitä kiistelemiseen kollegasi kanssa.

Yrität sokeasti optimoida ohjelmaa mittaamatta sitä, mihin se todellisuudessa käyttää aikaansa, on hyödytön harjoitus. Pelkän vaiston seuraaminen ei aina riitä.

Profilointia on monenlaista, kuten on monia asioita, joita voi mitata. Tässä harjoituksessa keskitymme suorittimen käyttöasteen profilointiin eli siihen, kuinka paljon aikaa kukin funktio käyttää ohjeiden suorittamiseen. Ilmeisesti voisimme tehdä monenlaista muutakin profilointia ja optimointia, kuten muistiprofilointia, joka mittaisi kunkin koodin käyttämää muistia – jotain, josta puhun teoksessa The Hacker’s Guide to Python.

cProfile

Python tarjoaa Python 2.5:stä lähtien C-moduulin nimeltä cProfile, jolla on kohtuullinen yleiskustannus ja joka tarjoaa riittävän hyvät ominaisuudet. Peruskäyttö menee näin:

Voit tosin ajaa sen avulla myös skriptin, joka osoittautuu käteväksi:

Tämä tulostaa kaikki kutsutut funktiot ja niihin kuluneen ajan sekä kuinka monta kertaa niitä on kutsuttu.

Edistyneempi visualisointi KCacheGrindin avulla

Ollessaan käyttökelpoinen ulostulomuoto on hyvin perustasoa eikä siitä ole helppo poimia tietoa kokonaisista ohjelmista. Edistyneempään visualisointiin hyödynnän KCacheGrindiä. Jos olet tehnyt C-ohjelmointia ja profilointia viime vuosina, olet ehkä käyttänyt sitä, sillä se on ensisijaisesti suunniteltu Valgrindin tuottamien call-graafien front-endiksi.

Käyttöä varten sinun on luotava cProfile-tulostiedosto ja muunnettava se sitten KCacheGrind-formaattiin. Siihen käytän pyprof2calltree.

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

Ja KCacheGrind-ikkuna ilmestyy maagisesti!

Konkreettinen tapaus: Carbonaran optimointi

Olin utelias Gnocchia varten kirjoittamani pienen aikasarjakirjaston Carbonaran suorituskyvystä. Päätin tehdä jonkinlaisen perusprofiloinnin nähdäkseni, olisiko mitään ilmeistä optimoitavaa.

Voidaksesi profiloida ohjelman, sinun täytyy ajaa se. Mutta koko ohjelman ajaminen profilointitilassa voi tuottaa paljon dataa, josta et välitä, ja se lisää kohinaa siihen, mitä yrität ymmärtää. Koska Gnocchissa on tuhansia yksikkötestejä ja muutama itse Carbonaralle, päätin profiloida näiden yksikkötestien käyttämän koodin, koska se kuvastaa hyvin kirjaston perusominaisuuksia.

Huomaa, että tämä on hyvä strategia uteliaalle ja naiiville ensikokeilun profiloinnille.
Ei ole mitään keinoa varmistua siitä, että yksikkötesteissä näkyvät kuumat kohdat ovat todellisia kuumat kohdat, joihin törmäät tuotannossa. Siksi profilointi olosuhteissa ja skenaariolla, joka jäljittelee sitä, mitä tuotannossa nähdään, on usein välttämättömyys, jos haluat viedä ohjelmasi optimointia pidemmälle ja haluat saavuttaa havaittavaa ja arvokasta hyötyä.

Aktivoin cProfilea edellä kuvatulla menetelmällä luomalla testieni ympärille cProfile.Profile-olion (itse asiassa aloin toteuttaa sitä testtoolsissa). Sitten suoritan KCacheGrindin edellä kuvatulla tavalla. KCacheGrindin avulla tuotin seuraavat luvut.

Testi, jonka profiloin tässä, on nimeltään test_fetch, ja se on melko helppo ymmärtää: se laittaa datan timeserie-objektiin ja hakee sitten aggregoidun tuloksen. Yllä olevasta listasta näkyy, että 88 % rasteista kuluu set_values:ssä (44 rastia yli 50). Tätä funktiota käytetään arvojen lisäämiseen timeserie-objektiin, ei arvojen noutamiseen. Se tarkoittaa, että tietojen lisääminen on todella hidasta ja niiden varsinainen hakeminen melko nopeaa.

Loppuosan luettelosta lukeminen osoittaa, että useat funktiot jakavat loput rasteista, update, _first_block_timestamp, _truncate, _resample jne. Osa listan funktioista ei kuulu Carbonaraan, joten niitä ei kannata yrittää optimoida. Ainoa asia, jota voidaan optimoida, on joskus niiden kutsumiskertojen määrä.

Kutsukaavio antaa minulle hieman enemmän tietoa siitä, mistä tässä on kyse. Käyttämällä tietojani Carbonaran toiminnasta en usko, että koko pino vasemmalla puolella _first_block_timestamp:n kohdalla on kovin järkevä. Tämän funktion on tarkoitus löytää aggregaatin ensimmäinen aikaleima, esimerkiksi kun aikaleima on 13:34:45 ja ajanjakso 5 minuuttia, funktion pitäisi palauttaa 13:30:00. Tällä hetkellä se toimii kutsumalla Pandasin resample-funktiota aikasarjalle, jossa on vain yksi elementti, mutta se näyttää olevan hyvin hidasta. Itse asiassa tällä hetkellä tämä funktio edustaa 25 % set_values:n käyttämästä ajasta (11 rastia 44:llä).

Suurimmaksi onneksi lisäsin hiljattain pienen funktion nimeltä _round_timestamp, joka tekee juuri sen, mitä _first_block_timestamp tarvitsee kutsumatta yhtään Pandasin funktiota, joten ei resample:tä. Niinpä päädyin kirjoittamaan tuon funktion uudelleen näin:

Ja sitten suoritin täsmälleen saman testin uudelleen verratakseni cProfile:n tulosta.

Funktion luettelo näyttää tällä kertaa aivan erilaiselta. set_values:n käyttämän ajan määrä putosi 88 %:sta 71 %:iin.

Kutsupino set_values:n kohdalla osoittaa tämän melko hyvin: emme edes näe _first_block_timestamp-funktiota, sillä se on niin nopea, että se katosi kokonaan näytöltä. Profiler pitää sitä nyt merkityksettömänä.

Niinpä me vain nopeutimme koko arvojen lisäysprosessia Carbonaraan mukavasti 25 % muutamassa minuutissa. Ei hassumpaa ensimmäiseksi naiiviksi läpikäynniksi, eikö?

Jos haluat tietää lisää, kirjoitin kokonaisen luvun koodin optimoinnista Scaling Python -teoksessa. Tsekkaa se!

Vastaa

Sähköpostiosoitettasi ei julkaista.