Diagnostikujte bežné problémy za behu pomocou hprof

Úniky pamäte a zablokovania a ošípané procesora, ach jaj! Vývojári aplikácií Java často čelia týmto runtime problémom. Môžu byť obzvlášť odstrašujúce v zložitej aplikácii s viacerými vláknami bežiacimi cez státisíce riadkov kódu - aplikácia, ktorú nemôžete odoslať, pretože rastie v pamäti, stáva sa neaktívnou alebo prehltne viac cyklov CPU, ako by mala.

Nie je žiadnym tajomstvom, že nástroje na profilovanie v prostredí Java majú za sebou dlhú cestu, aby sa vyrovnali svojim alternatívnym jazykom. V súčasnosti existuje veľa výkonných nástrojov, ktoré nám pomáhajú vypátrať vinníkov týchto bežných problémov. Ako si ale vybudujete dôveru v schopnosť efektívne využívať tieto nástroje? Koniec koncov, pomocou nástrojov diagnostikujete zložité správanie, ktorému nerozumiete. Aby ste sa uistili, že vaša situácia je zložitá, údaje poskytnuté nástrojmi sú primerane zložité a informácie, ktoré hľadáte, alebo nie sú vždy jasné.

Keď som čelil podobným problémom v mojej predchádzajúcej inkarnácii ako experimentálny fyzik, vytvoril som kontrolné experimenty s predvídateľnými výsledkami. To mi pomohlo získať dôveru v merací systém, ktorý som používal v experimentoch, ktoré generovali menej predvídateľné výsledky. Podobne aj tento článok používa nástroj na profilovanie hprof na preskúmanie troch jednoduchých ovládacích aplikácií, ktoré vykazujú tri bežné problémové chovania uvedené vyššie. Aj keď to nie je také užívateľsky prívetivé ako niektoré komerčné nástroje na trhu, hprof je súčasťou Java 2 JDK a ako ukážem, dokáže tieto správanie efektívne diagnostikovať.

Beh s hprof

Spustenie vášho programu s hprof je jednoduché. Jednoducho vyvolajte runtime Java pomocou nasledujúcej voľby príkazového riadku, ako je popísané v dokumentácii nástroja JDK pre spúšťač aplikácií Java:

java -Xrunhprof [: help] [: =, ...] MyMainClass 

Zoznam možností je k dispozícii na serveri [:Pomoc] zobrazená možnosť. Príklady v tomto článku som vygeneroval pomocou portu Blackdown JDK 1.3-RC1 pre Linux pomocou nasledujúceho príkazu na spustenie:

java -classic -Xrunhprof: halda = stránky, cpu = vzorky, hĺbka = 10, monitor = y, vlákno = y, doe = y MemoryLeak 

Nasledujúci zoznam vysvetľuje funkciu každej možnosti použitej v predchádzajúcom príkaze:

• halda = stránky: Hovorí spoločnosti hprof, aby generovala stopy zásobníka, ktoré označujú, kde bola alokovaná pamäť
• cpu = vzorky: Hovorí spoločnosti hprof, aby pomocou štatistického vzorkovania určila, kde CPU trávi čas
• hĺbka = 10: Príkazu hprof, aby zobrazoval stopy zásobníka maximálne v 10 úrovniach
• monitor = r: Hovorí spoločnosti hprof, aby generovala informácie o monitoroch sporov používaných na synchronizáciu práce viacerých vlákien
• závit = r: Hovorí spoločnosti hprof, aby identifikovala vlákna v stopách zásobníka
• laň = r: Hovorí spoločnosti hprof, aby po ukončení vytvorila výpis profilových údajov

Ak používate JDK 1.3, musíte vypnúť predvolený kompilátor HotSpot pomocou -klasické možnosť. HotSpot má vlastný profilovač vyvolaný prostredníctvom -Xprof možnosť, ktorá používa výstupný formát odlišný od toho, ktorý tu popíšem.

Spustenie programu s hprof zanechá súbor s názvom java.hprof.txt vo vašom pracovnom adresári; tento súbor obsahuje informácie o profilovaní zhromaždené počas spustenia vášho programu. Výpis môžete tiež vygenerovať kedykoľvek, keď je váš program spustený, stlačením klávesu Ctrl- \ v okne konzoly Java v systéme Unix alebo Ctrl-Break v systéme Windows.

