WSO2 10 Minuten

Log4j verrät Ihnen, was vor sich geht

Rob Blaauboer
Rob Blaauboer
Integration Consultant & WSO2 Trainer
Header LOG4J2
Scrollen

Log-Dateien zeigen Ihnen, was mit der Software, die Sie ausführen, geschieht. WSO2-Produkte, wie der Enterprise Integrator 6.6.0, arbeiten mit Log4j2, um die Informationen zu kontrollieren, die in den Protokollen angezeigt werden. 

Log4j und Log4j2 sind quasi Standard-Frameworks für die Protokollierung von Anwendungsmeldungen in Java. Im Grunde genommen fügen Sie bei der Entwicklung von Java-Anwendungen mehrere Anweisungen ein, die Informationen entsprechend dem von Ihnen eingestellten Level protokollieren. 

Log-levels in Log4j2

Die vordefinierten Log-Level für Log4j2 sind:

  1. OFF
  2. ALL
  3. FATAL
  4. ERROR
  5. WARN
  6. INFO
  7. DEBUG
  8. TRACE

Das Setzen einer bestimmten Klasse auf einen bestimmten Log-Level bedeutet, dass das Logging-Framework alle Log-Anweisungen bis zu diesem Level für diese bestimmte Klasse in die Log-Dateien ausgibt.

Im Quelltext können an Stellen, die für den Systemadministrator von Interesse sind, Anweisungen platziert werden, die Informationen für das Log auf einer bestimmten Ebene ausgeben. Die Log4j2 Konfiguration steuert dann, welche dieser Log-Anweisungen im Quellcode tatsächlich in die Logdateien ausgegeben werden sollen. 

Log-Level sind grundsätzlich kumulativ, d.h. wenn Sie in der Konfiguration einen Level von TRACE einstellen, dann erhalten Sie auch alle weiteren Log-Level (DEBUG,INFO,WARN, …). Wenn Sie jedoch den Level ERROR einstellen, dann erhalten Sie NICHT die Ausgänge der niedrigeren Levels. Dadurch wird eine recht detaillierte Ausgabe von Log-Statements in einer Klasse möglich. 

Es ist egal, ob Sie Ihre Logs mit einem Text-Editor betrachten oder einen ELK Stack im Einsatz haben, die Logs werden Ihnen die Wahrheit verraten. 

Wenn Sie mit Protokollen nicht so vertraut sind: Beim Start von Enterprise Integrator über die Befehlszeile oder das Terminal mit dem Befehl integrator.sh (oder bat) ist der Text, der auf der Konsole angezeigt wird, das, was vom Logging Framework ausgegeben wird und als „die Konsolenprotokolle“ bekannt ist. Auf der Festplatte, im wso2-home/repository/logs/wso2carbon.log finden Sie die permanente Form der Protokollierung, die Sie sehen können, auch wenn Sie keinen Zugriff auf die Konsole haben, auf der WSO2 Enterprise Integrator gestartet wurde.

LOG4J2 1

Wie Sie feststellen können, erhalten wir eine Menge INFO-Meldungen, die wir ignorieren können, da sie uns mitteilen, was sie tun. Doch nicht jede Meldung kann ignoriert werden. ERRORs weisen natürlich darauf hin, dass wir auf ein Problem gestoßen sind, das möglicherweise behoben werden muss.

Log4j2-Datei

Die Datei Log4j2 befindet sich im Verzeichnis [EI-HOME]/conf. Es handelt sich um eine Hot-Datei, was bedeutet, dass Sie die Auswirkungen einer Änderung sofort sehen. Zuerst durch eine Meldung auf der Konsole, dass die Datei geändert wurde. Sobald dann das betreffende Java Codestück ausgeführt wird, melden die Log-Mediatoren das. 

Wie sieht also die Datei aus?

Es beginnt alles mit einer Liste von Appendern. Ein Appenders ist dafür verantwortlich, Log-Meldungen an ein bestimmtes Ausgabeziel zu senden. Bei diesen Zielen handelt es sich häufig um Protokolldateien, es kann sich aber auch um eine Linux-Syslog-Einrichtung, eine Warteschlange oder ein beliebiges anderes Ziel handeln, das Informationen empfangen kann. 

Beim Enterprise Integrator können wir mehrere dieser Appender finden, die konfiguriert sind.

LOG4J2 2

Der erste Appender ist die Konsole. Sie sehen hier die Definition des Ausgabetyps Carbon-Konsole. Wenn Sie z. B. das [%d] aus dem Layout-Muster entfernen, entfällt der Datums-Zeitstempel in der Ausgabe. Fügt man ihn wieder ein, wird die vorherige Situation wiederhergestellt. 

Viele Appenders unterstützen die Angabe der Syntax einer Logline durch die Verwendung eines Musters. Protokolle enthalten mehrere Informationen, wie z. B. die Zeit, zu der die Log-Anweisung ausgeführt wurde, den Log-Level der Log-Zeile, die Klasse, die die Log-Zeile ausgegeben hat und die Nachricht, die von der Klasse der Log-Zeile hinzugefügt wurde. Mit dem Muster steuern Sie, welche und in welcher Reihenfolge die Attribute der Log-Anweisungen in den Appender geschrieben werden.

LOG4J2 3

Es gibt noch mehr Arten von Appendern als den Rolling File Appender und die Konsole, aber das sind die beiden, die im Enterprise Integrator verwendet werden. Wenn Sie die Konfiguration überprüfen, können Sie sehen, dass es einen täglichen Rollover des Carbon-Protokolls sowie eine auf der Größe basierende Richtlinie gibt.

Es wird empfohlen, diese Einstellungen so zu wählen, dass sie Ihren Anforderungen entsprechen. Eine zu knappe Einstellung der Rollover-Parameter bedeutet, dass die Protokolldatei recht häufig überrollt wird, was das Nachschlagen von Informationen aus ihr mühsamer machen kann. Die Einstellung zu groß kann bedeuten, dass die Protokolldatei zu groß wird, so dass Ihr Tooling nicht mehr handhabbar und nützlich für Sie ist. 

LOG4J2 4

Etwas unterhalb der Appenders befinden sich die Logger, die in einer Liste definiert sind, die Sie im Bild oben sehen können. Ein Logger muss wie das Beispiel, das Sie für org.apache.synapse sehen, definiert und zur Liste der Logger hinzugefügt werden. Wenn der Logger korrekt definiert ist, wird er aktiviert und es können Logmeldungen erscheinen, wenn er ausgelöst wird.

Eigene Logger hinzufügen 

Sie können Ihre eigenen Logger zu dieser Übersicht hinzufügen, indem Sie einfach die Java-Klasse angeben, die Sie protokollieren möchten. In Java sind Klassen Teil eines Packages. Ein Package umfasst null oder mehr Klassen. Packages werden hierarchisch betrachtet, wie eine Baumstruktur. 

Sie können einem Logger einen Klassennamen geben, um sehr spezifisch zu werden, oder Sie können ein Package angeben, das protokolliert werden soll. Wenn Sie ein Package angeben, gelten die in dieser Logger-Konfiguration vorgenommenen Einstellungen dann für alle Klassen innerhalb dieses Packages (und damit auch für alle Klassen in Unter-Packages). Dabei gilt: Je höher die Java-Klassen sind, also zum Beispiel org.apache.synapse, desto mehr tiefer liegende Klassen sind betroffen. Es sind beispielsweise Logger wie org.apache.synapse.mediators definiert, welche nur die Mediatoren innerhalb von synapse auslösen und nicht org.apache.synapse.transport.http.headers. 

Einen neuen Logger zu erstellen bedeutet, dass Sie die Klasse oder das Paket identifizieren, das Sie loggen möchten, in diesem Fall org.yenlo.example, indem Sie die folgenden drei Zeilen erstellen.

logger.org-yenlo-example.name=org.yenlo.example
logger.org-yenlo-example.level=DEBUG
logger.org-yenlo-example.appenderRef.CARBON_LOGFILE.ref = CARBON_LOGFILE

Zuletzt müssen wir es zur Liste der Logger hinzufügen. 

LOG4J2 5

Nun, wenn diese Klasse verwendet wird, und sie wurde mit Log4j2 im Hinblick darauf entwickelt, werden wir Meldungen erhalten.

Wir wollen den Log-Level für eine bestimmte Java-Klasse erhöhen.

Mit Log4j2 experimentieren

In diesem Blog werden wir ein wenig mit dem Logging herumspielen. Im Enterprise Integrator 6.6.0 erfolgt das Logging jetzt über die Datei Log4j2.properties und nicht mehr über die Management-Konsole.

Warnung! Vorsicht auf einem Produktivsystem, wenn Sie die Protokollebenen auf etwas Detaillierteres als INFO (also DEBUG oder TRACE) einstellen, denn dadurch können die Protokolle sehr viel ausführlicher werden und die Systemleistung beeinträchtigen. Die Logdatei auf der Festplatte kann je nach Serverlast sehr schnell an Größe zunehmen.

Die Datei „Log4j2.properties“ finden Sie im Verzeichnis [EI-HOME]/conf. Die Änderungen können mit einem Texteditor vorgenommen werden.

Generell wird es als praktisch angesehen, die folgenden Zeilen zu ändern/entkommentieren und/oder Zeilen hinzuzufügen, die nicht vorhanden sind. Stellen Sie sie auf INFO ein, da DEBUG dazu führt, dass detaillierte Informationen über Anfragen und Antworten, die in WSO2 Enterprise Integrator ein- und ausgehen, sowie solche, die an andere Systeme gesendet und von diesen empfangen werden, protokolliert werden. 

LOG4J2 6

Fügen Sie nun:

  • synapse-transport-http-headers
  • synapse-transport-http-wire
  • httpclient-wire-header
  • httpclient-wire-content

zur Loggerliste hinzu.

LOG4J2 7

Durch Änderung dieser Zeilen sind wir in der Lage, das Request- und Response-Wire-Logging ein- und auszuschalten. 

Testen wir diese Änderung der Logger-Konfiguration.

Starten Sie WSO2 Enterprise Integrator, sofern er noch nicht läuft. Legen Sie über die Verwaltungskonsole des Enterprise Integrator einen einfachen Proxy mit dem Namen ‚test‘ an, der die folgenden Felder enthält:

LOG4J2 8

Mit der Funktion „Try it“ des Test-Proxys können Sie eine Nachricht an diesen senden.

LOG4J2 9

Schauen Sie sich die Konsolen-Ausgabe oder die Datei wso2carbon.log an, um die Protokollinformationen zu sehen, die wir für die Protokollierung konfiguriert haben.

LOG4J2 10

Setzen Sie den Log-Level der logger.synapse-transport-http-wire- und logger.synapse-transport-http-header sowie logger.httpclient-wire-header und logger.httpclient-wire-content wieder auf INFO-Level. Warten Sie einen Moment, damit das Logging-Framework Ihre Änderung erkennt und eine weitere Nachricht an den Test-Proxy sendet.

Sie werden feststellen, dass die http-transport- und wire-bezogenen Protokollmeldungen bei Ihrem zweiten Versuch nicht mehr angezeigt werden.

Protokollierung konfigurieren

Wir werden den Log-Level der Mediatoren ändern, um den Effekt zu sehen, wenn eine Nachricht ins System gelangt.

Erstellen wir zunächst einen sehr einfachen Logging-Echo-Proxy-Dienst, der einen Mediator hat.

Wechseln Sie zum Hauptreiter und klicken Sie zu „Add proxy service“.

Dies ist der Quellcode:

<?xml version="1.0" encoding="UTF-8"?>
LOG4J2 11
<proxy name="logProxy" startOnLoad="true" transports="https http" xmlns="http://ws.apache.org/ns/synapse">
    <target>
        
        <inSequence>
          <log>
             <property expression="$ctx:SYSTEM_DATE" name="timetest"/>
          </log>
          <respond/>
        </inSequence>
        <outSequence/>
        <faultSequence/>
    </target>
</proxy>

Wählen Sie als Typ „Benutzerdefinierter Proxy“ und verwenden Sie „logProxy“ als „Proxy Service Name“.

Nachdem Sie den Namen eingegeben haben, klicken Sie auf „Switch to source view“ und ersetzen Sie den Body durch den oben gezeigten Quellcode.

Durch Klicken auf „Speichern“ wird die Erstellung des Proxys abgeschlossen.

Klicken Sie auf „Try this service“ des logProxy, damit wir einige Daten an den Proxy senden können.

Fügen Sie im Try-it-Fenster einen einfachen Body ein.

LOG4J2 12

Klicken Sie auf „Senden“, um den Proxy-Dienst aufzurufen. Lassen Sie diese Browser-Registerkarte geöffnet, Sie werden sie später noch brauchen.

