Logging dans .Net Core

L’idée de ce blog me vient de ce tweet:

https://twitter.com/vcsjones/status/1122537463195607043

 

Le SDK .NET Core assure la gestion des logs de façon très générique à travers diverses interfaces:

 

  1. ILogger
  2. ILoggerProvider
  3. ILoggerFactory
  4. ILoggerBuilder

 

 

Les deux dernières ont un nom un peu inquiétant pour de nombreux développeurs. Un SDK qui a besoin d’un Builder et d’une Factory c’est souvent suspect!

On va être honnête, si l’architecture fournie par Microsoft fonctionne, elle n’est pas totalement réussie.

 

Comment s’en servir? On a au moins deux approches dans un contexte Core:

  1. Profiter de l’injection de dépendance intégrée et injecter
  2. Créer une classe statique pour gérer ses logs

 

J’ai utilisé les deux approches tout au long de mes projets, je n’ai pas vraiment d’opinion.

D’un côté une classe statique ce n’est pas génial pour les tests unitaires, d’un autre côté l’injection de dépendance finit par donner des constructeurs avec une multitude de paramètres, c’est vite pénible.

Je suis intéressé par vos retours.

Dans ce tuto je vais me contenter de la première méthode.

 

Un dernier point: pour des projets vraiment très simples, Console.Writeline() est suffisant, même pour du web.

La démo niveau 101

 

On démarre avec le projet web .NET Core par défaut.

L’aventure démarre dans le fichier program.cs:


public static IWebHostBuilder CreateWebHostBuilder(string[] args) =>
   WebHost.CreateDefaultBuilder(args)
   .UseStartup<Startup>();

 

C’est le code par défaut créé lorsque l’on initie un projet ASP.NET Core.

 

Note: À partir de la version .NET Core 3.0, le Web Host Builder sera remplacé par Generic Host Builder:

https://wakeupandcode.com/generic-host-builder-in-asp-net-core/

 

Remarquez la méthode CreateDefaultBuilder().

Elle initialise un Builder avec une configuration par défaut qui entre autres active les fournisseurs de logs suivants:

  • Console
    Sortie vers la console
  • Debug
    Sortie via la classe System.Diagnostics.Debug
  • Event Source (depuis la version 2.2)
    Event logs Windows

Bien entendu on peut installer ses propres fournisseurs qu’ils soient par défaut ou fournis par des tiers:


public static IWebHostBuilder CreateWebHostBuilder(string[] args) =>
   WebHost.CreateDefaultBuilder(args)
      .UseStartup<Startup>()
      .ConfigureLogging(logging =>
      {
         logging.ClearProviders();
         logging.AddConsole();
});

 

On commence par un appel à ClearProviders(), puis on ajoute les fournisseurs qui nous intéressent.

 

Une fois cette initialisation terminée, l’essentiel est fait, il n’y a plus qu’à écrire dans les logs.

 

Dans une application Web, on injecte un ILogger dans un contrôleur:


private readonly ILogger _logger;

public HomeController(ILogger<HomeController> logger)
{
   _logger = logger;
}

public IActionResult Index()
{
   _logger.LogInformation("Mon premier log");

   return View();
}

 

Le code d’injection est très classique. Notez le paramètre du générique qui doit juste être une classe. Elle fonctionne comme une catégorie, une sorte d’espace de noms. On en reparlera dans le chapitre CONFIGURATION.

 

Note: avec une application Console, on utilisera LogFactory

 

Pour vérifier que tout fonctionne, le plus simple est d’observer la console Visual Studio où l’on découvre ce message:

DemoLogger.Controllers.HomeController:Information: Mon premier log

 

La structure du message reprend la catégorie, le niveau (Information), puis le message. Si l’on avait utilisé String comme source à la place de HomeController on aurait lu:

string:Information: Mon premier log

 

Configuration

 

Il existe plusieurs façons, les plus intéressantes sont je pense, le fichier de configuration ou les variables d’environnement.

Regardons justement notre fichier appsetting.json:

 

La propriété Logging est le bloc contenant la configuration des logs. Cet exemple est modeste, une seule propriété LogLevel est définie. Cette propriété spécifie le niveau de log minimal qui sera enregistré pour chaque catégorie.

On a qu’une seule catégorie (Default) dont vous devinez facilement la fonction.

 

Niveaux de logs

Les niveaux de logs sont les suivants par poids croissant:

  • Trace
    Informations uniquement destinées à un développeur à des fins de débogage
  • Debug
    Informations de débogage de niveau moins sensible que Trace.
    Trace pourra par exemple loguer des infos comme des mots de passe, des chaînes de connexion, mais pas Debug.
  • Info
    Trace de log générique., pas spécialement destinée à du débogage
  • Warning
    Situation inattendue ou anormale. Cela peut aussi être des conditions d’erreur, mais qui n’entraînent pas l’arrêt de l’application, par exemple FileNotFoundException si l’appli fournit une valeur par défaut.
  • Error
    Erreur ou exception qui causent l’arrêt de l’application ou de l’opération. Par exemple un problème d’insertion dans une base avec un ID déjà existant
  • Critical
    Erreur qui réclame une attention forte. Par exemple un espace de stockage est plein.
  • None
    Pas de filtrage

 

Catégories

À quoi correspondent les catégories.

 

Les catégories sont liées à l’espace de noms de la classe passée en paramètre générique de ILogger<>. Elles servent de filtrage comme on va le voir dans les exemples qui suivent.

Dans un premier temps, modifions ainsi la configuration:

 

Vous remarquez essentiellement une ligne supplémentaire qui correspond à l’espace de noms des contrôleurs. On modifie ensuite le code ainsi:


public IActionResult Index()
{
   _logger.LogInformation("Msg: Information");
   _logger.LogDebug("Msg: Debug");

   return View();
}

Et on lance. On lit alors dans la console:

DemoLogger.Controllers.HomeController:Information: Msg: Information

On a paramétré un blocage des logs en dessous du niveau Info. Donc la ligne en LogDebug n’imprime rien. C’est normal.

 

Construisons ce contrôleur similaire au précédent (ainsi que la plomberie, vue, lien…):


private readonly ILogger _logger;

public AboutController(ILogger&lt;AboutController&gt; logger)
{
   _logger = logger;
}

// GET: About
public ActionResult Index()
{
   _logger.LogInformation("Msg: Information");
   _logger.LogWarning("Msg: Warning");
    return View();
}

 

L’espace de noms est le même, seul le paramètre générique de ILogger<> diffère. Naviguons vers ce contrôleur, cette fois deux logs sont imprimés:

DemoLogger.Controllers.AboutController:Information: Msg: Information
DemoLogger.Controllers.AboutController:Warning: Msg: Warning

 

L’analyse est la même que tout à l’heure. Elle montre surtout que le paramétrage des log s’étend bien à tout le contexte défini par l’espace de noms DemoLogger.Controllers.

Pour conclure la démonstration, modifions la configuration:

On ajoute une deuxième catégorie DemoLogger.Controllers.AboutController.

Lançons l’appli. On constate que rien ne change pour la page d’accueil. La page About imprime quant à elle une seule ligne:

DemoLogger.Controllers.AboutController:Warning: Msg: Warning

 

Je pense que le fonctionnement des catégories est clair.

Dans la pratique je ne pense pas que l’utiliser comme sur la démo soit l’usage le plus fréquent. On va plutôt vouloir filtrer les logs du SDK avec ce genre d’espace de noms:

« System »: « Information »,
« Microsoft »: « Information »

 

Le paramétrage que l’on vient de voir est global, Il n’est pas impossible de le détailler à l’échelle du fournisseur. Par exemple pour la console on pourrait par exemple déclarer:

 

Si vous avez besoin d’en savoir plus, une étude complète se trouve ici:

https://docs.microsoft.com/en-us/aspnet/core/fundamentals/logging/?view=aspnetcore-2.2

 

ILoggerFactory

ILoggerFactory décrit un objet capable de créer un ILogger, mais aussi d’ajouter des ILoggerProvider, c’est à dire un service capable d’écrire des logs dans une source particulière (fichier, DB…). On peut enregistrer plusieurs fournisseurs, ILogger les logs seront automatiquement émit vers chacun d’entre eux. Le source est d’ailleurs intéressant à regarder:

https://github.com/aspnet/Logging/blob/master/src/Microsoft.Extensions.Logging/Logger.cs

Vous remarquerez au passage que Logger est essentiellement une liste de Loggers. Un pour chaque fournisseur.

 

Une autre façon d’écrire le code qui précède est le suivant:


private readonly ILogger _logger;

public HomeController(ILoggerFactory factory)
{
   _logger = factory.CreateLogger&lt;HomeController&gt;();
}

public IActionResult Index()
{
   _logger.LogDebug("Mon log est ici!");

   return View();
}

 

Cette syntaxe est intéressante si on souhaite gérer les catégories dynamiquement ou bien dans des applications comme les applications consoles.

 

ILoggerProvider

Un fournisseur de logs est une classe capable d’écrire des logs sur un média particulier (Console, fichier, base de données…). Ces fournisseurs sont injecté dans Core en implémentant ILoggerProvider.

Comme évoqué dans le chapitre précédent, ILoggerProvider instancie un Logger et l’ajoute à la collection de Loggers.

 

Microsoft en fournit nativement certains, des éditeurs tiers en fournissent d’autres et on peut aussi implémenter son fournisseur.

 

Faisons un essai. Commençons par implémenter un ILogger:


public class DummyLogger : ILogger
{
   public IDisposable BeginScope<TState>(TState state)
   {
      return null;
   }

   public bool IsEnabled(LogLevel logLevel)
   {
      return true;
   }

   public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
   {
      if (!IsEnabled(logLevel))
      {
         return;
      }

      Trace.WriteLine($"DummyLogger: {formatter(state, exception)}");
   }
}

 

Puis son ILoggerProvider:

 


public class DummyProvider : ILoggerProvider
{
   private readonly ConcurrentDictionary<string, DummyLogger> _loggers = new ConcurrentDictionary<string, DummyLogger>();

   public ILogger CreateLogger(string categoryName)
   {
      return _loggers.GetOrAdd(categoryName, name => new DummyLogger());
   }

   public void Dispose()
   {
      _loggers.Clear();
   }
}

 

L’injection du logger se fait dans le pipeline OWIN de façon classique:


public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory)
{
   // code supprime

   loggerFactory.AddProvider(new DummyProvider());

   // code supprimé
}

 

Note: une bonne idée est de créer une méthode d’extension spécialisée de ILoggerFactory

Le reste du code est inchangé, si on lance l’application on observe:

DummyLogger: Mon log est ici!

 

Note: c’est très instructif de placer un point d’arrêt dans les méthodes Log et Configure afin de mieux comprendre l’intérêt des catégories.

 

Remarques générales

Je me suis cantonné au cas du SDK Microsoft. Des éditeurs tiers, comme Serilog, NLog ou Elmah, propose eux aussi des outils de log qui s’insèrent dans la plomberie Core en implémentant les différentes interfaces que nous venons de voir.

Ils proposent aussi souvent des méthodes d’extension à ces interfaces qui peuvent simplifier la vie. Lisez bien leur doc.

 

On peut aussi se demander: doit t’on injecter un ILogger dans nos constructeurs ou bien un IloggerFactory.

Honnêtement je trouve que l’injection de ILogger est plus propre. L’injection de la factory implique de compléter le constructeur d’une ligne du style:


_logger = logger.CreateLogger("TodoApi.Controllers.TodoController");

Ce n’est pas le rôle d’un constructeur d’injection qui n’a qu’une responsabilité: accueillir les dépendances. On a ici une violation du principe SRP.

 

Cela ne signifie pas que ILogger soit sans inconvénients en particulier il serait plus intéressant que la plomberie d’injection de .Net Core sache injecter un ILogger générique. Si le sujet vous intéresse, voici deux lectures:

https://blog.simpleinjector.org/2016/06/whats-wrong-with-the-asp-net-core-di-abstraction/

https://vuscode.wordpress.com/2009/10/16/inversion-of-control-single-responsibility-principle-and-nikola-s-laws-of-dependency-injection/

 

Bibliographie

 

 

Votre commentaire

Entrez vos coordonnées ci-dessous ou cliquez sur une icône pour vous connecter:

Logo WordPress.com

Vous commentez à l’aide de votre compte WordPress.com. Déconnexion /  Changer )

Image Twitter

Vous commentez à l’aide de votre compte Twitter. Déconnexion /  Changer )

Photo Facebook

Vous commentez à l’aide de votre compte Facebook. Déconnexion /  Changer )

Connexion à %s