JDK Mission Control (JMC): JFR-Aufzeichnungen auswerten

JDK Mission Control (JMC) ist die grafische Oberfläche für den Java Flight Recorder (JFR). JMC öffnet .jfr-Dateien oder verbindet sich mit laufenden JVMs und startet dort Aufzeichnungen. Seine „Automated Analysis“ prüft eine Aufzeichnung gegen 68 Regeln und sagt dir, wo du zuerst hinsehen solltest.

JMC ist nicht Teil des JDK, du musst es separat herunterladen. In älteren Texten, etwa in JEP 283, heißt es noch Java Mission Control – gemeint ist dasselbe Werkzeug.

Im Artikel über den Java Flight Recorder habe ich eine Aufzeichnung mit dem Kommando jfr ausgewertet und darin fünf Probleme gefunden. Hier werte ich eine Aufzeichnung desselben Programms in JMC aus.

In diesem Artikel erfährst du,

• wo du JMC herunterlädst und mit welchem Java du es startest,
• wie du eine Aufzeichnung öffnest oder an einer laufenden JVM startest,
• wie die Oberfläche von JMC aufgebaut ist,
• was die Automated Analysis in der Aufzeichnung findet – und was nicht,
• wie du mit der Seite „Method Profiling“ und dem Flame Graph die CPU-Last findest,
• wie du mit den Seiten „Memory“ und „Live Objects“ Allokationen und ein Speicherleck findest,
• wie du mit den Seiten „Lock Instances“, „Socket I/O“ und „Threads“ Wartezeiten findest,
• wie du mit der Seite „Exceptions“ Exceptions als Kontrollfluss erkennst,
• ob der Garbage Collector die Anwendung bremst,
• wie du im Event Browser eigene Events findest,
• was die JMX Console an einer laufenden JVM zeigt,
• wann du jfr nimmst und wann JMC.

Alle Screenshots stammen aus JMC 9.1.2 unter Linux, die ausgewertete Aufzeichnung aus Java 27.

Das Beispiel: eine Aufzeichnung der Bestellverarbeitung

Ich verwende das Beispielprogramm aus dem Artikel über den Java Flight Recorder. Acht Worker-Threads erzeugen zufällige Bestellungen und verarbeiten sie. Für jede Bestellung

1. liest das Programm die Menge aus einem Textfeld,
2. prüft es, ob das Produkt auf einer Sperrliste steht,
3. fragt es die Versandkosten per HTTP bei einem Versanddienst ab,
4. holt es die nächste Rechnungsnummer,
5. setzt es den Text der Rechnung zusammen,
6. und schließlich legt es die Rechnung in einem Cache ab.

Fünf dieser Schritte sind absichtlich ungeschickt geschrieben – so, wie man sie in gewachsenem Code findet. Das sind die fünf Probleme, die wir im Folgenden mit JMC suchen:

• Mengen mit Einheit, z. B. "2 pcs", lösen beim Parsen eine NumberFormatException aus.
• Die Sperrliste ist eine ArrayList, die bei jeder Prüfung Element für Element durchsucht wird.
• Die Rechnungsnummer vergibt ein synchronized-Generator mit einem langsamen Datenbankzugriff.
• Der Rechnungstext entsteht durch String-Verkettung in einer Schleife.
• Der Cache hat keine Obergrenze.

Den Code und die Erklärung jeder Methode findest du im Abschnitt Das Beispiel in diesem Artikel des JFR-Artikels, den vollständigen Code im GitHub-Repository java-flight-recorder.

Die folgende Kommandozeile startet das Programm mit einer Laufzeit von 70 Sekunden und einer JFR-Aufzeichnung:

$ java -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints \
       -XX:StartFlightRecording:name=orders,settings=profile \
       -cp target/classes eu.happycoders.jfr.OrderProcessing 70

Nach 62 Sekunden habe ich die Aufzeichnung mit jcmd aus der laufenden JVM in eine Datei geschrieben:

$ jcmd 82930 JFR.dump name=orders filename=orders.jfr path-to-gc-roots=true
82930:
Dumped recording "orders", 2,7 MB written to:

<Pfad>/orders.jfr

Drei Optionen bereiten die Aufzeichnung auf die Auswertung vor:

