Nad rámec cProfile:

Poznámka: Tento článek vychází z přednášky, kterou jsem měl na PyGothamu 2019. Video si můžete prohlédnout zde.

Váš program v Pythonu je příliš pomalý. možná vaše webová aplikace nestíhá nebo vám některé dotazy trvají dlouho. možná máte dávkový program, jehož spuštění trvá hodiny nebo dokonce dny.

Jak zrychlit?

Základní postup, který budete pravděpodobně dodržovat, je:

1. Vyberte správný nástroj pro měření rychlosti.
2. Pomocí nástroje zjistěte úzké místo.
3. Opravte úzké místo.

Tento článek se zaměří na první krok: výběr správného nástroje. a zejména se bude zabývat:

• cProfile:
• Pyinstrument:
• Eliot:

Nebudu zabíhat do velkých podrobností o tom, jak tyto nástroje používat, protože cílem je pomoci vám vybrat ten správný. Vysvětlím však, co tyto nástroje dělají a kdy a proč byste měli zvolit jeden z nich místo druhého.

cProfile: Pracuje tak, že sleduje každé volání funkce v programu.Proto je to deterministický profiler: pokud ho spustíte se stejnými vstupy, poskytne stejný výstup.

Ve výchozím nastavení cProfile měří CPU procesu – kolik CPU váš proces dosud využil.Vždy byste se měli zeptat, co váš profiler měří, protože různé míry mohou odhalit různé problémy. měření CPU znamená, že nemůžete odhalit pomalost způsobenou jinými příčinami, například čekáním na odpověď z databázového dotazu.

Přestože je cProfile vždy k dispozici ve vaší instalaci Pythonu, má také některé problémy – a jak uvidíte, většinou ho nechcete používat.

Použití cProfile

Použití cProfile je poměrně snadné.Pokud máte skript, který obvykle spouštíte přímo takto:

$ python benchmark.py7855 messages/sec

Pak stačí předřadit předponu python -m cProfile a spustíte jej pod profilovačem:

Existuje také API pro profilování v Pythonu, takže můžete profilovat konkrétní funkce ve výzvě interpretu Pythonu nebo v zápisníku Jupyter.

Výstupní formát je tabulka, což není ideální: každý řádek je volání funkce, které proběhlo během profilovaného časového úseku, ale nevíte, jak toto volání funkce souvisí s jinými voláními funkcí.Pokud tedy máte funkci, která je dosažitelná z více cest kódu, může být obtížné zjistit, která cesta kódu byla zodpovědná za volání pomalé funkce.

Co vám může říct cProfile

Podíváte-li se na výše uvedenou tabulku, vidíte, že:

• _output.py(__call__) byla volána 50 000krát. Je to sudé číslo, protože se jedná o srovnávací skript, který spouští stejný kód ve smyčce 10 000krát. pokud jste záměrně nevolali funkci mnohokrát, může to být užitečné pro odhalení vysokého počtu volání je užitečné pro identifikaci vytížených vnitřních smyček.
• _output.py(send) použil 0,618 sekundy CPU (včetně času CPU funkcí, které volal) a 0,045 sekundy CPU (bez funkcí, které volal).

Pomocí těchto informací můžete odhalit pomalé funkce, které můžete optimalizovat – každopádně pomalé, co se týče procesoru.

Jak to funguje

cProfile měří každé jednotlivé volání funkce. konkrétně se každé volání funkce v běhu zabalí takto:

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

Profilovač zaznamenává čas procesoru na začátku a na konci a rozdíl se přiřadí na účet dané funkce.

Problémy s cProfile

Přestože je cProfile vždy k dispozici v každé instalaci Pythonu, trpí také některými významnými problémy.

Problém č. 1: Vysoká režie a zkreslené výsledky

Jak si dokážete představit, vykonávání práce navíc pro každé volání funkce má určité náklady:

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

Všimněte si, o kolik je běh cProfile pomalejší.A co je horší, zpomalení není rovnoměrné v celém programu: protože je vázáno na počet volání funkcí, části kódu s větším počtem volání funkcí budou zpomaleny více. tato režie tedy může zkreslit výsledky.

Problém č. 2: Příliš mnoho informací

Pokud si vzpomenete na výstup cProfile, který jsme viděli výše, obsahuje řádek pro každou jednotlivou funkci, která byla během běhu programu zavolána. většina těchto volání funkcí je pro náš výkonnostní problém irelevantní: proběhnou rychle a jen jednou nebo dvakrát.

Při čtení výstupu cProfile tedy máte co do činění s množstvím dalšího šumu, který maskuje signál.

Problém č. 3: Offline měření výkonu

Dosti často bude váš program pomalý pouze při běhu v reálných podmínkách, s reálnými vstupy. možná vaši webovou aplikaci zpomalují pouze konkrétní dotazy uživatelů a vy nevíte, které dotazy. možná je váš dávkový program pomalý pouze s reálnými daty.

