protected virtual void Initialize()
{
string hostLogPath = Path.Combine(ScriptConfig.RootLogPath, "Host");
FileUtility.EnsureDirectoryExists(hostLogPath);
string debugSentinelFileName = Path.Combine(hostLogPath, ScriptConstants.DebugSentinelFileName);
this.LastDebugNotify = File.GetLastWriteTime(debugSentinelFileName);
IMetricsLogger metricsLogger = ScriptConfig.HostConfig.GetService<IMetricsLogger>();
if (metricsLogger == null)
{
metricsLogger = new MetricsLogger();
ScriptConfig.HostConfig.AddService<IMetricsLogger>(metricsLogger);
}
using (metricsLogger.LatencyEvent(MetricEventNames.HostStartupLatency))
{
// read host.json and apply to JobHostConfiguration
string hostConfigFilePath = Path.Combine(ScriptConfig.RootScriptPath, ScriptConstants.HostMetadataFileName);
// If it doesn't exist, create an empty JSON file
if (!File.Exists(hostConfigFilePath))
{
File.WriteAllText(hostConfigFilePath, "{}");
}
if (ScriptConfig.HostConfig.IsDevelopment || InDebugMode)
{
// If we're in debug/development mode, use optimal debug settings
ScriptConfig.HostConfig.UseDevelopmentSettings();
}
string json = File.ReadAllText(hostConfigFilePath);
JObject hostConfig;
try
{
hostConfig = JObject.Parse(json);
}
catch (JsonException ex)
{
throw new FormatException(string.Format("Unable to parse {0} file.", ScriptConstants.HostMetadataFileName), ex);
}
ApplyConfiguration(hostConfig, ScriptConfig);
// Set up a host level TraceMonitor that will receive notification
// of ALL errors that occur. This allows us to inspect/log errors.
var traceMonitor = new TraceMonitor()
.Filter(p => { return true; })
.Subscribe(HandleHostError);
ScriptConfig.HostConfig.Tracing.Tracers.Add(traceMonitor);
TraceLevel hostTraceLevel = ScriptConfig.HostConfig.Tracing.ConsoleLevel;
if (ScriptConfig.FileLoggingMode != FileLoggingMode.Never)
{
// Host file logging is only done conditionally
string hostLogFilePath = Path.Combine(ScriptConfig.RootLogPath, "Host");
TraceWriter fileTraceWriter = new FileTraceWriter(hostLogFilePath, hostTraceLevel).Conditional(p => FileLoggingEnabled);
if (TraceWriter != null)
{
// create a composite writer so our host logs are written to both
TraceWriter = new CompositeTraceWriter(new[] { TraceWriter, fileTraceWriter });
}
else
{
TraceWriter = fileTraceWriter;
}
}
if (TraceWriter != null)
{
ScriptConfig.HostConfig.Tracing.Tracers.Add(TraceWriter);
}
else
{
// if no TraceWriter has been configured, default it to Console
TraceWriter = new ConsoleTraceWriter(hostTraceLevel);
}
_debugModeFileWatcher = new AutoRecoveringFileSystemWatcher(hostLogPath, ScriptConstants.DebugSentinelFileName,
includeSubdirectories: false, changeTypes: WatcherChangeTypes.Created | WatcherChangeTypes.Changed);
_debugModeFileWatcher.Changed += OnDebugModeFileChanged;
var storageString = AmbientConnectionStringProvider.Instance.GetConnectionString(ConnectionStringNames.Storage);
Task<BlobLeaseManager> blobManagerCreation = null;
if (storageString == null)
{
// Disable core storage
ScriptConfig.HostConfig.StorageConnectionString = null;
blobManagerCreation = Task.FromResult<BlobLeaseManager>(null);
}
else
{
blobManagerCreation = BlobLeaseManager.CreateAsync(storageString, TimeSpan.FromSeconds(15), ScriptConfig.HostConfig.HostId, InstanceId, TraceWriter);
}
var bindingProviders = LoadBindingProviders(ScriptConfig, hostConfig, TraceWriter);
ScriptConfig.BindingProviders = bindingProviders;
TraceWriter.Info(string.Format(CultureInfo.InvariantCulture, "Reading host configuration file '{0}'", hostConfigFilePath));
if (ScriptConfig.FileWatchingEnabled)
{
_scriptFileWatcher = new AutoRecoveringFileSystemWatcher(ScriptConfig.RootScriptPath);
_scriptFileWatcher.Changed += OnFileChanged;
}
// 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
// result from a bulk copy/unzip operation. In such cases, we only want to
// restart after ALL the operations are complete and there is a quiet period.
_restart = (e) =>
{
TraceWriter.Info(string.Format(CultureInfo.InvariantCulture, "File change of type '{0}' detected for '{1}'", e.ChangeType, e.FullPath));
TraceWriter.Info("Host configuration has changed. Signaling restart.");
RestartHost();
};
_restart = _restart.Debounce(500);
// take a snapshot so we can detect function additions/removals
_directoryCountSnapshot = Directory.EnumerateDirectories(ScriptConfig.RootScriptPath).Count();
List<FunctionDescriptorProvider> descriptionProviders = new List<FunctionDescriptorProvider>()
{
new ScriptFunctionDescriptorProvider(this, ScriptConfig),
new NodeFunctionDescriptorProvider(this, ScriptConfig),
new DotNetFunctionDescriptorProvider(this, ScriptConfig),
new PowerShellFunctionDescriptorProvider(this, ScriptConfig)
};
// Allow BindingProviders to initialize
foreach (var bindingProvider in ScriptConfig.BindingProviders)
{
try
{
bindingProvider.Initialize();
}
catch (Exception ex)
{
// If we're unable to initialize a binding provider for any reason, log the error
// and continue
TraceWriter.Error(string.Format("Error initializing binding provider '{0}'", bindingProvider.GetType().FullName), ex);
}
}
// Create the lease manager that will keep handle the primary host blob lease acquisition and renewal
// and subscribe for change notifications.
_blobLeaseManager = blobManagerCreation.GetAwaiter().GetResult();
if (_blobLeaseManager != null)
{
_blobLeaseManager.HasLeaseChanged += BlobLeaseManagerHasLeaseChanged;
}
// read all script functions and apply to JobHostConfiguration
Collection<FunctionDescriptor> functions = ReadFunctions(descriptionProviders);
Collection<CustomAttributeBuilder> typeAttributes = CreateTypeAttributes(ScriptConfig);
string defaultNamespace = "Host";
string typeName = string.Format(CultureInfo.InvariantCulture, "{0}.{1}", defaultNamespace, "Functions");
TraceWriter.Info(string.Format(CultureInfo.InvariantCulture, "Generating {0} job function(s)", functions.Count));
Type type = FunctionGenerator.Generate(HostAssemblyName, typeName, typeAttributes, functions);
List<Type> types = new List<Type>();
types.Add(type);
ScriptConfig.HostConfig.TypeLocator = new TypeLocator(types);
Functions = functions;
if (ScriptConfig.FileLoggingMode != FileLoggingMode.Never)
{
PurgeOldLogDirectories();
}
}
}
public async Task RecoveryTest(int expectedNumberOfAttempts, bool isFailureScenario)
{
var traceWriter = new TestTraceWriter(TraceLevel.Verbose);
using (var directory = new TempDirectory())
using (var watcher = new AutoRecoveringFileSystemWatcher(directory.Path, traceWriter: traceWriter))
{
Directory.Delete(directory.Path, true);
string fileWatcherLogPrefix = $"File watcher: ('{directory.Path}')";
// 1 trace per attempt + 1 trace per failed attempt
int expectedTracesBeforeRecovery = (expectedNumberOfAttempts * 2) - 1;
// Before + recovery trace
int expectedTracesAfterRecovery = expectedTracesBeforeRecovery + 1;
await TestHelpers.Await(() => traceWriter.Traces.Count == expectedTracesBeforeRecovery, pollingInterval: 500);
if (isFailureScenario)
{
watcher.Dispose();
}
else
{
Directory.CreateDirectory(directory.Path);
}
await TestHelpers.Await(() => traceWriter.Traces.Count == expectedTracesAfterRecovery, pollingInterval: 500);
TraceEvent failureEvent = traceWriter.Traces.First();
var retryEvents = traceWriter.Traces.Where(t => t.Level == TraceLevel.Warning).Skip(1).ToList();
Assert.Equal(TraceLevel.Warning, failureEvent.Level);
Assert.Contains("Failure detected", failureEvent.Message);
Assert.Equal(expectedNumberOfAttempts - 1, retryEvents.Count);
// Validate that our the events happened with the expected intervals
DateTime previoustTimeStamp = failureEvent.Timestamp;
for (int i = 0; i < retryEvents.Count; i++)
{
long expectedInterval = Convert.ToInt64((Math.Pow(2, i + 1) - 1) / 2);
TraceEvent currentEvent = retryEvents[i];
var actualInterval = currentEvent.Timestamp - previoustTimeStamp;
previoustTimeStamp = currentEvent.Timestamp;
Assert.Equal(expectedInterval, (int)actualInterval.TotalSeconds);
}
Assert.True(traceWriter.Traces.All(t => t.Message.StartsWith(fileWatcherLogPrefix)));
if (isFailureScenario)
{
Assert.Contains("Recovery process aborted.", traceWriter.Traces.Last().Message);
}
else
{
Assert.Contains("File watcher recovered.", traceWriter.Traces.Last().Message);
}
}
}
protected bool InitializeFileWatcherIfEnabled()
{
if (Host.ScriptConfig.FileWatchingEnabled)
{
string functionDirectory = Path.GetDirectoryName(Metadata.ScriptFile);
_fileWatcher = new AutoRecoveringFileSystemWatcher(functionDirectory);
_fileWatcher.Changed += OnScriptFileChanged;
return true;
}
return false;
}
public void FileWatcherTest(string path, Action<AutoRecoveringFileSystemWatcher> action, Func<FileSystemEventArgs, bool> changeHandler,
WatcherChangeTypes changeTypes = WatcherChangeTypes.All, bool expectEvent = true)
{
var traceWriter = new TestTraceWriter(System.Diagnostics.TraceLevel.Verbose);
using (var watcher = new AutoRecoveringFileSystemWatcher(path, traceWriter: traceWriter))
{
var resetEvent = new ManualResetEventSlim();
watcher.Changed += (s, a) =>
{
if (changeHandler(a))
{
resetEvent.Set();
}
};
action(watcher);
bool eventSignaled = resetEvent.Wait(TimeSpan.FromSeconds(5));
Assert.Equal(expectEvent, eventSignaled);
}
}