Das Nachvollziehen von Systemaufrufen zur Problemanalyse in verteilen JavaEE-Anwendungen anhand von Log-Dateien ist anstrengend und kostet Zeit. Gerade bei der Analyse von Störungen in einer Produktionsumgebung ist man von der Geschwätzigkeit der erzeugten Log-Einträge abhängig. Auch ist man dort eher selten in der Lage, mal eben das Log-Level zu erhöhen – sofern ein zu analysierendes Problem überhaupt reproduzierbar ist.

Heute möchten wir ein neues Framework und Open-Source-Projekt vorstellen, das diesem Problem zu Leibe rückt: TracEE. Aussagen wie „Das kann man jetzt so leider nicht mehr nachvollziehen!“ könnten bald der Vergangenheit angehören.

Wenn man einen einzelnen Applikationsserver betrachtet, lassen sich Systemaufrufe meist anhand des im Log stehenden Thread-Namens nachvollziehen. Das funktioniert gut, da JavaEE grundsätzlich mit einem Thread-per-Request-Modell arbeitet. Sobald die Verarbeitung jedoch die Thread-Grenze überschreitet, z.B. durch den Remote-Aufruf einer Komponente auf einem anderen Server, geht diese Kontextinformation verloren. Allein durch Sichtung der Log-Dateien kann keine Verbindung mehr zwischen den Verarbeitungsschritten auf dem ersten und dem zweiten Server hergestellt werden.

Um verteilte Systemaufrufe in Log-Dateien nachvollziehen zu können, benötigen wir den zu einem Log-Eintrag zugehörigen erweiterten Kontext. Praktisch wäre zum Beispiel ein Kontext, der sich über sämtliche Log-Ausgaben erstreckt, die durch eine Benutzerinteraktion (also etwa eines Http-Servlet-Request) ausgelöst wurden.

Eine Lösung, die wir in Projekten häufig vorfinden, ist das Durchreichen pseudo-fachlicher Korrelations-IDs auf fachlichen Schnittstellen. Bei jeder Log-Ausgabe wird diese Korrelations-ID explizit als Teil der Log-Nachricht mit ausgegeben. Diese Korrelations-ID wird dann bis in jede Komponente, auch über Systemgrenzen hinweg, durchgereicht, in der eine Log-Ausgabe erzeugt wird. Später können Log-Nachrichten dann anhand dieser Korrelations-ID gruppiert und ein Aufrufpfad im System nachvollzogen werden. Obwohl dieser Ansatz funktioniert, ist es aus Sicht des Software-Designs eine schlechte Idee, den technischen Aspekt der Nachvollziehbarkeit im Log über Parameter in fachlichen Schnittstellen abzubilden, denn dies erzeugt vermeidbare Abhängigkeiten und Komplexität.

Kontext-Logging mit dem Mapped Diagnostic Context (MDC)

Die Anbieter moderner Logging-Frameworks wie Log4J, Slf4J und jboss-logging adressieren dieses Problem bereits mit dem so genannten Mapped Diagnostic Context (MDC). Der MDC ist eine einfache statische Map, die an den Lebenszyklus eines Threads geknüpft ist. Eine Anwendung kann an einer beliebigen Stelle im Programmcode zusätzliche Kontextinformationen im MDC hinterlegen. Jede folgende Log-Ausgabe auf demselben Thread kann anschließend auf die im MDC hinterlegten Informationen zugreifen und sie als Teil einer Log-Nachricht ausgeben. Dazu gibt man in dem konfigurierbaren Log-Format die auszugebenden Keys der MDC-Map an. Wenn zu Beginn der Verarbeitung eines Servlet-Requests eine Kontext-ID für den Request im MDC hinterlegt wird, können alle folgenden Log-Ausgaben sehr einfach dem ausführenden Request zugeordnet werden.

Mit Hilfe des MDCs kann man den Aspekt der Weitergabe von Kontextinformationen weitgehend aus fachlichen Schnittstellen verbannen. Trotzdem geht die Kontextinformation beim Aufruf entfernter Services oder asynchroner Weiterverarbeitung bei einem Thread-Wechsel verloren. Was wir also zusätzlich brauchen, ist die Weitergabe von MDC-Kontextinformationen über Thread-, JVM- und Systemgrenzen hinweg.

Dieses Kernproblem ist völlig alltäglich und in beinahe jeder größeren JavaEE-Anwendung vorhanden, so dass wir beschlossen haben, es im Rahmen eines eigenen Frameworks zu lösen.

Kontext-Weitergabe über Systemgrenzen mit TracEE

An jeder Schnittstelle ist es möglich, den Aufruf transparent vorzuverarbeiten, ohne in die Businesslogik eingreifen zu müssen. TracEE lauscht so auf den Schnittstellen, nimmt die Kontext-Informationen entgegen und überführt diese in den MDC. Werden keine Informationen gefunden, werden entsprechend der Konfiguration neue Identifikationsmerkmale generiert und im MDC vorgehalten. Andersherum bei einem Aufruf eines nachgelagerten Systems: Die Kontextinformationen werden aus dem MDC gelesen und entsprechend der verwendeten Technologie transparent weitergereicht.

Das Verhalten von TracEE an den Schnittstellen kann sehr individuell gesteuert werden. So kann die Annahme wie auch die Weitergabe von bzw. an externe Systeme verhindert werden.

TracEE unterstützt dabei u.A. die folgenden Technologien und Protokolle:

• Java Message Service (JMS 1.1)
• Java Http-Servlets 2.5+
• Spring Framework 3.0+
• Enterprise Web Services (JAX-WS)
• Java API for RESTful Services (JAX-RS)

Das Einrichten von TracEE ist denkbar einfach. In vielen Fällen reicht das Hinzufügen weniger Maven-Dependencies und Annotationen sowie die Konfiguration des Logging-Formats aus, um sämtliche Log-Ausgaben ihrer ursächlichen Systeminteraktion zuordnen zu können. Darüber hinaus kann konfigurativ festgelegt werden, auf welchen Kommunikationsabschnitten welche Kontext-Informationen weitergegeben werden sollen.

TracEE wird ab sofort als Community-Projekt bei GitHub weitergeführt und wir freuen uns über jede Art von Beteiligung und Feedback.

Down the road

Als nächsten Schritt werden wir TracEE in weiteren Projekten einsetzen und dabei beobachten, wie die Integration in verschiedenen Umgebungen funktioniert und wo wir Verbesserungen an der Modulstruktur, API und Standardkonfiguration vornehmen können.

Wir haben aber auch bereits einige weitere spannende Ideen, wie man das Logging von JavaEE-Anwendungen mit TracEE nützlicher gestalten kann. Insbesondere im Zusammenspiel mit zentralen Log-Servern und structured logging sind fortschrittliche Monitoring- und Tracking-Lösungen machbar.

Ein weiterer Aspekt ist die Verbesserung der Log-Ausgabe im Fehlerfall. Neben dem üblichen Stack-Trace können zum Beispiel Aufrufparameter der fehlgeschlagenen Methoden ausgegeben werden.

Über spannende Neuerungen werden wir auf jeden Fall hier berichten!