From 46e14f769227453bc1ca806ed0dec2bb9157a2db Mon Sep 17 00:00:00 2001 From: Shannon Date: Wed, 22 Apr 2020 14:23:56 +1000 Subject: [PATCH] Fixes up all logging. Configures serilog logging to replace MS logging just like serilog does, adds new ILoggerConfiguration so we aren't hard coding things, dynamically adds enrichers when the container is ready to resolve services. --- .../Logging/ILoggingConfiguration.cs | 13 ++ .../Logging/LoggingConfiguration.cs | 20 ++++ .../Logging/MessageTemplates.cs | 8 +- .../Enrichers/HttpRequestIdEnricher.cs | 13 +- .../Enrichers/HttpRequestNumberEnricher.cs | 13 +- .../Enrichers/HttpSessionIdEnricher.cs | 2 +- .../Logging/Serilog/LoggerConfigExtensions.cs | 46 +++---- .../Logging/Serilog/SerilogLogger.cs | 113 +++--------------- .../Serilog/ThreadAbortExceptionEnricher.cs | 98 +++++++++++++++ .../Logging/Viewer/ILogViewer.cs | 4 +- .../Logging/Viewer/LogViewerComposer.cs | 2 +- ...onLogViewer.cs => SerilogJsonLogViewer.cs} | 21 ++-- ...eBase.cs => SerilogLogViewerSourceBase.cs} | 8 +- src/Umbraco.Tests.Common/TestHelperBase.cs | 9 ++ .../Implementations/TestHostingEnvironment.cs | 1 + src/Umbraco.Tests.Integration/RuntimeTests.cs | 4 +- .../Testing/UmbracoIntegrationTest.cs | 2 +- src/Umbraco.Tests/Logging/LogviewerTests.cs | 8 +- src/Umbraco.Tests/TestHelpers/TestHelper.cs | 2 + src/Umbraco.Tests/Testing/UmbracoTestBase.cs | 2 +- .../UmbracoExamine/ExamineBaseTest.cs | 2 +- .../UmbracoApplicationBuilderExtensions.cs | 11 ++ .../AspNetCoreHostingEnvironment.cs | 4 +- .../Extensions/HostBuilderExtensions.cs | 4 +- .../UmbracoCoreServiceCollectionExtensions.cs | 71 +++++++++-- .../UmbracoRequestLoggingMiddleware.cs | 36 ++++++ .../Middleware/UmbracoRequestMiddleware.cs | 1 - .../Config/serilog.Release.config | 4 +- .../Config/serilog.config | 4 +- src/Umbraco.Web.UI.NetCore/Startup.cs | 2 + .../config/serilog.Release.config | 4 +- src/Umbraco.Web/UmbracoApplicationBase.cs | 18 ++- 32 files changed, 359 insertions(+), 191 deletions(-) create mode 100644 src/Umbraco.Core/Logging/ILoggingConfiguration.cs create mode 100644 src/Umbraco.Core/Logging/LoggingConfiguration.cs create mode 100644 src/Umbraco.Infrastructure/Logging/Serilog/ThreadAbortExceptionEnricher.cs rename src/Umbraco.Infrastructure/Logging/Viewer/{JsonLogViewer.cs => SerilogJsonLogViewer.cs} (79%) rename src/Umbraco.Infrastructure/Logging/Viewer/{LogViewerSourceBase.cs => SerilogLogViewerSourceBase.cs} (93%) create mode 100644 src/Umbraco.Web.Common/Middleware/UmbracoRequestLoggingMiddleware.cs diff --git a/src/Umbraco.Core/Logging/ILoggingConfiguration.cs b/src/Umbraco.Core/Logging/ILoggingConfiguration.cs new file mode 100644 index 0000000000..47e2d8fa7c --- /dev/null +++ b/src/Umbraco.Core/Logging/ILoggingConfiguration.cs @@ -0,0 +1,13 @@ +namespace Umbraco.Core.Logging +{ + + public interface ILoggingConfiguration + { + /// + /// The physical path where logs are stored + /// + string LogDirectory { get; } + string LogConfigurationFile { get; } + string UserLogConfigurationFile { get; } + } +} diff --git a/src/Umbraco.Core/Logging/LoggingConfiguration.cs b/src/Umbraco.Core/Logging/LoggingConfiguration.cs new file mode 100644 index 0000000000..c657c9d430 --- /dev/null +++ b/src/Umbraco.Core/Logging/LoggingConfiguration.cs @@ -0,0 +1,20 @@ +using System; + +namespace Umbraco.Core.Logging +{ + public class LoggingConfiguration : ILoggingConfiguration + { + public LoggingConfiguration(string logDirectory, string logConfigurationFile, string userLogConfigurationFile) + { + LogDirectory = logDirectory ?? throw new ArgumentNullException(nameof(logDirectory)); + LogConfigurationFile = logConfigurationFile ?? throw new ArgumentNullException(nameof(logConfigurationFile)); + UserLogConfigurationFile = userLogConfigurationFile ?? throw new ArgumentNullException(nameof(userLogConfigurationFile)); + } + + public string LogDirectory { get; } + + public string LogConfigurationFile { get; } + + public string UserLogConfigurationFile { get; } + } +} diff --git a/src/Umbraco.Infrastructure/Logging/MessageTemplates.cs b/src/Umbraco.Infrastructure/Logging/MessageTemplates.cs index 4640007e1a..712ff85e16 100644 --- a/src/Umbraco.Infrastructure/Logging/MessageTemplates.cs +++ b/src/Umbraco.Infrastructure/Logging/MessageTemplates.cs @@ -16,14 +16,14 @@ namespace Umbraco.Core.Logging // but it only has a pre-release NuGet package. So, we've got to use Serilog's code, which // means we cannot get rid of Serilog entirely. We may want to revisit this at some point. + // TODO: Do we still need this, is there a non-pre release package shipped? + private static readonly Lazy MinimalLogger = new Lazy(() => new LoggerConfiguration().CreateLogger()); public string Render(string messageTemplate, params object[] args) { - // by default, unless initialized otherwise, Log.Logger is SilentLogger which cannot bind message - // templates. Log.Logger is set to a true Logger when initializing Umbraco's logger, but in case - // that has not been done already - use a temp minimal logger (eg for tests). - var logger = Log.Logger as global::Serilog.Core.Logger ?? MinimalLogger.Value; + // resolve a minimal logger instance which is used to bind message templates + var logger = MinimalLogger.Value; var bound = logger.BindMessageTemplate(messageTemplate, args, out var parsedTemplate, out var boundProperties); diff --git a/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpRequestIdEnricher.cs b/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpRequestIdEnricher.cs index 45468ace9f..704e80d302 100644 --- a/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpRequestIdEnricher.cs +++ b/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpRequestIdEnricher.cs @@ -11,13 +11,13 @@ namespace Umbraco.Core.Logging.Serilog.Enrichers /// Original source - https://github.com/serilog-web/classic/blob/master/src/SerilogWeb.Classic/Classic/Enrichers/HttpRequestIdEnricher.cs /// Nupkg: 'Serilog.Web.Classic' contains handlers & extra bits we do not want /// - internal class HttpRequestIdEnricher : ILogEventEnricher + public class HttpRequestIdEnricher : ILogEventEnricher { - private readonly Func _requestCacheGetter; + private readonly IRequestCache _requestCache; - public HttpRequestIdEnricher(Func requestCacheGetter) + public HttpRequestIdEnricher(IRequestCache requestCache) { - _requestCacheGetter = requestCacheGetter; + _requestCache = requestCache ?? throw new ArgumentNullException(nameof(requestCache)); } /// @@ -34,11 +34,8 @@ namespace Umbraco.Core.Logging.Serilog.Enrichers { if (logEvent == null) throw new ArgumentNullException(nameof(logEvent)); - var requestCache = _requestCacheGetter(); - if(requestCache is null) return; - Guid requestId; - if (!LogHttpRequest.TryGetCurrentHttpRequestId(out requestId, requestCache)) + if (!LogHttpRequest.TryGetCurrentHttpRequestId(out requestId, _requestCache)) return; var requestIdProperty = new LogEventProperty(HttpRequestIdPropertyName, new ScalarValue(requestId)); diff --git a/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpRequestNumberEnricher.cs b/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpRequestNumberEnricher.cs index 08eb6b93f0..20643ff539 100644 --- a/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpRequestNumberEnricher.cs +++ b/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpRequestNumberEnricher.cs @@ -13,9 +13,9 @@ namespace Umbraco.Core.Logging.Serilog.Enrichers /// Original source - https://github.com/serilog-web/classic/blob/master/src/SerilogWeb.Classic/Classic/Enrichers/HttpRequestNumberEnricher.cs /// Nupkg: 'Serilog.Web.Classic' contains handlers & extra bits we do not want /// - internal class HttpRequestNumberEnricher : ILogEventEnricher + public class HttpRequestNumberEnricher : ILogEventEnricher { - private readonly Func _requestCacheGetter; + private readonly IRequestCache _requestCache; private static int _lastRequestNumber; private static readonly string _requestNumberItemName = typeof(HttpRequestNumberEnricher).Name + "+RequestNumber"; @@ -25,9 +25,9 @@ namespace Umbraco.Core.Logging.Serilog.Enrichers private const string _httpRequestNumberPropertyName = "HttpRequestNumber"; - public HttpRequestNumberEnricher(Func requestCacheGetter) + public HttpRequestNumberEnricher(IRequestCache requestCache) { - _requestCacheGetter = requestCacheGetter; + _requestCache = requestCache ?? throw new ArgumentNullException(nameof(requestCache)); } /// @@ -39,10 +39,7 @@ namespace Umbraco.Core.Logging.Serilog.Enrichers { if (logEvent == null) throw new ArgumentNullException(nameof(logEvent)); - var requestCache = _requestCacheGetter(); - if (requestCache is null) return; - - var requestNumber = requestCache.Get(_requestNumberItemName, + var requestNumber = _requestCache.Get(_requestNumberItemName, () => Interlocked.Increment(ref _lastRequestNumber)); var requestNumberProperty = new LogEventProperty(_httpRequestNumberPropertyName, new ScalarValue(requestNumber)); diff --git a/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpSessionIdEnricher.cs b/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpSessionIdEnricher.cs index 1558cdcf21..19572b5b42 100644 --- a/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpSessionIdEnricher.cs +++ b/src/Umbraco.Infrastructure/Logging/Serilog/Enrichers/HttpSessionIdEnricher.cs @@ -10,7 +10,7 @@ namespace Umbraco.Core.Logging.Serilog.Enrichers /// Original source - https://github.com/serilog-web/classic/blob/master/src/SerilogWeb.Classic/Classic/Enrichers/HttpSessionIdEnricher.cs /// Nupkg: 'Serilog.Web.Classic' contains handlers & extra bits we do not want /// - internal class HttpSessionIdEnricher : ILogEventEnricher + public class HttpSessionIdEnricher : ILogEventEnricher { private readonly ISessionIdResolver _sessionIdResolver; diff --git a/src/Umbraco.Infrastructure/Logging/Serilog/LoggerConfigExtensions.cs b/src/Umbraco.Infrastructure/Logging/Serilog/LoggerConfigExtensions.cs index b0521c6da8..dfcc401ea3 100644 --- a/src/Umbraco.Infrastructure/Logging/Serilog/LoggerConfigExtensions.cs +++ b/src/Umbraco.Infrastructure/Logging/Serilog/LoggerConfigExtensions.cs @@ -7,11 +7,8 @@ using Serilog.Core; using Serilog.Events; using Serilog.Formatting; using Serilog.Formatting.Compact; -using Umbraco.Core.Cache; -using Umbraco.Core.Composing; using Umbraco.Core.Hosting; using Umbraco.Core.Logging.Serilog.Enrichers; -using Umbraco.Net; namespace Umbraco.Core.Logging.Serilog { @@ -25,27 +22,30 @@ namespace Umbraco.Core.Logging.Serilog /// It is highly recommended that you keep/use this default in your own logging config customizations /// /// A Serilog LoggerConfiguration - /// - public static LoggerConfiguration MinimalConfiguration(this LoggerConfiguration logConfig, IHostingEnvironment hostingEnvironment, ISessionIdResolver sessionIdResolver, Func requestCacheGetter) + /// + /// + public static LoggerConfiguration MinimalConfiguration( + this LoggerConfiguration logConfig, + IHostingEnvironment hostingEnvironment, + ILoggingConfiguration loggingConfiguration) { global::Serilog.Debugging.SelfLog.Enable(msg => System.Diagnostics.Debug.WriteLine(msg)); //Set this environment variable - so that it can be used in external config file //add key="serilog:write-to:RollingFile.pathFormat" value="%BASEDIR%\logs\log.txt" /> + Environment.SetEnvironmentVariable("UMBLOGDIR", loggingConfiguration.LogDirectory, EnvironmentVariableTarget.Process); Environment.SetEnvironmentVariable("BASEDIR", hostingEnvironment.ApplicationPhysicalPath, EnvironmentVariableTarget.Process); - Environment.SetEnvironmentVariable("MACHINENAME", Environment.MachineName, EnvironmentVariableTarget.Process); + Environment.SetEnvironmentVariable("MACHINENAME", Environment.MachineName, EnvironmentVariableTarget.Process); logConfig.MinimumLevel.Verbose() //Set to highest level of logging (as any sinks may want to restrict it to Errors only) .Enrich.WithProcessId() .Enrich.WithProcessName() .Enrich.WithThreadId() - .Enrich.WithProperty(AppDomainId, AppDomain.CurrentDomain.Id) + .Enrich.WithProperty(AppDomainId, AppDomain.CurrentDomain.Id) .Enrich.WithProperty("AppDomainAppId", hostingEnvironment.ApplicationId.ReplaceNonAlphanumericChars(string.Empty)) .Enrich.WithProperty("MachineName", Environment.MachineName) .Enrich.With() - .Enrich.With(new HttpSessionIdEnricher(sessionIdResolver)) - .Enrich.With(new HttpRequestNumberEnricher(requestCacheGetter)) - .Enrich.With(new HttpRequestIdEnricher(requestCacheGetter)); + .Enrich.FromLogContext(); // allows us to dynamically enrich return logConfig; } @@ -54,13 +54,14 @@ namespace Umbraco.Core.Logging.Serilog /// Outputs a .txt format log at /App_Data/Logs/ /// /// A Serilog LoggerConfiguration + /// /// The log level you wish the JSON file to collect - default is Verbose (highest) /// The number of days to keep log files. Default is set to null which means all logs are kept - public static LoggerConfiguration OutputDefaultTextFile(this LoggerConfiguration logConfig, IHostingEnvironment hostingEnvironment, LogEventLevel minimumLevel = LogEventLevel.Verbose, int? retainedFileCount = null) + public static LoggerConfiguration OutputDefaultTextFile(this LoggerConfiguration logConfig, ILoggingConfiguration loggingConfiguration, LogEventLevel minimumLevel = LogEventLevel.Verbose, int? retainedFileCount = null) { //Main .txt logfile - in similar format to older Log4Net output //Ends with ..txt as Date is inserted before file extension substring - logConfig.WriteTo.File(Path.Combine(hostingEnvironment.ApplicationPhysicalPath, $@"App_Data\Logs\UmbracoTraceLog.{Environment.MachineName}..txt"), + logConfig.WriteTo.File(Path.Combine(loggingConfiguration.LogDirectory, $@"UmbracoTraceLog.{Environment.MachineName}..txt"), shared: true, rollingInterval: RollingInterval.Day, restrictedToMinimumLevel: minimumLevel, @@ -86,8 +87,6 @@ namespace Umbraco.Core.Logging.Serilog Encoding encoding = null ) { - // TODO: Deal with this method call since it's obsolete, we need to change this - return configuration.Async( asyncConfiguration => asyncConfiguration.Map(AppDomainId, (_,mapConfiguration) => mapConfiguration.File( @@ -102,7 +101,8 @@ namespace Umbraco.Core.Logging.Serilog rollingInterval, rollOnFileSizeLimit, retainedFileCountLimit, - encoding), + encoding, + null), sinkMapCountLimit:0) ); } @@ -112,13 +112,14 @@ namespace Umbraco.Core.Logging.Serilog /// Outputs a CLEF format JSON log at /App_Data/Logs/ /// /// A Serilog LoggerConfiguration + /// /// The log level you wish the JSON file to collect - default is Verbose (highest) /// The number of days to keep log files. Default is set to null which means all logs are kept - public static LoggerConfiguration OutputDefaultJsonFile(this LoggerConfiguration logConfig, IHostingEnvironment hostingEnvironment, LogEventLevel minimumLevel = LogEventLevel.Verbose, int? retainedFileCount = null) + public static LoggerConfiguration OutputDefaultJsonFile(this LoggerConfiguration logConfig, ILoggingConfiguration loggingConfiguration, LogEventLevel minimumLevel = LogEventLevel.Verbose, int? retainedFileCount = null) { //.clef format (Compact log event format, that can be imported into local SEQ & will make searching/filtering logs easier) //Ends with ..txt as Date is inserted before file extension substring - logConfig.WriteTo.File(new CompactJsonFormatter(), Path.Combine(hostingEnvironment.ApplicationPhysicalPath, $@"App_Data\Logs\UmbracoTraceLog.{Environment.MachineName}..json"), + logConfig.WriteTo.File(new CompactJsonFormatter(), Path.Combine(loggingConfiguration.LogDirectory, $@"UmbracoTraceLog.{Environment.MachineName}..json"), shared: true, rollingInterval: RollingInterval.Day, //Create a new JSON file every day retainedFileCountLimit: retainedFileCount, //Setting to null means we keep all files - default is 31 days @@ -132,10 +133,11 @@ namespace Umbraco.Core.Logging.Serilog /// That allows the main logging pipeline to be configured /// /// A Serilog LoggerConfiguration - public static LoggerConfiguration ReadFromConfigFile(this LoggerConfiguration logConfig, IHostingEnvironment hostingEnvironment) + /// + public static LoggerConfiguration ReadFromConfigFile(this LoggerConfiguration logConfig, ILoggingConfiguration loggingConfiguration) { //Read from main serilog.config file - logConfig.ReadFrom.AppSettings(filePath: Path.Combine(hostingEnvironment.ApplicationPhysicalPath, @"config\serilog.config")); + logConfig.ReadFrom.AppSettings(filePath: loggingConfiguration.LogConfigurationFile); return logConfig; } @@ -145,13 +147,15 @@ namespace Umbraco.Core.Logging.Serilog /// That allows a separate logging pipeline to be configured that will not affect the main Umbraco log /// /// A Serilog LoggerConfiguration - public static LoggerConfiguration ReadFromUserConfigFile(this LoggerConfiguration logConfig, IHostingEnvironment hostingEnvironment) + /// + public static LoggerConfiguration ReadFromUserConfigFile(this LoggerConfiguration logConfig, ILoggingConfiguration loggingConfiguration) { //A nested logger - where any user configured sinks via config can not effect the main 'umbraco' logger above logConfig.WriteTo.Logger(cfg => - cfg.ReadFrom.AppSettings(filePath: Path.Combine(hostingEnvironment.ApplicationPhysicalPath, @"config\serilog.user.config"))); + cfg.ReadFrom.AppSettings(filePath: loggingConfiguration.UserLogConfigurationFile)); return logConfig; } + } } diff --git a/src/Umbraco.Infrastructure/Logging/Serilog/SerilogLogger.cs b/src/Umbraco.Infrastructure/Logging/Serilog/SerilogLogger.cs index e4695dedd1..38af9554ab 100644 --- a/src/Umbraco.Infrastructure/Logging/Serilog/SerilogLogger.cs +++ b/src/Umbraco.Infrastructure/Logging/Serilog/SerilogLogger.cs @@ -1,72 +1,56 @@ using System; using System.IO; -using System.Reflection; -using System.Threading; using Serilog; using Serilog.Events; -using Umbraco.Core.Cache; -using Umbraco.Core.Configuration; -using Umbraco.Core.Diagnostics; using Umbraco.Core.Hosting; -using Umbraco.Core.IO; -using Umbraco.Net; namespace Umbraco.Core.Logging.Serilog { + /// /// Implements on top of Serilog. /// public class SerilogLogger : ILogger, IDisposable { - private readonly ICoreDebugSettings _coreDebugSettings; - private readonly IHostingEnvironment _hostingEnvironment; - private readonly IMarchal _marchal; + public global::Serilog.ILogger SerilogLog { get; } /// /// Initialize a new instance of the class with a configuration file. /// /// - public SerilogLogger(ICoreDebugSettings coreDebugSettings, IHostingEnvironment hostingEnvironment, IMarchal marchal, FileInfo logConfigFile) + public SerilogLogger(FileInfo logConfigFile) { - _coreDebugSettings = coreDebugSettings; - _hostingEnvironment = hostingEnvironment; - _marchal = marchal; - - Log.Logger = new LoggerConfiguration() + SerilogLog = new LoggerConfiguration() .ReadFrom.AppSettings(filePath: logConfigFile.FullName) .CreateLogger(); } - public SerilogLogger(ICoreDebugSettings coreDebugSettings, IHostingEnvironment hostingEnvironment, IMarchal marchal, LoggerConfiguration logConfig) + public SerilogLogger(LoggerConfiguration logConfig) { - _coreDebugSettings = coreDebugSettings; - _hostingEnvironment = hostingEnvironment; - _marchal = marchal; - //Configure Serilog static global logger with config passed in - Log.Logger = logConfig.CreateLogger(); + SerilogLog = logConfig.CreateLogger(); } /// /// Creates a logger with some pre-defined configuration and remainder from config file /// /// Used by UmbracoApplicationBase to get its logger. - public static SerilogLogger CreateWithDefaultConfiguration(IHostingEnvironment hostingEnvironment, ISessionIdResolver sessionIdResolver, Func requestCacheGetter, ICoreDebugSettings coreDebugSettings, IIOHelper ioHelper, IMarchal marchal) + public static SerilogLogger CreateWithDefaultConfiguration(IHostingEnvironment hostingEnvironment, ILoggingConfiguration loggingConfiguration) { var loggerConfig = new LoggerConfiguration(); loggerConfig - .MinimalConfiguration(hostingEnvironment, sessionIdResolver, requestCacheGetter) - .ReadFromConfigFile(hostingEnvironment) - .ReadFromUserConfigFile(hostingEnvironment); + .MinimalConfiguration(hostingEnvironment, loggingConfiguration) + .ReadFromConfigFile(loggingConfiguration) + .ReadFromUserConfigFile(loggingConfiguration); - return new SerilogLogger(coreDebugSettings, hostingEnvironment, marchal, loggerConfig); + return new SerilogLogger(loggerConfig); } /// /// Gets a contextualized logger. /// private global::Serilog.ILogger LoggerFor(Type reporting) - => Log.Logger.ForContext(reporting); + => SerilogLog.ForContext(reporting); /// /// Maps Umbraco's log level to Serilog's. @@ -99,8 +83,7 @@ namespace Umbraco.Core.Logging.Serilog /// public void Fatal(Type reporting, Exception exception, string message) { - var logger = LoggerFor(reporting); - DumpThreadAborts(logger, LogEventLevel.Fatal, exception, ref message); + var logger = LoggerFor(reporting); logger.Fatal(exception, message); } @@ -108,8 +91,7 @@ namespace Umbraco.Core.Logging.Serilog public void Fatal(Type reporting, Exception exception) { var logger = LoggerFor(reporting); - var message = "Exception."; - DumpThreadAborts(logger, LogEventLevel.Fatal, exception, ref message); + var message = "Exception."; logger.Fatal(exception, message); } @@ -128,16 +110,14 @@ namespace Umbraco.Core.Logging.Serilog /// public void Fatal(Type reporting, Exception exception, string messageTemplate, params object[] propertyValues) { - var logger = LoggerFor(reporting); - DumpThreadAborts(logger, LogEventLevel.Fatal, exception, ref messageTemplate); + var logger = LoggerFor(reporting); logger.Fatal(exception, messageTemplate, propertyValues); } /// public void Error(Type reporting, Exception exception, string message) { - var logger = LoggerFor(reporting); - DumpThreadAborts(logger, LogEventLevel.Error, exception, ref message); + var logger = LoggerFor(reporting); logger.Error(exception, message); } @@ -146,7 +126,6 @@ namespace Umbraco.Core.Logging.Serilog { var logger = LoggerFor(reporting); var message = "Exception"; - DumpThreadAborts(logger, LogEventLevel.Error, exception, ref message); logger.Error(exception, message); } @@ -166,67 +145,9 @@ namespace Umbraco.Core.Logging.Serilog public void Error(Type reporting, Exception exception, string messageTemplate, params object[] propertyValues) { var logger = LoggerFor(reporting); - DumpThreadAborts(logger, LogEventLevel.Error, exception, ref messageTemplate); logger.Error(exception, messageTemplate, propertyValues); } - private void DumpThreadAborts(global::Serilog.ILogger logger, LogEventLevel level, Exception exception, ref string messageTemplate) - { - var dump = false; - - if (IsTimeoutThreadAbortException(exception)) - { - messageTemplate += "\r\nThe thread has been aborted, because the request has timed out."; - - // dump if configured, or if stacktrace contains Monitor.ReliableEnter - dump = _coreDebugSettings.DumpOnTimeoutThreadAbort || IsMonitorEnterThreadAbortException(exception); - - // dump if it is ok to dump (might have a cap on number of dump...) - dump &= MiniDump.OkToDump(_hostingEnvironment); - } - - if (dump) - { - try - { - var dumped = MiniDump.Dump(_marchal, _hostingEnvironment, withException: true); - messageTemplate += dumped - ? "\r\nA minidump was created in App_Data/MiniDump" - : "\r\nFailed to create a minidump"; - } - catch (Exception ex) - { - messageTemplate += "\r\nFailed to create a minidump"; - - //Log a new entry (as opposed to appending to same log entry) - logger.Write(level, ex, "Failed to create a minidump ({ExType}: {ExMessage})", - new object[]{ ex.GetType().FullName, ex.Message }); - } - } - } - - private static bool IsMonitorEnterThreadAbortException(Exception exception) - { - if (!(exception is ThreadAbortException abort)) return false; - - var stacktrace = abort.StackTrace; - return stacktrace.Contains("System.Threading.Monitor.ReliableEnter"); - } - - private static bool IsTimeoutThreadAbortException(Exception exception) - { - if (!(exception is ThreadAbortException abort)) return false; - if (abort.ExceptionState == null) return false; - - var stateType = abort.ExceptionState.GetType(); - if (stateType.FullName != "System.Web.HttpApplication+CancelModuleException") return false; - - var timeoutField = stateType.GetField("_timeout", BindingFlags.Instance | BindingFlags.NonPublic); - if (timeoutField == null) return false; - - return (bool) timeoutField.GetValue(abort.ExceptionState); - } - /// public void Warn(Type reporting, string message) { @@ -289,7 +210,7 @@ namespace Umbraco.Core.Logging.Serilog public void Dispose() { - Log.CloseAndFlush(); + SerilogLog.DisposeIfDisposable(); } } } diff --git a/src/Umbraco.Infrastructure/Logging/Serilog/ThreadAbortExceptionEnricher.cs b/src/Umbraco.Infrastructure/Logging/Serilog/ThreadAbortExceptionEnricher.cs new file mode 100644 index 0000000000..2a7d35b636 --- /dev/null +++ b/src/Umbraco.Infrastructure/Logging/Serilog/ThreadAbortExceptionEnricher.cs @@ -0,0 +1,98 @@ +using System; +using System.Reflection; +using System.Threading; +using Serilog.Core; +using Serilog.Events; +using Umbraco.Core.Configuration; +using Umbraco.Core.Diagnostics; +using Umbraco.Core.Hosting; + +namespace Umbraco.Core.Logging.Serilog +{ + /// + /// Enriches the log if there are ThreadAbort exceptions and will automatically create a minidump if it can + /// + public class ThreadAbortExceptionEnricher : ILogEventEnricher + { + private readonly ICoreDebugSettings _coreDebugSettings; + private readonly IHostingEnvironment _hostingEnvironment; + private readonly IMarchal _marchal; + + public ThreadAbortExceptionEnricher(ICoreDebugSettings coreDebugSettings, IHostingEnvironment hostingEnvironment, IMarchal marchal) + { + _coreDebugSettings = coreDebugSettings; + _hostingEnvironment = hostingEnvironment; + _marchal = marchal; + } + + public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) + { + switch (logEvent.Level) + { + case LogEventLevel.Error: + case LogEventLevel.Fatal: + DumpThreadAborts(logEvent, propertyFactory); + break; + } + } + + private void DumpThreadAborts(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) + { + if (!IsTimeoutThreadAbortException(logEvent.Exception)) return; + + var message = "The thread has been aborted, because the request has timed out."; + + // dump if configured, or if stacktrace contains Monitor.ReliableEnter + var dump = _coreDebugSettings.DumpOnTimeoutThreadAbort || IsMonitorEnterThreadAbortException(logEvent.Exception); + + // dump if it is ok to dump (might have a cap on number of dump...) + dump &= MiniDump.OkToDump(_hostingEnvironment); + + if (!dump) + { + message += ". No minidump was created."; + logEvent.AddPropertyIfAbsent(propertyFactory.CreateProperty("ThreadAbortExceptionInfo", message)); + } + else + { + try + { + var dumped = MiniDump.Dump(_marchal, _hostingEnvironment, withException: true); + message += dumped + ? ". A minidump was created in App_Data/MiniDump." + : ". Failed to create a minidump."; + logEvent.AddPropertyIfAbsent(propertyFactory.CreateProperty("ThreadAbortExceptionInfo", message)); + } + catch (Exception ex) + { + message = "Failed to create a minidump. " + ex; + logEvent.AddPropertyIfAbsent(propertyFactory.CreateProperty("ThreadAbortExceptionInfo", message)); + } + } + } + + private static bool IsTimeoutThreadAbortException(Exception exception) + { + if (!(exception is ThreadAbortException abort)) return false; + if (abort.ExceptionState == null) return false; + + var stateType = abort.ExceptionState.GetType(); + if (stateType.FullName != "System.Web.HttpApplication+CancelModuleException") return false; + + var timeoutField = stateType.GetField("_timeout", BindingFlags.Instance | BindingFlags.NonPublic); + if (timeoutField == null) return false; + + return (bool)timeoutField.GetValue(abort.ExceptionState); + } + + private static bool IsMonitorEnterThreadAbortException(Exception exception) + { + if (!(exception is ThreadAbortException abort)) return false; + + var stacktrace = abort.StackTrace; + return stacktrace.Contains("System.Threading.Monitor.ReliableEnter"); + } + + + } +} diff --git a/src/Umbraco.Infrastructure/Logging/Viewer/ILogViewer.cs b/src/Umbraco.Infrastructure/Logging/Viewer/ILogViewer.cs index dbdd7842ba..6763b0ebbb 100644 --- a/src/Umbraco.Infrastructure/Logging/Viewer/ILogViewer.cs +++ b/src/Umbraco.Infrastructure/Logging/Viewer/ILogViewer.cs @@ -1,7 +1,5 @@ -using System; -using System.Collections.Generic; +using System.Collections.Generic; using Umbraco.Core.Models; -using Umbraco.Core.Persistence.DatabaseModelDefinitions; namespace Umbraco.Core.Logging.Viewer { diff --git a/src/Umbraco.Infrastructure/Logging/Viewer/LogViewerComposer.cs b/src/Umbraco.Infrastructure/Logging/Viewer/LogViewerComposer.cs index e4acde1265..ee115be325 100644 --- a/src/Umbraco.Infrastructure/Logging/Viewer/LogViewerComposer.cs +++ b/src/Umbraco.Infrastructure/Logging/Viewer/LogViewerComposer.cs @@ -10,7 +10,7 @@ namespace Umbraco.Core.Logging.Viewer public void Compose(Composition composition) { composition.RegisterUnique(); - composition.SetLogViewer(); + composition.SetLogViewer(); } } } diff --git a/src/Umbraco.Infrastructure/Logging/Viewer/JsonLogViewer.cs b/src/Umbraco.Infrastructure/Logging/Viewer/SerilogJsonLogViewer.cs similarity index 79% rename from src/Umbraco.Infrastructure/Logging/Viewer/JsonLogViewer.cs rename to src/Umbraco.Infrastructure/Logging/Viewer/SerilogJsonLogViewer.cs index 54dd58ec03..366a0fb9de 100644 --- a/src/Umbraco.Infrastructure/Logging/Viewer/JsonLogViewer.cs +++ b/src/Umbraco.Infrastructure/Logging/Viewer/SerilogJsonLogViewer.cs @@ -10,23 +10,20 @@ using Umbraco.Core.IO; namespace Umbraco.Core.Logging.Viewer { - internal class JsonLogViewer : LogViewerSourceBase + internal class SerilogJsonLogViewer : SerilogLogViewerSourceBase { private readonly string _logsPath; private readonly ILogger _logger; - private readonly IHostingEnvironment _hostingEnvironment; - public JsonLogViewer(ILogger logger, ILogViewerConfig logViewerConfig, IHostingEnvironment hostingEnvironment) : base(logViewerConfig) + public SerilogJsonLogViewer( + ILogger logger, + ILogViewerConfig logViewerConfig, + ILoggingConfiguration loggingConfiguration, + global::Serilog.ILogger serilogLog) + : base(logViewerConfig, serilogLog) { - _hostingEnvironment = hostingEnvironment; _logger = logger; - - // TODO: this path is hard coded but it can actually be configured, but that is done via Serilog and we don't have a different abstraction/config - // for the logging path. We could make that, but then how would we get that abstraction into the Serilog config? I'm sure there is a way but - // don't have time right now to resolve that (since this was hard coded before). We could have a single/simple ILogConfig for umbraco that purely specifies - // the logging path and then we can have a special token that we replace in the serilog config that maps to that location? then at least we could inject - // that config in places where we are hard coding this path. - _logsPath = Path.Combine(_hostingEnvironment.ApplicationPhysicalPath, @"App_Data\Logs\"); + _logsPath = loggingConfiguration.LogDirectory; } private const int FileSizeCap = 100; @@ -133,7 +130,7 @@ namespace Umbraco.Core.Logging.Viewer { // As we are reading/streaming one line at a time in the JSON file // Thus we can not report the line number, as it will always be 1 - _logger.Error(ex, "Unable to parse a line in the JSON log file"); + _logger.Error(ex, "Unable to parse a line in the JSON log file"); evt = null; return true; diff --git a/src/Umbraco.Infrastructure/Logging/Viewer/LogViewerSourceBase.cs b/src/Umbraco.Infrastructure/Logging/Viewer/SerilogLogViewerSourceBase.cs similarity index 93% rename from src/Umbraco.Infrastructure/Logging/Viewer/LogViewerSourceBase.cs rename to src/Umbraco.Infrastructure/Logging/Viewer/SerilogLogViewerSourceBase.cs index aae2976044..7c8503a37e 100644 --- a/src/Umbraco.Infrastructure/Logging/Viewer/LogViewerSourceBase.cs +++ b/src/Umbraco.Infrastructure/Logging/Viewer/SerilogLogViewerSourceBase.cs @@ -8,13 +8,15 @@ using Umbraco.Core.Models; namespace Umbraco.Core.Logging.Viewer { - public abstract class LogViewerSourceBase : ILogViewer + public abstract class SerilogLogViewerSourceBase : ILogViewer { private readonly ILogViewerConfig _logViewerConfig; + private readonly global::Serilog.ILogger _serilogLog; - protected LogViewerSourceBase(ILogViewerConfig logViewerConfig) + protected SerilogLogViewerSourceBase(ILogViewerConfig logViewerConfig, global::Serilog.ILogger serilogLog) { _logViewerConfig = logViewerConfig; + _serilogLog = serilogLog; } public abstract bool CanHandleLargeLogs { get; } @@ -48,7 +50,7 @@ namespace Umbraco.Core.Logging.Viewer /// public string GetLogLevel() { - var logLevel = Enum.GetValues(typeof(LogEventLevel)).Cast().Where(Log.Logger.IsEnabled)?.Min() ?? null; + var logLevel = Enum.GetValues(typeof(LogEventLevel)).Cast().Where(_serilogLog.IsEnabled)?.Min() ?? null; return logLevel?.ToString() ?? ""; } diff --git a/src/Umbraco.Tests.Common/TestHelperBase.cs b/src/Umbraco.Tests.Common/TestHelperBase.cs index 42b1e6c0dd..21b1f66395 100644 --- a/src/Umbraco.Tests.Common/TestHelperBase.cs +++ b/src/Umbraco.Tests.Common/TestHelperBase.cs @@ -152,5 +152,14 @@ namespace Umbraco.Tests.Common return mock.Object; } + + public ILoggingConfiguration GetLoggingConfiguration(IHostingEnvironment hostingEnv = null) + { + hostingEnv = hostingEnv ?? GetHostingEnvironment(); + return new LoggingConfiguration( + Path.Combine(hostingEnv.ApplicationPhysicalPath, "App_Data\\Logs"), + Path.Combine(hostingEnv.ApplicationPhysicalPath, "config\\serilog.config"), + Path.Combine(hostingEnv.ApplicationPhysicalPath, "config\\serilog.user.config")); + } } } diff --git a/src/Umbraco.Tests.Integration/Implementations/TestHostingEnvironment.cs b/src/Umbraco.Tests.Integration/Implementations/TestHostingEnvironment.cs index 6430291bc2..9f29b14858 100644 --- a/src/Umbraco.Tests.Integration/Implementations/TestHostingEnvironment.cs +++ b/src/Umbraco.Tests.Integration/Implementations/TestHostingEnvironment.cs @@ -1,6 +1,7 @@ using Microsoft.AspNetCore.Hosting; using Microsoft.AspNetCore.Http; using Umbraco.Core.Configuration; +using Umbraco.Core.Logging; using Umbraco.Web.Common.AspNetCore; namespace Umbraco.Tests.Integration.Implementations diff --git a/src/Umbraco.Tests.Integration/RuntimeTests.cs b/src/Umbraco.Tests.Integration/RuntimeTests.cs index 52c29d2037..9bc8d31ded 100644 --- a/src/Umbraco.Tests.Integration/RuntimeTests.cs +++ b/src/Umbraco.Tests.Integration/RuntimeTests.cs @@ -99,7 +99,7 @@ namespace Umbraco.Tests.Integration // Add it! services.AddUmbracoConfiguration(hostContext.Configuration); - services.AddUmbracoCore(webHostEnvironment, umbracoContainer, GetType().Assembly, out _); + services.AddUmbracoCore(webHostEnvironment, umbracoContainer, GetType().Assembly, testHelper.GetLoggingConfiguration(), out _); }); var host = await hostBuilder.StartAsync(); @@ -138,7 +138,7 @@ namespace Umbraco.Tests.Integration // Add it! services.AddUmbracoConfiguration(hostContext.Configuration); - services.AddUmbracoCore(webHostEnvironment, umbracoContainer, GetType().Assembly, out _); + services.AddUmbracoCore(webHostEnvironment, umbracoContainer, GetType().Assembly, testHelper.GetLoggingConfiguration(), out _); }); var host = await hostBuilder.StartAsync(); diff --git a/src/Umbraco.Tests.Integration/Testing/UmbracoIntegrationTest.cs b/src/Umbraco.Tests.Integration/Testing/UmbracoIntegrationTest.cs index 101feb79a4..f3a2bcf011 100644 --- a/src/Umbraco.Tests.Integration/Testing/UmbracoIntegrationTest.cs +++ b/src/Umbraco.Tests.Integration/Testing/UmbracoIntegrationTest.cs @@ -108,7 +108,7 @@ namespace Umbraco.Tests.Integration.Testing // Add it! services.AddUmbracoConfiguration(hostContext.Configuration); - services.AddUmbracoCore(webHostEnvironment, umbracoContainer, GetType().Assembly, out _); + services.AddUmbracoCore(webHostEnvironment, umbracoContainer, GetType().Assembly, testHelper.GetLoggingConfiguration(), out _); }); var host = await hostBuilder.StartAsync(); diff --git a/src/Umbraco.Tests/Logging/LogviewerTests.cs b/src/Umbraco.Tests/Logging/LogviewerTests.cs index 75ff81a6d5..0a193b4446 100644 --- a/src/Umbraco.Tests/Logging/LogviewerTests.cs +++ b/src/Umbraco.Tests/Logging/LogviewerTests.cs @@ -1,9 +1,11 @@ using Moq; using NUnit.Framework; +using Serilog; using System; using System.IO; using System.Linq; using Umbraco.Core; +using Umbraco.Core.Logging; using Umbraco.Core.Logging.Viewer; using Umbraco.Tests.TestHelpers; @@ -35,8 +37,10 @@ namespace Umbraco.Tests.Logging var ioHelper = TestHelper.IOHelper; var hostingEnv = TestHelper.GetHostingEnvironment(); + var loggingConfiguration = TestHelper.GetLoggingConfiguration(hostingEnv); + var exampleLogfilePath = Path.Combine(TestContext.CurrentContext.TestDirectory, @"Logging\", _logfileName); - _newLogfileDirPath = Path.Combine(hostingEnv.ApplicationPhysicalPath, @"App_Data\Logs\"); + _newLogfileDirPath = loggingConfiguration.LogDirectory; _newLogfilePath = Path.Combine(_newLogfileDirPath, _logfileName); var exampleSearchfilePath = Path.Combine(TestContext.CurrentContext.TestDirectory, @"Logging\", _searchfileName); @@ -53,7 +57,7 @@ namespace Umbraco.Tests.Logging var logger = Mock.Of(); var logViewerConfig = new LogViewerConfig(hostingEnv); - _logViewer = new JsonLogViewer(logger, logViewerConfig, hostingEnv); + _logViewer = new SerilogJsonLogViewer(logger, logViewerConfig, loggingConfiguration, Log.Logger); } [OneTimeTearDown] diff --git a/src/Umbraco.Tests/TestHelpers/TestHelper.cs b/src/Umbraco.Tests/TestHelpers/TestHelper.cs index 7eca49183d..6fcba1ba1a 100644 --- a/src/Umbraco.Tests/TestHelpers/TestHelper.cs +++ b/src/Umbraco.Tests/TestHelpers/TestHelper.cs @@ -324,6 +324,8 @@ namespace Umbraco.Tests.TestHelpers public static IHostingEnvironment GetHostingEnvironment() => _testHelperInternal.GetHostingEnvironment(); + public static ILoggingConfiguration GetLoggingConfiguration(IHostingEnvironment hostingEnv) => _testHelperInternal.GetLoggingConfiguration(hostingEnv); + public static IApplicationShutdownRegistry GetHostingEnvironmentLifetime() => _testHelperInternal.GetHostingEnvironmentLifetime(); public static IIpResolver GetIpResolver() => _testHelperInternal.GetIpResolver(); diff --git a/src/Umbraco.Tests/Testing/UmbracoTestBase.cs b/src/Umbraco.Tests/Testing/UmbracoTestBase.cs index f62a69177a..80f6ab9c9e 100644 --- a/src/Umbraco.Tests/Testing/UmbracoTestBase.cs +++ b/src/Umbraco.Tests/Testing/UmbracoTestBase.cs @@ -264,7 +264,7 @@ namespace Umbraco.Tests.Testing profiler = Mock.Of(); break; case UmbracoTestOptions.Logger.Serilog: - logger = new SerilogLogger(TestHelper.CoreDebugSettings, HostingEnvironment, TestHelper.Marchal, new FileInfo(TestHelper.MapPathForTestFiles("~/unit-test.config"))); + logger = new SerilogLogger(new FileInfo(TestHelper.MapPathForTestFiles("~/unit-test.config"))); profiler = new LogProfiler(logger); break; case UmbracoTestOptions.Logger.Console: diff --git a/src/Umbraco.Tests/UmbracoExamine/ExamineBaseTest.cs b/src/Umbraco.Tests/UmbracoExamine/ExamineBaseTest.cs index 76b989a7a3..0d55fd99d7 100644 --- a/src/Umbraco.Tests/UmbracoExamine/ExamineBaseTest.cs +++ b/src/Umbraco.Tests/UmbracoExamine/ExamineBaseTest.cs @@ -18,7 +18,7 @@ namespace Umbraco.Tests.UmbracoExamine public void InitializeFixture() { - var logger = new SerilogLogger(TestHelper.CoreDebugSettings, HostingEnvironment, TestHelper.Marchal, new FileInfo(TestHelper.MapPathForTestFiles("~/unit-test.config"))); + var logger = new SerilogLogger(new FileInfo(TestHelper.MapPathForTestFiles("~/unit-test.config"))); _profilingLogger = new ProfilingLogger(logger, new LogProfiler(logger)); } diff --git a/src/Umbraco.Web.BackOffice/AspNetCore/UmbracoApplicationBuilderExtensions.cs b/src/Umbraco.Web.BackOffice/AspNetCore/UmbracoApplicationBuilderExtensions.cs index ddf06e6532..88b9b4ca9e 100644 --- a/src/Umbraco.Web.BackOffice/AspNetCore/UmbracoApplicationBuilderExtensions.cs +++ b/src/Umbraco.Web.BackOffice/AspNetCore/UmbracoApplicationBuilderExtensions.cs @@ -1,9 +1,11 @@ using System; using Microsoft.AspNetCore.Builder; using Microsoft.Extensions.DependencyInjection; +using Serilog.Context; using Smidge; using Umbraco.Core; using Umbraco.Core.Hosting; +using Umbraco.Web.Common.Middleware; namespace Umbraco.Web.BackOffice.AspNetCore { @@ -64,6 +66,15 @@ namespace Umbraco.Web.BackOffice.AspNetCore } } + public static IApplicationBuilder UseUmbracoRequestLogging(this IApplicationBuilder app) + { + if (app == null) throw new ArgumentNullException(nameof(app)); + + app.UseMiddleware(); + + return app; + } + public static IApplicationBuilder UseUmbracoRuntimeMinification(this IApplicationBuilder app) { if (app == null) throw new ArgumentNullException(nameof(app)); diff --git a/src/Umbraco.Web.Common/AspNetCore/AspNetCoreHostingEnvironment.cs b/src/Umbraco.Web.Common/AspNetCore/AspNetCoreHostingEnvironment.cs index decfcfa660..b3ec11c241 100644 --- a/src/Umbraco.Web.Common/AspNetCore/AspNetCoreHostingEnvironment.cs +++ b/src/Umbraco.Web.Common/AspNetCore/AspNetCoreHostingEnvironment.cs @@ -5,13 +5,12 @@ using Microsoft.AspNetCore.Hosting; using Microsoft.AspNetCore.Http; using Umbraco.Core; using Umbraco.Core.Configuration; +using Umbraco.Core.Logging; namespace Umbraco.Web.Common.AspNetCore { public class AspNetCoreHostingEnvironment : Umbraco.Core.Hosting.IHostingEnvironment { - - private readonly IHostingSettings _hostingSettings; private readonly IWebHostEnvironment _webHostEnvironment; @@ -28,6 +27,7 @@ namespace Umbraco.Web.Common.AspNetCore ApplicationVirtualPath = "/"; //TODO how to find this, This is a server thing, not application thing. IISVersion = new Version(0, 0); // TODO not necessary IIS + } public bool IsHosted { get; } = true; diff --git a/src/Umbraco.Web.Common/Extensions/HostBuilderExtensions.cs b/src/Umbraco.Web.Common/Extensions/HostBuilderExtensions.cs index 3cb0922837..d314a2ae30 100644 --- a/src/Umbraco.Web.Common/Extensions/HostBuilderExtensions.cs +++ b/src/Umbraco.Web.Common/Extensions/HostBuilderExtensions.cs @@ -1,5 +1,4 @@ using Microsoft.Extensions.Hosting; -using Serilog; using Umbraco.Core.Composing; namespace Umbraco.Web.Common.Extensions @@ -13,8 +12,7 @@ namespace Umbraco.Web.Common.Extensions /// public static IHostBuilder UseUmbraco(this IHostBuilder builder) { - return builder - .UseSerilog() + return builder .UseUmbraco(new UmbracoServiceProviderFactory()); } } diff --git a/src/Umbraco.Web.Common/Extensions/UmbracoCoreServiceCollectionExtensions.cs b/src/Umbraco.Web.Common/Extensions/UmbracoCoreServiceCollectionExtensions.cs index 843620d571..80482852f3 100644 --- a/src/Umbraco.Web.Common/Extensions/UmbracoCoreServiceCollectionExtensions.cs +++ b/src/Umbraco.Web.Common/Extensions/UmbracoCoreServiceCollectionExtensions.cs @@ -6,6 +6,10 @@ using Microsoft.AspNetCore.Hosting; using Microsoft.AspNetCore.Http; using Microsoft.Extensions.Configuration; using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; +using Serilog; +using Serilog.Extensions.Hosting; +using Serilog.Extensions.Logging; using Smidge; using Smidge.Nuglify; using Umbraco.Composing; @@ -71,7 +75,12 @@ namespace Umbraco.Web.Common.Extensions var umbContainer = UmbracoServiceProviderFactory.UmbracoContainer; - services.AddUmbracoCore(webHostEnvironment, umbContainer, Assembly.GetEntryAssembly(), out factory); + var loggingConfig = new LoggingConfiguration( + Path.Combine(webHostEnvironment.ContentRootPath, "App_Data\\Logs"), + Path.Combine(webHostEnvironment.ContentRootPath, "config\\serilog.config"), + Path.Combine(webHostEnvironment.ContentRootPath, "config\\serilog.user.config")); + + services.AddUmbracoCore(webHostEnvironment, umbContainer, Assembly.GetEntryAssembly(), loggingConfig, out factory); return services; } @@ -83,9 +92,16 @@ namespace Umbraco.Web.Common.Extensions /// /// /// + /// /// /// - public static IServiceCollection AddUmbracoCore(this IServiceCollection services, IWebHostEnvironment webHostEnvironment, IRegister umbContainer, Assembly entryAssembly, out IFactory factory) + public static IServiceCollection AddUmbracoCore( + this IServiceCollection services, + IWebHostEnvironment webHostEnvironment, + IRegister umbContainer, + Assembly entryAssembly, + ILoggingConfiguration loggingConfiguration, + out IFactory factory) { if (services is null) throw new ArgumentNullException(nameof(services)); var container = umbContainer; @@ -96,7 +112,7 @@ namespace Umbraco.Web.Common.Extensions // we resolve it before the host finishes configuring in the call to CreateCompositionRoot services.AddSingleton(); - CreateCompositionRoot(services, webHostEnvironment, out var logger, out var configs, out var ioHelper, out var hostingEnvironment, out var backOfficeInfo, out var profiler); + CreateCompositionRoot(services, webHostEnvironment, loggingConfiguration, out var logger, out var configs, out var ioHelper, out var hostingEnvironment, out var backOfficeInfo, out var profiler); var globalSettings = configs.Global(); var umbracoVersion = new UmbracoVersion(globalSettings); @@ -116,7 +132,7 @@ namespace Umbraco.Web.Common.Extensions return services; } - private static ITypeFinder CreateTypeFinder(ILogger logger, IProfiler profiler, IWebHostEnvironment webHostEnvironment, Assembly entryAssembly) + private static ITypeFinder CreateTypeFinder(Core.Logging.ILogger logger, IProfiler profiler, IWebHostEnvironment webHostEnvironment, Assembly entryAssembly) { // TODO: Currently we are not passing in any TypeFinderConfig (with ITypeFinderSettings) which we should do, however // this is not critical right now and would require loading in some config before boot time so just leaving this as-is for now. @@ -126,7 +142,7 @@ namespace Umbraco.Web.Common.Extensions return new TypeFinder(logger, new DefaultUmbracoAssemblyProvider(entryAssembly), runtimeHash); } - private static IRuntime GetCoreRuntime(Configs configs, IUmbracoVersion umbracoVersion, IIOHelper ioHelper, ILogger logger, + private static IRuntime GetCoreRuntime(Configs configs, IUmbracoVersion umbracoVersion, IIOHelper ioHelper, Core.Logging.ILogger logger, IProfiler profiler, Core.Hosting.IHostingEnvironment hostingEnvironment, IBackOfficeInfo backOfficeInfo, ITypeFinder typeFinder) { @@ -151,8 +167,11 @@ namespace Umbraco.Web.Common.Extensions return coreRuntime; } - private static IServiceCollection CreateCompositionRoot(IServiceCollection services, IWebHostEnvironment webHostEnvironment, - out ILogger logger, out Configs configs, out IIOHelper ioHelper, out Core.Hosting.IHostingEnvironment hostingEnvironment, + private static IServiceCollection CreateCompositionRoot( + IServiceCollection services, + IWebHostEnvironment webHostEnvironment, + ILoggingConfiguration loggingConfiguration, + out Core.Logging.ILogger logger, out Configs configs, out IIOHelper ioHelper, out Core.Hosting.IHostingEnvironment hostingEnvironment, out IBackOfficeInfo backOfficeInfo, out IProfiler profiler) { // TODO: We need to avoid this, surely there's a way? See ContainerTests.BuildServiceProvider_Before_Host_Is_Configured @@ -170,11 +189,7 @@ namespace Umbraco.Web.Common.Extensions hostingEnvironment = new AspNetCoreHostingEnvironment(hostingSettings, webHostEnvironment); ioHelper = new IOHelper(hostingEnvironment, globalSettings); - logger = SerilogLogger.CreateWithDefaultConfiguration(hostingEnvironment, - new AspNetCoreSessionManager(httpContextAccessor), - // TODO: We need to avoid this, surely there's a way? See ContainerTests.BuildServiceProvider_Before_Host_Is_Configured - () => services.BuildServiceProvider().GetService(), coreDebug, ioHelper, - new AspNetCoreMarchal()); + logger = AddLogger(services, hostingEnvironment, loggingConfiguration); backOfficeInfo = new AspNetCoreBackOfficeInfo(globalSettings); profiler = GetWebProfiler(hostingEnvironment, httpContextAccessor); @@ -182,6 +197,38 @@ namespace Umbraco.Web.Common.Extensions return services; } + /// + /// Create and configure the logger + /// + /// + private static Core.Logging.ILogger AddLogger(IServiceCollection services, Core.Hosting.IHostingEnvironment hostingEnvironment, ILoggingConfiguration loggingConfiguration) + { + // Create a serilog logger + var logger = SerilogLogger.CreateWithDefaultConfiguration(hostingEnvironment, loggingConfiguration); + + // Wire up all the bits that serilog needs. We need to use our own code since the Serilog ext methods don't cater to our needs since + // we don't want to use the global serilog `Log` object and we don't have our own ILogger implementation before the HostBuilder runs which + // is the only other option that these ext methods allow. + // I have created a PR to make this nicer https://github.com/serilog/serilog-extensions-hosting/pull/19 but we'll need to wait for that. + // Also see : https://github.com/serilog/serilog-extensions-hosting/blob/dev/src/Serilog.Extensions.Hosting/SerilogHostBuilderExtensions.cs + + services.AddSingleton(services => new SerilogLoggerFactory(logger.SerilogLog, false)); + + // This won't (and shouldn't) take ownership of the logger. + services.AddSingleton(logger.SerilogLog); + + // Registered to provide two services... + var diagnosticContext = new DiagnosticContext(logger.SerilogLog); + + // Consumed by e.g. middleware + services.AddSingleton(diagnosticContext); + + // Consumed by user code + services.AddSingleton(diagnosticContext); + + return logger; + } + public static IServiceCollection AddUmbracoRuntimeMinifier(this IServiceCollection services, IConfiguration configuration) { diff --git a/src/Umbraco.Web.Common/Middleware/UmbracoRequestLoggingMiddleware.cs b/src/Umbraco.Web.Common/Middleware/UmbracoRequestLoggingMiddleware.cs new file mode 100644 index 0000000000..f2034dbd82 --- /dev/null +++ b/src/Umbraco.Web.Common/Middleware/UmbracoRequestLoggingMiddleware.cs @@ -0,0 +1,36 @@ +using System.Threading.Tasks; +using Microsoft.AspNetCore.Http; +using Serilog.Context; +using Umbraco.Core.Cache; +using Umbraco.Core.Logging.Serilog.Enrichers; +using Umbraco.Net; + +namespace Umbraco.Web.Common.Middleware +{ + public class UmbracoRequestLoggingMiddleware + { + readonly RequestDelegate _next; + private readonly ISessionIdResolver _sessionIdResolver; + private readonly IRequestCache _requestCache; + + public UmbracoRequestLoggingMiddleware(RequestDelegate next, ISessionIdResolver sessionIdResolver, IRequestCache requestCache) + { + _next = next; + _sessionIdResolver = sessionIdResolver; + _requestCache = requestCache; + } + + public async Task Invoke(HttpContext httpContext) + { + // TODO: Need to decide if we want this stuff still, there's new request logging in serilog: + // https://github.com/serilog/serilog-aspnetcore#request-logging which i think would suffice and replace all of this? + + using (LogContext.Push(new HttpSessionIdEnricher(_sessionIdResolver))) + using (LogContext.Push(new HttpRequestNumberEnricher(_requestCache))) + using (LogContext.Push(new HttpRequestIdEnricher(_requestCache))) + { + await _next(httpContext); + } + } + } +} diff --git a/src/Umbraco.Web.Common/Middleware/UmbracoRequestMiddleware.cs b/src/Umbraco.Web.Common/Middleware/UmbracoRequestMiddleware.cs index 93461fc1d5..e8695f3c9c 100644 --- a/src/Umbraco.Web.Common/Middleware/UmbracoRequestMiddleware.cs +++ b/src/Umbraco.Web.Common/Middleware/UmbracoRequestMiddleware.cs @@ -22,5 +22,4 @@ namespace Umbraco.Web.Common.Middleware _umbracoRequestLifetimeManager.EndRequest(context); } } - } diff --git a/src/Umbraco.Web.UI.NetCore/Config/serilog.Release.config b/src/Umbraco.Web.UI.NetCore/Config/serilog.Release.config index e3cf52b3c5..9aca408b36 100644 --- a/src/Umbraco.Web.UI.NetCore/Config/serilog.Release.config +++ b/src/Umbraco.Web.UI.NetCore/Config/serilog.Release.config @@ -19,7 +19,7 @@ - + @@ -27,7 +27,7 @@ - + diff --git a/src/Umbraco.Web.UI.NetCore/Config/serilog.config b/src/Umbraco.Web.UI.NetCore/Config/serilog.config index e3cf52b3c5..9aca408b36 100644 --- a/src/Umbraco.Web.UI.NetCore/Config/serilog.config +++ b/src/Umbraco.Web.UI.NetCore/Config/serilog.config @@ -19,7 +19,7 @@ - + @@ -27,7 +27,7 @@ - + diff --git a/src/Umbraco.Web.UI.NetCore/Startup.cs b/src/Umbraco.Web.UI.NetCore/Startup.cs index 75b2d6f48e..d79fa0d917 100644 --- a/src/Umbraco.Web.UI.NetCore/Startup.cs +++ b/src/Umbraco.Web.UI.NetCore/Startup.cs @@ -54,6 +54,7 @@ namespace Umbraco.Web.UI.BackOffice }); //Finally initialize Current + // TODO: This should be moved to the UmbracoServiceProviderFactory when the container is cross-wired and then don't use the overload above to `out var factory` Current.Initialize( factory.GetInstance (), factory.GetInstance(), @@ -76,6 +77,7 @@ namespace Umbraco.Web.UI.BackOffice app.UseDeveloperExceptionPage(); } app.UseUmbracoCore(); + app.UseUmbracoRequestLogging(); app.UseUmbracoWebsite(); app.UseUmbracoBackOffice(); app.UseRouting(); diff --git a/src/Umbraco.Web.UI/config/serilog.Release.config b/src/Umbraco.Web.UI/config/serilog.Release.config index e3cf52b3c5..9aca408b36 100644 --- a/src/Umbraco.Web.UI/config/serilog.Release.config +++ b/src/Umbraco.Web.UI/config/serilog.Release.config @@ -19,7 +19,7 @@ - + @@ -27,7 +27,7 @@ - + diff --git a/src/Umbraco.Web/UmbracoApplicationBase.cs b/src/Umbraco.Web/UmbracoApplicationBase.cs index d884366bf1..1f90bc7d13 100644 --- a/src/Umbraco.Web/UmbracoApplicationBase.cs +++ b/src/Umbraco.Web/UmbracoApplicationBase.cs @@ -1,4 +1,5 @@ -using System; +using Serilog.Context; +using System; using System.IO; using System.Reflection; using System.Threading; @@ -12,6 +13,8 @@ using Umbraco.Core.Hosting; using Umbraco.Core.IO; using Umbraco.Core.Logging; using Umbraco.Core.Logging.Serilog; +using Umbraco.Core.Logging.Serilog.Enrichers; +using Umbraco.Net; using Umbraco.Web.AspNet; using Umbraco.Web.Hosting; using Umbraco.Web.Logging; @@ -34,12 +37,16 @@ namespace Umbraco.Web var configFactory = new ConfigsFactory(); var hostingSettings = configFactory.HostingSettings; - var coreDebug = configFactory.CoreDebugSettings; var globalSettings = configFactory.GlobalSettings; var hostingEnvironment = new AspNetHostingEnvironment(hostingSettings); + var loggingConfiguration = new LoggingConfiguration( + Path.Combine(hostingEnvironment.ApplicationPhysicalPath, "App_Data\\Logs"), + Path.Combine(hostingEnvironment.ApplicationPhysicalPath, "config\\serilog.config"), + Path.Combine(hostingEnvironment.ApplicationPhysicalPath, "config\\serilog.user.config")); var ioHelper = new IOHelper(hostingEnvironment, globalSettings); - var logger = SerilogLogger.CreateWithDefaultConfiguration(hostingEnvironment, new AspNetSessionManager(), () => _factory?.GetInstance(), coreDebug, ioHelper, new FrameworkMarchal()); + var logger = SerilogLogger.CreateWithDefaultConfiguration(hostingEnvironment, loggingConfiguration); + var configs = configFactory.Create(); var backOfficeInfo = new AspNetBackOfficeInfo(globalSettings, ioHelper, logger, configFactory.WebRoutingSettings); @@ -168,6 +175,11 @@ namespace Umbraco.Web Umbraco.Composing.Current.BackOfficeInfo); _factory = Current.Factory = _runtime.Configure(register); + // now we can add our request based logging enrichers (globally, which is what we were doing in netframework before) + LogContext.Push(new HttpSessionIdEnricher(_factory.GetInstance())); + LogContext.Push(new HttpRequestNumberEnricher(_factory.GetInstance())); + LogContext.Push(new HttpRequestIdEnricher(_factory.GetInstance())); + _runtime.Start(); }