Anatómia výstupného súboru hprof

Výstupný súbor hprof obsahuje oddiely popisujúce rôzne vlastnosti profilovaného programu Java. Začína sa to hlavičkou, ktorá popisuje jej formát, ktorého zmeny v hlavičke sa môžu bez predchádzajúceho upozornenia zmeniť.

Sekcie Thread and Trace výstupného súboru vám pomôžu zistiť, ktoré vlákna boli aktívne, keď bol váš program spustený, a čo robili. Sekcia Vlákno poskytuje zoznam všetkých vlákien, ktoré boli spustené a ukončené počas životnosti programu. Sekcia Sledovanie obsahuje zoznam očíslovaných stôp zásobníka pre niektoré vlákna. Na tieto čísla sledovania zásobníka sa odkazuje v iných oddieloch súborov.

Sekcie Heap Dump a Sites vám pomôžu analyzovať využitie pamäte. Záležiac ​​na halda výber, ktorý si vyberiete pri spustení virtuálneho stroja (VM), môžete získať výpis všetkých živých objektov v halde Java (halda = skládka) a / alebo triedený zoznam alokačných webov, ktoré identifikujú najviac pridelené objekty (halda = stránky).

Sekcie Vzorky CPU a Čas CPU vám pomôžu pochopiť využitie CPU; časť, ktorú získate, závisí od vášho CPU suboption (cpu = vzorky alebo cpu = čas). CPU Samples poskytuje štatistický profil vykonávania. Čas CPU zahŕňa merania toho, koľkokrát bola daná metóda volaná a ako dlho trvalo vykonanie každej metódy.

Sekcie Monitor Time a Monitor Dump vám pomôžu pochopiť, ako synchronizácia ovplyvňuje výkon vášho programu. Monitorovací čas ukazuje, koľko času majú vaše vlákna v spore o uzamknuté zdroje. Monitor Dump je momentka z momentálne používaných monitorov. Ako uvidíte, Monitor Dump je užitočný na nájdenie zablokovania.

Diagnostikujte únik pamäte

V Jave definujem únik pamäte ako (zvyčajne) neúmyselné zlyhanie dereferencie vyradených objektov, aby smetiar nemohol získať späť pamäť, ktorú používajú. The MemoryLeak program v zozname 1 je jednoduchý:

Zoznam 1. Program MemoryLeak

