Logging mit log4net unter .NET

log4net ist Teil des Apache "Logging Services"-Projektes bei der Apache Software Foundation. Das Projekt "Logging Services" dient der Bereitstellung von sprachenübergreifenden Logging-Diensten für das Debugging und die Protokollierung von laufenden Applikationen. Das Projekt startete ursprünglich mit dem log4j-Framwork für Java, welches 1995 entwickelt wurde und seitdem gepflegt und kontinuirlich erweitert wird. Bei log4net handelt es sich also um dessen Portierung in das .NET Ökosystem. Unter .NET existieren natürlich auch andere Möglichkeiten zur Protokollierung von Applikationen – neben log4net gibt es weitere etablierte Logging-Frameworks, zum Beispiel „NLOG“ oder auch „Logging Block“ der Microsoft Enterprise Library. Generell bieten Logging-Frameworks deutlich mehr Flexibilität, als eine schnelle Implementierung von Hand, beispielsweise um sogenannte, frei konfigurierbare Appender, also "Wohin" soll denn geloggt werden. Das folgende Tutorial gibt einen schnellen Einstieg in log4net.

Vorteile des log4net Frameworks sind u.a.:

  • Keine zusätzliche Kosten beim Einsatz, da die Lizenzbedingungen in der Regel nicht sehr restriktiv sind – bei log4net muss nur die ursprüngliche Lizenz einmal erwähnt werden, z.B. bei den Programminformationen
  • Log4net besteht lediglich aus einer der Basis‐Komponente und einer dazu passenden Konfiguration
  • Es gibt zwei Möglichkeiten zum Ablegen der Konfiguration. Einmal über die „app.config“ , als direkter Bestandteil der auszuführenden Assembly oder über eine eigenständige XML-Datei

Einbinden von log4net in .NET-Projekte

Der erste Schritt, um in einer Applikation Meldungen über log4net auszugeben, führt über ein entsprechendes Logger-Objekt. Der Logger ist sozusagen der Protokollführer. Bei log4net genügt es bereits, die Assembly über das entsprechende nuGet-Paket "log4net" in das Projekt mit einzubinden, oder über eine dedizierte bzw. signierte Version der Assembly "log4net.dll" direkt zu referenzieren, wenn diese beispielsweise von anderen verwendeten Komponenten entsprechend referenziert wird. Die manuelle Referenzierung empfiehlt sich im zweiten Fall sogar, da ansonsten Probleme beim späteren Deployment der Applikation auftreten können. Anschließend muss noch der Namensraum „log4net“ eingebunden werden und eine Logger-Instanz mithilfe der statischen Fabrikmethoden der Klasse „LogManager“ erzeugt werden.

Beim LogManager steht eine Methode zur Auswahl: „GetLogger()“. Diese erfordert den Namen eines Loggers als Parameter. Mittels des Reflection-Mechanismus in .NET, ermittelt sie den Namen der verwendenden Klasse und liefert einen Logger zurück, der diesem Namen entspricht. Auf diese Art ist es sehr einfach, einen Logger zu erzeugen, der an eine Klasse gebunden ist; auch wenn die Klasse via Recfactoring umbenannt wird, entspricht der Name des Loggers automatisch noch dem der Klasse, was die Wartung des betreffenden Codes einfach macht.

Durch die Verwendung von Reflection, um den Namen der verwendenden Klasse zu ermitteln, ist es bei dieser Methode um ihr Leistungsverhalten nicht sonderlich gut bestellt. Aus diesem Grund empfiehlt es sich, die zurückgegebene Instanz in einem Feld der Klasse zu cachen. Da log4net generell threadsicher implementiert sind, lässt sich dieses Feld gleich statisch markieren:

using log4net;

public class TestClass 
{
     private static readonly ILog log = LogManager.GetLogger(typeof(TestClass));
     // ...
}

Einrichtung in der Applikation

Über den globalen XmlConfigurator von log4net kann die Konfiguration gesetzt werden. Dieser sollte gleich im Einstiegspunkt der Applikation aufgerufen werden, beziehungsweise durch den Aufruf einer entsprechenden Methode:

using log4net;

private void SetupLog4Net(string file)
{
    if (File.Exists(file))
    {
        // set common log path for application
        log4net.GlobalContext.Properties["LogPath"] = Environment.GetFolderPath(Environment.SpecialFolder.MyDocuments);
        log4net.Config.XmlConfigurator.Configure(new FileInfo(file));
     }
     else
        throw new FileNotFoundException(file);
}

Über die Einrichtung eines eigenen FileSystemWatchers in der Applikation, ist die Übernahme von Änderungen an der Konfiguration zur Protokollierung zur Laufzeit möglich, welche sich beim Speichervorgang dann direkt auswirken:

private void SetupConfigfileWatcher(string filePath)
{
    if (Directory.Exists(filePath))
    {
        var watcher = new FileSystemWatcher(Path.GetDirectoryName(filePath));
        watcher.Filter = Path.GetFileName(filePath);
        watcher.EnableRaisingEvents = true;
        watcher.NotifyFilter = NotifyFilters.LastWrite | NotifyFilters.Size;

        watcher.Changed += (object sender, FileSystemEventArgs fs) =>
        {
            SetupLog4Net(filePath);
        };
    }
    else
        throw new DirectoryNotFoundException(filePath);
}        

public void SetupLogging(string filePath, bool watchFile = true)
{
    SetupLog4Net(filePath);

    if (watchFile)
        SetupConfigfileWatcher(filePath);     
}

Bei Fehlern, welche nicht in der Applikation behandelt werden können und damit zum Abbruch führen, empfiehlt es sich, diese mittels eines globalen Exception-Handlers abzufangen und mit „Fatal()“ auszugeben.

AppDomain.CurrentDomain.UnhandledException+=(sender, unhandledException) =>
{
    log.Fatal("Unhandled exception occured!");

    if (ue.ExceptionObject != null)
        log.Fatal($"Exception raised by: {unhandledException.ExceptionObject}");

	// exit application
};

Logmeldungen schreiben

Sobald ein Logger verfügbar ist, lassen sich darüber Meldungen in das Protokoll schreiben. Dazu bietet log4net verschiedene Methoden an, die verschiedene Prioritäten von Meldungen klassifizieren und sich entsprechend beim Protokollieren unterscheiden.

Level

Ausgabe

(0) OFF

Keine Ausgabe von Meldungen

(1) Info

Schreibt Meldungen, die nicht nur für den Entwickler, sondern auch für den Anwender interessant sein können, aber keine Fehler sind (Initialisierungsmeldungen usw.)

(2) Debug

Eignet sich für Informationen, die es ermöglichen, den Ablauf einer Anwendung zu verfolgen. Auch diese Meldungen enthalten Daten, die sich üblicherweise nur mithilfe eines Debuggers ermitteln lassen. Eventuell sollte man hier noch sehr tief gehende Informationen über die Assembly mit einbeziehen

(3) Warn

Sollte nur für Warnungen eingesetzt werden, also in Situationen, welche möglich, jedoch nicht erwartungsgemäß auftreten. Dies könnte beispielsweise beim fehlgeschlagenen Einladen von bestimmten Konfigurationensdateien einer Applikation sein. Die Applikation würde dann mit einer Standard-Konfiguration fortfahren

(4) Error

Sollte nur Meldungen kennzeichnen, die tatsächliche Fehler beschreiben, mit denen die Applikation aber noch in irgendeiner Form umgehen kann, ohne den Programmfluss abzubrechen

(5) Fatal

Nur Meldungen, die tatsächliche Fehler beschreiben, mit denen die Applikation nicht mehr umgehen kann und deshalb der Programmfluss komplett abgebrochen werden muss

(6) ALL

Gibt alle Meldungen aus (Info…Fatal)

Darüber hinaus gibt es noch weitere Loglevel, wie beispielsweise "Trace" und "Verbose", welche in Ausnahmefällen noch zusätzlich benutzt werden können. In meiner bisherigen Praxis hat es sich vor allem als sinnvoll erwiesen, zumindest sämtliche Konstruktor- und wichtige öffentliche Methodenaufrufe mit "Debug( )" zu erfassen. Dabei reicht es aus, wenn ein Logeintrag den Einstieg in eine Methode dokumentiert. Im einfachsten Fall könnte man dies beispielsweise über die Zeile log.Debug(„++“); definieren. Zum anderen sollte die zu loggende Klasse - beziehungsweise Methode - mit log4net generell so konfiguriert sein, dass nicht nur der Name der protokollierten Methode selbst enthalten sein soll, sondern auch den vollständigen Namensraum und der Name der Klasse, welche die Methode hält. Bei "sehr wichtigen" Methoden sollten sogar die Werte ihrer sämtlichen Parameter mit ausgegeben werden. Auf diese Weise lässt sich im Nachhinein der ausgeführte Weg besser nachvollziehen. Zum zweiten sollten sämtliche Ausnahmen mit „Error( )“ protokolliert werden. Bei nicht behandelten Fehlern sollten diese weiter „nach oben“ in der Applikation weitergegeben werden. Alternativ gibt es beispielsweise mit PostSharp ein Tool für aspektorientierte Programmierung (AOP), mit dessen Hilfe bei Kompiliervorgang ein solches Logging "on-the-fly" nachgereicht werden kann. Damit erspart man sich die explizite Definition von Logmeldungen am Anfang und/oder am Ende von Methoden.

Ausgaben von Meldungen konfigurieren

Jede log4net-Konfiguration beginnt mit dem „log4net“ bzw. dem einmaligen „root“ Element. Diese Konstellation könnte zum Beispiel jedoch nicht in eine bestehende „app.config“-Datei für die zu protokollierende der Applikation eingebunden werden. Dort gibt es einen etwas anderen Weg, mittels der Konfiguration über „config sections“.

<log4net>
  <root>    
    <level value="DEBUG" />
    <appender-ref ref="LogFileAppender" />
    <appender-ref ref="DebugAppender" />-->    
    <!--<appender-ref ref="OutputDebugStringAppender" />-->
  </root>

Im „root“-Element wird zunächst der minimale Level für die von log4net erkannte Protokollierung erkannt. Im Beispiel ist es „DEBUG“, das heißt, es werden alle Meldungen ausgegeben, außer Meldungen mit der Priorität „INFO“.
Des Weiteren werden hier sämtliche Ausgabekanäle referenziert, in welcher die Meldungen zur selben Zeit geschrieben werden. In dem obigen Beispiel wird einmal ein Appender für Ausgaben in Visual Studio referenziert und ein anderer, welcher die Meldungen in eine bestimmte Textdatei schreibt.

Auf derselben Hierachie-Ebene wie beim „root“-Element werden nun die Appender selbst definiert, wie im unteren Beispiel zu sehen ist. Über das „ConversionPattern“-Attribut kann das Ausgabeformat von Meldungen von jedem Appender individuell konfiguriert werden:

  <appender name="LogFileAppender" type="log4net.Appender.RollingFileAppender">
    <file type="log4net.Util.PatternString" value="%property{LogPath}\Vendor\App_log.txt" />
    <appendToFile value="true" />
    <rollingStyle value="Size" />
    <maxSizeRollBackups value="10" />
    <maximumFileSize value="10MB" />
    <staticLogFileName value="true" />
    <layout type="log4net.Layout.PatternLayout">
      <header value="[BEGIN LOGGING AT %date]%newline" type="log4net.Util.PatternString" />
      <footer value="[END LOGGING AT %date]%newline" type="log4net.Util.PatternString" />
      <param name="ConversionPattern" value="[%date{yyyy-MM-dd HH:mm:ss,ff}] [%-5level] [%thread] %type->%method(): %message%newline" />
    </layout>
  </appender>

  <appender name="DebugAppender" type="log4net.Appender.DebugAppender" >
    <layout type="log4net.Layout.PatternLayout">
      <param name="Header" value="[Header]\r\n" />
      <param name="Footer" value="[Footer]\r\n" />
      <param name="ConversionPattern" value="[%date{yyyy-MM-dd HH:mm:ss,ff}] %-5level [%thread] %type->%method(l:%line): %message%newline" />
    </layout>
  </appender>
 
  <appender name="SystemDebug" type="log4net.Appender.OutputDebugStringAppender" >
    <layout type="log4net.Layout.PatternLayout">
      <param name="Header" value="[Header]\r\n" />
      <param name="Footer" value="[Footer]\r\n" />
      <param name="ConversionPattern" value="[%date{yyyy-MM-dd hh:mm:ss,ff}] %-5level %type->%method(): %message%newline" />
    </layout>    
  </appender>  
</log4net>

Wie man in der Beispielkonfiguration sieht, ist der Aufbau der XML-Datei prinzipiell übersichtlich und einfach gehalten. Es existieren jedoch auch entsprechende GUI-Editoren für die Konfiguration von log4net. In den Ausgaben sollte auch die jeweilige Thread-ID enthalten sein. Speziell für Multithreading-Applikationen ist die Ausgabe der Thread-ID nämlich relevant, da bei den ganzen asynchronen Zugriffen auf Ressourcen nicht nur mehr der zeitliche Aspekt eine Rolle spielt. In speziellen Debugging-Sitzungen könnten während der Laufzeit auch Informationen wie beispiels weise „%file“ und „%line“ angegeben werden (für Datei und Codezeilennummer), um entsprechende Stellen schneller im Code zu finden. Diese Informationen verlangsamen jedoch die Protokollierung deutlich und sollten nur während der Entwicklung oder im Test verwendet werden.

LogfileAppender

Der im Beispiel zuerst aufgeführte LogFileAppender ist so konfiguriert, dass sämtliche betroffene Meldungen in eine spezifizierte Datei ausgegeben werden. Diese Datei darf jedoch im Beispiel die Maximalgröße von 10MB nicht überschreiten. Damit wird gleichzeitig ein bestimmtes Zeitfenster konfiguriert. Zusätzlich werden bei Beginn und am Ende der Protokollierung entsprechende eine Kopf- und Fußzeile eingezogen, um verschiedene Logging-Sitzungen besser auseinander halten zu können. Alte Meldungen werden nach dem Erreichen der Maximalgröße gelöscht.

DebugAppender

Der DebugAppender gibt Meldungen in das .NET-System aus und ist so konfiguriert, dass dieser sich gut für laufende Debugging-Sitzungen unter Visual Studio einsetzen lässt, wenn die Applikation darunter gestartet wird. Hier wird bei Ausgabe der Meldung zusätzlich die betroffene Zeile im Code ausgegeben.

SystemDebug

Dieser Appender gibt Meldungen zum Debugger aus. Wenn zur Laufzeit kein Debugger definiert ist, gibt der Systemdebugger die Meldung aus. In vielen klassischen Windows-Anwendungen bietet es sich an, diese Meldungen mit Hilfe von DebugView (Bestandteil der Sysinternals Suite von Microsoft) von laufenden Applikationen abzufangen und zu protokollieren. Die Konfiguration dieses Appenders ist im Beispiel gleich gehalten mit dem des DebugAppenders für den Einsatz im Visual Studio.

Eine vollständige Liste der Appender für log4net findet sich unter [1].

Definition von Filtern

Log4net bietet unter anderem auch die Definition von Filtern an, die direkt unterhalb der Definition der Appender in der Konfigurationsdatei hinzugefügt werden können. Über eine Bedingung ist anzugeben, wann der Filter aktiv werden soll.

<!-- 1. -->
<filter type="log4net.Filter.StringMatchFilter">
    <stringToMatch value="++" />
</filter>
<filter type=”log4net.Filter.DenyAllFilter” />

<!-- 2. -->
<filter type="log4net.Filter.LevelMatchFilter">
	 <acceptOnMatch value="true" />
	 <levelToMatch value="DEBUG" />
 </filter>
 <filter type="log4net.Filter.LevelMatchFilter">
	 <acceptOnMatch value="true" />
	 <levelToMatch value="ERROR" />
 </filter>     
 <filter type="log4net.Filter.DenyAllFilter" />

<!-- 3. -->
<filter type="log4net.Filter.LoggerMatchFilter">
	 <loggerToMatch value="ControlSet." />
	 <acceptOnMatch=”true” />
 </filter>
 <filter type="log4net.Filter.DenyAllFilter" />

Eine vollständige Beschreibung hierzu findet sich auf den Webseiten der Apache Foundation [2]. Im ersten Beispiel werden nur alle Meldungen protokolliert, welche „++“ als Vorkommen im String beinhalten. Alle anderen Meldungen werden gefiltert. Dies geschieht über die Definition von „DenyAllFilter“, welche ggf. immer am Ende von entsprechenden Filterketten stehen sollte. Im zweiten Beispiel werden nur bestimmte Level protokolliert. Im letzten Beispiel werden beispielsweise alle Meldungen, in welchen der Namespace „ControlSet“ vorkommt, protokolliert, alle anderen Meldungen werden gefiltert.

Ablage der Konfiguration

Im Framework gibt es verschiedene Möglichkeiten, die Konfiguration für log4net abzulegen. Einmal kann dies, wie bereits beschrieben, als eigenständige XML-Konfigurationsdatei erfolgen. Aber auch über die Einbettung in der „app.config“ kann diese abgelegt werden, nicht zuletzt jedoch direkt im Code eingebettet werden. Generell empiehlt sich die Ablage einer expliziten Konfigurationsdatei, je nach Deployment-Art, im Userland oder auf Maschinen-Ebene. Falls diese jedoch standardmäßig nicht mitgeliefert werden soll, sollte als Fallback-Strategie standardmäßig eine Defaultkonfiguration einkompiliert werden, welche in so einem Fall aktiv wird.

Fazit

Bei näherer Betrachtung des Themas Logging stellt sich heraus, dass es hier zahlreiche Aspekte zu beachten gilt. Das wichtigste Argument für den Einsatz eines Logging-Frameworks sollte die Flexibilität sein, die mit log4net auf jeden Fall gewährt ist. Generell empfehle ich sogar noch das Einziehen einer weiteren Abstraktionsschicht, beziehungsweise die Definition von entsprechenden Interfaces, um auch von log4net generell unabhängig zu sein. Die potentielle Definition dieser Abstraktionsschicht sollte gerade auch hinsichtlich ihrer Granularität wohlüberlegt sein, da man sich bei anschließender Einbettung Fakten schafft, welche mutmaßlich langfristig im eigenen Code wirken.

Links

[1] Vollständige Liste der Appender (Apache log4net)

[2] Vollständige Beschreibung der Konfigurationsmöglichkeiten (Apache log4net)

Wir benutzen Cookies
Diese Seite enthält Cookies. Wir verwenden Cookies, um Inhalte und Anzeigen zu personalisieren und die Zugriffe auf unsere Website zu analysieren.