Rond logging hangt een heel vreemd sfeertje. Aan de ene kant wordt dit door
iedereen als zeer nuttig ervaren en wil iedereen allerhande informatie loggen om
zeer uiteenlopende redenen.
Ontwikkelaars willen de interne werking ontsluiten daar waar ze geen
compiler mogen installeren om door de code te steppen. Projectleiders
willen graag inzicht in het aantal bugs en storingen die tijdens de testfase en
productie optreden. Het afdelinghoofd wil graag weten welke gebruiker door
roekeloos gebruik de helft van de administratie verwijderd heeft. Gebruikers
willen graag dat door hen ondervonden vage problemen bevestigd worden met
meldingen in de log en systeembeheer wil graag de gezondheid van de ‘vijandige’
applicaties op hun trouwe servers meten. Kortom, Logging moet staan als een
huis, ahum, Log..
.
Maar aan de andere kant is logging een sluitpost tijdens de bouw, test en
productiegang. Het mag geen performance kosten, het moet amper ruimte op de
server consumeren, de eventlog mag niet vervuild worden en de berichten moeten vooral bondig zijn om niet teveel bedrijfsinformatie prijs te geven.
Kortom, met logging is het wat treurig gesteld.
Gelukkig heft het probleem zichzelf snel op zodra de eerste uitrol naar de
testserver gedaan is. De ontwikkelaars verliezen bijna de totale controle over
de applicatie, kunnen geen uitspraak doen bij vage en minder vage problemen en
opeens staat logging weer hoog op hun verlanglijstje.
In een ontwikkelstraat is logging meestal al wel goed geregeld met een eigen
architectuur en in een SOA omgeving zal het zelfs onderdeel van het totale
systeem zijn. Hierbij kunnen berichten over de bus een prima indicatie geven
over de voortgang en werking. En puristen zullen met Aspect Oriented Programming (AOP) aan de slag gaan.
Maar als je niet in deze ‘luxe’ positie bent dan zal je zelf voor de logging
moeten zorgen. Natuurlijk is er de Enterprise library van Microsoft. Dit geeft gelijk een goede basis voor andere basis onderdelen van een gemiddeld systeem zoals data access, cryptografie, caching, exception handling en security.
Maar wil je een lichtere variant dan kan je eens kijken naar Trace listeners.
Hierbij is het loggen zeer eenvoudig. Eerst geef je in de app.config (of
web.config) een opsomming van de gewenste manier van loggen (bv. tekst bestand, Xml, CSV, eventlog) op. Daarna is een aanroep van b.v. Trace.WriteLine(“….”); voldoende. Dit is dus logging implementeren in enkele minuten en refactoren is een eitje. Overigens, waar in de functionele requirements stond de tekst over de implementatie van logging ook al weer? Dus wie maakt je wat?
Hieronder zijn de standaard aanwezige tracelisteners opgesomd welke in het
.Net framework al meegeleverd worden:
| Trace listener |
Gebruik |
| System.Diagnostics.DelimitedListTraceListener |
Schrijft meldingen in een CSV formaat |
| System.Diagnostics.XmlWriterTraceListener |
Schrijft meldingen in een XML formaat |
| System.Diagnostics.EventLogTraceListener |
Stuurt meldingen naar de eventlog |
| System.Diagnostics.TextWriterTraceListener |
Schrijft meldingen in een tekstbestand zonder formattering |
| Microsoft.VisualBasic.Logging.FileLogTraceListener |
Schrijft meldingen telkens in een nieuw tekstbestand op bv. dagelijkse
basis |
| System.Web.WebPageTraceListener |
Schrijft meldingen als trace bij de webpagina |
| System.Diagnostics.ConsoleTraceListener |
Schrijft meldingen als standaard output |
Vooral de EventLogTracelistener en de FileLogTraceListener zijn interessant.
De eerste kan (niet verwonderlijk) naar de eventlog loggen. Let er wel op dat
hier eventueel extra rechten voor nodig zijn. Ook logt deze direct in
Application log.
Vrijwel iedereen start met het loggen in TextWriterTraceListener terwijl deze
een veel interessanter zusje in de Visual Basic hoek van het framework heeft.
Anders dan haar broertje kan de log netjes per dag opgedeeld worden en
daardoor staat er geen unieke lock op het de totale log. Vooral systeembeheer
vind dit heel prettig… want dan kan de log weer snel verwijderd worden. Maar
voor een C# ontwikkelaar is het even slikken want hij is overgeleverd aan die
dekselse VB.Net 😉 En deze listener is een aardig alternatief voor de grote
broer, de Rolling Flat File Trace Listener uit de Enterprise Library.
Heb je jouw keuze kunnen maken? Ga dan door naar de volgende stap. Neem in
het configuratiebestand een SharedListeners sectie op. Hieronder is een hele
lijst opgesomd. Dit is indicatief, er wordt namelijk niet direct naar al de
genoemde listeners geschreven. Slechts diegene die ook genoemd worden in de
listeners sectie, zullen ook daadwerkelijk aangesproken gaan worden. Hiermee
wordt het dus eenvoudig om zonder een regel code aan te passen, te wisselen van
log.
<?xml version="1.0" encoding="utf-8" ?><configuration>
<system.diagnostics>
<sharedListeners>
<add name="MyDelimitedListTraceListener"
type="System.Diagnostics.DelimitedListTraceListener"
delimiter=":"
initializeData="c:\temp\MyDelimitedListTraceListener.txt"
traceOutputOptions="ProcessId, DateTime" >
<filter type="System.Diagnostics.EventTypeFilter"
initializeData="Verbose" />
</add>
<add name="MyXmlWriterTraceListener"
type="System.Diagnostics.XmlWriterTraceListener"
initializeData="c:\temp\MyXmlWriterTraceListener.xml"
traceOutputOptions="ProcessId, DateTime" >
<filter type="System.Diagnostics.EventTypeFilter"
initializeData="Verbose" />
</add>
<add name="MyEventLogTraceListener"
type="System.Diagnostics.EventLogTraceListener"
initializeData="MijnEigenTestLog"
source="MijnTraceEventLog" >
<filter type="System.Diagnostics.EventTypeFilter"
initializeData="Warning" />
</add>
<add name="MyFileLogTraceListener"
type="Microsoft.VisualBasic.Logging.FileLogTraceListener,
Microsoft.VisualBasic, Version=8.0.0.0, Culture=neutral,
PublicKeyToken=b03f5f7f11d50a3a, processorArchitecture=MSIL"
initializeData="FileLogWriter"
basefilename="MyFileLogName"
autoflush="true"
logfilecreationschedule="Daily"
location="Custom"
customlocation="c:/temp/" >
<filter type="System.Diagnostics.EventTypeFilter"
initializeData="Verbose" />
</add>
<add name="MyVerboseTextWriterTraceListener"
type="System.Diagnostics.TextWriterTraceListener"
initializeData="c:\temp\MyTextWriterTraceListener.log">
<filter type="System.Diagnostics.EventTypeFilter"
initializeData="Verbose" />
</add>
<add name="MyErrorTextWriterTraceListener"
type="System.Diagnostics.TextWriterTraceListener"
initializeData="c:\temp\MyTextWriterTraceListener.log">
<filter type="System.Diagnostics.EventTypeFilter"
initializeData="Error" />
</add>
<add name="MyWebPageTraceListener"
type="System.Web.WebPageTraceListener, System.Web" >
<filter type="System.Diagnostics.EventTypeFilter"
initializeData="Verbose" />
</add>
<add name="MyConsoleListener"
type="System.Diagnostics.ConsoleTraceListener" >
<filter type="System.Diagnostics.EventTypeFilter"
initializeData="Verbose" />
</add>
</sharedListeners>
<trace autoflush="true">
<listeners>
<remove name="Default"/>
<add name="MyFileLogTraceListener"/>
<add name="MyEventLogTraceListener"/>
</listeners>
</trace>
</system.diagnostics>
</configuration>
Wellicht is het ook opgevallen dat bij de listener een filter mogelijkheid
wordt opgegeven. Dit wordt ook wel het Trace Level genoemd. De Trace class geeft namelijk de mogelijkheid om logmeldingen van een typering te voorzien.
Foutmeldingen en waarschuwingen spreken voor zich. Het verschil tussen de
typeringen Verbose en Information zijn minder opzichting. Ik hou altijd de
vuistregel aan dat op productie alleen waarschuwingen en foutmeldingen getoond moeten worden. Information gebruik ik om gedrag en interne keuzes zichtbaar te maken en dit moet zo beperkt mogelijk. Maar voor alle overige meldingen gebruik ik Verbose, en dat kan best ver gaan. Zo is het een prima gebruik om bij het starten van een applicatie de totale config als verbose te loggen. Dit geeft goed aan onder welke randvoorwaarden de applicatie moet draaien.
Hierdoor zullen de logbestanden tijdens de ontwikkel en testfase best
uitdijen maar hiermee kan heel veel informatie ingewonnen worden om ongewenst gedrag te analyseren.
| Trace level instelling |
Wat wordt er dan gelogd? |
| Verbose |
Alle soorten meldingen |
| Information |
Ter zake doende informatie, waarschuwingen en foutmeldingen |
| Warning |
Slechts waarschuwingen en foutmeldingen |
| Error |
Alleen foutmeldingen |
| None |
Tja.. |
Op productie zie je dus meestal het Trace Level op Warning ingesteld zien
staan.
Hoe maak je dan het onderscheid tussen de verschillende boodschappen die je
wilt loggen? De Trace class heeft hiervoor een aantal verschillende methodes en
in onderstaande Log class is dit nog eens vereenvoudigd met slechts 1 methode.
Zoals alles in computerland zijn alle problemen op te lossen met slechts 1 laag
van abstractie dus later kan onder de class best een andere manier van loggen
gehangen worden.
/// <summary>/// Class voor het wrappen van en loggen via TraceListeners/// </summary>
public static class Log
{
/// <summary>
/// Log een melding.
/// </summary>
/// <param name="category">een categorie.</param>
/// <param name="messageText">de boodschap.</param>
/// <param name="traceLevel">Opgegeven level bij de boodschap.</param>
/// <exception cref="System.NotImplementedException">
/// Melding als de doorgegeven Traceswitch niet ondersteund wordt
/// </exception>
public static void LogTraceMessage( string category,
string messageText, TraceLevel traceLevel)
{
string tekst = category.PadRight(20) + "- " +
messageText.PadRight(50) + " at " +
DateTime.Now.ToString(CultureInfo.CurrentCulture);
switch (traceLevel)
{
case TraceLevel.Verbose:
{
Trace.WriteLine(tekst, category);
return;
}
case TraceLevel.Info:
{
Trace.TraceInformation(tekst, category);
return;
}
case TraceLevel.Warning:
{
Trace.TraceWarning(tekst, category);
return;
}
case TraceLevel.Error:
{
Trace.TraceError(tekst, category);
return;
}
case TraceLevel.Off:
{
return;
}
default:
{
throw new NotImplementedException("Onbekende tracelevel");
}
}
}
}
Kortom, nu is het mogelijk om op een eenvoudige en snelle manier logging te
introduceren.
Mocht het hier bescheven lijstje van listeners niet aan de wensen voldoen en
is de overstap naar een ander logging framework ook niet van toepassing, dan kun je nog altijd jouw eigen tracelistener overerving schrijven. Dit is redelijk
trivial. Het enige wat gedaan moet worden, is het implementeren van twee
overerfde methodes (Write en WriteLine) om b.v. met een SMS te loggen. Neem
daarna de assembly met de overerfde SmsTraceListener op in de configuratie en
het loggen gaat beginnen.
Loggen kan nu nooit meer een sluitpost zijn.
Sander van de Velde 