Open source Java profiler

Java

Mivel open source project, engedjétek meg az önreklámot:

http://code.google.com/p/oktech-profiler/

Update (2009-10-02): Megérkezett az 1.1-es verzió, instrumentáció profilerrel, jóval több dokumentációval és néhány kisebb funkcióval.
Nyugodtan jöhetnek kérdések, kérések, visszajelzések, ezek segítik a fejlesztés fókuszálását a későbbiekben.

  • 2205 megtekintés

( asch v | 2009. 08. 18., k – 10:32 )

Érdekes ez a mintavételezős ötlet a "szokásos" instrumentálás helyett. Legközelebb ha "profilozni" kell kipróbálom.

Köszi

Vannak előnyei és hátrányai, mindenképpen dokumentáljuk majd ezeket részletesen is. Át kell alakítani a "mindset"-et az emberekben: a "szoksásos" profiling sem pontos eredményeket ad, ez sem, a kérdés az overhead, az elérendő pontosság, valamint a statisztikai eredmények értelmezhetősége.

Nekem az nem tetszett az instrumentálással, hogy mikor már 10000+ metódust kellett instrumentálni, akkor kezdett sok lenni a metódusonkénti kb. 4ms overhead idő. Persze ezt lehet gyorsítani cache-eléssel meg mindenféle trükkel, de ehhez képest lényegesen kisebb overheadet jelent a mintavételezés.

Cserebe joval pontatlanabb is. Esetleg csomo fgv kimarad belole. Esetleg tok hibas kovetkeztetes adodik belole (mi a szuk keresztmetszet). Vagy pl nem megismetelheto meresi eredmenyeket ad.

Azert egy rendes profiling rendes es megismetelheto eredmenyt szokott adni ld. pl. purify, ami CPU ciklusban adja az idoket.

Mivel van egy olyan változatunk, ami instrumentation-nel számolja a CPU időket, ismerem azt az oldalt is. Úgy mondanám, hogy máshogyan torzít.

Tökeletes CPU számláló nincs, mert a stacktrace pozíció hozzárendelése az aktuális CPU időhöz, ennek kiírása egy queue-ba, ami majd fel lesz dolgozva, az is CPU idő, ami ráadásul nem is elválasztható az adott száltól, vagy ha elválasszák, akkor is belekerül néhány CPU ciklusba a feldolgozás, és a szálak közötti szinkronizáció fogja torzítani az eredményt. Ez 100 ms-os időknél persze mindegy, 10-20 ns-nél viszont már ez is jelentős torzítással jár, ami ráadásul halmozódik, és az okozott zaj nem is nagyon csökkenthető több mintavétellel.

Majd dokumentálok egypár tapasztalatot, amikor tényleg csak annyit csináltunk, hogy dinamikus bytecode instrumentációval a metódus elején egy időmérés a CPU időre, egy finally block-ban a végére, ezeket berakni egy queue-ba amit nem is az a szál dolgoz fel, és mindenféle szinkronizálás optimalizációval lehet elérni ugyan jó eredményeket, de attól még torz. Annyi az előnye, hogy jobban elhiszed a számszerű eredményeket, és ez egyszálú programra tényleg közel jó is. Mi ott kezdtünk el elgondolkodni más alternatíván, amikor egyszerre futott vagy 10 aktív szál egy adatstrukturán, és a profiler is torzította az egészet, nem derültek ki pontosan a szinkronizációs várakozási pontok (mert volt belőlük jó sok). Most szépen kijönnek, az idők _arányai_ pedig hasonlóak mint a korábbi mérések, szóval becslésnek így sem rossz...

Nem egeszen ertem mire gondolsz a queue-kal, de a purify cpu ciklust mer kozvetlenul es ez megismetelhetoen ugyanazt adja mindig (hasznaltam). Semmi fuggosege nincs a valos futasi idokhoz (pl vmi megszakitja a fgv belsejeben). Innen mar csak az az erdekes hanyszor hivodnak a fgv-ek es minden szamolhato beloluk.

Esetleg arra gondolhatsz ha jol sejtem hogy azt is meritek ha vmi megszakitja a fgv-t belul ? Nem tudom miert valasztottatok ezt celkent, biztos megvan az oka.

A tapasztalatokra kivancsi vagyok ! Anno nagyon hasznos volt a purify, de nem volt olcso :-)

amire gondolok:
void a() { b(); }
void b() { c(); }
void c() { d(); }
...

Namost amikor méred a c() idejét, akkor az elején meg a végén megméred az időt, és ezt eltárolod valahol. Az eltárolás az tipikusan belemegy egy queue-ba, de ez lényegtelen, ami fontos, hogy valahova ki kell rakni.
Amikor a b()-t méred, akkor már nem csak a c()-t méred, hanem a c() elején és végén lévő időmérő kódokat is (ugye ugyanaz a thread volt, ugyanaz a thread cpu kattogott közben), plussz az eltároló kódot.
Amikor az a()-t méred, akkor a c() és b() időmérő és eltároló kódjait is beleméred az a()-ba, stb.. Minél több metódust mérsz, annál több az overhead mérése is. És mi csináltunk olyant, hogy mértük azt az időt is, amit a profiler elszöszmötöl magában (CPU és system clock időt is), de mindig marad néhány utasítás, ami mindenképpen muszáj hogy ugyanabban a threadben maradjon.

Ebből a szempontból legalább ismételhető a hiba, de mindig jelen van, és minél kisebbek az idők, annál torzabb az eredmény.

Emiatt egyébként a Java HotSpot sem tud ugyanúgy optimalizálni, merthogy más a kód, nem működnek ugyanúgy a method inline-ok, szóval újra ismételhetően, de újra kicsit a valóságtól eltérő eredményt kapsz az instrumentációval.

( KGer | 2009. 08. 18., k – 12:16 )

En beraktam konyvjelzobe, azt hiszem kelleni fog

Pedig nagyjából a wiki oldalra leírtam ugyanazt amit itt, kicsit bővebben, részletezve az okokat, de nézzük még egyszer tömören.

