From 7ff06f2b96989ea52d12ba3d3f334c29570fb4e5 Mon Sep 17 00:00:00 2001 From: Hornwitser Date: Thu, 12 Sep 2024 18:31:29 +0200 Subject: [PATCH] Rewrite Factorio server shutdown logic Rewrite shutdown logic for Factorio servers to send a /quit command via RCON for both Linux and Windows when stopping a server to avoid having two confusingly intermixed code paths for Windows and Unix systems. This makes shutdown on Windows tell clients the server shut down instead of abruptly stoping to respond. --- CHANGELOG.md | 2 + packages/host/src/Instance.ts | 5 +- packages/host/src/server.ts | 193 ++++++++++++++----------- packages/lib/src/config/definitions.ts | 9 ++ test/host/server.js | 20 ++- test/integration/server.js | 44 ++++++ 6 files changed, 179 insertions(+), 94 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b388eaa6..05e6faa9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -48,6 +48,8 @@ Many thanks to the following for contributing to this release: - Fixed numeric admin name breaking login [#536](https://github.com/clusterio/clusterio/issues/536) - Added factorio.executable_path option which allows overriding the default path to the Factorio executable run. - Added instance version display [#573](https://github.com/clusterio/clusterio/pull/573) +- Added `factorio.shutdown_timeout` config to set the time the host will wait for a Factorio server to shut down befor killing it. +- Changed shutdown logic to prefer sending a /quit command via RCON instead of using diverging logic on Windows and Linux. ### Breaking Changes diff --git a/packages/host/src/Instance.ts b/packages/host/src/Instance.ts index f7e8ae7b..8cbc903b 100644 --- a/packages/host/src/Instance.ts +++ b/packages/host/src/Instance.ts @@ -153,7 +153,9 @@ export default class Instance extends lib.Link { this._configFieldChanged = (field: string, curr: unknown, prev: unknown) => { let hook = () => lib.invokeHook(this.plugins, "onInstanceConfigFieldChanged", field, curr, prev); - if (field === "factorio.settings") { + if (field === "factorio.shutdown_timeout") { + this.server.shutdownTimeoutMs = curr as number * 1000; + } else if (field === "factorio.settings") { this.updateFactorioSettings(curr as any, prev as any).finally(hook); } else if (field === "factorio.enable_whitelist") { this.updateFactorioWhitelist(curr as any).finally(hook); @@ -178,6 +180,7 @@ export default class Instance extends lib.Link { verboseLogging: this.config.get("factorio.verbose_logging"), stripPaths: this.config.get("factorio.strip_paths"), maxConcurrentCommands: this.config.get("factorio.max_concurrent_commands"), + shutdownTimeoutMs: this.config.get("factorio.shutdown_timeout") * 1000, }; this.server = new FactorioServer( diff --git a/packages/host/src/server.ts b/packages/host/src/server.ts index c486e4d4..7e72ba4b 100644 --- a/packages/host/src/server.ts +++ b/packages/host/src/server.ts @@ -351,20 +351,37 @@ const outputHeuristics: Heuristic[] = [ }, }, - // Message indicating the server is shutting down + // Last messages before the server hangs during shutdown waiting for console input on Windows. { filter: { type: "generic", - message: /^Quitting: /, + message: "Quitting: multiplayer error.", }, action: function(parsed) { - this.emit("_quitting"); - // On windows the Factorio server will wait for input on the console input buffer - // when an error occurs. Since we can't send input there we terminate the server + // before shutting down. Since we can't send input there we terminate the server // process when this happens. - if (process.platform === "win32" && parsed.message === "Quitting: multiplayer error.") { + if (process.platform === "win32") { this._server!.kill(); + // Notify that the server is being killed after the last message + // is logged so that it doesn't look like it was killed unnecessarily. + process.nextTick(() => { + this._logger.info("Killing Factorio process to avoid it hanging forever."); + }); + } + }, + }, + { + filter: { + type: "log", + message: /^updateTick\(\d+\) changing state from\(Disconnected\) to\(Closed\)$/, + }, + action: function() { + if (process.platform === "win32") { + this._server!.kill(); + process.nextTick(() => { + this._logger.info("Killing Factorio process to avoid it hanging forever."); + }); } }, }, @@ -428,8 +445,11 @@ export interface FactorioServerOptions { * connection. */ maxConcurrentCommands?: number - /** Timeout in ms to wait for a response to a shutdown command. */ - hangTimeoutMs?: number, + /** + * Timeout in ms to wait after a shutdown is requested before killing the + * process. Defaults to 0 meaning no timeout + */ + shutdownTimeoutMs?: number, } /** @@ -466,8 +486,8 @@ export class FactorioServer extends events.EventEmitter { enableAuthserverBans: boolean; /** Enable verbose logging */ verboseLogging: boolean; - /** Timeout in ms to wait for a response to a shutdown command */ - hangTimeoutMs = 5000; + _shutdownTimeoutMs = 0; + _stopTimeoutId?: ReturnType; _factorioDir: string; _writeDir: string; @@ -523,8 +543,9 @@ export class FactorioServer extends events.EventEmitter { this.verboseLogging = options.verboseLogging || false; /** Maximum number of RCON commands transmitted in parallel on the RCON connection */ this.maxConcurrentCommands = options.maxConcurrentCommands || 5; - /** Timeout in ms to wait for a response to a shutdown command */ - this.hangTimeoutMs = options.hangTimeoutMs ?? 5000; + if (options.shutdownTimeoutMs !== undefined) { + this.shutdownTimeoutMs = options.shutdownTimeoutMs; + } if (options.stripPaths) { let charSet = new Set(path.resolve(this.writePath("temp"))); @@ -666,10 +687,6 @@ export class FactorioServer extends events.EventEmitter { } async _startRcon() { - if (this._state === "stopping") { - return; - } - if (this._rconClient !== null) { throw Error("RCON client is already started"); } @@ -798,6 +815,9 @@ export class FactorioServer extends events.EventEmitter { `\n- ${this._unexpected.join("\n- ")}` )); } + + } else { // if state === "stopping" + this._clearStopTimeout(); } if (this._rconClient) { @@ -1005,6 +1025,44 @@ export class FactorioServer extends events.EventEmitter { return response; } + /** + * Timeout in ms to wait after a shutdown is requested before killing the + * process. Defaults to 0 meaning no timeout + */ + get shutdownTimeoutMs() { + return this._shutdownTimeoutMs; + } + + set shutdownTimeoutMs(newTimeoutMs: number) { + this._shutdownTimeoutMs = newTimeoutMs; + if (this._state === "stopping") { + this._clearStopTimeout(); + this._setStopTimeout(); + } + } + + _setStopTimeout() { + if (this._shutdownTimeoutMs !== 0) { + this._stopTimeoutId = setTimeout( + this.onStopTimeout.bind(this), + this.shutdownTimeoutMs + ); + } + } + + _clearStopTimeout() { + clearTimeout(this._stopTimeoutId); + this._stopTimeoutId = undefined; + } + + onStopTimeout() { + this._logger.error("Factorio appears to have hanged, killing process"); + if (this._rconClient) { + this._rconClient.end().catch(() => {}); + } + this._server!.kill("SIGKILL"); + } + /** * Stop the server * @@ -1013,88 +1071,53 @@ export class FactorioServer extends events.EventEmitter { */ async stop() { this._check(["running"]); - - let hanged = true; - let stopped = false; - function setAlive() { hanged = false; } - - let timeoutId = setTimeout(() => { - if (hanged) { - this._logger.error("Factorio appears to have hanged, sending SIGKILL"); - if (this._rconClient) { - this._rconClient.end().catch(() => {}); - } - this._server!.kill("SIGKILL"); - } - }, this.hangTimeoutMs); - - // It's possible the server decides to exit on its own, in which - // case the stop operation has to be cancelled. - this._server!.once("exit", () => { - stopped = true; - clearTimeout(timeoutId); - }); - this._state = "stopping"; - // On Windows we need to save the map as there's no graceful shutdown. - if (this._rconClient && process.platform === "win32") { - // Not using events.once here as that will reject on error. - let saved = new Promise(resolve => this.once("_saved", resolve)); - this.on("_saving", setAlive); - try { - await this.sendRcon("/server-save"); - await saved; + // It's possible the server doesn't stop if it's stuck in an infinite + // loop or overloaded, kill it if the shutdown takes too long. + this._setStopTimeout(); - } catch (err) { - // Ignore - } - - clearTimeout(timeoutId); - this.off("_saving", setAlive); - } - - if (this._rconClient) { - - // If RCON is not yet fully connected that operation needs to - // complete before the RCON connection can be closed cleanly. - if (!this._rconReady) { - await events.once(this, "rcon-ready"); - } - - await this._rconClient.end(); + // If RCON is not yet fully connected that operation needs to + // complete before the RCON connection can be used + if (!this._rconReady) { + await events.once(this, "rcon-ready"); } // The Factorio server may have decided to get ahead of us and // stop by itself before we had the chance to signal it. - if (stopped) { + if (this._state !== "stopping") { return; } - // On linux this sends SIGTERM to the process. On windows this - // will terminate the process with no cleanup. You can send your - // complaint for the lack of graceful shutdown to the Factorio - // developers. Rcon does not recognize /quit, stdin is not - // recognized, and there's no "send CTRL+C to process" on Windows. - this._server!.kill(); + const waitForExit = events.once(this._server!, "exit"); + waitForExit.catch(() => {}); // Prevent unhandled promise rejection - // There appears to be an race condition where sending SIGTERM - // immediatly before the RCON interface comes online causes the - // Factorio server to hang. It's also possible the server doesn't - // stop if it's stuck with an infinite lua code loop. In either - // case there's no recovering from it. - if (process.platform !== "win32") { - this.on("_quitting", setAlive); - await events.once(this._server!, "exit"); - - clearTimeout(timeoutId); - this.off("_quitting", setAlive); - - // On windows the process is terminated immediately, but to keep - // ordering wait until after the exit event here. + // Stop the server + if (this._rconClient) { + // Use RCON by default to stop the the server as it's available on + // all platforms and simplifies the code. + try { + await this.sendRcon("/quit"); + } catch (err: any) { + // Ignore RCON connection being closed while sending the quit command. + if (err.message !== "Connection closed") { + throw err; + } + } } else { - await events.once(this._server!, "exit"); + // No rcon connection is available, fallback to signal. On linux + // this sends SIGTERM to the process. On windows this + // will terminate the process without saving. You can send your + // complaint for the lack of graceful shutdown options to the + // Factorio developers. I haven't found any way to make stdin work + // and there's no "send CTRL+C to process" API on Windows. + if (process.platform === "win32") { + this._logger.warn("No RCON connection, falling back to killing the server."); + } + this._server!.kill(); } + + await waitForExit; } /** diff --git a/packages/lib/src/config/definitions.ts b/packages/lib/src/config/definitions.ts index 3079e5a7..b50eeaa3 100644 --- a/packages/lib/src/config/definitions.ts +++ b/packages/lib/src/config/definitions.ts @@ -262,6 +262,7 @@ export interface InstanceConfigFields { "factorio.version": string; "factorio.executable_path": string | null; + "factorio.shutdown_timeout": number; "factorio.game_port": number | null; "factorio.host_assigned_game_port": number | null; "factorio.rcon_port": number | null; @@ -320,6 +321,14 @@ export class InstanceConfig extends classes.Config { type: "string", optional: true, }, + "factorio.shutdown_timeout": { + description: + "Timeout in seconds to wait after requesting the server to stop before killing " + + "the process. Set to 0 to disable.", + type: "number", + initialValue: 300, + optional: true, + }, "factorio.game_port": { description: "UDP port to run game on, uses a port in host.factorio_port_range if null", restartRequired: true, diff --git a/test/host/server.js b/test/host/server.js index d4d51b18..1dc541cd 100644 --- a/test/host/server.js +++ b/test/host/server.js @@ -211,24 +211,28 @@ describe("host/server", function() { describe(".stop()", function() { it("should handle server quitting on its own during stop", async function() { - server.hangTimeoutMs = 20; + server.shutdownTimeoutMs = 20; server._server = new events.EventEmitter(); server._server.kill = () => true; server._state = "running"; - server._rconReady = true; + server._rconReady = false; server._rconClient = { + async sendRcon() { }, async end() { server._rconClient = null; - process.nextTick(() => { - server.emit("_quitting"); - server._server.emit("exit"); - }); }, }; server._watchExit(); - await server.stop(); - await wait(21); // Wait until after hang timeout + const stop = server.stop(); + stop.catch(() => {}); + process.nextTick(() => { + server.emit("rcon-ready"); + server._server.emit("exit"); + }); + + await stop; + await wait(21); // Wait until after shutdown timeout }); }); }); diff --git a/test/integration/server.js b/test/integration/server.js index 34890699..13c03b3f 100644 --- a/test/integration/server.js +++ b/test/integration/server.js @@ -229,7 +229,51 @@ describe("Integration of host/src/server", function() { server.sendRcon("/c while true do end").catch(() => {}); await new Promise((resolve) => setTimeout(resolve, 300)); log(".stop() for hang detection"); + server.shutdownTimeoutMs = 2000; await server.stop(); + server.shutdownTimeoutMs = 0; + }); + it("should not hang if RCON fails to connect", async function() { + slowTest(this); + + const origWaitForReady = server._waitForReady; + server._waitForReady = () => { + server._waitForReady = origWaitForReady; + server.rconPort -= 1; // Mangle port so it fails to connect. + return server._waitForReady(); + }; + try { + await server.start("test.zip"); + if (server._rconReady) { + assert.fail("Test failed, RCON managed to connect"); + } + await assert.rejects( + server.stop(), + { code: "ECONNREFUSED" } + ); + + } finally { + if (server._state !== "init") { + await server.kill(); + } + } + }); + it("should work if RCON has dropped out", async function() { + slowTest(this); + + try { + await server.start("test.zip"); + if (!server._rconReady) { + await events.once(server, "rcon-ready"); + } + await server._rconClient.end(); + await server.stop(); + + } finally { + if (server._state !== "init") { + await server.kill(); + } + } }); });