Diagnosoi yleisiä ajonaikaisia ​​ongelmia hprofin kanssa

Muistivuodot ja umpikujat ja CPU-siat, oh my! Java-sovelluskehittäjät kohtaavat usein nämä ajonaikaiset ongelmat. Ne voivat olla erityisen pelottavia monimutkaisessa sovelluksessa, jossa on useita ketjuja, jotka kulkevat satojen tuhansien koodirivien läpi - sovellus, jota et voi lähettää, koska se kasvaa muistissa, muuttuu passiiviseksi tai haisee enemmän suorittimen jaksoja kuin pitäisi.

Ei ole mikään salaisuus, että Java-profilointityökaluilla on ollut pitkä tapa saavuttaa vaihtoehtoisten kielten kollegansa. Nyt on olemassa monia tehokkaita työkaluja, jotka auttavat meitä jäljittämään näiden yleisten ongelmien syylliset. Mutta miten voit kehittää luottamusta kykysi käyttää näitä työkaluja tehokkaasti? Loppujen lopuksi käytät työkaluja diagnosoimaan monimutkainen käyttäytyminen, jota et ymmärrä. Ahdinkon lisäämiseksi työkalujen tarjoamat tiedot ovat kohtuullisen monimutkaisia ​​ja etsimäsi tai etsimäsi tiedot eivät aina ole selkeitä.

Kun edellisessä inkarnaatiossani kokeellisena fyysikkona kohtasin samanlaisia ​​ongelmia, loin kontrollikokeet ennustettavilla tuloksilla. Tämä auttoi minua saamaan luottamuksen mittausjärjestelmään, jota käytin kokeissa, jotka tuottivat vähemmän ennustettavia tuloksia. Vastaavasti tässä artikkelissa käytetään hprof-profilointityökalua tutkiakseen kolmea yksinkertaista ohjaussovellusta, joilla on kolme yllä lueteltua yleistä ongelmakäyttäytymistä. Vaikka hprof ei olekaan yhtä käyttäjäystävällinen kuin jotkut markkinoilla olevat kaupalliset työkalut, se sisältyy Java 2 JDK: n ja, kuten osoitan, se pystyy tehokkaasti diagnosoimaan nämä käyttäytymismuodot.

Suorita hprofin kanssa

Ohjelman ajaminen hprofilla on helppoa. Käynnistä Java-ajonaika seuraavalla komentorivivaihtoehdolla, kuten Java-sovellusten käynnistysohjelman JDK-työkaluohjeissa kuvataan:

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

Luettelo vaihtoehdoista on saatavana [:auta] esitetty vaihtoehto. Loin tämän artikkelin esimerkit käyttämällä JDK 1.3-RC1 for Linuxin Blackdown-porttia seuraavalla käynnistyskomennolla:

java -classic -Xrunhprof: kasa = sivustot, prosessori = näytteet, syvyys = 10, näyttö = y, säie = y, doe = y MemoryLeak 

Seuraava luettelo selittää kunkin edellisessä komennossa käytetyn alivaihtoehdon toiminnot:

• kasa = sivustot: Käskee hprofia generoimaan pinojäljet ​​osoittamaan, mihin muisti on varattu
• cpu = näytteet: Käskee hprofia käyttämään tilastollista näytteenottoa päättääkseen, missä CPU viettää aikaa
• syvyys = 10: Käskee hprofin näyttämään pinojäljet ​​korkeintaan 10 tasoa syvällä
• monitori = y: Käskee hprofia tuottamaan tietoja kilpailunäytöistä, joita käytetään useiden säikeiden työn synkronointiin
• lanka = y: Käskee hprofia tunnistamaan ketjut pinonjäljissä
• doe = y: Käskee hprofia tuottamaan profiilitietojen tyhjennyksen poistuttaessa

Jos käytät JDK 1.3: ta, sinun on kytkettävä oletusarvoinen HotSpot-kääntäjä pois päältä -klassikko vaihtoehto. HotSpotilla on oma profilointijärjestelmä, jota kutsutaan -Xprof vaihtoehto, joka käyttää eri tulostusmuotoa kuin tässä kuvataan.