Tehát ami eredetileg egy ilyen "összevont" (elég hülye, de nem tudom jobban szemlélteni) pszeudókód volt: 


a() {
   b() {
      c() {
      }
   }
}

Abból ez lesz: 


a() {
   startProfileA();
   b() {
      startProfileB();
      c() {
         startProfileC();
         // ...
         endProfileC();
      }
      endProfileB();
   }
   endProfileA();
}

Ha meggebedsz sem tudod ezeket az extra metódushívásokat kiiktatni az adott szálra vonatkozó CPU ciklusból, mert ha pl. metódushívás helyett csak átdobod az információt egy adatstrukturának, akkor is elfogyasztasz néhány CPU ciklust. Ha meg egyre több dolog ágyazódik egymásba, akkor egyre jobban akkumulálódnak ezek a pontatlansági idők... de ezt már leírtam egyszer. Még az abszolút ideálisnak és lockmentesnek tűnő, threadlocal láncolt listához hozzáadással is elmegy néhány ciklus (nem beszélve a memória-foglalásról).

Ha mégis ismersz módszert a kiiktatásra, kérlek írd le, mert tényleg megoldhat egy problémakört, de addig ez a torzítás ott lesz, csak szisztematikusan mindig, így nem feltűnő.

Továbbá ha megnézed a blog bejegyzést, akkor láthatod, hogy külön kezelem a system time-ot és a cpu time-ot. Ha megnézed a profiler forráskódját, abban is kétféle idő van mérve: system time és cpu time (függetlenül attól, hogy a sampling pontatlan, ezek az információk azért hasznosan kezelhetőek). Mindkettőnek megvan a maga szerepe és információja, és mindkettőre torzít az instrumentation profiler.

Egy modszer pl hogy tudod hogy az adott fgvben adott utasitas konkretan hany CPU ciklust emeszt fel, azaz azt kell nyomonkovetni melyik blokk hanyszor futott le a kodban. Nem az ido az erdekes hanem hogy melyik kod fut. Tok mindegy, hogy hol gyujtod az adatokat vagy mennyi kodot raksz instrumentalassal bele, azok persze elvisznek idot, azok nem jelennek meg a meresben. Maskeppen fogalmazva: nem a fuggveny a legkisebb instrumentalt egyseg hanem a kodblokk.

Peldanak azert irtam a purifyt mert azt hasznaltam, nem kicsi nevrol van szo es minden futasnal centire azonos CPU ciklus eredmenyt ad, nem pedig "similar"-t mint a linkben emlitve van. Gondolom pont azert mert nem az idoket meri.

Ne erts felre, nem azt mondom ez vagy az jobb, mikor melyik a jobb. Vannak rendszerek ahol a kodtomeg merete vagy a valos idohoz kozeli mukodes miatt nem johet szoba instrumentalas - de ezzel te is tisztaban vagy, nem ragozom :o)

Mint mondtam nem meglepő a purify és hasonló (többek között a mi első generációs) instrumentációs profilerek ismételhető eredménye, a torzítás konzisztens hibát ad, hiszen beleépül a kódba.
Az, hogy kódblokkról vagy éppen függvényről beszélünk, lényegtelen, a metódus azért megszokott, mert egyszerűbben azonosítható mint egy tetszőleges kódblokk, de a mechanizmusuk ugyanaz. Ha most azt mondom, hogy a többszörösen beágyazott kódblokkokra ugyanúgy jelentkezik a torzítás, akkor még mindig ugyanarról beszélek.

"Egy modszer pl hogy tudod hogy az adott fgvben adott utasitas konkretan hany CPU ciklust emeszt fel, azaz azt kell nyomonkovetni melyik blokk hanyszor futott le a kodban. Nem az ido az erdekes hanem hogy melyik kod fut. Tok mindegy, hogy hol gyujtod az adatokat vagy mennyi kodot raksz instrumentalassal bele, azok persze elvisznek idot, azok nem jelennek meg a meresben."

Értem amit mondasz, el is tudom képzelni, hogy valaki először leméri a profiler kód CPU ciklus-igényét, majd mindig szorgalmasan levonja (és persze úgy méri le, hogy egy ilyen levonás-eltárolás művelet is benne legyen). Még azt is el tudom képzelni, hogy ez kezelhető adatstrukturában nem emészt fel lényegesen sok memóriát (ezzel befolyásolva pl. a GC-t). Azonban mindaddig, amíg bármit beleszemetelünk a Java bytecode-ba, másképpen fog viselkedni a HotSpot:
1. nem fog beágyazni bizonyos metódusokat, néha lassabbnak fog mutatni bizonyos művelteket, mint amilyenek valójában
2. nincs semmi garancia arra, hogy önmagában lemért profiler CPU overhead az más helyeken is pont ugyanannyi (lásd első pont)
3. ráadásul elmegy egy csomó valós idő arra, hogy a cpu időt nagyon pontosan karban tartsuk.

Szerintem még így is torzított (csak éppen máshogyan torzított) eredményt kapunk. Ez egyetlen nem-torzító módszer a CPU-ciklus számláló pontos megfigyelésére, ha "virtuális gépben" futtatod a kódot, és minden egyes CPU lépésnél meg tudod nézni, hogy hol tart a Java kód, és ha már lezárult a valami, akkor kiolvasva a CPU számlálót már tökéletes az eredményed. Nem kell részleteznem, hogy ez miért nem elterjed módszer, ugye? :) Az abszolút pontosságért cserébe sokkal komplexebb profiler kell, valamint fel kell adni azt, hogy értelmes időben kezelhető és megfigyelhető a program.

Amúgy meg híve vagyok a részleges bizonytalanságnak, pl. ami itt van megfogalmazva:
http://www.infoq.com/presentations/programming-cloud-gregor-hohpe

