diff --git a/release_notes.md b/release_notes.md index 7f2d3d806a..347491a6b4 100644 --- a/release_notes.md +++ b/release_notes.md @@ -1,9 +1,9 @@ -### Release notes - - -- Add JitTrace Files for v4.1042 -- Updating OTel related nuget packages (#11216) -- Moving to version 1.5.7 of Microsoft.Azure.AppService.Middleware.Functions (https://github.com/Azure/azure-functions-host/pull/11231) - +### Release notes + + +- Add JitTrace Files for v4.1042 +- Updating OTel related nuget packages (#11216) +- Moving to version 1.5.7 of Microsoft.Azure.AppService.Middleware.Functions (https://github.com/Azure/azure-functions-host/pull/11231) +- Adding restart reason to the logs (#11191) \ No newline at end of file diff --git a/src/WebJobs.Script.Grpc/Channel/GrpcWorkerChannel.cs b/src/WebJobs.Script.Grpc/Channel/GrpcWorkerChannel.cs index 7b897bfea0..a04ab581af 100644 --- a/src/WebJobs.Script.Grpc/Channel/GrpcWorkerChannel.cs +++ b/src/WebJobs.Script.Grpc/Channel/GrpcWorkerChannel.cs @@ -140,7 +140,7 @@ internal GrpcWorkerChannel( _eventSubscriptions.Add(_eventManager.OfType() .Where(msg => _workerConfig.Description.Extensions.Contains(Path.GetExtension(msg.FileChangeArguments.FullPath))) .Throttle(TimeSpan.FromMilliseconds(300)) // debounce - .Subscribe(msg => _eventManager.Publish(new HostRestartEvent()))); + .Subscribe(msg => _eventManager.Publish(new HostRestartEvent($"Worker monitored file changed: '{msg.FileChangeArguments.Name}'.")))); _startLatencyMetric = metricsLogger?.LatencyEvent(string.Format(MetricEventNames.WorkerInitializeLatency, workerConfig.Description.Language, attemptCount)); diff --git a/src/WebJobs.Script.WebHost/Controllers/HostController.cs b/src/WebJobs.Script.WebHost/Controllers/HostController.cs index 0dbd778c3e..4dfa22b40d 100644 --- a/src/WebJobs.Script.WebHost/Controllers/HostController.cs +++ b/src/WebJobs.Script.WebHost/Controllers/HostController.cs @@ -290,7 +290,7 @@ public async Task Resume([FromServices] IScriptHostManager script if (drainModeManager.IsDrainModeEnabled) { _logger.LogDebug("Starting a new host"); - await scriptHostManager.RestartHostAsync(); + await scriptHostManager.RestartHostAsync("Resuming from drain mode.", CancellationToken.None); } var status = new ResumeStatus { State = scriptHostManager.State }; @@ -451,7 +451,7 @@ public async Task GetTriggers() [Authorize(Policy = PolicyNames.AdminAuthLevel)] public IActionResult Restart([FromServices] IScriptHostManager hostManager) { - Task ignore = hostManager.RestartHostAsync(); + Task ignore = hostManager.RestartHostAsync("Restart API called."); var hostOptionsValue = _applicationHostOptions.Value; var response = new HostRestartResponse() diff --git a/src/WebJobs.Script.WebHost/Diagnostics/Extensions/ScriptHostServiceLoggerExtension.cs b/src/WebJobs.Script.WebHost/Diagnostics/Extensions/ScriptHostServiceLoggerExtension.cs index ed2729a063..b44e9d8179 100644 --- a/src/WebJobs.Script.WebHost/Diagnostics/Extensions/ScriptHostServiceLoggerExtension.cs +++ b/src/WebJobs.Script.WebHost/Diagnostics/Extensions/ScriptHostServiceLoggerExtension.cs @@ -126,11 +126,11 @@ public static class ScriptHostServiceLoggerExtension new EventId(518, nameof(ActiveHostChanging)), "Active host changing from '{oldHostInstanceId}' to '{newHostInstanceId}'."); - private static readonly Action _enteringRestart = - LoggerMessage.Define( + private static readonly Action _enteringRestart = + LoggerMessage.Define( LogLevel.Debug, new EventId(519, nameof(EnteringRestart)), - "Restart requested."); + "Restart requested. Reason '{restartReason}'"); private static readonly Action _restartBeforeStart = LoggerMessage.Define( @@ -321,9 +321,9 @@ public static void ActiveHostChanging(this ILogger logger, string oldHostInstanc _activeHostChanging(logger, oldHostInstanceId, newHostInstanceId, null); } - public static void EnteringRestart(this ILogger logger) + public static void EnteringRestart(this ILogger logger, string reason) { - _enteringRestart(logger, null); + _enteringRestart(logger, reason, null); } public static void RestartBeforeStart(this ILogger logger) diff --git a/src/WebJobs.Script.WebHost/FileMonitoringService.cs b/src/WebJobs.Script.WebHost/FileMonitoringService.cs index f872ed2373..2449471fcc 100644 --- a/src/WebJobs.Script.WebHost/FileMonitoringService.cs +++ b/src/WebJobs.Script.WebHost/FileMonitoringService.cs @@ -32,7 +32,7 @@ public class FileMonitoringService : IFileMonitoringService, IDisposable private readonly ILogger _logger; private readonly ILogger _typedLogger; private readonly IList _eventSubscriptions = new List(); - private readonly Func _restart; + private readonly Func _restart; private readonly Action _shutdown; private readonly ImmutableArray _rootDirectorySnapshot; private AutoRecoveringFileSystemWatcher _debugModeFileWatcher; @@ -112,12 +112,12 @@ private void ResumeRestartIfScheduled() using (System.Threading.ExecutionContext.SuppressFlow()) { _typedLogger.LogDebug("Resuming scheduled restart."); - Task.Run(async () => await ScheduleRestartAsync()); + Task.Run(async () => await ScheduleRestartAsync("Resuming scheduled restart.")); } } } - private async Task ScheduleRestartAsync(bool shutdown) + private async Task ScheduleRestartAsync(string reason, bool shutdown) { _restartScheduled = true; if (shutdown) @@ -125,14 +125,14 @@ private async Task ScheduleRestartAsync(bool shutdown) _shutdownScheduled = true; } - await ScheduleRestartAsync(); + await ScheduleRestartAsync(reason); } - private async Task ScheduleRestartAsync() + private async Task ScheduleRestartAsync(string reason) { if (Interlocked.Read(ref _suspensionRequestsCount) > 0) { - _logger.LogDebug("Restart requested while currently suspended. Ignoring request."); + _logger.LogDebug("Restart requested while currently suspended. Reason: '{Reason}'. Ignoring request.", reason); } else { @@ -142,7 +142,7 @@ private async Task ScheduleRestartAsync() } else { - await _restart(); + await _restart(reason); } } } @@ -164,14 +164,18 @@ private void InitializeFileWatchers() } _eventSubscriptions.Add(_eventManager.OfType() - .Subscribe((msg) => ScheduleRestartAsync(false) - .ContinueWith(t => _logger.LogCritical(t.Exception.Message), - TaskContinuationOptions.OnlyOnFaulted | TaskContinuationOptions.ExecuteSynchronously))); + .Subscribe(HandleHostRestartEvent)); // Delay starting up for logging and debug file watchers to avoid long start up times Utility.ExecuteAfterColdStartDelay(_environment, InitializeSecondaryFileWatchers); } + private void HandleHostRestartEvent(HostRestartEvent restartEvent) + { + ScheduleRestartAsync($"Handling {nameof(HostRestartEvent)} ('{restartEvent.Name}':'{restartEvent.Source}'). Reason: {restartEvent.Reason}", false) + .ContinueWith(t => _logger.LogCritical(t.Exception?.Message), TaskContinuationOptions.OnlyOnFaulted | TaskContinuationOptions.ExecuteSynchronously); + } + /// /// Initializes the file and directory monitoring that does not need to happen as part of a Host startup /// These watchers can be started after a delay to avoid startup performance issue @@ -293,7 +297,8 @@ private void OnFileChanged(FileSystemEventArgs e) changeDescription = "File"; if (File.Exists(e.FullPath)) { - TraceFileChangeRestart(changeDescription, e.ChangeType.ToString(), e.FullPath, isShutdown: true); + string fileChangeMsg = string.Format(CultureInfo.InvariantCulture, "{0} change of type '{1}' detected for '{2}'", changeDescription, e.ChangeType.ToString(), e.FullPath); + TraceFileChangeRestart(fileChangeMsg, isShutdown: true); Shutdown(); } } @@ -316,15 +321,16 @@ private void OnFileChanged(FileSystemEventArgs e) shutdown = true; } - TraceFileChangeRestart(changeDescription, e.ChangeType.ToString(), e.FullPath, shutdown); - ScheduleRestartAsync(shutdown).ContinueWith(t => _logger.LogError(t.Exception, $"Error restarting host (full shutdown: {shutdown})"), - TaskContinuationOptions.ExecuteSynchronously | TaskContinuationOptions.OnlyOnFaulted); + string fileChangeMsg = string.Format(CultureInfo.InvariantCulture, "{0} change of type '{1}' detected for '{2}'", changeDescription, e.ChangeType.ToString(), e.FullPath); + TraceFileChangeRestart(fileChangeMsg, shutdown); + ScheduleRestartAsync(fileChangeMsg, shutdown) + .ContinueWith(t => _logger.LogError(t.Exception, $"Error restarting host (full shutdown: {shutdown})"), + TaskContinuationOptions.ExecuteSynchronously | TaskContinuationOptions.OnlyOnFaulted); } } - private void TraceFileChangeRestart(string changeDescription, string changeType, string path, bool isShutdown) + private void TraceFileChangeRestart(string fileChangeMsg, bool isShutdown) { - string fileChangeMsg = string.Format(CultureInfo.InvariantCulture, "{0} change of type '{1}' detected for '{2}'", changeDescription, changeType, path); _logger.LogInformation(fileChangeMsg); string action = isShutdown ? "shutdown" : "restart"; @@ -349,11 +355,11 @@ internal static string GetRelativeDirectory(string path, string scriptRoot) return string.Empty; } - private Task RestartAsync() + private Task RestartAsync(string reason) { if (!_shutdownScheduled && Interlocked.Exchange(ref _restartRequested, 1) == 0) { - return _scriptHostManager.RestartHostAsync(); + return _scriptHostManager.RestartHostAsync(reason); } return Task.CompletedTask; diff --git a/src/WebJobs.Script.WebHost/Middleware/HostWarmupMiddleware.cs b/src/WebJobs.Script.WebHost/Middleware/HostWarmupMiddleware.cs index 188524ca74..a9e4e2ca10 100644 --- a/src/WebJobs.Script.WebHost/Middleware/HostWarmupMiddleware.cs +++ b/src/WebJobs.Script.WebHost/Middleware/HostWarmupMiddleware.cs @@ -158,7 +158,7 @@ public async Task HostWarmupAsync(HttpRequest request) { if (request.Query.TryGetValue("restart", out StringValues value) && string.Compare("1", value) == 0) { - await _hostManager.RestartHostAsync(CancellationToken.None); + await _hostManager.RestartHostAsync("Host warmup call requested a restart.", CancellationToken.None); // This call is here for sanity, but we should be fully initialized. await _hostManager.DelayUntilHostReady(); diff --git a/src/WebJobs.Script.WebHost/Standby/StandbyManager.cs b/src/WebJobs.Script.WebHost/Standby/StandbyManager.cs index e60f8be35f..9da44cedd5 100644 --- a/src/WebJobs.Script.WebHost/Standby/StandbyManager.cs +++ b/src/WebJobs.Script.WebHost/Standby/StandbyManager.cs @@ -78,7 +78,7 @@ public Task SpecializeHostAsync() if (t.IsFaulted) { // if we fail during specialization for whatever reason - // this is fatal, so we shutdown + // this is fatal, so we stop the application. _logger.LogError(t.Exception, "Specialization failed. Shutting down."); _applicationLifetime.StopApplication(); } @@ -119,7 +119,7 @@ public async Task SpecializeHostCoreAsync() using (_metricsLogger.LatencyEvent(MetricEventNames.SpecializationRestartHost)) { - await _scriptHostManager.RestartHostAsync(); + await _scriptHostManager.RestartHostAsync("Host specialization."); } using (_metricsLogger.LatencyEvent(MetricEventNames.SpecializationDelayUntilHostReady)) diff --git a/src/WebJobs.Script.WebHost/WebJobsScriptHostService.cs b/src/WebJobs.Script.WebHost/WebJobsScriptHostService.cs index 8fb10c55db..7b66505c56 100644 --- a/src/WebJobs.Script.WebHost/WebJobsScriptHostService.cs +++ b/src/WebJobs.Script.WebHost/WebJobsScriptHostService.cs @@ -560,8 +560,10 @@ public async Task StopAsync(CancellationToken cancellationToken) State = ScriptHostState.Stopped; } - public async Task RestartHostAsync(CancellationToken cancellationToken) + public async Task RestartHostAsync(string reason, CancellationToken cancellationToken) { + ArgumentException.ThrowIfNullOrWhiteSpace(reason); + if (ShutdownRequested) { return; @@ -577,7 +579,7 @@ public async Task RestartHostAsync(CancellationToken cancellationToken) await _hostStarted; } - _logger.EnteringRestart(); + _logger.EnteringRestart(reason); // If anything is mid-startup, cancel it. _startupLoopTokenSource?.Cancel(); @@ -821,7 +823,7 @@ private void OnHostHealthCheckTimer(object state) // fail and we'll enter a restart loop (exponentially backing off) // until the host is healthy again and we can resume host processing. _logger.UnhealthyRestart(); - var tIgnore = RestartHostAsync(CancellationToken.None); + var tIgnore = RestartHostAsync("Host health check detected an unhealthy host.", CancellationToken.None); } } diff --git a/src/WebJobs.Script/Description/DotNet/DotNetFunctionInvoker.cs b/src/WebJobs.Script/Description/DotNet/DotNetFunctionInvoker.cs index efcc681e38..f31bb54b9e 100644 --- a/src/WebJobs.Script/Description/DotNet/DotNetFunctionInvoker.cs +++ b/src/WebJobs.Script/Description/DotNet/DotNetFunctionInvoker.cs @@ -176,13 +176,13 @@ private async Task ReloadScriptAsync() // If the compilation succeeded, AND: // - We haven't cached a function (failed to compile on load), OR - // - We're referencing local function types (i.e. POCOs defined in the function) AND Our our function signature has changed + // - We're referencing local function types (i.e. POCOs defined in the function) AND our function signature has changed // Restart our host. if (compilationSucceeded && (_functionSignature == null || (_functionSignature.HasLocalTypeReference || !_functionSignature.Equals(signature)))) { - await Host.RestartAsync().ConfigureAwait(false); + await Host.RestartAsync(".NET compilation.").ConfigureAwait(false); } } diff --git a/src/WebJobs.Script/Eventing/Host/HostRestartEvent.cs b/src/WebJobs.Script/Eventing/Host/HostRestartEvent.cs index 155468ef67..d0743afab4 100644 --- a/src/WebJobs.Script/Eventing/Host/HostRestartEvent.cs +++ b/src/WebJobs.Script/Eventing/Host/HostRestartEvent.cs @@ -1,13 +1,20 @@ // 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.Eventing { public class HostRestartEvent : ScriptEvent { - public HostRestartEvent() + public HostRestartEvent(string reason) : base(nameof(HostRestartEvent), EventSources.Worker) { + ArgumentException.ThrowIfNullOrWhiteSpace(reason); + + Reason = reason; } + + public string Reason { get; } } } diff --git a/src/WebJobs.Script/Host/IScriptHostManager.cs b/src/WebJobs.Script/Host/IScriptHostManager.cs index 0d99f70f42..582368970e 100644 --- a/src/WebJobs.Script/Host/IScriptHostManager.cs +++ b/src/WebJobs.Script/Host/IScriptHostManager.cs @@ -29,7 +29,7 @@ public interface IScriptHostManager /// /// Restarts the current Script Job Host. /// - /// A that will completed when the host is restarted. - Task RestartHostAsync(CancellationToken cancellationToken = default); + /// A that completes when the host is restarted. + Task RestartHostAsync(string reason, CancellationToken cancellationToken = default); } } \ No newline at end of file diff --git a/src/WebJobs.Script/Host/ScriptHost.cs b/src/WebJobs.Script/Host/ScriptHost.cs index 0bc3f96572..00ae152101 100644 --- a/src/WebJobs.Script/Host/ScriptHost.cs +++ b/src/WebJobs.Script/Host/ScriptHost.cs @@ -407,11 +407,9 @@ internal static Collection CreateTypeAttributes(ScriptJo return customAttributes; } - // TODO: DI (FACAVAL) Remove this method. - // all restart/shutdown requests should go through the - internal Task RestartAsync() + internal Task RestartAsync(string reason) { - _scriptHostManager.RestartHostAsync(); + _scriptHostManager.RestartHostAsync(reason); return Task.CompletedTask; } diff --git a/src/WebJobs.Script/Host/WorkerFunctionMetadataProvider.cs b/src/WebJobs.Script/Host/WorkerFunctionMetadataProvider.cs index 22c2c7a0b3..30fde995d9 100644 --- a/src/WebJobs.Script/Host/WorkerFunctionMetadataProvider.cs +++ b/src/WebJobs.Script/Host/WorkerFunctionMetadataProvider.cs @@ -93,8 +93,10 @@ public async Task GetFunctionMetadataAsync(IEnumerable GetFunctionSecretAsync(string functionName) public async Task RestartAsync(CancellationToken cancellationToken) { - await _hostService.RestartHostAsync(cancellationToken); + await _hostService.RestartHostAsync("test", cancellationToken); } private void StillRunningCallback(object state) diff --git a/test/WebJobs.Script.Tests.Integration/WebHostEndToEnd/NodeHostRestartEndToEndTests.cs b/test/WebJobs.Script.Tests.Integration/WebHostEndToEnd/NodeHostRestartEndToEndTests.cs index 555e43c1d7..c3d2a8147c 100644 --- a/test/WebJobs.Script.Tests.Integration/WebHostEndToEnd/NodeHostRestartEndToEndTests.cs +++ b/test/WebJobs.Script.Tests.Integration/WebHostEndToEnd/NodeHostRestartEndToEndTests.cs @@ -50,7 +50,7 @@ await TestHelpers.Await(() => }); // Once we've hit 2, we have a couple seconds to trigger a restart. - _ = Task.Run(() => scriptHostManager.RestartHostAsync()); + _ = Task.Run(() => scriptHostManager.RestartHostAsync("test")); DateTime start = DateTime.UtcNow; await TestHelpers.Await(() => diff --git a/test/WebJobs.Script.Tests.Shared/TestHelpers.cs b/test/WebJobs.Script.Tests.Shared/TestHelpers.cs index ca98a157e7..e14261b301 100644 --- a/test/WebJobs.Script.Tests.Shared/TestHelpers.cs +++ b/test/WebJobs.Script.Tests.Shared/TestHelpers.cs @@ -645,7 +645,7 @@ object IServiceProvider.GetService(Type serviceType) throw new NotImplementedException(); } - Task IScriptHostManager.RestartHostAsync(CancellationToken cancellationToken) + Task IScriptHostManager.RestartHostAsync(string reason, CancellationToken cancellationToken) { throw new NotImplementedException(); } diff --git a/test/WebJobs.Script.Tests/Controllers/Admin/HostControllerTests.cs b/test/WebJobs.Script.Tests/Controllers/Admin/HostControllerTests.cs index b7eee8c4ad..aaa02e0f79 100644 --- a/test/WebJobs.Script.Tests/Controllers/Admin/HostControllerTests.cs +++ b/test/WebJobs.Script.Tests/Controllers/Admin/HostControllerTests.cs @@ -349,7 +349,7 @@ public async Task ResumeHost_HostNotRunning_ReturnsExpected(ScriptHostState host var result = (StatusCodeResult)await _hostController.Resume(scriptHostManagerMock.Object, default); Assert.Equal(expectedCode, result.StatusCode); - scriptHostManagerMock.Verify(p => p.RestartHostAsync(It.IsAny()), Times.Never()); + scriptHostManagerMock.Verify(p => p.RestartHostAsync("test", It.IsAny()), Times.Never()); } [Fact] @@ -358,10 +358,11 @@ public async Task ResumeHost_HostRunning_DrainModeEnabled_StartNewHostSuccessful var scriptHostManagerMock = new Mock(MockBehavior.Strict); var serviceProviderMock = scriptHostManagerMock.As(); var drainModeManager = new Mock(MockBehavior.Strict); + var restartReason = "Resuming from drain mode."; serviceProviderMock.Setup(x => x.GetService(typeof(IDrainModeManager))).Returns(drainModeManager.Object); scriptHostManagerMock.SetupGet(p => p.State).Returns(ScriptHostState.Running); - scriptHostManagerMock.Setup(p => p.RestartHostAsync(It.IsAny())).Returns(Task.CompletedTask); + scriptHostManagerMock.Setup(p => p.RestartHostAsync(restartReason, It.IsAny())).Returns(Task.CompletedTask); drainModeManager.Setup(x => x.IsDrainModeEnabled).Returns(true); var expectedBody = new ResumeStatus { State = ScriptHostState.Running }; @@ -369,7 +370,7 @@ public async Task ResumeHost_HostRunning_DrainModeEnabled_StartNewHostSuccessful Assert.Equal(StatusCodes.Status200OK, result.StatusCode); Assert.Equal(expectedBody.State, (result.Value as ResumeStatus).State); - scriptHostManagerMock.Verify(p => p.RestartHostAsync(It.IsAny()), Times.Once()); + scriptHostManagerMock.Verify(p => p.RestartHostAsync(restartReason, It.IsAny()), Times.Once()); } [Fact] @@ -388,7 +389,7 @@ public async Task ResumeHost_HostRunning_DrainModeNotEnabled_DoesNotStartNewHost Assert.Equal(StatusCodes.Status200OK, result.StatusCode); Assert.Equal(expectedBody.State, (result.Value as ResumeStatus).State); - scriptHostManagerMock.Verify(p => p.RestartHostAsync(It.IsAny()), Times.Never()); + scriptHostManagerMock.Verify(p => p.RestartHostAsync("test", It.IsAny()), Times.Never()); } [Fact] @@ -398,7 +399,7 @@ public async Task ResumeHost_HostRunning_ClientDisconnect_DoesNotStartNewHost() using var cts = new CancellationTokenSource(); cts.Cancel(); await Assert.ThrowsAnyAsync(() => _hostController.Resume(scriptHostManagerMock.Object, cts.Token)); - scriptHostManagerMock.Verify(p => p.RestartHostAsync(It.IsAny()), Times.Never()); + scriptHostManagerMock.Verify(p => p.RestartHostAsync("test", It.IsAny()), Times.Never()); } } } diff --git a/test/WebJobs.Script.Tests/FileMonitoringServiceTests.cs b/test/WebJobs.Script.Tests/FileMonitoringServiceTests.cs index f813184554..10449c5f90 100644 --- a/test/WebJobs.Script.Tests/FileMonitoringServiceTests.cs +++ b/test/WebJobs.Script.Tests/FileMonitoringServiceTests.cs @@ -93,14 +93,17 @@ public static async Task HostRestarts_OnWatchFilesChange() var watchedFileEventArgs = new FileSystemEventArgs(WatcherChangeTypes.Created, tempDir, "my_watched_file.txt"); FileEvent watchedFileEvent = new FileEvent("ScriptFiles", watchedFileEventArgs); + var expectedReason = $"File change of type 'Created' detected for '{Path.Combine(tempDir, "my_watched_file.txt")}'"; + var notExpectedReason = $"File change of type 'Created' detected for '{Path.Combine(tempDir, "my_ignored_file.txt")}'"; + // Test mockEventManager.Publish(ignoredFileEvent); await Task.Delay(TimeSpan.FromSeconds(3)); - mockScriptHostManager.Verify(m => m.RestartHostAsync(default), Times.Never); + mockScriptHostManager.Verify(m => m.RestartHostAsync(notExpectedReason, default), Times.Never); mockEventManager.Publish(watchedFileEvent); await Task.Delay(TimeSpan.FromSeconds(3)); - mockScriptHostManager.Verify(m => m.RestartHostAsync(default)); + mockScriptHostManager.Verify(m => m.RestartHostAsync(expectedReason, default), Times.Once); } } @@ -156,14 +159,15 @@ public static async Task SuspendRestart_Restart() e2.Set(); }); - mockScriptHostManager.Verify(m => m.RestartHostAsync(default), Times.Never); + var restartReason = "Running restart requested while in a restart suspension scope."; + mockScriptHostManager.Verify(m => m.RestartHostAsync(restartReason, It.IsAny()), Times.Never); e1.WaitOne(5000); - mockScriptHostManager.Verify(m => m.RestartHostAsync(default), Times.Never); + mockScriptHostManager.Verify(m => m.RestartHostAsync(restartReason, It.IsAny()), Times.Never); e2.WaitOne(5000); // wait for restart await Task.Delay(1000); - mockScriptHostManager.Verify(m => m.RestartHostAsync(default), Times.Once); + mockScriptHostManager.Verify(m => m.RestartHostAsync(restartReason, It.IsAny()), Times.Once); await fileMonitoringService.StopAsync(CancellationToken.None); } } @@ -198,17 +202,18 @@ public static async Task SuspendRestart_Restart_NestedUsings_Work() var randomFileEventArgs = new FileSystemEventArgs(WatcherChangeTypes.Created, tempDir, "host.json"); FileEvent randomFileEvent = new FileEvent("ScriptFiles", randomFileEventArgs); + var expectedReason = $"Running restart requested while in a restart suspension scope."; using (fileMonitoringService.SuspendRestart(true)) { using (fileMonitoringService.SuspendRestart(true)) { } await Task.Delay(1000); - mockScriptHostManager.Verify(m => m.RestartHostAsync(default), Times.Never); + mockScriptHostManager.Verify(m => m.RestartHostAsync(expectedReason, default), Times.Never); mockEventManager.Publish(randomFileEvent); } await Task.Delay(1000); - mockScriptHostManager.Verify(m => m.RestartHostAsync(default), Times.Once); + mockScriptHostManager.Verify(m => m.RestartHostAsync(expectedReason, default), Times.Once); await fileMonitoringService.StopAsync(CancellationToken.None); } } @@ -307,7 +312,12 @@ public static async Task TestAppOfflineDebounceTime(string fileName, int delayIn TaskCompletionSource restart = new TaskCompletionSource(); var mockScriptHostManager = new Mock(); - mockScriptHostManager.Setup(m => m.RestartHostAsync(default)).Callback(() => restart.TrySetResult()); + mockScriptHostManager.Setup(m => m.RestartHostAsync(It.IsAny(), It.IsAny())) + .Callback((reason, ct) => + { + restart.TrySetResult(); + }) + .Returns(Task.CompletedTask); var mockEventManager = new ScriptEventManager(); var environment = new TestEnvironment(); @@ -338,14 +348,15 @@ public static async Task TestAppOfflineDebounceTime(string fileName, int delayIn mockApplicationLifetime.Verify(m => m.StopApplication(), Times.Never); } + var expectedReason = $"File change of type 'Created' detected for '{Path.Combine(tempDir, fileName)}'"; if (expectRestart) { await restart.Task.WaitAsync(TimeSpan.FromSeconds(5)); - mockScriptHostManager.Verify(m => m.RestartHostAsync(default)); + mockScriptHostManager.Verify(m => m.RestartHostAsync(expectedReason, default)); } else { - mockScriptHostManager.Verify(m => m.RestartHostAsync(default), Times.Never); + mockScriptHostManager.Verify(m => m.RestartHostAsync(expectedReason, default), Times.Never); } } } diff --git a/test/WebJobs.Script.Tests/Metrics/LinuxContainerLegionMetricsPublisherTests.cs b/test/WebJobs.Script.Tests/Metrics/LinuxContainerLegionMetricsPublisherTests.cs index 3181d55ae0..3e695891bc 100644 --- a/test/WebJobs.Script.Tests/Metrics/LinuxContainerLegionMetricsPublisherTests.cs +++ b/test/WebJobs.Script.Tests/Metrics/LinuxContainerLegionMetricsPublisherTests.cs @@ -267,7 +267,7 @@ public object GetService(Type serviceType) throw new NotImplementedException(); } - public Task RestartHostAsync(CancellationToken cancellationToken = default) + public Task RestartHostAsync(string reason, CancellationToken cancellationToken = default) { throw new NotImplementedException(); } diff --git a/test/WebJobs.Script.Tests/WebJobsScriptHostServiceTests.cs b/test/WebJobs.Script.Tests/WebJobsScriptHostServiceTests.cs index 092beeabf5..ce9e83b16d 100644 --- a/test/WebJobs.Script.Tests/WebJobsScriptHostServiceTests.cs +++ b/test/WebJobs.Script.Tests/WebJobsScriptHostServiceTests.cs @@ -438,7 +438,7 @@ public async Task DisposesScriptHost() var hostLogger = host.Object.GetTestLoggerProvider(); await _hostService.StartAsync(CancellationToken.None); - await _hostService.RestartHostAsync(CancellationToken.None); + await _hostService.RestartHostAsync("test", CancellationToken.None); Assert.True(AreRequiredMetricsGenerated(metricsLogger)); @@ -475,7 +475,7 @@ public async Task HostRestart_BeforeStart_WaitsForStartToContinue() // Simulate a call to specialize coming from the PlaceholderSpecializationMiddleware. This // can happen before we ever start the service, which could create invalid state. - Task restartTask = _hostService.RestartHostAsync(CancellationToken.None); + Task restartTask = _hostService.RestartHostAsync("test", CancellationToken.None); await _hostService.StartAsync(CancellationToken.None); await restartTask; @@ -580,7 +580,7 @@ public async Task DependencyTrackingTelemetryModule_Race() public void RestartHost() { - _hostService.RestartHostAsync(CancellationToken.None).Wait(); + _hostService.RestartHostAsync("test", CancellationToken.None).Wait(); } public void SpecializeHost()