Tracing in .net

Tracing.
Ismerjük a fogalmat? Persze. Olyan, mint a debugging, de mégse az.
De hogy is működik? Miért is kell?

Tracingre alapvetően akkor lehet szükségünk, ha debugolásra nincs lehetőségünk - pl. az alkalmazásunk sok szálon fut, és a debug jobban megkever minket, mint amennyit segít, vagy a szoftverünk már deployolásra került ügyfelünkhöz, és ő nem rajong a gondolatért, hogy remote debuggert futtassunk a produkciós környezetében. Valljuk be, mi sem rajonganánk.
Az ott felmerülő hibákat valahogy pedig meg kell találni, mi marad? Hát a tracing.
A tracing segítségével az alkalmazásunkból folyamatosan üzenhetünk a külvilág felé, hogy épp mit csinálunk, milyen állapotban vagyunk, vagy hogy épp olyan körülmények merültek fel, amik ugyan nem teszik lehetetlenné a továbbfutást, de hát legalábbis gyanúsak.
Ezeket az üzenetket figyelve elkaphatók azok a szituációk, amikor előbb jön meg a nyugtázó üzenet, mint ahogy a folyamat végrehajtódna, amikor két pozitív szám szorzata negatív, amikor a cache üríti ki a cache-t vezérlő kódot, és egyáltalán, amikor a befőtt akarja a nagymamát eltenni. Hogy olyat idézzek, aki már hál' isten klasszikus.

A tracingről írni azért nehéz, mert akkora témakör, hogy nehéz jó belépési pontot találni - én szokásomhoz híven az aljáról kezdtem.
System.Diagnostics.Trace.WriteLine("Hello, Trace!"); - mit csinál ez? Kiír egy üzenetet a debug konzolra, amit vagy a Visual Studio Output ablakában láthatunk (már ha a "Show output from:" a Debug-ra van állítva), vagy valamilyen olyan alkalmazás segítségével, ami megjeleníti nekünk a debug message-eket - erre jó szívvel ajánlom a DebugView-t, ami nagyon hasonlít a többi sysinternals toolhoz: nincs benne mp4 lejátszó, nincs benne webkettő integráció, egy dolgot tud, ami a neve, de azt nagyon. És ráfér az install egy DVD-re.
Na most hogy ezt így kiveséztük, nézzük meg, hogy mit csinál ez igazából. A rutinosabbak már hozzák is elő a nyárikonyhából Lutz Roe a Red Gate remek toolját, a .NET Reflectort. Nézzük:

[Conditional("TRACE")]
public static void WriteLine(string message)
{
  TraceInternal.WriteLine(message);
}

Hát ez bizony semmi mást nem csinál, csak továbbhív a TraceInternal osztály WriteLine(string message) metódusára. Tiszta Chewbacca-védelem: ennek nincs semmi értelme!
Nézzük tovább. Hátha mégis van. És tényleg: szegény kis metódust - biztos azért, mert igen rövidke, hát hogy ne szomorkodjon - feldíszítették, egész pontosan egy ConditionalAttribute-tal. A Conditional attribute egy paramétert is kapott, azt, hogy TRACE.
Mit is jelent ez? Annyit, hogy ennek a metódusnak a hívása csak akkor fog belefordulni a kódunkba, ha azt bekapcsolt TRACE compilation symbol mellett fordítottuk. Ha nem úgy fordítottuk, akkor mint ha a hívása ott se lenne, le se írtuk volna: nem hívódik meg.
Ha a Visual Studioban egy projecten klikkelünk egy jobbat, és megtekintjük az ő propertijei - egészen pontosan annak is a Build fülét -, ott láthatjuk, hogy a "Define DEBUG constant" és a "Define TRACE constant" be van pipálva.
Vagy épp nincs: válasszuk ki a fölső, Configuration dropdown-ból a Release-t! Ebben a konfigurációban már csak a TRACE lesz élesítve. Ha vannak saját build konfigurációink, akkor azt meg csak mi tudjuk, hogy abban mi van bepipálva, sőt, méginkább, hogy milyen egyéb symbolok vannak a "Conditional compilation symbols:"-nál beírva - ugyanis nem kell megelégednünk ezzel a kettővel, bátran kreálhatunk sajátokat, és dobálhatjuk fel a Conditional attribútumokat a metódusainkra, annak paraméterként a MY_LITTLE_COMPILATION_SYMBOL-t átadva.
Hab a tortán, hogy azt, hogy egy szimbólum definiált-e vagy sem, nem csak itt állíthatjuk be, hanem a forrásfájlokban is elhelyezhetünk #define MY_LITTLE_COMPILATION_SYMBOL jelzéseket, és akkor arra a fordítási egységre (cséfájlra, ha tetszik) az a szimbólum definiált lesz. Akik szeretnek scriptelni, természetesen a parancssori fordítónak is megmondható, hogy mely szimbólumok legyenek definiáltak.
Akit esetleg eddig kínzott volna a kíváncsiság, hogy mi a különbség a System.Diagnostics.Trace és a System.Diagnostics.Debug között, mikor "szemre" ugyanolyanok: az egyik metódusain [Conditional("TRACE")], a másikon [Conditional("DEBUG")] van, semmi több.

