Add keyed ILogger which forwards to ScriptHost when possible (#11398)

* Add keyed ILogger which forwards to ScriptHost when possible

Add mechanism to forward logs from WebHost to ScriptHost

* Suppress warning in test

* Add caching to ForwardingLoggerFactory

* Skip copying ILoggerFactory

* Update release_notes.md

* Rearrange some serivce setup. Fix tests

* Move dependency setup back to AddTelemetryPublisher

* Address PR feedback

* Fix merge/build issues

* Fix warning

Author: jviau

release_notes.md

@@ -6,6 +6,7 @@
 - Emit diagnostic warning for deprecated Azure Functions Proxies usage (#11405)
 - Update Python Worker Version to [4.40.2](https://github.com/Azure/azure-functions-python-worker/releases/tag/4.40.2)
 - Add JitTrace Files for v4.1044
+- Send `TelemetryHealthCheckPublisher` logs to ScriptHost `ILogger` (#11398)
 - Implementing a resolver that resolves worker configurations from specified probing paths (#11258)
 - Remove duplicate function names from sync triggers payload(#11371)
 - Avoid emitting empty tag values for health check metrics (#11393)

src/WebJobs.Script.WebHost/DependencyInjection/ServiceProviderExtensions.cs

@@ -27,6 +27,8 @@ public static class ServiceProviderExtensions
             typeof(IManagedHostedService), // These shouldn't be instantiated twice
             typeof(IHostedService),        // These shouldn't be instantiated twice
             typeof(ILoggerProvider),       // These shouldn't be instantiated twice
+            typeof(ILoggerFactory),        // WebHost has a keyed implementation which will fail propagation. ScriptHost registers its own anyways.
+            typeof(ILogger<>),             // Same reason as ILoggerFactory.
             typeof(HealthCheckService),    // Child container should instantiate its own.
             typeof(IConfigureOptions<HealthCheckServiceOptions>), // Child container should instantiate its own.
             typeof(IPostConfigureOptions<HealthCheckServiceOptions>), // Child container should instantiate its own.

src/WebJobs.Script.WebHost/Diagnostics/ILoggingBuilderExtensions.cs

@@ -1,19 +1,23 @@
-// Copyright (c) .NET Foundation. All rights reserved.
+// Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the MIT License. See License.txt in the project root for license information.
 
 using Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics;
 using Microsoft.Extensions.DependencyInjection;
 
+#nullable enable
+
 namespace Microsoft.Extensions.Logging
 {
     public static class ILoggingBuilderExtensions
     {
-        public static void AddWebJobsSystem<T>(this ILoggingBuilder builder) where T : SystemLoggerProvider
+        public static ILoggingBuilder AddWebJobsSystem<T>(this ILoggingBuilder builder)
+            where T : SystemLoggerProvider
         {
             builder.Services.AddSingleton<ILoggerProvider, T>();
 
             // Log all logs to SystemLogger
             builder.AddDefaultWebJobsFilters<T>(LogLevel.Trace);
+            return builder;
         }
     }
 }

src/WebJobs.Script.WebHost/Program.cs

@@ -1,4 +1,4 @@
-// Copyright (c) .NET Foundation. All rights reserved.
+// Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the MIT License. See License.txt in the project root for license information.
 
 using System;
@@ -88,6 +88,7 @@ public static IWebHostBuilder CreateWebHostBuilder(string[] args = null)
 
                     loggingBuilder.AddDefaultWebJobsFilters();
                     loggingBuilder.AddWebJobsSystem<WebHostSystemLoggerProvider>();
+                    loggingBuilder.AddForwardingLogger();
                     loggingBuilder.Services.AddSingleton<DeferredLoggerProvider>();
                     loggingBuilder.Services.AddSingleton<ILoggerProvider>(s => s.GetRequiredService<DeferredLoggerProvider>());
                     loggingBuilder.Services.AddSingleton<ISystemLoggerFactory, SystemLoggerFactory>();

src/WebJobs.Script.WebHost/WebHostServiceCollectionExtensions.cs

@@ -251,6 +251,7 @@ public static void AddWebJobsScriptHost(this IServiceCollection services, IConfi
             services.AddAzureStorageProviders();
 
             // Add health checks
+            services.AddMetrics();
             services.AddHealthChecks().AddWebJobsScriptHealthChecks();
         }
 

src/WebJobs.Script/Diagnostics/ForwardingLogger.cs

@@ -0,0 +1,110 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using System;
+using System.Diagnostics;
+using System.Diagnostics.CodeAnalysis;
+using Microsoft.Azure.WebJobs.Script;
+using Microsoft.Extensions.DependencyInjection;
+
+#nullable enable
+
+namespace Microsoft.Extensions.Logging
+{
+    internal sealed class ForwardingLogger : ILogger
+    {
+        // The service key to use for dependency injection to get forwarding loggers.
+        public const string ServiceKey = "Forwarding";
+
+        private readonly string _categoryName;
+        private readonly ILogger _fallback;
+        private readonly IScriptHostManager _manager;
+
+        // We use weak references so as to not keep a ScriptHost alive after it shuts down.
+        private readonly WeakReference<ILogger> _current = new(null!);
+        private readonly WeakReference<IServiceProvider> _services = new(null!);
+
+        public ForwardingLogger(string categoryName, ILogger inner, IScriptHostManager manager)
+        {
+            ArgumentNullException.ThrowIfNull(inner);
+            ArgumentNullException.ThrowIfNull(manager);
+            _categoryName = categoryName;
+            _fallback = inner;
+            _manager = manager;
+        }
+
+        private ILogger Current
+        {
+            get
+            {
+                if (TryGetCurrentLogger(out ILogger? logger))
+                {
+                    return logger;
+                }
+
+                // No current ScriptHost logger, or the ScriptHost is gone. Use the fallback WebHost logger.
+                return _fallback;
+            }
+        }
+
+        public IDisposable? BeginScope<TState>(TState state)
+            where TState : notnull
+            => Current.BeginScope(state);
+
+        public bool IsEnabled(LogLevel logLevel) => Current.IsEnabled(logLevel);
+
+        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
+            => Current.Log(logLevel, eventId, state, exception, formatter);
+
+        private bool TryGetCurrentLogger([NotNullWhen(true)] out ILogger? logger)
+        {
+            if (IsLoggerCurrent(out logger))
+            {
+                return true;
+            }
+            else if (_manager.Services is { } services)
+            {
+                logger = services.GetRequiredService<ILoggerFactory>().CreateLogger(_categoryName);
+                _services.SetTarget(services);
+                _current.SetTarget(logger);
+                return true;
+            }
+
+            logger = null;
+            return false;
+        }
+
+        private bool IsLoggerCurrent([NotNullWhen(true)] out ILogger? logger)
+        {
+            // First check if the last IServiceProvider we used is still active.
+            if (_services.TryGetTarget(out IServiceProvider? services)
+                && ReferenceEquals(services, _manager.Services))
+            {
+                // Service provider is still correct, so our logger is current.
+                return _current.TryGetTarget(out logger);
+            }
+
+            logger = null;
+            return false;
+        }
+    }
+
+    [DebuggerDisplay("{_logger}")]
+    internal sealed class ForwardingLogger<T> : ILogger<T>
+    {
+        private readonly ILogger _logger;
+
+        public ForwardingLogger([ForwardingLogger] ILoggerFactory factory)
+        {
+            ArgumentNullException.ThrowIfNull(factory);
+            _logger = factory.CreateLogger<T>();
+        }
+
+        IDisposable? ILogger.BeginScope<TState>(TState state) => _logger.BeginScope(state);
+
+        bool ILogger.IsEnabled(LogLevel logLevel) => _logger.IsEnabled(logLevel);
+
+        void ILogger.Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter) =>
+            _logger.Log(logLevel, eventId, state, exception, formatter);
+    }
+}

src/WebJobs.Script/Diagnostics/ForwardingLoggerAttribute.cs

@@ -0,0 +1,14 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using System;
+using Microsoft.Extensions.DependencyInjection;
+
+namespace Microsoft.Extensions.Logging
+{
+    [AttributeUsage(AttributeTargets.Parameter)]
+    internal class ForwardingLoggerAttribute()
+        : FromKeyedServicesAttribute(ForwardingLogger.ServiceKey)
+    {
+    }
+}

src/WebJobs.Script/Diagnostics/ForwardingLoggerFactory.cs

@@ -0,0 +1,60 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using System;
+using System.Collections.Concurrent;
+using System.Diagnostics;
+using Microsoft.Azure.WebJobs.Script;
+
+#nullable enable
+
+namespace Microsoft.Extensions.Logging
+{
+    /// <summary>
+    /// A logger factory that creates loggers which track the current active ScriptHost (if any), falling
+    /// back to the WebHost logger if no ScriptHost is active.
+    /// </summary>
+    [DebuggerDisplay(@"InnerFactory = {_inner}, ScriptHostState = {_manager.State}")]
+    public sealed class ForwardingLoggerFactory : ILoggerFactory
+    {
+        private readonly ConcurrentDictionary<string, ForwardingLogger> _loggers = new(StringComparer.Ordinal);
+        private readonly ILoggerFactory _inner;
+        private readonly IScriptHostManager _manager;
+
+        private bool _disposed;
+
+        public ForwardingLoggerFactory(ILoggerFactory inner, IScriptHostManager manager)
+        {
+            ArgumentNullException.ThrowIfNull(inner);
+            ArgumentNullException.ThrowIfNull(manager);
+            _inner = inner;
+            _manager = manager;
+        }
+
+        /// <inheritdoc />
+        public void AddProvider(ILoggerProvider provider)
+            => throw new NotSupportedException(
+                $"{nameof(ILoggerProvider)} can not be added to the {nameof(ForwardingLoggerFactory)}.");
+
+        /// <inheritdoc />
+        public ILogger CreateLogger(string categoryName)
+        {
+            ObjectDisposedException.ThrowIf(_disposed, this);
+
+            ForwardingLogger CreateLoggerImpl(string categoryName)
+            {
+                ILogger innerLogger = _inner.CreateLogger(categoryName);
+                return new ForwardingLogger(categoryName, innerLogger, _manager);
+            }
+
+            return _loggers.GetOrAdd(categoryName, CreateLoggerImpl);
+        }
+
+        /// <inheritdoc />
+        public void Dispose()
+        {
+            // this is just to block further logger creation.
+            _disposed = true;
+        }
+    }
+}

src/WebJobs.Script/Diagnostics/HealthChecks/DynamicHealthCheckService.cs

@@ -92,7 +92,7 @@ private HealthReport MergeReports(HealthReport left, HealthReport? right)
             Func<HealthCheckRegistration, bool>? predicate,
             CancellationToken cancellationToken = default)
         {
-            HealthCheckService? scriptHostCheck = _manager.Services.GetService<HealthCheckService>();
+            HealthCheckService? scriptHostCheck = _manager.Services?.GetService<HealthCheckService>();
             if (scriptHostCheck is null)
             {
                 Log.ScriptHostNoHealthCheckService(_logger);

src/WebJobs.Script/Diagnostics/HealthChecks/HealthCheckExtensions.cs

@@ -6,6 +6,7 @@
 using System.Linq;
 using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Diagnostics.HealthChecks;
+using Microsoft.Extensions.Logging;
 
 namespace Microsoft.Azure.WebJobs.Script.Diagnostics.HealthChecks
 {
@@ -82,8 +83,8 @@ static void RegisterPublisher(IServiceCollection services, string tag)
                 });
             }
 
-            builder.Services.AddLogging();
             builder.Services.AddMetrics();
+            builder.Services.AddLogging(b => b.AddForwardingLogger());
             builder.Services.AddSingleton<HealthCheckMetrics>();
             RegisterPublisher(builder.Services, null); // always register the default publisher