Debuggolni sem O2-vel forditott kodot erdemes mert nem azt fogod latni amire kivancsi vagy. Ha egy dinamikusan valtozo byte kodrol van szo amit merni akarsz, akkor ertelemszeruen nem fogod magad szivatni: vagy fixen letiltod a hotspotot es mersz, mert az a cel; vagy kicsikarod a hotspotbol hogy egy adott konfiggal (amit pl elozetes futasbol nyersz ki) dolgozzon, azaz konstans korulmenyeket teremtesz, de ez mar a vegso kin.

A meresek celja altalaban az, hogy a TE kodod jobb legyen, MAJD ha mar minden szuk keresztmetszet kinyirva, akkor jon a hotspot ami tovabb javit a sebessegen. A hotspot es a profiling celja sztem messze nem ugyanaz. Teljesen mas teruleteket celoznak meg. Persze lehet bonyolitani az eletet, de minek. Ennyi erovel mindig mas inputot is tolhatnal a programnak meresek kozott.

Apro comment:
Nem lemerni kell a kodblokk idejet, tudni kell azt. Egy adott kodrol el tudod donteni mennyi CPU ciklust igenyel, meres nelkul is. Ez a lenyeg. Emiatt nincs overhead a mert eredmenyben. Semmi szukseg CPU idoket pontosan tartani vagy idot merni akarhol. Fuggvenyben ezt nem tudod megtenni a ciklusok es feltetelek miatt, de kodblokkokban mar igen.

A reszleges bizonytalansagot megnezem, kivancsi vagyok ra :-)

"Nem lemerni kell a kodblokk idejet, tudni kell azt. Egy adott kodrol el tudod donteni mennyi CPU ciklust igenyel, meres nelkul is. Ez a lenyeg."

Ez az elmélet ugye. Elméletben szépen látod a statitikus kódot, szépen sorjázik egymás után. Minden utasításra meg tudod mondani hogy mennyi időt vesz igénybe. Egy monolitikus, egyszáló, semmivel nem kommunikáló alkalmazásnál ez tökéletesen megfelel a gyakorlatnak.

A profiling lényege meg az, hogy nem csak elméletben tudod, hanem megméred, éles körülmények között, ahogyan a végső alkalmazás is felépül és futni fog. Futása közben ugyanis kiderül az is, hogy egy blokk pl. várakozik akár egy mutexre, mert egy másik szál lassan szabadítja fel, vagy akár egy database connection-re a pool-ból, vagy hogy egy adott blokk túl sokszor példányosít objektumokat és a GC sokszor beüt. Egy sokszálú, disk IO-t lockokkal végző, vagy pl. adatbázissal is kommunikáló alkalmazásnál pl. teljesen hidegen hagy, hogy elméletben az adott utasítás 40 CPU ciklus, ha a szerencsétlen poolom miatt 25 szálon már kijön, hogy kicsi a poolom mérete, ami lassúvá teszi az egészet.

"A meresek celja altalaban az, hogy a TE kodod jobb legyen, MAJD ha mar minden szuk keresztmetszet kinyirva, akkor jon a hotspot ami tovabb javit a sebessegen. A hotspot es a profiling celja sztem messze nem ugyanaz. Teljesen mas teruleteket celoznak meg."

Ezzel egyetértek. De ha egyszer nem azt méred, ami később futni fog, akkor hiába a fene nagy pontosság, nem? Akkor annyi erővel egy kisebb pontosságú, gyorsabb eredmény is megteszi, hiszen úgyis csak nagyjából kell az, hogy mi a lassú...

"Az abszolút pontosságért cserébe sokkal komplexebb profiler kell, valamint fel kell adni azt, hogy értelmes időben kezelhető és megfigyelhető a program"

Igen. Komplexebb kell. Es ?

Tudom hogy a mintaveteles profilerek pont ezert nepszeruek ugymond (eleg jo az egyensuly az ar ertek arany vagy fejlesztei ido ertek aranyban), de ez nem jelenti azt hogy mindig a legolcsobb a jo, vagy eleg jo.

Minel kozelebb vagy a vashoz, annal kritikusabb a megbizhato meres. Tudnek peldakat mondani ahol egy egy if-ert is komoly verekedes megy, mert igenis szamit a kodban. Ilyen kornyezetben pedig nem engedheto meg a majdnem jo meres sem, kulonben roppant konnyu elcsuszni.

"Minel kozelebb vagy a vashoz, annal kritikusabb a megbizhato meres. Tudnek peldakat mondani ahol egy egy if-ert is komoly verekedes megy, mert igenis szamit a kodban. Ilyen kornyezetben pedig nem engedheto meg a majdnem jo meres sem, kulonben roppant konnyu elcsuszni."

De ha egyszer egy-egy if-ért komoly versengés megy, akkor miért nem úgy akarod mérni, ahogy a végén élesben fut? Lehet hogy a te early optimization-öd megöli a HotSpot javítási képességét, csak azért, mert a profilered instrumentációjával a kód már másképpen fut, más mérési adatot ad vissza, és te emiatt teljesen felrúgtad az amúgy jó kódodat. Másképpen megfogalmazva végső soron a profiler instrumentációjával módosított kódra optimalizálsz, ahelyett, hogy anélkül optimalizálnál.

Én látom a helyét az instrumentation profilernek, de azzal, hogy hardverközeli dolgokra hegyezed ki, pont hogy nem lesz tisztább (= bármilyen torzítástól mentes) a futási eredmény, pont hogy a kis időtartományokban kritikus a jelenléte. Vagy a hotspot kavar be, vagy annak a hiánya, semmiképpen sem ugyanaz mint a végső kód, és megjelenik itt is egy kis bizonytalanság, ami ráadásul ki sem mutatható :)

Nah, csak ide irok mert kezdunk szetesni es ugy erzem kezded kicsit kavarni a dolgokat :-)

