HostHealthMonitor improvements / reactivation

Author: mathewc

sample/host.json

@@ -22,5 +22,12 @@
         "prefetchCount": 1000,
         "batchCheckpointFrequency": 1
     },
+    "healthMonitor": {
+        "enabled": true,
+        "healthCheckInterval": "00:00:10",
+        "healthCheckWindow": "00:02:00",
+        "healthCheckThreshold": 6,
+        "counterThreshold": 0.80
+    },
     "functionTimeout": "00:05:00"
 }

src/WebJobs.Script/Config/HostHealthMonitorConfiguration.cs

@@ -0,0 +1,54 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using System;
+
+namespace Microsoft.Azure.WebJobs.Script
+{
+    public class HostHealthMonitorConfiguration
+    {
+        internal const float DefaultCounterThreshold = 0.80F;
+
+        public HostHealthMonitorConfiguration()
+        {
+            Enabled = true;
+
+            // these default numbers translate to a 50% health rating
+            // over the window.
+            HealthCheckInterval = TimeSpan.FromSeconds(10);
+            HealthCheckWindow = TimeSpan.FromMinutes(2);
+            HealthCheckThreshold = 6;
+            CounterThreshold = DefaultCounterThreshold;
+        }
+
+        /// <summary>
+        /// Gets or sets a value indicating whether host health monitoring
+        /// is enabled.
+        /// </summary>
+        public bool Enabled { get; set; }
+
+        /// <summary>
+        /// Gets or sets the interval at which host health will be checked
+        /// for threshold overages.
+        /// </summary>
+        public TimeSpan HealthCheckInterval { get; set; }
+
+        /// <summary>
+        /// Gets or sets a value defining the sliding time window
+        /// that <see cref="HealthCheckThreshold"/> applies to.
+        /// </summary>
+        public TimeSpan HealthCheckWindow { get; set; }
+
+        /// <summary>
+        /// Gets or sets the threshold for the <see cref="HealthCheckWindow"/>.
+        /// When the host has been unhealthy a number of times exceeding this
+        /// threshold, the host app domain will be recycled in an attempt to recover.
+        /// </summary>
+        public int HealthCheckThreshold { get; set; }
+
+        /// <summary>
+        /// Gets or sets the counter threshold for all counters.
+        /// </summary>
+        public float CounterThreshold { get; set; }
+    }
+}

src/WebJobs.Script/Config/ScriptHostConfiguration.cs

@@ -24,7 +24,7 @@ public ScriptHostConfiguration()
             LogFilter = new LogCategoryFilter();
             RootExtensionsPath = ConfigurationManager.AppSettings[EnvironmentSettingNames.AzureWebJobsExtensionsPath];
             LoggerFactoryBuilder = new DefaultLoggerFactoryBuilder();
-            HostHealthMonitorEnabled = true;
+            HostHealthMonitor = new HostHealthMonitorConfiguration();
         }
 
         /// <summary>
@@ -95,12 +95,6 @@ public ScriptHostConfiguration()
         /// </summary>
         public bool SwaggerEnabled { get; set; }
 
-        /// <summary>
-        /// Gets or sets a value indicating whether the hosting environment will be monitored
-        /// for health (e.g. socket thresholds, etc.). Default is true.
-        /// </summary>
-        public bool HostHealthMonitorEnabled { get; set; }
-
         /// <summary>
         /// Gets or sets a value indicating whether the host is running
         /// outside of the normal Azure hosting environment. E.g. when running
@@ -135,5 +129,10 @@ public ScriptHostConfiguration()
         /// Gets or sets a test hook for modifying the configuration after host.json has been processed.
         /// </summary>
         internal Action<ScriptHostConfiguration> OnConfigurationApplied { get; set; }
+
+        /// <summary>
+        /// Gets the <see cref="HostHealthMonitorConfiguration"/> to use.
+        /// </summary>
+        public HostHealthMonitorConfiguration HostHealthMonitor { get; }
     }
 }

src/WebJobs.Script/GlobalSuppressions.cs

