Merge pull request #36 from nblumhardt/dev

Fixes #35 - push ASP.NET contextual properties onto LogContext

Author: nblumhardt

README.md

@@ -11,8 +11,8 @@ This package routes ASP.NET log messages through Serilog, so you can get informa
 **First**, install the _Serilog.Extensions.Logging_ [NuGet package](https://www.nuget.org/packages/Serilog.Extensions.Logging) into your web or console app. You will need a way to view the log messages - _Serilog.Sinks.Literate_ writes these to the console.
 
 ```powershell
-Install-Package Serilog.Extensions.Logging
-Install-Package Serilog.Sinks.Literate
+Install-Package Serilog.Extensions.Logging -Pre -DependencyVersion Highest
+Install-Package Serilog.Sinks.Literate -Pre
 ```
 
 **Next**, in your application's `Startup` method, configure Serilog first:
@@ -31,7 +31,8 @@ public class Startup
     // Other startup code
 ```
 
-**Finally**, in your `Startup` class's `Configure()` method, call `AddSerilog()` on the provided `loggerFactory`.
+**Finally**, in your `Startup` class's `Configure()` method, remove the existing logger configuration entries and
+call `AddSerilog()` on the provided `loggerFactory`.
 
 ```csharp
   public void Configure(IApplicationBuilder app,
@@ -56,19 +57,6 @@ That's it! With the level bumped up a little you should see log output like:
 2015-05-15 22:14:45.741 +10:00 [DBG] Handled. Status code: 304 File: /css/site.css
 ```
 
-### Levels
-
-If you want to get more information from the log you'll need to bump up the level.
-
-Two things:
-
- * You need to set `MinimumLevel` on **both** the Serilog `LoggerConfiguration` and the `ILoggerFactory`
- * Serilog and ASP.NET assign different priorities to the `Debug` and `Verbose` levels; Serilog's `Debug` is ASP.NET's `Verbose`, and vice-versa
-
-### Building from source
-
-To build the `dev` branch, which tracks the `dev` branch of _Microsoft.Extensions.Logging_, you must add https://www.myget.org/F/aspnetvnext/ to your package sources.
-
 ### 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).

samples/WebSample/Controllers/HomeController.cs

@@ -3,6 +3,7 @@
 using System.Linq;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Mvc;
+using Serilog;
 
 namespace WebSample.Controllers
 {
@@ -17,6 +18,8 @@ public IActionResult About()
         {
             ViewData["Message"] = "Your application description page.";
 
+            Log.Information("This is a Serilog-native event from the About action");
+
             return View();
         }
 

samples/WebSample/Startup.cs

@@ -22,6 +22,7 @@ public Startup(IHostingEnvironment env)
         {
             Log.Logger = new LoggerConfiguration()
                 .MinimumLevel.Debug()
+                .Enrich.FromLogContext()
                 .WriteTo.Seq("http://localhost:5341")
                 .CreateLogger();
 

src/Serilog.Extensions.Logging/Extensions/Logging/EventIdEnricher.cs

@@ -1,3 +1,17 @@
+// Copyright 2016 Serilog Contributors
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
 using System.Collections.Generic;
 using Microsoft.Extensions.Logging;
 using Serilog.Core;

src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs

@@ -16,7 +16,6 @@ namespace Serilog.Extensions.Logging
     class SerilogLogger : FrameworkLogger
     {
         readonly SerilogLoggerProvider _provider;
-        readonly string _name;
         readonly ILogger _logger;
 
         static readonly MessageTemplateParser _messageTemplateParser = new MessageTemplateParser();
@@ -28,13 +27,12 @@ public SerilogLogger(
         {
             if (provider == null) throw new ArgumentNullException(nameof(provider));
             _provider = provider;
-            _name = name;
             _logger = logger;
 
             // If a logger was passed, the provider has already added itself as an enricher
             _logger = _logger ?? Serilog.Log.Logger.ForContext(new[] { provider });
 
-            if (_name != null)
+            if (name != null)
             {
                 _logger = _logger.ForContext(Constants.SourceContextPropertyName, name);
             }
@@ -47,7 +45,7 @@ public bool IsEnabled(LogLevel logLevel)
 
         public IDisposable BeginScope<TState>(TState state)
         {
-            return _provider.BeginScope(_name, state);
+            return _provider.BeginScope(state);
         }
 
         public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)

src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs

@@ -2,7 +2,6 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 using System;
-using System.Collections.Generic;
 #if ASYNCLOCAL
 using System.Threading;
 #else
@@ -34,27 +33,16 @@ public FrameworkLogger CreateLogger(string name)
             return new SerilogLogger(this, _logger, name);
         }
 
-        public IDisposable BeginScope<T>(string name, T state)
+        public IDisposable BeginScope<T>(T state)
         {
-            return new SerilogLoggerScope(this, name, state);
+            return new SerilogLoggerScope(this, state);
         }
 
         public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
         {
             for (var scope = CurrentScope; scope != null; scope = scope.Parent)
             {
-                var stateStructure = scope.State as IEnumerable<KeyValuePair<string, object>>;
-                if (stateStructure != null)
-                {
-                    foreach (var keyValue in stateStructure)
-                    {
-                        if (keyValue.Key == OriginalFormatPropertyName && keyValue.Value is string)
-                            continue;
-
-                        var property = propertyFactory.CreateProperty(keyValue.Key, keyValue.Value);
-                        logEvent.AddPropertyIfAbsent(property);
-                    }
-                }
+                scope.Enrich(logEvent, propertyFactory);
             }
         }
 

src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs

@@ -2,46 +2,66 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 using System;
+using System.Collections.Generic;
+using Serilog.Context;
+using Serilog.Core;
+using Serilog.Events;
 
 namespace Serilog.Extensions.Logging
 {
-    class SerilogLoggerScope : IDisposable
+    class SerilogLoggerScope : IDisposable, ILogEventEnricher
     {
         readonly SerilogLoggerProvider _provider;
-        bool _disposedValue; // To detect redundant calls
+        readonly object _state;
+        readonly IDisposable _popSerilogContext;
 
-        public SerilogLoggerScope(SerilogLoggerProvider provider, string name, object state)
+        // An optimization only, no problem if there are data races on this.
+        bool _disposed;
+
+        public SerilogLoggerScope(SerilogLoggerProvider provider, object state)
         {
             _provider = provider;
-            Name = name;
-            State = state;
+            _state = state;
 
             Parent = _provider.CurrentScope;
             _provider.CurrentScope = this;
+            _popSerilogContext = LogContext.PushProperties(this);
         }
 
         public SerilogLoggerScope Parent { get; }
-        public string Name { get; private set; }
-        public object State { get; private set; }
-
-        public void RemoveScope()
+        
+        public void Dispose()
         {
-            for (var scan = _provider.CurrentScope; scan != null; scan = scan.Parent)
+            if (!_disposed)
             {
-                if (ReferenceEquals(scan, this))
+                _disposed = true;
+
+                // In case one of the parent scopes has been disposed out-of-order, don't
+                // just blindly reinstate our own parent.
+                for (var scan = _provider.CurrentScope; scan != null; scan = scan.Parent)
                 {
-                    _provider.CurrentScope = Parent;
+                    if (ReferenceEquals(scan, this))
+                        _provider.CurrentScope = Parent;
                 }
+
+                _popSerilogContext.Dispose();
             }
         }
 
-        public void Dispose()
+        public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
         {
-            if (!_disposedValue)
+            var stateProperties = _state as IEnumerable<KeyValuePair<string, object>>;
+            if (stateProperties != null)
             {
-                RemoveScope();
+                foreach (var stateProperty in stateProperties)
+                {
+                    if (stateProperty.Key == SerilogLoggerProvider.OriginalFormatPropertyName && stateProperty.Value is string)
+                        continue;
+
+                    var property = propertyFactory.CreateProperty(stateProperty.Key, stateProperty.Value);
+                    logEvent.AddPropertyIfAbsent(property);
+                }
             }
-            _disposedValue = true;
         }
     }
 }