"Ez az elmélet ugye. Elméletben szépen látod a statitikus kódot, szépen sorjázik egymás után. Minden utasításra meg tudod mondani hogy mennyi időt vesz igénybe. Egy monolitikus, egyszáló, semmivel nem kommunikáló alkalmazásnál ez tökéletesen megfelel a gyakorlatnak."
Azt mondom, hogy tudod mennyi a blokkok futasi ideje ciklusban es a meres arra iranyul hogy adott blokk hanyszor fut (sorrendiseget figyelembe veve). Ez 100%-osan jo eredmenyt ad, overhead nelkul. Az az erv hogy mas inputra maskeppen reagal, az minden meresre igaz es semmi koze ahhoz hogy mivel mered, nem is ertem miert merult fel egyaltalan. Szoval akarmire hasznalhatod, nem csak monolitikus kodra ami ucsorog a sarokban.

Java instrumentalas: elmeletben meg lehet csinalni, semmivel nem masabb mint maga az object kod (ebbol a szempontbol). Nem latom miert ne letezhetne ilyen eszkoz.

Ne kavarjuk a valos ideju rendszereket a hotspottal. A kettonek nem sok koze egymashoz. A pelda arrol szolt hogy van helyzet amikor a megbizhato meres alapkovetelmeny nem pedig luxus. Senkinek nem fog eszebe jutni egy valtozo bytekodos reteget egy valos ideju cucc ala pakolni, elhiheted.

"Ezzel egyetértek. De ha egyszer nem azt méred, ami később futni fog, akkor hiába a fene nagy pontosság, nem? Akkor annyi erővel egy kisebb pontosságú, gyorsabb eredmény is megteszi, hiszen úgyis csak nagyjából kell az, hogy mi a lassú.."
Minden meres azzal indul, hogy eldontod mi a use case amit mersz. Nem fogod tudni az osszes input kombinaciot vegignezni. Ez kabe minden tesztelesre igy mukodik. A megbizhatosaga a meresnek viszont igenis szamit.

"De ha egyszer egy-egy if-ért komoly versengés megy, akkor miért nem úgy akarod mérni, ahogy a végén élesben fut? Lehet hogy a te early optimization-öd megöli a HotSpot javítási képességét, csak azért, mert a profilered instrumentációjával a kód már másképpen fut, más mérési adatot ad vissza, és te emiatt teljesen felrúgtad az amúgy jó kódodat. Másképpen megfogalmazva végső soron a profiler instrumentációjával módosított kódra optimalizálsz, ahelyett, hogy anélkül optimalizálnál."
Nem hiszem hogy van epeszu fejlesztes ahol a hotspot igenyei alapjan fejlesztenek. Pont azert atlatszo reteg, hogy ne is lasd mi a hatasa a kododnak az o mukodesere, sot, tovabbmegyek nem is SZABAD latnod vagy szamitani ra. Ettol absztrakt reteg, pont ugy ahogy tojsz arra magasbol mibol lesz a gepi kod a vegen. Ennyi erovel foglalkozhatnal a disk driverrel, a forditoval, a kernel utemezesevel, etc. Ugye nem teszed ? A hotspot szep feature, de nem a profiling egy szinttel feljebb letezik mint a hotspot. Ergo profiling mereseknel (hacsak nem azt mered mit nyersz vele) semmi keresnivaloja. Szerintem.

"Másképpen megfogalmazva végső soron a profiler instrumentációjával módosított kódra optimalizálsz, ahelyett, hogy anélkül optimalizálnál."
Ezt nem ertem. A ket kod ugyanaz. Amig a use case hatarait be tudod tartani, a kod ugyanaz ami fut. Ha pedig nem tudod betartani, a modszer eleve ertelmetlen mert nem azt mered amit akarsz. Mekkora rendszerre gondoltal ? Full system test ?

"Én látom a helyét az instrumentation profilernek, de azzal, hogy hardverközeli dolgokra hegyezed ki, pont hogy nem lesz tisztább (= bármilyen torzítástól mentes) a futási eredmény, pont hogy a kis időtartományokban kritikus a jelenléte. Vagy a hotspot kavar be, vagy annak a hiánya, semmiképpen sem ugyanaz mint a végső kód, és megjelenik itt is egy kis bizonytalanság, ami ráadásul ki sem mutatható :)"
Attol fugg ugyebar milyen az az instrumentation profiler. Ha nincs overhead a riportban, akkor az egesz amit irsz ervenyet veszti. Vagy azt akarod elmagyarazni hogy a purify nem is mukodik ? Ne mar :-)

A kulcsmondat azt hiszem ez:
"úgyis csak nagyjából kell az, hogy mi a lassú.."
Ezzel nemigen lehet vitatkozni =) De akkor meg minek szoptatok az instrumentalassal ? :-D

Kozben megneztem az eloadas anyagot (ppt-t nem a videot), hat mit mondjak semmi ujat nem mondott. Az elosztott rendszerekben ez a tema lenyegeben par tiz eve ismert eleg jol.

Megpróbálok tömöríteni (sikertelenül), mert sokfelé ágazunk, miközben az alapproblémát abban látom, hogy te beágyazott, valós idejű rendszerekre koncentrálsz, míg én Java szerver oldali, tipikusan webes, sokszálas, sokfelhasználós alkalmazásokra. Az előbbinél valószínűleg ismert az a konkrét blokk, ami sok időt elvesz, utóbbinál a kismillió komponens miatt tipikusan nincs kiindulási alap, hogy hol lassú, kell egy mérés hogy el lehessen indulni. Egy adott teljesítményt nyújtó if-et kioptimalizálni nem kell hagyományos értelembe vette profiler, sokkal inkább egy ultrapontos benchmark, míg egy teljesen ismeretlen karakterisztikával rendelkező alkalmazásról kellenek profile-információk, ezt szerzi be a profiler. Lásd még:
http://en.wikipedia.org/wiki/Profiler_(computer_science)
http://en.wikipedia.org/wiki/Benchmark_(computing)

"Mekkora rendszerre gondoltal? Full system test?".
Igen, a profilernek az a feladata, hogy a teljes rendszerről adjon képet, nem csak egy for ciklusról. Az nem profiler feladat, nem is instrumentációs feladat, hanem benchmarking, egy szálon, egy célmetódusra vonatkoztatva. Ott teljesen értelmet nyer az összes általad elmondott érv, ilyen környezetben ezt nem is vitatom.

