Komunikaty dziennika Java Garbage Collection


96

Skonfigurowałem Javę do zrzucania informacji o wyrzucaniu elementów bezużytecznych do dzienników ( pełny GC ). Nie jestem pewien, co oznaczają wpisy dotyczące czyszczenia pamięci w dziennikach. Przykładowe wpisy zamieszczono poniżej. Szukałem w Google i nie znalazłem solidnych wyjaśnień.

Mam kilka rozsądnych domysłów, ale szukam odpowiedzi, które zawierają ścisłe definicje tego, co oznaczają liczby we wpisach, poparte wiarygodnymi źródłami. Automatyczne +1 do wszystkich odpowiedzi, które cytują dokumentację słońca. Moje pytania to:

  1. Do czego odnosi się PSYoungGen? Zakładam, że ma to coś wspólnego z poprzednim (młodszym?) Pokoleniem, ale co dokładnie?
  2. Jaka jest różnica między drugą trójką liczb a pierwszą?
  3. Dlaczego nazwa (PSYoungGen) jest określona dla pierwszej trójki liczb, ale nie dla drugiej?
  4. Co oznacza każda liczba (rozmiar pamięci) w trójce. Na przykład w 109884K-> 14201K (139904K) jest to pamięć przed GC 109884k, a następnie jest zmniejszana do 14201K. Jakie znaczenie ma trzecia liczba? Dlaczego mielibyśmy potrzebować drugiego zestawu liczb?

8109.128: [GC [PSYoungGen: 109884K-> 14201K (139904K)] 691015K-> 595332K (1119040K), 0,0454530 s]

8112.111: [GC [PSYoungGen: 126649K-> 15528K (142336K)] 707780K-> 605892K (1121472K), 0,0934560 s]

8112.802: [GC [PSYoungGen: 130344K-> 3732K (118592K)] 720708K-> 607895K (1097728K), 0,0682690 s]


cała kupa, część sterty młodego pokolenia, pomniejsze gc jak działa gc, sprawdź np. cubrid.org/blog/dev-platform/…
— MarianP

Odpowiedzi:


90

Większość z nich jest wyjaśniona w przewodniku po strojeniu GC (który i tak warto przeczytać).

Opcja wiersza polecenia -verbose:gcpowoduje, że informacje o stercie i wyrzucaniu elementów bezużytecznych są drukowane przy każdej kolekcji. Na przykład tutaj jest wyjście z dużej aplikacji serwerowej:

[GC 325407K->83000K(776768K), 0.2300771 secs]
[GC 325816K->83372K(776768K), 0.2454258 secs]
[Full GC 267628K->83769K(776768K), 1.8479984 secs]

Tutaj widzimy dwie mniejsze kolekcje, po których następuje jedna duża kolekcja. Liczby przed i za strzałką (np. 325407K->83000KZ pierwszego wiersza) wskazują łączny rozmiar obiektów na żywo odpowiednio przed i po czyszczeniu pamięci. Po mniejszych kolekcjach rozmiar obejmuje niektóre obiekty, które są śmieciami (już nie żyją), ale których nie można odzyskać. Obiekty te są zawarte w pokoleniu wykupionym lub istnieją odniesienia do pokoleń posiadanych lub stałych.

Następna liczba w nawiasach (np. (776768K)Ponownie z pierwszego wiersza) to zatwierdzony rozmiar sterty: ilość miejsca, którą można wykorzystać dla obiektów Java bez żądania większej ilości pamięci z systemu operacyjnego. Zwróć uwagę, że liczba ta nie obejmuje jednej z przestrzeni ocalałych, ponieważ w danym momencie można użyć tylko jednej, a także nie obejmuje trwałego generowania, które zawiera metadane używane przez maszynę wirtualną.

Ostatnia pozycja w wierszu (np. 0.2300771 secs) Wskazuje czas potrzebny do wykonania pobrania; w tym przypadku około ćwierć sekundy.

Format głównej kolekcji w trzeciej linii jest podobny.

Format danych wyjściowych utworzonych przez -verbose:gcmoże ulec zmianie w przyszłych wersjach.

Nie jestem pewien, dlaczego w twoim jest PSYoungGen; czy zmieniłeś śmieciarkę?


Gdzie znaleźć pliki dziennika GC?
— Pan Lou

