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

@@ -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
 

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(

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<typeof setTimeout>;
 
 	_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;
 	}
 
 	/**

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<InstanceConfigFields> {
 			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,

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
 			});
 		});
 	});

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();
+					}
+				}
 			});
 		});