Ale cProfile, jak jsme viděli, váš program docela zpomalí, a proto ho pravděpodobně nechcete spouštět v produkčním prostředí. takže zatímco pomalost je reprodukovatelná pouze v produkci, cProfile vám pomůže pouze ve vašem vývojovém prostředí.

Problém č. 4: Výkon se měří pouze pro funkce

cProfile vám může říct „slowfunc() je pomalý“, kde zprůměruje všechny vstupy do této funkce.A to je v pořádku, pokud je funkce vždy pomalá.

Ale někdy máte nějaký algoritmický kód, který je pomalý jen pro určité vstupy. je docela možné, že:

• slowfunc(100) je rychlý.
• slowfunc(0) je pomalý.

cProfile vám nebude schopen říci, které vstupy způsobily pomalost, což může ztížit diagnostiku problému.

cProfile: Místo toho si příště povíme o dvou alternativách:

• Pyinstrument řeší problémy č. 1 a 2.
• Eliot řeší problémy č. 3 a 4.

Pyinstrument: vzorkovací profilovač

Pyinstrument řeší dva z problémů, které jsme popsali výše:

• Má nižší režii než cProfile a nezkresluje výsledky.
• Odfiltruje irelevantní volání funkcí, takže je v něm méně šumu.

Pyinstrument měří uplynulý čas wallclock, nikoli čas procesoru, takže může zachytit zpomalení způsobené síťovými požadavky, zápisem na disk, soupeřením o zámek atd.

Jak ho použít

Použití Pyinstrumentu je podobné jako u cProfile; stačí do skriptu přidat předponu:

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

Všimněte si, že má určitou režii, ale ne tak velkou jako cProfile – a režie je rovnoměrná.

Pyinstrument má také rozhraní API jazyka Python, takže jej můžete použít k profilování konkrétních částí kódu v interaktivním interpretu jazyka Python nebo v zápisníku Jupyter.

Výstup

Výstupem Pyinstrumentu je strom volání, který měří čas na nástěnných hodinách:

Na rozdíl od řádku na funkci v cProfile vám Pyinstrument poskytne strom volání funkcí, takže můžete vidět kontext zpomalení. funkce se může objevit vícekrát, pokud je zpomalení způsobeno více cestami kódu.

Výstup Pyinstrumentu je tak mnohem snadněji interpretovatelný a dává vám mnohem lepší představu o struktuře výkonu vašeho programu než výchozí výstup cProfile.

Jak to funguje (cat edition)

Představte si, že máte kočku. chcete vědět, jak tato kočka tráví svůj čas.

Mohli byste špehovat každý její okamžik, ale to by bylo hodně práce.

• Místo toho se rozhodnete pro vzorky: každých 5 minut strčíte hlavu do místnosti, kde je kočka, a zapíšete si, co dělá.

  Například:

  • 12:00 hod: Spí 💤
  • 12:05: Spí 💤
  • 12:10: Jí 🍲
  • 12:15: Používá záchod 💩
  • 12:20: Spí 💤
  • 12:25: Spaní 💤
  • 12:30: Spaní 💤

  O několik dní později můžete svá pozorování shrnout:

  • 80%: Spící 💤
  • 10%: Jídlo 🍲
  • 9%: Používání odpadkového koše 💩
  • 1%: 🐦

  Takže jak přesný je tento přehled?Pokud je vaším cílem změřit, kde kočka trávila většinu času, je pravděpodobně přesný. a čím častější pozorování (==vzorky) a čím více pozorování provedete, tím je přehled přesnější.

  Pokud vaše kočka tráví většinu času spánkem, očekáváte, že většina pozorování ve vzorcích ukáže, že spí. a ano, vynecháte některé rychlé a vzácné činnosti – ale pro účely „čím kočka trávila většinu času“ jsou tyto rychlé a vzácné činnosti irelevantní.

  Jak to funguje (softwarové vydání)

  Podobně jako naše kočka i Pyinstrument vzorkuje chování programu v jazyce Python v intervalech: každou 1 ms kontroluje, jaká funkce právě běží. to znamená:

  • Je-li funkce kumulativně pomalá, bude se objevovat často.
  • Je-li funkce kumulativně rychlá, většinou ji neuvidíme vůbec.

  To znamená, že náš přehled výkonu má menší šum: funkce, které se téměř nepoužívají, budou většinou přeskočeny.

  Eliot: Celkově je však přehled poměrně přesný, pokud jde o to, jak program trávil svůj čas, pokud jsme vzali dostatek vzorků.

  Eliot:

  Podívejte se na přehled výkonu: Řeší další dva problémy, které jsme viděli u cProfile:

  • Logging lze použít ve výrobě.
  • Logging může zaznamenávat argumenty funkcí.

  Jak uvidíte, Eliot poskytuje některé jedinečné možnosti, díky nimž zaznamenává výkon lépe než běžné knihovny pro protokolování. jak již bylo řečeno, s trochou práce navíc můžete stejné výhody získat i z jiných knihoven pro protokolování.

  Přidání logování do existujícího kódu

  Podívejme se na následující náčrt programu:

  Můžeme vzít tento kód a přidat do něj nějaké logování:

  Konkrétně uděláme dvě věci:

  1. Řekneme Eliotu, kam má vypisovat zprávy protokolu (v tomto případě do souboru s názvem „out.log“).
  2. Ozdobíme funkce pomocí dekorátoru @log_call.Ten zaznamená skutečnost, že byla funkce zavolána, její argumenty a návratovou hodnotu (nebo vyvolanou výjimku).

  Eliot má další, jemnější API, ale pro demonstraci výhod logování @log_call postačí.

  Výstup programu Eliot

  Po spuštění programu se můžeme podívat na protokoly pomocí nástroje eliot-tree:

  Všimněte si, že podobně jako u Pyinstrumentu se díváme na strom akcí.Výstup jsem trochu zjednodušil – původně proto, aby se vešel na slajd, který jsem použil v přednáškové verzi tohoto článku – ale i v prozaickém článku nám umožňuje soustředit se na výkonnostní aspekt.

  V Eliotu má každá akce začátek a konec a může spouštět další akce – proto ten výsledný strom.Protože víme, kdy každá zaznamenaná akce začíná a končí, víme také, jak dlouho trvala.

  V tomto případě se každá akce mapuje jedna ku jedné s voláním funkce. a jsou zde některé rozdíly oproti výstupu Pyinstrumentu:

  1. Místo spojení více volání funkcí vidíte každé jednotlivé volání zvlášť.
  2. Vidíte argumenty a návratový výsledek každého volání.
  3. Vidíte uplynulý čas wallclock každé akce.

  Například vidíte, že multiplysum() trvalo 10 sekund, ale naprostá většina času byla strávena v multiply(), se vstupy 3 a 4.

