From 71165692d5f66c811c3b251047b12c259ac2fe23 Mon Sep 17 00:00:00 2001 From: Nicholas Blumhardt Date: Mon, 14 Oct 2019 19:08:15 +1000 Subject: [PATCH 01/11] Dev version bump [skip ci] --- src/Serilog.AspNetCore/Serilog.AspNetCore.csproj | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Serilog.AspNetCore/Serilog.AspNetCore.csproj b/src/Serilog.AspNetCore/Serilog.AspNetCore.csproj index ed44508..cc4f82f 100644 --- a/src/Serilog.AspNetCore/Serilog.AspNetCore.csproj +++ b/src/Serilog.AspNetCore/Serilog.AspNetCore.csproj @@ -2,7 +2,7 @@ Serilog support for ASP.NET Core logging - 3.1.0 + 3.1.1 Microsoft;Serilog Contributors netstandard2.0 true From 3852fa1aa94dcbf0ada0b9ac017ae86da8cee3c4 Mon Sep 17 00:00:00 2001 From: Tom Kerkhove Date: Tue, 29 Oct 2019 13:34:30 +0100 Subject: [PATCH 02/11] Add RequestHost & RequestScheme to log properties --- README.md | 11 ++++++++++- .../AspNetCore/RequestLoggingMiddleware.cs | 4 +++- 2 files changed, 13 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index 4c324f6..1f529fb 100644 --- a/README.md +++ b/README.md @@ -134,7 +134,7 @@ Then, in your application's _Startup.cs_, add the middleware with `UseSerilogReq // Other app configuration ``` -It's important that the `UseSerilogRequestLogging()` call appears _before_ handlers such as MVC. The middleware will not time or log components that appear before it in the pipeline. (This can be utilized to exclude noisy handlers from logging, such as `UseStaticFiles()`, by placing `UseSerilogRequestLogging()` after them.) +It's important that the `UseSerilogRequestLogging()` call appears _before_ handlers such as MVC. The middleware will not time or log components that appear before it in the pipeline. You can override the message template by specifying `messageTemplate`. (This can be utilized to exclude noisy handlers from logging, such as `UseStaticFiles()`, by placing `UseSerilogRequestLogging()` after them.) During request processing, additional properties can be attached to the completion event using `IDiagnosticContext.Set()`: @@ -159,6 +159,15 @@ During request processing, additional properties can be attached to the completi This pattern has the advantage of reducing the number of log events that need to be constructed, transmitted, and stored per HTTP request. Having many properties on the same event can also make correlation of request details and other data easier. +The following request information will be added as log properties: + +* `RequestMethod` +* `RequestScheme` +* `RequestHost` +* `RequestPath` +* `StatusCode` +* `Elapsed` + ### Inline initialization You can alternatively configure Serilog inline, in `BuildWebHost()`, using a delegate as shown below: diff --git a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs index 954b326..9234afb 100644 --- a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs +++ b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs @@ -78,11 +78,13 @@ bool LogCompletion(HttpContext httpContext, DiagnosticContextCollector collector if (!collector.TryComplete(out var collectedProperties)) collectedProperties = NoProperties; - + // Last-in (correctly) wins... var properties = collectedProperties.Concat(new[] { new LogEventProperty("RequestMethod", new ScalarValue(httpContext.Request.Method)), + new LogEventProperty("RequestHost", new ScalarValue(httpContext.Request.Host.Value)), + new LogEventProperty("RequestScheme", new ScalarValue(httpContext.Request.Scheme)), new LogEventProperty("RequestPath", new ScalarValue(GetPath(httpContext))), new LogEventProperty("StatusCode", new ScalarValue(statusCode)), new LogEventProperty("Elapsed", new ScalarValue(elapsedMs)) From 166783d44e65dc02e062ad3d82b18391238fbf2e Mon Sep 17 00:00:00 2001 From: Tom Kerkhove Date: Tue, 29 Oct 2019 16:59:45 +0100 Subject: [PATCH 03/11] Remove spaces --- src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs index 9234afb..0c0d24e 100644 --- a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs +++ b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs @@ -78,7 +78,7 @@ bool LogCompletion(HttpContext httpContext, DiagnosticContextCollector collector if (!collector.TryComplete(out var collectedProperties)) collectedProperties = NoProperties; - + // Last-in (correctly) wins... var properties = collectedProperties.Concat(new[] { From 398cc94d2cd6edef8a568de3c00e698ec8f48133 Mon Sep 17 00:00:00 2001 From: Tom Kerkhove Date: Mon, 4 Nov 2019 09:06:18 -0500 Subject: [PATCH 04/11] Align with suggested approach Signed-off-by: Tom Kerkhove --- README.md | 15 +++++++++++++-- samples/EarlyInitializationSample/Startup.cs | 11 +++++++++-- samples/InlineInitializationSample/Startup.cs | 9 ++++++++- .../AspNetCore/RequestLoggingMiddleware.cs | 9 ++++++--- .../AspNetCore/RequestLoggingOptions.cs | 5 +++++ 5 files changed, 41 insertions(+), 8 deletions(-) diff --git a/README.md b/README.md index 1f529fb..bab3dfc 100644 --- a/README.md +++ b/README.md @@ -162,12 +162,23 @@ This pattern has the advantage of reducing the number of log events that need to The following request information will be added as log properties: * `RequestMethod` -* `RequestScheme` -* `RequestHost` * `RequestPath` * `StatusCode` * `Elapsed` +Not enough? You can extend the information that is being emitted by using `options.EnrichDiagnosticContext`: + +```csharp +app.UseSerilogRequestLogging(options => +{ + options.EnrichDiagnosticContext = (diagnosticContext, httpContext) => + { + diagnosticContext.Set("RequestHost", httpContext.Request.Host.Value); + diagnosticContext.Set("RequestScheme", httpContext.Request.Scheme); + }; +}); +``` + ### Inline initialization You can alternatively configure Serilog inline, in `BuildWebHost()`, using a delegate as shown below: diff --git a/samples/EarlyInitializationSample/Startup.cs b/samples/EarlyInitializationSample/Startup.cs index 502c133..2782f7b 100644 --- a/samples/EarlyInitializationSample/Startup.cs +++ b/samples/EarlyInitializationSample/Startup.cs @@ -30,8 +30,15 @@ public void Configure(IApplicationBuilder app, IWebHostEnvironment env) // Write streamlined request completion events, instead of the more verbose ones from the framework. // To use the default framework request logging instead, remove this line and set the "Microsoft" // level in appsettings.json to "Information". - app.UseSerilogRequestLogging(); - + app.UseSerilogRequestLogging(options => + { + options.EnrichDiagnosticContext = (diagnosticContext, httpContext) => + { + diagnosticContext.Set("RequestHost", httpContext.Request.Host.Value); + diagnosticContext.Set("RequestScheme", httpContext.Request.Scheme); + }; + }); + app.UseRouting(); app.UseEndpoints(endpoints => diff --git a/samples/InlineInitializationSample/Startup.cs b/samples/InlineInitializationSample/Startup.cs index 82f3bcd..a1965a4 100644 --- a/samples/InlineInitializationSample/Startup.cs +++ b/samples/InlineInitializationSample/Startup.cs @@ -32,7 +32,14 @@ public void Configure(IApplicationBuilder app, IWebHostEnvironment env) // Write streamlined request completion events, instead of the more verbose ones from the framework. // To use the default framework request logging instead, remove this line and set the "Microsoft" // level in appsettings.json to "Information". - app.UseSerilogRequestLogging(); + app.UseSerilogRequestLogging(options => + { + options.EnrichDiagnosticContext = (diagnosticContext, httpContext) => + { + diagnosticContext.Set("RequestHost", httpContext.Request.Host.Value); + diagnosticContext.Set("RequestScheme", httpContext.Request.Scheme); + }; + }); app.UseRouting(); diff --git a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs index 9234afb..7618641 100644 --- a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs +++ b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs @@ -29,6 +29,7 @@ class RequestLoggingMiddleware readonly RequestDelegate _next; readonly DiagnosticContext _diagnosticContext; readonly MessageTemplate _messageTemplate; + readonly Action _enrichDiagnosticContext; readonly Func _getLevel; static readonly LogEventProperty[] NoProperties = new LogEventProperty[0]; @@ -39,6 +40,7 @@ public RequestLoggingMiddleware(RequestDelegate next, DiagnosticContext diagnost _diagnosticContext = diagnosticContext ?? throw new ArgumentNullException(nameof(diagnosticContext)); _getLevel = options.GetLevel; + _enrichDiagnosticContext = options.EnrichDiagnosticContext; _messageTemplate = new MessageTemplateParser().Parse(options.MessageTemplate); } @@ -78,13 +80,14 @@ bool LogCompletion(HttpContext httpContext, DiagnosticContextCollector collector if (!collector.TryComplete(out var collectedProperties)) collectedProperties = NoProperties; - + + // Enrich diagnostic context + _enrichDiagnosticContext?.Invoke(_diagnosticContext, httpContext); + // Last-in (correctly) wins... var properties = collectedProperties.Concat(new[] { new LogEventProperty("RequestMethod", new ScalarValue(httpContext.Request.Method)), - new LogEventProperty("RequestHost", new ScalarValue(httpContext.Request.Host.Value)), - new LogEventProperty("RequestScheme", new ScalarValue(httpContext.Request.Scheme)), new LogEventProperty("RequestPath", new ScalarValue(GetPath(httpContext))), new LogEventProperty("StatusCode", new ScalarValue(statusCode)), new LogEventProperty("Elapsed", new ScalarValue(elapsedMs)) diff --git a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs index 3a4127a..555e8d9 100644 --- a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs +++ b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs @@ -45,6 +45,11 @@ public class RequestLoggingOptions /// public Func GetLevel { get; set; } + /// + /// Gets or sets the action that allows you to enrich the diagnostic context + /// + public Action EnrichDiagnosticContext { get; set; } + internal RequestLoggingOptions() { } } } \ No newline at end of file From 8651ec767544a2a036eeae74d0cc0a2662584b28 Mon Sep 17 00:00:00 2001 From: Nicholas Blumhardt Date: Wed, 6 Nov 2019 12:45:52 +1000 Subject: [PATCH 05/11] Some slight README organization tweaks --- README.md | 15 +++++++++++---- 1 file changed, 11 insertions(+), 4 deletions(-) diff --git a/README.md b/README.md index bab3dfc..b132e58 100644 --- a/README.md +++ b/README.md @@ -82,7 +82,7 @@ That's it! With the level bumped up a little you will see log output resembling: A more complete example, showing `appsettings.json` configuration, can be found in [the sample project here](https://github.com/serilog/serilog-aspnetcore/tree/dev/samples/EarlyInitializationSample). -### Request logging `3.0.0-*` +### Request logging `3.0.0` The package includes middleware for smarter HTTP request logging. The default request logging implemented by ASP.NET Core is noisy, with multiple events emitted per request. The included middleware condenses these into a single event that carries method, path, status code, and timing information. @@ -134,7 +134,7 @@ Then, in your application's _Startup.cs_, add the middleware with `UseSerilogReq // Other app configuration ``` -It's important that the `UseSerilogRequestLogging()` call appears _before_ handlers such as MVC. The middleware will not time or log components that appear before it in the pipeline. You can override the message template by specifying `messageTemplate`. (This can be utilized to exclude noisy handlers from logging, such as `UseStaticFiles()`, by placing `UseSerilogRequestLogging()` after them.) +It's important that the `UseSerilogRequestLogging()` call appears _before_ handlers such as MVC. The middleware will not time or log components that appear before it in the pipeline. (This can be utilized to exclude noisy handlers from logging, such as `UseStaticFiles()`, by placing `UseSerilogRequestLogging()` after them.) During request processing, additional properties can be attached to the completion event using `IDiagnosticContext.Set()`: @@ -159,18 +159,25 @@ During request processing, additional properties can be attached to the completi This pattern has the advantage of reducing the number of log events that need to be constructed, transmitted, and stored per HTTP request. Having many properties on the same event can also make correlation of request details and other data easier. -The following request information will be added as log properties: +The following request information will be added as properties by default: * `RequestMethod` * `RequestPath` * `StatusCode` * `Elapsed` -Not enough? You can extend the information that is being emitted by using `options.EnrichDiagnosticContext`: +You can modify the message template used for request completion events, add additional properties, or change the event level, using the `options` callback on `UseSerilogRequestLogging()`: ```csharp app.UseSerilogRequestLogging(options => { + // Customize the message template + options.MessageTemplate = "Handled {RequestPath}"; + + // Emit debug-level events instead of the defaults + options.GetLevel = (httpContext, elapsed, ex) => LogEventLevel.Debug; + + // Attach additional properties to the request completion event options.EnrichDiagnosticContext = (diagnosticContext, httpContext) => { diagnosticContext.Set("RequestHost", httpContext.Request.Host.Value); From 3f0b9a6f52d9286ae217498f504933358df7bb12 Mon Sep 17 00:00:00 2001 From: Nicholas Blumhardt Date: Wed, 6 Nov 2019 12:46:43 +1000 Subject: [PATCH 06/11] Use the simpler defaults in examples. --- samples/EarlyInitializationSample/Startup.cs | 9 +-------- 1 file changed, 1 insertion(+), 8 deletions(-) diff --git a/samples/EarlyInitializationSample/Startup.cs b/samples/EarlyInitializationSample/Startup.cs index 2782f7b..25d0c75 100644 --- a/samples/EarlyInitializationSample/Startup.cs +++ b/samples/EarlyInitializationSample/Startup.cs @@ -30,14 +30,7 @@ public void Configure(IApplicationBuilder app, IWebHostEnvironment env) // Write streamlined request completion events, instead of the more verbose ones from the framework. // To use the default framework request logging instead, remove this line and set the "Microsoft" // level in appsettings.json to "Information". - app.UseSerilogRequestLogging(options => - { - options.EnrichDiagnosticContext = (diagnosticContext, httpContext) => - { - diagnosticContext.Set("RequestHost", httpContext.Request.Host.Value); - diagnosticContext.Set("RequestScheme", httpContext.Request.Scheme); - }; - }); + app.UseSerilogRequestLogging(); app.UseRouting(); From 90587d17d442ccb3e8d69171014540ff3edd7f8b Mon Sep 17 00:00:00 2001 From: Nicholas Blumhardt Date: Wed, 6 Nov 2019 12:47:08 +1000 Subject: [PATCH 07/11] Use simpler defaults in examples. --- samples/InlineInitializationSample/Startup.cs | 9 +-------- 1 file changed, 1 insertion(+), 8 deletions(-) diff --git a/samples/InlineInitializationSample/Startup.cs b/samples/InlineInitializationSample/Startup.cs index a1965a4..82f3bcd 100644 --- a/samples/InlineInitializationSample/Startup.cs +++ b/samples/InlineInitializationSample/Startup.cs @@ -32,14 +32,7 @@ public void Configure(IApplicationBuilder app, IWebHostEnvironment env) // Write streamlined request completion events, instead of the more verbose ones from the framework. // To use the default framework request logging instead, remove this line and set the "Microsoft" // level in appsettings.json to "Information". - app.UseSerilogRequestLogging(options => - { - options.EnrichDiagnosticContext = (diagnosticContext, httpContext) => - { - diagnosticContext.Set("RequestHost", httpContext.Request.Host.Value); - diagnosticContext.Set("RequestScheme", httpContext.Request.Scheme); - }; - }); + app.UseSerilogRequestLogging(); app.UseRouting(); From c350bce6a18f407d20e80a3384580cafd2560c19 Mon Sep 17 00:00:00 2001 From: Nicholas Blumhardt Date: Wed, 6 Nov 2019 12:49:55 +1000 Subject: [PATCH 08/11] Some minor doc edits. --- .../AspNetCore/RequestLoggingOptions.cs | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs index 555e8d9..327e468 100644 --- a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs +++ b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs @@ -35,21 +35,21 @@ public class RequestLoggingOptions public string MessageTemplate { get; set; } /// - /// Gets or sets the function returning the based on the , the number of + /// A function returning the based on the , the number of /// elapsed milliseconds required for handling the request, and an if one was thrown. /// The default behavior returns when the response status code is greater than 499 or if the /// is not null. /// /// - /// The function returning the . + /// A function returning the . /// public Func GetLevel { get; set; } /// - /// Gets or sets the action that allows you to enrich the diagnostic context + /// A callback that can be used to set additional properties on the request completion event. /// public Action EnrichDiagnosticContext { get; set; } internal RequestLoggingOptions() { } } -} \ No newline at end of file +} From 00c6182c08f6eb29383bf78a71eda2002bd46c91 Mon Sep 17 00:00:00 2001 From: Nicholas Blumhardt Date: Wed, 6 Nov 2019 12:54:27 +1000 Subject: [PATCH 09/11] Request logging and provider support have shipped [skip ci] --- README.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index b132e58..860fe95 100644 --- a/README.md +++ b/README.md @@ -82,7 +82,7 @@ That's it! With the level bumped up a little you will see log output resembling: A more complete example, showing `appsettings.json` configuration, can be found in [the sample project here](https://github.com/serilog/serilog-aspnetcore/tree/dev/samples/EarlyInitializationSample). -### Request logging `3.0.0` +### Request logging The package includes middleware for smarter HTTP request logging. The default request logging implemented by ASP.NET Core is noisy, with multiple events emitted per request. The included middleware condenses these into a single event that carries method, path, status code, and timing information. @@ -203,7 +203,7 @@ If this method is used, `Log.Logger` is assigned implicitly, and closed when the A complete example, showing this approach, can be found in [the _InlineIntializationSample_ project](https://github.com/serilog/serilog-aspnetcore/tree/dev/samples/InlineInitializationSample). -### Enabling `Microsoft.Extensions.Logging.ILoggerProvider`s `3.0.0-*` +### Enabling `Microsoft.Extensions.Logging.ILoggerProvider`s Serilog sends events to outputs called _sinks_, that implement Serilog's `ILogEventSink` interface, and are added to the logging pipeline using `WriteTo`. _Microsoft.Extensions.Logging_ has a similar concept called _providers_, and these implement `ILoggerProvider`. Providers are what the default logging configuration creates under the hood through methods like `AddConsole()`. From fd6bf028579faab2bb0e721b415dbd2fb611e57d Mon Sep 17 00:00:00 2001 From: Nicholas Blumhardt Date: Wed, 6 Nov 2019 12:55:31 +1000 Subject: [PATCH 10/11] Now supports `options.EnrichDiagnosticContext` --- src/Serilog.AspNetCore/Serilog.AspNetCore.csproj | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Serilog.AspNetCore/Serilog.AspNetCore.csproj b/src/Serilog.AspNetCore/Serilog.AspNetCore.csproj index cc4f82f..5c5c3f7 100644 --- a/src/Serilog.AspNetCore/Serilog.AspNetCore.csproj +++ b/src/Serilog.AspNetCore/Serilog.AspNetCore.csproj @@ -2,7 +2,7 @@ Serilog support for ASP.NET Core logging - 3.1.1 + 3.2.0 Microsoft;Serilog Contributors netstandard2.0 true From db1e0580f68e08580970db3d70b3c63294b3a3a1 Mon Sep 17 00:00:00 2001 From: Alastair Green Date: Thu, 7 Nov 2019 12:06:36 +0000 Subject: [PATCH 11/11] FIX: Enrich context before collecting properties LogCompletion event was not including properties added via `EnrichDiagnosticContext` delegate on options because the properties had been collected before invoking the enricher. Swapping the order of the statements fixes this. --- .../AspNetCore/RequestLoggingMiddleware.cs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs index 7618641..e6c17f1 100644 --- a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs +++ b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs @@ -78,12 +78,12 @@ bool LogCompletion(HttpContext httpContext, DiagnosticContextCollector collector if (!logger.IsEnabled(level)) return false; - if (!collector.TryComplete(out var collectedProperties)) - collectedProperties = NoProperties; - // Enrich diagnostic context _enrichDiagnosticContext?.Invoke(_diagnosticContext, httpContext); + if (!collector.TryComplete(out var collectedProperties)) + collectedProperties = NoProperties; + // Last-in (correctly) wins... var properties = collectedProperties.Concat(new[] {