Ohjelman suorittaminen hprof: lla jättää tiedoston nimeltä java.hprof.txt työhakemistossasi; tämä tiedosto sisältää profilointitiedot, jotka on kerätty ohjelman suorittamisen aikana. Voit myös luoda dumpin milloin tahansa ohjelman ollessa käynnissä painamalla Ctrl- \ Java-konsoli -ikkunassa Unixissa tai Ctrl-Break Windowsissa.

Hprof-lähtötiedoston anatomia

Hprof-lähtötiedosto sisältää osia, jotka kuvaavat profiloidun Java-ohjelman erilaisia ​​ominaisuuksia. Se alkaa otsakkeella, joka kuvaa sen muotoa, jota otsikon mukaan voidaan muuttaa ilman erillistä ilmoitusta.

Lähtötiedoston säike- ja jäljitysosat auttavat sinua selvittämään, mitkä ketjut olivat aktiivisia, kun ohjelma suoritettiin ja mitä he tekivät. Lanka-osassa on luettelo kaikista ohjelman aikana aloitetuista ja lopetetuista säikeistä. Jäljitys-osio sisältää luettelon joistakin säikeistä numeroiduista pinojäljistä. Näihin pinon jäljitysnumeroihin viitataan ristiin muissa tiedosto-osioissa.

Heap Dump and Sites -osio auttaa analysoimaan muistin käyttöä. Riippuen pino valitsemasi alavalinnan, kun käynnistät virtuaalikoneen (VM), saat kaatopaikan kaikista Java-kasan live-objekteista (kasa = kaatopaikka) ja / tai lajiteltu luettelo allokointisivustoista, jotka tunnistavat eniten varatut objektit (kasa = sivustot).

Suorittimen näytteet ja CPU-aika-osiot auttavat sinua ymmärtämään suorittimen käyttöä. saamasi osio riippuu prosessori alavalinta (cpu = näytteet tai cpu = aika). CPU Samples tarjoaa tilastollisen suoritusprofiilin. CPU-aika sisältää mittaukset siitä, kuinka monta kertaa tiettyä menetelmää kutsuttiin ja kuinka kauan kunkin menetelmän suorittaminen kesti.

Monitorin aika- ja Monitor Dump -osiossa voit ymmärtää, miten synkronointi vaikuttaa ohjelman suorituskykyyn. Monitor Time näyttää, kuinka kauan ketjut kokevat kilpailun lukittujen resurssien suhteen. Monitor Dump on tilannekuva nykyisistä näytöistä. Kuten näette, Monitor Dump on hyödyllinen umpikujaan.

Diagnosoi muistivuoto

Java-ohjelmassa määritän muistivuodon (yleensä) tahattomaksi epäonnistumiseksi hylätä esineitä, jotta roskakorin kerääjä ei voi palauttaa käyttämäänsä muistia. Muistivuoto Listaus 1 -ohjelma on yksinkertainen:

Luettelo 1. MemoryLeak-ohjelma

