Dijagnosticirajte uobičajene probleme u radu s hprofom

Curenje memorije, mrtve točke i CPU svinja, oh moj! Programeri Java aplikacija često se suočavaju s tim problemima u izvođenju. Oni mogu biti posebno zastrašujući u složenoj aplikaciji s više niti koja prolaze kroz stotine tisuća redaka koda - program koji ne možete isporučiti jer raste u memoriji, postaje neaktivan ili proguta više procesorskih ciklusa nego što bi trebao.

Nije tajna da su Java alati za profiliranje dugo uspjeli stići svoje kolege na alternativnim jezicima. Sada postoje mnogi moćni alati koji će nam pomoći da pronađemo krivce za te uobičajene probleme. Ali kako razviti povjerenje u svoju sposobnost učinkovite upotrebe ovih alata? Napokon, koristite alate za dijagnosticiranje složenog ponašanja koje ne razumijete. Da bi vam zakomplicirali stanje, podaci koje pružaju alati prilično su složeni, a podaci koje tražite ili nisu uvijek jasni.

Kad sam se suočio sa sličnim problemima u svojoj prethodnoj inkarnaciji kao eksperimentalni fizičar, stvorio sam kontrolne eksperimente s predvidljivim rezultatima. To mi je pomoglo da steknem povjerenje u mjerni sustav koji sam koristio u eksperimentima koji su generirali manje predvidljive rezultate. Slično tome, ovaj članak koristi alat za profiliranje hprof za ispitivanje tri jednostavne kontrolne aplikacije koje pokazuju tri gore navedena uobičajena problematična ponašanja. Iako nije toliko user-friendly kao neki komercijalni alati na tržištu, hprof je uključen u Java 2 JDK i, kao što ću pokazati, može učinkovito dijagnosticirati ta ponašanja.

Trči s hprofom

Pokretanje vašeg programa s hprofom je jednostavno. Jednostavno pozovite Java runtime sa sljedećom opcijom naredbenog retka, kao što je opisano u dokumentaciji JDK alata za pokretač Java programa:

java -Xrunhprof [: pomoć] [: =, ...] MyMainClass 

Popis podopcija dostupan je s [:help]prikazanom opcijom. Primjere u ovom članku generirao sam koristeći Blackdown priključak JDK 1.3-RC1 za Linux pomoću sljedeće naredbe za pokretanje:

java -classic -Xrunhprof: hrpa = web mjesta, cpu = uzorci, dubina = 10, monitor = y, nit = y, doe = y MemoryLeak 

Sljedeći popis objašnjava funkciju svake podopcije korištene u prethodnoj naredbi:

  • heap=sites: Govori hprofu da generira tragove stoga koji pokazuju gdje je dodijeljena memorija
  • cpu=samples: Kaže hprofu da koristi statističko uzorkovanje kako bi odredio gdje CPU provodi vrijeme
  • depth=10: Kaže hprof-u da pokaže tragove stoga duboko najviše 10 nivoa
  • monitor=y: Kaže hprof-u da generira informacije o monitorima prijepora koji se koriste za sinkronizaciju rada više niti
  • thread=y: Govori hprof-u da identificira niti u tragovima stoga
  • doe=y: Kaže hprof-u da proizvede odlagalište podataka profiliranja po izlasku

Ako upotrebljavate JDK 1.3, morate isključiti zadani prevoditelj HotSpot s tom -classicopcijom. HotSpot ima vlastiti profiler koji se poziva putem -Xprofopcije koja koristi izlazni format različit od onoga koji ću ovdje opisati.

Pokretanje vašeg programa s hprof ostavit će datoteku pozvanu java.hprof.txtu vaš radni direktorij; ova datoteka sadrži podatke o profiliranju prikupljene tijekom izvođenja vašeg programa. Također možete generirati deponij u bilo kojem trenutku dok se vaš program izvodi pritiskom na Ctrl- \ u prozoru Java konzole na Unixu ili Ctrl-Break na Windowsu.

Anatomija izlazne datoteke hprof

Izlazna datoteka hprof uključuje odjeljke koji opisuju razne karakteristike profiliranog Java programa. Počinje zaglavljem koje opisuje njegov format, za koji zaglavlje tvrdi da se može promijeniti bez najave.