• settings=profile: Die Profiling-Settings zeichnen mehr Events auf als die Standard-Settings, bei typischerweise etwa 2 % Overhead.
• -XX:+DebugNonSafepoints: Für das CPU-Profil liest der Flight Recorder mit den Profiling-Settings alle 10 ms die Stacktraces der Threads, die gerade Java-Code ausführen. Mit dieser Option landen diese Stichproben (Samples) bei der Methode, die tatsächlich lief, auch wenn der JIT-Compiler sie in ihren Aufrufer eingebettet (geinlined) hat. Wo die Stichproben ohne diese Option landen, zeigt der Abschnitt Wo verbraucht die Anwendung CPU-Zeit? des JFR-Artikels.
• path-to-gc-roots=true: Der Flight Recorder ermittelt für langlebige Objekte den Pfad von der GC-Root zum Objekt. Diesen Pfad zeigt JMC auf der Seite „Live Objects“. Dass der Flight Recorder den Pfad beim Dump aus der laufenden JVM für deutlich mehr Objekte findet als beim Beenden der JVM, zeigt der Abschnitt Was hält den Speicher fest? des JFR-Artikels.

JMC herunterladen und starten

JMC ist ein OpenJDK-Projekt, aber kein Bestandteil des JDK. Mehrere Anbieter bauen es aus dem Quellcode und bieten es zum Download an:

• jdk.java.net/jmc: Hier liegen die Builds des OpenJDK-Projekts für Linux, macOS und Windows.
• Adoptium: Die Eclipse-Organisation hinter Temurin vertreibt JMC unter dem Namen Eclipse Mission Control.
• Azul: Azul bietet JMC als Azul Mission Control an, früher Zulu Mission Control, in der aktuellen Version 9.1.2.
• BellSoft: BellSoft bietet als Liberica Mission Control nur die ältere Version 8.3 an, und nur für x86-64.

JMC ist selbst eine Java-Anwendung, gebaut auf der Eclipse Rich Client Platform. Die Version 9.1.2 vom Januar 2026 braucht zum Start Java 21 oder neuer.

Der Build von jdk.java.net bringt kein eigenes Java mit, sondern verwendet das Java, das im Pfad liegt. Nimm dafür ein JDK, kein reines Runtime-Image – sonst findet JMC die lokal laufenden JVMs nicht. Ein bestimmtes JDK wählst du mit der Option -vm und dem Verzeichnis des java-Kommandos:

$ jmc -vm $JAVA_HOME/bin

JMC zeichnet sich übrigens selbst auf: In seiner Konfigurationsdatei jmc.ini steht die Option -XX:StartFlightRecording=name=JMC_Default,maxsize=100m.

Eine Aufzeichnung öffnen

JMC liest eine Aufzeichnung auf zwei Wegen: aus einer .jfr-Datei oder direkt aus einer laufenden JVM.

Eine .jfr-Datei öffnen

Eine vorhandene .jfr-Datei öffnest du mit „File > Open File…“. JMC liest die Datei ein, wertet sie mit allen Regeln der Automated Analysis aus und öffnet sie in einem Editor-Tab.

Eine Aufzeichnung an einer laufenden JVM starten

Links im Fenster zeigt der JVM Browser alle JVMs, die auf dem Rechner laufen. Unter jeder JVM steht ein Knoten „Flight Recorder“. Mit einem Rechtsklick darauf und „Start Flight Recording…“ öffnest du den Wizard „Start Flight Recording“:

Im Wizard legst du folgende Einstellungen fest:

• Destination File und Name: Wohin JMC die Aufzeichnung schreibt und unter welchem Namen sie in der JVM läuft.
• Time fixed recording oder Continuous recording: Eine Aufzeichnung mit fester Dauer schreibt JMC nach Ablauf automatisch in die Datei und öffnet sie. Eine fortlaufende Aufzeichnung läuft so lange weiter, bis du sie stoppst.
• Event settings: Hier stehen die Vorlagen „Continuous - on server“ und „Profiling - on server“. Das sind die Settings default und profile des JDK unter ihren Anzeigenamen.

Die Daten einer fortlaufenden („continuous“) Aufzeichnung holst du dir mit einem Rechtsklick auf die Aufzeichnung im JVM Browser: „Dump whole recording“ schreibt die ganze Aufzeichnung in eine Datei, „Dump last part of recording“ nur die letzte Zeitspanne.

Die Oberfläche von JMC

Nach dem Öffnen von JDK Mission Control siehst du die folgende Oberfläche:

Links oben, neben dem JVM Browser, steht die Outline, ein Baum mit den Auswertungsseiten der Aufzeichnung:

• Automated Analysis Results: die Ergebnisse der 68 Regeln, mit denen JMC die Aufzeichnung automatisch prüft – mehr dazu im nächsten Abschnitt.
• Java Application: Threads, Memory mit der Unterseite Live Objects, Lock Instances, File I/O, Socket I/O, Method Profiling, Exceptions und Thread Dumps.
• JVM Internals: Garbage Collections, GC Configuration, GC Summary, Compilations, Class Loading, VM Operations und TLAB Allocations.
• Environment: Processes, Environment Variables, System Properties, Native Libraries, Agents und Recording.
• Event Browser: alle Events, sortiert nach Event-Typ.

