Übermäßige Garbage Collections in Hotspot JVM überwachen

Marja-Liisa Jöckel

Häufig führen Speicherlecks und andere Speicher-Probleme zum einem Einfrieren der Applikation, während der Garbage-Collector-Prozess läuft und erfolglos versucht, Speicherplatz freizugeben. Das gängige Procedere eines Admins ist dann, die Applikation neu zu starten, ohne das entsprechende Problem tatsächlich gelöst zu haben.

Artiom Gourevitch hat sich mit dem GC-Prozess auseinander gesetzt, um aufzuzeigen, wie man übermäßige Garbage Collections identifiziert und einen Heapdump erzeugt, wann immer ein solches Speicherproblem auftritt. Es wird von Hotspot JVM 1.6 oder höher ausgegangen.

Relevante JVM Flags

Zunächst muss der XX:+HeapDumpOnOutOfMemoryError gesetzt werden. Ziel ist dabei, einen OutOfMemory Error zu erzeugen. Zudem helfen zwei weitere Flags bei der Erzeugung des Fehlers:

  • -XX: GCTimeLimit = 98   – definiert eine Grenze beim Anteil der Zeit, die der GC verbraucht, bevor ein OutOfMemory Fehler ausgelöst wird.
  • -XX: GCHeapFreeLimit = 2   – definiert einen Mindest-Prozentsatz an freiem Speicherplatz nach einem vollständigen GC, bevor ein OutOfMemoryError ausgegeben wird.

Beide Flags sind standard-mäßig aktiviert, trotz allem wird der OutOfMemory Error nicht sehr häufig ausgelöst. Um zu entscheiden, welche Standardwerte gut sind und wann welches Flag nützlich ist, ist ein tieferes Verständnis des CG-Prozesses und des OutOfMemory-Fehlers notwendig.

Ein Blick in die Oracle-Dokumentation

The concurrent collector will throw an OutOfMemoryError if too much time is being spent in garbage collection: if more than 98% of the total time is spent in garbage collection and less than 2% of the heap is recovered, an OutOfMemoryError will be thrown. This feature is designed to prevent applications from running for an extended period of time while making little or no progress because the heap is too small. If necessary, this feature can be disabled by adding the option -XX:-UseGCOverheadLimit to the command line.

The policy is the same as that in the parallel collector, except that time spent performing concurrent collections is not counted toward the 98% time limit. In other words, only collections performed while the application is stopped count toward excessive GC time. Such collections are typically due to a concurrent mode failure or an explicit collection request (e.g., a call to System.gc())

Im zweiten Absatz wird deutlich: GCTimeLimit funktioniert nicht gut bei parallelen Collector.

Defaults für GCHeapFreeLimit auswählen

Die resultierenden Werte können von Applikation zu Applikation leicht variieren, daher sollte zunächst ein einfacher Test definiert werden. Zudem sollten GC Logging Flags hinzugefügt werden. Artiom Gourevitch hat für seine Applikation folgende Flags hinzugefügt:

  • -XX:+PrintGCDetails
  • -XX:+PrintGCDateStamps
  • -XX:+PrintTenuringDistribution
  • -Xloggc:/root/gc.log
  • -XX:+HeapDumpOnOutOfMemoryError 
  • -XX:HeapDumpPath=/root/dumps

Er erhält folgende Ausgaben:

[Full GC [PSYoungGen: 290112K->33213K(308672K)] [PSOldGen: 655359K->655359K(655360K)] 945471K->688573K(964032K)]

Nach wenigen Minuten reagiert die Anwendung nicht mehr:

[Full GC [PSYoungGen: 290112K->213269K(308672K)] [PSOldGen: 655359K->655359K(655360K)] 945471K->868629K(964032K)]

Wie auch die Oracle-Dokumentation formuliert, benötigt die jüngste Generation der Collection keine Garantie für die vollständige Förderung aller Live-Objekte. Aufgrund fehlgeschlagener Aktionen sind viel mehr referenzierte Objekte als bei der jüngsten Generation zu erwarten. Um weniger False-Positive zu erhalten, geht Gourevitch davon aus, dass, wenn 1/3 des jüngsten Speicherplatzes Müll ist, der alte voll ist und das System somit mittels GC angetrieben wird.

Daher rät er bei einer ähnlichen Applikation zu einem Verhältnis von 200/950 und damit zu einem GCHeapFreeLimit von 20 (-XX: GCHeapFreeLimit = 20).

Geschrieben von
Marja-Liisa Jöckel
Kommentare

Schreibe einen Kommentar

Deine E-Mail-Adresse wird nicht veröffentlicht.