Managed Core Logging & Plugin Logging (#102)

managed/CounterStrikeSharp.API/Core/BasePlugin.cs

@@ -32,6 +32,7 @@
 using CounterStrikeSharp.API.Modules.Timers;
 using McMaster.NETCore.Plugins;
 using CounterStrikeSharp.API.Modules.Config;
+using Microsoft.Extensions.Logging;
 
 namespace CounterStrikeSharp.API.Core
 {
@@ -53,6 +54,7 @@ public BasePlugin()
         public string ModulePath { get; internal set; }
 
         public string ModuleDirectory => Path.GetDirectoryName(ModulePath);
+        public ILogger Logger { get; set; }
 
         public virtual void Load(bool hotReload)
         {
@@ -314,7 +316,8 @@ public void RegisterListener<T>(T handler) where T : Delegate
                 .Select(p => p.GetCustomAttribute<CastFromAttribute>()?.Type)
                 .ToArray();
 
-            Console.WriteLine($"Registering listener for {listenerName} with {parameterTypes.Length}");
+            GlobalContext.Instance.Logger.LogDebug("Registering listener for {ListenerName} with {ParameterCount} parameters",
+                listenerName, parameterTypes.Length);
 
             var wrappedHandler = new Action<ScriptContext>(context =>
             {

managed/CounterStrikeSharp.API/Core/CoreConfig.cs

@@ -24,6 +24,8 @@
 using CounterStrikeSharp.API.Modules.Admin;
 using CounterStrikeSharp.API.Modules.Commands;
 using System.Collections.Generic;
+using CounterStrikeSharp.API.Core.Logging;
+using Microsoft.Extensions.Logging;
 
 namespace CounterStrikeSharp.API.Core
 {
@@ -79,6 +81,9 @@ public static partial class CoreConfig
     public static partial class CoreConfig
     {
         private static CoreConfigData _coreConfig = new CoreConfigData();
+
+        // TODO: ServiceCollection
+        private static ILogger _logger = CoreLogging.Factory.CreateLogger("CoreConfig");
 
         static CoreConfig()
         {
@@ -97,7 +102,7 @@ public static void Load(string coreConfigPath)
         {
             if (!File.Exists(coreConfigPath))
             {
-                Console.WriteLine($"Core configuration could not be found at path '{coreConfigPath}', fallback values will be used.");
+                _logger.LogWarning("Core configuration could not be found at path \"{CoreConfigPath}\", fallback values will be used.", coreConfigPath);
                 return;
             }
 
@@ -109,12 +114,12 @@ public static void Load(string coreConfigPath)
                 {
                     _coreConfig = data;
                 }
-
-                Console.WriteLine($"Loaded core configuration");
+                
+                _logger.LogInformation("Successfully loaded core configuration.");
             }
             catch (Exception ex)
             {
-                Console.WriteLine($"Failed to load core configuration: {ex}, fallback values will be used.");
+                _logger.LogWarning(ex, "Failed to load core configuration, fallback values will be used");
             }
         }
     }

managed/CounterStrikeSharp.API/Core/FunctionReference.cs

@@ -18,6 +18,7 @@
 using System.Collections.Generic;
 using System.Linq;
 using System.Runtime.InteropServices;
+using Microsoft.Extensions.Logging;
 
 namespace CounterStrikeSharp.API.Core
 {
@@ -76,7 +77,7 @@ private FunctionReference(Delegate method)
                     }
                     catch (Exception e)
                     {
-                        Console.WriteLine(e);
+                        GlobalContext.Instance.Logger.LogError(e, "Error invoking callback");
                     }
                 });
                 s_callback = dg;
@@ -140,10 +141,7 @@ public static void Remove(int reference)
             {
                 ms_references.Remove(reference);
 
-                Console.BackgroundColor = ConsoleColor.Blue;
-                Console.ForegroundColor = ConsoleColor.White;
-                Console.WriteLine($"Removing function/callback reference: {reference}");
-                Console.ResetColor();
+                GlobalContext.Instance.Logger.LogDebug("Removing function/callback reference: {Reference}", reference);
             }
         }
     }

managed/CounterStrikeSharp.API/Core/GameData.cs

@@ -1,9 +1,11 @@
 using System;
 using System.Collections.Generic;
 using System.IO;
+using System.Linq;
 using System.Runtime.InteropServices;
 using System.Text.Json;
 using System.Text.Json.Serialization;
+using Microsoft.Extensions.Logging;
 
 namespace CounterStrikeSharp.API.Core;
 
@@ -39,17 +41,17 @@ public static void Load(string gameDataPath)
         {
             _methods = JsonSerializer.Deserialize<Dictionary<string, LoadedGameData>>(File.ReadAllText(gameDataPath))!;
 
-            Console.WriteLine($"Loaded game data with {_methods.Count} methods.");
+            GlobalContext.Instance.Logger.LogInformation("Loaded game data with {Count} methods.", _methods.Count);
         }
         catch (Exception ex)
         {
-            Console.WriteLine($"Failed to load game data: {ex}");
+            GlobalContext.Instance.Logger.LogError(ex, "Failed to load game data");
         }
     }
 
     public static string GetSignature(string key)
     {
-        Console.WriteLine($"Getting signature: {key}");
+        GlobalContext.Instance.Logger.LogDebug("Getting signature: {Key}", key);
         if (!_methods.ContainsKey(key))
         {
             throw new ArgumentException($"Method {key} not found in gamedata.json");

managed/CounterStrikeSharp.API/Core/GlobalContext.cs

@@ -1,4 +1,4 @@
-/*
+/*
  *  This file is part of CounterStrikeSharp.
  *  CounterStrikeSharp is free software: you can redistribute it and/or modify
  *  it under the terms of the GNU General Public License as published by
@@ -20,18 +20,25 @@
 using System.Linq;
 using System.Reflection;
 using System.Text;
+using CounterStrikeSharp.API.Core.Logging;
 using CounterStrikeSharp.API.Modules.Admin;
 using CounterStrikeSharp.API.Modules.Commands;
 using CounterStrikeSharp.API.Modules.Menu;
 using CounterStrikeSharp.API.Modules.Utils;
+using Microsoft.Extensions.Logging;
+using Serilog;
+using ILogger = Microsoft.Extensions.Logging.ILogger;
 
 namespace CounterStrikeSharp.API.Core
 {
     public sealed class GlobalContext
     {
         private static GlobalContext _instance = null;
+
+        public ILogger Logger { get; }
         public static GlobalContext Instance => _instance;
 
+        public static string RootDirectory => _instance.rootDir.FullName;
         private DirectoryInfo rootDir;
 
         private readonly List<PluginContext> _loadedPlugins = new();
@@ -40,6 +47,9 @@ public GlobalContext()
         {
             rootDir = new FileInfo(Assembly.GetExecutingAssembly().Location).Directory.Parent;
             _instance = this;
+            Logger = CoreLogging.Factory.CreateLogger("Core");
+
+            Logger.LogInformation("CounterStrikeSharp is starting up...");
         }
 
         ~GlobalContext()
@@ -59,18 +69,26 @@ public void OnNativeUnload()
         }
         public void InitGlobalContext()
         {
-            Console.WriteLine("Loading CoreConfig from \"configs/core.json\"");
-            CoreConfig.Load(Path.Combine(rootDir.FullName, "configs", "core.json"));
-
-            Console.WriteLine("Loading GameData from \"gamedata/gamedata.json\"");
-            GameData.Load(Path.Combine(rootDir.FullName, "gamedata", "gamedata.json"));
-
-            Console.WriteLine("Loading Admin Groups from \"configs/admin_groups.json\"");
-            AdminManager.LoadAdminGroups(Path.Combine(rootDir.FullName, "configs", "admin_groups.json"));
-            Console.WriteLine("Loading Admins from \"configs/admins.json\"");
-            AdminManager.LoadAdminData(Path.Combine(rootDir.FullName, "configs", "admins.json"));
-            Console.WriteLine("Loading Admin Command Overrides from \"configs/admin_overrides.json\"");
-            AdminManager.LoadCommandOverrides(Path.Combine(rootDir.FullName, "configs", "admin_overrides.json"));
+            var coreConfigPath = Path.Combine(rootDir.FullName, "configs", "core.json");
+            Logger.LogInformation("Loading CoreConfig from {Path}", coreConfigPath);
+            CoreConfig.Load(coreConfigPath);
+
+            var gameDataPath = Path.Combine(rootDir.FullName, "gamedata", "gamedata.json");
+            Logger.LogInformation("Loading GameData from {Path}", gameDataPath);
+            GameData.Load(gameDataPath);
+
+
+            var adminGroupsPath = Path.Combine(rootDir.FullName, "configs", "admin_groups.json");
+            Logger.LogInformation("Loading Admin Groups from {Path}", adminGroupsPath);
+            AdminManager.LoadAdminGroups(adminGroupsPath);
+
+            var adminPath = Path.Combine(rootDir.FullName, "configs", "admins.json");
+            Logger.LogInformation("Loading Admins from {Path}", adminPath);
+            AdminManager.LoadAdminData(adminPath);
+
+            var overridePath = Path.Combine(rootDir.FullName, "configs", "admin_overrides.json");
+            Logger.LogInformation("Loading Admin Command Overrides from {Path}", overridePath);
+            AdminManager.LoadCommandOverrides(overridePath);
 
             AdminManager.MergeGroupPermsIntoAdmins();
 
@@ -83,10 +101,10 @@ public void InitGlobalContext()
                     ChatMenus.OnKeyPress(player, key);
                 });
             }
-
-            Console.WriteLine("Loading C# plugins...");
+            
+            Logger.LogInformation("Loading C# plugins...");
             var pluginCount = LoadAllPlugins();
-            Console.WriteLine($"All managed modules were loaded. {pluginCount} plugins loaded.");
+            Logger.LogInformation("All managed modules were loaded. {PluginCount} plugins loaded.", pluginCount);
 
             RegisterPluginCommands();
         }
@@ -113,7 +131,7 @@ private int LoadAllPlugins()
             }
             catch (Exception e)
             {
-                Console.WriteLine(e);
+                Logger.LogError(e, "Error finding plugin path");
                 return 0;
             }
 
@@ -136,14 +154,13 @@ private int LoadAllPlugins()
 
             foreach (var path in filePaths)
             {
-                Console.WriteLine($"Plugin path: {path}");
                 try
                 {
                     LoadPlugin(path);
                 }
                 catch (Exception e)
                 {
-                    Console.WriteLine($"Failed to load plugin {path} with error {e}");
+                    Logger.LogError(e, "Failed to load plugin from {Path}", path);
                 }
             }
 
@@ -267,7 +284,7 @@ private void OnCSSPluginCommand(CCSPlayerController? caller, CommandInfo info)
                     }
                     catch (Exception e)
                     {
-                        Console.WriteLine($"Failed to load plugin {path} with error {e}");
+                        Logger.LogError(e, "Failed to load plugin from {Path}", path);
                     }
 
                     break;

managed/CounterStrikeSharp.API/Core/Logging/CoreLogging.cs

@@ -0,0 +1,29 @@
+using System;
+using System.IO;
+using Microsoft.Extensions.Logging;
+using Serilog;
+using ILogger = Microsoft.Extensions.Logging.ILogger;
+
+namespace CounterStrikeSharp.API.Core.Logging;
+
+public static class CoreLogging
+{
+    public static ILoggerFactory Factory { get; }
+
+    static CoreLogging()
+    {
+        var logger = new LoggerConfiguration()
+            .Enrich.FromLogContext()
+            .Enrich.With<SourceContextEnricher>()
+            .WriteTo.Console(outputTemplate: "{Timestamp:HH:mm:ss} [{Level:u4}] (cssharp:{SourceContext}) {Message:lj}{NewLine}{Exception}")
+            .WriteTo.File(Path.Join(new[] {GlobalContext.RootDirectory, "logs", $"log-cssharp.txt"}), rollingInterval: RollingInterval.Day, outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u4}] (cssharp:{SourceContext}) {Message:lj}{NewLine}{Exception}")
+            .WriteTo.File(Path.Join(new[] {GlobalContext.RootDirectory, "logs", $"log-all.txt"}), rollingInterval: RollingInterval.Day, shared: true, outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u4}] (cssharp:{SourceContext}) {Message:lj}{NewLine}{Exception}")
+            .CreateLogger();
+
+        Factory =
+            LoggerFactory.Create(builder =>
+            {
+                builder.AddSerilog(logger);
+            });
+    }
+}

managed/CounterStrikeSharp.API/Core/Logging/PluginLogging.cs

@@ -0,0 +1,32 @@
+using System.IO;
+using Microsoft.Extensions.Logging;
+using Serilog;
+using ILogger = Microsoft.Extensions.Logging.ILogger;
+
+namespace CounterStrikeSharp.API.Core.Logging;
+
+public class PluginLogging
+{
+    /// <summary>
+    /// Creates a logger scoped to a specific plugin
+    /// <remarks>Eventually this should probably come from a service collection</remarks>
+    /// </summary>
+    public static ILogger CreatePluginLogger(PluginContext pluginContext)
+    {
+        var logger = new LoggerConfiguration()
+            .Enrich.FromLogContext()
+            .Enrich.With(new PluginNameEnricher(pluginContext))
+            .WriteTo.Console(outputTemplate: "{Timestamp:HH:mm:ss} [{Level:u4}] (plugin:{PluginName}) {Message:lj}{NewLine}{Exception}")
+            .WriteTo.File(Path.Join(new[] {GlobalContext.RootDirectory, "logs", $"log-{pluginContext.PluginType.Name}.txt"}), rollingInterval: RollingInterval.Day, outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u4}] plugin:{PluginName} {Message:lj}{NewLine}{Exception}")
+            .WriteTo.File(Path.Join(new[] {GlobalContext.RootDirectory, "logs", $"log-all.txt"}), rollingInterval: RollingInterval.Day, shared: true, outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u4}] plugin:{PluginName} {Message:lj}{NewLine}{Exception}")
+            .CreateLogger();
+
+        using ILoggerFactory loggerFactory =
+            LoggerFactory.Create(builder =>
+            {
+                builder.AddSerilog(logger);
+            });
+
+        return loggerFactory.CreateLogger(pluginContext.PluginType);
+    }
+}

managed/CounterStrikeSharp.API/Core/Logging/PluginNameEnricher.cs

@@ -0,0 +1,22 @@
+using Serilog.Core;
+using Serilog.Events;
+
+namespace CounterStrikeSharp.API.Core.Logging;
+
+public class PluginNameEnricher : ILogEventEnricher
+{
+    public const string PropertyName = "PluginName";
+
+    public PluginNameEnricher(PluginContext pluginContext)
+    {
+        Context = pluginContext;
+    }
+
+    public PluginContext Context { get; }
+
+    public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
+    {
+        var property = propertyFactory.CreateProperty(PropertyName, Context.PluginType.Name);
+        logEvent.AddPropertyIfAbsent(property);
+    }
+}

managed/CounterStrikeSharp.API/Core/Logging/SourceContextEnricher.cs

@@ -0,0 +1,26 @@
+using System.Linq;
+using Serilog.Core;
+using Serilog.Events;
+
+namespace CounterStrikeSharp.API.Core.Logging;
+
+public class SourceContextEnricher : ILogEventEnricher
+{
+    public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
+    {
+        if (logEvent.Properties.TryGetValue("SourceContext", out var property))
+        {
+            var scalarValue = property as ScalarValue;
+            var value = scalarValue?.Value as string;
+
+            if (value?.StartsWith("CounterStrikeSharp") ?? false)
+            {
+                var lastElement = value.Split(".").LastOrDefault();
+                if (!string.IsNullOrWhiteSpace(lastElement))
+                {
+                    logEvent.AddOrUpdateProperty(new LogEventProperty("SourceContext", new ScalarValue(lastElement)));
+                }
+            }
+        }
+    }
+}