01 import java.util.Vector; 02 03 verejná trieda MemoryLeak {04 05 public static void main (String [] args) {06 07 int MAX_CONSUMERS = 10 000; 08 int SLEEP_BETWEEN_ALLOCS = 5; 09 10 ConsumerContainer objectHolder = nový ConsumerContainer (); 11 12 while (objectHolder.size () <MAX_CONSUMERS) {13 System.out.println ("Allocating object" + 14 Integer.toString (objectHolder.size ()) 15); 16 objectHolder.add (nový MemoryConsumer ()); 17 vyskúšajte {18 Thread.currentThread (). Sleep (SLEEP_BETWEEN_ALLOCS); 19} catch (InterruptedException ie) {20 // Nerobiť nič. 21} 22} // zatiaľ. 23} // hlavné. 24 25} // Koniec MemoryLeak. 26 27 / ** Pomenovaná trieda kontajnera na uchovávanie odkazov na objekty. * / 28 class ConsumerContainer rozširuje vektorovú {} 29 30 / ** triedu, ktorá spotrebúva pevné množstvo pamäte. * / 31 trieda MemoryConsumer {32 public static final int MEMORY_BLOCK = 1024; 33 verejných bajtov [] memoryHoldingArray; 34 35 MemoryConsumer () {36 memoryHoldingArray = nový bajt [MEMORY_BLOCK]; 37} 38} // Ukončiť spotrebiteľa pamäte. 

Po spustení programu sa vytvorí a ConsumerContainer objekt, potom začne vytvárať a pridávať MemoryConsumer má proti tomu objekty veľkosti najmenej 1 kB ConsumerContainer objekt. Udržiavanie prístupných objektov ich robí nedostupnými na zhromažďovanie odpadkov, čo simuluje únik pamäte.

Pozrime sa na vybrané časti profilového súboru. Prvých pár riadkov sekcie Weby jasne ukazuje, čo sa deje:

STRÁNKY ZAČÍNAJÚ (zoradené podľa živých bajtov) Pon sep 3 19:16:29 2001 percent živých alokovaných zásobníkov triedna trieda vlastné hromadenie bajtov objs bajtov objs názov stopy 1 97,31% 97,31% 10280000 10 000 10280000 10 000 1995 [B 2 0,39% 97,69% 40964 1 81880 10 1996 [L; 3 0,38% 98,07% 40000 10 000 40000 10 000 1994 PamäťSpotrebiteľ 4 0,16% 98,23% 16388 1 16388 1 1295 [C 5 0,16% 98,38% 16388 1 16388 1 1304 [C ... 

Existuje 10 000 predmetov typu bajt [] ([B vo VM-speak), ako aj 10 000 MemoryConsumer predmety. Bajtové polia zaberajú 10 280 000 bajtov, takže zjavne existuje réžia tesne nad surovými bajtmi, ktoré každé pole spotrebuje. Pretože počet pridelených objektov sa rovná počtu živých objektov, môžeme dospieť k záveru, že žiadny z týchto objektov nemohol byť zhromažďovaný odpadkami. Je to v súlade s našimi očakávaniami.

Ďalším zaujímavým bodom: pamäť, o ktorej sa uvádza, že je spotrebovaná serverom MemoryConsumer objekty nezahŕňa pamäť spotrebovanú bajtovými poľami. To ukazuje, že náš nástroj na vytváranie profilov nevystavuje vzťahy hierarchického obmedzení, ale skôr štatistiku triedu po triede. Toto je dôležité pochopiť pri používaní nástroja hprof na zisťovanie úniku pamäte.

Odkiaľ sa vzali tie netesné bajtové polia? Všimnite si, že MemoryConsumer objekty a referenčné stopy bajtových polí 1994 a 1995 v nasledujúcej časti Trace. Hľa, tieto stopy nám hovoria, že MemoryConsumer objekty boli vytvorené v MemoryLeak triedy hlavný() metóda a že bajtové polia boli vytvorené v konštruktore (() metóda vo VM-speak). Našli sme náš únik pamäte, čísla riadkov a všetko:

TRACE 1994: (vlákno = 1) MemoryLeak.main (MemoryLeak.java:16) TRACE 1995: (vlákno = 1) MemoryConsumer. (MemoryLeak.java:36) MemoryLeak.main (MemoryLeak.java:16) 

Diagnostikujte prasa procesora

V zozname 2, a BusyWork trieda má každé vlákno volanie metódy, ktorá reguluje, ako veľmi vlákno funguje, tým, že mení jeho čas spánku medzi jednotlivými cyklami vykonávania výpočtov náročných na procesor:

Zoznam 2. Program CPUHog

01 / ** Hlavná trieda pre kontrolný test. * / 02 verejná trieda CPUHog {03 verejné static void main (String [] args) {04 05 Thread slouch, workingStiff, workaholic; 06 slouch = new Slouch (); 07 workingStiff = nový WorkingStiff (); 08 workoholik = nový workoholik (); 09 10 slouch.start (); 11 workingStiff.start (); 12 workoholik.štart (); 13} 14} 15 16 / ** Nízke využitie procesora. * / 17 trieda Slouch rozširuje vlákno {18 public Slouch () {19 super ("Slouch"); 20} 21 public void run () {22 BusyWork.slouch (); 23} 24} 25 26 / ** Stredné vlákno využívajúce CPU. * / 27 trieda WorkingStiff rozširuje vlákno {28 public WorkingStiff () {29 super ("WorkingStiff"); 30} 31 public void run () {32 BusyWork.workNormally (); 33} 34} 35 36 / ** Vlákno s vysokým využitím procesora. * / 37 trieda workoholik rozširuje vlákno {38 public workaholic () {39 super ("workoholik"); 40} 41 public void run () {42 BusyWork.workTillYouDrop (); 43} 44} 45 46 / ** Trieda so statickými metódami na spotrebovanie rôzneho množstva 47 * času procesora. * / 48 trieda BusyWork {49 50 public static int callCount = 0; 51 52 public static void slouch () {53 int SLEEP_INTERVAL = 1000; 54 computeAndSleepLoop (SLEEP_INTERVAL); 55} 56 57 public static void workNormally () {58 int SLEEP_INTERVAL = 100; 59 computeAndSleepLoop (SLEEP_INTERVAL); 60} 61 62 public static void workTillYouDrop () {63 int SLEEP_INTERVAL = 10; 64 computeAndSleepLoop (SLEEP_INTERVAL); 65} 66 67 private static void computeAndSleepLoop (int sleepInterval) {68 int MAX_CALLS = 10 000; 69 while (callCount <MAX_CALLS) {70 computeAndSleep (sleepInterval); 71} 72} 73 74 private static void computeAndSleep (int sleepInterval) {75 int VÝPOČTY = 1000; 76 dvojnásobný výsledok; 77 78 // Vypočítať. 79 callCount ++; 80 pre (int i = 0; i <VÝPOČTY; i ++) {81 result = Math.atan (callCount * Math.random ()); 82} 83 84 // Spánok. 85 vyskúšajte {86 Thread.currentThread (). Sleep (sleepInterval); 87} catch (InterruptedException ie) {88 // Nerobiť nič. 89} 90 91} // Ukončiť computeAndSleep. 92} // Ukončiť BusyWork. 

Existujú tri vlákna - Workoholik, WorkingStiffa Slúchadlo - ktorých pracovná etika sa líši rádovo, súdiac podľa práce, ktorú sa rozhodnú robiť. Preskúmajte sekciu Vzorky procesora profilu uvedenú nižšie. Tri najvyššie hodnotené stopy ukazujú, že procesor strávil väčšinu času výpočtom náhodných čísel a dotykových oblúkov, ako by sme očakávali:

VZORKY CPU ZAČÍNAJÚ (celkom = 935) Utorok 4. septembra 20:44:49 2001 hodnotenie vlastnej akumulácie počítania metód sledovania 1 39,04% 39,04% 365 2040 java / util / Random.next 2 26,84% 65,88% 251 2042 java / util / Random. nextDouble 3 10,91% 76,79% 102 2041 java / lang / StrictMath.atan 4 8,13% 84,92% 76 2046 BusyWork.computeAndSleep 5 4,28% 89,20% 40 2050 java / lang / Math.atan 6 3,21% 92,41% 30 2045 java / lang / Math.random 7 2,25% 94,65% 21 2051 java / lang / Math.random 8 1,82% 96,47% 17 2044 java / util / Random.next 9 1,50% 97,97% 14 2043 java / util / Random.nextDouble 10 0,43% 98,40% 4 2047 BusyWork.computeAndSleep 11 0,21% 98,61% 2 2048 java / jazyk / StrictMath.atan 12 0,11% 98,72% 1 1578 java / io / BufferedReader.readLine 13 0,11% 98,82% 1 2054 java / jazyk / vlákno.sleep 14 0,11% 98,93% 1 1956 java / security / PermissionCollection.setReadOnly iba 15 0,11% 99,04% 1 2055 java / lang / Thread.sleep 16 0,11% 99,14% 1 1593 java / lang / String.valueOf 17 0,11% 99,25% 1 2052 java / lang / Matematika. Náhoda 18 0,11% 99,36% 1 2049 java / util / Random.nextDouble 19 0,11% 99,47% 1 2031 BusyWork.computeAndSleep 20 0,11% 99,57% 1 1530 slnka / io / CharToByteISO8859_1.convert ... 

Upozorňujeme, že hovory do BusyWork.computeAndSleep () metóda zaberá 8,13 percenta, 0,43 percenta a 0,11 percenta pre Workoholik, WorkingStiffa Slúchadlo vlákna, resp. To, o ktoré vlákna sa jedná, môžeme zistiť tak, že preskúmame stopy, na ktoré sa odkazuje v stĺpci sledovania sekcie CPU Samples vyššie (poradie 4, 10 a 19) v nasledujúcej sekcii Trace: