From cba94465650b4bbfe7ae42e918e9f6012b5d58cf Mon Sep 17 00:00:00 2001 From: Aleksandr Vishniakov Date: Tue, 24 Dec 2024 18:10:19 +0200 Subject: [PATCH] Refactor serilog initialization and add module initialization logging (#2871) Co-authored-by: Oleg Zhuk --- .../Logger/ConsoleLog.cs | 1 + .../ModuleInitializer.cs | 6 ++-- .../ModuleManager.cs | 21 +++++--------- .../Extensions/ServiceCollectionExtensions.cs | 7 ++--- src/VirtoCommerce.Platform.Web/Program.cs | 14 +-------- src/VirtoCommerce.Platform.Web/Startup.cs | 29 ++++++++++++++----- .../appsettings.Development.json | 4 ++- .../appsettings.Production.json | 1 + 8 files changed, 42 insertions(+), 41 deletions(-) diff --git a/src/VirtoCommerce.Platform.Core/Logger/ConsoleLog.cs b/src/VirtoCommerce.Platform.Core/Logger/ConsoleLog.cs index 6669938792e..a2e2fb79b05 100644 --- a/src/VirtoCommerce.Platform.Core/Logger/ConsoleLog.cs +++ b/src/VirtoCommerce.Platform.Core/Logger/ConsoleLog.cs @@ -2,6 +2,7 @@ namespace VirtoCommerce.Platform.Core.Logger { + [Obsolete("Use Serilog's static Log.Logger or inject ILogger instead", DiagnosticId = "VC0010", UrlFormat = "https://docs.virtocommerce.org/platform/user-guide/versions/virto3-products-versions/")] public static class ConsoleLog { public static void BeginOperation(string message) diff --git a/src/VirtoCommerce.Platform.Modules/ModuleInitializer.cs b/src/VirtoCommerce.Platform.Modules/ModuleInitializer.cs index 5577e9df72e..99620289bb9 100644 --- a/src/VirtoCommerce.Platform.Modules/ModuleInitializer.cs +++ b/src/VirtoCommerce.Platform.Modules/ModuleInitializer.cs @@ -48,7 +48,7 @@ public ModuleInitializer( /// /// Initializes the specified module. /// - /// The module to initialize + /// The module to initialize public void Initialize(ModuleInfo moduleInfo) { if (moduleInfo == null) @@ -80,6 +80,7 @@ public void Initialize(ModuleInfo moduleInfo) hasModuleCatalog.ModuleCatalog = _moduleCatalog; } + _loggerFacade.LogDebug("Initializing module {ModuleName}.", moduleInfo.ModuleName); moduleInstance.Initialize(_serviceCollection); moduleInfo.State = ModuleState.Initialized; } @@ -103,6 +104,7 @@ public void PostInitialize(ModuleInfo moduleInfo, IApplicationBuilder appBuilder { if (moduleInstance != null) { + _loggerFacade.LogDebug("Post-initializing module {ModuleName}.", moduleInfo.ModuleName); moduleInstance.PostInitialize(appBuilder); } } @@ -115,7 +117,7 @@ public void PostInitialize(ModuleInfo moduleInfo, IApplicationBuilder appBuilder /// /// Handles any exception occurred in the module Initialization process, /// logs the error using the and throws a . - /// This method can be overridden to provide a different behavior. + /// This method can be overridden to provide a different behavior. /// /// The module metadata where the error happened. /// The exception thrown that is the cause of the current error. diff --git a/src/VirtoCommerce.Platform.Modules/ModuleManager.cs b/src/VirtoCommerce.Platform.Modules/ModuleManager.cs index e4b9d9451ba..cca08ff21ad 100644 --- a/src/VirtoCommerce.Platform.Modules/ModuleManager.cs +++ b/src/VirtoCommerce.Platform.Modules/ModuleManager.cs @@ -3,14 +3,13 @@ using System.Linq; using Microsoft.AspNetCore.Builder; using Microsoft.Extensions.Logging; -using VirtoCommerce.Platform.Core.Logger; using VirtoCommerce.Platform.Core.Modularity; using VirtoCommerce.Platform.Core.Modularity.Exceptions; namespace VirtoCommerce.Platform.Modules { /// - /// Component responsible for coordinating the modules' type loading and module initialization process. + /// Component responsible for coordinating the modules' type loading and module initialization process. /// public class ModuleManager : IModuleManager, IDisposable { @@ -77,17 +76,13 @@ private void RaiseLoadModuleCompleted(LoadModuleCompletedEventArgs e) /// public void Run() { - ConsoleLog.BeginOperation("Initializing module catalog"); + _loggerFacade.LogInformation("Initializing module catalog"); this.ModuleCatalog.Initialize(); - ConsoleLog.EndOperation(); - - ConsoleLog.BeginOperation("Loading modules"); + _loggerFacade.LogInformation("Loading modules"); this.LoadModulesWhenAvailable(); - - ConsoleLog.EndOperation(); } @@ -117,8 +112,8 @@ public void PostInitializeModule(ModuleInfo moduleInfo, IApplicationBuilder appl } /// - /// Returns the list of registered instances that will be - /// used to load the types of modules. + /// Returns the list of registered instances that will be + /// used to load the types of modules. /// /// The module type loaders. public virtual IEnumerable ModuleTypeLoaders @@ -161,8 +156,8 @@ protected virtual bool ModuleNeedsRetrieval(ModuleInfo moduleInfo) if (moduleInfo.State == ModuleState.NotStarted) { - // If we can instantiate the type, that means the module's assembly is already loaded into - // the AppDomain and we don't need to retrieve it. + // If we can instantiate the type, that means the module's assembly is already loaded into + // the AppDomain and we don't need to retrieve it. bool isAvailable = Type.GetType(moduleInfo.ModuleType) != null; if (isAvailable) { @@ -286,7 +281,7 @@ private void IModuleTypeLoader_LoadModuleCompleted(object sender, LoadModuleComp /// /// Handles any exception occurred in the module type loading process, /// logs the error using the and throws a . - /// This method can be overridden to provide a different behavior. + /// This method can be overridden to provide a different behavior. /// /// The module metadata where the error happened. /// The exception thrown that is the cause of the current error. diff --git a/src/VirtoCommerce.Platform.Web/Extensions/ServiceCollectionExtensions.cs b/src/VirtoCommerce.Platform.Web/Extensions/ServiceCollectionExtensions.cs index c3f98d4fdbd..5d8166e04f0 100644 --- a/src/VirtoCommerce.Platform.Web/Extensions/ServiceCollectionExtensions.cs +++ b/src/VirtoCommerce.Platform.Web/Extensions/ServiceCollectionExtensions.cs @@ -4,10 +4,11 @@ using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Hosting; using Microsoft.Extensions.Logging; +using Serilog; using VirtoCommerce.Platform.Core.Common; -using VirtoCommerce.Platform.Core.Logger; using VirtoCommerce.Platform.Core.Modularity; using VirtoCommerce.Platform.Modules.External; +using VirtoCommerce.Platform.Web; namespace VirtoCommerce.Platform.Modules { @@ -38,7 +39,7 @@ public static IServiceCollection AddModules(this IServiceCollection services, IM manager.Run(); // Ensure all modules are loaded - ConsoleLog.BeginOperation("Registering API controllers"); + Log.ForContext().Information("Registering API controllers"); var notStartedModules = moduleCatalog.Modules.Where(x => x.State == ModuleState.NotStarted); var modules = moduleCatalog.CompleteListWithDependencies(notStartedModules) @@ -59,8 +60,6 @@ public static IServiceCollection AddModules(this IServiceCollection services, IM } } - ConsoleLog.EndOperation(); - services.AddSingleton(moduleCatalog); return services; } diff --git a/src/VirtoCommerce.Platform.Web/Program.cs b/src/VirtoCommerce.Platform.Web/Program.cs index e0a6864b955..124e3242f61 100644 --- a/src/VirtoCommerce.Platform.Web/Program.cs +++ b/src/VirtoCommerce.Platform.Web/Program.cs @@ -59,7 +59,7 @@ public static IHostBuilder CreateHostBuilder(string[] args) => }) .ConfigureServices((hostingContext, services) => { - //Conditionally use the hangFire server for this app instance to have possibility to disable processing background jobs + //Conditionally use the hangFire server for this app instance to have possibility to disable processing background jobs if (hostingContext.Configuration.GetValue("VirtoCommerce:Hangfire:UseHangfireServer", true)) { // Add & start hangfire server immediately. @@ -83,18 +83,6 @@ public static IHostBuilder CreateHostBuilder(string[] args) => } }); } - }) - .UseSerilog((context, services, loggerConfiguration) => - { - // read from configuration - _ = loggerConfiguration.ReadFrom.Configuration(context.Configuration); - - // enrich configuration from external sources - var configurationServices = services.GetService>(); - foreach (var service in configurationServices) - { - service.Configure(loggerConfiguration); - } }); } } diff --git a/src/VirtoCommerce.Platform.Web/Startup.cs b/src/VirtoCommerce.Platform.Web/Startup.cs index eda4e598ed1..13c435649cc 100644 --- a/src/VirtoCommerce.Platform.Web/Startup.cs +++ b/src/VirtoCommerce.Platform.Web/Startup.cs @@ -33,6 +33,7 @@ using Newtonsoft.Json.Converters; using OpenIddict.Abstractions; using OpenIddict.Validation.AspNetCore; +using Serilog; using VirtoCommerce.Platform.Core; using VirtoCommerce.Platform.Core.Common; using VirtoCommerce.Platform.Core.DynamicProperties; @@ -98,11 +99,26 @@ public Startup(IConfiguration configuration, IWebHostEnvironment hostingEnvironm // This method gets called by the runtime. Use this method to add services to the container. public void ConfigureServices(IServiceCollection services) { - ConsoleLog.BeginOperation("Virto Commerce is loading"); + // Use temporary bootstrap logger (which will be replaced with configured version later) until DI initialization completed + Log.Logger = new LoggerConfiguration().ReadFrom.Configuration(Configuration).CreateBootstrapLogger(); - var databaseProvider = Configuration.GetValue("DatabaseProvider", "SqlServer"); + services.AddSerilog((serviceProvider, loggerConfiguration) => + { + _ = loggerConfiguration.ReadFrom.Configuration(Configuration); + + // Enrich configuration from external sources + var configurationServices = serviceProvider.GetService>(); + foreach (var service in configurationServices) + { + service.Configure(loggerConfiguration); + } + // Preserve static logger (i.e. create new logger for DI, instead of reconfiguring existing) + // to avoid exception about frozen logger because BuildServiceProvider is called multiple times + }, preserveStaticLogger: true); + + Log.ForContext().Information("Virto Commerce is loading"); - ConsoleLog.EndOperation(); + var databaseProvider = Configuration.GetValue("DatabaseProvider", "SqlServer"); // Optional Modules Dependecy Resolving services.Add(ServiceDescriptor.Singleton(typeof(IOptionalDependency<>), typeof(OptionalDependencyManager<>))); @@ -301,9 +317,8 @@ public void ConfigureServices(IServiceCollection services) break; } - ConsoleLog.BeginOperation("Getting server certificate"); + Log.ForContext().Information("Getting server certificate"); ServerCertificate = GetServerCertificate(certificateLoader); - ConsoleLog.EndOperation(); //Create backup of token handler before default claim maps are cleared // [Obsolete("Use JsonWebToken", DiagnosticId = "VC0009", UrlFormat = "https://docs.virtocommerce.org/products/products-virto3-versions/")] @@ -671,11 +686,9 @@ public void Configure(IApplicationBuilder app, IWebHostEnvironment env, ILogger< app.UseAutoAccountsLockoutJob(options.Value); // Complete modules startup and apply their migrations - ConsoleLog.BeginOperation("Post initializing modules"); + Log.ForContext().Information("Post initializing modules"); app.UseModules(); - - ConsoleLog.EndOperation(); }); app.UseEndpoints(SetupEndpoints); diff --git a/src/VirtoCommerce.Platform.Web/appsettings.Development.json b/src/VirtoCommerce.Platform.Web/appsettings.Development.json index 1ffb7526b40..6197e674b20 100644 --- a/src/VirtoCommerce.Platform.Web/appsettings.Development.json +++ b/src/VirtoCommerce.Platform.Web/appsettings.Development.json @@ -10,7 +10,9 @@ "System": "Information", "Microsoft": "Information", "Microsoft.AspNetCore.SignalR": "Verbose", - "Microsoft.AspNetCore.Http.Connections": "Verbose" + "Microsoft.AspNetCore.Http.Connections": "Verbose", + "VirtoCommerce.Platform.Modules": "Information", + "VirtoCommerce.Platform.Web.Startup": "Information" } }, "WriteTo": [ diff --git a/src/VirtoCommerce.Platform.Web/appsettings.Production.json b/src/VirtoCommerce.Platform.Web/appsettings.Production.json index 4b39dd1c672..04194a7f802 100644 --- a/src/VirtoCommerce.Platform.Web/appsettings.Production.json +++ b/src/VirtoCommerce.Platform.Web/appsettings.Production.json @@ -9,6 +9,7 @@ "System": "Error", "Microsoft": "Warning", "Microsoft.Hosting.Lifetime": "Information", + "VirtoCommerce.Platform.Modules": "Debug", "VirtoCommerce.Platform.Web.Startup": "Information" } },