Quand vous Ă©crivez des logs dans une application, vous avez sĂ»rement une classe dĂ©diĂ©e (voire une instance singleton) qui gĂšre lâĂ©criture de ces logs et que vous utilisez partout dans votre code. Ce mĂ©canisme est gĂ©nĂ©ralement simple et direct. Mais si vous jetez un Ćil Ă la façon dont on utilise le logger dans PandApache, vous pourriez ĂȘtre un peu surpris par cette ligne :
ExecutionContext.Current.Logger.LogInfo($"Admin server listening on {ServerConfiguration.Instance.ServerIP}:{ServerConfiguration.Instance.AdminPort}");
Sortie:
12/09/2024 12:26:48 - Module: Admin - Thread ID: 1 - INFO - Admin server listening on 0.0.0.0:4040
Avant d'expliquer cette ligne, prenons un peu de recul pour comprendre comment on en est arrivé là .
Comment PandApache fonctionne?
Lorsque PandApache est en cours d'exécution, vous avez plusieurs éléments en jeu :
- Le Service : c'est le programme principal lui-mĂȘme.
- Les modules : chaque module crĂ©e une nouvelle tĂąche, car ils sâexĂ©cutent simultanĂ©ment.
- Les sous-tùches : certains modules peuvent démarrer leurs propres sous-tùches en fonction de l'action qu'ils effectuent.
L'objectif est de rendre chaque module le plus indépendant et configurable possible. Ainsi, chaque module doit posséder :
- Son propre logger : cela permet de savoir quel log a été écrit par quel module, tout en appliquant des rÚgles de log spécifiques (niveaux différents, fichiers différents, etc.).
- Son propre task scheduler : pour ne pas monopoliser toutes les ressources et laisser suffisamment pour les autres
comment gérer le bon logger dans chaque module ?
Il existe plusieurs façons de s'assurer que chaque module utilise le bon logger (et le bon task scheduler, mais on va le laisser de coté pour le moment). Une solution serait de passer le logger approprié en paramÚtre à chaque méthode, ou d'utiliser l'injection de dépendance. Cela pourrait ressembler à ceci :
Logger loggerAdmin = new Logger(configAdmin);
Logger loggerWeb = new Logger(configWeb);
Module moduleAdmin = new Module(loggerAdmin);
Module moduleWeb = new Module(loggerWeb);
Cette approche n'est pas idéale. Pourquoi ? Parce qu'il faudrait que chaque sous-fonction puisse accéder au logger approprié, soit en le passant explicitement en paramÚtre, soit par injection de dépendance, ce qui peut rapidement devenir lourd et redondant.
Prenons un exemple dans un module :
Module{
public Logger LoggerAdmin;
Foo() {
LoggerAdmin.LogInfo("Here");
RandomObject.Bar(LoggerAdmin);
}
}
RandomObject{
Bar(Logger logger) {
logger.LogInfo("There");
}
}
On pourrait aussi opter pour une solution avec des objets statiques qui renverraient le bon logger, ce qui donnerait :
Foo() {
LoggerAdmin.LogInfo("Here");
}
Bar() {
LoggerAdmin.LogInfo("There");
}
Mais cette solution présente deux problÚmes majeurs :
Choisir manuellement le bon logger : à chaque fonction ou classe, il faut décider quel logger utiliser. Et si une fonction change de contexte (par exemple, du module Web au module Admin), il faut constamment adapter ce choix. Cela manque de flexibilité et augmente les risques de bugs.
La gestion des instances multiples : Les modules Web et Admin sont en rĂ©alitĂ© deux instances du mĂȘme module, mais qui exĂ©cutent le mĂȘme code. Comment faire en sorte que chaque instance ait son propre logger sans avoir Ă le spĂ©cifier Ă chaque appel ?
Le vĂ©ritable dĂ©fi est de trouver un moyen de rĂ©cupĂ©rer automatiquement le bon logger (ou tout autre objet spĂ©cifique au module) sans avoir Ă le prĂ©ciser chaque fois et sans passer par des paramĂštres spĂ©cifiques. Ce bon objet doit ĂȘtre dĂ©terminĂ© en fonction du module qui est actuellement en cours dâexĂ©cution, et non de maniĂšre manuelle Ă chaque appel de fonction.
Dans cette optique, comment pourriez-vous rĂ©soudre ce problĂšme de maniĂšre plus Ă©lĂ©gante ? Laissez un commentaire pour partager votre approche et expliquer comment vous gĂ©reriez lâinjection de dĂ©pendances dans ce contexte, en particulier pour des objets spĂ©cifiques Ă chaque module comme le logger.
Virtual Logger
Pour bien imaginer la solution finale, avoir les logs souhaitĂ©s en tĂȘte est important. Voici les logs de PandApache :
12/09/2024 12:33:25 - Module: Server - Thread ID: 1 - WARNING - Module Telemetry disabled
12/09/2024 12:33:25 - Module: Server - Thread ID: 1 - INFO - PandApache3 is starting
12/09/2024 12:33:25 - Module: Web - Thread ID: 1 - INFO - Starting Connection manager module
12/09/2024 12:33:25 - Module: Web - Thread ID: 1 - INFO - Web server listening on 0.0.0.0:8080
12/09/2024 12:33:25 - Module: Admin - Thread ID: 1 - INFO - Starting Connection manager module
12/09/2024 12:33:25 - Module: Admin - Thread ID: 1 - INFO - Admin server listening on 0.0.0.0:4040
12/09/2024 12:33:25 - Module: default - Thread ID: 1 - INFO - PandApache3 process id:3738
12/09/2024 12:33:25 - Module: default - Thread ID: 1 - INFO - PandApache3 process name:dotnet
12/09/2024 12:33:25 - Module: Server - Thread ID: 1 - INFO - PandApache3 is up and running!
12/09/2024 12:33:25 - Module: Web - Thread ID: 6 - INFO - Running Connection manager module
12/09/2024 12:33:28 - Module: Web - Thread ID: 6 - INFO - Client connected
12/09/2024 12:33:28 - Module: Web - Thread ID: 12 - INFO - Reading query string parameter
12/09/2024 12:33:28 - Module: Web - Thread ID: 13 - INFO - LoggerMiddleware invoked
12/09/2024 12:33:28 - Module: Web - Thread ID: 13 - INFO - Log Request
12/09/2024 12:33:28 - Module: Web - Thread ID: 13 - INFO - [12/09/2024 10:33:28] GET /
12/09/2024 12:33:28 - Module: Web - Thread ID: 14 - INFO - Log Response
12/09/2024 12:33:28 - Module: Web - Thread ID: 14 - INFO - [12/09/2024 10:33:28] Response status code: 200
12/09/2024 12:33:28 - Module: Web - Thread ID: 14 - INFO - client Closed
12/09/2024 12:33:28 - Module: Web - Thread ID: 6 - INFO - Client connected
12/09/2024 12:33:28 - Module: Web - Thread ID: 13 - INFO - Reading query string parameter
On y voit des informations classiques, mais deux éléments qui changent de façon réguliÚre et qui sont trÚs importants : le module et le thread ID.
Pour comprendre comment on en arrive à ces logs, le plus logique est sans doute de commencer par regarder de quoi est composé un module de PandApache, notamment ses propriétés. Voici les propriétés du module ConnectionManager, qui est la classe instanciée pour le module Web et Admin :
public TcpListener Listener { get; set; }
public TaskFactory TaskFactory { get; }
public ModuleConfiguration ModuleInfo { get; set; }
public ModuleType ModuleType { get; set; }
private static AsyncLocal<ModuleConfiguration> _current = new AsyncLocal<ModuleConfiguration>();
public CancellationTokenSource _cancellationTokenSource { get; } = new CancellationTokenSource();
private ConcurrentDictionary<Guid, ISocketWrapper> _clients { get; } = new ConcurrentDictionary<Guid, ISocketWrapper>();
private ConcurrentDictionary<Guid, ISocketWrapper> _clientsRejected = new ConcurrentDictionary<Guid, ISocketWrapper>();
private Func<HttpContext, Task> _pipeline;
private TaskScheduler _taskScheduler;
Les propriétés qui vont nous intéresser en particulier sont :
public ModuleConfiguration ModuleInfo { get; set; }private TaskScheduler _taskScheduler;
Le TaskScheduler est plutĂŽt simple, mĂȘme si nous avons rĂ©implĂ©mentĂ© notre propre TaskScheduler pour quelques modifications. Câest un hĂ©ritage de la classe par dĂ©faut et donc fonctionne globalement de la mĂȘme maniĂšre.
ModuleConfiguration, quant Ă elle, est une classe originale que voici :
public class ModuleConfiguration
{
private TaskScheduler _taskScheduler;
public ModuleType Type;
public string Name;
public bool isEnable;
public TaskFactory TaskFactory { get; }
public VirtualLogger Logger;
public ModuleConfiguration(string name)
{
Name = name;
Type = moduleType;
Logger = new VirtualLogger(name);
}
}
On retrouve notre TaskScheduler, mais nous avons aussi un VirtualLogger qui prend en paramĂštre un nom.
Un VirtualLogger est exactement comme le logger normal de PandApache. Dâailleurs, la classe VirtualLogger et Logger implĂ©mentent tous deux lâinterface ILogger.
La différence est que le VirtualLogger envoie son log au Logger, et ce dernier envoie son log au systÚme (Console ou fichier).
Nous avons donc des modules qui sâexĂ©cutent chacun dans leur propre tĂąche et qui contiennent nos deux instances dâobjets que lâon souhaite utiliser dans des contextes dâexĂ©cution bien prĂ©cis. Nous avons tous les Ă©lĂ©ments mis en place pour ce que nous souhaitons faire, il suffit de voir ensemble comment cela fonctionne.
Entre nous
On pourrait se dire quâun
VirtualLoggerest une abstraction inutile ici. On pourrait trĂšs bien utiliser directement la classeLoggeroriginelle avec plusieurs instances diffĂ©rentes, exactement comme ce que lâon fait avec leVirtualLogger. Câest certes vrai, mais il y a d'autres avantages auVirtualLoggerqui nâont pas Ă©tĂ© expliquĂ©s ici. Ce quâil faut retenir, câest que leVirtualLoggernâest pas lĂ uniquement pour avoir des loggers indĂ©pendants, mais surtout pour sĂ©parer lâaction de logger une information et lâaction de la distribuer, que ce soit Ă la console ou dans un fichier. On explorera cela dans un prochain billet de blog.
Le Contexte d'Exécution
Reprenons la ligne pour exécuter le logger du début.
ExecutionContext.Current.Logger.LogInfo($"Admin server listening on {ServerConfiguration.Instance.ServerIP}:{ServerConfiguration.Instance.AdminPort}");
Il est temps de parler de lâobjet ExecutionContext. Il sâagit dâune classe simple qui ne contient quâun champ statique pour ĂȘtre appelĂ© de partout facilement. La voici :
public static class ExecutionContext
{
private static AsyncLocal<ModuleConfiguration> _current = new AsyncLocal<ModuleConfiguration>();
public static ModuleConfiguration Current
{
get => _current.Value;
set => _current.Value = value;
}
}
La particularité de cette classe est le type de _current, qui est un AsyncLocal<ModuleConfiguration>. Cela nous permet de garantir une valeur distincte de _current dans les différents contextes d'exécution, autrement dit, dans les tùches.
Chaque module, au dĂ©marrage, assigne Ă la variable _current de son contexte d'exĂ©cution lâobjet ModuleInfo :
ExecutionContext.Current = ModuleInfo;
Quand, dans le module, la ligne :
ExecutionContext.Current.Logger.LogInfo("Starting Connection manager module");
Sortie:
12/09/2024 12:26:48 - Module: Web - Thread ID: 1 - INFO - Starting Connection manager module
est utilisĂ©e, câest donc bien le bon logger qui est utilisĂ©, celui du module.
D'ailleurs voici les 2 sorties de log de cette mĂȘme ligne gĂ©nĂ©rĂ© par 2 modules (Web et Admin)
Sortie:
12/09/2024 12:26:48 - Module: Web - Thread ID: 1 - INFO - Starting Connection manager module
12/09/2024 12:26:48 - Module: Web - Thread ID: 1 - INFO - Web server listening on 0.0.0.0:8080
12/09/2024 12:26:48 - Module: Admin - Thread ID: 1 - INFO - Starting Connection manager module
12/09/2024 12:26:48 - Module: Admin - Thread ID: 1 - INFO - Admin server listening on 0.0.0.0:4040
Quand un module lance une autre tĂąche, comme le module Web qui accepte une connexion pour traiter la requĂȘte :
await AcceptConnectionsAsync(client);
On change théoriquement de contexte, on est dans une sous-tùche de la tùche principale. Cependant, la valeur de la propriété AsyncLocal est automatiquement héritée, ce qui fait que dans la fonction AcceptConnectionsAsync, quand on utilise le logger via ExecutionContext :
ExecutionContext.Current.Logger.LogInfo($"Client connected");
sortie:
12/09/2024 12:33:45 - Module: Admin - Thread ID: 9 - INFO - Client connected
Nous avons toujours le bon ModuleInfo configuré.
Finalement
Tout ceci nous permet beaucoup de choses dans PandApache. Pour les loggers, mĂȘme si chaque VirtualLogger diffĂšre trĂšs peu (seul le nom du module stockĂ© directement dans le logger diffĂšre dâun VirtualLogger Ă lâautre), nous avons quand mĂȘme lâavantage de la transparence et de lâisolation logique au moment de lâutilisation, ainsi que de la cohĂ©rence et de la standardisation au moment de lâĂ©criture.
Le TaskScheduler, dont nous avons trĂšs peu parlĂ© car moins visuel, mais qui fonctionne exactement comme le logger, nous permet encore une fois de façon trĂšs transparente de lancer de nouvelles tĂąches dans notre module, en ayant des rĂšgles notamment au niveau du nombre de threads personnalisĂ©s. Ainsi, on peut sâassurer que le module tĂ©lĂ©metrie, qui nâest pas un module vital, nâutilise pas trop de ressources (un thread pour la tĂ©lĂ©metrie est, par exemple, suffisant selon le nombre de mĂ©triques que vous souhaitez capturer).
Au contraire, si votre module web nâa plus assez de ressources pour gĂ©rer une nouvelle requĂȘte, vous allez ĂȘtre trĂšs contrariĂ©. Câest donc une gestion des ressources plus fine qui peut ĂȘtre effectuĂ©e au final grĂące Ă ce contexte dâexĂ©cution partagĂ©.
JâespĂšre que cet article vous aura aidĂ© Ă mieux comprendre l'utilisation de AsyncLocal en C#. Si ce langage vous intĂ©resse, sachez que le code de PandApache3 est disponible sur GitHub et en live sur Twitch. NâhĂ©sitez pas Ă suivre lâaventure !
Top comments (0)