Le log : des bases à l'automatisation via l'interception Unity

Le code du développeur utilise une instance de la classe System.Diagnostics.TraceSource (Doc MSDNDocumentation TraceSource sur la MSDN) contenue dans l'assembly System (System.dll).
Cette classe existe depuis le Framework 2.0.
L'instance de cette classe se voit injecter des messages à tracer en fonction d'un niveau de trace (de type TraceLevel Doc MSDNEnumeration TraceLevel sur la MSDN).

Le flux de fonctionnement observé est le suivant :

Le flux décrit ci-dessus simplifie la réalité volontairement.
Je vous invite à consulter le code de la classe à l'aide d'un outil tel que ReflectorReflector (payant) ou IL SpyIL Spy (gratuit).

La déclaration de l'instance TraceSource est triviale :

TraceSource _monTraceur = new TraceSource("[Identifiant-Du-Traceur]");

La déclaration nécessite de préciser (a minima) l'identifiant du traceur.
Cet identifiant sera utilisé ultérieurement dans le fichier de configuration pour préciser les comportements attendus par le traceur.
L'identifiant doit être une chaine de caractères sans espace.

N'utiliser que les caractères alphanumériques non accentués ([a-z] [A-Z] [0-9]) pour l'identifiant du traceur.

L'utilisation de l'instance TraceSource ne présente aucune difficulté particulière :

this._monTraceur.TraceEvent(TraceEventType.Information, 1);
this._monTraceur.TraceEvent(TraceEventType.Warning, 2, "Mon message à tracer !");

Les utilisations faites ci-dessus tracent une information et un avertissement. D'autres niveaux existent.

L'utilisation nécessite de préciser a minima (premier appel) :