Im Hauptbereich rechts oben steht die ausgewählte Auswertungsseite. Unter ihr zeigt die Ansicht Stack Trace die Stacktraces der Events, die du auf der Auswertungsseite ausgewählt hast, zusammengefasst zu einem Baum mit den Spalten „Samples“ und „Percentage“. Im Tab daneben zeigt der Flame Graph dieselben Stacktraces als Grafik. Beide behandeln wir weiter unten: die Ansicht „Stack Trace“ auf den Seiten „Memory“, „Lock Instances“ und „Exceptions“, der Flame Graph im Abschnitt Der Flame Graph.

Dieses Zusammenspiel ist der Kern der Arbeit mit JMC: Du wählst auf einer Auswertungsseite eine Zeile aus – z. B. eine Methode, eine Klasse, ein Lock –, und die Ansichten darunter zeigen dir, woher die zugehörigen Events kommen.

Automated Analysis: Was JMC von sich aus findet

Die Seite „Automated Analysis Results“ zeigt nach dem Öffnen die Ergebnisse der 68 Regeln, mit denen JMC jede Aufzeichnung automatisch prüft, gruppiert nach den Auswertungsseiten. Jede Regel vergibt einen Score von 0 bis 100:

• ab 75: eine Warnung,
• 25 bis 74: ein Hinweis,
• unter 25: in Ordnung.

Für die Aufzeichnung des Beispiels gibt JMC zwei Warnungen und vier Hinweise aus:

Regel	Score	Befund laut JMC
Java Blocking	99	Threads waren insgesamt 3 min 32 s an Locks blockiert, 10.223-mal an InvoiceNumberGenerator.
Inverted Parallelism	75	In 4 von 42 Garbage Collections kamen die GC-Threads zusammen auf weniger CPU-Zeit, als die Collection gedauert hat – sie haben also mehr gewartet als gearbeitet.
Heap Live Set Trend	74	Der Heap, der nach den Garbage Collections belegt bleibt, wächst um etwa 552 KiB pro Sekunde; JMC nennt einen Memory-Leak-Kandidaten.
Competing Processes	69	Auf dem Rechner liefen 996 andere Prozesse.
Allocated Classes	67	Am meisten allokiert wird byte[], meist über StringConcatHelper.newArray().
Thrown Errors	44	Es wurden 38 Errors geworfen, davon 35-mal ein NoSuchMethodError.

Drei der fünf Probleme des Beispiels findet die Automated Analysis also selbst:

• Der Lock um die Rechnungsnummer: „Java Blocking“ nennt die Klasse InvoiceNumberGenerator und die Wartezeit.
• Der Cache ohne Obergrenze: „Heap Live Set Trend“ meldet das wachsende sogenannte Live Set, also den Speicher, den nach einer Garbage Collection noch erreichbare Objekte belegen.
• Die String-Verkettung: „Allocated Classes“ führt über StringConcatHelper zur Verkettung, nennt aber nicht die Methode formatReceipt(), die letztendlich die häufigen StringConcatHelper-Aufrufe verursacht.

Zwei Probleme findet die Analyse nicht. Die Regel „Method Profiling“ meldet mit Score 7, sie habe keine Methode gefunden, deren Optimierung sich besonders lohnen würde – obwohl die Threads gut die Hälfte ihrer Rechenzeit in einer linearen Suche verbringen. Und die Regel „Thrown Exceptions“ bewertet 31,9 Exceptions pro Sekunde mit Score 0.

Die übrigen drei Befunde betreffen nicht das Programm:

• Inverted Parallelism und Competing Processes: Beide beschreiben den Rechner. Ich habe auf meinem Arbeitsrechner aufgezeichnet, auf dem nebenher fast tausend Prozesse liefen. Als mögliche Ursachen für „Inverted Parallelism“ nennt die Regel viel I/O oder zu wenig CPU für die GC-Threads – bei so vielen Prozessen ist das Zweite naheliegend.
• Thrown Errors: Die NoSuchMethodErrors wirft das JDK selbst, im Package java.lang.invoke beim Auflösen von Method Handles, nicht der Code des Beispiels.

Die Automated Analysis ist damit ein guter Startpunkt, aber kein Ersatz für den Blick auf die einzelnen Auswertungsseiten. Die folgenden Abschnitte gehen die fünf Probleme dort der Reihe nach durch.

Method Profiling: Wo verbraucht die Anwendung CPU-Zeit?

