fix: Propagate framework scopes

Our logging providers need to implement ISupportExternalScope in order to retain scopes from Kestrel.

Fixes #509.

Author: jskeet

src/Google.Cloud.Functions.Hosting.Tests/Logging/JsonConsoleLoggerTest.cs

@@ -94,7 +94,7 @@ public void Scopes()
         private static JObject GetLogEntry(string category, Action<ILogger> action)
         {
             var builder = new StringBuilder();
-            ILogger logger = new JsonConsoleLogger(category, new StringWriter(builder));
+            ILogger logger = new JsonConsoleLogger(category, scopeProvider: null, new StringWriter(builder));
             action(logger);
             return JObject.Parse(builder.ToString());
         }

src/Google.Cloud.Functions.Hosting.Tests/Logging/LoggingIntegrationTest.cs

@@ -0,0 +1,54 @@
+// Copyright 2024, Google LLC
+//
+// 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
+//
+//     https://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 Google.Cloud.Functions.Framework;
+using Google.Cloud.Functions.Testing;
+using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.Logging;
+using System.Threading.Tasks;
+using Xunit;
+
+namespace Google.Cloud.Functions.Hosting.Tests.Logging;
+
+public class LoggingFunction : IHttpFunction
+{
+    private readonly ILogger _logger;
+
+    public LoggingFunction(ILogger<LoggingFunction> logger) =>
+        _logger = logger;
+
+    public Task HandleAsync(HttpContext context)
+    {
+        _logger.LogInformation("Test log entry");
+        return Task.CompletedTask;
+    }
+}
+
+public class LoggingIntegrationTest : FunctionTestBase<LoggingFunction>
+{
+    // Note: this test doesn't test JsonConsoleLogger and SimpleConsoleLogger directly;
+    // it's testing MemoryLoggerProvider's handling of scope providers - but that's basically
+    // the same code as in FactoryLoggerProvider, so it helps to build confidence.
+    // (The others have been tested manually.)
+    [Fact]
+    public async Task LogEntryHasScopes()
+    {
+        await ExecuteHttpGetRequestAsync();
+        var logEntries = GetFunctionLogEntries();
+        var entry = Assert.Single(logEntries);
+        Assert.Equal("Test log entry", entry.Message);
+        // Kestrel adds two scopes: one of SpanId/TraceId/ParentId, one of RequestPath/RequestId.
+        Assert.Equal(2, entry.Scopes.Count);
+    }
+}

src/Google.Cloud.Functions.Hosting.Tests/Logging/SimpleConsoleLoggerTest.cs

@@ -116,7 +116,7 @@ private static string SkipTimestamp(string line)
         private static List<string> GetLogLines(string category, Action<ILogger> action)
         {
             var builder = new StringBuilder();
-            ILogger logger = new SimpleConsoleLogger(category, new StringWriter(builder));
+            ILogger logger = new SimpleConsoleLogger(category, scopeProvider: null, new StringWriter(builder));
             action(logger);
             var reader = new StringReader(builder.ToString());
             List<string> ret = new List<string>();

src/Google.Cloud.Functions.Hosting/Extensions/FunctionsFrameworkLoggingExtensions.cs

@@ -36,8 +36,8 @@ public static ILoggingBuilder AddFunctionsConsoleLogging(this ILoggingBuilder bu
         {
             var options = FunctionsFrameworkOptions.FromConfiguration(context.Configuration);
             ILoggerProvider provider = options.JsonLogging
-                ? new FactoryLoggerProvider(category => new JsonConsoleLogger(category, System.Console.Out))
-                : new FactoryLoggerProvider(category => new SimpleConsoleLogger(category, System.Console.Out));
+                ? new FactoryLoggerProvider((category, scopeProvider) => new JsonConsoleLogger(category, scopeProvider, System.Console.Out))
+                : new FactoryLoggerProvider((category, scopeProvider) => new SimpleConsoleLogger(category, scopeProvider, System.Console.Out));
             builder.AddProvider(provider);
             return builder;
         }

src/Google.Cloud.Functions.Hosting/Logging/FactoryLoggerProvider.cs

@@ -20,14 +20,18 @@ namespace Google.Cloud.Functions.Hosting.Logging
     /// <summary>
     /// Simple logger provider that just calls a factory method each time it's asked for logger.
     /// </summary>
-    internal class FactoryLoggerProvider : ILoggerProvider
+    internal class FactoryLoggerProvider : ILoggerProvider, ISupportExternalScope
     {
-        private readonly Func<string, ILogger> _factory;
+        private readonly Func<string, IExternalScopeProvider?, ILogger> _factory;
+        private IExternalScopeProvider? _externalScopeProvider;
 
-        internal FactoryLoggerProvider(Func<string, ILogger> factory) =>
+        void ISupportExternalScope.SetScopeProvider(IExternalScopeProvider externalScopeProvider) =>
+            _externalScopeProvider = externalScopeProvider;
+
+        internal FactoryLoggerProvider(Func<string, IExternalScopeProvider?, ILogger> factory) =>
             _factory = factory;
 
-        public ILogger CreateLogger(string categoryName) => _factory(categoryName);
+        public ILogger CreateLogger(string categoryName) => _factory(categoryName, _externalScopeProvider);
 
         public void Dispose()
         {

src/Google.Cloud.Functions.Hosting/Logging/JsonConsoleLogger.cs

@@ -34,8 +34,8 @@ internal class JsonConsoleLogger : LoggerBase
 
         private readonly TextWriter _console;
 
-        internal JsonConsoleLogger(string category, TextWriter console)
-            : base(category) => _console = console;
+        internal JsonConsoleLogger(string category, IExternalScopeProvider? scopeProvider, TextWriter console)
+            : base(category, scopeProvider) => _console = console;
 
         protected override void LogImpl<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, string formattedMessage)
         {

src/Google.Cloud.Functions.Hosting/Logging/LoggerBase.cs

@@ -33,10 +33,11 @@ internal abstract class LoggerBase : ILogger
 
         private readonly bool _isKestrelCategory;
         protected string Category { get; }
-        protected IExternalScopeProvider ScopeProvider { get; } = new LoggerExternalScopeProvider();
+        protected IExternalScopeProvider ScopeProvider { get; }
 
-        protected LoggerBase(string category) =>
-            (Category, _isKestrelCategory) = (category, category == KestrelCategory);
+        protected LoggerBase(string category, IExternalScopeProvider? scopeProvider) =>
+            (Category, _isKestrelCategory, ScopeProvider) =
+            (category, category == KestrelCategory, scopeProvider ?? new LoggerExternalScopeProvider());
 
         public IDisposable BeginScope<TState>(TState state) => ScopeProvider.Push(state);
 
@@ -68,14 +69,6 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
         /// </summary>
         protected abstract void LogImpl<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, string formattedMessage);
 
-        // Used for scope handling.
-        private class SingletonDisposable : IDisposable
-        {
-            internal static readonly SingletonDisposable Instance = new SingletonDisposable();
-            private SingletonDisposable() { }
-            public void Dispose() { }
-        }
-
         /// <summary>
         /// Convenience method to convert a value into a string using the invariant
         /// culture for formatting. Null input is converted into an empty string.

src/Google.Cloud.Functions.Hosting/Logging/SimpleConsoleLogger.cs

@@ -25,8 +25,8 @@ internal class SimpleConsoleLogger : LoggerBase
     {
         private readonly TextWriter _console;
 
-        internal SimpleConsoleLogger(string category, TextWriter console)
-            : base(category) => _console = console;
+        internal SimpleConsoleLogger(string category, IExternalScopeProvider? scopeProvider, TextWriter console)
+            : base(category, scopeProvider) => _console = console;
 
         protected override void LogImpl<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, string formattedMessage)
         {

src/Google.Cloud.Functions.Testing/MemoryLogger.cs

@@ -27,13 +27,23 @@ public class MemoryLogger : ILogger
     {
         private readonly string _categoryName;
         private readonly ConcurrentQueue<TestLogEntry> _logEntries = new ConcurrentQueue<TestLogEntry>();
-        private readonly IExternalScopeProvider _scopeProvider = new LoggerExternalScopeProvider();
+        private readonly IExternalScopeProvider _scopeProvider;
 
         /// <summary>
         /// Creates a logger with the given category name.
         /// </summary>
         /// <param name="categoryName">The category name of the logger.</param>
-        public MemoryLogger(string categoryName) => _categoryName = categoryName;
+        public MemoryLogger(string categoryName) : this(categoryName, null)
+        {
+        }
+
+        /// <summary>
+        /// Creates a logger with the given category name and scope provider
+        /// </summary>
+        /// <param name="categoryName">The category name of the logger.</param>
+        /// <param name="scopeProvider">The scope provider to use, or null to create a new provider.</param>
+        public MemoryLogger(string categoryName, IExternalScopeProvider? scopeProvider) =>
+            (_categoryName, _scopeProvider) = (categoryName, scopeProvider ?? new LoggerExternalScopeProvider());
 
         /// <summary>
         /// Clears the log entries in this logger.

src/Google.Cloud.Functions.Testing/MemoryLoggerProvider.cs

@@ -21,13 +21,18 @@ namespace Google.Cloud.Functions.Testing
     /// <summary>
     /// A logger provider that creates instances of <see cref="MemoryLogger"/>.
     /// </summary>
-    internal sealed class MemoryLoggerProvider : ILoggerProvider
+    internal sealed class MemoryLoggerProvider : ILoggerProvider, ISupportExternalScope
     {
         private readonly ConcurrentDictionary<string, MemoryLogger> _loggersByCategory =
             new ConcurrentDictionary<string, MemoryLogger>();
 
+        private IExternalScopeProvider? _scopeProvider;
+
+        void ISupportExternalScope.SetScopeProvider(IExternalScopeProvider scopeProvider) =>
+            _scopeProvider = scopeProvider;
+
         public ILogger CreateLogger(string categoryName) =>
-            _loggersByCategory.GetOrAdd(categoryName, name => new MemoryLogger(name));
+            _loggersByCategory.GetOrAdd(categoryName, name => new MemoryLogger(name, _scopeProvider));
 
         internal void Clear() => _loggersByCategory.Clear();