@@ -238,4 +238,5 @@
 [assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Naming", "CA1709:IdentifiersShouldBeCasedCorrectly", MessageId = "Io", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.Scale.ApplicationPerformanceCounters.#WriteIoBytes")]
 [assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Naming", "CA1709:IdentifiersShouldBeCasedCorrectly", MessageId = "Io", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.Scale.ApplicationPerformanceCounters.#OtherIoBytes")]
 [assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Reliability", "CA2000:Dispose objects before losing scope", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.ScriptHostManager.#.ctor(Microsoft.Azure.WebJobs.Script.ScriptHostConfiguration,Microsoft.Azure.WebJobs.Script.Config.ScriptSettingsManager,Microsoft.Azure.WebJobs.Script.IScriptHostFactory,Microsoft.Azure.WebJobs.Script.Eventing.IScriptEventManager,Microsoft.Azure.WebJobs.Script.IScriptHostEnvironment,Microsoft.Azure.WebJobs.Script.Scale.HostPerformanceManager)")]
-[assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Usage", "CA2213:DisposableFieldsShouldBeDisposed", MessageId = "_hostHealthCheckTimer", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.ScriptHostManager.#Dispose(System.Boolean)")]
+[assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Usage", "CA2213:DisposableFieldsShouldBeDisposed", MessageId = "_hostHealthCheckTimer", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.ScriptHostManager.#Dispose(System.Boolean)")]
+[assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Maintainability", "CA1502:AvoidExcessiveComplexity", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.ScriptHostManager.#RunAndBlock(System.Threading.CancellationToken)")]

src/WebJobs.Script/Host/ScriptHost.cs

@@ -48,7 +48,7 @@ public class ScriptHost : JobHost
         private static readonly string[] WellKnownHostJsonProperties = new[]
         {
             "id", "functionTimeout", "http", "watchDirectories", "functions", "queues", "serviceBus",
-            "eventHub", "tracing", "singleton", "logger", "aggregator", "applicationInsights"
+            "eventHub", "tracing", "singleton", "logger", "aggregator", "applicationInsights", "healthMonitor"
         };
 
         private string _instanceId;
@@ -100,6 +100,8 @@ protected internal ScriptHost(IScriptHostEnvironment environment,
             _proxyClient = proxyClient;
         }
 
+        public event EventHandler HostInitializing;
+
         public event EventHandler HostInitialized;
 
         public event EventHandler HostStarted;
@@ -269,7 +271,10 @@ internal static void AddFunctionError(Dictionary<string, Collection<string>> fun
             await base.CallAsync(method, arguments, cancellationToken);
         }
 
-        protected virtual void Initialize()
+        /// <summary>
+        /// Performs all required initialization on the host. Must be called before the host is started.
+        /// </summary>
+        public void Initialize()
         {
             FileUtility.EnsureDirectoryExists(ScriptConfig.RootScriptPath);
             string hostLogPath = Path.Combine(ScriptConfig.RootLogPath, "Host");
@@ -298,19 +303,6 @@ protected virtual void Initialize()
                     _hostConfig.UseDevelopmentSettings();
                 }
 
-                // Ensure we always have an ILoggerFactory,
-                // regardless of whether AppInsights is registered or not
-                if (_hostConfig.LoggerFactory == null)
-                {
-                    _hostConfig.LoggerFactory = new LoggerFactory();
-
-                    // If we've created the LoggerFactory, then we are responsible for
-                    // disposing. Store this locally for disposal later. We can't rely
-                    // on accessing this directly from ScriptConfig.HostConfig as the
-                    // ScriptConfig is re-used for every host.
-                    _loggerFactory = _hostConfig.LoggerFactory;
-                }
-
                 Func<string, FunctionDescriptor> funcLookup = (name) => this.GetFunctionOrNull(name);
                 _hostConfig.AddService(funcLookup);
 
@@ -349,6 +341,16 @@ protected virtual void Initialize()
                     TraceWriter = new ConsoleTraceWriter(hostTraceLevel);
                 }
 
