PEAR - II (Profilování, hledání chyb)

22. 4. 2005 | Pavel Szalbot | Programování | 7984×

Představujeme balíčky pro profilování aplikací a hledání chyb ve zdrojových kódech.

Úvod - problematika

Seznámení s jazykem PHP probíhá různě. Pro někoho může práce s ním být prvním programátorským počinem, pro jiné zase jen další kapitolou. Informace o jazyce ale obě skupiny zpravidla získávají z odborné literatury, případně z online dokumentace. Dokud vyvíjeme relativně jednoduché aplikace, všechno se zdá být v pořádku, PHP plně vyhovuje a vlastně bychom si vystačili i s tím, co PHP nabízí samo o sobě. Jenže snad každý, kdo se zabývá psaním dynamických webových aplikací, bude postaven před úkol vytvořit "něco většího".

Najednou je třeba kontrolovat efektivitu a kvalitu kódu daleko více. Literatura adepty v tomto směru zpravidla nepoučí, přestože příklad složitějších aplikací hojně obsahuje. Jak tedy zjistit efektivitu kódu, když něco nefunguje tak, jak má? Oblíbenou možností je odhadnout, co by mohlo aplikaci brzdit (vždyť to často bývá způsobeno interakcí s databází), zkusit část kódu upravit a oslnit kolegy řešením. Nebo se trápit dále?

V tomto díle si představíme techniky, jak identifikovat "úzká hrdla" v aplikacích psaných v PHP, a přestože je seriál věnován PEARu, zmíním se i o nástroji ab, který je dodáván spolu s webovým serverem Apache.

Benchmark

Základním způsobem, jak testovat výkon různých částí kódu, je měřit čas, který byl zapotřebí k jejich vykonání. Zjistit to můžeme například voláním funkce microtime() před a po dokončení zvoleného úseku a následným odečtením získaných hodnot. Kód ovšem obvykle nebývá přímočarý, obsahuje různá větvení (smyčky, volání funkcí, podmínky), a dal by se tak v podstatě rozdělit na menší bloky či sekce, které by nás také mohly zajímat (problém by mohl být právě v nich).

Repositář PEARu obsahuje balíček s názvem Benchmark, který nám s analýzou kódu pomůže. Tvoří ho tři třídy, jmenovitě Benchmark_Timer, Benchmark_Iterate a Benchmark_Profiler, jejichž názvy napovídají, k čemu se dají použít.

Benchmark_Timer

Použití třídy Benchmark_Timer si vysvětlíme na velmi jednoduchém příkladu.

<?php
	require_once('Benchmark/Timer.php');

	function my_sleep() {
		global $timer;
		$timer->setMarker('funkce my_sleep');  // značka
		sleep(1);
	}

	$timer = new Benchmark_Timer();
	$timer->start();	// začínáme měřit
	sleep(2);
	my_sleep();
	$timer->stop();	// konec měření
	$timer->display();
?>

Na začátku jsme vytvořili objekt třídy Benchmark_Timer a posléze časovač spustili funkcí start(). Pokud chcete začít měřit hned po vytvoření objektu, předejte konstruktoru jako parametr hodnotu TRUE, destruktor pak měření zastaví (stejně jako funkce stop()) a zobrazí výsledky. Skript jsme nechali odpočinout (sleep()) a následně zavolali funkci my_sleep(). Ta používá metodu třídy setMarker(), která vytvoří "mezičas" zobrazovaný ve výsledcích. Díky mezičasům můžeme měřit dobu výpočtu různých bloků. Výpis tohoto programu u mě vypadá takto (spuštěno v CLI verzi PHP):

-----------------------------------------------------------------------
marker              time index            ex time               perct
-----------------------------------------------------------------------
Start               1113649899.69254300   -                       0.00%
-----------------------------------------------------------------------
znacka_1            1113649901.69398800   2.001445               66.64%
-----------------------------------------------------------------------
funkce my_sleep     1113649901.69410400   0.000116                0.00%
-----------------------------------------------------------------------
Stop                1113649902.69575700   1.001653               33.35%
-----------------------------------------------------------------------
total               -                     3.003214              100.00%
-----------------------------------------------------------------------

Jak vidíte, u každého mezičasu je uveden unixový čas průchodu, čas, který uplynul od posledního mezičasu a procentuální vyjádření náročnosti úseku. Třída bohužel neobsahuje metodu, která výsledky zobrazí setříděny podle jiného kritéria než podle času, nicméně zdrojový kód je přehledný a jednoduchý a neměli byste mít problém napsat vlastní funkci, která vám vlastní třídění umožní (použitý objektový model PHP 4 bez přístupových identifikátorů je v tomto případě výhodou).

Benchmark_Iterate

Benchmark_Iterate vznikla z třídy Benchmark_Timer děděním a najdete ji v souboru Benchmark/Iterate.php. Umožňuje nám oproti Benchmark_Timer navíc několikrát spustit a analyzovat vybranou funkci a to díky metodě run(). Jako parametr jí předáte počet volání, název funkce, která se má volat, a nakonec její parametry. Volání vypadá např. takto:

$timer->run(10, 'my_function', 3, 'parametr2', array(1, 2, 4));

Samozřejmě můžete volat také metody tříd. Druhý parametr pak může být buď 'objekt->funkce' nebo 'třída::funkce'. Výsledky zobrazíte stejně jako v rodičovské třídě funkcí display().

Benchmark_Profiler

Pro názornost si znovu ukážeme jednoduchý kus kódu:

<?php
	require_once('Benchmark/Profiler.php');

	function my_func() {
        	global $timer;
	        $timer->enterSection('my_func');
		sleep(1);
	        $timer->leaveSection('my_func');
	}
	$timer = new Benchmark_Profiler(TRUE);
	my_func();
?>

Tentokrát jsme při vytváření instance předali konstruktoru zmiňovanou hodnotu TRUE, takže jsme nemuseli volat funkce start(), stop() a display(), které Benchmark_Profiler definuje, přestože není odvozená od žádné z předchozích tříd. Funkce enterSection($name) a leaveSection($name) vytvoří v kódu pojmenovanou sekci, která je sledována, a čas v ní strávený je zobrazen ve výsledcích. Sekce mohou obsahovat další podsekce, ty se však nesmí křížit (jako první musí být ukončena ta sekce, která byla otevřena jako poslední). Výsledky kromě časových údajů obsahují také počet iterací všech navštívených sekci.

Výhodou balíčku Benchmark je především jednoduchost zmíněných tříd a možnost využití i v rámci webhostingu. Nabízené možnosti ovšem nejsou příliš široké. Chybí funkce jako zobrazení stromu volání nebo filtrování. Největší slabinou však bude omezenost použití, protože profilování aplikace vyžaduje zásahy do zdrojových kódu, což vám nemusí vždy vyhovovat. Podíváme se proto na balíček, který je součásti repositáře PECL.

APD

APD (Advanced PHP Debugger) je rozšíření Zendu enginu, které slouží k profilování aplikací napsaných v PHP. Poskytuje daleko více možností než třídy z balíčku Benchmark a dovolím si říct, že je to nejlepší open source nástroj svého druhu pro PHP. Pojďme si tedy říct, jak jej nainstalovat, a podívejme se, co všechno umí.

Balíček nejprve nainstalujte klasickým způsobem (pear install apd) a poté do php.ini přidejte následující řádky:

zend_extension = /cesta/k/apd/apd.so

apd.dumpdir = /kam/ukladat/vysledky/

Rozšíření tak bude nahráno do paměti a bude použitelné v každém skriptu. Do adresáře určeného volbou apd.dumpdir se budou ukládat výsledky profilování, a PHP (Apache) tam proto musí mít právo zapisovat. U webhostingu to obvykle není možné a vlastně nevím o žádném, který by APD měl nainstalováno, nicméně výsledky z vývojového prostředí by měly být násobkem těch z produkčního prostředí, takže informace o efektivitě jsou dobře použitelné nezávisle na výkonu stroje.

APD se používá velmi snadno. Do bodu, od kterého chcete začít profilovat, vložte volání funkce apd_set_pprof_trace(), čímž se APD v daném místě aktivuje. Výsledky se po ukončení skriptu uloží do souboru pprof.<pid>.<ext> ve zvoleném adresáři (apd.dumpdir) a můžete je zobrazit programem pprofp (PHP skript), který byl nainstalován spolu s APD. Mimo pprofp je k dispozici i skript pprof2calltree, který převede výsledky z vybraného souboru do formátu používaného programem KCacheGrind, který určitě stojí za vyzkoušení.

Syntax skriptu pprofp vypadá následovně:

pprofp <přepínače> <soubor s profilem>

Volby pro třídění:
  -a	třídit dle názvů funkcí
  -l	třídit dle počtu volání
  -r	třídit dle času stráveného v tělech funkcí (real time)
  -R	třídit dle času stráveného v tělech funkcí (real time)
	(započítává se i čas volaných funkcí)
  -s	jako -r, ale dle systémového času (system time)
  -S	jako -R, ale dle systémového času (system time)
  -u	jako -r, ale dle uživatelského času (user time)
  -U	jako -R, ale dle uživatelského času (user time)
  -v	třídit dle průměrného času stráveného v tělech funkcí
  -z	třídit dle uživatelského + systémového času

Volby zobrazení:
  -c	zobrazí čas strávený ve funkcích (real time) vedle stromu volání
  -m	zobrazí umístění souborů
  -i	potlačí volání funkcí PHP
  -O n	určuje maximální počet zobrazených funkcí
  -t	zobrazí zabalený strom volání funkcí
  -T	zobrazí rozbalený strom volání funkcí

Jak vidíte, možností máme skutečně více a hlavně můžeme profilování zrušit zakomentováním jediného řádku v souboru se zdrojovým kódem, což je pružnější než používání tříd z balíčku Benchmark. Ukázkový výpis pprofp by mohl vypadat například takto (upravil jsem ho tak, aby se vešel na stránku):

[pavel@pandora bin]$ pprofp -r /tmp/traces/pprof.05969.12

Trace for /var/www/metalshop/client/cz/list_products.php
Total Elapsed Time = 0.45
Total System Time  = 0.03
Total User Time    = 0.20


         Real         User        System             secs/    cumm
%Time (excl/cumm) (excl/cumm) (excl/cumm) Calls  call  s/call  Memory Usage Name
--------------------------------------------------------------------------------
27.2 0.12 0.12  0.00 0.00  0.00 0.00     7  0.0175   0.0175     0 pg_query
12.4 0.06 0.06  0.00 0.00  0.00 0.00     1  0.0563   0.0563     0 pg_connect
8.1 0.04 0.04  0.02 0.02  0.00 0.00   858  0.0000   0.0000     0 is_array
7.0 0.03 0.10  0.02 0.09  0.00 0.01    14  0.0023   0.0075     0 require_once
6.8 0.03 0.03  0.03 0.03  0.00 0.00   543  0.0001   0.0001   0 htmlspecialchars
3.4 0.02 0.02  0.01 0.01  0.00 0.00   220  0.0001   0.0001     0 array_keys
3.1 0.01 0.01  0.01 0.01  0.00 0.00     3  0.0047   0.0047     0 defined
2.6 0.01 0.01  0.01 0.01  0.00 0.00   239  0.0000   0.0000     0 explode
2.6 0.01 0.01  0.00 0.00  0.00 0.00   262  0.0000   0.0000     0 count
2.5 0.01 0.01  0.01 0.01  0.00 0.00   366  0.0000   0.0000     0 is_resource
2.0 0.01 0.01  0.01 0.01  0.00 0.00    23  0.0004   0.0004     0 preg_match
1.8 0.01 0.01  0.00 0.00  0.00 0.00     4  0.0020   0.0020     0 include_once
1.5 0.01 0.01  0.01 0.01  0.00 0.00   348  0.0000   0.0000     0 pg_fetch_assoc
1.4 0.01 0.01  0.00 0.00  0.00 0.00     9  0.0007   0.0007     0 array_merge
1.3 0.01 0.01  0.00 0.00  0.00 0.00    38  0.0001   0.0001     0 file_exists
1.2 0.01 0.32  0.00 0.21  0.00 0.03    19  0.0003   0.0167     0 include

ab, httperf

Přestože tyto dva nástroje nejsou ani součástí PEARu a vlastně ani přímo nesouvisí s PHP, chtěl bych se o nich alespoň krátce zmínit. Jejich primárním úkolem je měření výkonu webového serveru Apache. Získáte tak přehled o tom, kolik požadavků je server schopen vyřídit za určitý čas. Můžete také simulovat různá zatížení serveru a sledovat reakce vaší aplikace.

Ab je součástí standardní distribuce Apache, takže jej pravděpodobně najdete v adresáři, kde máte nainstalovaného httpd démona. Stejně jako httperf dovoluje mj. zadat celkový počet požadavků, počet souběžných požadavků, poslat POST request, nastavit cookies atd. Httperf za ab v ničem nezaostává, naopak poskytuje více možností, jak generovat HTTP požadavky. Jejich hlubší popis je ovšem nad rámec tohoto článku.

Závěr

Ukázali jsme si nástroje, které vám mohou pomoci s odhalením chyb, které brzdí vaše PHP aplikace. Schválně jsem se vyhnul umělým příkladům a úryvkům anonymního kódu, které by vás dost možná jen zmátly. Nejlepší způsob, jak odhalit sílu a užitečnost podobných nástrojů, je vyzkoušet si je na reálné aplikaci, které rozumíte. Určitě objevíte její slabá místa a to bylo cílem tohoto článku.