Odjeljci niti i praćenja izlazne datoteke pomažu vam da otkrijete koje su niti bile aktivne kada se vaš program izvodio i što su radili. Odjeljak niti pruža popis svih niti započetih i završenih tijekom života programa. Odjeljak Trace uključuje popis numeriranih tragova stogova za neke niti. Na ove brojeve tragova stogova križano je upućivanje u drugim odjeljcima datoteke.

Odjeljci Heap Dump i Sites pomažu vam u analizi korištenja memorije. Ovisno o heappodopciji koju odaberete prilikom pokretanja virtualnog stroja (VM), možete dobiti izvatk svih aktivnih objekata u Java gomili ( heap=dump) i / ili sortirani popis mjesta za dodjelu koji identificira najaktivnije dodijeljene objekte ( heap=sites).

Odjeljci CPU i CPU Time pomažu vam da razumijete upotrebu CPU-a; odjeljak koji dobijete ovisi o vašoj cpupodopciji ( cpu=samplesili cpu=time). CPU Uzorci pružaju statistički profil izvršenja. CPU Vrijeme uključuje mjerenja koliko je puta data metoda bila pozvana i koliko je vremena trebalo da se izvrši.

Odjeljci Monitor time i Monitor Dump pomažu vam da shvatite kako sinkronizacija utječe na izvedbu vašeg programa. Monitor Time pokazuje koliko vremena vaše niti doživljavaju sukob za zaključane resurse. Dump Monitor je snimak monitora koji se trenutno koriste. Kao što ćete vidjeti, Monitor Dump je koristan za pronalaženje mrtvih točaka.

Dijagnosticirajte curenje memorije

U Javi curenje memorije definiram kao (obično) nenamjerni neuspjeh dereferenciranja odbačenih objekata tako da sakupljač smeća ne može povratiti memoriju koju koriste. MemoryLeakProgram Oglas 1 je jednostavna:

Popis 1. Program MemoryLeak

01 import java.util.Vector; 02 03 javna klasa MemoryLeak {04 05 javna statička void glavna (String [] args) {06 07 int MAX_CONSUMERS = 10000; 08 int SLEEP_BETWEEN_ALLOCS = 5; 09 10 ConsumerContainer objectHolder = novi ConsumerContainer (); 11 12 while (objectHolder.size () <MAX_CONSUMERS) {13 System.out.println ("Dodjela objekta" + 14 Integer.toString (objectHolder.size ()) 15); 16 objectHolder.add (novi MemoryConsumer ()); 17 pokušaj {18 Thread.currentThread (). Sleep (SLEEP_BETWEEN_ALLOCS); 19} catch (InterruptedException tj.) {20 // Ne poduzimati ništa. 21} 22} // dok. 23} // glavni. 24 25} // Kraj MemoryLeak-a. 26 27 / ** Imenovana klasa spremnika za čuvanje referenci na objekt. * / 28 klasa ConsumerContainer proširuje Vector {} 29 30 / ** Klasa koja troši fiksnu količinu memorije. * / 31 klasa MemoryConsumer {32 javni statički konačni int MEMORY_BLOCK = 1024;33 javni bajt [] memoryHoldingArray; 34 35 MemoryConsumer () {36 memoryHoldingArray = novi bajt [MEMORY_BLOCK]; 37} 38} // Kraj memorijskog potrošača.

Kada se program pokrene, on stvara ConsumerContainerobjekt, a zatim započinje s stvaranjem i dodavanjem MemoryConsumerobjekata najmanje 1 KB tom ConsumerContainerobjektu. Održavanje predmeta dostupnim čini ih nedostupnima za odvoz smeća, simulirajući curenje memorije.

Pogledajmo odabrane dijelove datoteke profila. Prvih nekoliko redaka odjeljka Web mjesta jasno pokazuju što se događa:

LOKACIJE POČINJU (poredano po bajtovima uživo) ponedjeljak 3. rujna 19:16:29 2001 posto dodijeljeni stack klasa rang samoakumulirani bajtovi objs bajtovi objs ime traga 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 Potrošač memorije 4 0,16% 98,23% 16388 1 16388 1 1295 [C 5 0,16% 98,38% 16388 1 16388 1 1304 [C ...

Postoji 10.000 vrsta tipa byte[]( [Bu VM-govoru), kao i 10.000 MemoryConsumerobjekata. Nizovi bajtova zauzimaju 10.280.000 bajtova, tako da očito ima nadzemnih troškova neposredno iznad sirovih bajtova koje svaki niz troši. Budući da je broj dodijeljenih predmeta jednak broju živih predmeta, možemo zaključiti da niti jedan od tih predmeta ne može biti sakupljen smeće. To je u skladu s našim očekivanjima.

Još jedna zanimljiva stvar: memorija za koju izvještavaju da je troše MemoryConsumerobjekti ne uključuje memoriju koju troše bajtni nizovi. To pokazuje da naš alat za profiliranje ne izlaže hijerarhijske odnose ograničavanja, već statistiku klase po klasu. Ovo je važno razumjeti kada se hprof koristi za utvrđivanje curenja memorije.

E sad, odakle ti propusni bajtovski nizovi? Primijetite da se MemoryConsumerpredmeti i nizovi bajtova odnose na tragove 1994i 1995u sljedećem odjeljku Trace. Evo i pogledajte, ovi nam tragovi govore da su MemoryConsumerobjekti stvoreni u metodi MemoryLeakklase main()i da su nizovi bajtova stvoreni u konstruktoru ( ()metoda u VM-govoru). Pronašli smo curenje memorije, brojeve linija i sve:

TRACE 1994: (nit = 1) MemoryLeak.main (MemoryLeak.java:16) TRACE 1995: (nit = 1) MemoryConsumer. (MemoryLeak.java:36) MemoryLeak.main (MemoryLeak.java:16) 

Dijagnosticirajte procesorsku svinju

Na popisu 2, BusyWorkklasa ima svaki poziv niti metodu koja regulira koliko nit radi mijenjajući vrijeme spavanja između napada izvedbe CPU-intenzivnih izračuna:

Listing 2. CPUHog program

01 /** Main class for control test. */ 02 public class CPUHog { 03 public static void main(String[] args) { 04 05 Thread slouch, workingStiff, workaholic; 06 slouch = new Slouch(); 07 workingStiff = new WorkingStiff(); 08 workaholic = new Workaholic(); 09 10 slouch.start(); 11 workingStiff.start(); 12 workaholic.start(); 13 } 14 } 15 16 /** Low CPU utilization thread. */ 17 class Slouch extends Thread { 18 public Slouch() { 19 super("Slouch"); 20 } 21 public void run() { 22 BusyWork.slouch(); 23 } 24 } 25 26 /** Medium CPU utilization thread. */ 27 class WorkingStiff extends Thread { 28 public WorkingStiff() { 29 super("WorkingStiff"); 30 } 31 public void run() { 32 BusyWork.workNormally(); 33 } 34 } 35 36 /** High CPU utilization thread. */ 37 class Workaholic extends Thread { 38 public Workaholic() { 39 super("Workaholic"); 40 } 41 public void run() { 42 BusyWork.workTillYouDrop(); 43 } 44 } 45 46 /** Class with static methods to consume varying amounts 47 * of CPU time. */ 48 class 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 = 10000; 69 while (callCount < MAX_CALLS) { 70 computeAndSleep(sleepInterval); 71 } 72 } 73 74 private static void computeAndSleep(int sleepInterval) { 75 int COMPUTATIONS = 1000; 76 double result; 77 78 // Compute. 79 callCount++; 80 for (int i = 0; i < COMPUTATIONS; i++) { 81 result = Math.atan(callCount * Math.random()); 82 } 83 84 // Sleep. 85 try { 86 Thread.currentThread().sleep(sleepInterval); 87 } catch (InterruptedException ie) { 88 // Do nothing. 89 } 90 91 } // End computeAndSleep. 92 } // End BusyWork. 

There are three threads -- Workaholic, WorkingStiff, and Slouch -- whose work ethics vary by orders of magnitude, judging by the work they choose to do. Examine the profile's CPU Samples section shown below. The three highest ranked traces show that the CPU spent most of its time calculating random numbers and arc tangents, as we would expect:

CPU SAMPLES BEGIN (total = 935) Tue Sep 4 20:44:49 2001 rank self accum count trace method 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/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/Math.random 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 sun/io/CharToByteISO8859_1.convert ... 

Imajte na umu da su pozivi prema BusyWork.computeAndSleep()metodi zauzimaju 8.13 posto, 0,43 posto i 0,11 posto za Workaholic, WorkingStiffte Slouchniti, respektivno. Koje su to niti možemo utvrditi ispitivanjem tragova navedenih u stupcu tragova odjeljka CPU Samples (redovi 4, 10 i 19) u sljedećem odjeljku Trace: