diff --git a/samples/WebSample/Controllers/HomeController.cs b/samples/WebSample/Controllers/HomeController.cs index 2880e9f..207393a 100644 --- a/samples/WebSample/Controllers/HomeController.cs +++ b/samples/WebSample/Controllers/HomeController.cs @@ -4,15 +4,32 @@ using System.Threading.Tasks; using Microsoft.AspNetCore.Mvc; using Serilog; +using Microsoft.Extensions.Logging; namespace WebSample.Controllers { public class HomeController : Controller { + ILogger _logger; + + public HomeController(ILogger logger) + { + _logger = logger; + } + public IActionResult Index() { - Log.Information("Hello from the Index!"); + _logger.LogInformation("Before"); + + using (_logger.BeginScope("Some name")) + using (_logger.BeginScope(42)) + using (_logger.BeginScope("Formatted {WithValue}", 12345)) + using (_logger.BeginScope(new Dictionary { ["ViaDictionary"] = 100 })) + { + _logger.LogInformation("Hello from the Index!"); + } + _logger.LogInformation("After"); return View(); } @@ -20,6 +37,7 @@ public IActionResult About() { ViewData["Message"] = "Your application description page."; + // Directly through Serilog Log.Information("This is a handler for {Path}", Request.Path); return View(); diff --git a/samples/WebSample/appsettings.json b/samples/WebSample/appsettings.json index 02557b3..73a0849 100644 --- a/samples/WebSample/appsettings.json +++ b/samples/WebSample/appsettings.json @@ -12,7 +12,8 @@ ], "WriteTo": [ "Trace", - "LiterateConsole" + "LiterateConsole", + {"Name": "Seq", "Args": {"serverUrl": "http://localhost:5341" }} ] } } diff --git a/samples/WebSample/project.json b/samples/WebSample/project.json index c9468c7..4ad7c34 100644 --- a/samples/WebSample/project.json +++ b/samples/WebSample/project.json @@ -23,7 +23,8 @@ "Serilog.Extensions.Logging": { "target": "project" }, "Serilog.Settings.Configuration": "2.1.0-dev-00028", "Serilog.Sinks.Trace": "2.0.0", - "Serilog.Sinks.Literate": "2.0.0" + "Serilog.Sinks.Literate": "2.0.0", + "Serilog.Sinks.Seq": "3.1.1" }, "tools": { diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs index af9b0ad..9507548 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs @@ -12,6 +12,8 @@ using Serilog.Core; using Serilog.Events; using FrameworkLogger = Microsoft.Extensions.Logging.ILogger; +using System.Collections.Generic; +using Serilog.Context; namespace Serilog.Extensions.Logging { @@ -21,6 +23,7 @@ namespace Serilog.Extensions.Logging public class SerilogLoggerProvider : ILoggerProvider, ILogEventEnricher { internal const string OriginalFormatPropertyName = "{OriginalFormat}"; + internal const string ScopePropertyName = "Scope"; // May be null; if it is, Log.Logger will be lazily used readonly ILogger _logger; @@ -54,15 +57,36 @@ public FrameworkLogger CreateLogger(string name) /// public IDisposable BeginScope(T state) { - return new SerilogLoggerScope(this, state); + if (CurrentScope != null) + return new SerilogLoggerScope(this, state); + + // The outermost scope pushes and pops the Serilog `LogContext` - once + // this enricher is on the stack, the `CurrentScope` property takes care + // of the rest of the `BeginScope()` stack. + var popSerilogContext = LogContext.PushProperties(this); + return new SerilogLoggerScope(this, state, popSerilogContext); } /// public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) { + List scopeItems = null; for (var scope = CurrentScope; scope != null; scope = scope.Parent) { - scope.Enrich(logEvent, propertyFactory); + LogEventPropertyValue scopeItem; + scope.EnrichAndCreateScopeItem(logEvent, propertyFactory, out scopeItem); + + if (scopeItem != null) + { + scopeItems = scopeItems ?? new List(); + scopeItems.Add(scopeItem); + } + } + + if (scopeItems != null) + { + scopeItems.Reverse(); + logEvent.AddPropertyIfAbsent(new LogEventProperty(ScopePropertyName, new SequenceValue(scopeItems))); } } diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs index 005585b..424d459 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs @@ -3,29 +3,30 @@ using System; using System.Collections.Generic; -using Serilog.Context; using Serilog.Core; using Serilog.Events; namespace Serilog.Extensions.Logging { - class SerilogLoggerScope : IDisposable, ILogEventEnricher + class SerilogLoggerScope : IDisposable { + const string NoName = "None"; + readonly SerilogLoggerProvider _provider; readonly object _state; - readonly IDisposable _popSerilogContext; + readonly IDisposable _chainedDisposable; // An optimization only, no problem if there are data races on this. bool _disposed; - public SerilogLoggerScope(SerilogLoggerProvider provider, object state) + public SerilogLoggerScope(SerilogLoggerProvider provider, object state, IDisposable chainedDisposable = null) { _provider = provider; _state = state; Parent = _provider.CurrentScope; _provider.CurrentScope = this; - _popSerilogContext = LogContext.PushProperties(this); + _chainedDisposable = chainedDisposable; } public SerilogLoggerScope Parent { get; } @@ -44,19 +45,30 @@ public void Dispose() _provider.CurrentScope = Parent; } - _popSerilogContext.Dispose(); + _chainedDisposable?.Dispose(); } } - public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) + public void EnrichAndCreateScopeItem(LogEvent logEvent, ILogEventPropertyFactory propertyFactory, out LogEventPropertyValue scopeItem) { + if (_state == null) + { + scopeItem = null; + return; + } + var stateProperties = _state as IEnumerable>; if (stateProperties != null) { + scopeItem = null; // Unless it's `FormattedLogValues`, these are treated as property bags rather than scope items. + foreach (var stateProperty in stateProperties) { if (stateProperty.Key == SerilogLoggerProvider.OriginalFormatPropertyName && stateProperty.Value is string) + { + scopeItem = new ScalarValue(_state.ToString()); continue; + } var key = stateProperty.Key; var destructureObject = false; @@ -71,6 +83,10 @@ public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) logEvent.AddPropertyIfAbsent(property); } } + else + { + scopeItem = propertyFactory.CreateProperty(NoName, _state).Value; + } } } } diff --git a/src/Serilog.Extensions.Logging/project.json b/src/Serilog.Extensions.Logging/project.json index e6844d4..84dc340 100644 --- a/src/Serilog.Extensions.Logging/project.json +++ b/src/Serilog.Extensions.Logging/project.json @@ -21,6 +21,12 @@ "net4.5": { "dependencies": { "System.Runtime": "4.0.0" } }, + "net4.6": { + "dependencies": { "System.Runtime": "4.0.20" }, + "buildOptions": { + "define": [ "ASYNCLOCAL" ] + } + }, "netstandard1.3": { "buildOptions": { "define": ["ASYNCLOCAL"] diff --git a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs index 4795713..5dbc4b5 100644 --- a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs +++ b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs @@ -364,6 +364,30 @@ public void BeginScopeDoesNotModifyKeyWhenDestructurerIsNotUsedInDictionary() Assert.True(sink.Writes[0].Properties.ContainsKey("FirstName")); } + [Fact] + public void NamedScopesAreCaptured() + { + var t = SetUp(LogLevel.Trace); + var logger = t.Item1; + var sink = t.Item2; + + using (logger.BeginScope("Outer")) + using (logger.BeginScope("Inner")) + { + logger.Log(LogLevel.Information, 0, TestMessage, null, null); + } + + Assert.Equal(1, sink.Writes.Count); + + LogEventPropertyValue scopeValue; + Assert.True(sink.Writes[0].Properties.TryGetValue(SerilogLoggerProvider.ScopePropertyName, out scopeValue)); + + var items = (scopeValue as SequenceValue)?.Elements.Select(e => ((ScalarValue)e).Value).Cast().ToArray(); + Assert.Equal(2, items.Length); + Assert.Equal("Outer", items[0]); + Assert.Equal("Inner", items[1]); + } + private class FoodScope : IEnumerable> { readonly string _name;