Most hogy már ennyit szót fecséreltünk egyetlen sorra, ami rádásul nem is a metódusban, hanem még az előtt van, itt az idő, hogy most már bele is nézzünk. Mit csinál a internal WriteLine?
Ha eltekintünk az olyan sallangoktól, mint a szálbiztosság biztosítása, semmi mást, mint hogy végigmegy a TraceListener-eken, és mindegyiknek odaaadja a message-ünket: írd ki! Egy klikkolással azt is kideíthetjük, hogy honnan tudja, hogy kik a trace listenerek: hát a [Web|App].configból.
Ehhez persze Reflectort használni már perverzió, és amúgy is: ha olyan kérdést szegeznek nekünk asp.net témában, amiről lövésünk sincs, mondjuk azt nyugodtan: "be kell állítani a Web.configban", egyrészt profin hangzik, másrészt 99% találati aránnyal okosat mondunk. Szóval egyelőre Reflector el, bölcs tudomány elő: kik azok a TraceListenerek?

A trace listenerek azok, akik figyelnek a trace üzenetekre. Hoppá.
De miért kell nekik figyelni?
Hova is akarunk tracelni? A debug konzolra, persze. De mindig? Nem lenne jó néha mondjuk fájlba? A ha debug console elszáll, az írás akkor is megmarad, dehogynem lenne jó.
Aztán még hova? Az eseménynaplóba, például. Az is de jó lenne. Meg egy webes alkalmazásnál a weboldalba! Meg az IIS logba! Meg saját adatbázisba! Meg valaki más adatbázisába! Meg szikratávírón az űrbe! És lehessen őket vezérelni! Most csak a fiúk! Most csak a lányok! Most mindenki egyszerre!
Egy feladat, több párhuzamos megvalósítás, néhány triviálisan adódó alap-igény, ugyanakkor a legvadabb saját elképzeléseket is támogatni kell... ez nagyon provider-szagú.
Így is van, az [App|Web].config fájlunkban a configuration, system.diagnostics szekciója alatt van (ha nincs, ne szégyenlősködjünk: csináljunk) egy trace szekció. Valami ilyesmi:

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <system.diagnostics>
      <trace>
          <listeners>
              <add name="NoisyTraceListener" type="TraceStudy.NoisyTraceListener, TraceStudy"></add>
          </listeners>
      </trace>
  </system.diagnostics>
</configuration>

Itt a listenersen belül van add, remove, clear - semmi extra, aki konfigurált már bármi ilyesmit ismerős lesz neki. Egy kis trükk van: a saját trace típusunk betöltésénél kicsit háklisabb valamiért a runtime, mint egyébként. Még ha egyazon assemblyn belül is van a trace listenerünk, mint a futó kódunk, akkor is meg kell adni az assembly nevét, különben könnyen jön a ConfigurationErrorsException: Couldn't find type for class... kezdetű nóta. Aki tudja miért, írja meg kommentbe túrórudiért. Most miután ilyen jól belementünk, hogy hogyan kell beállítani a saját trace listenerünket, nézzük is meg, hogy mi is ez.
A Trace.WriteLine(), mint láttuk, belül trace listenerekre bízza az érdemi munkát. Alapesetben a System.Diagnostics.DefaultTraceListener-re, akibe ha beletúrunk, végül egy SafeNativeMethods.OutputDebugString() hívásnál lyukadunk ki. Bizony, a debug console Win32 szolgáltatás. Ha nem (csak) ide szeretnénk tracelni, akkor a .config fájlunkban elvehetünk és/vagy hozzáadhatunk trace listenereket. Néhányat kapunk készen, mint pl:

• System.Diagnostics.EventLogTraceListener: az eseménynapló logoláshoz
• System.Diagnostics.XmlWriterTraceListener: XML-be logoláshoz
• System.Diagnostics.DelimitedListTraceListener: csv-be logoláshoz
• System.Web.WebPageTraceListener: ASP.NET oldalba logoláshoz

Vannak még mások is rajtuk kívül - de ha mindez nem lenne elég, írhatunk mi magunk is trace listenert. Nyilván nem elég, mert nekünk valami sokkal extrább kell, úgyhogy gyerünk! Nincs más dolgunk, mint leszármazni az absztrakt TraceListener oszályból, megvalósítani két metódust, és kész!
Alább látható saját fejlesztésű trace listenerem, amivel alighanem forradalmasítom az informatikát:

class NoisyTraceListener : TraceListener
{
    public override void Write(string message)
    {
        WriteLine(message);
    }

    public override void WriteLine(string message)
    {
        int i = 0;

        if (Int32.TryParse(message, out i))
        {
            Console.Beep(i+50, 100);
        }
        else
        {
            Console.Beep(100, 300);
        }
    }
}

Tehát ha a trace message szám, akkor sípolunk egyet, méghozzá olyan hangmagasságút, mint amit paraméterként kaptunk. Ha nem számot kaptunk, akkor is sípolunk, de akkor gorombát.
Ezek után nincs más dolgunk, mint kipróbálni új trace listenerünket:

class Program
{
    static void Main(string[] args)
    {
        for (int i = 0; i < 100; i++)
        {
            Console.WriteLine("i={0}", i);
            System.Diagnostics.Trace.WriteLine(i);
        }
    }
}

F5, és láss hallj csodát.

To be continued...