Besser zentral: Professionelles Logging

Beispiel

Wie die konkrete Anbindung funktioniert, ist im Folgenden auf Basis eines einfachen Beispiels zu sehen: Auf einen FTP-Server greifen mehrere FTP-Clients zu. Die Zugriffe sollen so geloggt werden, dass die Nutzeranfragen durchgängig nachvollziehbar sind. Das Beispiel verwendet den Apache FTP Server und den Netzwerk-Browser JFtp auf der Client-Seite. Für das Logging arbeiten die beiden quelloffenen Anwendungen mit log4j.

Um die Zusammenstellung der Logs und ihren Transport zum Log-Server kümmert sich ein passender log4j-Appender (AsyncSocketAppender). Dieser wird von der Herstellerseite heruntergeladen und im Klassenpfad der Anwendung bekannt gemacht. Damit log4j den Appender verwenden kann, wird es über eine ebenfalls im Klassenpfad liegende log4j-Konfiguration so eingerichtet wie im folgenden Code-Beispiel im Properties-Stil abgebildet.

01: log4j.rootLogger=DEBUG, LFS
02: log4j.appender.LFS = com.moonlit.logfaces.appenders.AsyncSocketAppender
03: log4j.appender.LFS.remoteHost = logserver-demo.accso.de
04: log4j.appender.LFS.port = 55200
05: log4j.appender.LFS.reconnectionDelay = 5000
06: log4j.appender.LFS.offerTimeout = 0
07: log4j.appender.LFS.queueSize = 200
08: log4j.appender.LFS.threshold = ALL
09: log4j.appender.LFS.locationInfo = true
10: log4j.appender.LFS.backupFile = c:/logs/ftpd.log.xml
11: log4j.appender.LFS.application = apache-ftpserver-dev

Zeile 1 stellt den in Zeile 2 referenzierten Logfaces-Appender (LFS) als Standardausgabe von log4j ein. Sie definiert außerdem, dass Log-Ereignisse ab Level DEBUG über diese Ausgabe protokolliert werden sollen. Die Zeilen 3 bis 7 bestimmen die Verbindungsparameter. Sie geben an, wohin die Ereignisse übermittelt werden (logserver-demo.accso.de:55200), wie lange nach einem Verbindungsabbruch bis zum nächsten Verbindungsversuch gewartet wird (5000 ms), ob und wie lange bei einem beständig langsamen Log-Server auf diesen gewartet werden soll (0 ms) und wie viele Log-Einträge in der lokalen Warteschlange auflaufen können (200 Stück). Zeile 8 definiert noch auf Appender-Ebene das Log-Level, unterhalb dessen Ereignisse verworfen und oberhalb dessen sie übertragen werden; im Beispiel werden alle übertragen.

log4j spickt einige Log-Ereignisse mit Lokalisierungsinformationen wie Klassen- und Methodennamen sowie Zeilennummern. So stellen insbesondere Log-Ereignisse zu Exceptions über Stack Traces einen genauen Bezug zu den beteiligten Quelltextstellen her. Die Definition locationInfo=true sorgt dafür, dass der Appender die Informationen überträgt. Falls der Log-Server nicht erreichbar ist, werden die Ereignisse in eine lokale Datei im log4j-XML-Format geschrieben. Aus dieser Rückfallebene lassen sie sich später bei Bedarf im Log-Server importieren. Abschließend ordnet die Konfiguration den Appender einer Anwendung zu (apache-ftpserver-dev). Er wird den Lesern bei der Analyse der Log-Dateien erneut begegnen.

Inhaltlich besteht ein Anwendungslog-Eintrag klassisch aus den Attributen Zeitstempel, Name des Loggers, Thread-Kennung, Log-Level, einer Nachricht und gegebenenfalls einem Stack Trace. Die Inhalte stellt bereits log4j bereit. Der Logfaces-Appender ergänzt, zu welcher Anwendung (siehe Konfiguration) und auf welcher Maschine ein Log-Ereignis erzeugt wurde.

Damit es im Beispiel eindrucksvoll knallt, kann man etwa den Server-Code des STOR-Befehls manipulieren (vgl. Abb. 2). Die Log-Ausgabe mit anhängiger NullPointerException ist gleich weiter unten zu sehen (vgl. Abb. 6).

Das Beispiel lässt es krachen: Error-Log-Ausgabe mit angehängter NullPointerException (Abb. 2)

Der Logfaces-Server nimmt die Einträge entgegen und schreibt sie wahlweise in eine beliebige relationale Datenbank oder eine MongoDB als dokumentenorientierte NoSQL-Datenbank. In der Praxis ist die Verwendung einer dokumentenorientierten Persistierung von Log-Einträgen aus folgenden Gründen ratsam: Zum einen lassen sich Logs um weitere Datenfelder ergänzen (siehe unten), wodurch sich das Datenbankschema dynamisch ändert. Zum anderen sind oft nur einige Datenfelder eines Log-Ereignisses gefüllt, sodass eine schemalose Speicherung ökonomischer ist. Für den Start empfiehlt sich die Installation von Log-Server und -Datenbank auf derselben Maschine. Bei Logfaces findet der Server die MongoDB-Installation automatisch.

Zum Einrichten stellt der Logfaces-Server eine Weboberfläche bereit. Nach dem Hochladen der Lizenzdatei funktioniert der Server dann. Die Voreinstellungen sind weitgehend sinnvoll getroffen. Insbesondere ist der Empfang von Log-Ereignissen über log4j-Appender bereits standardmäßig aktiviert (vgl. Abb. 3).

Log-Einträge lassen sich aus Quellen unterschiedlicher Art empfangen (Abb. 3).

Abhängig von verfügbarem Speicherplatz und betrieblichen Vorgaben sollte noch ein Blick auf die Verwahrdauer (Retention) der persistierten Einträge geworfen werden (vgl. Abb. 4).

Logging benötigt temporäre Persistenz - eine Datenbank im Hintergrund hilft dabei (Abb. 4).

In Szenarien, bei denen Server viele Clients (quasi-)parallel bedienen, ist der Einsatz eines Nested oder Mapped Diagnostic Context (NDC, MDC) zu empfehlen, um den Log-Einträgen kontextabhängige Zusatzinformationen wie eine Session-ID sowie eine Nutzer- oder Client-Kennung mitzugeben (siehe Kasten).

Diagnostic Context

Nahezu alle Log-Bibliotheken unterstützen zwei Arten diagnostischer Kontexte: Nested Diagnostic Contexts (NDC) sowie Mapped Diagnostic Contexts (MDC). Sie erlauben es der Anwendung, spezifische Informationen zum Ausführungskontext zu sammeln, wie Session-IDs, Übergabeparameter oder Zwischenergebnisse (vgl. hier). Diese Informationen bleiben innerhalb eines Thread erhalten und werden beim Erzeugen von Log-Ereignissen automatisch beigefügt.

Ein NDC implementiert einen Stack. Typischerweise, werden ihm beim Abstieg in der Aufrufhierarchie der Anwendung Daten hinzugefügt, die bei der Rückkehr wieder entfernt werden. Ein MDC ist eine Map mit Schlüssel-Wert-Paaren. Er nimmt eine Menge "benannter" Werte auf.

Auch für das Beispiel lässt sich von der Annahme ausgehen, dass der FTP-Server mehrere Clients zeitgleich bedient und die Übermittlung einiger benutzerdefinierter Felder bei der späteren Analyse hilfreich sein wird (vgl. Abb. 5).

Über definierbare Felder kann man anwendungsspezifische Kontextinformation bekannt machen (Abb. 5).

Zur Autorisierung der an den Logs interessierten Nutzer lässt sich noch eine LDAP-Anbindung konfigurieren. Bei der Anmeldung mit dem Logfaces-Client wird diese dann berücksichtigt. Abschließend können Anwender noch Benachrichtigungen konfigurieren. Hierüber kann der Log-Server die Operatoren alarmieren oder Reports an Interessierte ausliefern.