+                // Before configuration has been fully read, configure a default logger factory
+                // to ensure we can log any configuration errors. There's no filters at this point,
+                // but that's okay since we can't build filters until we apply configuration below.
+                // We'll recreate the loggers after config is read. We initialize the public logger
+                // to the startup logger until we've read configuration settings and can create the real logger.
+                // The "startup" logger is used in this class for startup related logs. The public logger is used
+                // for all other logging after startup.
+                ConfigureLoggerFactory();
+                Logger = _startupLogger = _hostConfig.LoggerFactory.CreateLogger(LogCategories.Startup);
+
                 string readingFileMessage = string.Format(CultureInfo.InvariantCulture, "Reading host configuration file '{0}'", hostConfigFilePath);
                 TraceWriter.Info(readingFileMessage);
 
@@ -360,41 +362,29 @@ protected virtual void Initialize()
                 }
                 catch (JsonException ex)
                 {
-                    // If there's a parsing error, set up the logger and write out the previous messages so that they're
-                    // discoverable in Application Insights. There's no filter, but that's okay since we cannot parse host.json to
-                    // determine how to build the filtler.
-                    ConfigureDefaultLoggerFactory();
-                    ILogger startupErrorLogger = _hostConfig.LoggerFactory.CreateLogger(LogCategories.Startup);
-                    startupErrorLogger.LogInformation(readingFileMessage);
-
+                    // If there's a parsing error, write out the previous messages without filters to ensure
+                    // they're logged
+                    _startupLogger.LogInformation(readingFileMessage);
                     throw new FormatException(string.Format("Unable to parse {0} file.", ScriptConstants.HostMetadataFileName), ex);
                 }
 
                 string sanitizedJson = SanitizeHostJson(hostConfigObject);
                 string readFileMessage = $"Host configuration file read:{Environment.NewLine}{sanitizedJson}";
                 TraceWriter.Info(readFileMessage);
 
-                try
-                {
-                    ApplyConfiguration(hostConfigObject, ScriptConfig);
-                }
-                catch (Exception)
-                {
-                    // If we have an error applying the configuration (for example, a value is invalid),
-                    // make sure we have a default LoggerFactory so that the error log can be written.
-                    ConfigureDefaultLoggerFactory();
-                    throw;
-                }
+                ApplyConfiguration(hostConfigObject, ScriptConfig);
+
+                // now the configuration has been read and applied re-create the logger
+                // factory and loggers ensuring that filters and settings have been applied
+                ConfigureLoggerFactory(recreate: true);
+                _startupLogger = _hostConfig.LoggerFactory.CreateLogger(LogCategories.Startup);
+                Logger = _hostConfig.LoggerFactory.CreateLogger(ScriptConstants.LogCategoryHostGeneral);
 
                 // Allow tests to modify anything initialized by host.json
                 ScriptConfig.OnConfigurationApplied?.Invoke(ScriptConfig);
 
-                ConfigureDefaultLoggerFactory();
-
-                // Use the startupLogger in this class as it is concerned with startup. The public Logger is used
-                // for all other logging after startup.
-                _startupLogger = _hostConfig.LoggerFactory.CreateLogger(LogCategories.Startup);
-                Logger = _hostConfig.LoggerFactory.CreateLogger(ScriptConstants.LogCategoryHostGeneral);
+                // only after configuration has been applied and loggers have been created, raise the initializing event
+                HostInitializing?.Invoke(this, EventArgs.Empty);
 
                 // Do not log these until after all the configuration is done so the proper filters are applied.
                 _startupLogger.LogInformation(readingFileMessage);
@@ -645,8 +635,21 @@ private IMetricsLogger CreateMetricsLogger()
             return metricsLogger;
         }
 
-        private void ConfigureDefaultLoggerFactory()
+        private void ConfigureLoggerFactory(bool recreate = false)
         {
+            // Ensure we always have an ILoggerFactory,
+            // regardless of whether AppInsights is registered or not
+            if (recreate || _hostConfig.LoggerFactory == null)
+            {
+                _hostConfig.LoggerFactory = new LoggerFactory();
+
+                // If we've created the LoggerFactory, then we are responsible for
+                // disposing. Store this locally for disposal later. We can't rely
+                // on accessing this directly from ScriptConfig.HostConfig as the
+                // ScriptConfig is re-used for every host.
+                _loggerFactory = _hostConfig.LoggerFactory;
+            }
+
             ConfigureLoggerFactory(ScriptConfig, FunctionTraceWriterFactory, _settingsManager, () => FileLoggingEnabled);
         }
 
