Attach the correlation id to the request scope if logging is on (#1138)

- Add the correlation id to the request scope as well as setting
it as the parent id of the activity

src/Microsoft.AspNetCore.Hosting/Internal/HostingApplicationDiagnostics.cs

@@ -46,12 +46,22 @@ namespace Microsoft.AspNetCore.Hosting.Internal
                 RecordRequestStartEventLog(httpContext);
             }
 
+            var diagnosticListenerEnabled = _diagnosticListener.IsEnabled();
+            var loggingEnabled = _logger.IsEnabled(LogLevel.Critical);
 
-            if (_diagnosticListener.IsEnabled())
+            // If logging is enabled or the diagnostic listener is enabled, try to get the correlation
+            // id from the header
+            StringValues correlationId;
+            if (diagnosticListenerEnabled || loggingEnabled)
+            {
+                httpContext.Request.Headers.TryGetValue(RequestIdHeaderName, out correlationId);
+            }
+
+            if (diagnosticListenerEnabled)
             {
                 if (_diagnosticListener.IsEnabled(ActivityName, httpContext))
                 {
-                    context.Activity = StartActivity(httpContext);
+                    context.Activity = StartActivity(httpContext, correlationId);
                 }
                 if (_diagnosticListener.IsEnabled(DeprecatedDiagnosticsBeginRequestKey))
                 {
@@ -61,12 +71,12 @@ namespace Microsoft.AspNetCore.Hosting.Internal
             }
 
             // To avoid allocation, return a null scope if the logger is not on at least to some degree.
-            if (_logger.IsEnabled(LogLevel.Critical))
+            if (loggingEnabled)
             {
                 // Scope may be relevant for a different level of logging, so we always create it
                 // see: https://github.com/aspnet/Hosting/pull/944
                 // Scope can be null if logging is not on.
-                context.Scope = _logger.RequestScope(httpContext);
+                context.Scope = _logger.RequestScope(httpContext, correlationId);
 
                 if (_logger.IsEnabled(LogLevel.Information))
                 {
@@ -230,15 +240,15 @@ namespace Microsoft.AspNetCore.Hosting.Internal
         }
 
         [MethodImpl(MethodImplOptions.NoInlining)]
-        private Activity StartActivity(HttpContext httpContext)
+        private Activity StartActivity(HttpContext httpContext, StringValues requestId)
         {
             var activity = new Activity(ActivityName);
-            if (httpContext.Request.Headers.TryGetValue(RequestIdHeaderName, out var requestId))
+            if (!StringValues.IsNullOrEmpty(requestId))
             {
                 activity.SetParentId(requestId);
 
                 // We expect baggage to be empty by default
-                // Only very advanced users will be using it in near future, we encouradge them to keep baggage small (few items)
+                // Only very advanced users will be using it in near future, we encourage them to keep baggage small (few items)
                 string[] baggage = httpContext.Request.Headers.GetCommaSeparatedValues(CorrelationContextHeaderName);
                 if (baggage != StringValues.Empty)
                 {

src/Microsoft.AspNetCore.Hosting/Internal/HostingLoggerExtensions.cs

@@ -13,10 +13,9 @@ namespace Microsoft.AspNetCore.Hosting.Internal
 {
     internal static class HostingLoggerExtensions
     {
-        public static IDisposable RequestScope(this ILogger logger, HttpContext httpContext)
+        public static IDisposable RequestScope(this ILogger logger, HttpContext httpContext, string correlationId)
         {
-
+            return logger.BeginScope(new HostingLogScope(httpContext, correlationId));
-            return logger.BeginScope(new HostingLogScope(httpContext));
         }
 
         public static void ApplicationError(this ILogger logger, Exception exception)
@@ -96,6 +95,7 @@ namespace Microsoft.AspNetCore.Hosting.Internal
         private class HostingLogScope : IReadOnlyList<KeyValuePair<string, object>>
         {
             private readonly HttpContext _httpContext;
+            private readonly string _correlationId;
 
             private string _cachedToString;
 
@@ -103,7 +103,7 @@ namespace Microsoft.AspNetCore.Hosting.Internal
             {
                 get
                 {
-                    return 2;
+                    return 3;
                 }
             }
 
@@ -119,13 +119,19 @@ namespace Microsoft.AspNetCore.Hosting.Internal
                     {
                         return new KeyValuePair<string, object>("RequestPath", _httpContext.Request.Path.ToString());
                     }
-                    throw new IndexOutOfRangeException(nameof(index));
+                    else if (index == 2)
+                    {
+                        return new KeyValuePair<string, object>("CorrelationId", _correlationId);
+                    }
+
+                    throw new ArgumentOutOfRangeException(nameof(index));
                 }
             }
 
-            public HostingLogScope(HttpContext httpContext)
+            public HostingLogScope(HttpContext httpContext, string correlationId)
             {
                 _httpContext = httpContext;
+                _correlationId = correlationId;
             }
 
             public override string ToString()

test/Microsoft.AspNetCore.Hosting.Tests/HostingApplicationTests.cs

@@ -4,6 +4,7 @@
 using System;
 using System.Collections.Generic;
 using System.Diagnostics;
+using System.Linq;
 using System.Reflection;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Hosting.Internal;
@@ -30,6 +31,22 @@ namespace Microsoft.AspNetCore.Hosting.Tests
             hostingApplication.DisposeContext(context, null);
         }
 
+        [Fact]
+        public void CreateContextSetsCorrelationIdInScope()
+        {
+            // Arrange
+            var logger = new LoggerWithScopes();
+            var hostingApplication = CreateApplication(out var features, logger: logger);
+            features.Get<IHttpRequestFeature>().Headers["Request-Id"] = "some correlation id";
+
+            // Act
+            var context = hostingApplication.CreateContext(features);
+
+            Assert.Equal(1, logger.Scopes.Count);
+            var pairs = ((IReadOnlyList<KeyValuePair<string, object>>)logger.Scopes[0]).ToDictionary(p => p.Key, p => p.Value);
+            Assert.Equal("some correlation id", pairs["CorrelationId"].ToString());
+        }
+
         [Fact]
         public void ActivityIsNotCreatedWhenIsEnabledForActivityIsFalse()
         {
@@ -60,7 +77,7 @@ namespace Microsoft.AspNetCore.Hosting.Tests
             hostingApplication.CreateContext(features);
             Assert.Null(Activity.Current);
             Assert.True(isEnabledActivityFired);
-            Assert.False (isEnabledStartFired);
+            Assert.False(isEnabledStartFired);
             Assert.False(eventsFired);
         }
 
@@ -261,7 +278,7 @@ namespace Microsoft.AspNetCore.Hosting.Tests
         }
 
         private static HostingApplication CreateApplication(out FeatureCollection features,
-            DiagnosticListener diagnosticSource = null)
+            DiagnosticListener diagnosticSource = null, ILogger logger = null)
         {
             var httpContextFactory = new Mock<IHttpContextFactory>();
 
@@ -272,7 +289,7 @@ namespace Microsoft.AspNetCore.Hosting.Tests
 
             var hostingApplication = new HostingApplication(
                 ctx => Task.FromResult(0),
-                new NullScopeLogger(),
+                logger ?? new NullScopeLogger(),
                 diagnosticSource ?? new NoopDiagnosticSource(),
                 httpContextFactory.Object);
 
@@ -290,6 +307,31 @@ namespace Microsoft.AspNetCore.Hosting.Tests
             }
         }
 
+        private class LoggerWithScopes : ILogger
+        {
+            public IDisposable BeginScope<TState>(TState state)
+            {
+                Scopes.Add(state);
+                return new Scope();
+            }
+
+            public List<object> Scopes { get; set; } = new List<object>();
+
+            public bool IsEnabled(LogLevel logLevel) => true;
+
+            public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
+            {
+                
+            }
+
+            private class Scope : IDisposable
+            {
+                public void Dispose()
+                {
+                }
+            }
+        }
+
         private class NoopDiagnosticSource : DiagnosticListener
         {
             public NoopDiagnosticSource() : base("DummyListener")