A legfőbb problémám egyébként az, hogy olyan feltételezésekkel élsz ("tudod mennyi a blokkok futasi ideje ciklusban es a meres arra iranyul hogy adott blokk hanyszor fut", "tudod hogy az adott fgvben adott utasitas konkretan hany CPU ciklust emeszt fel", "nem lemerni kell a kodblokk idejet, tudni kell azt. Egy adott kodrol el tudod donteni mennyi CPU ciklust igenyel, meres nelkul is."), ami után a "profiler" persze hogy nem overhead, persze hogy kiszűrhető, az instrumentáció is csak smafu. De ilyen eseteket nevezzünk inkább benchmarknak, vagy teljesítmény-mérésnek, amelyeknek megvan a helye, de egy full ismeretlen, 4-5 réteggel + 2-3 cache réteggel rendelkező alkalmazásnál, amit egyszerre 10000-en kattintanak egy szerveren, nos ott inkább a profilerre van szükség. És ilyen környezetben nem is az az izgalmas, hogy egy adott metódus mennyi időt vesz igénybe, mert lehet, hogy az esetek 98%-ban lefut 2ns alatt, hanem az, hogy melyik az az execution path, ahol az esetek 2%-ban több mint 5 másodpercig is időzik, ezzel tipikusan egyszerre 200 felhasználónak elveszi a "felhasználói élményt".

Ettől függetlenül, mivel írtam olyan kódrészletet, ami instrumentation profilerrel dolgoz fel code execution path-ra lebontható statisztikákat, tudom, hogy van egy pont, ahol megméred a profiler által okozott overheadet, és ezt el kell tárolni valahol, hogy majd le tudd vonni a végső időből. És mindig van 1-3 utasítás, ami hirtelen kiesik ebből az időből, merthogy ki kell olvasni és el kell tárolni az overhead időt valahogy, valamilyen módon, és ezt az 1-3 utasítást, bár nyilván nem sok idő, nem tartom sem teljesen elhanyagolhatónak, sem teljesen pontosan kiszámíthatónak (különösen Java környezetben), sőt, ahogyan azt már a szisztematikus hiba esetén írtam, ezt akkumulálódónak tartom. Erről csak egy nagyon konkrét ellenpélda bírna meggyőzni, az "elméletileg elképzelhetőnek tartom"-ot én is csak addig tartottam, amikor realizáltam, hogy az a minimálisan 1-2 utasítás _mindenképpen_ ott lesz, és _Java_ alatt nincs más lehetőségem.

Valamint a HotSpot jelentlétét sem különíteném el akkor, ha tudott és ismert dolog, hogy egyszercsak megváltozik miatta a futási karakterisztika. Ha egy metódusbelső sok alkalommal fut le, és a HotSpot miatt tizedére csökken a futási ideje, akkor lehet, hogy nem is azon a kódrészleten kell optimalizálni, hanem egy sokkal kevesebb alkalommal hívott, de összeségében sokkal inkább időrabló kódrészleten. Ha extrém módon félregondolom a logikádat, akkor futtatni sem kellene a kódot, hiszen már a bináris kódból megállapítható minden kódblokk futási ideje, az összes gépi utasítás dokumentált CPU ciklusidővel rendelkezik...

A HotSpot figyelembe vételéhez hasonlóan fontosnak tartom az instrumentation-nek a többszálúságra tett hatását kiemelni. Míg egyszálú esetben végletesen ki tudjuk vonni a profiler overhead nagy részét a képletből, addig többszáló esetben módosulnak olyan fontos paraméterek, mint pl. a szinkronizációs kódblokk hossza, azaz gyakorlatilag az abban eltöltött idő, valamint ezáltal a többi szál várakozással eltöltött ideje. Egy másik termékünknél ez pl. fontos tétel, hogy az áteresztőképesség érdekében minél kevesebb és rövidebb ilyen blokk legyen, de ha ez akár csak 4 utasítással hosszabb, annak is mérhető impact-je lehet a várakozási időn, máshogyan versenyeznek ezáltal a szálak.

És ha megnézed, továbbra sem azt mondom, hogy az instrumentation profiler (vagy éppen annak egy speciális esete, a purify) nem működik, hanem csak azt, hogy a fizika alaptörvényeihez hasonlóan a megfigyelésnek itt is megvan a maga hatása az eseményekre, módszertől és szofisztikációtól függően, de befolyásolja azt. Azért nevezik szisztematikus hibának / torzításnak az instrumentation profiler ilyen típusú behatását, mert az egymást követő lefutásoknál mindig ugyanúgy működik. Azért nevezik sokan megbízhatatlannak a sampling profiler-t, mert ott az torzul, hogy nem is nézünk meg mindig mindent, emiatt amúgy nem is lehet szisztematikus. A hagyományos esetben hajlamosak vagyunk elfeledkezni róla, és inkább csak megbízunk az eredményekben. Nincs ezzel semmi baj, én is ezt tettem ismeretek hiányában egy jódarabig, és ha most megnéznek egy instrumentation profiler eredményt, nem azon gondolkodok, hogy mennyi a szisztematikus torzítás, hanem készpénznek veszem azt a 253 ms-os futási időt arra az adott metódusra. Ettől még persze nem tökéletes a mérés, de mivel mindig ugyanazt a 253-at mondja, elhiszem neki. Igaz nem is fontos számomra a 253, csak az arányok...

A videót azért linkeltem be, mert egy jól összefoglalt példája annak, hogy merjünk együttélni a bizonytalanságokkal (pl. hiába növeljük az elosztott tranzakciós koordinációt 10-fázisú committá, akkor is lesz egy utolsó lépés, ahol az üzenetvesztés miatt bizonytalanná válhat az egész művelet), amelyekre persze már sokan megmondták a tutit, és még többen egyáltalán nem merik alkalmazni. De pl. a bizonytalanságot alkalmazva merjünk elszakadni attól, hogy valami vajon 253 vagy 275 ms-ig fut, sokkal fontosabb az, hogy az összidő hány százalákában fut, vagy hogy milyen execution path esetén fut sokat. Erre meg egy (olcsó) sampling profiler is alkalmas :)