01 tuo java.util.Vector; 02 03 public class MemoryLeak {04 05 public staattinen void main (String [] args) {06 07 int MAX_CONSUMERS = 10000; 08 int SLEEP_BETWEEN_ALLOCS = 5; 09 10 ConsumerContainer objectHolder = uusi ConsumerContainer (); 11 12 kun (objectHolder.size () <MAX_CONSUMERS) {13 System.out.println ("Kohteen jakaminen" + 14 Integer.toString (objectHolder.size ()) 15); 16 objectHolder.add (uusi MemoryConsumer ()); 17 kokeile {18 Thread.currentThread (). Sleep (SLEEP_BETWEEN_ALLOCS); 19} catch (InterruptedException ie) {20 // Älä tee mitään. 21} 22} // kun. 23} // tärkein. 24 25} // MemoryLeak-loppu. 26 27 / ** Nimetty säilöluokka objektiviittausten säilyttämistä varten. * / 28 -luokan ConsumerContainer laajentaa Vector {} 29 30 / ** -luokkaa, joka kuluttaa kiinteän määrän muistia. * / 31 luokan MemoryConsumer {32 julkinen staattinen loppu int MEMORY_BLOCK = 1024; 33 julkista tavua [] memoryHoldingArray; 34 35 MemoryConsumer () {36 memoryHoldingArray = uusi tavu [MEMORY_BLOCK]; 37} 38} // Lopeta MemoryConsumer. 

Kun ohjelma suoritetaan, se luo ConsumerContainer objektin, sitten alkaa luoda ja lisätä MuistiKuluttaja objektit, joiden koko on vähintään 1 kt ConsumerContainer esine. Kohteiden pitäminen esteettöminä tekee niistä poissa käytöstä roskien keräystä varten, mikä simuloi muistivuotoja.

Katsotaanpa profiilitiedoston tiettyjä osia. Sivustot-osan muutamat ensimmäiset rivit osoittavat selvästi, mitä tapahtuu:

SIVUSTOT alkavat (elävien tavujen järjestyksessä) ma 3. syyskuuta 19:16:29 2001 prosenttia live-allokoidun pino -luokan sijoitus itsestään tavut objs tavut objs-jäljen nimi 1 97,31% 97,31% 10280000 10000 10280000 10000 1995 [B 2 0,39% 97,69% 40964 1 81880 10 1996 [L; 3 0,38% 98,07% 40000 10000 40000 10000 1994 MuistiKäyttäjä 4 0,16% 98,23% 16388 1 16388 1 1295 [C 5 0,16% 98,38% 16388 1 16388 1130 [C ... 

Tyyppisiä esineitä on 10000 tavu[] ([B VM-puhua) sekä 10 000 MuistiKuluttaja esineitä. Tavu-matriisit vievät 10 280 000 tavua, joten ilmeisesti jokaisen taulukon kuluttaman raakatavun yläpuolella on yläpuolella. Koska allokoitujen kohteiden lukumäärä on yhtä suuri kuin elävien kohteiden lukumäärä, voidaan päätellä, että yksikään näistä esineistä ei voi olla kerätty roskiin. Tämä vastaa odotuksiamme.

Toinen mielenkiintoinen asia: muistin ilmoitettiin kuluttaneen MuistiKuluttaja objektit eivät sisällä tavutaulukkojen käyttämää muistia. Tämä osoittaa, että profilointityökalumme ei paljasta hierarkkisia eristyssuhteita, vaan pikemminkin luokkakohtaisia ​​tilastoja. Tämä on tärkeää ymmärtää käytettäessä hprofia muistivuodon määrittämiseen.

Mistä nämä vuotavat tavutaulukot ovat peräisin? Huomaa, että MuistiKuluttaja objektit ja tavutaulukot viittaavat jälkiin 1994 ja 1995 seuraavassa Jäljitys-osassa. Katso, nämä jäljet ​​kertovat meille, että MuistiKuluttaja esineitä luotiin Muistivuoto luokan main () menetelmä ja että tavutaulukot luotiin konstruktoriin (() menetelmä VM-puhua). Olemme löytäneet muistivuotomme, linjanumeromme ja kaikki:

TRACE 1994: (säie = 1) MemoryLeak.main (MemoryLeak.java:16) TRACE 1995: (thread = 1) MemoryConsumer. (MemoryLeak.java:36) MemoryLeak.main (MemoryLeak.java:16) 

Diagnosoi suorittimen sika

Luettelossa 2 a VarattuTyö luokka on jokainen säiekutsu menetelmä, joka säätelee langan toimintaa vaihtelemalla sen lepoaikaa suorittimen intensiivisten laskelmien suorittamisen välillä:

Luettelo 2. CPUHog-ohjelma

01 / ** Pääluokka kontrollikokeille. * / 02 julkisen luokan CPUHog {03 public static void main (String [] args) {04 05 Langankierto, workingStiff, työnarkomaani; 06 slouch = uusi slouch (); 07 workingStiff = uusi WorkingStiff (); 08 työarkki = uusi työarkki (); 09 10 slouch.start (); 11 työskentelyJäykkä.aloitus (); 12 työarkki.aloitus (); 13} 14} 15 16 / ** Alhainen suorittimen käyttöaste. * / 17-luokan Slouch laajentaa lankaa {18 public Slouch () {19 super ("Slouch"); 20} 21 julkista mitätöintiä () {22 BusyWork.slouch (); 23} 24} 25 26 / ** Keskisuuri suorittimen käyttökierre. * / 27-luokan WorkingStiff laajentaa säiettä {28 public WorkingStiff () {29 super ("WorkingStiff"); 30} 31 public void run () {32 BusyWork.workNormally (); 33} 34} 35 36 / ** Suuri suorittimen käyttöaste. * / 37-luokan työarkolaiset laajentavat säiettä {38 julkista työnarkomaania () {39 super ("työarkki"); 40} 41 public void run () {42 BusyWork.workTillYouDrop (); 43} 44} 45 46 / ** Luokka staattisilla menetelmillä kuluttaa vaihtelevia määriä 47 * CPU-aikaa. * / 48 luokan BusyWork {49 50 julkinen staattinen int callCount = 0; 51 52 julkinen staattinen tyhjä slouch () {53 int SLEEP_INTERVAL = 1000; 54 computeAndSleepLoop (SLEEP_INTERVAL); 55} 56 57 julkinen staattinen tyhjä työ Normaalisti () {58 int SLEEP_INTERVAL = 100; 59 computeAndSleepLoop (SLEEP_INTERVAL); 60} 61 62 julkinen staattinen tyhjä työTillYouDrop () {63 int SLEEP_INTERVAL = 10; 64 computeAndSleepLoop (SLEEP_INTERVAL); 65} 66 67 yksityinen staattinen void computeAndSleepLoop (int sleepInterval) {68 int MAX_CALLS = 10000; 69 while (callCount <MAX_CALLS) {70 computeAndSleep (sleepInterval); 71} 72} 73 74 yksityinen staattinen void computeAndSleep (int sleepInterval) {75 int LASKENTAT = 1000; 76 kaksinkertainen tulos; 77 78 // Laske. 79 callCount ++; 80 (int i = 0; i <LASKENTAT; i ++) {81 tulos = Math.atan (callCount * Math.random ()); 82} 83 84 // Lepotila. 85 kokeile {86 Thread.currentThread (). Sleep (sleepInterval); 87} catch (InterruptedException ie) {88 // Älä tee mitään. 89} 90 91} // Lopeta computeAndSleep. 92} // Lopeta varattu työ. 

Ketjuja on kolme - Työnarkomaani, Työntöjäykkyysja Laahustaa - joiden työetiikka vaihtelee suuruusluokittain, päätellen tekemänsä työn perusteella. Tutki profiilin alla olevaa CPU-näytteet-osiota. Kolme korkeimmaksi luokiteltavaa jälkeä osoittavat, että keskusyksikkö käytti suurimman osan ajastaan ​​satunnaislukujen ja kaaren tangenttien laskemiseen, kuten odotamme:

Suorittimen näytteet alkavat (yhteensä = 935) Tiistai 4. syyskuuta 20:44:49 2001 sijoitusluettelon jälkimenetelmä 1 39,04% 39,04% 365 2040 java / util / Random.sext 2 26.84% 65.88% 251 2042 java / util / Random. seuraavaDouble 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.sext 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 / lang / StrictMath.atan 12 0.11% 98.72% 1 1578 java / io / BufferedReader.readLine 13 0.11% 98.82% 1 2054 java / lang / Thread.sleep 14 0.11% 98,93% 1 1956 java / security / PermissionCollection.setReadOnly 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 / Matematiikan satunnainen 18 0,11% 99,36% 1 2049 java / util / Random.sextDouble 19 0.11% 99.47% 1 2031 BusyWork.computeAndSleep 20 0.11% 99.57% 1 1530 sun / io / CharToByteISO8859_1.convert ... 

Huomaa, että puhelut BusyWork.computeAndSleep () menetelmä vie 8,13 prosenttia, 0,43 prosenttia ja 0,11 prosenttia Työnarkomaani, Työskentelyjäykkyysja Laahustaa langat, vastaavasti. Voimme kertoa, mitkä ketjut nämä ovat, tutkimalla jäljityksiä, joihin viitataan CPU-näytteet-osan yllä olevassa sarakkeessa (riveissä 4, 10 ja 19) seuraavassa jäljitysosassa: