Die Reparatur alter Fehler kostet oft mehr als die Anschaffung neuer. – Wieslaw Brudzinski

25 Logging und Monitoring

Nicht nur in der Informatik ist der rasante Wechsel der Technologien zu beobachten. Ein Beispiel ist das Automobil, das in den letzten 100 Jahren tiefgreifende Änderungen durchmachte. Von den vielen Schlagwörtern sind ESP und ABS nur zwei, die zudem eine Elektrifizierung bedeuten. Die Komponenten eines Autos sind vernetzt, und Signalgeber melden in Echtzeit Informationen an elektronische Steuereinheiten (Electronic Control Units, ECU). In modernen Kraftfahrzeugen werten fast 100 ECUs mehr als 1 GB an Daten pro Sekunde aus. Damit verschiebt sich auch eine Fehlerquelle: Während früher schon eine Sicherung durchbrennen musste, bleibt heute ein Auto schon stehen, wenn der Bordcomputer einen Fehler meldet. Auch in der Entwicklung ist das teuer: BMW gibt an, dass 40 % der Herstellungskosten auf Elektronik und Software anfallen.

25.1 Logging mit Java

Das Loggen (Protokollieren) von Informationen über Programmzustände in externe Speicher ist ein wichtiger Teil, um später den Ablauf und Zustände von Programmen rekonstruieren und verstehen zu können. Mit einer Logging-API lassen sich Meldungen in eine XML-Datei, Textdatei oder Datenbank schreiben oder über einen Chat verbreiten.

25.1.1 Logging-APIs

Apache log4j (http://logging.apache.org/log4j/) ist eine ausgezeichnete API zum Loggen. Die Open-Source-Bibliothek ist sehr populär und wird in nahezu jedem größeren Java-Projekt eingesetzt. Sun hat in Java 1.4 eine eigene Logging-API (JSR 47) eingeführt, was die Java-Gemeinde in Erstaunen versetzte, da es viele Erfahrungen mit log4j gibt und log4j sehr gut getestet ist. Suns Logging-API ist dagegen nur ein laues Lüftchen, das nur Grundlegendes wie hierarchische Logger bietet. An die Leistungsfähigkeit von log4j mit einer großen Anzahl von Schreibern in Dateien (FileAppender, RollingFileAppender, DailyRollingFileAppender), Syslog und NT-Logger (SyslogAppender, NTEventLogAppender), Datenbanken, Versand über das Netzwerk (JMSAppender, SMTPAppender, SocketAppender, TelnetAppender) kommt das Sun-Logging nicht heran. Versuche, mit dem Apache Commons Logging (http://jakarta.apache.org/commons/logging/) die Logging-Bibliothek von Sun und log4j unter einen Hut zu bringen, führen in der Praxis zu gewaltigen Problemen (http://www.qos.ch/logging/thinkAgain.jsp) und werden von einigen Kritikern als größter Irrsinn beschimpft (http://www.jroller.com/page/fate/?anchor=the_apache_syndrome).

25.1.2 Logging mit log4j

Die Logging-Bibliothek log4j (http://logging.apache.org/log4j/1.2/index.html) ist Open Source und unterliegt der unternehmerfreundlichen Apache Software License. Log4j ist so populär geworden, dass die API auch in anderen Programmiersprachen übersetzt wurde, etwa für C++ (log4cxx), Microsoft .NET (log4net) oder PHP (log4php). Die Installation im Fall von Java besteht darin, ein Java-Archiv, wie log4j-1.2.15.jar, in den Klassenpfad aufzunehmen.

Das erste Beispiel

Eine Beispielklasse deklariert ein Logger-Objekt als statische Variable, damit main() später über log.info() und log.error() Meldungen über den Logger absetzen kann. Das Hauptprogramm nutzt zur ersten Konfiguration den BasicConfigurator – im nächsten Schritt ersetzen wir diesen durch eine Konfigurationsdatei.

Listing 25.1 com/tutego/insel/logging/Log4jDemo.java, Log4jDemo

public class Log4jDemo 
{ 
  private final static Logger log = Logger.getLogger( Log4jDemo.class ); 
 
  public static void main( String[] args ) 
  { 
    BasicConfigurator.configure(); 
 
    log.info( "Dann mal los." ); 
 
    try 
    { 
      ((Object) null).toString(); 
    } 
    catch ( Exception e ) 
    { 
      log.error( "oh oh", e ); 
    } 
 
    log.info( "Ging alles glatt." ); 
  } 
}

Die Ausgabe ist:

0 [main] INFO com.tutego.insel.logging.Log4jDemo   – Dann mal los. 
2 [main] ERROR com.tutego.insel.logging.Log4jDemo  – oh oh 
 
java.lang.NullPointerException 
  at com.tutego.insel.logging.Log4jDemo.main(Log4jDemo.java:18) 
2 [main] INFO com.tutego.insel.logging.Log4jDemo  – Ging alles glatt.

Zu sehen sind: Die Anzahl vergangener Millisekunden seit dem Start des Programms, Name des loggenden Threads, Log-Level, Name des Loggers und die geloggte Nachricht.

Logger, Level, Appenders, Layout

Beim Logging mit log4j trifft man auf vier zentrale Begriffe:

• Logger. Derjenige, der die zu loggenden Einträge annimmt. Steuert, ob überhaupt geloggt werden soll. Steht im Zentrum des Interesses.

• Level. Was soll geloggt werden? Nur Fehler, oder auch Warnungen und Informationen? Der Level priorisiert die Ausgaben, damit die Entwickler den Wald vor lauter Bäumen sehen können.

• Appenders. Hängen die Log-Ausgabe irgendwo an. Etwa an Dateien, die Konsole, NT-Event-Log, Unix Syslog …

• Layout. Wie sollen die Ausgaben formatiert werden? Etwa in HTML oder XML?

Der Logger ist mit einem Appender, einem Log-Level und mit einem Layout assoziiert.

Logger-Konfiguration

Log4j lässt sich konfigurieren mit Java-Anweisungen im Quellcode oder mit Konfigurationsdateien im XML- oder Properties-Format. Nehmen wir die programmierte Konfiguration über BasicConfigurator.configure(); aus dem Programm, so liefert log4j lediglich die Ausgabe:

log4j:WARN No appenders could be found for logger (com.tutego.insel.logging.Log4jDemo). 
log4j:WARN Please initialize the log4j system properly.

Der Hinweis ist klar: Es muss eine Konfiguration geben. Setzen wir daher in den Klassenpfad eine Datei mit genau dem Namen log4j.properties und dem folgenden Inhalt:

log4j.rootLogger=DEBUG, A 
log4j.appender.A=org.apache.log4j.ConsoleAppender 
log4j.appender.A.layout=org.apache.log4j.PatternLayout 
log4j.appender.A.layout.ConversionPattern=%-4r [%t] %-5p %c %x – %m%n

Starten wir wiederum das Programm, ist die Ausgabe wie vorher:

0    [main] INFO  com.tutego.insel.logging.Log4jDemo  – Dann mal los. 
2    [main] ERROR com.tutego.insel.logging.Log4jDemo  – oh oh 
java.lang.NullPointerException 
  at com.tutego.insel.logging.Log4jDemo.main(Log4jDemo.java:17) 
2    [main] INFO  com.tutego.insel.logging.Log4jDemo  – Ging alles glatt.

Das Muster »=%-4r [%t] %-5p %c %x – %m%n« bestimmt demnach die Formatierung der Ausgabe in den ConsoleAppender. Der Log-Level ist alles »größer« als DEBUG. Wenn wir das einschränken auf

log4j.rootLogger=ERROR, A

bekommen wir lediglich in der Konsolenausgabe Folgendes geschrieben:

0    [main] ERROR com.tutego.insel.logging.Log4jDemo  – oh oh 
java.lang.NullPointerException 
  at com.tutego.insel.logging.Log4jDemo.main(Log4jDemo.java:17)

Logger-Hierarchien

Ohne eine Logging-API würden Entwickler vermutlich mit System.out oder System.err Ausgaben schreiben. Dabei gelangen jedoch alle an System.out gesendeten Zeichenketten in den Standardausgabekanal und alle an System.err gesendeten Fehler oder Warnungen in den Fehlerstrom. Ein Wunsch ist, dass die Ausgaben nur für gewisse Pakete oder Klassen gelten sollten. Bei Ausgaben über System.out/err lässt sich das »Logging« aber nicht einfach ausschalten und dann wieder einschalten.

Eine gute Logging-API bietet daher Hierarchien, sodass gewisse Einstellungen einer Ebene auf untergeordnete Ebenen übertragen werden. Diese Baumstruktur kennen wir schon von Paketen.

Die Wurzel-Hierarchie steht am Anfang aller Hierarchien. Sie bildet den Root-Logger. Er hat keinen Namen.

Wenn wir in unserem Fall für das Paket com.tutego und alle Unterpakete den Log-Level auf WARN stellen, schreiben wir in der Konfigurationsdatei:

log4j.logger.com.tutego=WARN

Ihr Kommentar