Volt egy erzesem hogy azert beszelunk el ugymond kicsit egymas mellett (vagy tekintunk mast celnak vagy adottnak) mert mas teruletekrol jottunk, de ezzel nincs gond :-) En valos ideju es nem valos ideju kornyezetben egyarant hasznaltam a cuccot, nem vagyok azert annyira tosgyokeres vaspisti :o)

Nem kotexem vagy kotom az ebet a karohoz, de ugy erzem azert a profiling es a benchmark kozott van kulonbseg rendesen. A rational is profiling eszkoznek hirdeti a termeket, en ahhoz a terminologiahoz igazodtam. A profiling hasznalati terulete nem csupan az hogy adott metodust kimersz. Pontosan az a lenyege ami celt irtal: adott use case-eknel megnezed mi emeszti a legtobb idot es ott probalsz faragni. A benchmark pusztan arra jo hogy ugyanazon inputokra mit valtozik a sebesseg. A profiling ennel sokkal tobbet ad (mikozben tudja ezt is nyujtani).

"Igen, a profilernek az a feladata, hogy a teljes rendszerről adjon képet, nem csak egy for ciklusról."
Ezzel a fentiekbol kovetkezoen nem ertek egyet. Mindketto a celja lehet. Techologiai korlataid lehetnek hogy mire leszel kepes vele, de az egy masik dolog. Holnaptol akar ez meg is valtozhat. Ma ez a korlat es egyeb praktikus okok (nem kell az auto hogy a kormanymuvet kiteszteld) foleg a system teszt ala szoritjak.

"az a minimálisan 1-2 utasítás _mindenképpen_ ott lesz, és _Java_ alatt nincs más lehetőségem"
Elhiszem neked, nekem ebben nincs tapasztalatom, de azert arra kivancsi vagyok, ezt nem-e ugy mondod, hogy kozben ott lebeg a fejedben az a gondolat hogy "esszeru idon es koltsegen belul".

"Ha extrém módon félregondolom a logikádat, akkor futtatni sem kellene a kódot, hiszen már a bináris kódból megállapítható minden kódblokk futási ideje, az összes gépi utasítás dokumentált CPU ciklusidővel rendelkezik..."
Igen, tenyleg extrem modon felregondoltad :-D Mivel leirtam tobbszor is hogy merni ettol meg kell, mert nyilvan a program belso allapota dinamikus es nem tudod melyik kodresz hanyszor fut.

"továbbra sem azt mondom, hogy az instrumentation profiler (vagy éppen annak egy speciális esete, a purify) nem működik"
vs
"és ha most megnéznek egy instrumentation profiler eredményt, nem azon gondolkodok, hogy mennyi a szisztematikus torzítás"
Hasznalj olyan toolt ami ki tudja szurni a torzitast az eredmenybol. Szivem szerint azt kivanom barcsak joval tobb open sourceos fejleszto (nem ratok celzok!) lenne eltokelt annyira hogy ilyet tuz ki celnak, nem pedig mindig a konnyebbik vegerol fogja meg a botot.

Az instrumentalasnak van hatasa persze, akar szisztematikus is (tojok ra igazabol), de a lenyeg az hogy van ra modszer, lehetoseg nevezd aminek akarod, hogy a hibat 100%osan kiszurd. Pont. A masodik idezett mondatod ennek ellentmond, ezekbol kovetkeztettem arra hogy meg mindig nem hiszed el hogy letezhet ilyen :-))

Egyebkent gondolj egy kicsit bele (McHalls hatradol egy gozolgo kaveval a kezeben a puha fotelben =): szamitogeprol beszelunk. CPUrol, ami adott ciklusban daralja neked az utasitaskeszletet, determinisztikusan. Szerintem ha azzal a gonddal szembesulsz hogy ezt nem tudod lemerni, azt foleg a SW-nek koszonheted. Elmeletileg semmi akadalya hogy lekuzdd. Nem olcso ? Meglehet. De gondold el: ha meg tudnad tenni konnyen (pl Java alatt), melyiket valasztanad ?

Gondolkoztam ezen a hotspottal valo meresen. Ahonnan en jovok, ott elegge szeparalva vannak a tesztelesi fazisok (leven bitang nagy rendszerekrol van szo), de meg soha nem hallottam olyanrol hogy system teszten mert profiling adat alapjan kodot faragjanak. Altalaban a tipikus hasznalati inputokat meg lehet adni mar system teszt elott is, ergo az alrendszereket lehet veluk tesztelni. Ha pedig nem lehet megadni, akkor tok mindegy mit optimalizalsz mert ugysem tudod hogyan valtozik a jovoben az input minta. Valahogy nem erzem kereknek ezt az egeszet :-)

"Az instrumentalasnak van hatasa persze, akar szisztematikus is (tojok ra igazabol), de a lenyeg az hogy van ra modszer, lehetoseg nevezd aminek akarod, hogy a hibat 100%osan kiszurd. Pont. A masodik idezett mondatod ennek ellentmond, ezekbol kovetkeztettem arra hogy meg mindig nem hiszed el hogy letezhet ilyen :-))"

Elméleti aggályaim vannak vele szemben, tudod, a "ha módosítod a kódot, nem ugyanazt méred" mantra többszálú környezetre :) , lásd alább...

"Ahonnan en jovok, ott elegge szeparalva vannak a tesztelesi fazisok (leven bitang nagy rendszerekrol van szo), de meg soha nem hallottam olyanrol hogy system teszten mert profiling adat alapjan kodot faragjanak. Altalaban a tipikus hasznalati inputokat meg lehet adni mar system teszt elott is, ergo az alrendszereket lehet veluk tesztelni. Ha pedig nem lehet megadni, akkor tok mindegy mit optimalizalsz mert ugysem tudod hogyan valtozik a jovoben az input minta."

Ezzel szemben ez a termék meg a követelményrendszere onnan nőtte ki magát, hogy az ügyfél fejlesztett rendszere az átvétel során (éles és teszt adatok, egyszerre 40+ valódi ember kattintotta) irgalmatlan lassúnak bizonyult, és a fejlesztők nem tudták megmondani, hogy hol a probléma, mutogattak minden élő emberre és egyéb távoli rendszerekre, hogy miattuk van. Ekkor jöttünk mi, hogy megmondjuk. Megnéztük, megmondtuk, kijavítottuk, elfogadható gyorsaságú lett. Egy olyan tipikus esetről volt szó, hogy a fejlesztő egyszem gépén, egyszem tesztfelhasználóval persze hogy gyors volt, aztán rászábadultak a párhuzamos felhasználók, a szálak, a cache szinkronizáció, a connection poolok, egy kis JAXB rossz használat, és hamar megakasztották a dolgot - és kis környezetben persze ki sem derülhet, mert amúgy teljesen jó egy szálon az egész...

"szamitogeprol beszelunk. CPUrol, ami adott ciklusban daralja neked az utasitaskeszletet, determinisztikusan. Szerintem ha azzal a gonddal szembesulsz hogy ezt nem tudod lemerni, azt foleg a SW-nek koszonheted. Elmeletileg semmi akadalya hogy lekuzdd. Nem olcso ? Meglehet. De gondold el: ha meg tudnad tenni konnyen (pl Java alatt), melyiket valasztanad ?"

Igen, ha egy teljesen izolált, virtualizált környezetben lépteted a CPU órajelet, bármit pontosan lemérsz. Ha a SW engedi, akkor minél inkább megközelítheted ezt az ideális állapotot SW-környezettel is. Hogy megéri-e? Miután gyakran vártam több percet, hogy az instrumentáció végre lefusson azon a 10000+ metóduson, ráadásul nem csak indításkor, hanem a jópofa, runtime generált osztályokra is (hosszú történet), nos ahhoz képest nem látom az extra pontosság előnyeit minden esetben.

A kedvenc példám a unit teszt, most fejlesztünk egy webes alkalmazást, aminek a user interfész felületét is lefedjük unit tesztekkel. Van alatta in-memory (nem rdbms) adatbázis, meg indexek, meg aszinkron folyamatok, több feldolgozó szál, minden szépség. Miután beleintegráltuk a profilingot a build folyamatba, a fejlesztők is sokkal szívesebben írják a unit tesztet, mert ha lefut, akkor kap egy reportot az alkalmazásról, van valami, ami egy kicsi plusszt ad azon kívül, hogy XY test success... És míg mondjuk korábban lefutott 20 másodperc alatt az első adag user interfész tesztje (minden környezet felépítés included), addig az instrumentációval volt az 1 perc is, samplinggel meg csak 21 másodperc. Namost ilyen esetben igenis a samplinget fogom választani, még akkor is, ha az instrumentáció pontosabb.

"egy teljesen izolált ... bármit pontosan lemérsz"
Nem igazan ertem miert kapalozol ennyire az ellen hogy meg lehet merni torzitas nelkul is a ciklusokat. Nem kell barmit lemerni. Pontosan adva van mit kell merni, nem mindent. Egyebkent meg lennek lepve ha a JVM-ekben elobb utobb nem bukkanna fel annak a lehetosege amirol beszeltem.

A tobbszalusag maskeppen megy az instrumentalt koddal ? Persze. De maskeppen megy az magatol is es a sampling profilerrel is. Relevans ? Nem. Persze benyalhatod, de ez kozhely a tobbszalusagnal. Akar evekig tesztelheted aztan masik vasra teszed es total maskeppen viselkedik. Megvannak ra az ipari modszerek hogy ennek a hatasat csokkenteni lehessen. Nem veletlen hogy nem system teszt alatt szokas profilerezni.

Amit emlitettel eset az elegge nem tipikus, legalabbis remelem hogy nem ez a tipikus, mert elegge elszomorito hallani. De szerintem egyetertunk hogy legalabbis nem ez a cel.

Az hogy a te altalad hasznalt tool mennyire gyors, jo vagy hasznos, nyilvan te tudod, nem is azt mondtam hasznalj mast. De azert nem kellene par open source szirszarbol altalanositani. A mi projektunkben az instrumentalas nehany masodperc volt per forditas, a futasi overheaden meglatszott hogy megy a profiling alatta, de igy sem volt kritikus a lassusag. Mi egyebkent nem profilereztuk allandoan (sokkal inkabb merfoldkoveknel); mi inkabb a runtime hibaellenorzest (memoria, leak, nem inicializalt terulettel valo babralas es egyeb hibak amik C-ben szokasosak) hasznaltuk allandoan, ami pontosan ugyanolyan kodinjektalassal mukodik a mint a profiler (source kod modositas nelkul).

Azert postoltam, hogy emlitsek egy olyan toolt, ami mas megkozelitessel allt neki mint a legtobb mas tool, meglehetosen megbizhato es alapos. Ugy tunik nem jott be.

"Pontosan adva van mit kell merni, nem mindent."

Már megint ez a benchmarking beidegződés... Egy sör mellett szívesen elmesélem azt a projektet, mikor először szembesültünk azzal a problémával, hogy egy 20+ modulból, 5000+ osztályból álló projektet hol kell kezdeni mérni. Nem, nincs adva hogy mit kell, mert mindent kell. Voltak azért extra constraintek, amik távol álltak az ideális világtól, pl. hogy nem fértünk hozzá a távoli rendszerhez, nem lehetett új buildet csinálni és újradeployolni, max újraindítani, stb...

"A mi projektunkben az instrumentalas nehany masodperc volt per forditas, a futasi overheaden meglatszott hogy megy a profiling alatta, de igy sem volt kritikus a lassusag."

Mekkora projekt, hány osztály, hány metódus volt instrumentálva / elemezve? Mit jelent a futási overhead a nem-profile-olt futáshoz képest?

"Nem veletlen hogy nem system teszt alatt szokas profilerezni."

