Java aktuell – Bernd Zuther – Canary-Releases mit der Very Awesome Microservices Platform

Immer mehr Unternehmen zerschlagen ihre Software-Systeme in kleine Microservices. Wenn das passiert, entstehen mehrere Deployment-Artefakte, was nicht nur das Deployment des Gesamtsystems komplexer macht. Um diese Komplexität beherrschen zu können und die Auslieferungsmöglichkeiten einer Software zu verbessern, ist der Einsatz von Werkzeugen zur Infrastruktur-Automatisierung unumgänglich.


Microservices and Conversion Hunting: Build Architectures for Changeability

To gain validated learning and reduce risk and uncertainty while developing new products, you have to bring each increment into production. Only information gathered from the behavior of real users with each increment ensures that you’ll build the right thing in the end. In this session, you’ll learn how you can stop building monolithic systems and start designing software based on microservices—each having its own lifecycle and being an independent deployment unit. You’ll get a pretty good idea of how to manage such distributed applications in production successfully as well. The presentation uses an online shop application based on microservices for a discussion of topics such as deployment and operational aspects such as monitoring and logging.

Folien:
slides/14_javaone/

Quellcode:
https://github.com/zutherb/AppStash/

Microservice – Deployment ganz einfach

Um veränderbare Software zu erhalten, die in kurzen Zyklen ausgeliefert werden kann, zerlegen immer mehr Unternehmen ihre Software-Systeme in kleine Microservices. Hat man seine Software in Microservices zerlegt, erhält man mehrere Deployment-Artefakte, was das Deployment des Gesamtsystems aber auch komplexer macht. Um diese Komplexität beherrschen zu können, ist der Einsatz von Werkzeugen zur Infrastrukturautomatisierung unumgänglich.

Wir schauen uns deshalb an einem Microservice-Architektur-Beispiel an, wie man Deployment-Pipelines mit verschiedenen auf Docker basierenden Werkzeugen, wie z.B. Kubernetes und Vamp, aufbauen und ein verteiltes System hochverfügbar und stressfrei betreiben kann.

Folien:
slides/11_ljugm/

Quellcode:
https://github.com/zutherb/AppStash/

Java aktuell – Bernd Zuther – Microservices und die Jagd nach mehr Konversion – das Heilmittel für erkrankte It-Architekturen

Die Software-Entwicklung begibt sich derzeit auf eine neue Evolutionsstufe: Fachabteilungen haben gelernt, mithilfe agiler Methoden Änderungen in kurzen Zyklen produktiv umzusetzen. Damit haben sie die Möglichkeit, Änderungen an einem Produkt mit echtem Benutzer-Feedback vermessen zu können und durch empirische Untersuchungen des Benutzerverhaltens fundierte Entscheidungen über neue Software-Funktionalitäten zu treffen. Dazu müssen aber die meisten IT-Architekturen erst einmal so auf Vordermann gebracht werden, dass einzelne Teile einer Software flexibel ausgetauscht und unabhängig voneinander ausgeliefert werden können.

Microservices und die Jagd nach mehr Konversion – Fluch oder Segen für den Entwickler

Softwareentwicklung wandelt sich derzeit: Es reicht nicht mehr Produktinkremente potenziell produktiv zu setzen, sondern Änderungen müssen produktiv gehen. Um in gesättigten Märkten noch Innovationen hervorzubringen und neues Wachstum zu generieren, arbeiten Fachabteilungen immer öfter mit Lean-Startup-Methoden. Eine Methode im Lean-Startup ist die Bildung von Hypothesen, die durch Tests validiert werden. Dazu wird Software in unterschiedlichen Varianten ausgespielt und dann beobachtet, wie Kunden auf eine Änderungen reagieren. Je nach Test-Ergebnis werden Teile der Software dann wieder entfernt oder angepasst. Somit ist es wichtig Software schnell an den an den Anwender zu bringen.

Software schneller in Produktion zu bringen, ist mit den meisten Softwarearchitekturen nicht so einfach. Häufig existieren monolithische Anwendungen, die kompliziert zu installieren sind und bei denen für kleine Änderungen die Koordination von vielen Teams nötig ist. Um Teile der Software zu entkoppeln und Koordinationsaufwand zwischen den Teams zu verringern, wird häufig vorgeschlagen eine Applikation in kleine Dienste zu zerlegen, oft kurz Microservice-Architektur genannt.

Wir sehen uns an Hand eines konkreten Beispiels an, wie man eine bestehende Architektur in eine Mircroservice-Architektur überführen kann und welche Konsequenzen dies auf technischer Ebene hat. Zum Beispiel führen Microservices zu mehreren Deployment Pipelines und man braucht Konzepte die unterschiedlichen Teile der Software auch schnell auf unterschiedlichen Rechner provisionieren zu können. Außerdem sollte man sich Gedanken zum Thema Logging und dem Monitoring im Betrieb machen, denn sonst kann der Betrieb eines solchen hochverteilten Systems schnell zur Qual werden.

Folien

slides/zuther/slides/02_bobkonf/index.html
Quellcode
https://github.com/zutherb/AppStash/
Artikel in der Java-Aktuell 02/2015

Deployment ganz einfach – Microservice Deployment mit Hilfe der Linux Paketverwaltung

Softwareentwicklung wandelt sich, anstatt Software für die nächsten Jahre zu planen, zu entwickeln und dann erst dem Kunden zu präsentieren, arbeiten Fachabteilungen oft mit kleinen Hypothesen. Diese Hypothesen werden mithilfe von A/B Tests direkt am Kunden validiert und kommen dann als neue Userstories in den Entwicklungsprozess. Damit werden schrittweise Unternehmensprozesse und bestehende Software optimiert. Durch dieses Vorgehen bauen Fachabteilung Software, die ihre Kunden wirklich wollen. Das stellt die IT-Abteilungen natürlich vor die Herausforderung öfter und schneller ausliefern zu müssen, um schneller von den Testergebnissen profitieren zu können und letztlich mehr Umsatz zu generieren.

Beispielsweise kann eine simple Änderung der Farbe eines Links in einem Online-Shop eine Konvertierungssteigerung von 20% auslösen. Ein solche Änderung ist relativ schnell umgesetzt, doch selbst mit Continuous Delivery und einer Deployment Pipeline kann, der Durchlauf bis in Produktion mehrere Stunden in Anspruch nehmen, was ziemlich viel Geld kosten kann. Es gibt deshalb Stimmen, die meinen, dass solche langen Durchlaufzeiten am architektonischen Aufbau der Anwendungen liegt.

Aufbau von Web-Anwendungen

Web-Anwendungen sind häufig aus den folgenden drei Teilen aufgebaut:

  • Einer Benutzerschnittstelle (z.B. HTML),
  • einer Datenbank und
  • einer Server-Komponente.

Die Server-Komponente kümmert sich um die Abarbeitung der HTTP Requests, führt die Domänenlogik aus, ließt und schreibt Daten aus/in die Datenbank, bestimmt welche Teile der  Benutzerschnittstelle ausgeliefert werden müssen. Jede Änderung in diesem System erfordert einen Build und ein Deployment einer neuen Version der kompletten Software. Solche Anwendungen werden auch Monolithen genannt.

Auch wenn Monolithen sehr erfolgreich sein können, gibt es eine steigende Anzahl von Leuten, die mit diesen Ansatz nicht zufrieden sind, weil man auch für kleine Änderungen sehr hohe Durchlaufzeiten bis in Produktion hat und die Entwicklungsteams nicht mehr richtig skalieren, da man immer wieder die komplexen und zeitaufwendigen Buildprozesse der Monolithen durchlaufen muss und Änderungen an der Software immer schwieriger werden. Außerdem skalieren Monolithen schlecht. Wenn man einen solchen Monolithen skalieren möchte, muss man immer die komplette Anwendung verteilen, auch wenn nur bestimmte Teile der Anwendung Performance-Probleme hervorrufen. 

Es gibt Stimmen, die meinen, dass die klassische Drei-Schichten nicht mehr gut genug skaliert, um kleine gewinnbringende Features schnell genug ausliefern zu können. Deshalb erfreut sich das Konzept der Microservice-Architektur immer größer Beliebtheit. Ziel ist es die Anwendung entsprechend ihrer Fachlichkeit zuzuschneiden und in kleine Services zu unterteilen, die getrennt von einander ausgeliefert werden können. Damit soll die Durchlauf eines Features bis in Produktion verringert werden.

Die Microservice-Architektur zerschneidet Anwendungen in eine Anzahl an Diensten. Diese Dienste sind eigenständig deploy- und skalierbar. Jeder Dienst stell eine abgrenzte Fachlichkeit bereit, kann in einer beliebigen Programmiersprache implementiert sein und von unterschiedlichen Teams bereitgestellt werden. Zerschneidet man eine Software in eigenständige Dienste erzeugt man natürlich eine Vielzahl an Deployment-Artifakten. Häufig hat der Betrieb aber schon Probleme mit dem Deployment einer einzelnen monolithischen Anwendung. Deshalb muss man einen Weg finden Abhängigkeiten besser aufzulösen, die für eine erfolgreiche Auslieferung benötigt werden.

Deployment von Web-Anwendungen

In der Regel werden Web-Anwendungen in einen Anwendungsserver aufgeliefert. Ein Anwendungsserver stellt einen Container dar,  der spezielle Dienste zur Verfügung stellt, wie beispielsweise Transaktionen, Authentifizierung oder den Zugriff auf Verzeichnisdienste, Webservices und Datenbanken über definierte Schnittstellen.

Um das Deployment in einem Anwendungsserver zu standardisieren gibt es das Web Archive oder das Enterprise Archive. Ein Web Archive ist ein Dateiformat, das beschreibt, wie eine vollständige Webanwendung nach der Java-Servlet-Spezifikation in eine Datei im JAR- bzw. ZIP-Format verpackt wird. Bei einem Enterprise Archive handelt es sich ebenfalls um eine Datei im JAR- bzw. ZIP-Format, die ein vollständiges Anwendungsprogramm – meist eine Webanwendung – gemäß dem Standard Java Platform, Enterprise Edition (Java EE) enthält. Leider reichen diese beiden Standards nicht aus, um alle Abhängigkeiten aufzulösen, die eine Anwendung für den fehlerfreien Betrieb benötigen.

Abhängigkeiten zwischen Anwendung und Anwendungsserver

Die Abbildung zeigt die Abhängigkeiten zwischen Anwendung und Anwendungsserver. Eine Anwendung hängt vom Anwendungsserver ab, da die Anwendung Bibliotheken und Infrastruktur des Anwendungsserver nutzt. Umgekehrt ist der Anwendungsserver aber auch von der Anwendung abhängig, da der Anwendungsserver für eine Anwendung speziell konfiguriert werden muss. Damit ist ein Anwendungsserver eigentlich Teil einer Anwendung und man sollte Anwendungsserver und Anwendung als eine Komponente sehen.

Benötigt eine neue Version der Anwendung auch einen neue Version des  Anwendungsserver gibt es für den Betrieb häufig viele manuelle Schritte auszuführen, weil diese Abhängigkeiten in eine WAR oder einem EAR nicht ausgedrückt werden können. Diese Abhängigkeiten werden dann oft textuell in Form eines Tickets beschrieben und wenn man Glück hat werden die Instruktionen vom Betrieb richtig ausgeführt. Ähnliches gilt bei Datenbankänderungen. Es wäre deshalb wünschenswert Deployment-Artifakte zu haben, die auch diese Abhängigkeiten ausdrücken können. Ein Beispiel für solche Deployment-Artifakte liefert Apple.

Deployment von Anwendungen über den App Store

IMG_1453Apple liefert pro Sekunde mehr als 800 Apps über den App Store aus (Quelle). Apple-typisch lädt man sich eine Anwendung herunter und nach einem Klick auf das Icon läuft die Anwendung immer sofort, ohne das der Benutzer noch irgend etwas machen muss.

Apple löst die Herausforderung eine Anwendung auszuliefern mit dem sogenannten Application Bundle. Native Mac OS X Applikationen sind mehr als nur eine einfache ausführbare Datei, auch wenn ein Benutzer im Finder immer nur ein einzelnes IcIMG_1449on sieht. Unter Mac OS X besteht eine Applikation Bundle aus einer Verzeichnisstruktur, die sowohl die ausführbaren Dateien als auch alle benötigen Ressourcen enthält, die von einer Applikation benötigt werden. Diese Struktur ist von Apple genau definiert.

Verzeichnis-Struktur eines Applikation Bundles
Verzeichnis-Struktur eines Applikation Bundles

Ein Application Bundle enthält die folgenden Verzeichnisse und Dateien:

  • Eine Info.plist Datei im Contents Verzeichnis, die wichtige Meta-Informationen enthält, die von Mac OS X benutzt werden, um die Anwendung zu starten. (“Java Dictionary Info.plist Keys”)
  • Außerdem sollte eine Datei mit dem Namen PkgInfo in dem Contents Verzeichnis enthalten sein. (“Data Type Registration”)
  • Die Icons, die im Dock und im Finder angezeigt werden, befinden sich im Resources Verzeichnis.
  • Im Resources Verzeichnis werden außerdem Dateien abgelegt, die für die Ausführung benötigt werden.
  • Im MacOS Verzeichnis befinden sich die ausführbaren Dateien.

Wenn man eine Anwendung im App Store veröffentlichen möchte, müssen alle Ressourcen, die von der Anwendung benötigt werden mit der Anwendung ausgeliefert werden. Ansonsten wird die Anwendung von Apple abgelehnt und kann nicht veröffentlich werden. Dieses Konzept scheint sich wunderbar zu eignen um einen Microservice auszuliefern. Meistens hat man in Produktion aber keine Apple Server. Deshalb wäre es wünschenswert ein alternativ Konzept dafür zu haben. Häufig werden Webanwendungen auf einen Linux-Server ausgeliefert. Daher hat die Anwendung noch eine zusätzliche Abhängigkeit zu Infrastruktur und diese Abhängigkeit kann man benutzen, um die Anwendung auszuliefern.

Linux-Paketverwaltung

Die meisten Linux Distributionen verfügen über eine Software-Paketverwaltung. Eine Software-Paketverwaltung ermöglicht die komfortable Verwaltung von Software, die in Paketform vorliegt. Dazu gehören das Installieren, Aktualisieren und Deinstallieren der Software.

Voraussetzung für Paket-Management ist, dass die zu installierende Software als entsprechendes Paket vorliegt. Ein solches Paket wird meistens von einem Betriebssystemanbieter erstellt, angeboten und gepflegt. Software wird meistens verteilt in unterschiedlichen Verzeichnissen des System installiert. Diese Verzeichnisse sind im Filesystem Hierarchy Standard definiert.

Änderungen, welche die Paketverwaltung zur Installation des Pakets am System vornehmen muss, werden von der Paketverwaltung aus dem Paket ausgelesen und umgesetzt. Erkennt die Paketverwaltung dabei, dass noch weitere Software für das Funktionieren benötigt wird (sogenannte Abhängigkeit, z. B. eine Programmbibliothek), aber noch nicht installiert ist, warnt sie entweder oder versucht, die fehlende Software mit den ihr zur Verfügung stehenden Mitteln, z. B. aus einem Repository, nachzuladen und vorweg zu installieren.

Konkrete Beispiele für Programme um Software-Pakete zu installieren sind:

  • Das Programm RPM, dass Pakete vom Typ *.rpm installieren und löschen kann  und
  • das Programm Dpkg, dass Pakete vom Typ *.deb installieren und löschen kann.

Beide können aber keine Abhängigkeiten auflösen, da sie keine Funktionen haben, um Software nachzuladen. Dies können höhere Schichten der Paketverwaltungen wie YUM, APT, pkg-get und andere. Mit YUM oder APT ist es aber somit möglich auch die Abhängigkeiten zwischen Anwendungsserver und Anwendung aus zu drücken. Da ich häufig Ubuntu verwende und ich deshalb mit Deb-Paketen besser vertraut bin, möchte ich diese im folgenden Besprechen. Die Konzepte für Rpm-Pakete sind allerdings ähnlich.

Aufbau ein Deb-Paket

Jedes Deb-Paket besteht aus drei Dateien, die mittels des UNIX-Kommandos ar oder dem debianspezifischen Kommando dpkg-deb entpackt werden können:

  • debian-binary: eine Textdatei mit der Versionsnummer des verwendeten Paketformats.
  • control.tar.gz: ein gepacktes Archiv, dass Dateien enthält, die zur Installation dienen oder Abhängigkeiten auflisten. Hier werden nur ein paar Beispiele aufgeführt. Weiterführende Beschreibungen dazu finden sich z. B. in der Offiziellen Debian FAQ zu .deb Paketen.
    • control enthält eine Kurzbeschreibung des Paketes sowie weitere Informationen, wie dessen Abhängigkeiten.
    • md5sums enthält MD5-Prüfsummen aller im Paket enthaltenen Dateien, um Verfälschungen erkennen zu können.
    • conffiles listet die Dateien des Paketes auf, die als Konfigurationsdateien behandelt werden sollen.
    • preinst, postinst, prerm, postrm sind optionale Skripte, die vor oder nach dem Installieren, Aktualisieren oder Entfernen des Pakets ausgeführt werden. Sie werden mit den Rechten des Nutzers root ausgeführt.
  • data.* Ist ein mit komprimiertes Archiv und enthält die eigentlichen Programmdaten mit relativen, beim Stammverzeichnis beginnenden Pfaden.

Integration in das Buildsystem

Mit jdeb gibt es eine Bibliothek, die einen Ant task und ein Maven Plugin bereitstellt um Debian Pakete zu erstellen. Diese Bibliothek ist Plattform unabhängig und baut Debian Pakete ohne die Installation von irgendwelchen zusätzlichen Tools. 

Natürlich gibt es auch ein Gradle-Plugin das  Debian Pakete baut. Das Plugin basiert auch auf jdeb und stellt eine Brücke zwischen jdeb und Gradle dar. Das folgende Listing zeigt die Verwendung des Plugins zusammen mit dem Application Plugin:

apply plugin: 'application'
apply plugin: 'pkg-debian'
debian {
    packagename = "product"
    publications = ['mavenStuff']
    controlDirectory = "${projectDir}/debian/control"
    changelogFile = "${projectDir}/debian/changelog"
    outputFile = "${buildDir}/debian/${packagename}_${version}.deb"

    data {
        dir {
            name = "${projectDir}/debian/data"
            exclusions = ["**/.DS_Store", "changelog"]
        }
        dir {
            name = "${buildDir}/debian-data/"
            exclusions = ["**/.DS_Store"]
        }
        file {
            name = "${projectDir}/src/main/resources/application.conf"
            target = "etc/product/application.conf"
            mapper {
                fileMode = "755"
            }
        }
    }
}

task prepareDeb {
    dependsOn installApp

    copy {
        from "${buildDir}/install/"
        into "${buildDir}/debian-data/usr/share/"
    }
}

Zusammenfassung

Die Microservices-Bewegung erscheint auf den ersten Blick, wie das reaktive Manifest der Fachabteilung. Durch das parallele Bearbeiten von Fachlichkeiten kann das vorher monolithische Deployment von Anwendungen parallelisiert werden und die IT Abteilung schneller liefern. Dadurch erzeugt man aber eine Vielzahl an Deployment-Artifakten, die gemanagt werden müssen. Häufig ist ein monolithisches Deployment aber schon schwer genug. Da sehr viele Abhängigkeiten existieren. Sehr oft werden Anwendungen auf Linuxsystemen ausgeliefert. Diese Abhängigkeit zur Infrastruktur kann man aber auch ausnutzen, in dem man die Paketverwaltung der Linuxsysteme nutzt, um die Anwendungen auszuliefern, man baut dann nicht einfach nur ein Web Archive (WAR Dateien), sondern liefert ein Linux-Paket aus, darin ist alles enthalten, was ein Dienst benötigt, um ordnungsgemäß ausgeführt werden zu können. Die Paketverwaltung löst dann alle Abhängigkeiten auf, damit eine Anwendung/Dienst läuft und führt alle nötigen Schritte zur Installation der Software automatisiert aus. Damit erhält man auf den Linuxsystemen ein Apple ähnliches Deployment und kann sich eine Art App Store in Form eines Repository aufbauen, das die Auslieferung von Software stark vereinfach. Theoretisch ist durch dieses Vorgehen möglich seinen kompletten IT-Stack einfach nur mit einen Befehl auszuliefern , führt man z.B. „apt-get upgrade“ aus, werden alle  Pakete wenn möglich auf verbesserte Version aktualisiert.

devops2

Java Profiler – Marke Eigenbau mit Elasticsearch, Logstash und Kibana (ELK Stack)

In meinen Beitrag “OutOfMemoryError: Java Heapdump Analyse – Was tun? Wenn die Produktion spinnt!” werden verschiedene Werkzeuge genannt, mit denen man eine Java-Anwendung überwachen kann. VisualVM und JConsole sind hervorragende  Werkzeuge, die einem Software Ingenieur Einblick in eine einzelne laufende Applikation geben.

VisualVM ermöglicht es zwar Snapshots von Anwendungsmetriken, wie Speicherverbrauch, CPU-Auslastung aufzunehmen, aber man muss diese Snapshots  händisch erstellen, tut man das nicht sind alle Daten weg, wenn man VisualVM beendet. Außerdem muss VisualVM  zur Aufzeichnung der Daten die ganzen Zeit parallel zur Anwendung laufen. Wenn VisualVM gerade nicht läuft, dann werden logischerweise auch keine Daten gesammelt. Meistens hat man in modernen Web-Architekturen auch nicht nur einen Anwendungsserver und gerade für die Überwachung und Aufzeichnung eines kompletten Clusters ist VisualVM nur bedingt geeignet, hier braucht man schnell kommerzielle Lösungen, wie AppDynamics oder NewRelic.

VisualVM

Abbildung 1: VisualVM – Laufzeitmetriken während eines Lasttests

Ein anderes Problem ist, dass man Laufzeitmetriken nur schwer mit Logdaten korrelieren kann, da es für unterschiedliche Probleme in den meisten Unternehmen auch unterschiedliche Lösungen gibt, z.B. NewRelic zum Aufzeichnen von Laufzeitmetriken einer Anwendung und Splunk für die Logdateianalyse. Man muss also ständig zwischen den unterschiedlichen Software-Lösungen  hin und her springen und ist selbst dafür verantwortlich seine Zeiteinstellungen in beiden Anwendungen zu synchronisieren, was bei komplexeren Zeitreihenanalysen lästig ist. Somit kann es schwer fallen das Zugriffsprotokoll mit dem Ansteigen des Speichers oder der CPU-Auslastung in Beziehung zu bringen. Gerade bei plötzlich auftretenden java.lang.OutOfMemoryError wäre es wünschenswert, wenn man Laufzeitmetriken mit den Aktivitäten auf der Webseite korrelieren könnte.

Daraus ergeben sich die folgenden funktionalen Anforderungen an eine Software Lösung zur Laufzeit-Überwachung einer Anwendung:

  • Laufzeitdaten einer Anwendung sollen kontinuierlich automatisch gesammelt werden,
  • Logdaten sollen ebenfalls automatisch kontinuierlich gesammelt werden,
  • Laufzeitdaten und Logdaten von mehren Server müssen korreliert werden können.

Im meinem letzten Beitrag „Splunk – Marke Eigenbau mit Elasticsearch, Logstash und Kibana (ELK Stack)“ wird der ELK Stack vorgestellt, um Logdaten sammeln und analysieren zu können. Mit Kibana werden die gesammelten Logdaten visualisiert und ausgewertet. Eine interessante Frage ist nun: Kann man den ELK Stack auch benutzen, um seine Java-Anwendung zu überwachen. Dann wären alle drei Anforderungen an Software-Lösung zur Laufzeit-Überwachung einer Anwendung auf einen Schlag erfüllt.

Die Frage, ob man den ELK Stack auch zum Überwachen von Java-Anwendungen benutzen kann, wird in diesem Beitrag beantwortet, in dem wir einen einfachen Java-Profiler bauen, der auf dem ELK Stack basiert. Ziel ist es den Speicherverbrauch eines Anwendungsserver-Cluster mit dem ELK Stack zu  überwachen und mit Logdaten korrelieren zu können. Betrachten wir also zunächst, welche Möglichkeiten in der Java-Laufzeitumgebung existieren, um das Laufzeitverhalten von Software zu messen.

Java Profiling

Profiler sind Werkzeuge, mit denen sich das Laufzeitverhalten von Software analysieren lässt. Es gibt unterschiedliche Problembereiche in der Softwareentwicklung, die durch ineffiziente Programmierung ausgelöst werden. Ein Profiler hilft einem Software Ingenieur durch Analyse und Vergleich von laufenden Programmen die verschiedensten Problembereiche aufzudecken. Daraus kann man Maßnahmen zur strukturellen und algorithmischen Verbesserung des Quellcodes ableiten. Beispielsweise kann das Ziel eines Profiling das Aufspüren von Performance-Bottenecks oder eines Memory-Leaks sein, die anschließend beseitigt werden müssen.

Die JVM ist der Teil der Java-Laufzeitumgebung, der für die Ausführung des Bytecodes verantwortlich ist. Während der Bytecode-Ausführung gibt es bestimmte Laufzeitmetriken, die gemessen werden können. Beispiele für Laufzeitmetriken sind der Speicherverbrauch, die Anzahl von laufenden Threads oder die CPU Auslastung.

Abbildung 2 zeigt die Java Memory Architektur der Oracle HotSpot Implementierung der JVM und die JVM-Parameter, mit denen man die Speicherverwaltung beeinflussen kann. Young und Old Generation bilden zusammen den Heap. Daneben steht die Permanent Generation, die man seit JDK8 auch Metaspace nennt. In allen genannten Bereichen kann der Speicher ausgehen, schließlich handelt es sich dabei um eine physikalisch begrenzte Größe. Geht der Speicher in Heap oder Metaspace aus, dann kommt es zum  sogenannten OutOfMemoryError.

Java Heap
Abbildung 2: Java Speicher Unterteilung

In der Java-Welt gibt es die folgenden beiden Spezifikationen, die sich u.a. damit beschäftigen die Java Memory Architektur zu überwachen können: JSR-174: Monitoring and Management Specification for the Java Virtual Machine und JSR-163: Java Platform Profiling Architecture. JSR-174 definiert Anforderungen an ein JVM Monitoring- und Managementsystem. Der JSR-163 definiert nicht nur Schnittstellen, die von JSR-174 benötigt werden, sondern stellt auch Referenz-Implementierungen und Test-Werkzeuge bereit, um Java-Anwendungen überwachen, fern steuern und messen zu können. Seit JDK5 sind die beiden JSRs in der Laufzeitumgebung integriert (Quelle). Beispiele für eine  Schnittstelle und Referenz-Implementierung zur Überwachung der Java Memory Architektur sind die Schnittstelle java.lang.management.MemoryPoolMXBean und die Klasse java.lang.management.MemoryUsage.

Die JVM besitzt eine automatische Speicherverwaltung und benutzt den Heap zum Allokieren von neuen Objekten, der wiederum aus mehreren Speicherbereichen besteht. Außerdem besitzt die JVM den sogenannten Non-Heap Memory in dem sich das sogenannte Method Area befindet, in dem sich die geladenen Klassen befinden. Daraus resultieren mehre Memory Pools. Ein Instanz der Management-Schnittstelle MemoryPoolMXBean repräsentiert also immer einen spezifischen Memory Pool, wie z.B Old Generation oder Eden Space. In Oracle HotSpot Implementierung findet man alle in Abbildung 2 dargestellten Memory Pools wieder. Auf alle Instanzen (sun.management.MemoryPoolImpl) der unterschiedlichen Memory Pools kann man mit der ManagementFactory.getMemoryPoolMXBeans() zugreifen.

Mit der Methode  getUsage() bekommt man die geschätzte Speichergröße des aktuellen Memory Pools. Für einen Memory Pool, der vom einem Garbage Collector bereinigt wird, gilt das die Speichergröße sowohl reachable als auch unreachable Objekte beinhaltet.

Die Klasse MemoryUsage beinhaltet die folgenden vier Werte:

WertBeschreibung
initrepräsentiert die initiale Speichermenge in bytes, die während des Startvorgangs der JVM allokiert wird. Dieser Wert kann auch undefined sein.
usedrepräsentiert den aktuellen Speicherverbrauch in bytes.
committedrepräsentiert den maximalen Speicherverbrauch, der von der JVM ohne Speicherumstrukturierung garantiert wird. Dieser Wert kann sich über die Laufzeit hinweg ändern.
maxrepräsentiert maximalen Speicherverbrauch, der von der JVM allokiert werden kann.

Ähnliche Management-Beans gibt es auch zum Abfragen von anderen Laufzeitmetriken, wie Anzahl an laufenden Threads oder geladenen Klassen. Laufzeitmetriken, die nicht in der java.lang.management API enthalten ist, kann man selbst implementieren. Dazu gibt es die java.lang.instrument API, damit ist es z.B. auch möglich die Laufzeit von Methoden zu messen, in dem man den Bytecode eine Klasse verändert. Dazu verwendet man einen sogenannten Java-Agenten. Diese API ist die Grundlage für viele kommerzielle Profiler und wird üblicherweise als JAR-Datei aufgeliefert. Das folgende Listig zeigt einen Java-Agenten und wie man den Bytecode einer Klasse mit Javassist umschreiben kann, um nach jeden Methoden-Aufruf die Ausführungzeit der Methode in der Konsole ausgegeben wird:

public class AppStashAgent {
    public static void premain(String agentArguments, Instrumentation instrumentation) {
         instrumentation.addTransformer(new ClassFileTransformer() {
            @Override
            public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined, ProtectionDomain protectionDomain, byte[] classfileBuffer) throws IllegalClassFormatException {
                byte[] result = new byte[0];

                try {
                    String dotClassName = className.replace('/', '.');

                    ClassPool cp = ClassPool.getDefault();
                    CtClass ctClazz = cp.get(dotClassName);

                    for (CtMethod method1 : ctClazz.getDeclaredMethods()) {
                        method1.addLocalVariable("elapsedTime", CtClass.longType);

                        method1.insertBefore("elapsedTime = System.nanoTime();");
                        method1.insertAfter(" { elapsedTime = System.nanoTime() - elapsedTime; "
                                + "System.out.println(\" Method elapsedTime = \" + elapsedTime);}");
                        result = ctClazz.toBytecode();

                    }

                } catch (Throwable e) {
                    e.printStackTrace();
                }
                return result;
            }
        });
    }
}

Die meisten Java-Profiler geben zwar einen detaillierten Einblick in eine Anwendung. Es kann aber vorkommen, dass man einen  Profiler nicht produktiv Betrieb benutzen kann. Das kann daran liegen, dass dieser Profiler entweder das Java Virtual Machine Profiling Interface (JVMPI) oder das Java Virtual Machine Tool Interface (JVMTI) zum Sammeln von Daten benutzt.  Die Verwendung der JVMPI oder JVMTI kann dazu führen, dass sich die Ausführungszeit der Anwendung verlangsamt.

In diesem Fall erzwingt das Vorhandensein eines Agenten, dass der gesamte Bytecode einer Klasse immer von der Festplatte geladen wird, da der Bytecode nach dem Laden der Klasse verändert wird. Um einen solchen Profiler trotzdem benutzen zu können, muss man aufwändig produktionsnahe Lastsenarien mit Lasttest-Werkzeugen wie JMeter oder Gatling simulieren.

Eine Alternative zum klassischen Profiling ist die manuelle Messung der Ausführungszeit im Quellcode, die in eine Logdatei geschrieben wird. Abhängig von der Größe des Entwicklungsteams und Anwendung kann das Schnell zum Wartungsalptraum werden, da man den Quellcode mit dem Messcode verschmutzt. Um den Quellcode nicht zu verschmutzen, existieren Frameworks wie JETM. JETM betrachten wir im Folgenden, um ein besseres Verständnis darüber zu bekommen, welche Möglichkeiten und Konzepte existieren, um eine Anwendung alternativ als mit einem Agenten zu messen.

Java Execution Time Measurement Library (JETM)

Mit Java Execution Time Measurement Library (JETM) kann ein Software Ingenieur die Ausführungsgeschwindigkeit seiner Anwendung bis auf Methoden-Ebene messen. In einer Spring-Anwendungen kann mit JETM die Ausführungsgeschwindigkeit sogar messen werden, ohne eine Zeile Quellcode anzufassen. JETM benutzt dann Spring AOP und generiert dynamische Proxies zum Messen der Spring-Beans. JETM ist sehr einfach zu benutzen, man muss nur die JETM-JARs auf dem ClassPath packen und die Konfiguration der Anwendung entsprechend anpassen. Das folgende Listing zeigt, was man in der web.xml einer Web-Anwendung konfigurieren muss, um mit JETM die einzelnen Requests einer Anwendung zu messen.

<servlet>
    <servlet-name>performanceMonitor</servlet-name>
    <servlet-class>etm.contrib.integration.spring.web.SpringHttpConsoleServlet</servlet-class>
    <load-on-startup>1</load-on-startup>
</servlet>
<servlet-mapping>
    <servlet-name>performanceMonitor</servlet-name>
    <url-pattern>/performance/*</url-pattern>
</servlet-mapping>

<filter>
    <filter-name>performance-monitor</filter-name>
    <filter-class>
      etm.contrib.integration.spring.web.SpringHttpRequestPerformanceFilter
    </filter-class>
</filter>

<filter-mapping>
    <filter-name>performance-monitor</filter-name>
    <url-pattern>*</url-pattern>
</filter-mapping>

Die sogenannte JETM Console macht die Ergebnisse der Messungen verfügbar. In Abbildung 3 ist ein Bildschirmfoto der JETM Konsole zu sehen. Die JETM Console kann man entweder über ein Servlet in eine bestehende Web-Anwenundung integrieren werden oder man benutzt einen Standalone HTTP Console Server. Damit kann JETM sowohl für Macrobenchmarks als auch für Microbenchmarks benutzt werden.JETM Console

Abbildung 3: JETM Console

Aus den Betrachtungen über die java.lang.management, java.lang.instrument API und JETM ergeben sich noch zwei nicht funktionale Anforderungen an eine Software-Lösung zur Laufzeit-Überwachung einer Java-Anwendung:

  • Laufzeitdaten müssen auch in Produktion gesammelt werden können,
  • Das Sammeln von Laufzeitmetriken sollte über Konfiguration gestartet werden.

Betrachten wir nun im Folgenden, wie wir aus den definierten funktionalen und nicht-funktionalen Anforderungen ein Minimum Viable Product einer Software-Lösung zur Laufzeit-Überwachung bauen können.

Profiler auf ELK Stack Basis

Wie bereits erwähnt, ergeben sich die folgenden funktionalen und nicht-funktionalen Anforderungen an eine Software-Lösung zur Laufzeit-Überwachung einer Anwendung:

  • Laufzeitdaten einer Anwendung sollen kontinuierlich automatisch gesammelt werden,
  • Logdaten sollen ebenfalls automatisch kontinuierlich gesammelt werden,
  • Laufzeitdaten und Logdaten von mehren Server müssen korreliert werden können,
  • Laufzeitdaten müssen auch in Produktion gesammelt werden können,
  • Das Sammeln von Laufzeitmetriken sollte über Konfiguration gestartet werden.

Der ELK Stack ermöglicht es Logdaten automatisch zu sammeln und besteht aus den folgenden Komponenten:

  • Elasticsearch – für die Suche und Datenanalyse,
  • Logstash – zum Zentralisieren, Anreichern und Parsen von Logdaten,
  • Kibana – für die Daten Visualisierung.
logstash-architecture
Abbildung 4: ELK Stack Architektur

Abbildung 4 zeigt einen möglichen architektonischen Aufbau eines ELK Clusters. Das Cluster besteht aus drei Rechnern. Auf zwei Rechner sind Tomcat-Anwendungserver installiert. Von den Tomcat-Anwendungserver werden kontinuierlich Logdaten schreiben. Auf diesen beiden Rechnern ist deshalb ausserdem Logstash installiert. Logstash wirkt in der Installation als ETL-Tool und extrahiert die Logdaten, transformiert sie ggf., sodass die Logdaten in Elasticsearch geschrieben und von Elasticsearch indexiert werden können. Auf einem dritten Rechner ist ein Apache Webserver installiert, der als Webverzeichnis für Kibana dient, dass die von Logstash gesammelten Logdaten der beiden Tomcat-Anwendungsserver visualisiert. Für die Visualisierung nutzt Kibana die Rest-API von Elasticsearch.

Log = Timestamp + Data

Die Logdaten einer Anwendung bestehen immer aus einem Zeitstempel und irgendwelchen Daten. Die Laufzeitmetriken unserer Anwendung haben einen ähnlichen Aufbau. Zu einem bestimmten Zeitpunkt wird von der Anwendung eine bestimmte Menge des Speichers konsumiert.

Man kann sich die JVM, wie eine echte Maschine vorstellen, die mit Sensoren bestückt ist, diese Sensoren können periodisch zur Überwachung abgefragt werden. Ein solcher Sensor ist z.B. eine MemoryPoolMXBean-Instanz. Wenn man diese Sensordaten in eine Form bringt, die noch über einen Zeitstempel verfügt und in eine Datei schreibt, können die Logdaten von Logstash verarbeitet und in Elasticsearch überführen werden. Das folgende Listing zeigt eine mögliche JSON Struktur für unseren Speichersensor:

{
    "name": "PS Old Gen", 
    "type": "Heap memory", 
    "@timestamp": "2014-05-28T23:43:19", 
    "@version": "1",
    "init": 266862592,
    "used": 2417592, 
    "committed": 266862592, 
    "max": 2863661056 
}

Damit ist der ELK Stack schonmal in der Lage unsere funktionalen Anforderungen an eine Software-Lösung zur Laufzeit-Überwachung einer Anwendung zu erfüllen.  Wir haben aber noch nicht-funktionale Anforderungen definiert, u.a sollen die Laufzeitmetriken auch produktiv gesammelt werden können und das Sammeln über Konfiguration gestartet werden. Um losgelöst von Rest der Anwendung Laufzeitmetriken sammeln, bietet sich ein Runnable an. Ein Runnable kann über den ScheduledThreadPoolExecutor immer im einem Hintergrund der Anwendung laufen und kontinuierlich Laufzeitmetriken sammeln. Denn ScheduledThreadPoolExecutor kann man mit Spring einfach konfigurieren, wie wir später sehen werden. Das folgende Listing zeigt, wie man die MemoryUsage Werte der unterschiedlichen MemoryPoolMXBean in der Konsole im JSON-Format weglassen kann:

public class MemoryLoggingTask implements Runnable {
    private static final Logger LOGGER = LoggerFactory.getLogger(MemoryLoggingTask.class);
    private static final ObjectMapper OBJECT_MAPPER = new ObjectMapper();

    @Override
    public void run() {
        for (MemoryPoolMXBean memoryPoolMXBean : ManagementFactory.getMemoryPoolMXBeans()) {
            try {
                String message = memoryUsageAsJsonString(memoryPoolMXBean);
                LOGGER.info(message);
            } catch (IOException e) {
                LOGGER.error("Object could not converted to JSON String:", e);
            }
        }
    }

    private String memoryUsageAsJsonString(MemoryPoolMXBean memoryPoolMXBean) throws IOException {
        return OBJECT_MAPPER.writeValueAsString(buildMemoryUsageInfo(memoryPoolMXBean));
    }

    private MemoryUsageInfo buildMemoryUsageInfo(MemoryPoolMXBean memoryPoolMXBean) {
        return MemoryUsageInfo.builder()
                .name(memoryPoolMXBean.getName())
                .type(memoryPoolMXBean.getType().toString())
                .usage(memoryPoolMXBean.getUsage())
                .build();
    }
}

Die Frage ist nun: Ist unser MemoryLoggingTask schnell genug für den produktiven Einsatz? Abbildung 5 zeigt einen Microbenchmark der run-Methode, der mit JETM aufgezeichnet wurden ist. Die Methode wurde 130 mal aufgerufen und die Ausführungszeit braucht im Mittel 1ms. Was man in der Abbildung nicht sieht, ist das der Maximalwert bei ersten Aufruf erfolgt ist. Bei jeden weiteren Methoden wird ungefähr 150ns für die Ausführung benötigt. Damit spricht nichts gegen den produktiven Einsatz des MemoryLoggingTask.

JETM Console MemoryLoggingTask
Abbildung 5: MemoryLoggingTask Laufzeitverhalten

Die letzte nicht-funktionale Anforderung ist, dass das Sammeln von Laufzeitmetriken über Konfiguration gestartet werden sollte. Wie schon erwähnt, ist es mit Spring sehr einfach unseren MemoryLoggingTask im Hintergrund laufen zulassen. Das folgende Listing zeigt, was man dazu machen muss.

<bean id="appStashMemoryLogging" class="io.github.appstash.task.MemoryLoggingTask" />

<task:scheduled-tasks scheduler="appStashScheduler">
    <task:scheduled ref="appStashMemoryLogging" method="run" fixed-delay="1000"/>
</task:scheduled-tasks>

<task:scheduler id="appStashScheduler" pool-size="10"/>

Zusammenfassung

Wie haben in diesen Beitrag gesehen, dass man sich mit einfachsten Mitteln einen Profiler selber schreiben kann. Da Laufzeitmetriken auch als Zeitstempel mit Daten gesehen werden können, kann man diese Daten in eine Datei schreiben und mit einem Loganalysewerkzeug visualisieren. Abbildung 6 zeigt die Kibana Visualisierung vom Heap-Speicher neben VisualVM. Deutlich zu erkennen ist die kontinuierliche Garage Collection des Heaps.  Natürlich kann man das gleiche Konzept auch mit anderen Loganalysewerkzeugen, wie z.B. Splunk nutzen, um ähnliche Visualisierungen herzustellen.

Cluster-Heap-Analyse
Abbildung 6: Cluster-Heap-Analyse mit Kibana im Vergleich zu VisualVM

Um den kompletten Cluster, der in Abbildung 4 dargestellt ist, zu starten, muss man nur VirtualBox und Vagrant installieren. Danach kann man nur die folgenden drei Befehle ausführen. Das in Abbildung 6 dargestellte Dashbord befindet sich unter /appstash/external/Heap Memory Dashboard.

bernd@mbp ~$ git clone https://github.com/zutherb/AppStash.git appstash
bernd@mbp ~$ git checkout elk-example
bernd@mbp ~$ cd appstash/vagrant
bernd@mbp ~$ vagrant up

Auf die inAbbildung 4 im dargestellten Komponenten des ELK Stacks kann man über die folgenden Port Forwardings zu greifen:

  • Kibana – http://localhost:8000/
  • Elasticsearch – http://localhost:9200/
  • Applikation 1 – http://localhost:8080/pizza/
  • Applikation 2 – http://localhost:8081/pizza/

Splunk – Marke Eigenbau mit Elasticsearch, Logstash und Kibana (ELK Stack)

Wie man im meinen Beitrag „OutOfMemoryError: Java Heapdump Analyse – Was tun? Wenn die Produktion spinnt!“ sehen kann, hat Softwareentwicklung manchmal auch etwas mit Datenanalyse zu tun. Bei der Heapdump Analyse arbeitet man mit einer großen Menge  Objekten und leidet aus Dominatorbäumen Metriken ab, um potentielle Memory Leaks aufzuspüren. Die Heapdump Analyse ist aber nur ein Beispiel dafür, dass ein Software Ingenieur auch in der Lage sein muss Datenanalysen durchzuführen.

Die Logdateianalyse ist ein weiteres Beispiel für eine Datenanalyse, um die ein Software Ingenieur früher oder später nicht herum kommen wird. Spätestens wenn sein Softwareprodukt in Produktion  geht, muss die Logdateianalyse zum Handwerkszeug eines Software Ingenieur gehören, um Fehler schneller zu erkennen und schneller auf Fehlverhalten der Software reagieren zu können.

„Was man nicht messen kann, kann man nicht lenken.“
Peter F. Drucker

Gerade in verteilen Software-Architekturen stellt die Logdateianalyse keine geliebte Aufgabe dar. Denn diese Aufgabe hat häufig damit zu tun, dass man sich auf vielen unterschiedlichen Servern einloggen muss, um händisch die Logdateien zu durchsuchen.

In diesem Beitrag geht es, um die Logdateianalyse. Ich möchte den ELK Stack (Elasticsearch, Logstash, Kibana) als Alternative zu dem kommerziellen Werkzeug Splunk vorstellen, dass einem das händische durchsuchen von Logdateien auf verschiedenen Server abnimmt. Der ELK Stack besteht aus mehren Komponenten, die Logdaten sammeln, indexieren und mit einer grafischen Oberfläche für eine schnelle und gezielte Analyse verfügbar machen.

Betrachten wir aber zunächst, wie Logdateianalyse abläuft, wenn man kein dediziertes Werkzeug dafür benutzt und finden heraus, welche Anforderungen sich aus der händischen Logdateianalyse an ein Logdateianalyse-Werkzeug ergeben.

Logdateianalyse

Bei der Logdateianalyse werden Logdateien eines Computersystems während eines gewissen Zeitraumes nach bestimmten Kriterien durchsucht. Bei vielen Softwaresystemen werden die unterschiedlichsten Ereignisse mitprotokolliert. Beispielsweise finden sich heutzutage bei nahezu allen Webserver, bei vielen Datenbanken und Firewalls Logdateien. Je nach Art, Inhalt und Umfang der Aufzeichnung in den Logdateien können durchaus  verschiedene Schlüsse gezogen werden. Die Logdateianalyse kann z.B.  als Grundlage für Benutzerfreundlichkeitsanalysen dienen oder  Aussagen über den Erfolg einer Marketingaktion liefern.

Eine Logdatei enthält meisten ein automatisch geführtes Protokoll aller oder bestimmter Aktionen von Prozessen, die in einem Computersystem ablaufen. Deshalb wir eine Logdatei häufig auch als Protokolldatei bezeichnet. Das folgende Listing zeigt die Zugriffsprotokolldatei eines Tomcat Anwendungsserver, dass alle Anfragen auf dem Webserver protokolliert:

0:0:0:0:0:0:0:1 - - [18/May/2014:15:42:38 +0200] "GET /pizza/assets/img/Pizza/spaghetti-with-clams.jpg HTTP/1.1" 200 23875
0:0:0:0:0:0:0:1 - - [18/May/2014:15:42:38 +0200] "GET /pizza/assets/img/Pizza/tuna.jpg HTTP/1.1" 200 79792
0:0:0:0:0:0:0:1 - - [18/May/2014:15:42:39 +0200] "GET /pizza/productdetail/capricciosa?2-1.ILinkListener-otherUsersAlsoViewedProducts-products-3-product-productDetailLink HTTP/1.1" 302 -
|      Data       |          Timestamp             |                                                              Data                                     Data                            |

Bei den einzelnen Einträgen in dem Zugriffsprotokoll handelt es sich um  unstrukturierte Daten. Ein Mensch erkennt zwar höchstwahrscheinlich auf den ersten Blick auf welche Webseiten zugegriffen wurden ist, aber was bedeuten die letzten beiden Zahlen in den Zugriffsprotokoll? Die Erste, der beiden letzten Zahlen, könnte den Statuscode des HTTP-Response darstellen, der vom Server ausgeliefert wird. Bei der letzten Zahl könnte es sich um die übertragenen Bytes handeln. Diese Information wird allerdings für den Mensch nicht auf den ersten Blick ersichtlich, sondern muss in die Spezifikation der Logdatei nachlesen werden, um mit Sicherheit sagen zu können, dass es sich bei der letzten Zahl um die übertragenen Bytes handelt. Ein Computer kann diese Verbindung nicht automatisch herstellen. Ein solches Log-Format verhindert, dass man die Request mit Statuscode 200 einfach zählen kann. Man muss zuerst die Zeilen mit dem Statuscode 200 extrahieren und kann dann die Zeilen zählen.

Allgemein gilt, dass unstrukturierte Daten digitalisierte Informationen sind, die in einer nicht formalisierten Struktur vorliegen. Durch die nicht formalisierte Struktur können Computerprogrammen nicht über eine einzelne Schnittstelle aggregiert auf diese Daten zugegriffen.

Was man in den Zugriffsprotokoll aber auch sehen kann, ist das ein Log-Eintrag immer aus einem Zeitstempel (Timestamp) und Daten (Data) besteht. Gelingt es  die unstrukturierte Daten in eine zumindest semistrukturierte Form bringen, die Struktur Informationen enthält (z.B. JSON oder XML), dann kann man  Leistungskennzahlen benennen und errechnen, wie es in Abbildung 1 dargestellt ist, die verschiedene HTTP-Response Stati über die Zeit zeigt.

Was ist ein Log
Abbildung 1: Log = Timestamp + Data

Jetzt haben wir viel über eine einzelne Log-Datei gesprochen. Häufig bestehen moderne Web-Architekturen aus mehren Anwendungsservern. Auf den Anwendungsservern laufen auch mehrere Web-Anwendungen, die mit einer Vielzahl von Backendsystemen kommunizieren. Um nachvollziehen zu können, was bei Zusammenspiel der unterschiedlichen Softwarekomponenten eines Softwaresystems passiert, werden i.d.R auf den unterschiedlichen Anwendungsservern von den installierten Anwendungen Logdateien geschrieben.

bernd@mbp:/var/log/tomcat7$ ll
total 456
drwxr-x---  2 tomcat7 adm      4096 May 21 13:55 ./
drwxr-xr-x 12 root    root     4096 May 21 14:45 ../
-rw-r--r--  1 tomcat7 tomcat7 26547 May 21 14:45 catalina.2014-05-21.log
-rw-r--r--  1 tomcat7 tomcat 318574 May 21 14:45 catalina.out
-rw-r--r--  1 tomcat7 tomcat7  8825 May 21 14:45 localhost.2014-05-21.log
-rw-r--r--  1 tomcat7 tomcat7 17176 May 21 14:09 localhost_access_log.2014-05-21.txt
-rw-r--r--  1 tomcat7 tomcat7 65554 May 22 06:48 probe.log
bernd@mbp:/var/log/tomcat7$

Einen Blick in das Log-Verzeichnis des Tomcat-Anwendungsserver, zeigt, dass sich mehre Logdateien in dem Verzeichnis befinden. Mindestens mit den beiden Logdateien catalina.log und localhost_access_log.txt kann man immer rechnen. I.d.R gibt es aber noch viel mehr Logdateien in diesem Verzeichnis. Gehen wir der Einfachheit halber erst einmal nur von diesen beiden genannten Logdateien aus, dann hat man bei 10 Anwendungsservern schon 20 Logdateien, die bei der Logdateianalyse berücksichtigt werden müssen und ggf. alle durchsucht werden müssen, um ein Fehlverhalten des Softwaresystems besser verstehen zu können.

Ohne eine zentrale Logdaten-Speicherung bedeutet das häufig für einen Software Ingenieur, dass er sich auf 20 Servern über SSH anmelden musst und die Logdateien von Hand in der Konsole durchsuchen musst. Natürlich bietet die Unix-Shell eine Vielzahl an Programmen für die Datenanalyse, wie man in meinem Beitrag „Data Analysis with the Unix Shell“ sehen kann. Doch ist das händische Durchsuchen von Logdateien nicht sonderlich komfortabel und auch nicht wirklich schnell, da die unterschiedlichen Log-Files nicht indexiert sind und das Auffinden von Regulärer Ausdrücken in gigabyte–großen Logdateien schon eine Weile dauern kann.

Das folgende Listing verdeutlicht die Arbeit, die man machen muss, um Logdateien auf der Kommandozeile zu durchsuchen. Ziel ist es die Requests zu zählen, die erfolgreich bearbeitet wurden sind. In Zeile 4 ist ein Unix-Pipeline aus den beiden Unix-Befehlen grep und wc zu sehen. Mit dem Regex ‚“ 200 [0-9]‘ selektieren wir alle Zeilen in denen wir den Statuscode 200 finden. Diese Zeilen zählt uns dann das Kommando wc. Mit dieser Pipeline erhalten wir das Ergebnis 47 auf dem aktuellen Rechner, wenn wir das Ergebnis für einen gesamten Cluster haben wollen, dann müssen wir dieses Vorgehen auf allen anderen Rechnern im Cluster wiederholen und die einzelnen Ergebnisse entsprechend aggregieren.

bernd@mbp ~/tomcat/logs $ grep '" 200 [0-9]' localhost_access_log.2014-05-18.txt
0:0:0:0:0:0:0:1 - - [18/May/2014:15:42:34 +0200] "GET /pizza/assets/css/bootstrap.css HTTP/1.1" 200 129119
0:0:0:0:0:0:0:1 - - [18/May/2014:15:42:34 +0200] "GET /pizza/wicket/resource/com.comsysto.shop.ui.application.settings.AbstractJavaScriptLibrarySettings/jquery/jquery-1.9.1.min-ver-1400416490000.js HTTP/1.1" 200 92629
bernd@mbp ~/tomcat/logs $ grep '" 200 [0-9]' localhost_access_log.2014-05-18.txt | wc -l
      47

Fassen wir die Anforderungen an ein Logdateianalyse Werkzeug zusammen, die sich aus diesem Beispiel ergeben:

  • Unstrukturierte Daten sorgen dafür, dass es schwer fällt Leistungskennzahl zu benennen und zu errechnen. Anhand einer Leistungskennzahl soll der Fortschritt oder der Erfüllungsgrad hinsichtlich wichtiger Zielsetzungen gemessen werden.
    -> Ein Werkzeug zur Logdateianalyse muss es ermöglichen unstrukturierte Daten in eine strukturierte Form zu bringen, um Kennzahlen berechnen zu können.
  • Die Verteilung der Logdateien stellt ein Problem dar, wenn man Abfrage über den gesamten Datenbestand durchführen möchte.
    -> Alle Logdateien müssen an einer zentralen Stelle durchsucht werden können.
  • Außerdem benötigt man eine Abfragesprache, die bei der Suche nach Informationen hilft. Das Ergebnis einer Abfrage (Query) muss eine Teilmenge des zugrunde liegenden Informationsbestandes liefern.
    -> Es muss eine Abfrage Sprachen geben, mit der man gesamten Datenbestand schnell durchsuchen kann.

Splunk

Um dem Software Ingenieur die Möglichkeit zu geben verschiedene Logdateien an einer zentralen Stelle zu durchsuchen, gibt es eine kommerzielle Lösung namens Splunk. Splunk ist ein Log-, Monitoring- und Reporting-Tool für IT-Systemadministratoren. Es sammelt Logdateien, Leistungskennzahlen und weitere Daten von unterschiedlichen Applikationen, Servern und Netzwerkgeräten und indiziert sie in ein durchsuchbaren Repository. Mit Splunk lassen sich Grafiken, SQL-Reports und Warnmeldungen generieren. Splunk hilft, Störfälle zu erkennen und Log-Daten verschiedenster Systeme und Softwarekomponenten zueinander korreliert zu können. Dazu hat Splunk eine eigene Abfragesprache.

Splunk erfüllt somit unsere drei Anforderungen an Logdateianalyse Werkzeug. Der Preis von Splunk ist abhängig von der zu indexierenden Datenmenge pro Tag und startet bei  $4,500 für 1 GB/Tag für eine Splunk Enterprise Lizenz (Quelle).

Splunk
Abbildung 2: Splunk

Logdateien können aber erstaunliche Menge an Gigabytes produzieren und dann kann diese kommerzielle Lösung schnell sehr teuer werden, vorallen wenn man nur bestimmte Features wirklich nutzt. Häufig gibt es aber in vielen Organisationen nicht mal ein Logdateianalysewerkzeug und hohe Lizenzkosten können die Einstiegshürde zusätzlich vergrößern.  Eine alternative zu der kommerziellen Lösung Splunk ist der ELK Stack, der aus den folgenden Open-Source Komponenten besteht.

  • Elasticsearch – für die Suche und Datenanalyse,
  • Logstash – zum Zentralisieren, Anreichern und Parsen von Logdaten,
  • Kibana – für die Daten Visualisierung.

Elasticsearch

Elasticsearch ist eine hoch-skalierende Volltext-Suche, die auf Apache Lucene aufbaut. Außerdem stellt Elasticsearch eine REST-API  für das Suchen und Analysieren von Daten bereit.

# Index erstellen
bernd@mbp ~ $ curl -XPUT 'http://localhost:9200/twitter/'
{"acknowledged":true}                            # Document indexieren
bernd@mbp ~ $ curl -XPUT 'http://localhost:9200/twitter/tweet/1' -d '{
     "user" : "bernd",
     "post_date" : "2009-11-15T14:12:12",
     "message" : "trying out Elasticsearch"
 }'
{"_index":"twitter","_type":"tweet","_id":"1","_version":1,"created":true}
# nach Document suchen
bernd@mbp ~ $ curl -XGET 'http://localhost:9200/twitter/tweet/1'
{"_index":"twitter","_type":"tweet","_id":"1","_version":1,"found":true, "_source" : {
    "user" : "bernd",
    "post_date" : "2009-11-15T14:12:12",
    "message" : "trying out Elasticsearch"
}}

Elasticsearch erlaubt es mit einem Server anzufangen und später horizontal zu skalieren. Wenn man mehr Kapazität braucht, muss man einfach nur einen neuen Knoten hinzufügen. Elasticsearch reorganisiert dann das Cluster von selbst, um von der neuen Hardware zu profitieren.

Elasticsearch ist im ELK Stack als Backend zum Speichern, Indexieren von Dokumenten an zusehen, dass über eine REST-API leicht für analytische Anfragen zugänglich ist. Da Elasticsearch auf Lucene basiert, verfügt es außerdem über die Lucene Anfragesprache, mit der man indexierte Dokument selektieren kann und analytische Abfragen gestalten kann. Im Folgenden werden ein paar Lucene Abfragen gezeigt, die man zu selektieren von Dokumenten im Index benutzen kann (Dokumentation):

  • status:active – Status muss ‚active‘ beinhalten,
  • title:(bernd zuther) – Titel muss bernd oder zuther enthalten,
  • author:“Bernd Zuther“ – Author muss „Bernd Zuther“ vollständig enthalten,
  • status:[200 TO 299] – Status muss zwischen 199 und 300 liegen
  • status:200 AND  host:“app-server-node-1″ – Status gleich 200 und Host gleich ‚app-server-node-1‘
10.0.2.2 - - [23/May/2014:07:31:09 +0000] "GET /pizza/checkout?5-IResourceListener-header-home-logo HTTP/1.1" 200 23875

Die REST-API von Elasticsearch nimmt JSON-Dokumente entgegen. Wenn wir uns dann das Zugriffsprotokoll des Tomcat-Anwendungsservers erinnern, das Eingangs als Beispiel diente, dann heißt das, dass die Daten in einer Zeilen erst mal transformiert werden müssen, um sie an Elasticsearch schicken zu können. Zunächst muss eine semistruktuierte Form aus einer Zeile erzeugt werden, wie es im folgenden Listing dargestellt ist.

{
    "remoteHost": "10.0.2.2",
    "remoteLogname": "-",
    "user": "-",
    "request": "GET /pizza/checkout?5-IResourceListener-header-home-logo HTTP/1.1",
    "status": "200",
    "size": "29822",
    "@version": "1",
    "@timestamp": "2014-05-23T07:31:16.375Z",
    "type": "access-log",
    "host": "app-server-node-1",
    "path": "/var/log/tomcat7/localhost_access_log.2014-05-23.txt"
}

Den Transport der einzelnen Logzeilen zu Elasticsearch wird im ELK Stack von Logstash übernommen, das im folgenden beschrieben wird.

Logstash

bin/logstash -e 'input { stdin { } } output { stdout {} }'
hello world
2013-11-21T01:22:14.405+0000 0.0.0.0 hello world

Logstash kann mit einer Unix-Pipeline verglichen werden. Es nimmt Daten entgegen, die über eine Input Schnittstelle hereinkommen. Diese Daten können  dann gefiltert und transformiert werden. Nach der Transformation können die Daten wieder an ein Output geschickt werden. Logstash verfügt über eine große Menge verschiedener Input und Output. Es ist u.a. mögliche bekannte NoSQL-Datenbanken, wie  MongoDB, Redis und Riak als Input und Output zu nutzen. Außerdem kann man auch Elasticsearch oder RabbitMQ nutzen.

Logstash normalisiert Logeinträge und transportiert sie von einem System an eine zentrale Stelle. Es gibt verschiedene Ansätze, um Logstash zu integrieren. Ein möglicher architektonischer Aufbau wird in Abbildung 3 gezeigt. Auf den Rechnern, die die Logdateien produzieren, läuft Logstash als sogenannte Shipper Instanz. Die Shipper sende die Logeinträge an Redis. Redis spielt hierbei nur die Rolle einer Queue in der einzelnen Logeinträge zwischen gespeichert werden können. Die Logeinträge in Redis werden kann von einer Indexer Instanz von Logstash genommen und in Elasticsearch überführt.

Zentralisiertes Log Architektur
Abbildung 3: Zentralisiertes Log Architektur

Logstash kann als Dienst gesehen werden, der eingehende Daten einfängt und aggregiert.  Außerdem kann Logstash so konfiguriert werden, dass Daten durch eine Serie von Filtern geschickt werden, um transformiert oder normalisiert zu werden, bevor die Daten letztlich in einem Backend wie Elasticsearch gespeichert und indexiert werden. Die komplette Konfiguration von Logstash erfolgt über eine Konfigurationssprache.

Die Logstash Konfigurationssprache ist sehr einfach gehalten und besteht nur aus den drei Teilen: inputs, filters, outputs. In diesen Sektionen können Plugins konfiguriert werden. Die einzelnen Plugin Konfigurationen beinhalten dann die Einstellungen, die Plugins benötigen.

input {
    file {
        type => "access-log"
        path => "/var/log/tomcat7/localhost_access_log.*.txt
        codec => json
        sincedb_path => "/var/logstash/sincedb/access-log"
    }
}
output {
    elasticsearch {
        host => "10.211.55.100"
        port => "9200"
        embedded => false
        codec => json
        protocol => http
    }
}

Es gibt verschiedene Ansätze die Logeinträge in eine strukturierte Form zu bringen. Zum Einen existieren Filter-Plugins wie grok, das man benutzen muss, wenn man das Logformat nicht verändern will. Zum Anderen kann man aber auch das Logformat in den Logdateien direkt in eine strukturierte Form bringen. Es existieren fertige Encoder für Log4J und Logback, die die Logeinträge in ein JSON-Format bringen, dass direkt von Logstash an Elasticsearch geschickt werden kann, wie es im oben-stehenden Listing zu sehen ist. Das folgende Listing zeigt die Groovy-Konfiguration von dem schnellen Logger-Framework Logback, das die Logausgaben in ein JSON-Format umwandelt.

import net.logstash.logback.encoder.LogstashEncoder
import ch.qos.logback.core.ConsoleAppender

import static ch.qos.logback.classic.Level.*

appender("stdout", ConsoleAppender) {
    encoder(LogstashEncoder) {}
}
root(ERROR, ["stdout"])

Natürlich kann man sowohl die Logformate des Apache Webserver als auch des Tomcat Anwendungsservers konfigurieren, dass JSON als Logformat benutzt wird. Das kann Sinn machen, um die Einträge besser filtern zu können. Das folgende Listing zeigt, was dazu in der server.xml des Tomcat Anwendungsserver konfiguiert werden muss:

className="org.apache.catalina.valves.AccessLogValve" directory="logs"
                       prefix="localhost_access_log." suffix=".txt"
                       pattern="{ "remoteHost":"%h", "remoteLogname":"%l", "user":"%u", "time":"%t", "request":"%r", "status":"%s", "size":"%b", "referer":"%{Referer}i", "userAgent":"%{User-agent}i" }"/>

Logstash Forwarder / Lumberjack

Logstash hat einen signifikanten Memory Footprint (mindestens 512MB bis zu einem GigaByte). Deshalb gibt es auch leichtgewichtigere Lösungen zum Versenden von Daten zu einen zentralen Logstash Empfänger.

Der Logstash Forwarder ist ein leichtgewichtigere Daemon für das Versenden von Logdaten an eine zentrale Stelle. Der Logstash Forwarder hat mit 64KB einen wesentlich geringeren Memory Footprint und kann anstatt der bekannten Logstash Shipper Instanzen benutzt werden.

Damit wissen wir nun, wie man mit Logstash Logeinträge sammeln kann. Im Folgenden wird nun erklärt, wie man diese Logeinträge visualisieren kann.

Kibana

Kibana ist seit Version 1.2 das offizielle Webinterface von Logstash. Mit Kibana erfolgt die Visualisierung und Analyse der in Elasticsearch gespeicherten Daten. Kibana besteht aus einem Javascript-Frontend,  dass direkt mit dem REST-Interface von Elasticsearch kommuniziert. Kibana ist in der Lage von einem vom Web erreichbaren Verzeichnis (Apache Webserver) ohne weitere Installation benutzt werden zu können.

Kibana - Dashboard
Abbildung 4: Kibana

Kibana bietet die Möglichkeit Dashboards zu erstellen und Interface-Elemente auf die eigenen Suchen abzustimmen. Ein solches Dashboard kann in einem File, Gist oder in Elasticsearch abgelegt werden, um ein Dashboard mit anderen Kollegen zu teilen. Ein Dashboard besteht immer aus einer beliebigen Anzahl an Zeilen (Rows). Zeilen sind wiederum in Kacheln (Panels) unterteilt.

Übergeordnet sind die Kacheln für die Zeiteinschränkung (Timepicker) und die Suchanfragen (Query) zu betrachten, da sich deren Auswahl auf das gesamte Dashboard auswirkt und die in der ausgewählten Zeitperiode dargestellten Werte direkt beeinflusst. Die Zeiteinschränkungskachel bietet eine Vorauswahl von voreingestellten Zeitfenstern und aktualisiert das Dashboard auf Wunsch in regelmäßigen Abständen.

Kacheln beschreiben in welcher Form die Daten aus Elasticsearch präsentiert werden. Es sind Listen, Charts und auch Map-Darstellungen möglich. Unter Verwendung der jeweiligen Attribute kann die Darstellung dann noch weiter verfeinert werden. Um sich mit dem Userinterface besser vertraut zu machen, kann ich das Video „Kibana: Data Visualization Made Simple and Beautiful“ empfehlen, dass man sich unbedingt angucken sollte, um die Oberfläche besser zu verstehen.

ELK Stack – Architektur

Abbildung 5 zeigt ein Verteilungsdiagramm, dass die Architektur eines einfachen ELK Cluster zeigt. Diese ELK Cluster besteht aus den folgenden drei Knoten:

  • Einen Elasticsearch Knoten, auf dem auch Kibana innerhalb eines Apache Webservers installiert ist,
  • Außerdem gibt es zwei Anwendungsserver auf denen sich jeweils ein Tomcat und eine Logstash Shipper-Instanz befindet. Die Shipper-Instanzen beliefern direkt den Elasticsearch Knoten, in dem sie die JSON-Logeinträge im den Logdateien direkt weiterleiten.
Beispiel Architektur ELK Stack
Abbildung 5: Beispiel Architektur ELK Stack

Ein solches Cluster aufzubauen sieht auf den ersten Blick nach jeder Menge Infrastruktur Arbeit aus. Das kann abschrecken, wenn man einfach mal mit Kibana und Logstash herumspielen möchte. Ich hoffe diese Angst kann ich dem Leser nehmen, denn wir können den Cluster mit drei Befehlen bauen.

Vagrant setzt an dieser Stelle an. Vagrant hat das Ziel das Erstellen und Provisionieren von virtuellen Maschinen vereinfachen und beschleunigen. Bei Vagrant handelt es sich, um ein Werkzeug, dass es ermöglicht verschiedene virtuelle Maschinen auf einem einzigen physischen Rechner zu managen. Vagrant  unterstützt von Haus aus VirtualBox. (Mehr zum Thema Vagrant finde man in dem Artikel „Automatisierte virtuelle Testumgebungen mit Vagrant und Puppet“.) Vagrant wird automatisch den in Abbildung 5 abgebildeten ELK Stack initialisieren. Dazu muss man nur die folgenden Befehle in der Kommandozeile ausführen, nachdem man Vagrant und Virtualbox installiert hat.

bernd@mbp ~$ git clone https://github.com/zutherb/AppStash.git appstash
bernd@mbp ~$ git checkout elk-example
bernd@mbp ~$ cd appstash/vagrant
bernd@mbp ~$ vagrant up

Nach dem Start des Clusters mit dem Befehl vagrant up dauert es beim ersten Start einen Moment bis das Cluster komplett eingerichtet ist. Auf die im Verteilungsdiagramm dargestellten Komponenten des ELK Stacks kann man über die folgenden Port Forwardings zu greifen.

Sollten die oben genannten Port auf dem Rechner schon belegt sein ändert Vagrant diese automatisch. Dann muss im Konsolenoutput nach den entsprechenden Ports suchen.

Realtime Logdateianalyse

Im external Verzeichnis des Git-Repository, dass man zuvor ausgecheckt hat, befindet sich die Datei logstash-traffic-simulation.jmx. Diese Datei kann man mit JMeter öffnen und enthält einen einfachen Lasttest. Wenn man den Lasttest ausführt, erzeugt man auf den beiden Anwendungsservern Traffic. Die beiden Anwendungsservern schreiben nun Logeinträge in die Zugriffsprotokolldateien.

Logstash Dashboard
Abbildung 6: Realtime Logstash Dashboard

Ebenfalls im external Verzeichnis des Git-Repository befindet sich die Datei „Logstash Dashboard“. Dieses Dashboard kann man über die Addresse  http://localhost:8000/ in Kibana laden. Als Resultat erhält man ein Realtime Dashboard, dass die HTTP-Response Statuscodes auf den beiden Anwendugnsservern visualisiert.

[youtube http://www.youtube.com/watch?v=HHomI4y7yGs&rel=0&hd=1]

Zusammenfassung

Eingangs haben wir die folgenden funktionalen Anforderungen an ein Logdateianalyse Werkzeug definiert:

  • Ein Werkzeug zur Logdateianalyse muss es ermöglichen unstrukturierte Daten in eine strukturierte Form zu bringen, um Kennzahlen berechnen zu können.
  • Alle Logdateien müssen an einer zentralen Stelle durchsucht werden können.
  • Es muss eine Abfrage Sprachen geben, mit der man die Daten schnell durchsuchen kann.

ELK Stack erfüllt all diese Anforderungen. Kibana dient dabei zur Visualisierung der Daten und greift über die REST-API der Elasticsearch-DB auf die Datenbank selbst zu, die mithilfe von Logstash befüllt wird. Eine zentralisierte Logdateianalyse ist mit dem ELK Stack definitiv möglich.

OutOfMemoryError: Java Heapdump Analyse – Was tun? Wenn die Produktion spinnt!

Die Ausnahme java.lang.OutOfMemoryError kann zum Alptraum eines Entwickler werden. Diese Ausnahme tritt oft ohne Vorwarnung, erst unter Volllast in der Produktion auf. OutOfMemoryErrors sind während der Entwicklung nur schwer zu entdecken. Denn häufig wird die Bedeutung von automatisierten Lasttest unterschätzt, die ein solches Szenario simulieren könnten. Kommt es in Produktion zum Super-GAU und die Applikation steigt mit einem OutOfMemoryError aus, dann geht für den Entwickler die forensische Arbeit los. Dabei gilt es herauszufinden, in welchen Situationen die Applikation zu viel Speicher benötigt und wie man vermeiden kann, dass die Applikation abstürzt. In diesem Beitrag geht es darum, wie man bei der Analyse eines solchen Fehlers vorgeht. Um diese Ausnahme besser zu verstehen, wird  zuerst die Java Memory Architektur vorgestellt.

Java Memory Architektur

Die Java Plattform verfügt über eine automatische Speicherverwaltung, die in der Java Virtual Machine Specification festgelegt ist. Zur Laufzeit wird zwischen verschiedenen Speicherbereichen unterschieden. Es gibt einen Speicherbereich, der für alle Threads sichtbar. Dieser Speicherbereich enthält unter anderen das sogenannte Method Area (PermGen) und den Heap.  Ein anderer Speicherbereich ist exklusiv nur für den ausgeführten Thread sichtbar.

Java Memory Architektur
Abbildung 1: Java Memory Architektur

Das Method Area wird beim Start der JVM initialisiert und darin befinden sich die geladenen Klassen. Der Heap verwaltet hingegen alle Objekte und Arrays, die zur Laufzeit erzeugt werden. Der Heap ist für alle Threads sichtbar.

Die JVM Spezifikation sieht weiterhin eine automatische Speicherverwaltung des Heaps in Form einer sogenannten Garbage Collection vor, die vom Garbage Collector durchgeführt wird. Bei der Garbage Collection handelt es sich, um eine explizite Deallokation von Objekten auf dem Heap, die automatisch abläuft. Eine Garbage Collection sollte normalerweise ohne das Zutun eines Entwicklers ablaufen.

Java Heap
Abbildung 2: Java Heap Struktur

Abbildung 2 zeigt den Aufbau der Oracle HotSpot Implementierung des Heaps und die JVM-Parameter, die man benutzen kann, um den Speicher an entsprechenden Stellen zu vergrößern. Der Heap ist in mehreren Generationen unterteilt: Der Young Generation und der Old Generation. Die Young Generation sorgt für eine Optimierung der Garbage Collection. Außerdem soll die Young Generation die Allokation neuer Objekte, sowie die Deallokation nicht mehr benötigter Objekte vereinfachen. Wenn Objekte ein gewisses Lebensalter überschritten, werden sie in die langsamere Old Generation kopiert. Neben diesen beiden Generationen gab es bis Java 8 noch die Permanent Generation. Im Zuge der Vereinigung der Codebasis der HotSpot und JRockit JVM wurde die Permanent Generation allerdings entfernt (Quelle).

Nachdem nun der Aufbau der Java Memory Architektur  geklärt ist, betrachten wir im Folgenden , wie man Java Memory Architektur überwachen kann.

Überwachung der Java Memory Architektur

Die Java Plattform bringt eine Reihe von Werkzeugen mit, um die Java Memory Architektur zu überwachen. Das einfachste Werkzeug ist das  Konsolen-Programm jmap. jmap gibt dem Benutzer textuelle Informationen über die verfügbaren JVM Speicherbereiche auf der Konsole aus, wie Young Generation und Old Generation. Das folgende Listing zeigt den Aufruf, den man in der Konsole ausführen muss, um sich Information über den Java-Heap mit jmap anzeigen zu lassen. Zunächst muss man mit dem Konsolenprogramm jps die Prozess-ID des Java Prozesses ermitteln, den man überwachen möchte. Dann kann man mit der herausgefundenen Prozess-ID und dem Parameter -heap das Programm jmap aufrufen und erhält Informationen über den verfügbaren Speicher:

bernd@mbp ~ $ jps
7409 Runner
25297 Jps
bernd@mbp ~ $ jmap -heap 7409
...
Heap Usage:
PS Young Generation
Eden Space:
   capacity = 60817408 (58.0MB)
   used     = 24817576 (23.667884826660156MB)
   free     = 35999832 (34.332115173339844MB)
   40.80669797700027% used
...
13008 interned Strings occupying 1759648 bytes.

Natürlich gibt es auch grafische Werzeuge, um die Java Memory Architektur zu überwachen. Im Folgenden werden die beiden Tools JConsole und VisualVM kurz vorgestellt.

JConsole ist eine Swing-Applikation, die seit Java Version 1.5 mit dem JDK mitgeliefert wird und  zur Überwachung von Java Prozessen via JMX auf lokalen oder entfernten Systemen dient. JMX steht für Java Management Extension und ist eine Weiterentwicklung eines Java Standards, der auch die Kommunikation zwischen unterschiedlichen Java Prozessen ermöglicht.

Last login: Wed Apr 30 19:51:45 on ttys000
bernd@mbp ~ $ jconsole

Nach dem Start von JConsole auf der Kommandozeile erscheinen  im einem Startscreen alle lokalen Java-Prozesse, diese können mit einem Doppelklick überwacht werden. Für das Monitoring entfernter JVM’s muss auf dem Zielsystem der entsprechende RMI-Zugriff aktiviert sein.

JConsole Startbildschirm
Abbildung 3: JConsole Startbildschirm
Abbildung 4: JConsole Überschicht
Abbildung 4: JConsole Überschicht
Abbildung 5: JConsole Speicherübersicht
Abbildung 5: JConsole Speicherübersicht
Last login: Thu May  1 10:08:40 on ttys003
bernd@mbp ~ $ jvisualvm

VisualVM ist ein weiteres grafisches Werkzeug mit einfachen Profiling-Möglichkeiten, dass auch über eine grafischen Oberfläche für das JDK-Tool jstack verfügt, mit dem Threaddumps erstellen werden können. VisualVM ist Bestandteil des JDK 6. Innerhalb der JDK heißt VisualVM allerdings Java VisualVM und kann mit dem Befehl jvisualvm in der Kommandozeile aufgerufen werden. Die aktuelle Version von VisualVM findet sich auf der Webseite und kann getrennt von der JVM installiert werden.

JVisualVM-Speicherübersicht
Abbildung 6: JVisualVM Speicherübersicht

Da wir nun wissen, wie wir die JVM überwachen können, sollten wir als Nächstes betrachten, welche Arten der Ausnahme java.lang.OutOfMemoryError auftreten können.

Arten von OutOfMemoryError

Ein Speicherüberlauf tritt immer dann auf, wenn der Garbage Collector keinen Speicher mehr deallokieren kann, um eine Speicheranfrage für das Instanzieren eines neuen Objekts zu erfüllen. Ein solcher Fehler führt zu einem java.lang.OutMemoryError, der sich in einer der folgenden textuelle Beschreibung äußert:

OutOfMemoryErrorBedeutung
Java heap spaceDer Garbage Collector kann keinen Speicher mehr freimachen, um eine Speicheranfrage für ein neues Objekt zu erfüllen.
Requested array size exceeds Es wird versucht ein Array auf dem Heap anzulegen, das größer ist als der Heap selber.
PermGen spaceEs steht nicht genug Speicher zur Verfügung, um Klassen Informationen im Method Area abzulegen oder der Code Cache vollläuft.
unable to create new native threadEs existieren zu viele Threads innerhalb der JVM. Es steht nicht mehr genug Speicher zur Verfügung , um einen neuen nativen Thread anzulegen.
request bytes for . Out of swap space? Der Heap muss erweitert werden, aber auf Betriebssystem Seite steht nicht mehr genügend Speicher zur Verfügung.
GC overhead limit exceededDer Garbage-Collector ist überdimensional oft und zu lange aktiv, so dass das eigentliche Programm nicht mehr vorankommt.

Nachdem nun die unterschiedlichen OutMemoryErrors kurz vorgestellt worden, wird im Folgenden genauer betrachtet, wie ein solcher Fehler entsteht und wie man ihn aufspüren kann.

Java Memory Leaks

Alle Objekte werden auf dem Heap erzeugt. Die Lebensdauer eines Objekts auf dem Heap ist abhängig davon, ob das Objekt von einem anderen Objekt referenziert wird. Der Garbage Collector prüft, wenn bestimmte Schwellwerte überschritten werden, ob ein Objekt noch referenziert ist. Sollte ein Objekt nicht mehr referenziert sein, wird das Objekt vom Garbage Collector als „Müll“ markiert und in einem späteren Schritt aufgeräumt und dessen Speicher freigegeben.

Sogenannte Garbage Collector Root (GC Root) Referenzen sind für das Überleben eines Objekts entscheidend. Ein GC Root ist ein Objekt, auf das es keine eingehenden Referenzen gibt. GC Roots sind verantwortlich dafür, dass referenzierte Objekte im Speicher gehalten werden. Wird weder direkt noch indirekt von einem GC Root referenziert, wird ein Objekt es als “unreachable” gekennzeichnet und zur Garbage Collection freigegeben. Man kann die folgenden Arten von Garbage Collection Roots unterscheiden:

  • Temporäre Variablen auf dem Stack eines Threads
  • Statische Felder von Klassen
  • Spezielle native Referenzen in JNI

GC Root lassen sich am besten anhand eines konkreten Code-Beispiels verdeutlichen:

public class MyPage extends org.apache.wicket.markup.html.WebPage {

  //Die Liste ist erreichbar,
  //wenn die Klasse geladen ist
  public static final List STATIC = new ArrayList();

  //Die Liste ist erreichbar,
  //solange eine Instanz der Seite existiert
  private final List instance = new ArrayList()

  //Die Liste ist erreichbar,
  //solange die Methode ausgeführt wird
  //auch wenn die Liste nicht benutzt wird
  private void myMethod(List parameter) {
    
    //solange die Methode ausgeführt wird
    //ist die List von Stack erreichbar
    List local = new ArrayList();
  }

}

GC Root Objekte sind für die folgenden OutOfMemoryError Problemen verantwortlich:

  • Objekte, die nie mehr im Anwendungscode genutzt werden, aber noch eine GC Root Referenz haben, verursachen Java Memory Leaks, da diese Objekte nicht vom Carbage Collector aufgeräumt werden können.
  • Durch die Verwendung von großen Objektbäume, die im Speicher gehalten werden (z.B. Caches), kann es dazu kommen, dass nicht genug Heap zu Verfügung steht. Dann muss der Speicher für die Applikation erhöht werden.
  • Zu viele temporäre Objekte, die dazu führen, dass temporär bei der Verarbeitung im Java-Code zu viel Speicher benötigt wird.

Java Memory Leaks entstehen immer dann, wenn ein Objekt noch eine GC Root Referenz hat, aber nicht mehr in der Anwendung benutzt wird. Solche Objekte werden „Loitering Objects“ genannt. Loitering Objects belegen für die komplette Ausführungsdauer den JVM Speicher. Durch solche „Objekt-Leichen“  wird der Anwendungsspeicher nicht mehr ausreichen und es kommt zu einem OutOfMemoryError. Häufig wird ein OutOfMemoryError von statischen Collections ausgelöst.  Dann werden Objekte der Collection hinzugefügt, aber nicht wieder gelöscht. Die hinzugefügten Objekte werden durch die statischen Collection-Einträge referenziert und können aufgrund der GC Root Referenz (statisch) nicht mehr freigegeben werden.

Abbildung 6 - Dominatoren
Abbildung 7 – Dominatoren

Im Zusammenhang mit Java Memory Leaks wird weiterhin oft von sogenannten Dominatoren und Dominatorbäumen gesprochen. Bei  Dominatoren handelt es sich, um ein Konzept aus der Graphentheorie.  Ein Dominator ist ein Knoten, durch den ein kompletter Teilgraph erreichbar ist. Auf das Speichermanagement umgesetzt, heißt das, dass  ein Objekt A ein Dominator eines anderen Objekts B ist, wenn es kein weiteres Objekt C gibt, das eine Referenz auf B hält. Wird also die Wurzelreferenz freigegeben, wird auch der ganze Dominatorbaum freigeben. Sehr große Dominatorenbäume sind also sehr gute potenzielle Kandidaten bei der Memory Leak Suche.

Die Memory Leak Suche beginnt mit dem Erstellen eines Heapdump. Im Folgenden werden zunächst Möglichkeiten vorgestellt, um einen Heapdump zu erstellen.

Java Heapdump

Ein Heapdump ist eine textuelle oder binäre Abbildung des Java Heaps. Aus den Informationen, die in einem Heapdump enthalten sind, lassen sich mit verschiedenen Werkzeugen die gesamten Objekte, die von einer Applikation erzeugt werden, rekonstruieren. Außerdem sind alle Referenzen zwischen den Objekten in einem Heapdump enthalten. Ein Heapdump kann im Fehlerfall durch die JVM  Option -XX:+HeapDumpOnOutOfMemoryError beim Auftreten eines OutOfMemoryErrors  automatisch erzeugen werden. Heapdumps enthalten meistens die folgenden Arten von Objekten:

  • lebendige Objekte, das sind Objekte, die über eine GC Root Referenz erreichbar sind
  • Alle nicht mehr referenzierten Objekte

Alternativ zur JVM Option kann ein Heapdump mit dem Konsolen-Werkzeug jmap erstellt werden, das wir bereits zur Überwachung der JVM kennengelernt haben. Das folgende Listing zeigt, wie man einen Heapdump über die Konsole erstellen kann.

bernd@mbp ~ $ jps
16497 AppMain
16520 Jps
bernd@mbp ~ $ jmap -dump:live,format=b,file=dump.hprof 16497
Dumping heap to /Users/berndzuther/dump.hprof ...
Heap dump file created

Natürlich gibt es auch ein grafische Werkzeug, wie z.B. VisualVM, mit dem man auch einen Heapdump erstellen kann.

VisualVM Heapdump
Abbildung 8: VisualVM Heapdump

Nachdem wir nun einen Heapdump erzeugen können, können wir beginnen den Heapdump zu analysieren. Dazu stehen uns die folgenden Tools zur Verfügung.

Heapdump Analyse

Das JDK 1.6 bringt ein kleines Tool mit Namen jhat (Java Heap Analysis Tool) zur Analyse von Heapdumps mit. jhat startet einen lokalen Webserver. Der Heapdump kann unter Verwendung der Defaulteinstellungen über die Adresse http://localhost:7000 analysiert werden. Das Tool stellt aber leider nur sehr rudimentäre Funktionen zur Auswertung des Heapdumps zur Verfügung und ist es nicht sehr gut zu bedienen.

bernd@mbp ~ $ jhat -J-mx2000m dump.hprof
Reading from dump.hprof...
Dump file created Fri May 02 18:37:18 CEST 2014
Snapshot read, resolving...
Resolving 2013119 objects...

Ein schönes Werkzeug für die Analyse von Heapdumps ist der  Memory Analyzer (MAT), der in der Lage ist sehr große Heapdumps zu verarbeiten. Ältere Tools haben oft das Problem, dass der Heapdump zur Analyse komplett in den Arbeitsspeicher geladen werden muss und man i.d.R. das 1,5-fache des Heaps zur Analyse benötigt. D.h. ein Heap von 2GB Größe benötigte 3 GB Heap zur Analyse. Der Memory Analyzer indiziert zunächst einen Heapdump, um hinterher in vertretbarer Zeit und mit verkraftbarem Speicherverbrauch eine Analyse auf dem Dump ermöglichen zu können.

Memory Analyzer
Abbildung 9: Memory Analyzer

Der Memory Analyzer analysiert die Referenzbeziehungen zwischen Objekten auf dem Heap und erzeugt daraus  Dominatorbäume. Außerdem sucht der Memory Analyzer die Dominatoren im Heap (diese werden im MAT Akkumulierungspunkte genannt) heraus. Die Dominatoren erhalten große Mengen Speicher am Leben und werden als „Suspect Report“ dargestellt, wie es in Abbildung 9 zu sehen ist.

Memory Analyzer OGL
Abbildung 10: Memory Analyzer OGL

Um Objekte in einem Heapdump abzufragen, gibt es die sogenannte Object Query Language (OQL). OQL führt bei Abfragen zu mehr Flexibilität und ermöglicht es Objekte nach bestimmten Kriterien zu filtern. Dazu benutzt OQL die JavaScript Expression Language.

Eine OQL Anfrage hat die folgende Struktur:

select 
         [ from [instanceof]  
         [ where  ] ]

--selektiert alle Strings, die mehr als 100 Zeichen haben
select s from java.lang.String s where s.count >= 100

--selektiert alle int arrays mit mehr als 256 Elementen
select a from int[] a where a.length >= 256

Im nächten Schritt führen wir eine Java Heap Analyse mit dem Memory Analyzer an einem konkreten Beispiel aus.

Online Shop – Beispiel Heapdump-Analyse

Die Firma comSysto hat im Rahmen des Meetup Boost your Java Enterprise Stack with MongoDB einen Onlineshop in seinen Github Repository veröffentlicht. Das folgende Youtube-Video zeigt, über welche Funktionalität dieser Onlineshop verfügt und gibt eine kleine Einführung in den Onlineshop.

[youtube http://www.youtube.com/watch?v=uJpFp9qR4Z4&rel=0&hd=1]

Im Folgenden verwenden wir einen Fork dieses Onlineshop, um eine Memory Leak Analyse durchzuführen. Diesen Fork kann man in meinem Github Repository auschecken.  Das folgende Listing zeigt, was dazu zu tun ist:

bernd@mbp ~ $ git clone https://github.com/zutherb/memory-leak-detection.git
Cloning into 'memory-leak-detection'...
remote: Counting objects: 1231, done.
remote: Compressing objects: 100% (632/632), done.
remote: Total 1231 (delta 211), reused 1231 (delta 211)
Receiving objects: 100% (1231/1231), 5.72 MiB | 1.56 MiB/s, done.
Resolving deltas: 100% (211/211), done.
Checking connectivity... done.
bernd@mbp ~ $ cd memory-leak-detection
bernd@mbp ~/memory-leak-detection (master)$ git branch -r
  origin/HEAD -> origin/master
  origin/master
  origin/memory-leak-fix

Manchen wir uns im nächsten Schritt mit dem Repository vertraut. Das Repository verfügt über zwei Branches. Der master-Branch ist mit einem Memory Leak präpariert und im memory-leak-fix-Branch befindet sich der Onlineshop in einer  Memory Leak freien Version.

Gitk - Memory Leak Detection Repository
Abbildung 11: Gitk – Memory Leak Detection Repository

Nachdem wir nun den Aufbau des Repository kennen, können wir uns mit dem Onlineshop selbst vertraut machen. Der Onlineshop basiert auf Java 8. Um den Onlineshop bauen und starten zu können, muss also auch Java 8 auf dem Rechner installiert sein und das entsprechende Java_Home als Umgebungsvariable eingestellt sein. Als Buildtool wird Gradle verwendet, das schon aus dem Artikel „Gradle: Erstellen von einem Java Application Bundle unter Mac OS X“ bekannt ist. Gradle ist ein auf Groovy und Java basierendes Build-Management-Automatisierungs-Tool, dass vergleichbar mit Apache Ant und Apache Maven ist. Gradle nutzt jedoch im Gegensatz zu Maven und Ant eine auf Groovy basierende domänenspezifische Sprache (DSL) zur Beschreibung der zu bauenden Projekte. Gradle muss nicht auf dem Rechner installiert sein, man kann den sogenannten Gradle-Wrapper benutzen, der sich im Wurzel-Verzeichnis des Projektes befindet. Um das Projekt zu bauen und die Anwendung zu starten. Hierzu nutzen wir den Task jettyRun im Projekt shop/ui. Nach einer Weile startet der Onlineshop auf der Url http://localhost:8080/pizza. Das folgende Listing zeigt, wie man unter MacOSX das JAVA_HOME für Java 8 setzen kann  (VORRAUSSETZUNG: Java 8 ist installiert) und den Onlineshop startet:

bernd@mbp ~/mld $ export JAVA_HOME="${/usr/libexec/java_home -v 1.8}"
bernd@mbp ~/mld (master)$ ./gradlew -p shop/ui/ jettyRun

Die Katalog-Seite des Onlineshop ist mit einem Memory Leak präpariert. Dieser äußert sind in einem OutOfMemoryError: Java Heap Space, wenn man die Katalog-Seite oft genug aufruft.  Um nicht ständig die Katalog-Seite http://localhost:8080/pizza/productcatalog/pizza per Hand aufrufen zu müssen, befindet sich im Verzeichnis external  die Datei loadtest.jmx. Diese Datei kann man mit dem Programm Apache JMeter ausführen. JMeter ist ein freies, in Java geschriebenes Werkzeug zum Ausführen von Lasttests in Client/Server-Anwendungen. JMeter ermöglicht es durch das  Zusammenstellen eines Testplanes zu spezifizieren, welche Teile der Anwendung durchlaufen werden sollen, um konkrete Ergebnisse über das Antwortzeitverhalten zu bekommen.

JMeter - Lasttest
Abbildung 12: JMeter – Lasttest

Öffnen wir  JMeter und führen die Datei loadtest.jmx gegen den laufenden Shop aus, in dem wir auf den grünen Play-Button unterhalb der Menü-Liste in JMeter klicken. Nach einiger Zeit kommt es zu einem OutOfMemoryError: Java heap space.

Error for /pizza/productcatalog/pizza
java.lang.OutOfMemoryError: Java heap space

Jetzt ist der Moment erreicht, in dem wir einen Heapdump erstellen sollen. Das folgende Listing zeigt, wie wir mittels jps die Prozess-ID des laufenden Onlineshops herausfinden können, um einen Heapdump erstellen zu können. Denn ersten jps Aufruf sollte man machen bevor, man mit Gradle den Onlineshop startet. In der Regel ist aber die höchste Prozess-ID des GradleDaemon auch die Prozess-ID des laufenden Onlineshops.

bernd@mbp ~/memory-leak-detection (master)$ jps
6097 
535 WrapperSimpleApp
4509 GradleDaemon
6404 Jps
bernd@mbp ~/memory-leak-detection (master)$ jps
6097 
535 WrapperSimpleApp
6451 GradleDaemon
4509 GradleDaemon
6481 Jps
6441 GradleWrapperMain
bernd@mbp ~/memory-leak-detection (master)$ jmap -dump:live,format=b,file=dump.hprof 6451
Dumping heap to /Users/berndzuther/memory-leak-detection/dump.hprof ...
Heap dump file created

Natürlich kann man den Onlineshop auf während des Lasttests mit VisualVM überwachen. Dann kann man dabei zu gucken, wie der Heap Speicher vollläuft, wie es in Abbildung 13 zusehen ist.

VisualVM - Lasttest
Abbildung 13: VisualVM – Lasttest

Wenn wir den Dump nun in den Memory Analyzer laden und einen Suspect Report erstellen, warnt uns der Memory Analyzer vor einem potentiellen Memory Leak in der Klasse ProductCatalogPage.

Memory Analyzer - Suspect Report
Abbildung 14: Memory Analyzer – Suspect Report

In unserem Beispiel wird eine ArrayList als Hauptverdächtiger präsentiert.  Durch das verdächtige Objekt wird circa die Hälfte, des Speichers verbraucht, der der Anwendung zur Verfügung steht. Als nächstes kann man sich eine detailliere Beschreibung ausgeben lassen, in dem man auf Details klickt. In dieser Ansicht sieht man, was die verdächtige ArrayList enthält und wer die ArrayList referenziert.  Auch diese Information ist im Memory Analyzer gut aufbereitet:

Memory Analyzer - Suspect Report Detail
Abbildung 15: Memory Analyzer – Accumulation Point

In der Accumulation Point Ansicht des Suspect Report sieht man, das die Klasse ProductCatalogPage eine Variable memoryLeak  enthält, die die verdächtige  ArrayList referenziert. Ein Blick in den Quellcode verrät uns, dass es sich dabei um eine statische Variable handelt, die bei jeden rendern des Produkt-Katalogs immer wieder alle Elemente im Katalog in sich und sich danach selbst kopiert. Wenn man die Liste entfernt, kann man den Lasttest ausführen, ohne das es zu einem OutOfMemoryError kommt. Damit haben wir das Memory Leak in der Applikation gefunden und beseitigt.

@MountPath("productcatalog/${type}")
@EnumProductTypeNavigationItem(enumClazz = ProductType.class, defaultEnum = "PIZZA", sortOrder = 2)
public class ProductCatalogPage extends AbstractBasePage {

    @SpringBean(name = "productService")
    private ProductService productService;

    private IModel productTypeModel;
    private IModel productListModel;
    private Component basketPanel;

    private static List memoryLeak = new ArrayList();
    ...
    private Component productView() {
        return new DataView("products", productDataProvider()) {

            @Override
            protected void populateItem(final Item item) {
                memoryLeak.add(item.getModelObject());
                memoryLeak.addAll(new ArrayList<>(memoryLeak));
                ...
            }
        };
    }
    ...
}

Auch in Dominatorbaum Ansicht, die in Abbildung 15 dargestellt wird, sieht man, dass es sich bei der ArrayList, um einen potenziellen Kandidaten für einen Memory-Leak handelt.

Memory Analyzer - Dominatorbaum
Abbildung 16: Memory Analyzer – Dominatorbaum

Zusammenfassung

In diesem Artikel haben wir die Suche nach Memory Leaks mit Hilfe eines Heapdumps betrachtet. Ein Heapdump kann z.B. mit dem Konsolen-Programm jmap oder über eine JVM Option im Fehlerfall erstellt werden.

Eine Heapdumps Analyse wird oft post mortem durchgeführt, nachdem die Anwendung bereits wegen einem OutOfMemoryError abgebrochen wurde. Für eine  Heapdump-Analyse, kann das frei verfügbare Werkzeug Memory Analyzer MAT verwendet werden, das einen potentielle Kandidaten für einen Memory Leak vorschlägt. Sehr große Dominatorenbäume sind auch sehr gute potenzielle Kandidaten bei der Memory-Leak-Suche.

—————————————————-

Ich danke Daniel Mitterdorfer für die vielen Anregungen und Ideen zu diesem Artikel. Daniel Mitterdorfer ist ein Software Engineer und Mitglied der Application Performance guild bei der comSysto GmbH.

Probleme kann man niemals mit derselben Denkweise lösen, durch die sie entstanden sind.