Die Seite „Method Profiling“ unter „Java Application“ wertet die Stichproben der Ausführung aus, die Events vom Typ jdk.ExecutionSample. Die Tabelle in der oberen Hälfte des folgenden Screenshots listet die Methoden, die zum Zeitpunkt einer Stichprobe ganz oben auf dem Stack standen, mit der Zahl der Stichproben („Count“) und ihrem Anteil („Percentage“).

Ganz oben steht String.equals() mit 314 von 946 Stichproben (33,2 %). ArrayList.indexOfRange() steht zweimal in der Tabelle, mit 100 und mit 76 Stichproben: JMC trennt eine Methode nach der Art ihres Frames. Welche Art eine Zeile meint, zeigt ihr Tooltip: Dort steht hinter der Methode „[INLINED]“ bei den 100 Stichproben und „[JIT_COMPILED]“ bei den 76.

Das Symbol vor dem Namen zeigt mit Form und Farbe die Sichtbarkeit der Methode:

• grüner Kreis: public,
• blaues Dreieck: package-private,
• rotes Quadrat: private,
• gelbe Raute: protected.

Ein kleiner gelber Blitz rechts oben am Symbol markiert Frames, die nicht interpretiert liefen, sondern kompiliert oder geinlined.

Eine JDK-Methode an der Spitze sagt noch nicht, welcher Code des Beispiels sie aufruft. Das zeigt der Tab „Predecessors“ unter der Tabelle: Für die ausgewählte Methode String.equals() klappt er die Aufrufer auf, Ebene für Ebene:

java.lang.String.equals(Object)
  java.util.ArrayList.indexOfRange(Object, int, int)
    java.util.ArrayList.indexOf(Object)
      java.util.ArrayList.contains(Object)
        eu.happycoders.jfr.OrderService.isBlocked(String)
          eu.happycoders.jfr.OrderService.process(Order)

Wählst du mehrere Methoden aus, steht jede davon als eigener Knoten auf der obersten Ebene des Baums. Wird eine Methode von verschiedenen Stellen aus aufgerufen, verzweigt sich der Baum: Unter ihrem Knoten stehen dann alle Aufrufer, jeder mit seiner Zahl an Stichproben, absteigend sortiert. Im folgenden Screenshot sind alle Methoden der Tabelle ausgewählt; aufgeklappt ist String.length(), das in seinen 6 Stichproben von vier verschiedenen Methoden aufgerufen wurde – dreimal von StringConcatHelper.stringSize() und je einmal von drei anderen Methoden:

Dabei fasst „Predecessors“ die Stichproben einer Methode über alle Frame-Arten hinweg zusammen: 315 Stichproben (33,3 %) für String.equals() und 176 (18,6 %) für indexOfRange(). Erst danach folgt mit formatReceipt() und 100 Stichproben eine Methode aus dem Beispiel.

Der Tab „Successors“ daneben zeigt umgekehrt, welche Methoden von der ausgewählten Methode aufgerufen werden, ebenfalls als Baum, der sich verzweigt. Er wertet aber immer nur eine Methode aus, auch wenn du mehrere Zeilen auswählst. Und die Zahl in seiner obersten Zeile ist in JMC 9.1.2 durch einen Fehler doppelt so hoch wie die Zahl der Stichproben: Für process() steht dort 1.532, obwohl process() nur in 766 Stichproben vorkommt. Die Zahlen in den Zeilen darunter stimmen.

Der Flame Graph

Der Flame Graph im Tab neben „Stack Trace“ zeigt alle Stacktraces der Stichproben auf einmal. Jeder Balken ist eine Methode; über ihr stehen die Methoden, die die darunter liegende Methode aufgerufen hat. Die Breite eines Balkens entspricht dem Anteil der Stichproben, in deren Stacktrace die Methode an dieser Stelle vorkommt.

Über OrderService.process() steht ein Turm, der breiter ist als alle anderen: OrderService.isBlocked(), darüber ArrayList.contains(), indexOf(), indexOfRange() und ganz oben String.equals(). Der Balken von isBlocked() umfasst 490 der 946 Stichproben, also 51,8 %: So oft stand isBlocked() im Stacktrace. Mehr als die Hälfte der Rechenzeit geht damit in die Prüfung gegen die Sperrliste.

Die Ursache steht im Code: blockedProducts ist eine ArrayList mit 200.000 Produktnummern, und contains() vergleicht die gesuchte Nummer der Reihe nach mit jeder davon. Ein HashSet dagegen würde ein Element über seinen Hashwert finden, mit einem einzigen Vergleich im Normalfall.