Nálatok. Máshol más szokások vannak, de gondolj bele: pl. egy iwiw-et vagy facebook-ot lehet úgy is mérni, hogy egy laborgépen megnézed a myprofile weboldal futási idejét, de lehet úgy is, hogy hozzácsapod a futó, éles alkalmazáshoz a profiler-t, vársz egy kicsit, majd megnézed az eredményt. Ha valami, akkor ez utóbbi valódi eredményt ad, pontosan láthatod, hogy mi a szűk keresztmetszet. Kell egy kis bizalom az eszközben hogy ezt megcsináld, no meg persze az, hogy az eszköz maga ne nyírja ki az alkalmazást, de ha a megfelelő technológiával belevágsz, megéri :)

"Amit emlitettel eset az elegge nem tipikus, legalabbis remelem hogy nem ez a tipikus, mert elegge elszomorito hallani. De szerintem egyetertunk hogy legalabbis nem ez a cel."

Pedig... (sóhaj). Mondom, a webes, többrétegű, többszálú alkalmazások világára vonatkozik ez, nem ritka az, hogy max. a legvégén futtatják a profiler-t, ha egyáltalán van bármilyen teljesítménymérés. És hogy mennyire cél? Szerintem sokkal egyszerűbb egy mindent-mérünk hozzáállás, mint egy itt-van-ezt-mérjük, utóbbiból ugyanis esetleg kimaradhat egy frissen implementált rész...

"A tobbszalusag maskeppen megy az instrumentalt koddal ? Persze. De maskeppen megy az magatol is es a sampling profilerrel is."

A sampling profiler tipikusan nem-blokkoló szálat jelent, ami ráadásul az idő borzasztó nagy százalékában inaktív. Az instrumentation profiler esetén ezen túl tipikusan van a szálak között blokkoló szinkronizáció, plussz a kód mérete és karakterisztikája is megváltozik. Ez alapján a sampling profilernek kisebb a módosító hatása, amit pl. úgy lehetne még csökkenteni, hogy egyáltalán nem vezetsz be sem új szálat, sem blokkoló szinkronizációt, sem kódmódosítást - azaz virtualizációs külső megfigyelőt használsz.

Ha már a fenenagy pontosságra törekszel a CPU counter esetén, akkor beláthatod, hogy más hasznossági függvény meg optimalizálhat az impact-minimalizálásra :)

"mi inkabb a runtime hibaellenorzest (memoria, leak, nem inicializalt terulettel valo babralas es egyeb hibak amik C-ben szokasosak) hasznaltuk allandoan, ami pontosan ugyanolyan kodinjektalassal mukodik a mint a profiler"
"Azert postoltam, hogy emlitsek egy olyan toolt, ami mas megkozelitessel allt neki mint a legtobb mas tool, meglehetosen megbizhato es alapos."

Az általad említett tool bizonyára megbízható és alapos C környezetben, de a dolog nem releváns Java környezetben. És bár a hibaellenőrzésre használt instrumentáció, mint instrumentáció ugyanolyan a profiler esetén is, nem az instrumentáción múlik, hogy a profiler nem tudja kiszűrni _tökéletesen_ a profilerben eltöltött időt attól, ami a metódus mérésére van: szerintem ha elkezded implementálni, beláthatod, hogy nem lehet olyan időmérő kódot írni, ami leméri a saját overheadjét, és levonja azt a mért metódus overheadjéből, mindezt hierarchikusan kezelve. Ha mégis megcsinálod (elég csak a pszeudo-kód), akkor azon túl, hogy vendégem vagy egy sörre: ígérem, hogy implementálom instrumentációs profilerben és elérhetővé teszem a jelenlegi mellett :)

"Egyebkent meg lennek lepve ha a JVM-ekben elobb utobb nem bukkanna fel annak a lehetosege amirol beszeltem."

Én sem leszek meglepve, de azt nem instrumentációnak fogják hívni - pont ugyanolyan okokból, ahogy a Java default hibakezelése sem instrumentáció, hanem a platform része. Ha lesz is ilyen lehetőség, az mint egy külső felügyeleti eszköz meg tudja akasztani a "teljes" JVM-et, kiolvassa az értékeket, majd folytatja a futást. A már sokat emlegetett virtualizációs megközelítés.

"De azert nem kellene par open source szirszarbol altalanositani."

Ezt azért mókás volt olvasni :)

Most realizálóm, hogy ez C kódra van. Ott nincs HotSpot, azaz nincs semmi, ami igazán befolyásolná az egyszer már lefordított kódot. Nna, úgy persze az előbb leírtak nem vonatkoznak, azaz akár lehet is közel reális CPU ciklust mérni, de itt még bonyolultabb helyesre megírni a beágyazott mérési pontokból a profiling idő kiszűrését. Ez amúgy egyre közelebb van az általam említett "virtuális futtatás" kategóriához, szép nagy overheaddel :)

Java környezetben továbbra is létezőnek tartom az instrumentációs profilerek szisztematikus hibáját, igaz a fentiek tükrében finomítani kell a leíráson, hogy az egész még megkavaródik egy HotSpottal is...

Ahogy elnézem leginkább JNI-vel és egyéb olyan feltételekkel (Java 1.2), ami ma már elképzelhetetlenné teszi az alkalmazását. C-re biztosan jó, illetve az IBM-nek is volt olyan terméke, ami C-s alkalmazásokat borzasztóan kioptimalizált, de ez a Java világra nem alkalmazható jelenleg.

( _Joel | 2009. 08. 26., sze – 01:09 )

A unit test profilingot mekkora munka lenne szerinted egy surefire-be integrálni maven alatti automatikus futtatás céljából?

--
The reason that half of us are in computing at all is that we see computers as things that we can make beautiful things out of..

( syntern | 2009. 08. 27., cs – 17:56 )

Bejelentés: ma úgy döntöttünk, hogy az instrumentálást is közzétesszük nyílt forráskód alatt, egyfajta szimbiózisban fog élni a kétféle profiling bizonyos esetekben. Lesz még ezen kívül HTML report, néhány újdonság, várhatóan jövő hét végére...