7
Ta odpowiedź tak naprawdę nie odnosi się do oryginalnych pytań. Czuję, że odpowiedź Michaela Josepha jest lepsza. Odpowiada na pytania zadawane przez Ethana i lepiej rozbija oryginalny przykład. Chociaż w jego odpowiedzi są dwa problemy (jego łącze jest teraz martwe, a rafa.ferreria wskazał na drugie), to nie tylko zwraca uwagę na dokument Oracle.
— Dirk

127
  1. PSYoungGen odnosi się do modułu wyrzucania elementów bezużytecznych używanego do poboru podrzędnego. PS oznacza Parallel Scavenge.
  2. Pierwszy zestaw liczb to rozmiary przed / po młodego pokolenia, a drugi zestaw dotyczy całej sterty. ( Diagnozowanie problemu z odśmiecaniem pamięci szczegółowo opisuje format)
  3. Nazwa wskazuje generację i kolektor, o którym mowa, drugi zestaw dotyczy całej sterty.

Przykład powiązanego pełnego GC pokazuje również kolektory używane dla starych i stałych pokoleń:

3.757: [Full GC [PSYoungGen: 2672K->0K(35584K)] 
            [ParOldGen: 3225K->5735K(43712K)] 5898K->5735K(79296K) 
            [PSPermGen: 13533K->13516K(27584K)], 0.0860402 secs]

Na koniec podzielmy jeden wiersz przykładowego wyjścia dziennika:

8109.128: [GC [PSYoungGen: 109884K->14201K(139904K)] 691015K->595332K(1119040K), 0.0454530 secs]
  • 107 MB używane przed GC, 14 MB używane po GC, maksymalny rozmiar młodego pokolenia 137 MB
  • Sterta 675 MB używana przed GC, sterta 581 MB używana po GC, maksymalny rozmiar sterty 1 Gb
  • minor GC wystąpił 8109,128 sekund od uruchomienia JVM i zajął 0,04 sekundy

8
tylko drobny komentarz, wartość między '()' nie jest maksymalnym rozmiarem, na zawsze jest maksymalnym rozmiarem w danym momencie. Jeśli GC nie może zwolnić sterty mniej, wówczas ten limit będzie wymagał większej ilości miejsca dla systemu operacyjnego, a wartość ta wzrośnie. Przestrzegając oczywiście limitu określonego na: -Xmx
— rafa.ferreira

@ rafa.ferreira Myślę, że wartość w parantezie tj. 1119040K jest zatwierdzoną wielkością sterty. Nie sądzę, by GC drukowało wszędzie rozmiar „maksymalnego sterty”. Odnośnik 1 i Odnośnik 2
— rohitmohta

23

Chciałem tylko wspomnieć, że można uzyskać szczegółowy dziennik GC za pomocą pliku

-XX:+PrintGCDetails 

parametr. Następnie zobaczysz wynik PSYoungGen lub PSPermGen, jak w odpowiedzi.

-Xloggc:gc.logWydaje się również, że generuje to samo wyjście, -verbose:gcale możesz określić plik wyjściowy w pierwszym.

Przykładowe użycie:

java -Xloggc:./memory.log -XX:+PrintGCDetails Memory

Aby lepiej zwizualizować dane, możesz wypróbować gcviewer ( nowszą wersję można znaleźć na github ).

Uważaj, aby poprawnie zapisać parametry, zapomniałem "+", a mój JBoss nie uruchomił się bez żadnego komunikatu o błędzie!


3
Zauważ, że gc.log zostanie nadpisany po ponownym uruchomieniu java (na przykład, jeśli zrestartujesz swojego tomcata z powodu problemów z pamięcią, a chciałbyś zobaczyć ten gc.log). A przynajmniej tak się stanie, jeśli obrócisz dzienniki GC. Istnieje wiele innych opcji kontrolujących logowanie gc. Zobacz oracle.com/technetwork/articles/java/vmoptions-jsp-140102.html . W szczególności rozważ-XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=<some number of files> -XX:GCLogFileSize=<some size> -XX:+PrintTenuringDistribution
— Dan Pritts
Korzystając z naszej strony potwierdzasz, że przeczytałeś(-aś) i rozumiesz nasze zasady używania plików cookie i zasady ochrony prywatności.
Licensed under cc by-sa 3.0 with attribution required.