avatar
Today is Friday
October 18, 2019

Search Results Archives: October 2007

October 17, 2007

De zwarte doos, tracen voor luilakken

by tsnoei — Categories: Uncategorized — No Comments - Afdrukken Afdrukken

Tracing is een manier om informatie te loggen over de werking van applicatiecode. Een soort van “zwarte doos” voor software. In de System.Diagnostics namespace zijn een aantal klassen opgenomen waarmee tracing en debugging informatie kan worden gelogd naar een bestand, eventlog of welke ander outputdevice of datasource ook. Dit gebeurd via zogenaamde listeners. Tracing is met name bedoeld voor applicaties die in release mode zijn gecompileerd. Debug wordt echter alleen gebruikt voor het loggen van gegevens in debug mode.

Console.WriteLine("Applicatie gestart...");
System.Diagnostics.Debug.WriteLine("Debugging...");
Console.ReadLine();

Bovenstaande code schrijft standaard alle debug regels naar het “output” venster van Visual Studio. Dit komt omdat er een default listener actief is voor het wegschrijven van deze informatie naar dit window.
output.png
Het is mogelijk een nieuwe listener te activeren die deze informatie naar (bijv.) een tekstbestand schrijft. Naast deze globale informatie waarover je veel meer kunt vinden op het web is het handig te weten dat tracemessages in 4 niveaus kunnen worden verdeeld:

  • Verbose (level: 4)
  • Info (level: 3)
  • Warning (level: 2)
  • Error (level: 1)

Verbose is het meest gedetaileerde niveau waarop wordt gelogd. Error is het minst gedetaileerde niveau. Je kunt voor een lopende applicatie bepalen welk soort tracemessages moeten worden gelogd. Kiezen we voor “Warning” dan worden zowel “Warning” als “Error” message gelogd. Kiezen we voor Verbose dan worden alle messages gelogd etc… Uiteraard wordt bij level 0 niets gelogd.

Automatiseren van de logging

Vooral bij tracing wil je een aantal standaardgegevens opnemen voor elk tracemessage. Praktische informatie die ik bij elke gelogde regel zou willen hebben is:

  • Datum/Tijd
  • Gebruikersnaam waaronder de applicatie draait.
  • Gegevens van de methode waarin de trace wordt weggeschreven.

.. en het logbericht natuurlijk. Het is natuurlijk onhandig als je bij elk logbericht al die gegevens keer op keer moet meegeven.

De oplossing hiervoor is de zelfbouw TraceManager class. Om deze te kunnen gebruiken moet er het volgende gebeuren. In de app.config of web.config van de applicatie moet de volgende Xml worden opgenomen:

<configuration>
  <system.diagnostics>
    <switches>
      <add name="TraceLevelSwitch" value="4" />
    </switches>
  </system.diagnostics>
</configuration>

Met deze switch wordt aangegeven op welk level moet worden gelogd. Vervolgens wordt met de volgende regel de TraceManager geinitialiseerd:

TraceManager.Initialize("c:\\testtrace.log");

De tracemanager gaat alle logregels wegschrijven naar een bestand met de naam c:\testtrace.log.
Met de volgende code loggen we een tracebericht:

TraceManager.WriteVerbose("Application has started");

Dit bericht resulteert in de volgende gegevens in het testtrace.log bestand:

----[ VERBOSE ]------------------------------------------------------------
Datum               : 17-10-2007 19:43:51
User                : MYDOMAIN\snoei
Message             : Application has started
Class               : TestApp.Program
Method              : Main(System.String[] args)
Return Type         : System.Void
--------------------------------------------------------------------------------

Zie hier… er is een klein wondertje gebeurt. De applicatie heeft via een kijkje in de callstack en een stukje reflection de methode vastgesteld waarin de tracemessage is aangemaakt. Op deze manier is tracen een makkie geworden.

Maar hoe werkt deze “zwarte” TraceManager doos?

De datum en de gebruiker vaststellen is niet zo heel ingewikkeld. (Geen zorgen trouwens je kunt de code downloaden via de link onder aan dit artikel ;-) .)Het vasstellen van de aanroepende methode heeft wat meer voeten in aarde. Het ophalen van deze gegevens heeft alles te maken met de callstack. De callstack is een hierarchische lijst van methodes die elkaar hebben aangeroepen. We hebben in de file program.cs de methode Main() deze roept een methode Print() aan en die roept weer de methode PrintFirstLine() aan. De callstack is bij het aanroepen van de methode PrintFirstLine() hierarchisch:
Main() (stackframe 2)
> Print() (stackframe 1)
> > PrintFirstLine() (stackframe 0)

Met de onderstaande code kunnen we voor elk stackframe gegevens van de methode ophalen.
public static MethodBase CallingMethodBase(int pStackPosition)
{
	StackTrace callStack = new StackTrace();
	StackFrame frame = callStack.GetFrame(pStackPosition);
	MethodBase method = frame.GetMethod();
	return method;
}

MethodBase is een object uit de System.Reflection namespace en bevat informatie over een methode (metadata). Als we echter een TraceMessage.WriteVerbose(…) methode plaatsen binnen de PrintFirstLine() methode dan zal deze stackframe 0 worden en PrintFirstLine() stackframe 1 etc… Daarom willen we het eerste stackframe ophalen wat GEEN methode is van de TraceManager class. Dat doen we met de volgende code:

private static MethodBase GetCallingMethodBase()
{
  bool found = false;
  int Stackpos = 1;
   while (!found)
   {
     MethodBase CallingMethodBase = callstack.CallingMethodBase(Stackpos);
     if (CallingMethodBase.DeclaringType.Name != "TraceManager")
        return CallingMethodBase;
     Stackpos++;
   }
   return null;
}

LET OP! Mocht je dus in de toekomst besluiten de naam van de TraceManager te veranderen. Dan moet je de hier niet vergeten mee te wijzigen anders werkt de code niet meer. (Dit is overigens intelligenter op te lossen met een stukje reflection maar daar ben ik nog niet aan toegekomen) Bovenstaande functie retourneert informatie over de methode die de (bijv.) TraceManager.WriteVerbose(…) methode aanroept.

Met onderstaande code kunnen vervolgens de gegevens als naam van de methode, parameters en return type worden opgehoest:

MethodBase CallingMethodBase = GetCallingMethodBase(); //This will NOT work correctly from IDE, but standalone it's OK.
string CallingClass = CallingMethodBase.DeclaringType.FullName;
string CallingMethodData = CallingMethodBase.Name;
string CallingParams = "";
string ReturnType = "";

if (CallingMethodBase is MethodInfo)
{
  MethodInfo CallingMethodInfo = (MethodInfo)CallingMethodBase;
  ParameterInfo[] Ps = CallingMethodInfo.GetParameters();
  for (int i = 0; i < Ps.Length; i++)
  {
    CallingParams += Ps[i].ParameterType.FullName + " " + Ps[i].Name;
    if (i != Ps.Length - 1)
      CallingParams += ", ";
  }
  ReturnType = CallingMethodInfo.ReturnType.FullName;
}

Kortom tracen voor luilakken. Je loopt nu tegen het probleem aan dat je eigenlijk niet meer weet wat je als daadwerkelijke message mee moet geven aangezien zo wat alles al wordt gelogd ;-) .

Vooruit downloaden maar.. en veel plezier er mee!
TestApp.zip

© 2019 Snoei's .NET blog All rights reserved - Wallow theme v0.44 by ([][]) TwoBeers - Powered by WordPress - Have fun!