function timeout now disposes of WebHost services (#5593)

Author: brettsam

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

@@ -8,7 +8,7 @@
 
 namespace Microsoft.Azure.WebJobs.Script.WebHost.DependencyInjection
 {
-    public class WebHostServiceProvider : IServiceProvider, IServiceScopeFactory
+    public class WebHostServiceProvider : IServiceProvider, IServiceScopeFactory, IDisposable
     {
         private static readonly Rules _defaultContainerRules;
         private readonly Container _container;
@@ -50,5 +50,10 @@ public IServiceScope CreateScope()
         {
             return new JobHostServiceScope(_container.OpenScope(preferInterpretation: _container.PreferInterpretation));
         }
+
+        public void Dispose()
+        {
+            _container?.Dispose();
+        }
     }
 }

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

@@ -12,7 +12,6 @@
 using Microsoft.Azure.WebJobs.Script.Description;
 using Microsoft.Azure.WebJobs.Script.Diagnostics;
 using Microsoft.Azure.WebJobs.Script.WebHost.ContainerManagement;
-using Microsoft.Azure.WebJobs.Script.WebHost.Management;
 using Microsoft.Azure.WebJobs.Script.WebHost.Metrics;
 using Microsoft.Azure.WebJobs.Script.WebHost.Models;
 using Microsoft.Extensions.Logging;
@@ -32,11 +31,14 @@ public class MetricsEventManager : IDisposable
         private readonly object _functionActivityTrackerLockObject = new object();
         private readonly IMetricsPublisher _metricsPublisher;
         private readonly ILinuxContainerActivityPublisher _linuxContainerActivityPublisher;
+        private readonly ILogger<MetricsEventManager> _logger;
         private bool _disposed;
         private IOptionsMonitor<AppServiceOptions> _appServiceOptions;
 
-        public MetricsEventManager(IOptionsMonitor<AppServiceOptions> appServiceOptions, IEventGenerator generator, int functionActivityFlushIntervalSeconds, IMetricsPublisher metricsPublisher, ILinuxContainerActivityPublisher linuxContainerActivityPublisher, int metricsFlushIntervalMS = DefaultFlushIntervalMS)
+        public MetricsEventManager(IOptionsMonitor<AppServiceOptions> appServiceOptions, IEventGenerator generator, int functionActivityFlushIntervalSeconds, IMetricsPublisher metricsPublisher, ILinuxContainerActivityPublisher linuxContainerActivityPublisher, ILogger<MetricsEventManager> logger, int metricsFlushIntervalMS = DefaultFlushIntervalMS)
         {
+            _logger = logger ?? throw new ArgumentNullException(nameof(logger));
+
             // we read these in the ctor (not static ctor) since it can change on the fly
             _appServiceOptions = appServiceOptions;
             _eventGenerator = generator;
@@ -303,6 +305,15 @@ protected internal virtual void WriteMetricEvents(SystemMetricEvent[] metricEven
 
         protected virtual void Dispose(bool disposing)
         {
+            try
+            {
+                _logger.LogDebug($"Disposing {nameof(MetricsEventManager)}");
+            }
+            catch
+            {
+                // Best effort logging.
+            }
+
             if (!_disposed)
             {
                 if (disposing)

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

@@ -6,6 +6,7 @@
 using Microsoft.Azure.WebJobs.Script.Diagnostics;
 using Microsoft.Azure.WebJobs.Script.WebHost.ContainerManagement;
 using Microsoft.Azure.WebJobs.Script.WebHost.Metrics;
+using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Options;
 
 namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
@@ -15,8 +16,8 @@ public class WebHostMetricsLogger : IMetricsLogger, IDisposable
         private readonly MetricsEventManager _metricsEventManager;
         private bool disposed = false;
 
-        public WebHostMetricsLogger(IOptionsMonitor<AppServiceOptions> appServiceOptions, IEventGenerator eventGenerator, IMetricsPublisher metricsPublisher, ILinuxContainerActivityPublisher linuxContainerActivityPublisher)
-            : this(appServiceOptions, eventGenerator, metricsPublisher, linuxContainerActivityPublisher, 5)
+        public WebHostMetricsLogger(IOptionsMonitor<AppServiceOptions> appServiceOptions, IEventGenerator eventGenerator, IMetricsPublisher metricsPublisher, ILinuxContainerActivityPublisher linuxContainerActivityPublisher, ILoggerFactory loggerFactory)
+            : this(appServiceOptions, eventGenerator, metricsPublisher, linuxContainerActivityPublisher, 5, loggerFactory)
         {
         }
 
@@ -25,9 +26,9 @@ public WebHostMetricsLogger(MetricsEventManager eventManager)
             _metricsEventManager = eventManager;
         }
 
-        protected WebHostMetricsLogger(IOptionsMonitor<AppServiceOptions> appServiceOptions, IEventGenerator eventGenerator, IMetricsPublisher metricsPublisher, ILinuxContainerActivityPublisher linuxContainerActivityPublisher, int metricEventIntervalInSeconds)
+        protected WebHostMetricsLogger(IOptionsMonitor<AppServiceOptions> appServiceOptions, IEventGenerator eventGenerator, IMetricsPublisher metricsPublisher, ILinuxContainerActivityPublisher linuxContainerActivityPublisher, int metricEventIntervalInSeconds, ILoggerFactory loggerFactory)
         {
-            _metricsEventManager = new MetricsEventManager(appServiceOptions, eventGenerator, metricEventIntervalInSeconds, metricsPublisher, linuxContainerActivityPublisher);
+            _metricsEventManager = new MetricsEventManager(appServiceOptions, eventGenerator, metricEventIntervalInSeconds, metricsPublisher, linuxContainerActivityPublisher, loggerFactory.CreateLogger<MetricsEventManager>());
         }
 
         public object BeginEvent(string eventName, string functionName = null, string data = null)

src/WebJobs.Script.WebHost/FileMonitoringService.cs

@@ -17,6 +17,7 @@
 using Microsoft.Extensions.Hosting;
 using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Options;
+using IApplicationLifetime = Microsoft.AspNetCore.Hosting.IApplicationLifetime;
 
 namespace Microsoft.Azure.WebJobs.Script.WebHost
 {
@@ -28,6 +29,7 @@ public class FileMonitoringService : IHostedService, IDisposable
         private readonly IScriptHostManager _scriptHostManager;
         private readonly string _hostLogPath;
         private readonly ILogger _logger;
+        private readonly ILogger<FileMonitoringService> _typedLogger;
         private readonly IList<IDisposable> _eventSubscriptions = new List<IDisposable>();
         private readonly Func<Task> _restart;
         private readonly Action _shutdown;
@@ -38,6 +40,8 @@ public class FileMonitoringService : IHostedService, IDisposable
         private bool _shutdownScheduled;
         private int _restartRequested;
         private bool _disposed = false;
+        private bool _watchersStopped = false;
+        private object _stopWatchersLock = new object();
 
         public FileMonitoringService(IOptions<ScriptJobHostOptions> scriptOptions, ILoggerFactory loggerFactory, IScriptEventManager eventManager, IApplicationLifetime applicationLifetime, IScriptHostManager scriptHostManager)
         {
@@ -48,6 +52,9 @@ public FileMonitoringService(IOptions<ScriptJobHostOptions> scriptOptions, ILogg
             _hostLogPath = Path.Combine(_scriptOptions.RootLogPath, "Host");
             _logger = loggerFactory.CreateLogger(LogCategories.Startup);
 
+            // Use this for newer logs as we can't change existing categories of log messages
+            _typedLogger = loggerFactory.CreateLogger<FileMonitoringService>();
+
             // If a file change should result in a restart, we debounce the event to
             // ensure that only a single restart is triggered within a specific time window.
             // This allows us to deal with a large set of file change events that might
@@ -85,6 +92,7 @@ public Task StartAsync(CancellationToken cancellationToken)
 
         public Task StopAsync(CancellationToken cancellationToken)
         {
+            StopFileWatchers();
             return Task.CompletedTask;
         }
 
@@ -120,6 +128,40 @@ private void InitializeFileWatchers()
                         TaskContinuationOptions.OnlyOnFaulted | TaskContinuationOptions.ExecuteSynchronously)));
         }
 
+        private void StopFileWatchers()
+        {
+            lock (_stopWatchersLock)
+            {
+                if (_watchersStopped)
+                {
+                    return;
+                }
+
+                _typedLogger.LogDebug("Stopping file watchers.");
+
+                _fileEventSource?.Dispose();
+
+                if (_debugModeFileWatcher != null)
+                {
+                    _debugModeFileWatcher.Changed -= OnDebugModeFileChanged;
+                    _debugModeFileWatcher.Dispose();
+                }
+
+                if (_diagnosticModeFileWatcher != null)
+                {
+                    _diagnosticModeFileWatcher.Changed -= OnDiagnosticModeFileChanged;
+                    _diagnosticModeFileWatcher.Dispose();
+                }
+
+                foreach (var subscription in _eventSubscriptions)
+                {
+                    subscription.Dispose();
+                }
+
+                _watchersStopped = true;
+            }
+        }
+
         /// <summary>
         /// Whenever the debug sentinel file changes we update our debug timeout
         /// </summary>
@@ -264,24 +306,7 @@ protected virtual void Dispose(bool disposing)
             {
                 if (disposing)
                 {
-                    _fileEventSource?.Dispose();
-
-                    if (_debugModeFileWatcher != null)
-                    {
-                        _debugModeFileWatcher.Changed -= OnDebugModeFileChanged;
-                        _debugModeFileWatcher.Dispose();
-                    }
-
-                    if (_diagnosticModeFileWatcher != null)
-                    {
-                        _diagnosticModeFileWatcher.Changed -= OnDiagnosticModeFileChanged;
-                        _diagnosticModeFileWatcher.Dispose();
-                    }
-
-                    foreach (var subscription in _eventSubscriptions)
-                    {
-                        subscription.Dispose();
-                    }
+                    StopFileWatchers();
                 }
 
                 _disposed = true;

src/WebJobs.Script.WebHost/WebJobsScriptHostService.cs

@@ -19,6 +19,7 @@
 using Microsoft.Extensions.Hosting;
 using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Options;
+using IApplicationLifetime = Microsoft.AspNetCore.Hosting.IApplicationLifetime;
 
 namespace Microsoft.Azure.WebJobs.Script.WebHost
 {
@@ -52,7 +53,7 @@ public class WebJobsScriptHostService : IHostedService, IScriptHostManager, ISer
 
         public WebJobsScriptHostService(IOptionsMonitor<ScriptApplicationHostOptions> applicationHostOptions, IScriptHostBuilder scriptHostBuilder, ILoggerFactory loggerFactory,
             IServiceScopeFactory rootScopeFactory, IScriptWebHostEnvironment scriptWebHostEnvironment, IEnvironment environment,
-            HostPerformanceManager hostPerformanceManager, IOptions<HostHealthMonitorOptions> healthMonitorOptions, IMetricsLogger metricsLogger,  IApplicationLifetime applicationLifetime)
+            HostPerformanceManager hostPerformanceManager, IOptions<HostHealthMonitorOptions> healthMonitorOptions, IMetricsLogger metricsLogger, IApplicationLifetime applicationLifetime)
         {
             if (loggerFactory == null)
             {

src/WebJobs.Script.WebHost/WebScriptHostExceptionHandler.cs

@@ -4,9 +4,9 @@
 using System;
 using System.Runtime.ExceptionServices;
 using System.Threading.Tasks;
+using Microsoft.AspNetCore.Hosting;
 using Microsoft.Azure.WebJobs.Host;
 using Microsoft.Azure.WebJobs.Host.Timers;
-using Microsoft.Extensions.Hosting;
 using Microsoft.Extensions.Logging;
 
 namespace Microsoft.Azure.WebJobs.Script.WebHost

src/WebJobs.Script/Description/Workers/Http/HttpFunctionDescriptorProvider.cs

@@ -2,9 +2,9 @@
 // Licensed under the MIT License. See License.txt in the project root for license information.
 
 using System.Collections.Generic;
+using Microsoft.AspNetCore.Hosting;
 using Microsoft.Azure.WebJobs.Script.Extensibility;
 using Microsoft.Azure.WebJobs.Script.Workers;
-using Microsoft.Extensions.Hosting;
 using Microsoft.Extensions.Logging;
 
 namespace Microsoft.Azure.WebJobs.Script.Description

src/WebJobs.Script/Description/Workers/Rpc/RpcFunctionDescriptorProvider.cs

@@ -4,9 +4,9 @@
 using System;
 using System.Collections.Generic;
 using System.Threading.Tasks;
+using Microsoft.AspNetCore.Hosting;
 using Microsoft.Azure.WebJobs.Script.Extensibility;
 using Microsoft.Azure.WebJobs.Script.Workers;
-using Microsoft.Extensions.Hosting;
 using Microsoft.Extensions.Logging;
 
 namespace Microsoft.Azure.WebJobs.Script.Description

src/WebJobs.Script/Description/Workers/WorkerFunctionDescriptorProvider.cs

@@ -8,11 +8,11 @@
 using System.Reflection;
 using System.Reflection.Emit;
 using System.Threading.Tasks;
+using Microsoft.AspNetCore.Hosting;
 using Microsoft.Azure.WebJobs.Description;
 using Microsoft.Azure.WebJobs.Script.Binding;
 using Microsoft.Azure.WebJobs.Script.Extensibility;
 using Microsoft.Azure.WebJobs.Script.Workers;
-using Microsoft.Extensions.Hosting;
 using Microsoft.Extensions.Logging;
 
 namespace Microsoft.Azure.WebJobs.Script.Description

src/WebJobs.Script/Description/Workers/WorkerFunctionInvoker.cs

@@ -10,10 +10,10 @@
 using System.Reactive.Linq;
 using System.Threading;
 using System.Threading.Tasks;
+using Microsoft.AspNetCore.Hosting;
 using Microsoft.Azure.WebJobs.Script.Binding;
 using Microsoft.Azure.WebJobs.Script.Workers;
 using Microsoft.CodeAnalysis;
-using Microsoft.Extensions.Hosting;
 using Microsoft.Extensions.Logging;
 using Newtonsoft.Json.Linq;