Například multiplysum() trvalo 10 sekund.Okamžitě tedy víte, že pro optimalizaci výkonu se chcete zaměřit na multiply(), a máte nějaké počáteční vstupy (3 a 4), se kterými si můžete pohrát.

Omezení logování

Logování samo o sobě jako zdroj informací o výkonu nestačí.

Za prvé, informace získáte pouze z kódu, kam jste explicitně přidali volání logování.Profiler může běžet na libovolném kusu kódu bez předchozí přípravy, ale s logováním musíte udělat nějakou práci předem.

Pokud jste nepřidali logovací kód, nezískáte žádné informace.

Eliot to trochu zlepšuje, protože struktura stromu akcí vám dává určitou představu o tom, kde byl stráven čas, ale stále to není dostatečné, pokud je logování příliš řídké.

druhé, logování nemůžete přidat všude, protože to zpomalí váš program. logování není levné – má vyšší režii než cProfile. takže ho musíte přidávat uvážlivě, v klíčových bodech, kde maximalizuje informace, které poskytuje, aniž by to mělo dopad na výkon.

Výběr správných nástrojů

Kdy byste tedy měli jednotlivé nástroje používat?

Vždy přidejte logování

Každý netriviální program pravděpodobně potřebuje nějaké logování, už jen proto, abyste zachytili chyby a omyly. a pokud už logování přidáváte, můžete si dát tu práci, abyste logovali i informace, které potřebujete k ladění výkonu.

Eliot to usnadňuje, protože logování akcí ze své podstaty poskytuje informace o uplynulém čase, ale s trochou práce navíc to můžete udělat s jakoukoli knihovnou pro logování.

Logování vám může pomoci odhalit konkrétní místo, kde je váš program pomalý, a přinejmenším některé vstupy způsobující pomalost, ale často to nestačí.Dalším krokem je tedy použití profileru, a to zejména profileru pro vzorkování, jako je Pyinstrument:

• Má nízkou režii a hlavně nezkresluje výsledky.
• Měří wallclock čas, takže nepředpokládá, že úzkým hrdlem je procesor.
• Vypisuje pouze pomalejší funkce a vynechává nepodstatné rychlé funkce.

Použijete cProfile, pokud potřebujete vlastní nákladovou metriku

Pokud někdy budete potřebovat napsat vlastní profiler, cProfile umožňuje zapojit různé nákladové funkce, což z něj dělá snadný nástroj pro měření neobvyklejších metrik.

Můžete měřit:

• No-CPU, veškerý čas strávený čekáním na události, které se netýkají CPU.
• Počet dobrovolných přepnutí kontextu, tj. počet systémových volání, která trvají dlouho.
• Alokace paměti.
• V širším smyslu jakýkoli čítač, který se zvýší.

TL;DR

Jako dobrý výchozí bod nástrojů pro optimalizaci výkonu doporučuji:

1. Zaznamenávat klíčové vstupy a výstupy a uplynulý čas klíčových akcí pomocí knihovny Eliot nebo jiné knihovny pro záznam.
2. Používejte Pyinstrument – nebo jiný profiler pro vzorkování – jako výchozí profiler.
3. Používejte cProfile, pokud potřebujete vlastní profiler.

Používejte cProfile, pokud potřebujete vlastní profiler.