Der Unterschied zwischen Tabelle und Flame Graph: Die Tabelle zählt nur die oberste Methode jeder Stichprobe. In den 490 Stichproben mit isBlocked() war das jedes Mal eine JDK-Methode, 314-mal String.equals() und 176-mal indexOfRange() – deshalb taucht isBlocked() in der Tabelle der Seite „Method Profiling“ gar nicht auf. Der Flame Graph zeigt den ganzen Stacktrace und damit, welcher Code des Beispiels die teuren JDK-Methoden aufruft.

Bei großen Graphen hilft das Suchfeld der Ansicht: Es hebt alle Balken einer Methode hervor. Außerdem kannst du die Ansicht von „Flame Graph“ zu „Icicle Graph“ umschalten, bei dem der Graph von oben nach unten wächst, und du kannst den Graphen als PNG- oder JPEG-Bild speichern.

Memory: Welcher Code erzeugt die meisten Objekte?

Die Seite „Memory“ listet oben in einer Tabelle die allokierten Klassen, u. a. mit der Spalte „Total Allocation (%)“, dem geschätzten Anteil der Klasse an allen Allokationen. Darunter zeigt sie grafisch den Verlauf der Allokationen und des Heaps über die Zeit.

byte[] steht mit 88,2 % an der Spitze. Ein Byte-Array ist der Inhalt fast jedes Strings, also sagt die Klasse allein noch wenig. Den Code hinter der Allokation von Byte-Arrays zeigt die Ansicht „Stack Trace“, sobald du byte[] in der Tabelle auswählst. Der Pfad, den sie zeigt, beginnt so:

jdk.internal.misc.Unsafe.allocateUninitializedArray(Class, int)
java.lang.StringConcatHelper.newArray(int)
java.lang.StringConcatHelper.newArrayWithSuffix(String, int, byte)

Darunter folgen vier Frames, mit denen die JVM den Operator + für Strings ausführt – eine generierte Klasse String$$StringConcat und drei Frames aus java.lang.invoke –, und dann OrderService.formatReceipt(). Die Byte-Arrays entstehen also bei der String-Verkettung in formatReceipt().

Die Ansicht zeigt dabei immer nur einen Pfad. Wo sich die Stacktraces verzweigen, folgt sie dem Zweig mit den meisten Stichproben, hier also den meisten Allokations-Events – nicht dem Zweig mit den meisten Bytes. Die Verzweigungen erkennst du an den Symbolen und Farben: Ein einfacher Pfeil steht vor einem Frame, an dem alle Stichproben des Zweigs denselben Weg nehmen. Ein Pfeil mit Abzweig markiert den ersten Frame eines Zweigs, neben dem es weitere Zweige gibt – im Screenshot oben bei allocateUninitializedArray() und bei String$$StringConcat.concat(). Die Hintergrundfarbe wechselt mit jedem neuen Zweig zwischen Gelb und Weiß. Zu den anderen Zweigen wechselst du mit den Pfeiltasten links und rechts oder mit „Previous Frame Group“ und „Next Frame Group“ in der Werkzeugleiste der Ansicht.

Über alle Klassen gerechnet stammen 80,3 % der allokierten Bytes aus formatReceipt() – 1,82 von insgesamt 2,27 GB in 62 Sekunden. Diese Zahlen zeigt die Ansicht „Stack Trace“, wenn du drei Einstellungen änderst: In der Tabelle wählst du alle Klassen aus, im Kontextmenü der Ansicht stellst du „Group Stacktraces From“ auf „Thread Root“, und im Auswahlfeld oben rechts wählst du „Sample Weight“ statt „Samples“. Dann beginnt jeder Pfad beim Thread, und die Spalte „Sample Weight“ summiert die geschätzten Bytes. In der Zeile mit OrderService.formatReceipt() siehst du dann die 1,82 GB und die 80,3 %:

Die Ursache: formatReceipt() hängt jede Bestellposition mit += an den bisherigen Rechnungstext. Jede Verkettung erzeugt einen neuen String und kopiert dabei den ganzen bisherigen Text. Bei 50 bis 149 Positionen pro Bestellung wächst die kopierte Menge quadratisch mit der Zahl der Positionen. Ein StringBuilder hingegen würde den Text in einem Durchgang zusammensetzen.

Live Objects: Was hält den Speicher fest?

Der Heap-Verlauf auf der Seite „Memory“ (im Screenshot des vorigen Abschnitts) zeigt ein Sägezahnmuster: Der Heap wächst, bis eine Garbage Collection die nicht mehr erreichbaren Objekte entfernt. Achte einmal auf die Tiefpunkte des Sägezahns, also den Heap direkt nach jeder Garbage Collection: Sie steigen über die Laufzeit an – von 15,8 MB nach der vierten Garbage Collection kurz nach dem Start bis auf 47,5 MB nach der letzten, der 42. Collection. Dieser Anstieg ist das Live Set, das auch die Regel „Heap Live Set Trend“ gemeldet hat.

Welche Objekte da festgehalten werden, zeigt die Memory-Unterseite „Live Objects“. Sie wertet die Events vom Typ jdk.OldObjectSample aus: Stichproben von Objekten, die lange am Leben bleiben, mit dem Pfad von der GC-Root bis zum Objekt. Die Aufzeichnung des Beispiels enthält 188 solcher Stichproben.

Die Tabelle fasst die Pfade aller Stichproben zu einem Baum zusammen. Die Spalte „Count“ nennt, wie viele Stichproben unter einem Knoten liegen. Die Spalte „Description“ beschreibt bei den obersten Knoten die GC-Root, hier eine lokale Variable des Threads main. Wie wahrscheinlich ein Knoten ein Speicherleck festhält, schätzt JMC als „Relevance“. Den Wert zeigt eine ausgeblendete Spalte, die du im Kontextmenü unter „Visible Columns“ einblendest. Viel hilft die Relevance im Beispiel allerdings nicht: Den höchsten Wert, 2,99, bekommt die ArrayList der Sperrliste mit einer einzigen Stichprobe, die ConcurrentHashMap des Caches nur 0,95.

Der Baum zeigt zunächst nur die Klassen der Objekte auf dem Pfad. Die Namen der Felder, über die ein Objekt das nächste referenziert, blendest du über das Kontextmenü ein, mit „Object Formatting Options > Field“. Von den 188 Stichproben führen 178 über dieselbe Kette:

1. Das OrderService-Objekt referenziert über sein Feld receiptCache eine ConcurrentHashMap,
2. die ConcurrentHashMap referenziert über ihr Feld table ein Array von ConcurrentHashMap$Node-Objekten,
3. die Knoten referenzieren die Strings der Rechnungstexte,
4. und schließlich referenzieren die Strings ihre Byte-Arrays.

Das ist der Cache ohne Obergrenze: Das Programm legt jede Rechnung darin ab und entfernt nie eine. Abhilfe würde ein Cache mit einer Obergrenze oder mit einem Ablaufdatum für seine Einträge schaffen.

Lock Instances und Socket I/O: Worauf warten die Threads?

Die Seite „Method Profiling“ zeigt nur, wo die Threads rechnen. Den größten Teil ihrer Zeit warten die Worker-Threads im Beispiel aber – auf ein Lock oder auf das Netzwerk.

Lock Instances

Die Seite „Lock Instances“ listet die Klassen der Objekte, an deren Monitor Threads blockiert waren, mit den Spalten „Total Blocked Time“, „Distinct Threads“ und „Count“. Die Spalten „Maximum Blocked Time“ und „Average Blocked Time“ kannst du im Kontextmenü unter „Visible Columns“ einblenden. Im Beispiel steht dort eine einzige Klasse:

An InvoiceNumberGenerator waren die Threads 10.223-mal blockiert, zusammen 3 min 32 s, im Mittel 20,7 ms und höchstens 43,2 ms lang. Alle acht Worker-Threads stehen dort an, jeder rund 1.278-mal. Die Ansicht „Stack Trace“ führt zur Methode InvoiceNumberGenerator.next(), aufgerufen aus OrderService.process().

Die Methode next() ist synchronized und simuliert darin einen Datenbankzugriff von 5 ms. Mehr als 200 Rechnungsnummern pro Sekunde kann der Generator also nicht vergeben, und die acht Threads stehen Schlange. Abhilfe würde eine Sequenz in der Datenbank oder ein Generator schaffen, der Nummern blockweise reserviert. Die Rechnung dazu steht im Abschnitt Worauf warten die Threads? des JFR-Artikels.

Socket I/O

Die zweite Wartezeit zeigt die Seite „Socket I/O“. Sie gruppiert die Lese- und Schreibvorgänge nach Host, nach Port oder nach beidem. Im Beispiel gehen alle 10.238 Lesevorgänge an 127.0.0.1, also localhost, wo der simulierte Versanddienst läuft. Sie dauern im Mittel 20,7 ms und höchstens 54,4 ms, zusammen 3 min 32 s. Mittel- und Höchstwert stehen in den Spalten „Average I/O Time“ und „Maximum I/O Time“, die du wie bei „Lock Instances“ unter „Visible Columns“ einblendest.

Die 20 ms sind die Antwortzeit des Versanddienstes; beim Aufrufer lassen sie sich nicht beschleunigen. Wegfallen würde die Wartezeit mit einem Cache für die Versandkosten.

Die Zeitleiste der Threads

Wann ein einzelner Thread worauf gewartet hat, zeigt die Seite „Threads“. Sie zeichnet für jeden Thread eine Zeitleiste, auf der die Events des Threads als farbige Balken liegen.

Um den Takt der Worker-Threads zu sehen, blendest du mit dem Tabellensymbol oben rechts die Thread-Tabelle ein, wählst darin die acht Worker-Threads aus und grenzt unter „Filter Events“ den Zeitraum auf 400 ms ein:

Rot sind die Lesevorgänge („Socket Read“), beige ist das Warten auf das Lock („Java Monitor Blocked“). Welche Farbe zu welchem Event gehört, zeigt die Schaltfläche „Thread State Selection“.

Die grünen Abschnitte sind dagegen kein Event. Grün ist die Grundfarbe der Zeitleiste vom Start bis zum Ende des Threads; sie scheint überall dort durch, wo der Flight Recorder für den Thread kein Event mit einer Dauer aufgezeichnet hat. Im Beispiel rechnet der Thread in diesen Momenten, etwa in isBlocked() oder formatReceipt(), oder er schläft die 5 ms des simulierten Datenbankzugriffs in InvoiceNumberGenerator.next(). Dafür entsteht kein Event, denn die Aufzeichnung erfasst Thread.sleep() erst ab 10 ms.

Exceptions: Welche Exceptions fliegen?

Die Seite „Exceptions“ zeigt oben eine Tabelle, die du mit den Icon-Schaltern rechts oben „By Class“, „By Message“ oder „By Class and Message“ gruppierst, und darunter die Exceptions und Errors über die Zeit.

Nach Klasse gruppiert steht java.lang.NumberFormatException mit 1.977 Exceptions oben. Nach Meldung gruppiert zeigt sich, woran das Parsen scheitert: an Mengen mit Einheit, z. B. For input string: "2 pcs" mit 250 Exceptions. Die Ansicht „Stack Trace“ führt zur Methode parseQuantity(), die die NumberFormatException fängt und den Fallback-Wert 1 zurückgibt.

Eine Exception als Kontrollfluss ist teuer, denn jede Exception erzeugt einen Stacktrace. Ungültige Eingaben solltest du besser vor dem Parsen erkennen.

Garbage Collections: Bremst der GC die Anwendung?

Die Seite „Garbage Collections“ unter „JVM Internals“ listet jede Garbage Collection mit Spalten wie „Cause“, „Collector Name“, „Longest Pause“ und „Sum of Pauses“. Dazu zeigt sie auf einer Zeitachse den Heap, den Heap nach jeder Collection („Heap Post GC“), den Metaspace und die Pausen.

Im Beispiel liefen 42 Garbage Collections, alle vom Typ G1New mit der Ursache „G1 Evacuation Pause“. Die längste Pause dauerte 2,45 ms, alle Pausen zusammen 57,7 ms – bei 62 Sekunden Aufzeichnung sind das 0,09 % der Laufzeit. Den Garbage Collector zu optimieren lohnt sich hier also nicht.

Die Seite „Garbage Collections“ zeigt damit zweierlei: Die Pausen sind kurz, aber der Heap nach jeder Collection – das Live Set – wächst. Der wachsende Heap ist kein GC-Problem, sondern der Cache aus dem Abschnitt über Live Objects.

Der Event Browser: alle Events, auch die eigenen

Der Event Browser listet alle Event-Typen der Aufzeichnung in einem Baum, mit der Zahl ihrer Events, und zeigt die Events des ausgewählten Typs als Tabelle. Hier findest du auch eigene Events, im Beispiel das OrderEvent mit dem Namen eu.happycoders.Order. JMC zeigt es unter seinem Label „Order“ in der Kategorie „Uncategorized“, mit 10.232 Events – eines pro verarbeitete Bestellung. Wie du ein solches Event schreibst, steht im Abschnitt Eigene Events des JFR-Artikels. Am schnellsten findest du das Event mit dem Suchfeld über dem Baum:

Aus einer Auswahl von Event-Typen machst du mit „Create a new page using the selected event types“ eine eigene Auswertungsseite in der Outline – praktisch für Events, die von keiner der vorhandenen Auswertungsseiten ausgewertet werden.

Die JMX Console: live in die JVM schauen

Neben der Auswertung von Flight-Recorder-Aufzeichnungen enthält JMC eine JMX-Konsole. Du startest sie im JVM Browser mit einem Rechtsklick auf eine JVM und „Start JMX Console“. Sie zeigt keine Aufzeichnung, sondern Live-Daten der JVM:

• Overview: Diagramme zu CPU-Last und Heap.
• MBean Browser: alle MBeans der JVM mit ihren Attributen und Operationen.
• System, Memory und Threads: Systemdaten, Speicherbereiche und die laufenden Threads.
• Diagnostic Commands: dieselben Diagnose-Kommandos, die du auf der Kommandozeile mit jcmd aufrufst.

Für die Fehlersuche in einer Aufzeichnung brauchst du die JMX Console nicht. Sie ist das Werkzeug für den Blick in eine laufende JVM, etwa auf den Heap während eines Lasttests.

jfr oder JMC?

Beide Werkzeuge – jfr und JMC – lesen dieselbe Datei. Welches du nimmst, hängt davon ab, wo du arbeitest und was du suchst:

	jfr	JMC
Installation	Teil des JDK	separater Download, braucht Java 21
Bedienung	Terminal, auch per SSH auf dem Server	grafische Oberfläche
Ausgabe für andere Werkzeuge	JSON, XML	HTML-Report der Automated Analysis
Automatische Bewertung	✗	Automated Analysis
Aufrufer einer Methode	jfr print --stack-depth	Predecessors, Stack Trace, Flame Graph
Pfad zur GC-Root	jfr print, eine Kette pro Event	Live Objects, ein Baum über alle Ketten
Live-Verbindung zur JVM	jcmd	JVM Browser, JMX Console

Ich nehme jfr, wenn ich direkt auf dem Server arbeite, auf dem die Aufzeichnung entstanden ist, und ich eine konkrete Frage habe – etwa, welche Methoden die meiste CPU-Zeit verbrauchen. JMC nehme ich, wenn ich eine Aufzeichnung nicht kenne und erst einen Überblick brauche, oder wenn ich einem Problem durch die Stacktraces folge.

Zusammenfassung

JDK Mission Control (JMC) ist die grafische Oberfläche für den Java Flight Recorder. Du musst es separat herunterladen, z. B. von jdk.java.net oder von Adoptium, und startest es mit Java 21 oder neuer. JMC öffnet .jfr-Dateien, startet Aufzeichnungen an laufenden JVMs und enthält eine JMX-Konsole.

Die Automated Analysis hat in der Aufzeichnung des Beispiels drei der fünf Probleme gefunden: das Lock, den wachsenden Cache und – über die Klasse StringConcatHelper – die String-Verkettung. Die lineare Suche und die Exceptions als Kontrollfluss hat sie nicht gemeldet.

Die Auswertungsseiten haben alle fünf Probleme gezeigt:

• Method Profiling und Flame Graph: Mehr als die Hälfte der Rechenzeit geht in isBlocked(), eine lineare Suche in einer ArrayList mit 200.000 Einträgen; ein HashSet hingegen würde ein Element über seinen Hashwert finden.
• Memory: 80 % der allokierten Bytes entstehen bei der String-Verkettung in formatReceipt(); ein StringBuilder würde den Text in einem Durchgang erzeugen.
• Live Objects: Die Rechnungen bleiben in einem Cache ohne Obergrenze; er bräuchte eine Obergrenze oder ein Ablaufdatum für seine Einträge.
• Lock Instances: Alle acht Threads warten an einem Lock um einen langsamen Datenbankzugriff; Abhilfe würde eine Sequenz in der Datenbank oder ein Generator schaffen, der Nummern blockweise reserviert.
• Exceptions: Fast 2.000 NumberFormatExceptions in 62 Sekunden zeigen eine Exception als Kontrollfluss; ungültige Eingaben solltest du besser vor dem Parsen erkennen.

Meine Empfehlungen:

• Fang mit der Automated Analysis an, aber verlass dich nicht auf sie: Ein Score unter 25 heißt nicht, dass auf der zugehörigen Auswertungsseite nichts zu finden ist.
• Lies die Seite „Method Profiling“ im Flame Graph, nicht nur in der Tabelle – die Tabelle nennt meist eine JDK-Methode, der Flame Graph deinen Code.
• Zeichne für die Seite „Live Objects“ mit path-to-gc-roots=true auf, am besten per jcmd … JFR.dump aus der laufenden JVM.
• Prüf den Feldnamen im Referenzbaum von „Live Objects“, wenn ein Objekt mehrere Kinder hat; JMC 9.1.2 zeigt dort den Feldnamen des Kindes, das es zuerst eingehängt hat.
• Zeichne auf einem Rechner auf, der sonst wenig zu tun hat – sonst schlagen Regeln wie „Competing Processes“ wegen der Last anderer Prozesse auf dem Rechner an statt wegen deines Programms.