Tracer les événements se produisant dans une application est très important lorsque vient le moment de débugger lors des phases de recette ou… en prod. Dans cet article, nous verrons comment mettre en place cela en utilisant ETW (le système ultra-performant de log de Windows) et les possibilités que cela ouvre.

Ecriture de logs

Le principe est assez simple : il “suffit” de créer une classe de base dérivant d’EventSource et d’y créer nos différentes méthodes permettant d’écrire des logs en y apposant des attributs “Event”.

L’écriture d’un message est réalisée par un appel à la méthode WriteEvent prenant en paramètre un niveau de log sous la forme d'un entier et le message à tracer.

Afin de faciliter l’utilisation de notre logger, nous crééons une instance statique “Log” de celui-ci à même la classe. Le code résultant est :

[EventSource(Name = "InfiniteSquare-AppLog", Guid = "D1835D42-7071-4F29-AC7F-0BAFC3CA7B1E")]
public sealed class InfiniteSquareEventSource : EventSource
{
    public static InfiniteSquareEventSource Log
        = new InfiniteSquareEventSource();

    [Event(1, Level = EventLevel.Verbose)]
    public void Debug(string message)
    {
        WriteEvent(1, message);
    }

    [Event(2, Level = EventLevel.Informational)]
    public void Info(string message)
    {
        WriteEvent(2, message);
    }

    [Event(3, Level = EventLevel.Warning)]
    public void Warn(string message)
    {
        WriteEvent(3, message);
    }

    [Event(4, Level = EventLevel.Error)]
    public void Error(string message)
    {
        WriteEvent(4, message);
    }

    [Event(5, Level = EventLevel.Critical)]
    public void Critical(string message)
    {
        WriteEvent(5, message);
    }
}

Vous noterez la présence de l’attribut EventSource sur la classe où je définis un nom et un identifiant (généré aléatoirement – il n’a aucune signification particulière).

Enfin, l’utilisation de ce logger est aisée, un simple appel à la méthode voulue au bon moment :

InfiniteSquareEventSource.Log.Info("MainPage::InitAsync --> Start");
await Task.Delay(3000);
InfiniteSquareEventSource.Log.Info("MainPage::InitAsync --> End");

InfiniteSquareEventSource.Log.Critical("Ouch ça pique");

Afficher les logs dans la fenêtre de sortie de Visual Studio

Une fois les événements tracés, il faut être en mesure de les exploiter dans l’application.

Pour cela on dérive de la classe EventListener et on surcharge simplement la méthode OnEventWritten.

Il y a de très bons exemples sur MSDN d’écriture dans un fichier de log, dans notre cas nous allons simplement écrire dans la console de sortie de Visual Studio.

public class ConsoleEventListener : EventListener
{
    string format = "{0:yyyy-MM-dd HH\\:mm\\:ss\\:ffff}\tType: {1}\tId: {2}\tMessage: '{3}'";

    protected override void
        OnEventWritten(EventWrittenEventArgs eventData)
    {
        var line = string.Format(format, DateTime.Now,
            eventData.Level, eventData.EventId, eventData.Payload[0]);

        Debug.WriteLine(line);
    }
}

Lire les logs en temps réel grâce à xperf

xperf est un outil en ligne de commande faisant partie du SDK Windows. Vous pouvez y accéder en lançant une ligne de commande et en tapant “xperf”.

Il permet de démarrer la collecte des traces pour une source de log précise et de les exporter dans un fichier de sortie pouvant être exploité avec l’outil “Windows Performance Analyser (WPA)” du SDK Windows.

La source à utiliser est précisée en utilisant le GUID que nous avions justement placé dans l’attribut EventSource.

Voici les commandes à taper pour démarrer puis stopper la collecte des traces :

xperf -start traceMe -on D1835D42-7071-4F29-AC7F-0BAFC3CA7B1E
... utiliser l'application ici
xperf -stop traceMe -d fini.etl

Une fois terminé, j’ai un fichier .etl que je peux ouvrir avec WPA en double-cliquant dessus. Il faut alors déplier le groupe “system activity” à gauche et glisser-déposer la zone “généric events” dans la zone vide à droite.

J’ai alors cet affichage qui me présente les différents événements, leur heure d’arrivée, leur niveau de criticité et pleins d’options pour les filtrer.