Servlet logging mit log4j

Autor:
Ralf Rapude

1. Einleitung
Gerade bei der Erstellung komplexerer Anwendungen kommt dem Logging eine große Bedeutung zu. Zwar lassen sich auf die Schnelle auch über ein "System.out.println()" Ausgaben erstellen, doch hat diese Form des Loggings IMHO einige große Nachteile:

  1. Es lassen sich keine Level für die Ausgabe festlegen, d.h, das Logging erfolgt unabhängig vom Gewicht, das der Entwickler dem Ereignis zuordnet.
  2. Es gibt keine zentrale Steuerung für das Logging. Ist eine Anpassung gewünscht, muß die komplette Codebasis durchsucht und ggf. angepasst werden.
  3. Die Ausgaben sind unter Umständen in unterschiedlicher Form erwünscht, d.h. bestimmte Informationen sollen vielleicht auf der Konsole für eine sofortige Kontrolle ausgegeben werden, andere in eine Textdatei geschrieben, und wieder andere evtl. per Mail oder SMS an einen Verantwortlichen weitergeleitet werden (z.B. bei einem Systemabsturz).

Log4j bietet diese Möglichkeiten und ist, sollte es nicht durch die ab Java 1.4 integrierte Logging Api abgelöst werden, Mittel der Wahl, gerade wenn es um Anwendungen geht, die Servlets in großem Umfang einsetzen, da hier ein gezieltes Debugging und Tracing der Applikation ansonsten nur über ein Remote-Debugging möglich wäre.
Zwar bringt Tomcat als Servlet-Engine ein eigenes Logging mit, doch gibt es hier eine große Zahl von Schaltern, die an unterschiedlichster Stelle untergebracht sind, so das eine gezielte Steuerung zu einem mühsamen Unterfangen werden kann.
Ich ziehe deshalb log4j vor und empfinde diese Api gerade im Zusammenhang mit Tomcat als große Erleichterung, denn Tomcat arbeitet je nach Vorliebe es Entwicklers sowohl mit der jakarta.commons logging Api zusammen wie auch mit java.util.logging oder eben log4j.

top

2. Systemvoraussetzungen
Um dieses Tutorial nachzuvollziehen ist eigentlich nur das Sun SDK, log4j und eine Servlet-Engine notwendig, etwas komfotabler wird es jedoch, wenn weitere geeignete Werkzeuge vorhanden sind. Dieses Tutorial entstand deshalb unter folgenden Voraussetzungen:
Es wurde unter Eclipse 2.1 entwickelt. Bisher hat sich diese IDE ja nicht gerade mit Ruhm bekleckert, wenn es um die Erstellung von Web-Anwendungen ging, doch hat sich dies gründlich geändert nachdem MyEclipseIde an dem Markt ging, denn jetzt werden dem Entwickler sehr schöne (aber nicht kostenlose) Entwicklungswerkzeuge an die Hand gegeben, die z.B. einen vernünftigen jsp-Editor (incl. Syntaxhighlighting, Code-Completition), Struts-Support, X-Doclet Unterstützung, sowie einen xml-Editor usw. beinhalten.
Es wurde ausserdem das Sysdeo-Tomcat Plugin verwandt, um einen möglichst schnellen und problemlosen Tomcat-Restart zu ermöglichen, sowie Tomcat 5.0.16 und das Ganze lief unter Linux (Suse 8.2) als OS. Zu beziehen sind diese Dinge hier :o):

  • Java SDK ( zur Zeit aktuell 1.4.2_03)
  • Log4j (momentan 1.2.8)
  • Eclipse (aktuell ist 3.0, besser ist aber die Version 2.1 geeignet, da die 3.0 im Zusammenhang mit diversen Plugins, zu diesem Zeitpunkt noch nicht stabil lief).
  • MyEclipseIde (es gibt eine 30 Tage Testversion zum Download)
  • Sysdeo Tomcat Plugin für Eclipse (aktuell ist momentan V 2.2)
  • Tomcat (zur Zeit V 5.0.16)

Das komplette Tutorial gibt es als Eclipse Projekt hier. Es fehlt einzig die log4j.jar, die noch eingebunden werden muß.

top

3. Vorbereitungen
Nach dem herunterladen des tutorials zunächst das zip entpacken, und, falls Eclipse genutzt wird, als Projekt importieren. Dieser Import ist einfach zu bewerkstelligen, wenn im Navigator oder dem Package Explorer über die rechte Maustaste der der Menüpunkt "import" ausgewählt wird. Wenn ein anderer Editor genutzt wird, ist es wichtig, dass noch die log4j.jar noch in den Classpath eingebunden wird. Danach das Projekt kompilieren und jetzt sollte folgende Verzeichnisstruktur sichtbar sein:

Um das Projekt nun noch in den Tomcat einzubinden, gibt es mehrere Möglichkeiten. Entweder es wird, wennn das Sysdeo Plugin für Eclipse genutzt wird das komplette Projekt markiert, dann die rechte Maustaste geklickt und "Tomcat Projekt/Kontext in server.xml aktualisieren" ausgewählt oder dieser Eintrag wird von Hand unter $TOMCAT_HOME/conf/server.xml vorgenommen. Der Eintrag sollte am Ende der Datei vorgenommen werden und sollte so aussehen:

...
...
       <!-- hier folgt der Eintrag -->
       <Context path="/log4jtut" reloadable="true" docBase="/pathto/log4jtut" />
       <!-- Rest der server.xml -->
     </Host>
   </Engine>
 </Service>
</Server>

Dieser Eintrag setzt einen sogenannten Context, d.h. obwohl sich das Tutorial nicht im Verzeichnis "webapps" von Tomcat befindet, mappt Tomcat auf das angegebene Verzeichnis unter docBase, wenn im Browser "http://localhost:8080/log4jtut" eingegeben wird. Wenn man sich das alles sparen möchte, hat man natürlich noch die Möglichkeit, das zip direkt ins Verzeichnis webapps zu entpacken, um dann ohne den Eintrag in der server.xml das Verzeichnis zu browsen.

top


3. Vorgehen
Um mit log4j im Tomcat eine Anwendung zu tracen sind neben der log4j.jar folgende Dateien wichtig.

1. web.xml
Log4j muss initialisiert werden. Das bedeutet, es wird eine Konfigurationsdatei benötigt, die die erforderlichen Initialisierungsparameter enthält. Um diese Datei beim Tomcat Start einzulesen, ist es sinnvoll ein Servlet zu schreiben, dass beim Start von Tomcat ausgeführt wird und das Einlesen der Parameter veranlasst, um sie so log4j bekannt zu machen.
Um das zu erreichen, wurde in unter WEB-INF/web.xml folgender Eintrag vorgenommen:

<web-app>
  <servlet>
    <servlet-name>log4j-Initialisierung</servlet-name>
    <servlet-class>de.wirage.Log4jTutorial</servlet-class>
    <!-- Lade so schnell wie möglich -->
   <load-on-startup>0</load-on-startup>
  </servlet>
</web-app>

Dieser Eintrag führt dazu, dass unser Servlet bereits beim Start von Tomcat ausgeführt wird und die Konfiguration von log4j vornimmt. Alternativ wäre es möglich, die Verwendung von Struts vorausgesetzt, ein Servlet als PlugIn zauszuführen.
In diesem Fall muß der entsprechende Eintrag in der struts-config.xml vorgenommen werden und die Klasse muss vom Interface PlugIn abgeleitet werden. Es enthält dann nur die Methoden init() und destroy(), hat jedoch die gleiche Funktion wie unser Servlet, nämlich einfach nur log4j zu initialisieren.

top

2. Log4jTutorial.java
Die Log4jTutorial.java stößt die Initialisierung an, indem es ein Einlesen der Konfigurationsdatei veranlasst. Die Datei hat folgenden Inhalt:

// package Deklaration
package
de.wirage;

// Importanweisungen
import javax.servlet.http.HttpServlet;
import org.apache.log4j.Logger;
import org.apache.log4j.xml.DOMConfigurator;

// Das Servlet erbt von HttpServlet, enthält aber nur die Methode init()
public class Log4jTutorial extends HttpServlet {

 // über Logger (der "Hauptklasse" von log4j) wird ein logging Objekt geholt,
 // dem die aufrufende Instanz per Reflection übergeben wird.
 private static final Logger LOG = Logger.getLogger(Log4jTutorial.class);

public void init() {
  // Den Pfad zur Konfigurationsdatei, der log4j.xml festlegen
  String
prefix = getServletContext().getRealPath("/");
  String resource = prefix +"WEB-INF/log4j.xml";
  
  // Über ein DOMConfigurator Objekt wird log4j konfiguriert, indem
  // die xml-Datei an den Configurator übergeben wird
  DOMConfigurator.configure(resource);

  // die erste Ausgabe einer Meldung
  logger.info("Log4j erfolgreich durch " + getClass().getName() + " initialisiert :o)");
   }
}

top

3. Die log4j.xml
Die Konfiguration von log4j kann wahlweise über Property Dateien oder über xml files erfolgen. Ich persönlich bevorzuge xml, da diese, mit vielen hilfreichen Kommentaren versehen, direkt aus dem JBoss Application Server (http://www.jboss.org) im Verzeichnis $JBOSS_HOME/server/default/conf herauskopiert werden kann und mit wenigen Änderungen auch im Tomcat lauffähig ist. Im Gegensatz zum JBoss muß Tomcat jedoch nach Änderungen an der Konfigurationsdatei neu gestartet werden, d.h. Anpassungen sind nicht sofort sichtbar, sondern log4j muss bei jeder Änderung an der Konfiguration in der log4j.xml über einen Restart von Tomcat erneut initialisiert werden.

Die Ausgabe der Meldungen für das Tracing erfolgt über sogenannte Appender. Ein Appender legt dabei das Ziel für die Ausgabe fest, d.h. ob die Meldungen z.B. in eine Datei geschrieben werden sollen, oder direkt auf der Konsole ausgegeben.
Hier z.B. ein File Appender, d.h. als Ziel für die Ausgabe wird eine Datei festgelegt.

<!-- Ein Zeit basierter File Appender -->
<appender name="FILE" class="org.apache.log4j.DailyRollingFileAppender">
<param name="File" value="/pfad zur log datei/server.log"/>
<param name="Append" value="true"/>

<!-- Immer um Mitternacht wird eine neue Datei angelegt-->
<param name="DatePattern" value="'.'yyyy-MM-dd"/>

<!-- wahlweise bei vielen Meldungen auch stündlich
<param name="DatePattern" value="'.'yyyy-MM-dd-HH"/>
-->

<layout class="org.apache.log4j.PatternLayout">
<!-- Das Layout für die Meldungen, in diesem Fall Datum, Klasse und die Meldung-->
<param name="ConversionPattern" value="%d %-5p [%c] %m%n"/>
</layout>
</appender>

Der Console Appender funktioniert im Prinzip analog, weist aber eine Zeile auf, die einen signifikanten Unterschied ausmacht:

<param name="Threshold" value="INFO"/>

An dieser Stelle findet sowas wie eine globale Steuerung für die Konsole statt, d.h. während der File Appender alle Informationen unabhängig von ihrem Loglevel in die Datei schreibt, wird durch diesen Parameter festgelegt, dass nur Meldungen die das Level INFO oder höher besitzen geloggt werden, und zwar unabhängig davon, welches Level in den Limitern gesetzt wurde. Diese Limiter stellen nämlich eine weitere wichtige Möglichkeit dar, um die Ausgabe zu steuern, d.h. die Prioritäten für die Ausgabe einzelner Meldungen in den unterschiedlichen Klassen festzulegen. Die Priorisierung erfolgt dabei hierarchisch und hat diese Reihenfolge der Gewichtung:

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

In der log4j.xml sieht die Nutzung dann so aus:

<!-- Limitierung des loggings für de.wirage -->
<category name="de.wirage">
<priority value="INFO"/>
</category>

Das bedeutet für unser Tutorial folgendes:
Klassen, die dem package de.wirage zugeordnet sind, sollen nur Meldungen ausgeben, die eine höhere Priorität als "INFO" haben. Wird also dieser Limiter also eingesetzt, erscheint nach wie vor unsere Kontrollausgabe im Initialisierungsservlet. Ändere ich im Servlet diese Zeile:

LOG.info("Log4j erfolgreich durch " + getClass().getName() + " initialisiert :o)");

in diese:

LOG.debug("Log4j erfolgreich durch " + getClass().getName() + " initialisiert :o)");

und führe einen restart von Tomcat durch, erscheint meine Erfolgsmeldung nicht mehr. Zwar wurde log4j trotzdem erfolgreich initialisiert, aber da das Level DEBUG niedriger ist als INFO erscheint die Meldung nicht mehr. Setze ich jedoch in der log4j.xml das Level des Limiters auf DEBUG

<category name="de.wirage">
<priority value="DEBUG"/>
</category>

so erscheint meine Logging Ausgabe aufs neue, sobald Tomcat neu gestartet wird. Aus diesem Wege kann gezielt und zentral das Tracing beeinflusst werden, ohne bei Änderungswünschen Anpassungen im Code vornehmen zu müssen.

top