Ladeni vykonu – Piseme si vlastni JVM profiler

Motto:

Zakaznik:”HW by stacil na realtime simulaci utoku USA na Iran, operacni system je ditetem naseho super-admina se snidani ve vousech, databaze vytunena do krasna a slozitosti O(1), aplikaci psal Bloch,Eckel a meli k ruce Becka.”
Tuner: “Aha, tak kde je problem?”
Zakaznik: “Jede to pomalu, proto jste tady.”

Pravidelne se prinachomytnu k projektu, kde to skutecne stoji za to a tamni olgoj chorchoj mi saje veskerou energii a volny cas. Takovymto projektem muze byti napriklad ladeni vykonu nezname a zpravidla velice rozsahle aplikace nebo psani dokumentace. Zustanu u ladeni.

Pravidlo c.1 – Duverujte pouze sami sobe

Verte vlastnim ocim, testum a rozumu. Kazde oci jsou zaostreny trochu jinak (viz. XP – parove programovani).

Pravidlo c.2. – Bavte se s odporniky

Je dobre mit budto okruh znamych, kteri jsou spickami ve svych oblastech (Jipi, Frank, Dagi, Boruvek – java,j2ee, Dlabik – Oracle) nebo si zaplatit inzenyra zodpovedneho za dany produkt (OS, DB nebo treba J2EE server).

Pravidlo c.3. – Pouzivejte tooly pro nalezeni priciny

Pravidlo c.2 vam muze prinest sadu nastroju, ktere jsou vhodne pro danou situaci. Rozhovor probiha vetsinou nasledovne:

Fil:” Dlabiku, porad, jak rychle vypsat statistiky pro tenhle sql dotaz.”
Dlabik:” Lamo, lamo, zkus Toad a nebo tenhle skript.”

Takhle jsem se z predchozi zkusenosti dostal ke dvema v soucasnosti nejlepsim nastrojum na profilovani java a j2ee aplikaci – Optimizeit a JProbe.Pokud delate byt jen trochu vetsi aplikaci, stoji za zvazeni nakup nektereho z nich a zahrnuti vykonnostnich testu do vaseho dev cyklu.Pokud nemate penize, muzete pouzit hprof profiler, ktery je soucasti jdk od verze 1.2.

Vsechny tyhle nastroje jsou krasne, ovsem dost dobre se nedaji pouzit na produkcnim serveru, jelikoz aplikace ztrati 300 – 1000% vykonu (vlastni zkusenost). Jelikoz jsem v mem pripadne potreboval pouze identifikovat metody, ktere konzumovaly nejvice CPU a trvaly nejdele pri danem user requestu, rozhodl jsem se napsat si profiler sam. Java pro tyto ucely poskytuje JVMPI rozhrani, ktere vam umoznuje naprogramovat v C listenery JVM. Udelal jsem tedy listenera na vstup a vystup do metody. Jelikoz je API docela derave, musel jsem se dale zaregistrovat na loadovani trid a drzet (!) si vlastni lookup hastable pro vsechny tridy a jejich metody tak, abych byl schopen vyhledat jmeno invokovane metody. Produktem meho snazeni je dll (filprofiler.dll), ktere se jvm preda nasledujicim prikazem

java -Xrunfilprofiler:exec_time=2000,cpu_time=20 CLASSNAME

exec_time a cpu_time jsou v ms a jejich vyznam je celkem zrejmy.

Takze treba pro

public class Pokus {


  public static void main(String[] args) throws Exception{
           Thread.sleep(5000);

  }
}

to vypise vsechny metody, ktere vzaly CPU vice jak 20ms nebo trvaly dele jak 2s

java -Xrunfilprofiler:exec_time=2000,cpu_time=20 Pokus
Exec time: 2000
CPU time: 20
<filprof> started
<filprof>CPU time of java.security.AccessController.doPrivileged() 20
<filprof>CPU time of java.net.URLClassLoader.findClass() 20
<filprof>CPU time of java.lang.ClassLoader.loadClass() 20
<filprof>CPU time of java.lang.ClassLoader.loadClass() 30
<filprof>CPU time of sun.misc.Launcher$AppClassLoader.loadClass() 30
<filprof>CPU time of java.lang.ClassLoader.loadClass() 30
<filprof>CPU time of java.lang.ClassLoader.loadClassInternal() 30
<filprof>Exec time of java.lang.Thread.sleep() 5007
<filprof>Exec time of Pokus.main() 5007

Vyhodou prime prace s JVMPI je to, ze si timto zpusobem nasekate profilery na co potrebujete a zbytecne neberete vice vykonu nez je nezbytne nutne.

Veskere zdrojaky najdete zde src a zkompilovany dll tady