HowTo: Logging mit Log4Net

imageSobald die Anwendung läuft und die ersten Bugs vom Kunden werden ist es enorm wichtig zu wissen, was eigentlich vorgegangen ist und wie es zu dem Fehler gekommen ist. An wichtigen Punkten ein Logging einzubauen ist deshalb sehr hilfreich beim Debuggen. Log4Net ist eine sehr schicke Logging Bibliothek, die fast jeden Wunsch erfüllt und das ganze in nur wenigen Minuten aufgesetzt.

Log4Net
Log4Net ist eine sehr praktische .NET Bibliothek, welche das Logging vereinfach. Dabei gibt es verschiedene "Log Stufen" (Debug, Error, Info…) und verschiedene Arten des Loggings ("Appender"), so kann man beispielsweise ins Visual Studio Debug Fenster "loggen" oder in eine Datei, DB etc.
Das ganze kann über XML zur Laufzeit auch konfiguriert werden, sodass man auch auf dem Produktivsystem die entsprechenden Log Stufen setzen kann.

Eine gute Einführung findet sich auf den Log4Net Seiten.

Praktischer Einstieg
Um das ganze mal sehr einfach zu Demonstrieren, lege ich ein Consolen Program an und binde die Log4Net DLL ein. Die "log4net.dll" bekommt man von hier.

image

Konfiguration von Log4Net
Log4Net kann man sehr simpel über die App/Web.Config konfigurieren. Dafür legen wir in unserem Beispiel die "App.config" an:

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>
  </configSections>
  <log4net>
    <appender name="DebugAppender" type="log4net.Appender.DebugAppender" >
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
      </layout>
    </appender>
    <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
      </layout>
    </appender>
    <root>
      <level value="All" />
      <appender-ref ref="DebugAppender" />
      <appender-ref ref="ConsoleAppender" />
    </root>
  </log4net>
</configuration>

Erklärung:

Oben definieren wir uns eine eigene ConfigSections, sodass alles zentral geregelt werden kann.

In dieser log4net-Section kommen die verschiedenen "Appender" zum Einsatz. Je nach Appender wird anders geloggt, der "ConsoleAppender" loggt beispielsweise auf die Kommandozeile und der "DebugAppender" in das Visual Studio Output Fenster. Weitere Appender finden sich hier: Config Examples. In einem Appender kann jeweils noch Layout vorgegeben werden, sodass man die Log Message entsprechend anpassen kann.

Im letzten Abschnitt legen wir das Level fest, welches geloggt werden soll – bei uns erstmal alles und wir nutzen die beiden definierten Appender.

"Logging Code"

    class Program
    {
        static void Main(string[] args)
        {
            log4net.Config.XmlConfigurator.Configure();
            ILog logger = LogManager.GetLogger(typeof (Program));

            logger.Debug("Hello World!");
            logger.Error("D´oh!");

            Console.ReadLine();
        }
    }

In der Zeile 5 veranlassen wir Log4Net in der XML Config nachzusehen und dann holen wir uns unseren Logger. Der Logger hat dabei für jedes "Log Level" eine Methode:

image

Ergebnis:

Wenn ich nun die Anwendung starte, habe ich folgende Ausgabe in der Konsole:

image

… und dies im Output Fenster im Visual Studio:

image

Wo genau soll man loggen?

Eine Grundregel habe ich nicht gefunden, allerdings ist der Sinn des Loggens ja, nachzuverfolgen wie ein Fehler zustande kam. Daher könnte man z.B. bei einer Methode die Parameter rausloggen, wichtige "Aufrufe von anderen Services" sowie die Ausgabe loggen. So bekommt man ein Gefühl dafür wie der Code intern tickt.

Insbesondere mit dem "DebugAppender" ist es ganz witzig wenn man einen Button auf der Webseite drückt und man sieht wie der Request durch die Schichten geht und die Werte rausloggt – ein nerdiges Vergnügen :)

[ Download Democode ]

Wenn dir der Blogpost gefallen hat, dann hinterlasse doch einen Kommentar. Wenn du auf dem Laufenden bleiben willst, abonniere unseren RSS Feed oder folge uns auf Twitter.

About the author

Written by

Hi, ich bin Robert Mühsig und bin Webentwickler und beschäftige mich mit Web-Frameworks auf dem Microsoft Web Stack und scheue mich auch nicht vor Javascript. Der Blog begann als "Problemsammelstelle und Lösungshilfe" und seitdem schreibe ich hier alles auf. Seit 2008 bin ich Microsoft MVP für ASP.NET. Treffen kann man mich online via Twitter (@robert0muehsig) oder hier.

3 Responses

  1. Volle Zustimmung, log4net ist überaus nützlich und extrem flexibel. Ich leite z.B. gern mal alle SQL queries von NHibernate in ein eigenes Logfile um, eta so:

     <appender name="LogFileSql" type="log4net.Appender.RollingFileAppender">
    … log file konfigurieren
      </appender>

      <logger name="NHibernate.SQL" additivity="false">
        <level value="DEBUG" />  Â
        <appender-ref ref="LogFileSql" />
      </logger>

    Alle Logger, die mit NHibernate.SQL starten werden hier an den LogFileSql appender geschickt, aber nicht mehr an den root appender (additivity="false"). Das Hauplog bleibt lesbarer und zur Not kann man sehen, was genau NH gemacht hat.

    Auch witzig: alle Queries per Webrequest zählen, siehe http://blog.andreloker.de/post/2008/05/09/NHibernate-counting-database-queries-per-web-request.aspx

    (Wobei das mit den NH2 Statistics wohl eher obsolet geworden ist).

    Grüße,
    Andre

    Reply

Comment on this post

Letzte Posts

  • image_thumb.png
    NuGet Package Restore & Build Server wie z.B. AppVeyor

    NuGet ist ja mittlerweile weit verbreitet, aber eine Frage stellt sich natürlich immer noch: Checkt man die NuGet Packages ein oder nicht? In meinem kleinen Side-Projekt, welches auf GitHub liegt und ich über AppVeyor auch bauen lasse nutze ich das Package Restore Feature von NuGet, d.h. in meinem Repository befindet sich kein NuGet Package mehr, […]

  • image.png
    Microsoft Account Login via ASP.NET Identity

    Der Microsoft Account ist die zentrale Identifikationsstelle in der “Consumer-Microsoft-Welt”, allerdings ist das Einbinden eben dieser in die eigene Applikation eher schwierig. Das “Live SDK” ist nun unter dem OneDrive Dev Center zu finden und ganz professionell wurden auch alle Links zum alten Live SDK damit unbrauchbar gemacht. Beim Microsoft Account ist es auch unmöglich […]

  • image.png
    Zeitgesteuerte Azure WebJobs – so einfach kann Azure sein

    Das noch in Entwicklung befindliche Azure WebJob SDK bietet einige coole Features zum Verarbeiten und Bereitstellen von Daten. Bekanntes Beispiel ist das Sample welches auf eine Azure Queue lauscht und sobald ein Item da vorhanden ist anfängt dies zu verarbeiten. Szenario: Zeitgesteuerte Aktivitäten – ohne Queue und co. Mein Szenario war allerdings wesentlich trivialer: Ich […]

  • image.png
    Get Involved in OSS! Ja, aber wie geht das denn mit GitHub?

    Auch im .NET Lager gibt es Bewegung im OSS Bereich und es gibt verschiedene Arten wie man bei einem Open Source Projekt “Contributed”. Was zählt alles zu “Contribution”? Unter “Contribution” läuft eigentlich alles – ob es Fragen/Probleme zu dem Projekt via Issues ist oder Dokumentation nachreicht oder ob man darüber bloggt oder das Projekt vorstellt. […]

  • HowTo: Web.config samt eigener ConfigSection zur Laufzeit ändern

    In dem HowTo geht es darum wie man die Web.config zur Laufzeit ändert und was es dabei zu beachten gilt. Das ganze klappt auch mit komplexeren ConfigSections. Eigene ConfigSection? Vor einer ganzen Weile habe ich mal über das Erstellen einer eigenen ConfigSection geschrieben – im Grunde nutzen wir jetzt fast dieselbe Config. Zur Laufzeit? Startet […]

Amazon Shop

Facebook