From d3132eb5285d6ae284df2a022a7cf461a7c75c8c Mon Sep 17 00:00:00 2001 From: Jordan Brown Date: Mon, 11 May 2020 03:21:52 -0400 Subject: [PATCH] Implement watchdog heartbeats - Refactor MonitorLifetimes so the code isn't duplicated in the Basic and Experimental watchdogs - Add IsAdminChannel to ChannelMapping - Allow watchdog messages to be potentially restricted to admin chats - Add topic command type for heartbeats - Change ISessionController.SendCommand return type to also give the Byond.TopicSender response - Added OnPrime event to ISessionController, this is now used for inactive server startup - Added TaskExtension for creating infinite tasks. - Fixed watchdog shutdown crash. WIP --- .../Components/Chat/ChannelMapping.cs | 5 + .../Components/Chat/ChatManager.cs | 22 +- .../Components/Chat/IChatManager.cs | 3 +- .../Components/Interop/DMApiConstants.cs | 2 +- .../Interop/Topic/TopicCommandType.cs | 7 +- .../Interop/Topic/TopicParameters.cs | 9 + .../Components/Interop/Topic/TopicResponse.cs | 4 +- .../Components/Watchdog/BasicWatchdog.cs | 202 ++++-------- .../Watchdog/CombinedTopicResponse.cs | 32 ++ .../Watchdog/DeadSessionController.cs | 8 +- .../Watchdog/ExperimentalWatchdog.cs | 262 +++++----------- .../Components/Watchdog/ISessionController.cs | 7 +- .../Watchdog/MonitorActivationReason.cs | 7 +- .../Components/Watchdog/MonitorState.cs | 2 +- .../Components/Watchdog/SessionController.cs | 62 ++-- .../Components/Watchdog/WatchdogBase.cs | 294 ++++++++++++++++-- .../Controllers/DreamDaemonController.cs | 20 +- src/Tgstation.Server.Host/Core/Application.cs | 6 +- .../Extensions/TaskExtensions.cs | 6 + .../Tgstation.Server.Host.csproj | 2 +- .../Instance/WatchdogTest.cs | 62 +++- tests/Tgstation.Server.Tests/TestingServer.cs | 3 +- .../Tgstation.Server.Tests.csproj | 6 + 23 files changed, 636 insertions(+), 397 deletions(-) create mode 100644 src/Tgstation.Server.Host/Components/Watchdog/CombinedTopicResponse.cs diff --git a/src/Tgstation.Server.Host/Components/Chat/ChannelMapping.cs b/src/Tgstation.Server.Host/Components/Chat/ChannelMapping.cs index 6dc3c84b9c..e89cd1a2f2 100644 --- a/src/Tgstation.Server.Host/Components/Chat/ChannelMapping.cs +++ b/src/Tgstation.Server.Host/Components/Chat/ChannelMapping.cs @@ -25,6 +25,11 @@ /// public bool IsUpdatesChannel { get; set; } + /// + /// If the is an admin channel. + /// + public bool IsAdminChannel { get; set; } + /// /// The with the mapped Id. /// diff --git a/src/Tgstation.Server.Host/Components/Chat/ChatManager.cs b/src/Tgstation.Server.Host/Components/Chat/ChatManager.cs index 87873422eb..2782f9aba1 100644 --- a/src/Tgstation.Server.Host/Components/Chat/ChatManager.cs +++ b/src/Tgstation.Server.Host/Components/Chat/ChatManager.cs @@ -452,6 +452,7 @@ namespace Tgstation.Server.Host.Components.Chat { IsWatchdogChannel = x.IsWatchdogChannel == true, IsUpdatesChannel = x.IsUpdatesChannel == true, + IsAdminChannel = x.IsAdminChannel == true, ProviderChannelId = y.RealId, ProviderId = connectionId, Channel = y @@ -596,12 +597,25 @@ namespace Tgstation.Server.Host.Components.Chat } /// - public Task SendWatchdogMessage(string message, CancellationToken cancellationToken) + public Task SendWatchdogMessage(string message, bool adminOnly, CancellationToken cancellationToken) { - List wdChannels; + List wdChannels = null; message = String.Format(CultureInfo.InvariantCulture, "WD: {0}", message); - lock (mappedChannels) // so it doesn't change while we're using it - wdChannels = mappedChannels.Where(x => x.Value.IsWatchdogChannel).Select(x => x.Key).ToList(); + + // so it doesn't change while we're using it + lock (mappedChannels) + { + if (adminOnly) + { + wdChannels = mappedChannels.Where(x => x.Value.IsAdminChannel).Select(x => x.Key).ToList(); + if (wdChannels.Count == 0) + adminOnly = false; + } + + if (!adminOnly) + wdChannels = mappedChannels.Where(x => x.Value.IsWatchdogChannel).Select(x => x.Key).ToList(); + } + return SendMessage(message, wdChannels, cancellationToken); } diff --git a/src/Tgstation.Server.Host/Components/Chat/IChatManager.cs b/src/Tgstation.Server.Host/Components/Chat/IChatManager.cs index 9e2b882ab7..2c9b286c30 100644 --- a/src/Tgstation.Server.Host/Components/Chat/IChatManager.cs +++ b/src/Tgstation.Server.Host/Components/Chat/IChatManager.cs @@ -56,9 +56,10 @@ namespace Tgstation.Server.Host.Components.Chat /// Send a chat to configured watchdog channels /// /// The message being sent + /// If the message should be sent to admin channels only. If no admin-only channels are configured, it will be sent to the watchdog channels. /// The for the operation /// A representing the running operation - Task SendWatchdogMessage(string message, CancellationToken cancellationToken); + Task SendWatchdogMessage(string message, bool adminOnly, CancellationToken cancellationToken); /// /// Send a chat to configured update channels diff --git a/src/Tgstation.Server.Host/Components/Interop/DMApiConstants.cs b/src/Tgstation.Server.Host/Components/Interop/DMApiConstants.cs index b0b95efbae..f14967cf94 100644 --- a/src/Tgstation.Server.Host/Components/Interop/DMApiConstants.cs +++ b/src/Tgstation.Server.Host/Components/Interop/DMApiConstants.cs @@ -33,7 +33,7 @@ namespace Tgstation.Server.Host.Components.Interop /// /// The DMAPI being used. /// - public static readonly Version Version = new Version(5, 0, 0); + public static readonly Version Version = new Version(5, 1, 0); /// /// for use when communicating with the DMAPI. diff --git a/src/Tgstation.Server.Host/Components/Interop/Topic/TopicCommandType.cs b/src/Tgstation.Server.Host/Components/Interop/Topic/TopicCommandType.cs index 735dd0c9da..463f33f9d7 100644 --- a/src/Tgstation.Server.Host/Components/Interop/Topic/TopicCommandType.cs +++ b/src/Tgstation.Server.Host/Components/Interop/Topic/TopicCommandType.cs @@ -38,6 +38,11 @@ /// /// The server's port was possibly changed. /// - ServerPortUpdate + ServerPortUpdate, + + /// + /// Ping to ensure the server is running. + /// + Heartbeat, } } \ No newline at end of file diff --git a/src/Tgstation.Server.Host/Components/Interop/Topic/TopicParameters.cs b/src/Tgstation.Server.Host/Components/Interop/Topic/TopicParameters.cs index b029fb643a..1309384ac9 100644 --- a/src/Tgstation.Server.Host/Components/Interop/Topic/TopicParameters.cs +++ b/src/Tgstation.Server.Host/Components/Interop/Topic/TopicParameters.cs @@ -113,5 +113,14 @@ namespace Tgstation.Server.Host.Components.Interop.Topic { ChatUpdate = channelsUpdate ?? throw new ArgumentNullException(nameof(channelsUpdate)); } + + /// + /// Initializes a new instance of the . + /// + /// Constructor for s. + public TopicParameters() + : this(TopicCommandType.Heartbeat) + { + } } } diff --git a/src/Tgstation.Server.Host/Components/Interop/Topic/TopicResponse.cs b/src/Tgstation.Server.Host/Components/Interop/Topic/TopicResponse.cs index e0a397fae3..bb7d85414c 100644 --- a/src/Tgstation.Server.Host/Components/Interop/Topic/TopicResponse.cs +++ b/src/Tgstation.Server.Host/Components/Interop/Topic/TopicResponse.cs @@ -10,11 +10,11 @@ namespace Tgstation.Server.Host.Components.Interop.Topic /// /// The text to reply with as the result of a request, if any. /// - public string CommandResponseMessage { get; set; } + public string CommandResponseMessage { get; private set; } /// /// The s to send as the result of a request, if any. /// - public ICollection ChatResponses { get; set; } + public ICollection ChatResponses { get; private set; } } } diff --git a/src/Tgstation.Server.Host/Components/Watchdog/BasicWatchdog.cs b/src/Tgstation.Server.Host/Components/Watchdog/BasicWatchdog.cs index 36f1b5e3a7..39ab878f09 100644 --- a/src/Tgstation.Server.Host/Components/Watchdog/BasicWatchdog.cs +++ b/src/Tgstation.Server.Host/Components/Watchdog/BasicWatchdog.cs @@ -1,5 +1,6 @@ using Microsoft.Extensions.Logging; using System; +using System.Collections.Generic; using System.Globalization; using System.Threading; using System.Threading.Tasks; @@ -79,7 +80,25 @@ namespace Tgstation.Server.Host.Components.Watchdog autoStart) { } - async Task HandleMonitorWakeup(MonitorActivationReason reason, CancellationToken cancellationToken) + /// + protected override IReadOnlyDictionary GetMonitoredServerTasks(MonitorState monitorState) + { + Logger.LogDebug("Server compile job ID is {0}", Server.Dmb.CompileJob.Id); + + monitorState.ActiveServer = Server; + + return new Dictionary + { + { MonitorActivationReason.ActiveServerCrashed, Server.Lifetime }, + { MonitorActivationReason.ActiveServerRebooted, Server.OnReboot }, + { MonitorActivationReason.InactiveServerCrashed, Extensions.TaskExtensions.InfiniteTask() }, + { MonitorActivationReason.InactiveServerRebooted, Extensions.TaskExtensions.InfiniteTask() }, + { MonitorActivationReason.InactiveServerStartupComplete, Extensions.TaskExtensions.InfiniteTask() } + }; + } + + /// + protected override async Task HandleMonitorWakeup(MonitorActivationReason reason, MonitorState monitorState, CancellationToken cancellationToken) { switch (reason) { @@ -88,13 +107,31 @@ namespace Tgstation.Server.Host.Components.Watchdog if (Server.RebootState == Watchdog.RebootState.Shutdown) { // the time for graceful shutdown is now - await Chat.SendWatchdogMessage(String.Format(CultureInfo.InvariantCulture, "Server {0}! Exiting due to graceful termination request...", exitWord), cancellationToken).ConfigureAwait(false); + await Chat.SendWatchdogMessage( + String.Format( + CultureInfo.InvariantCulture, + "Server {0}! Stopping due to graceful termination request...", + exitWord), + false, + cancellationToken) + .ConfigureAwait(false); DisposeAndNullControllers(); - return MonitorAction.Exit; + monitorState.NextAction = MonitorAction.Exit; + } + else + { + await Chat.SendWatchdogMessage( + String.Format( + CultureInfo.InvariantCulture, + "Server {0}! Rebooting...", + exitWord), + false, + cancellationToken) + .ConfigureAwait(false); + monitorState.NextAction = MonitorAction.Restart; } - await Chat.SendWatchdogMessage(String.Format(CultureInfo.InvariantCulture, "Server {0}! Rebooting...", exitWord), cancellationToken).ConfigureAwait(false); - return MonitorAction.Restart; + break; case MonitorActivationReason.ActiveServerRebooted: var rebootState = Server.RebootState; gracefulRebootSetDueToNewDmb = false; @@ -103,28 +140,39 @@ namespace Tgstation.Server.Host.Components.Watchdog switch (rebootState) { case Watchdog.RebootState.Normal: - return HandleNormalReboot(); + monitorState.NextAction = HandleNormalReboot(); + break; case Watchdog.RebootState.Restart: - return MonitorAction.Restart; + monitorState.NextAction = MonitorAction.Restart; + break; case Watchdog.RebootState.Shutdown: // graceful shutdown time - await Chat.SendWatchdogMessage("Active server rebooted! Exiting due to graceful termination request...", cancellationToken).ConfigureAwait(false); + await Chat.SendWatchdogMessage( + "Active server rebooted! Stopping due to graceful termination request...", + false, + cancellationToken) + .ConfigureAwait(false); DisposeAndNullControllers(); - return MonitorAction.Exit; + monitorState.NextAction = MonitorAction.Exit; + break; default: throw new InvalidOperationException($"Invalid reboot state: {rebootState}"); } + break; case MonitorActivationReason.ActiveLaunchParametersUpdated: await Server.SetRebootState(Watchdog.RebootState.Restart, cancellationToken).ConfigureAwait(false); - return MonitorAction.Continue; + monitorState.NextAction = MonitorAction.Continue; + break; case MonitorActivationReason.NewDmbAvailable: await HandleNewDmbAvailable(cancellationToken).ConfigureAwait(false); - return MonitorAction.Continue; + monitorState.NextAction = MonitorAction.Continue; + break; case MonitorActivationReason.InactiveServerCrashed: case MonitorActivationReason.InactiveServerRebooted: case MonitorActivationReason.InactiveServerStartupComplete: throw new NotSupportedException($"Unsupported activation reason: {reason}"); + case MonitorActivationReason.Heartbeat: default: throw new InvalidOperationException($"Invalid activation reason: {reason}"); } @@ -238,138 +286,6 @@ namespace Tgstation.Server.Host.Components.Watchdog } } - /// - protected sealed override async Task MonitorLifetimes(CancellationToken cancellationToken) - { - Logger.LogTrace("Entered MonitorLifetimes"); - - // this function is responsible for calling HandlerMonitorWakeup when necessary and manitaining the MonitorState - var iteration = 1; - for (MonitorAction nextAction = MonitorAction.Continue; nextAction != MonitorAction.Exit; ++iteration) - { - // always start out with continue - nextAction = MonitorAction.Continue; - - // dump some info to the logs - Logger.LogDebug("Iteration {0} of monitor loop", iteration); - try - { - Logger.LogDebug("Server Compile Job ID: {0}", Server.Dmb.CompileJob.Id); - - // load the activation tasks into local variables - Task activeServerLifetime = Server.Lifetime; - var activeServerReboot = Server.OnReboot; - Task activeLaunchParametersChanged = ActiveParametersUpdated.Task; - var newDmbAvailable = DmbFactory.OnNewerDmb; - - // cancel waiting if requested - var cancelTcs = new TaskCompletionSource(); - using (cancellationToken.Register(() => cancelTcs.SetCanceled())) - { - var toWaitOn = Task.WhenAny(activeServerLifetime, activeServerReboot, newDmbAvailable, cancelTcs.Task, activeLaunchParametersChanged); - - // wait for something to happen - await toWaitOn.ConfigureAwait(false); - cancellationToken.ThrowIfCancellationRequested(); - } - - var chatTask = Task.CompletedTask; - using (await SemaphoreSlimContext.Lock(Semaphore, cancellationToken).ConfigureAwait(false)) - { - // always run HandleMonitorWakeup from the context of the semaphore lock - // multiple things may have happened, handle them one at a time - for (var moreActivationsToProcess = true; moreActivationsToProcess && (nextAction == MonitorAction.Continue || nextAction == MonitorAction.Skip);) - { - MonitorActivationReason activationReason = default; // this will always be assigned before being used - - // process the tasks in this order and call HandlerMonitorWakup for each - bool CheckActivationReason(ref Task task, MonitorActivationReason testActivationReason) - { - var taskCompleted = task?.IsCompleted == true; - task = null; - if (nextAction == MonitorAction.Skip) - nextAction = MonitorAction.Continue; - else if (taskCompleted) - { - activationReason = testActivationReason; - return true; - } - - return false; - } - - if (CheckActivationReason(ref activeServerLifetime, MonitorActivationReason.ActiveServerCrashed) - || CheckActivationReason(ref activeServerReboot, MonitorActivationReason.ActiveServerRebooted) - || CheckActivationReason(ref newDmbAvailable, MonitorActivationReason.NewDmbAvailable) - || CheckActivationReason(ref activeLaunchParametersChanged, MonitorActivationReason.ActiveLaunchParametersUpdated)) - { - Logger.LogTrace("Monitor activation: {0}", activationReason); - nextAction = await HandleMonitorWakeup(activationReason, cancellationToken).ConfigureAwait(false); - } - else - moreActivationsToProcess = false; - } - } - - // full reboot required - if (nextAction == MonitorAction.Restart) - { - Logger.LogDebug("Next state action is to restart"); - DisposeAndNullControllers(); - - for (var retryAttempts = 1; nextAction == MonitorAction.Restart; ++retryAttempts) - { - Exception launchException = null; - using (await SemaphoreSlimContext.Lock(Semaphore, cancellationToken).ConfigureAwait(false)) - try - { - // use LaunchImplNoLock without announcements or restarting the monitor - await LaunchImplNoLock(false, false, null, cancellationToken).ConfigureAwait(false); - if (Running) - { - Logger.LogDebug("Relaunch successful, resetting monitor state..."); - break; // continue on main loop - } - } - catch (OperationCanceledException) - { - throw; - } - catch (Exception e) - { - launchException = e; - } - - await chatTask.ConfigureAwait(false); - if (!Running) - { - if (launchException == null) - Logger.LogWarning("Failed to automatically restart the watchdog! Attempt: {0}", retryAttempts); - else - Logger.LogWarning("Failed to automatically restart the watchdog! Attempt: {0}, Exception: {1}", retryAttempts, launchException); - var retryDelay = Math.Min(Math.Pow(2, retryAttempts), 3600); // max of one hour, increasing by a power of 2 each time - chatTask = Chat.SendWatchdogMessage(String.Format(CultureInfo.InvariantCulture, "Failed to restart watchdog (Attempt: {0}), retrying in {1} seconds...", retryAttempts, retryDelay), cancellationToken); - await Task.WhenAll(AsyncDelayer.Delay(TimeSpan.FromSeconds(retryDelay), cancellationToken), chatTask).ConfigureAwait(false); - } - } - } - } - catch (OperationCanceledException) - { - Logger.LogDebug("Monitor cancelled"); - break; - } - catch (Exception e) - { - // really, this should NEVER happen - Logger.LogError("Monitor crashed! Iteration: {0}, NextAction: {1}, Exception: {2}", iteration, nextAction, e); - await Chat.SendWatchdogMessage(String.Format(CultureInfo.InvariantCulture, "Monitor crashed, this should NEVER happen! Please report this, full details in logs! Restarting monitor... Error: {0}", e.Message), cancellationToken).ConfigureAwait(false); - } - } - - Logger.LogTrace("Monitor exiting..."); - } - /// /// Handler for when the is . /// diff --git a/src/Tgstation.Server.Host/Components/Watchdog/CombinedTopicResponse.cs b/src/Tgstation.Server.Host/Components/Watchdog/CombinedTopicResponse.cs new file mode 100644 index 0000000000..34da84f1ef --- /dev/null +++ b/src/Tgstation.Server.Host/Components/Watchdog/CombinedTopicResponse.cs @@ -0,0 +1,32 @@ +using System; +using Tgstation.Server.Host.Components.Interop.Topic; + +namespace Tgstation.Server.Host.Components.Watchdog +{ + /// + /// Combines a with a . + /// + sealed class CombinedTopicResponse + { + /// + /// The raw . + /// + public global::Byond.TopicSender.TopicResponse ByondTopicResponse { get; } + + /// + /// The interop , if any. + /// + public TopicResponse InteropResponse { get; } + + /// + /// Initializes a new instance of the . + /// + /// The value of . + /// The optional value of . + public CombinedTopicResponse(global::Byond.TopicSender.TopicResponse byondTopicResponse, TopicResponse interopResponse) + { + ByondTopicResponse = byondTopicResponse ?? throw new ArgumentNullException(nameof(byondTopicResponse)); + InteropResponse = interopResponse; + } + } +} diff --git a/src/Tgstation.Server.Host/Components/Watchdog/DeadSessionController.cs b/src/Tgstation.Server.Host/Components/Watchdog/DeadSessionController.cs index 8b680b567c..8c8a72f147 100644 --- a/src/Tgstation.Server.Host/Components/Watchdog/DeadSessionController.cs +++ b/src/Tgstation.Server.Host/Components/Watchdog/DeadSessionController.cs @@ -42,6 +42,9 @@ namespace Tgstation.Server.Host.Components.Watchdog /// public Task OnReboot { get; } + /// + public Task OnPrime { get; } + /// public Task Lifetime { get; } @@ -70,7 +73,8 @@ namespace Tgstation.Server.Host.Components.Watchdog StartupTime = TimeSpan.FromSeconds(0) }); Lifetime = Task.FromResult(-1); - OnReboot = new TaskCompletionSource().Task; + OnReboot = Extensions.TaskExtensions.InfiniteTask(); + OnPrime = Extensions.TaskExtensions.InfiniteTask(); disposeLock = new object(); } @@ -97,7 +101,7 @@ namespace Tgstation.Server.Host.Components.Watchdog public void ResetRebootState() => throw new NotSupportedException(); /// - public Task SendCommand(TopicParameters parameters, CancellationToken cancellationToken) => throw new NotSupportedException(); + public Task SendCommand(TopicParameters parameters, CancellationToken cancellationToken) => throw new NotSupportedException(); /// public void SetHighPriority() => throw new NotSupportedException(); diff --git a/src/Tgstation.Server.Host/Components/Watchdog/ExperimentalWatchdog.cs b/src/Tgstation.Server.Host/Components/Watchdog/ExperimentalWatchdog.cs index 7df5e8d77f..90ede2c656 100644 --- a/src/Tgstation.Server.Host/Components/Watchdog/ExperimentalWatchdog.cs +++ b/src/Tgstation.Server.Host/Components/Watchdog/ExperimentalWatchdog.cs @@ -1,6 +1,6 @@ using Microsoft.Extensions.Logging; -using Newtonsoft.Json; using System; +using System.Collections.Generic; using System.Diagnostics; using System.Globalization; using System.Threading; @@ -92,15 +92,9 @@ namespace Tgstation.Server.Host.Components.Watchdog alphaIsActive = true; } - /// - /// Handles the actions to take when the monitor has to "wake up" - /// - /// The that caused the invocation - /// The current . Will be modified upon retrn - /// The for the operation - /// A representing the running operation + /// #pragma warning disable CA1502 // TODO: Decomplexify - async Task HandlerMonitorWakeup(MonitorActivationReason activationReason, MonitorState monitorState, CancellationToken cancellationToken) + protected override async Task HandleMonitorWakeup(MonitorActivationReason activationReason, MonitorState monitorState, CancellationToken cancellationToken) { Logger.LogDebug("Monitor activation. Reason: {0}", activationReason); @@ -203,7 +197,10 @@ namespace Tgstation.Server.Host.Components.Watchdog cancellationToken) .ConfigureAwait(false); monitorState.InactiveServer.SetHighPriority(); - await Chat.SendWatchdogMessage("Staging newest DMB on inactive server failed: {0} Falling back to previous dmb...", cancellationToken).ConfigureAwait(false); + await Chat.SendWatchdogMessage( + "Staging newest DMB on inactive server failed: {0} Falling back to previous dmb...", + false, + cancellationToken).ConfigureAwait(false); } catch (OperationCanceledException) { @@ -214,7 +211,10 @@ namespace Tgstation.Server.Host.Components.Watchdog // fuuuuucckkk Logger.LogError("Backup strategy failed! Monitor will restart when active server reboots! Exception: {0}", e2.ToString()); monitorState.InactiveServerCritFail = true; - await Chat.SendWatchdogMessage("Attempted reboot of inactive server failed. Watchdog will reset when active server fails or exits", cancellationToken).ConfigureAwait(false); + await Chat.SendWatchdogMessage( + "Attempted reboot of inactive server failed. Watchdog will reset when active server fails or exits", + false, + cancellationToken).ConfigureAwait(false); return; } } @@ -232,7 +232,13 @@ namespace Tgstation.Server.Host.Components.Watchdog if (monitorState.ActiveServer.RebootState == Watchdog.RebootState.Shutdown) { // the time for graceful shutdown is now - await Chat.SendWatchdogMessage(String.Format(CultureInfo.InvariantCulture, "Active server {0}! Exiting due to graceful termination request...", ExitWord(monitorState.ActiveServer)), cancellationToken).ConfigureAwait(false); + await Chat.SendWatchdogMessage( + String.Format( + CultureInfo.InvariantCulture, + "Active server {0}! Exiting due to graceful termination request...", + ExitWord(monitorState.ActiveServer)), + false, + cancellationToken).ConfigureAwait(false); DisposeAndNullControllers(); monitorState.NextAction = MonitorAction.Exit; break; @@ -241,14 +247,27 @@ namespace Tgstation.Server.Host.Components.Watchdog if (FullRestartDeadInactive()) { // tell chat about it and go ahead - await Chat.SendWatchdogMessage(String.Format(CultureInfo.InvariantCulture, "Active server {0}! Inactive server unable to online!", ExitWord(monitorState.ActiveServer)), cancellationToken).ConfigureAwait(false); + await Chat.SendWatchdogMessage( + String.Format( + CultureInfo.InvariantCulture, + "Active server {0}! Inactive server unable to online!", + ExitWord(monitorState.ActiveServer)), + false, + cancellationToken).ConfigureAwait(false); // we've already been set to restart break; } // tell chat about it - await Chat.SendWatchdogMessage(String.Format(CultureInfo.InvariantCulture, "Active server {0}! Onlining inactive server...", ExitWord(monitorState.ActiveServer)), cancellationToken).ConfigureAwait(false); + await Chat.SendWatchdogMessage( + String.Format( + CultureInfo.InvariantCulture, + "Active server {0}! Onlining inactive server...", + ExitWord(monitorState.ActiveServer)), + false, + cancellationToken) + .ConfigureAwait(false); // try to activate the inactive server if (!await MakeInactiveActive().ConfigureAwait(false)) @@ -259,7 +278,14 @@ namespace Tgstation.Server.Host.Components.Watchdog break; case MonitorActivationReason.InactiveServerCrashed: // just announce and try to bring it back - await Chat.SendWatchdogMessage(String.Format(CultureInfo.InvariantCulture, "Inactive server {0}! Rebooting...", ExitWord(monitorState.InactiveServer)), cancellationToken).ConfigureAwait(false); + await Chat.SendWatchdogMessage( + String.Format( + CultureInfo.InvariantCulture, + "Inactive server {0}! Rebooting...", + ExitWord(monitorState.InactiveServer)), + false, + cancellationToken) + .ConfigureAwait(false); await UpdateAndRestartInactiveServer(false).ConfigureAwait(false); break; case MonitorActivationReason.ActiveServerRebooted: @@ -285,7 +311,11 @@ namespace Tgstation.Server.Host.Components.Watchdog break; case Watchdog.RebootState.Shutdown: // graceful shutdown time - await Chat.SendWatchdogMessage("Active server rebooted! Exiting due to graceful termination request...", cancellationToken).ConfigureAwait(false); + await Chat.SendWatchdogMessage( + "Active server rebooted! Stopping due to graceful termination request...", + false, + cancellationToken) + .ConfigureAwait(false); DisposeAndNullControllers(); monitorState.NextAction = MonitorAction.Exit; return; @@ -352,12 +382,16 @@ namespace Tgstation.Server.Host.Components.Watchdog // just reload the inactive server and wait for a swap to apply the changes await UpdateAndRestartInactiveServer(true).ConfigureAwait(false); break; + case MonitorActivationReason.Heartbeat: default: - Trace.Assert(false, String.Format(CultureInfo.InvariantCulture, "Invalid monitor activation reason: {0}!", activationReason)); - break; + throw new InvalidOperationException( + String.Format( + CultureInfo.InvariantCulture, + "Invalid monitor activation reason: {0}!", + activationReason)); } } - #pragma warning restore CA1502 +#pragma warning restore CA1502 /// /// Call on and and set them to @@ -372,169 +406,37 @@ namespace Tgstation.Server.Host.Components.Watchdog } /// - #pragma warning disable CA1502 // TODO: Decomplexify - protected override async Task MonitorLifetimes(CancellationToken cancellationToken) + protected override IReadOnlyDictionary GetMonitoredServerTasks(MonitorState monitorState) { - Logger.LogTrace("Entered MonitorLifetimes"); + if (AlphaIsActive) + Logger.LogDebug("Alpha is the active server"); + else + Logger.LogDebug("Bravo is the active server"); - // this function is responsible for calling HandlerMonitorWakeup when necessary and manitaining the MonitorState - var iteration = 1; - for (var monitorState = new MonitorState(); monitorState.NextAction != MonitorAction.Exit; ++iteration) + if (monitorState.RebootingInactiveServer) + Logger.LogDebug("Inactive server is rebooting"); + + // update the monitor state with the inactive/active servers + monitorState.ActiveServer = AlphaIsActive ? alphaServer : bravoServer; + monitorState.InactiveServer = AlphaIsActive ? bravoServer : alphaServer; + + if (monitorState.ActiveServer.ClosePortOnReboot) + Logger.LogDebug("Active server will close port on reboot"); + if (monitorState.InactiveServer.ClosePortOnReboot) + Logger.LogDebug("Inactive server will close port on reboot"); + + Logger.LogDebug("Active server Compile Job ID: {0}", monitorState.ActiveServer.Dmb.CompileJob.Id); + Logger.LogDebug("Inactive server Compile Job ID: {0}", monitorState.InactiveServer.Dmb.CompileJob.Id); + + return new Dictionary { - // always start out with continue - monitorState.NextAction = MonitorAction.Continue; - - // dump some info to the logs - Logger.LogDebug("Iteration {0} of monitor loop", iteration); - try - { - if (AlphaIsActive) - Logger.LogDebug("Alpha is the active server"); - else - Logger.LogDebug("Bravo is the active server"); - - if (monitorState.RebootingInactiveServer) - Logger.LogDebug("Inactive server is rebooting"); - - // update the monitor state with the inactive/active servers - monitorState.ActiveServer = AlphaIsActive ? alphaServer : bravoServer; - monitorState.InactiveServer = AlphaIsActive ? bravoServer : alphaServer; - - if (monitorState.ActiveServer.ClosePortOnReboot) - Logger.LogDebug("Active server will close port on reboot"); - if (monitorState.InactiveServer.ClosePortOnReboot) - Logger.LogDebug("Inactive server will close port on reboot"); - - Logger.LogDebug("Active server Compile Job ID: {0}", monitorState.ActiveServer.Dmb.CompileJob.Id); - Logger.LogDebug("Inactive server Compile Job ID: {0}", monitorState.InactiveServer.Dmb.CompileJob.Id); - - // load the activation tasks into local variables - Task activeServerLifetime = monitorState.ActiveServer.Lifetime; - Task inactiveServerLifetime = monitorState.InactiveServer.Lifetime; - var activeServerReboot = monitorState.ActiveServer.OnReboot; - var inactiveServerReboot = monitorState.InactiveServer.OnReboot; - Task inactiveServerStartup = monitorState.RebootingInactiveServer ? monitorState.InactiveServer.LaunchResult : null; - Task activeLaunchParametersChanged = ActiveParametersUpdated.Task; - var newDmbAvailable = DmbFactory.OnNewerDmb; - - // cancel waiting if requested - var cancelTcs = new TaskCompletionSource(); - using (cancellationToken.Register(() => cancelTcs.SetCanceled())) - { - var toWaitOn = Task.WhenAny(activeServerLifetime, inactiveServerLifetime, activeServerReboot, inactiveServerReboot, newDmbAvailable, cancelTcs.Task, activeLaunchParametersChanged); - if (monitorState.RebootingInactiveServer) - toWaitOn = Task.WhenAny(toWaitOn, inactiveServerStartup); - - // wait for something to happen - await toWaitOn.ConfigureAwait(false); - cancellationToken.ThrowIfCancellationRequested(); - } - - var chatTask = Task.CompletedTask; - using (await SemaphoreSlimContext.Lock(Semaphore, cancellationToken).ConfigureAwait(false)) - { - // always run HandleMonitorWakeup from the context of the semaphore lock - // multiple things may have happened, handle them one at a time - for (var moreActivationsToProcess = true; moreActivationsToProcess && (monitorState.NextAction == MonitorAction.Continue || monitorState.NextAction == MonitorAction.Skip);) - { - MonitorActivationReason activationReason = default; // this will always be assigned before being used - - // process the tasks in this order and call HandlerMonitorWakup for each - bool CheckActivationReason(ref Task task, MonitorActivationReason testActivationReason) - { - var taskCompleted = task?.IsCompleted == true; - task = null; - if (monitorState.NextAction == MonitorAction.Skip) - monitorState.NextAction = MonitorAction.Continue; - else if (taskCompleted) - { - activationReason = testActivationReason; - return true; - } - - return false; - } - - if (CheckActivationReason(ref activeServerLifetime, MonitorActivationReason.ActiveServerCrashed) - || CheckActivationReason(ref inactiveServerLifetime, MonitorActivationReason.InactiveServerCrashed) - || CheckActivationReason(ref activeServerReboot, MonitorActivationReason.ActiveServerRebooted) - || CheckActivationReason(ref inactiveServerReboot, MonitorActivationReason.InactiveServerRebooted) - || CheckActivationReason(ref inactiveServerStartup, MonitorActivationReason.InactiveServerStartupComplete) - || CheckActivationReason(ref newDmbAvailable, MonitorActivationReason.NewDmbAvailable) - || CheckActivationReason(ref activeLaunchParametersChanged, MonitorActivationReason.ActiveLaunchParametersUpdated)) - { - Logger.LogTrace("Monitor activation: {0}", activationReason); - await HandlerMonitorWakeup(activationReason, monitorState, cancellationToken).ConfigureAwait(false); - } - else - moreActivationsToProcess = false; - } - - // writeback alphaServer and bravoServer from monitor state in case they changesd - alphaServer = AlphaIsActive ? monitorState.ActiveServer : monitorState.InactiveServer; - bravoServer = !AlphaIsActive ? monitorState.ActiveServer : monitorState.InactiveServer; - } - - // full reboot required - if (monitorState.NextAction == MonitorAction.Restart) - { - Logger.LogDebug("Next state action is to restart"); - DisposeAndNullControllers(); - chatTask = Chat.SendWatchdogMessage("Restarting entirely due to complications...", cancellationToken); - - for (var retryAttempts = 1; monitorState.NextAction == MonitorAction.Restart; ++retryAttempts) - { - Exception launchException = null; - using (await SemaphoreSlimContext.Lock(Semaphore, cancellationToken).ConfigureAwait(false)) - try - { - // use LaunchImplNoLock without announcements or restarting the monitor - await LaunchImplNoLock(false, false, null, cancellationToken).ConfigureAwait(false); - if (Running) - { - Logger.LogDebug("Relaunch successful, resetting monitor state..."); - monitorState = new MonitorState(); // clean the slate and continue - } - } - catch (OperationCanceledException) - { - throw; - } - catch (Exception e) - { - launchException = e; - } - - await chatTask.ConfigureAwait(false); - if (!Running) - { - if (launchException == null) - Logger.LogWarning("Failed to automatically restart the watchdog! Attempt: {0}", retryAttempts); - else - Logger.LogWarning("Failed to automatically restart the watchdog! Attempt: {0}, Exception: {1}", retryAttempts, launchException); - var retryDelay = Math.Min(Math.Pow(2, retryAttempts), 3600); // max of one hour, increasing by a power of 2 each time - chatTask = Chat.SendWatchdogMessage(String.Format(CultureInfo.InvariantCulture, "Failed to restart watchdog (Attempt: {0}), retrying in {1} seconds...", retryAttempts, retryDelay), cancellationToken); - await Task.WhenAll(AsyncDelayer.Delay(TimeSpan.FromSeconds(retryDelay), cancellationToken), chatTask).ConfigureAwait(false); - } - } - } - } - catch (OperationCanceledException) - { - Logger.LogDebug("Monitor cancelled"); - break; - } - catch (Exception e) - { - // really, this should NEVER happen - Logger.LogError("Monitor crashed! Iteration: {0}, State: {1}, Exception: {2}", iteration, JsonConvert.SerializeObject(monitorState), e); - await Chat.SendWatchdogMessage(String.Format(CultureInfo.InvariantCulture, "Monitor crashed, this should NEVER happen! Please report this, full details in logs! Restarting monitor... Error: {0}", e.Message), cancellationToken).ConfigureAwait(false); - } - } - - Logger.LogTrace("Monitor exiting..."); + { MonitorActivationReason.ActiveServerCrashed, monitorState.ActiveServer.Lifetime }, + { MonitorActivationReason.ActiveServerRebooted, monitorState.ActiveServer.OnReboot }, + { MonitorActivationReason.InactiveServerCrashed, monitorState.InactiveServer.Lifetime }, + { MonitorActivationReason.InactiveServerRebooted, monitorState.InactiveServer.OnReboot }, + { MonitorActivationReason.InactiveServerStartupComplete, monitorState.InactiveServer.OnPrime } + }; } - #pragma warning restore CA1502 /// #pragma warning disable CA1502 // TODO: Decomplexify @@ -611,7 +513,7 @@ namespace Tgstation.Server.Host.Components.Watchdog const string FailReattachMessage = "Unable to properly reattach to active server! Restarting..."; Logger.LogWarning(FailReattachMessage); Logger.LogDebug(bothServersDead ? "Also could not reattach to inactive server!" : "Inactive server was reattached successfully!"); - chatTask = Chat.SendWatchdogMessage(FailReattachMessage, cancellationToken); + chatTask = Chat.SendWatchdogMessage(FailReattachMessage, false, cancellationToken); callBeforeRecurse(); await LaunchImplNoLock(true, false, null, cancellationToken).ConfigureAwait(false); await chatTask.ConfigureAwait(false); @@ -620,7 +522,7 @@ namespace Tgstation.Server.Host.Components.Watchdog // we still have the active server but the other one is dead to us, hand it off to the monitor to restart const string InactiveReattachFailureMessage = "Unable to reattach to inactive server. Leaving for monitor to reboot..."; - chatTask = Chat.SendWatchdogMessage(InactiveReattachFailureMessage, cancellationToken); + chatTask = Chat.SendWatchdogMessage(InactiveReattachFailureMessage, false, cancellationToken); Logger.LogWarning(InactiveReattachFailureMessage); if (reattachInfo.AlphaIsActive) diff --git a/src/Tgstation.Server.Host/Components/Watchdog/ISessionController.cs b/src/Tgstation.Server.Host/Components/Watchdog/ISessionController.cs index 7eaa564691..e27cfa084b 100644 --- a/src/Tgstation.Server.Host/Components/Watchdog/ISessionController.cs +++ b/src/Tgstation.Server.Host/Components/Watchdog/ISessionController.cs @@ -62,6 +62,11 @@ namespace Tgstation.Server.Host.Components.Watchdog /// Task OnReboot { get; } + /// + /// A that completes when the server calls /world/TgsInitializationsComplete() + /// + Task OnPrime { get; } + /// /// Releases the without terminating it. Also calls /// @@ -74,7 +79,7 @@ namespace Tgstation.Server.Host.Components.Watchdog /// The to send. /// The for the operation /// A resulting in the of /world/Topic() - Task SendCommand(TopicParameters parameters, CancellationToken cancellationToken); + Task SendCommand(TopicParameters parameters, CancellationToken cancellationToken); /// /// Causes the world to start listening on a diff --git a/src/Tgstation.Server.Host/Components/Watchdog/MonitorActivationReason.cs b/src/Tgstation.Server.Host/Components/Watchdog/MonitorActivationReason.cs index 2863028238..b21186b5ff 100644 --- a/src/Tgstation.Server.Host/Components/Watchdog/MonitorActivationReason.cs +++ b/src/Tgstation.Server.Host/Components/Watchdog/MonitorActivationReason.cs @@ -38,6 +38,11 @@ /// /// Server launch parameters were changed /// - ActiveLaunchParametersUpdated + ActiveLaunchParametersUpdated, + + /// + /// A heartbeat is required. + /// + Heartbeat, } } diff --git a/src/Tgstation.Server.Host/Components/Watchdog/MonitorState.cs b/src/Tgstation.Server.Host/Components/Watchdog/MonitorState.cs index 79dc4f955d..60d15c8ded 100644 --- a/src/Tgstation.Server.Host/Components/Watchdog/MonitorState.cs +++ b/src/Tgstation.Server.Host/Components/Watchdog/MonitorState.cs @@ -18,7 +18,7 @@ namespace Tgstation.Server.Host.Components.Watchdog public bool InactiveServerCritFail { get; set; } /// - /// The next to take in + /// The next to take in /// public MonitorAction NextAction { get; set; } diff --git a/src/Tgstation.Server.Host/Components/Watchdog/SessionController.cs b/src/Tgstation.Server.Host/Components/Watchdog/SessionController.cs index b0a4ef7884..c74bd16565 100644 --- a/src/Tgstation.Server.Host/Components/Watchdog/SessionController.cs +++ b/src/Tgstation.Server.Host/Components/Watchdog/SessionController.cs @@ -96,6 +96,9 @@ namespace Tgstation.Server.Host.Components.Watchdog /// public Task OnReboot => rebootTcs.Task; + /// + public Task OnPrime => primeTcs.Task; + /// /// The up to date /// @@ -156,6 +159,11 @@ namespace Tgstation.Server.Host.Components.Watchdog /// TaskCompletionSource rebootTcs; + /// + /// The that completes when DD tells us it's primed. + /// + TaskCompletionSource primeTcs; + /// /// If we know DreamDaemon currently has it's port closed /// @@ -218,6 +226,7 @@ namespace Tgstation.Server.Host.Components.Watchdog released = false; rebootTcs = new TaskCompletionSource(); + primeTcs = new TaskCompletionSource(); synchronizationLock = new object(); @@ -365,7 +374,9 @@ namespace Tgstation.Server.Host.Components.Watchdog cancellationToken).ConfigureAwait(false); break; case BridgeCommandType.Prime: - // currently unused, maybe in the future + var oldPrimeTcs = primeTcs; + primeTcs = new TaskCompletionSource(); + oldPrimeTcs.SetResult(null); break; case BridgeCommandType.Kill: logger.LogInformation("Bridge requested process termination!"); @@ -451,9 +462,9 @@ namespace Tgstation.Server.Host.Components.Watchdog portClosedForReboot = true; } - var oldTcs = rebootTcs; + var oldRebootTcs = rebootTcs; rebootTcs = new TaskCompletionSource(); - oldTcs.SetResult(null); + oldRebootTcs.SetResult(null); break; case null: response.ErrorMessage = "Missing commandType!"; @@ -495,7 +506,7 @@ namespace Tgstation.Server.Host.Components.Watchdog } /// - public async Task SendCommand(TopicParameters parameters, CancellationToken cancellationToken) + public async Task SendCommand(TopicParameters parameters, CancellationToken cancellationToken) { if (Lifetime.IsCompleted) { @@ -509,6 +520,7 @@ namespace Tgstation.Server.Host.Components.Watchdog var json = JsonConvert.SerializeObject(parameters, DMApiConstants.SerializerSettings); logger.LogTrace("Topic request: {0}", json); + Exception caughtException; try { var commandString = String.Format(CultureInfo.InvariantCulture, @@ -524,33 +536,39 @@ namespace Tgstation.Server.Host.Components.Watchdog cancellationToken).ConfigureAwait(false); var topicReturn = topicResponse.StringData; - if (topicReturn != null) - logger.LogTrace("Topic response: {0}", topicReturn); - try - { - var result = JsonConvert.DeserializeObject(topicReturn, DMApiConstants.SerializerSettings); - if (result.ErrorMessage != null) + Interop.Topic.TopicResponse interopResponse = null; + if (topicReturn != null) + try { - logger.LogWarning("Errored topic response for command {0}: {1}", parameters.CommandType, result.ErrorMessage); + interopResponse = JsonConvert.DeserializeObject(topicReturn, DMApiConstants.SerializerSettings); + if (interopResponse.ErrorMessage != null) + { + logger.LogWarning("Errored topic response for command {0}: {1}", parameters.CommandType, interopResponse.ErrorMessage); + } + + logger.LogTrace("Interop response: {0}", topicReturn); + } + catch + { + logger.LogWarning("Invalid interop response: {0}", topicReturn); } - return result; - } - catch - { - logger.LogWarning("Invalid topic response: {0}", topicReturn); - } + return new CombinedTopicResponse(topicResponse, interopResponse); } - catch (OperationCanceledException) + catch (OperationCanceledException e) { - throw; + cancellationToken.ThrowIfCancellationRequested(); + caughtException = e; } catch (Exception e) { - logger.LogWarning("Send command exception:{0}{1}", Environment.NewLine, e.Message); + caughtException = e; } + if (caughtException == null) + logger.LogWarning("Send command exception:{0}{1}", Environment.NewLine, caughtException.Message); + return null; } @@ -569,7 +587,7 @@ namespace Tgstation.Server.Host.Components.Watchdog cancellationToken) .ConfigureAwait(false); - if (commandResult.ErrorMessage != null) + if (commandResult.InteropResponse?.ErrorMessage != null) return false; reattachInformation.Port = port; @@ -600,7 +618,7 @@ namespace Tgstation.Server.Host.Components.Watchdog cancellationToken) .ConfigureAwait(false); - return result != null && result.ErrorMessage == null; + return result?.InteropResponse != null && result.InteropResponse?.ErrorMessage == null; } /// diff --git a/src/Tgstation.Server.Host/Components/Watchdog/WatchdogBase.cs b/src/Tgstation.Server.Host/Components/Watchdog/WatchdogBase.cs index 25113ccfcf..88c6d1cf89 100644 --- a/src/Tgstation.Server.Host/Components/Watchdog/WatchdogBase.cs +++ b/src/Tgstation.Server.Host/Components/Watchdog/WatchdogBase.cs @@ -1,5 +1,6 @@ using Microsoft.EntityFrameworkCore; using Microsoft.Extensions.Logging; +using Newtonsoft.Json; using System; using System.Collections.Generic; using System.Linq; @@ -117,6 +118,11 @@ namespace Tgstation.Server.Host.Components.Watchdog /// Task monitorTask; + /// + /// The number of hearbeats missed. + /// + int heartbeatsMissed; + /// /// If the servers should be released instead of shutdown /// @@ -206,7 +212,7 @@ namespace Tgstation.Server.Host.Components.Watchdog return; if (!graceful) { - var chatTask = announce ? Chat.SendWatchdogMessage("Terminating...", cancellationToken) : Task.CompletedTask; + var chatTask = announce ? Chat.SendWatchdogMessage("Terminating...", false, cancellationToken) : Task.CompletedTask; await StopMonitor().ConfigureAwait(false); DisposeAndNullControllers(); @@ -223,6 +229,56 @@ namespace Tgstation.Server.Host.Components.Watchdog await toKill.SetRebootState(Watchdog.RebootState.Shutdown, cancellationToken).ConfigureAwait(false); } + /// + /// Handles a watchdog heartbeat. + /// + /// The active . + /// The for the operation. + /// A resulting in the next to take. + async Task HandleHeartbeat(ISessionController activeServer, CancellationToken cancellationToken) + { + Logger.LogTrace("Sending heartbeat to session controller on :{0}", activeServer.Port); + + var response = await activeServer.SendCommand(new TopicParameters(), cancellationToken).ConfigureAwait(false); + + if (response == null) + { + switch (++heartbeatsMissed) + { + case 1: + Logger.LogDebug("DEFCON 4: Watchdog missed first heartbeat!"); + break; + case 2: + var message2 = "DEFCON 3: Watchdog has missed 2 heartbeats!"; + Logger.LogInformation(message2); + await Chat.SendWatchdogMessage(message2, true, cancellationToken).ConfigureAwait(false); + break; + case 3: + var message3 = "DEFCON 2: Watchdog has missed 3 heartbeats! If DreamDaemon does not respond to the next one, the server will be restarted!"; + Logger.LogWarning(message3); + await Chat.SendWatchdogMessage(message3, false, cancellationToken).ConfigureAwait(false); + break; + case 4: + var shouldShutdown = activeServer.RebootState == Watchdog.RebootState.Shutdown; + var actionToTake = shouldShutdown + ? "Shutting down due to graceful termination request" + : "Restarting"; + var message4 = $"DEFCON 1: Four heartbeats have been missed! {actionToTake}..."; + Logger.LogWarning(message4); + DisposeAndNullControllers(); + await Chat.SendWatchdogMessage(message4, false, cancellationToken).ConfigureAwait(false); + return shouldShutdown ? MonitorAction.Exit : MonitorAction.Restart; + default: + Logger.LogError("Invalid heartbeats missed count: {0}", heartbeatsMissed); + break; + } + } + else + heartbeatsMissed = 0; + + return MonitorAction.Continue; + } + /// /// Launches the watchdog. /// @@ -244,14 +300,15 @@ namespace Tgstation.Server.Host.Components.Watchdog // this is necessary, the monitor could be in it's sleep loop trying to restart, if so cancel THAT monitor and start our own with blackjack and hookers Task chatTask; if (startMonitor && await StopMonitor().ConfigureAwait(false)) - chatTask = Chat.SendWatchdogMessage("Automatic retry sequence cancelled by manual launch. Restarting...", cancellationToken); + chatTask = Chat.SendWatchdogMessage("Automatic retry sequence cancelled by manual launch. Restarting...", false, cancellationToken); else if (announce) - chatTask = Chat.SendWatchdogMessage(reattachInfo == null ? "Starting..." : "Reattaching...", cancellationToken); // simple announce + chatTask = Chat.SendWatchdogMessage(reattachInfo == null ? "Starting..." : "Reattaching...", false, cancellationToken); // simple announce else chatTask = Task.CompletedTask; // no announce // since neither server is running, this is safe to do LastLaunchParameters = ActiveLaunchParameters; + heartbeatsMissed = 0; // for when we call ourself and want to not catch thrown exceptions var ignoreNestedException = false; @@ -277,7 +334,7 @@ namespace Tgstation.Server.Host.Components.Watchdog async Task ChainChatTaskWithErrorMessage() { await originalChatTask.ConfigureAwait(false); - await Chat.SendWatchdogMessage("Startup failed!", cancellationToken).ConfigureAwait(false); + await Chat.SendWatchdogMessage("Startup failed!", false, cancellationToken).ConfigureAwait(false); } chatTask = ChainChatTaskWithErrorMessage(); @@ -337,7 +394,7 @@ namespace Tgstation.Server.Host.Components.Watchdog const string FailReattachMessage = "Unable to properly reattach to server! Restarting..."; Logger.LogWarning(FailReattachMessage); Logger.LogDebug(inactiveReattachSuccess ? "Also could not reattach to inactive server!" : "Inactive server was reattached successfully!"); - Task chatTask = Chat.SendWatchdogMessage(FailReattachMessage, cancellationToken); + Task chatTask = Chat.SendWatchdogMessage(FailReattachMessage, false, cancellationToken); await LaunchImplNoLock(true, false, null, cancellationToken).ConfigureAwait(false); await chatTask.ConfigureAwait(false); } @@ -382,11 +439,201 @@ namespace Tgstation.Server.Host.Components.Watchdog protected abstract WatchdogReattachInformation CreateReattachInformation(); /// - /// The loop that watches the watchdog + /// Gets the tasks for the following s: , , , , . /// - /// The for the operation - /// A representing the running operation - protected abstract Task MonitorLifetimes(CancellationToken cancellationToken); + /// The current . + /// A of the s keyed by their . + protected abstract IReadOnlyDictionary GetMonitoredServerTasks(MonitorState monitorState); + + /// + /// Handles the actions to take when the monitor has to "wake up" + /// + /// The that caused the invocation. + /// The current . + /// The for the operation. + /// A representing the running operation. + protected abstract Task HandleMonitorWakeup( + MonitorActivationReason activationReason, + MonitorState monitorState, + CancellationToken cancellationToken); + + /// + /// The loop that watches the watchdog. + /// + /// The for the operation. + /// A representing the running operation. + private async Task MonitorLifetimes(CancellationToken cancellationToken) + { + Logger.LogTrace("Entered MonitorLifetimes"); + + // this function is responsible for calling HandlerMonitorWakeup when necessary and manitaining the MonitorState + var iteration = 1; + for (var monitorState = new MonitorState(); monitorState.NextAction != MonitorAction.Exit; ++iteration) + { + Logger.LogDebug("Iteration {0} of monitor loop", iteration); + try + { + // load the activation tasks into local variables + cancellationToken.ThrowIfCancellationRequested(); + var serverTasks = GetMonitoredServerTasks(monitorState); + if (serverTasks.Count != 5) + throw new InvalidOperationException("Expected 5 monitored server tasks!"); + + var activeServerLifetime = serverTasks[MonitorActivationReason.ActiveServerCrashed]; + var activeServerReboot = serverTasks[MonitorActivationReason.ActiveServerRebooted]; + var inactiveServerLifetime = serverTasks[MonitorActivationReason.InactiveServerCrashed]; + var inactiveServerReboot = serverTasks[MonitorActivationReason.InactiveServerRebooted]; + var inactiveStartupComplete = serverTasks[MonitorActivationReason.InactiveServerStartupComplete]; + Task activeLaunchParametersChanged = ActiveParametersUpdated.Task; + var newDmbAvailable = DmbFactory.OnNewerDmb; + var heartbeatSeconds = ActiveLaunchParameters.HeartbeatSeconds.Value; + var heartbeat = heartbeatSeconds == 0 + ? Extensions.TaskExtensions.InfiniteTask() + : Task.Delay(TimeSpan.FromSeconds(heartbeatSeconds)); + + // cancel waiting if requested + var cancelTcs = new TaskCompletionSource(); + using (cancellationToken.Register(() => cancelTcs.SetCanceled())) + { + var toWaitOn = Task.WhenAny( + activeServerLifetime, + activeServerReboot, + inactiveServerLifetime, + inactiveServerReboot, + inactiveStartupComplete, + heartbeat, + newDmbAvailable, + cancelTcs.Task, + activeLaunchParametersChanged); + + // wait for something to happen + await toWaitOn.ConfigureAwait(false); + cancellationToken.ThrowIfCancellationRequested(); + } + + var chatTask = Task.CompletedTask; + using (await SemaphoreSlimContext.Lock(Semaphore, cancellationToken).ConfigureAwait(false)) + { + // always run HandleMonitorWakeup from the context of the semaphore lock + // multiple things may have happened, handle them one at a time + for (var moreActivationsToProcess = true; moreActivationsToProcess && (monitorState.NextAction == MonitorAction.Continue || monitorState.NextAction == MonitorAction.Skip);) + { + MonitorActivationReason activationReason = default; // this will always be assigned before being used + + // process the tasks in this order and call HandlerMonitorWakup for each + bool CheckActivationReason(ref Task task, MonitorActivationReason testActivationReason) + { + var taskCompleted = task?.IsCompleted == true; + task = null; + if (monitorState.NextAction == MonitorAction.Skip) + monitorState.NextAction = MonitorAction.Continue; + else if (taskCompleted) + { + activationReason = testActivationReason; + return true; + } + + return false; + } + + if (CheckActivationReason(ref activeServerLifetime, MonitorActivationReason.ActiveServerCrashed) + || CheckActivationReason(ref activeServerReboot, MonitorActivationReason.ActiveServerRebooted) + || CheckActivationReason(ref newDmbAvailable, MonitorActivationReason.NewDmbAvailable) + || CheckActivationReason(ref inactiveServerLifetime, MonitorActivationReason.InactiveServerCrashed) + || CheckActivationReason(ref inactiveServerReboot, MonitorActivationReason.InactiveServerRebooted) + || CheckActivationReason(ref inactiveStartupComplete, MonitorActivationReason.InactiveServerStartupComplete) + || CheckActivationReason(ref activeLaunchParametersChanged, MonitorActivationReason.ActiveLaunchParametersUpdated)) + { + Logger.LogTrace("Monitor activation: {0}", activationReason); + await HandleMonitorWakeup(activationReason, monitorState, cancellationToken).ConfigureAwait(false); + } + else if (CheckActivationReason(ref heartbeat, MonitorActivationReason.Heartbeat)) + { + Logger.LogTrace("Monitor activation: {0}", activationReason); + monitorState.NextAction = await HandleHeartbeat(monitorState.ActiveServer, cancellationToken).ConfigureAwait(false); + } + else + moreActivationsToProcess = false; + } + } + + // full reboot required + if (monitorState.NextAction == MonitorAction.Restart) + { + Logger.LogDebug("Next state action is to restart"); + DisposeAndNullControllers(); + + for (var retryAttempts = 1; ; ++retryAttempts) + { + Exception launchException = null; + using (await SemaphoreSlimContext.Lock(Semaphore, cancellationToken).ConfigureAwait(false)) + try + { + // use LaunchImplNoLock without announcements or restarting the monitor + await LaunchImplNoLock(false, false, null, cancellationToken).ConfigureAwait(false); + if (Running) + { + Logger.LogDebug("Relaunch successful, resetting monitor state..."); + break; // continue on main loop + } + } + catch (OperationCanceledException) + { + throw; + } + catch (Exception e) + { + launchException = e; + } + + await chatTask.ConfigureAwait(false); + if (!Running) + { + if (launchException == null) + Logger.LogWarning("Failed to automatically restart the watchdog! Attempt: {0}", retryAttempts); + else + Logger.LogWarning("Failed to automatically restart the watchdog! Attempt: {0}, Exception: {1}", retryAttempts, launchException); + var retryDelay = Math.Min( + Convert.ToInt32( + Math.Pow(2, retryAttempts)), + TimeSpan.FromHours(1).Seconds); // max of one hour, increasing by a power of 2 each time + chatTask = Chat.SendWatchdogMessage( + $"Failed to restart (Attempt: {retryAttempts}), retrying in {retryDelay}", + false, + cancellationToken); + await Task.WhenAll( + AsyncDelayer.Delay( + TimeSpan.FromSeconds(retryDelay), + cancellationToken), + chatTask) + .ConfigureAwait(false); + } + } + } + } + catch (OperationCanceledException) + { + Logger.LogDebug("Monitor cancelled"); + break; + } + catch (Exception e) + { + // really, this should NEVER happen + Logger.LogError( + "Monitor crashed! Iteration: {0}, Monitor State: {1}, Exception: {2}", + iteration, + JsonConvert.SerializeObject(monitorState), + e); + await Chat.SendWatchdogMessage( + $"Monitor crashed, this should NEVER happen! Please report this, full details in logs! Restarting monitor... Error: {e.Message}", + false, + cancellationToken) + .ConfigureAwait(false); + } + } + + Logger.LogTrace("Monitor exiting..."); + } /// /// Starts all s. @@ -417,7 +664,7 @@ namespace Tgstation.Server.Host.Components.Watchdog if (!Running) return true; - TopicResponse result; + CombinedTopicResponse result; using (await SemaphoreSlimContext.Lock(Semaphore, cancellationToken).ConfigureAwait(false)) { if (!Running) @@ -437,11 +684,11 @@ namespace Tgstation.Server.Host.Components.Watchdog .ConfigureAwait(false); } - if (result?.ChatResponses == null) + if (result?.InteropResponse?.ChatResponses == null) return true; await Task.WhenAll( - result.ChatResponses.Select( + result.InteropResponse.ChatResponses.Select( x => Chat.SendMessage( x.Text, x.ChannelIds @@ -474,10 +721,14 @@ namespace Tgstation.Server.Host.Components.Watchdog var activeServer = GetActiveController(); var commandResult = await activeServer.SendCommand(command, cancellationToken).ConfigureAwait(false); - return commandResult?.CommandResponseMessage ?? - (commandResult == null - ? "ERROR: Bad topic exchange!" - : "TGS: Command processed but no DMAPI response returned!"); + if (commandResult == null) + return "TGS: Bad topic exchange!"; + + if (commandResult.InteropResponse == null) + return "TGS: Bad topic response!"; + + return commandResult.InteropResponse.CommandResponseMessage ?? + "TGS: Command processed but no DMAPI response returned!"; } } @@ -512,7 +763,7 @@ namespace Tgstation.Server.Host.Components.Watchdog Task chatTask; if (Running) { - chatTask = Chat.SendWatchdogMessage("Manual restart triggered...", cancellationToken); + chatTask = Chat.SendWatchdogMessage("Manual restart triggered...", false, cancellationToken); await TerminateNoLock(false, false, cancellationToken).ConfigureAwait(false); } else @@ -569,7 +820,10 @@ namespace Tgstation.Server.Host.Components.Watchdog { try { - if (releaseServers && Running) + if (!Running) + return; + + if (releaseServers) { await StopMonitor().ConfigureAwait(false); @@ -577,7 +831,7 @@ namespace Tgstation.Server.Host.Components.Watchdog await reattachInfoHandler.Save(reattachInformation, cancellationToken).ConfigureAwait(false); } - await Terminate(false, cancellationToken).ConfigureAwait(false); + await TerminateNoLock(false, !releaseServers, cancellationToken).ConfigureAwait(false); } catch { @@ -598,7 +852,7 @@ namespace Tgstation.Server.Host.Components.Watchdog { releaseServers = true; if (Running) - await Chat.SendWatchdogMessage("Detaching...", cancellationToken).ConfigureAwait(false); + await Chat.SendWatchdogMessage("Detaching...", false, cancellationToken).ConfigureAwait(false); } } } diff --git a/src/Tgstation.Server.Host/Controllers/DreamDaemonController.cs b/src/Tgstation.Server.Host/Controllers/DreamDaemonController.cs index 38d443ae52..0500729b4c 100644 --- a/src/Tgstation.Server.Host/Controllers/DreamDaemonController.cs +++ b/src/Tgstation.Server.Host/Controllers/DreamDaemonController.cs @@ -120,19 +120,19 @@ namespace Tgstation.Server.Host.Controllers var alphaActive = dd.AlphaIsActive; var llp = dd.LastLaunchParameters; var rstate = dd.RebootState; - result.AutoStart = settings.AutoStart; - result.CurrentPort = alphaActive ? llp?.PrimaryPort : llp?.SecondaryPort; - result.CurrentSecurity = llp?.SecurityLevel; - result.CurrentAllowWebclient = llp?.AllowWebClient; - result.PrimaryPort = settings.PrimaryPort; - result.AllowWebClient = settings.AllowWebClient; + result.AutoStart = settings.AutoStart.Value; + result.CurrentPort = alphaActive ? llp?.PrimaryPort.Value : llp?.SecondaryPort.Value; + result.CurrentSecurity = llp?.SecurityLevel.Value; + result.CurrentAllowWebclient = llp?.AllowWebClient.Value; + result.PrimaryPort = settings.PrimaryPort.Value; + result.AllowWebClient = settings.AllowWebClient.Value; result.Running = dd.Running; - result.SecondaryPort = settings.SecondaryPort; - result.SecurityLevel = settings.SecurityLevel; + result.SecondaryPort = settings.SecondaryPort.Value; + result.SecurityLevel = settings.SecurityLevel.Value; result.SoftRestart = rstate == RebootState.Restart; result.SoftShutdown = rstate == RebootState.Shutdown; - result.StartupTimeout = settings.StartupTimeout; - result.HeartbeatSeconds = settings.HeartbeatSeconds; + result.StartupTimeout = settings.StartupTimeout.Value; + result.HeartbeatSeconds = settings.HeartbeatSeconds.Value; } if (revision) diff --git a/src/Tgstation.Server.Host/Core/Application.cs b/src/Tgstation.Server.Host/Core/Application.cs index eac9c572f3..44d1dc7a9b 100644 --- a/src/Tgstation.Server.Host/Core/Application.cs +++ b/src/Tgstation.Server.Host/Core/Application.cs @@ -276,8 +276,10 @@ namespace Tgstation.Server.Host.Core services.AddSingleton(); services.AddSingleton(new SocketParameters { - ReceiveTimeout = postSetupServices.GeneralConfiguration.ByondTopicTimeout, - SendTimeout = postSetupServices.GeneralConfiguration.ByondTopicTimeout + ReceiveTimeout = TimeSpan.FromMilliseconds(postSetupServices.GeneralConfiguration.ByondTopicTimeout), + SendTimeout = TimeSpan.FromMilliseconds(postSetupServices.GeneralConfiguration.ByondTopicTimeout), + ConnectTimeout = TimeSpan.FromMilliseconds(postSetupServices.GeneralConfiguration.ByondTopicTimeout), + DisconnectTimeout = TimeSpan.FromMilliseconds(postSetupServices.GeneralConfiguration.ByondTopicTimeout) }); // configure component services diff --git a/src/Tgstation.Server.Host/Extensions/TaskExtensions.cs b/src/Tgstation.Server.Host/Extensions/TaskExtensions.cs index f2e8802173..b71e5edc60 100644 --- a/src/Tgstation.Server.Host/Extensions/TaskExtensions.cs +++ b/src/Tgstation.Server.Host/Extensions/TaskExtensions.cs @@ -48,5 +48,11 @@ namespace Tgstation.Server.Host.Extensions return await task.ConfigureAwait(false); } + + /// + /// Creates a that never completes. + /// + /// A never ending . + public static Task InfiniteTask() => new TaskCompletionSource().Task; } } diff --git a/src/Tgstation.Server.Host/Tgstation.Server.Host.csproj b/src/Tgstation.Server.Host/Tgstation.Server.Host.csproj index 402b3354be..4db31fc889 100644 --- a/src/Tgstation.Server.Host/Tgstation.Server.Host.csproj +++ b/src/Tgstation.Server.Host/Tgstation.Server.Host.csproj @@ -48,7 +48,7 @@ - + diff --git a/tests/Tgstation.Server.Tests/Instance/WatchdogTest.cs b/tests/Tgstation.Server.Tests/Instance/WatchdogTest.cs index 39c7937357..fcbe9ca146 100644 --- a/tests/Tgstation.Server.Tests/Instance/WatchdogTest.cs +++ b/tests/Tgstation.Server.Tests/Instance/WatchdogTest.cs @@ -1,7 +1,10 @@ using Byond.TopicSender; +using Microsoft.Extensions.Logging; using Microsoft.VisualStudio.TestTools.UnitTesting; +using Moq; using System; using System.IO; +using System.Linq; using System.Net; using System.Threading; using System.Threading.Tasks; @@ -24,13 +27,16 @@ namespace Tgstation.Server.Tests.Instance public async Task Run(CancellationToken cancellationToken) { - // Increase startup timeout + // Increase startup timeout, disable heartbeats await instanceClient.DreamDaemon.Update(new DreamDaemon { - StartupTimeout = 45 + StartupTimeout = 45, + HeartbeatSeconds = 0, }, cancellationToken); await RunBasicTest(cancellationToken); + await RunHeartbeatTest(cancellationToken); + // await RunLongRunningTestThenUpdate(cancellationToken); // await RunLongRunningTestThenUpdateWithByondVersionSwitch(cancellationToken); @@ -64,6 +70,52 @@ namespace Tgstation.Server.Tests.Instance await CheckDMApiFail(daemonStatus.ActiveCompileJob, cancellationToken); } + async Task RunHeartbeatTest(CancellationToken cancellationToken) + { + // enable heartbeats + await instanceClient.DreamDaemon.Update(new DreamDaemon + { + HeartbeatSeconds = 1, + }, cancellationToken); + + var startJob = await instanceClient.DreamDaemon.Start(cancellationToken).ConfigureAwait(false); + + await WaitForJob(startJob, 10, false, cancellationToken); + + await instanceClient.DreamDaemon.Update(new DreamDaemon + { + SoftShutdown = true + }, cancellationToken); + + // lock on to DD and pause it so it can't heartbeat + var ddProcs = System.Diagnostics.Process.GetProcessesByName("DreamDaemon").ToList(); + if (ddProcs.Count != 1) + Assert.Inconclusive($"Incorrect number of DD processes: {ddProcs.Count}"); + + var pid = ddProcs.Single().Id; + using var ourProcessHandler = new ProcessExecutor( + new PlatformIdentifier().IsWindows ? (IProcessSuspender)new WindowsProcessSuspender(Mock.Of>()) : new PosixProcessSuspender(Mock.Of>()), + Mock.Of>(), + LoggerFactory.Create(x => { })).GetProcess(pid); + ourProcessHandler.Suspend(); + + await Task.WhenAny(ourProcessHandler.Lifetime, Task.Delay(TimeSpan.FromSeconds(20))); + + var timeout = 10; + do + { + await Task.Delay(TimeSpan.FromSeconds(1), cancellationToken).ConfigureAwait(false); + var ddStatus = await instanceClient.DreamDaemon.Read(cancellationToken); + Assert.AreEqual(1U, ddStatus.HeartbeatSeconds.Value); + if (!ddStatus.Running.Value) + break; + + if (--timeout == 0) + Assert.Fail("DreamDaemon didn't shutdown within the timeout!"); + } + while (timeout > 0); + } + async Task RunLongRunningTestThenUpdate(CancellationToken cancellationToken) { const string DmeName = "LongRunning/long_running_test"; @@ -163,8 +215,10 @@ namespace Tgstation.Server.Tests.Instance { var bts = new TopicClient(new SocketParameters { - SendTimeout = 5000, - ReceiveTimeout = 5000 + SendTimeout = TimeSpan.FromSeconds(5), + ReceiveTimeout = TimeSpan.FromSeconds(5), + ConnectTimeout = TimeSpan.FromSeconds(5), + DisconnectTimeout = TimeSpan.FromSeconds(5) }); try diff --git a/tests/Tgstation.Server.Tests/TestingServer.cs b/tests/Tgstation.Server.Tests/TestingServer.cs index 18d38d4586..6346c766ee 100644 --- a/tests/Tgstation.Server.Tests/TestingServer.cs +++ b/tests/Tgstation.Server.Tests/TestingServer.cs @@ -75,7 +75,8 @@ namespace Tgstation.Server.Tests String.Format(CultureInfo.InvariantCulture, "General:MinimumPasswordLength={0}", 10), String.Format(CultureInfo.InvariantCulture, "General:InstanceLimit={0}", 11), String.Format(CultureInfo.InvariantCulture, "General:UserLimit={0}", 150), - String.Format(CultureInfo.InvariantCulture, "General:ValidInstancePaths:0={0}", Directory) + String.Format(CultureInfo.InvariantCulture, "General:ValidInstancePaths:0={0}", Directory), + "General:ByondTopicTimeout=3000" }; if (!String.IsNullOrEmpty(gitHubAccessToken)) diff --git a/tests/Tgstation.Server.Tests/Tgstation.Server.Tests.csproj b/tests/Tgstation.Server.Tests/Tgstation.Server.Tests.csproj index 56f6e6bb3b..67ce0f1a7d 100644 --- a/tests/Tgstation.Server.Tests/Tgstation.Server.Tests.csproj +++ b/tests/Tgstation.Server.Tests/Tgstation.Server.Tests.csproj @@ -20,4 +20,10 @@ + + + ..\..\..\Byond.TopicSender\Byond.TopicSender\bin\Debug\netstandard2.1\Byond.TopicSender.dll + + +