diff --git a/README.md b/README.md index 2dbb39d..905fc55 100644 --- a/README.md +++ b/README.md @@ -80,6 +80,69 @@ That's it! With the level bumped up a little you should see log output like: [22:14:45.741 DBG] Handled. Status code: 304 File: /css/site.css ``` +### Notes on Log Scopes + +_Microsoft.Extensions.Logging_ provides the `BeginScope` API, which can be used to add arbitrary properties to log events within a certain region of code. The API comes in two forms: + +1. The method: `IDisposable BeginScope(TState state)` +2. The extension method: `IDisposable BeginScope(this ILogger logger, string messageFormat, params object[] args)` + +Using the extension method will add a `Scope` property to your log events. This is most useful for adding simple "scope strings" to your events, as in the following code: + +```cs +using (_logger.BeginScope("Transaction")) { + _logger.LogInformation("Beginning..."); + _logger.LogInformation("Completed in {DurationMs}ms...", 30); +} +// Example JSON output: +// {"@t":"2020-10-29T19:05:56.4126822Z","@m":"Beginning...","@i":"f6a328e9","SourceContext":"SomeNamespace.SomeService","Scope":["Transaction"]} +// {"@t":"2020-10-29T19:05:56.4176816Z","@m":"Completed in 30ms...","@i":"51812baa","DurationMs":30,"SourceContext":"SomeNamespace.SomeService","Scope":["Transaction"]} +``` + +If you simply want to add a "bag" of additional properties to your log events, however, this extension method approach can be overly verbose. For example, to add `TransactionId` and `ResponseJson` properties to your log events, you would have to do something like the following: + +```cs +// WRONG! Prefer the dictionary approach below instead +using (_logger.BeginScope("TransactionId: {TransactionId}, ResponseJson: {ResponseJson}", 12345, jsonString)) { + _logger.LogInformation("Completed in {DurationMs}ms...", 30); +} +// Example JSON output: +// { +// "@t":"2020-10-29T19:05:56.4176816Z", +// "@m":"Completed in 30ms...", +// "@i":"51812baa", +// "DurationMs":30, +// "SourceContext":"SomeNamespace.SomeService", +// "TransactionId": 12345, +// "ResponseJson": "{ \"Key1\": \"Value1\", \"Key2\": \"Value2\" }", +// "Scope":["TransactionId: 12345, ResponseJson: { \"Key1\": \"Value1\", \"Key2\": \"Value2\" }"] +// } +``` + +Not only does this add the unnecessary `Scope` property to your event, but it also duplicates serialized values between `Scope` and the intended properties, as you can see here with `ResponseJson`. If this were "real" JSON like an API response, then a potentially very large block of text would be duplicated within your log event! Moreover, the template string within `BeginScope` is rather arbitrary when all you want to do is add a bag of properties, and you start mixing enriching concerns with formatting concerns. + +A far better alternative is to use the `BeginScope(TState state)` method. If you provide any `IEnumerable>` to this method, then Serilog will output the key/value pairs as structured properties _without_ the `Scope` property, as in this example: + +```cs +var scopeProps = new Dictionary { + { "TransactionId", 12345 }, + { "ResponseJson", jsonString }, +}; +using (_logger.BeginScope(scopeProps) { + _logger.LogInformation("Transaction completed in {DurationMs}ms...", 30); +} +// Example JSON output: +// { +// "@t":"2020-10-29T19:05:56.4176816Z", +// "@m":"Completed in 30ms...", +// "@i":"51812baa", +// "DurationMs":30, +// "SourceContext":"SomeNamespace.SomeService", +// "TransactionId": 12345, +// "ResponseJson": "{ \"Key1\": \"Value1\", \"Key2\": \"Value2\" }" +// } +``` + ### Credits This package evolved from an earlier package _Microsoft.Framework.Logging.Serilog_ [provided by the ASP.NET team](https://github.com/aspnet/Logging/pull/182).