• le niveau (Information, Warning, Error, Critical, etc.) ;
• l'id de l'évènement tracé
  Le principe d'ID d'évènement est le suivant :
  la valeur identifie l'évènement ou la fonctionnalité de façon unique dans le projet (voire l'application),
  le développeur est libre d'utiliser n'importe quelle valeur entre 0 et xxx,
  lorsqu'utilisé, il est intéressant de garder une table de correspondance entre l'id et sa description dans une documentation de projet.
  Il peut ne pas être utilisé (initialisation à une valeur unique lors de l'appel de TraceEvent).

Le second appel correspond à l'utilisation la plus fréquente. Les paramètres de base (ci-dessus) se voient complétés par le message tracé.

Le paramétrage se réalise dans le fichier de configuration de l'application.

Le paramétrage manipule les concepts suivants :

• source
  Une « source » est une structure permettant de paramétrer une instance de TraceSource.
  Le lien se réalise par l'intermédiaire du nom de la source qui doit correspondre au nom indiqué lors de l'instanciation de l'objet TraceSource.
  Si le nom précisé ne correspond à aucune source paramétrée, aucun comportement ne sera exécuté (pas d'exception retournée ni de log).
  Le paramétrage disponible permet le filtrage de contenu en fonction du niveau souhaité. D'autres filtrages sont possibles (cf. documentation).
  La source se voit déclarer de 0 à n listeners.
  Ces déclarations peuvent pointer vers un listener partagé ou spécifique.
• listener
  Un « listener » représente une interface de sortie de la trace.
  Au cours de l'exemple, nous avons utilisé un TextWriterTraceListener qui écrit dans un fichier texte.
  D'autres Listeners existent (Console, Event logs, XML, etc.), il demeure possible de créer vos propres customs listeners (implémentation de la classe abstraite System.Diagnostics.TraceListener).
  

<configuration>
 ...
  <system.diagnostics>
    <trace autoflush="true" /> <!-- Permet de ne pas devoir flusher à chaque écriture -->
    <sources>

      <source name="App" switchValue="Warning">
        <listeners>
          <clear />
          <!-- Utilisation du traceur partagé nommé FileListener -->
          <add name="FileListener" />
        </listeners>
      </source>

      <source name="UserFunctionality" switchValue="All">
        <listeners>
          <clear />
          <!-- Utilisation du traceur partagé nommé FileListener -->
          <add name="FileListener" />
        </listeners>
      </source>
      
      <source name="LeTraceurDeBase" switchValue="All">
        <listeners>
          <clear />
          <!-- Déclaration d'un listener spécifique pour LeTraceurDeBase -->
          <add name="TraceurBaseFileListener"
           type="System.Diagnostics.TextWriterTraceListener"
           initializeData=".\BaseTraceLog.txt" traceOutputOptions="DateTime" />
        </listeners>
      </source>
    </sources>

    <!-Déclaration des Listeners partagés -->
    <sharedListeners>
      <add name="FileListener"
           type="System.Diagnostics.TextWriterTraceListener"
           initializeData=".\TraceLog.txt" traceOutputOptions="DateTime" />
    </sharedListeners>

  </system.diagnostics>
...
</configuration>

L'implémentation différente de TraceSource demeure triviale.
La récupération d'une instance de logs se réalise comme suit :

var loggerInstance1 = NLog.LogManager.GetLogger("LoggerName");

Le principe d'utilisation demeure similaire à celui de tracesource, même si les méthodes sont différentes.
En effet, le choix du niveau de log se réalise par appel de la méthode de log correspondante.

loggerInstance1.Warn("Log with trace source started.");
loggerInstance1.Error("User enter 'Q' > Exit signal launched.");

Ci-dessus, nous logguons en mode Warning, et Error. D'autres niveaux existent.
Le logger nécessite de préciser le message à logguer a minima.
D'autres surcharges existent (cf. documentation nlog).

Le paramétrage basique est très simple. Il consiste à ajouter une déclaration section de configuration et la configuration qui lui est liée.

Les sections de configuration (appelée aussi configSection) sont des structures permettant la sérialisation/désérialisation des blocs XML contenus dans les fichiers de configuration des applications .net.
Tous les blocs utilisés dans nos fichiers de configuration ont une configSection déclarée.
Cette déclaration se situe dans le fichier machine.config pour toutes les configSection de base.
NLogs nécessite une déclaration particulière, car le framework n'est pas nativement connu par le Framework.net.
La déclaration des configSection se réalise en début de fichier.

Déclaration de la section de configuration :

<configuration>
  <configSections>
    <!-- Déclaration du type pour la désérialisation des infos de configuration de nLogs contenues dans ce fichier de config -->
    <section name="nlog" type="NLog.Config.ConfigSectionHandler, NLog" />
  </configSections>
  ...
<configuration>

Il convient ensuite de compléter le fichier de configuration par la déclaration de la configuration propre à nLogs :

Lors de la déclaration de la section de configuration, nous avons précisé « nlog » dans l'attribut « name ».
Cette valeur indique le nom de l'élément XML correspondant à la configuration dans le fichier XML.

<!-- DEBUT - Configuration nLogs - DEBUT -->
  <nlog 
     xmlns="http://www.nlog-project.org/schemas/NLog.xsd" 
     xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" autoReload="true">
    <targets>
      <target name="file" xsi:type="File" 
              layout="${longdate} ${logger} ${message}" 
              fileName="[${shortdate}][${machinename}]Trace.txt" />
    </targets>
    <rules>
      <logger name="*" minlevel="Trace" writeTo="file" />
    </rules>
  </nlog>
  <!-- FIN - Configuration nLogs - FIN -->

La configuration ci-dessus est basique, elle a comme résultat un fichier de log unique contenant toutes les sorties de logs.

Il est possible de séparer les logs dans des sorties différentes en fonction du niveau, ou d'autres critères tels que le nom du logger, le contenu du message, etc. Je vous invite à tester toutes les possibilités offertes dans un POC (Proof Of Concept).
Toute la documentation est accessible ici : http://nlog-project.org/http://nlog-project.org/.

La configuration nLogs permet de préciser le format de sortie des lignes de logs (attribut layout ci-dessus).

Dans l'exemple qui nous concerne, nous optons pour l'adoption d'une « fabrique abstraite » sur un fournisseur de services de logs (ILogManager).
ILogManager permettra à l'appelant d'obtenir des instances responsables de produire les logs.

Le diagramme supérieur montre le principe de la fabrique abstraite ; l'inférieure décrit son application pour le cas qui nous concerne.

Notre code applicatif est alors couplé à des contrats d'implémentation ILogManager et ILogger et non aux instances du framework de logs choisi.
ILogManager constitue le contrat de fabrique des instances responsables de logger. Il propose donc une seule méthode permettant de récupérer des instances de ILogger.
ILogger expose les méthodes d'un composant capable de logger : WriteError(…), WriteInfo(…), etc.

Le changement de framework de logs se limite alors à coder deux nouvelles classes : une instance ILogManager, et une ILogger !

Le diagramme ci-dessus indique trois implémentations de fournisseur de logs :

• LogManagerForNLog et LoggerForNLog
  Implémentation exploitant nLog ;
• LogManagerForTraceSource et LoggerForTraceSource
  Implémentation exploitant TraceSource ;
• LogManagerForDisable et LoggerForDisable
  Implémentation ne disposant d'aucun comportement. Ce stratagème est utilisé afin de permettre au code appelant la logique de log de ne pas devoir vérifier la nullité des instances de logs. L'appel ne générant aucun log.

Par défaut, une instance doit être retournée. Si aucune solution de log ne doit être indiquée, le type retourné est une instance LogManagerForDisable.

Ce faible couplage a un coût faible, si adopté dès le début du projet.
Son retour sur investissement (ROI) est important.

L'implémentation peut être faite via un Framework IOC de type Unity, ou par l'implémentation du pattern de fabrique abstraite à la main. L'exemple montre le second cas.

La déclaration d'un ILogManager et la récupération d'une instance ILogger demeure somme toute aussi simple que l'adoption par appel direct (moyennant la précision du nom du logger) :

ILogManager _logManager = LoggerFactory.GetLogManager();
var myLogger = _logManager.GetLogger("App");

Dans l'exemple de code, nous n'utilisons pas le Framework IOC (type Unity) pour retourner les instances de fabriques. Nous disposons d'un point d'entrée statique nommé LoggerFactory qui se charge de retourner les instances de fabrique de loggers.

Exemple d'utilisation de « ILogger » :

myLogger.WriteWarning("Application is starting...");
myLogger.WriteWarning("Program", "Main", "SetCompatibleTextRenderingDefault");

Le premier appel loggue un message simple, le second précise le nom de la classe, la méthode et le message à logguer.

Le contrat de ILogger propose un log sur quatre niveaux (Error > Warning > Information > Verbose) connu par la majorité des frameworks de logs. Pour chaque niveau, le contrat propose deux méthodes de logs en fonction des besoins des développeurs :

• non détaillé : seul le message est à préciser ;
• détaillé : les informations suivantes sont précisées, et formatées lors du log
  o nom de la classe,
  o méthode de la classe,
  o message.

Complément d'information à destination des utilisateurs avertis des Designs Patterns : une fabrique simple aurait pu faire l'affaire pour retourner des instances de ILogger (et donc, se passer de ILogManager). Dans de nombreux cas, nous avons le besoin d'interagir avec un gestionnaire de la couche de logs pour un ensemble de tâches.
Exemple : modification du niveau de logs de façon applicative, ajout de filtres de sortie dynamiquement, etc. D'où la fabrique abstraite.

Ce mode d'implémentation (à la main) permet de découpler le code appelant de l'implémentation, mais laisse un couplage plus fort entre assembly (l'assembly de l'appelant référence l'assembly de la fabrique abstraite). L'utilisation de Unity permet de disposer du couplage faible absolu.

Le paramétrage n'est pas lié à l'implémentation d'une solution de couplage faible, mais bien à la solution de logs implémentée. Dès lors, aucune précision n'est nécessaire en plus de ce qui existe déjà pour les Frameworks de logs

Mais avant de les nommer, attardons-nous sur les principes utilisés par le dernier exemple fourni.

Au début de cet article, nous évoquions le modèle de fabrique abstraite. Si nous appliquons ce principe aux classes de services couplées au fournisseur d'IOC Unity, le diagramme de couches sera le suivant :

L'application consommatrice de la couche de services est liée aux interfaces de celle-ci (et non aux classes d'implémentation).
Elle s'adresse à Unity pour lui fabriquer les instances implémentant les interfaces de services.

Ce principe de base de fonctionnement apporte un gain important en termes de couplage faible.

Unity propose un principe d'Interception. Ce principe dit que, en lieu et place du type déclaré à l'interface, Unity va retourner un proxy qui permet d'intercepter tous les appels effectués et de les rerouter vers des instances implémentant IInterceptionBehavior sous la forme d'une chaîne de responsabilités (encore un Design Pattern) pour laquelle le dernier maillon appelé est l'appel réel sur le type attendu (voir schéma ci-dessous).

En d'autres termes, lorsque l'application demande à Unity une instance de service, ce dernier ne retourne pas directement le type d'implémentation attendu, mais bien l'instance d'un proxy (Unity Interceptor) qui intercepte tous les appels effectués sur les méthodes ou propriétés.

Une fois l'interception faite, les appels sont effectués sous la forme d'une chaine de responsabilité (Unity Interception Pipeline) où chaque maillon est une instance d'IInterceptorBehavior. Lorsque toutes les instances ont consommé/analysé l'appel (paramètres, etc.) le dernier maillon de la chaine est l'appel réel sur la méthode d'implémentation de la classe de services (Target Object).

Le retour s'effectue de la même manière, en sens inverse.

Tout ceci se réalise de façon transparente pour l'application qui consomme le service. En effet, cette dernière ne traite que sur des types d'interface ! Dès lors, que l'instance retournée soit d'un type A ou B, cela lui importe peu.

Dans notre cas de figure (le log automatique) la classe qui implémente l'interception est de type LoggerInterceptionBehavior. Elle est contenue dans BDV.POC.ArticleLog.Loggers.UnityExtensions.

Le comportement est complété par la mécanique de log (pour laquelle l'intercepteur est lui-même couplé faiblement aux instances d'ILogManager) et une classe d'extension sur le log permettant de retourner sous la forme d'une chaîne de caractères la description d'un objet. Cette dernière mécanique est contenue dans la classe LoggerExtender située dans BDV.POC.ArticleLog.Loggers.Contracts.

Nous vous conseillons de déboguer tous les appels entre l'application console et la méthode de service cible en pas à pas afin de bien visualiser le comportement. N'hésitez pas à vous servir de l'espion afin de visualiser les types retournés par les containers Unity.

L'exemple se sert du Framework Unity pour réaliser les IOC et interceptions.
D'autres frameworks présentent également une mécanique d'interception et d'IOC : SpringSpring, Castle Dynamic ProxyCastle Dynamic Proxy.
Il est également possible d'automatiser le log via le principe d'AOP. Le framework PostsharpPostsharpexpose ce principe. Le tutoriel suivant présente le principe : Redécouvrez les custom attributs avec PostSharpRedécouvrez les custom attributs avec PostSharp.
Néanmoins, l'AOP présente comme inconvénient de devoir modifier le code source pour ajouter les attributs correspondant au tracing.

Nous vous invitons à placer un point d'arrêt dans la méthode DoSomething afin de tracer le comportement.

L'implémentation n'est pas triviale : l'utilisation de Unity nécessite de prendre en mains la mécanique !

Il convient de

• paramétrer Unity ;
• charger une configuration Unity ;
• récupérer des instances pour les appels clients.

VIII-B-1. Chargement de la configuration Unity▲

// Instanciation d'un conteneur
var container = new UnityContainer();

// Récupération de la configuration Unity depuis le fichier de configuration de l'application
var section = (UnityConfigurationSection)ConfigurationManager.GetSection("unity");

// Chargement du conteneur, avec la configuration de conteneur portant le nom "WithInterception"
Microsoft.Practices.Unity.Configuration.UnityContainerExtensions.LoadConfiguration(container, section, "WithInterception");

VIII-B-2. Récupération des instances▲

ServicesProvider.GetInstanceOf<BDV.POC.ArticleLog.Services.IExempleServiceMetier>();

GetCurrentUnityContainer().Resolve<T>();

Le paramétrage peut être effectué en code (c#, vb.net, etc.) ou en XML. Nous ne traiterons que la configuration XML (utilisée dans l'exemple)

Le paramétrage consiste à :

• indiquer au Framework Unity quels sont les types qui seront demandés par les consommateurs, et quels sont les types à instancier en face ;
• préciser les paramètres des constructeurs des types à instancier ;
• préciser les interceptions éventuelles.

Nous ne détaillerons pas toutes les possibilités de Unity (cet article n'a pas cette vocation), il précise uniquement les concepts utilisés dans les exemples.

VIII-C-1. Configuration▲

<configSections>
  &#8230;
<section name="unity" type="Microsoft.Practices.Unity.Configuration.UnityConfigurationSection, Microsoft.Practices.Unity.Configuration, Version=3.0.1208.0,  Culture=neutral, PublicKeyToken=31bf3856ad364e35"/>
  &#8230;
</configSections>

<unity>
  <sectionExtension type="Microsoft.Practices.Unity.InterceptionExtension.Configuration.InterceptionConfigurationExtension, Microsoft.Practices.Unity.Interception.Configuration" />

  <container name="Main">
    <extension type="Interception" />

    <types>
      <type 
        type="BDV.POC.ArticleLog.Loggers.ILogManager, BDV.POC.ArticleLog.Loggers.Contracts" 
        mapTo="BDV.POC.ArticleLog.Loggers.NLogProvider.LogManagerForNLog, BDV.POC.ArticleLog.Loggers" >
      </type>

      <type 
        type="BDV.POC.ArticleLog.Services.IExempleServiceMetier, BDV.POC.ArticleLog.Services.Contracts" 
        mapTo="BDV.POC.ArticleLog.Services.ExempleServiceMetier, BDV.POC.ArticleLog.Services">
          <interceptor type="InterfaceInterceptor"/>
          <interceptionBehavior 
       type="BDV.POC.ArticleLog.Loggers.LoggerInterceptionBehavior, BDV.POC.ArticleLog.Loggers.UnityExtensions" />
        </type>
      </types>
    </container>
  </unity>