@@ -801,28 +804,6 @@ private void PurgeOldLogDirectories()
             }
         }
 
-        public static ScriptHost Create(IScriptHostEnvironment environment, IScriptEventManager eventManager,
-            ScriptHostConfiguration scriptConfig = null, ScriptSettingsManager settingsManager = null, ProxyClientExecutor proxyClient = null)
-        {
-            ScriptHost scriptHost = new ScriptHost(environment, eventManager, scriptConfig, settingsManager, proxyClient);
-            try
-            {
-                scriptHost.Initialize();
-            }
-            catch (Exception ex)
-            {
-                string errorMsg = "ScriptHost initialization failed";
-                scriptHost.TraceWriter?.Error(errorMsg, ex);
-
-                ILogger logger = scriptConfig?.HostConfig?.LoggerFactory?.CreateLogger(LogCategories.Startup);
-                logger?.LogError(0, ex, errorMsg);
-
-                throw;
-            }
-
-            return scriptHost;
-        }
-
         private static Collection<ScriptBindingProvider> LoadBindingProviders(ScriptHostConfiguration config, JObject hostMetadata, TraceWriter traceWriter, ILogger logger, IEnumerable<string> usedBindingTypes)
         {
             JobHostConfiguration hostConfig = config.HostConfig;
@@ -1401,12 +1382,6 @@ internal static void ApplyConfiguration(JObject config, ScriptHostConfiguration
                 }
             }
 
-            JToken hostHealthMonitorEnabled = (JToken)config["hostHealthMonitorEnabled"];
-            if (hostHealthMonitorEnabled != null && hostHealthMonitorEnabled.Type == JTokenType.Boolean)
-            {
-                scriptConfig.HostHealthMonitorEnabled = (bool)hostHealthMonitorEnabled;
-            }
-
             // Apply Singleton configuration
             JObject configSection = (JObject)config["singleton"];
             JToken value = null;
@@ -1434,6 +1409,33 @@ internal static void ApplyConfiguration(JObject config, ScriptHostConfiguration
                 }
             }
 
+            // Apply Host Health Montitor configuration
+            configSection = (JObject)config["healthMonitor"];
+            value = null;
+            if (configSection != null)
+            {
+                if (configSection.TryGetValue("enabled", out value) && value.Type == JTokenType.Boolean)
+                {
+                    scriptConfig.HostHealthMonitor.Enabled = (bool)value;
+                }
+                if (configSection.TryGetValue("healthCheckInterval", out value))
+                {
+                    scriptConfig.HostHealthMonitor.HealthCheckInterval = TimeSpan.Parse((string)value, CultureInfo.InvariantCulture);
+                }
+                if (configSection.TryGetValue("healthCheckWindow", out value))
+                {
+                    scriptConfig.HostHealthMonitor.HealthCheckWindow = TimeSpan.Parse((string)value, CultureInfo.InvariantCulture);
+                }
+                if (configSection.TryGetValue("healthCheckThreshold", out value))
+                {
+                    scriptConfig.HostHealthMonitor.HealthCheckThreshold = (int)value;
+                }
+                if (configSection.TryGetValue("counterThreshold", out value))
+                {
+                    scriptConfig.HostHealthMonitor.CounterThreshold = (float)value;
+                }
+            }
+
             // Apply Tracing/Logging configuration
             configSection = (JObject)config["tracing"];
             if (configSection != null)

src/WebJobs.Script/Host/ScriptHostFactory.cs

@@ -10,7 +10,7 @@ public sealed class ScriptHostFactory : IScriptHostFactory
     {
         public ScriptHost Create(IScriptHostEnvironment environment, IScriptEventManager eventManager, ScriptSettingsManager settingsManager, ScriptHostConfiguration config)
         {
-            return ScriptHost.Create(environment, eventManager, config, settingsManager);
+           return new ScriptHost(environment, eventManager, config, settingsManager);
         }
     }
 }