Gabi und Sascha
Kategorien : Alle | Berlin | Bücher | Fotografie | Java | Linkhalde | Weichware | Verfassung

Über das Loggen habe ich schon mehrfach geschrieben. Für meinen Arbeitgeber haben wir ein Framework geschaffen, welches loggen etwas verbessert. Dies hinsichtlich eindeutiger IDs, Internationalisierung und Validierung während des compilierens. Die Implementierung reduziert grep Monster, mit denen Operatoren sonst hantieren mussten.

Ich bin mit dem Loggen immer noch unzufrieden

Wir kennen heute zwar unterschiedliche Log-Level und unterschiedlichste Konfigurationsmöglichkeiten für die Logger. Aber im Grund ist es immer noch ein simples raushauen von Nachrichten, deren Informationsgehalt mehr oder minder wertvoll ist. In den meisten Situationen bin ich sogar der Meinung, dass der Informationsgehalt fast gegen Null geht. Das liegt am Ziel des Loggens. Log-Ausgaben sind so gut wie immer nur für die Post-mortem-Analyse interessant. Also dann, wenn ein Fehler analysiert werden muss.

Für Post-mortem-Analyse nicht die richtigen Informationen

Für die Post-mortem-Analyse sind in der Log-Ausgaben meistens nicht die richtigen Daten vorhanden. Das liegt daran, dass wir uns abgewöhnt haben das Ergebnis jeder erfolgreich abgeschlossene Funktionalität zu loggen. Grundsätzlich ist das ist kein Mangel. Wir hätten sonst wieder die unendlichen Textwüsten vergangener Tage. In den wenigen vorhandenen Daten sind dann aber meistens die entscheidenden Informationen nicht vorhanden. Dabei geben die Entwickler diese (Kontext)-Informationen meistens aus. Aber aus Gründen der Performanz wird die Ausgabe unterdrückt.


    if (LOG.isEnabled(DEBUG)) {LOG.debug("Current…");}

Kontextinformation für Post-mortem-Analyse

Sinnvoll würde es sein die Kontextinformationen von debug Logausgaben für eine Post-mortem-Analyse zu bekommen.

Anmerkung

Viele Logging Systeme sind von Log4j inspiriert. Leider hat die damalige Genialität von Log4j dazu geführt, dass sich Log-Systeme seit über einem Jahrzehnt nicht wirklich weiter entwickelt haben. Daran ändert auch Logback Implementierung von Ceki Gülcü nichts.

Der Einfachheit halber verwende ich die Log4j Nomenklatur für Log-Level. Diese wird auch durch Abstraktions APIs wie commons-logging oder slf4j nachgebildet.

Dazu müssen aktuelle Logging Systeme derart erweitert werden, dass sie

  1. zu einem bestimmten Zeitpunkt mit der Aufzeichnung von debug Meldungen beginnen.
  2. aufgezeichnete debug Informationen im Fehlerfall über das Log-System ausgeben.

Der Eintrittspunkt für die Speicherung kann als Stack gespeichert werden, um den Umfang des Kontext zu erweitern oder dynamisch zu verschieben. Alternativ kann ein Name verwendet werden. Hier ist die Idee noch nicht weiter ausgereift.

Logging goes Architecture

Egal ob auf Namen basierend oder Stack orientiert, Loggen muss mit dem Ansatz etwas mehr koordiniert werden. Wo findet der Eintritt in einen Log-Kontext statt? Kontexte dürfen nicht zu eng gezogen werden, aber auch nicht zu weit auseinander liegen. Dies sind Entscheidungen, die mehr auf architektonischer Ebene getroffen werden müssen, weg vom Entwickler.

Wie weiter?

Das weiss ich zu diesem Zeitpunkt auch noch nicht. Eine Herausforderung ist die Umsetzung. Sie muss in bestehende Logging Systeme eingepasst werden. Java Util Logging oder Log4j werden noch über Jahre hinaus in der Java Welt die bestehenden Logging Systeme bleiben. Um sie herum ist einfach ein zu grosses Ökosystem gewachsen. Aber zumindest die Frontend Systeme wie Apache commons-logging oder slf4j können ersetzt werden. Hier kann angesetzt werden.


Warum nicht die Debugmeldungen und Positivmeldungen in einem fixedsize Memorylogger online halten, dessen Inhalt im Fehlerfall in die normale Logdatei geschrieben wird? Grüße, Timo

Das ist die technische Umsetzung. So würde ich es machen. Das grösste Problem ist die Semantik des Kontext. Ausserdem unterstützen die aktuellen APIs noch keine Methoden dafür. Das muss aufgebohrt werden. Beispielsweise mit einem

   try {
      Logger.enterContext();
   } catch (final Exception e) {
      Logger.error(message); // löst debug logging aus
   } finally {
      Logger.exitContext();
   }

Noch besser würde es natürlich sein, wenn das System alles so erweitert, dass nur eine Annotation im Code ist und AOP mässig alles in den Code eingewebt wird.