Wenn Sie jetzt die Protokolle in der Konsole oder in der Datei wso2carbon.log überprüfen, werden Sie sehen, dass es eine LogMediator-Zeile gibt, die anzeigt, dass der Proxy aufgerufen wurde.

INFO {org.apache.synapse.mediators.builtin.LogMediator} -  To: /services/logProxy.logProxyHttpSoap12Endpoint, WSAction: urn:mediate, SOAPAction: urn:mediate, MessageID: urn:uuid:0cf3cc3f-3bb9-49c7-b754-06534f185e47, Direction: request {org.apache.synapse.mediators.builtin.LogMediator}

Änderungen in Log4j2 vornehmen

Öffnen Sie die Log4j2-Datei und fügen Sie einen neuen Logger hinzu, wie ich es weiter oben bereits beschrieben habe. Fügen Sie diese Zeilen hinzu:

logger.org-apache-synapse-mediators.name=org.apache.synapse.mediators
logger.org-apache-synapse-mediators.level=DEBUG
logger.org-apache-synapse-mediators.appenderRef.CARBON_LOGFILE.ref = CARBON_LOGFILE

Und nicht vergessen, den Logger in die Liste loggers= aufzunehmen. Finden Sie einfach den letzten Eintrag, und fügen Sie ‚ , org-apache-synapse-mediators‘ am Ende hinzu. Speichern Sie die Datei. 

Nun rufen Sie den try-it-Dienst für den logProxy erneut auf, Sie sollten ihn immer noch in Ihrem Browser geöffnet haben. Falls nicht, gehen Sie zurück zu dieser Anleitung, um zu prüfen, wie Sie den try-it-Dienst öffnen können.

Wenn Sie jetzt die Logdatei überprüfen, dann werden Sie mehr Details in der Logausgabe der Mediatoren sehen.

Zum Beispiel sollte diese Zeile erscheinen:

[2021-06-03 15:35:46,253] DEBUG {org.apache.synapse.mediators.builtin.LogMediator} - Start : Log mediator
[2021-06-03 15:35:46,254]  INFO {org.apache.synapse.mediators.builtin.LogMediator} - To: /services/logProxy.logProxyHttpSoap12Endpoint, WSAction: urn:mediate, SOAPAction: urn:mediate, MessageID: urn:uuid:43393d8a-f10f-4d2a-accf-fa6e5f8beea1, Direction: request, datetest = 6/3/21 3:35 PM
[2021-06-03 15:35:46,255] DEBUG {org.apache.synapse.mediators.builtin.LogMediator} - End : Log mediator

Sie sehen, dass wir jetzt mehr Informationen über den LogMediator haben, den wir gerade verwendet haben. Und zwar über alle Mediatoren, da wir die Protokollierung auf Mediatoren eingestellt haben, und nicht speziell auf einen LogMediator. Ich habe sie nur nicht sichtbar gemacht.

Schlussfolgerung

Die Protokollierung bietet dem Systemadministrator oder den Entwicklern einen Einblick in die Vorgänge innerhalb des Produkts. Die Log-Informationen darüber, was das Produkt beim Eingang einer Nachricht in das System tut, oder die Logs, die zeigen, welche Schritte der Vermittlungsfluss durchläuft, sind von hohem Wert für die Ursachenanalyse. 

Wir bei Yenlo haben verschiedene Ansätze entwickelt, wie wir am besten in unseren Integrationen protokollieren, so dass wir im Nachhinein nachvollziehen können, wie eine Nachricht in der Integrationsschicht verarbeitet wurde. 

Ohne eine angemessene Protokollierung ist das Produkt eine Blackbox, in der wir nicht sehen können, was im Falle von unerwarteten Fehlern passiert. Ein angemessenes Logging kann das Produkt viel transparenter machen, was es macht, und daher ist es immer eine gute Idee, Logging in Ihre Integrationen einzubauen und das Logging-Framework so zu konfigurieren, dass es genau das protokolliert, was Sie wollen.

Der kombinierte Einsatz von Tools wie dem ELK-Stack, der Ihre Logs aus mehreren Quellen in einem einzigen Tool für die Log-Suche zusammenfassen kann, ist unserer Meinung nach eine sehr leistungsstarke Kombination. So können wir zum Beispiel ein Dashboard auf Basis von Business-Logs über Verkäufe in Kibana erstellen. Aber das ist vielleicht ein Thema für einen anderen Blog.