Merge pull request #464 from Hornwitser/player-time-autosave

Player online autosave pool

docs/configuration.md

@@ -271,6 +271,19 @@ If null a random secure password is generated and used each time the instance st
 Defaults to null.
 
 
+### player_online_autosave_slots
+
+Keeps a separate pool for autosaves where at least on player has been online since the previous autosave was done.
+This requires regular autosaving to be enabled and will rename autosaves to `_autosave_poN.zip` (where N is a slot number) whenever a player has been online for that save.
+The slot numbers start at 1, are incremented by 1 after each autosave that is renamed and reset back to 1 whenever this value is exceeded.
+Note that this value should be set to a higher value than the value of `autosave_slots` in `factorio.settings`.
+Useful for preventing the loss of all progress when nobody is around on always online servers with auto pause disabled.
+
+If 0 no autosave renaming takes place.
+
+Defaults to 5.
+
+
 ### factorio.enable_save_patching
 
 Whether to use save patching or not.

packages/lib/config/definitions.js

@@ -265,6 +265,14 @@ FactorioGroup.define({
 	type: "string",
 	optional: true,
 });
+FactorioGroup.define({
+	name: "player_online_autosave_slots",
+	description:
+		"Rename autosaves where players have been online since the previous autosave into a separate autosave " +
+		"pool with this many slots. Requires autosaves to be enabled to work. Set to 0 to disable.",
+	type: "number",
+	initial_value: 5,
+});
 FactorioGroup.define({
 	name: "enable_save_patching",
 	description: "Patch saves with Lua code. Required for Clusterio integrations, lua modules, and most plugins.",

packages/slave/modules/clusterio/impl.lua

@@ -46,7 +46,7 @@ end
 
 
 -- This is not part of the add_remote_interface callback to ensure it is
--- available when the clusterio_lib mod is loaded.	The reason this is
+-- available when the clusterio_lib mod is loaded.  The reason this is
 -- neccessary is that on_init for newly added mods happen before on_load
 -- for existing mods, and the add_remote_interface callback is done in
 -- on_load.  See https://forums.factorio.com/viewtopic.php?f=25&t=81552 for

packages/slave/src/Instance.js

@@ -247,12 +247,134 @@ class Instance extends libLink.Link {
 		});
 
 		this.server.on("ipc-player_event", event => {
-			libLink.messages.playerEvent.send(this, {
-				instance_id: this.id,
-				...event,
-			});
-			libPlugin.invokeHook(this.plugins, "onPlayerEvent", event);
+			if (event.type === "join") {
+				this._recordPlayerJoin(event.name);
+			} else if (event.type === "leave") {
+				this._recordPlayerLeave(event.name);
+			}
 		});
+
+		/**
+		 * @typedef module:slave/src/Instance~PlayerStat
+		 * @type {object}
+		 * @property {number} lastJoinAt -
+		 *     Unix timestamp in ms the player was last seen joining this
+		 *     instance.
+		 * @property {number=} lastLeaveAt -
+		 *     Unix timestamp in ms the player was last seen leaving this
+		 *     instance.  Not present if player has yet to leave after first
+		 *     time joining.
+		 * @property {number} joinCount -
+		 *     Count of the number of times this player has been seen
+		 *     joining this server.
+		 * @property {number} onlineTimeMs -
+		 *     Time in ms this player has been seen online on this instance.
+		 */
+
+		/**
+		 * Per player statistics recorded by this instance.
+		 * @type {Map<string, module:slave/src/Instance~PlayerStat>}
+		 */
+		this.playerStats = new Map();
+
+		/**
+		 * Players currently online on the instance.
+		 * @type {Map<string, string>}
+		 */
+		this.playersOnline = new Set();
+		this._playerCheckInterval = null;
+		this._hadPlayersOnline = false;
+		this._playerAutosaveSlot = 1;
+	}
+
+	_watchPlayerJoinsByChat() {
+		this.server.on("output", (parsed, line) => {
+			if (parsed.type !== "action") {
+				return;
+			}
+
+			let name = /^([^ ]+)/.exec(parsed.message)[1];
+			if (parsed.action === "JOIN") {
+				this._recordPlayerJoin(name);
+			} else if (["LEAVE", "KICK", "BAN"].includes(parsed.action)) {
+				this._recordPlayerLeave(name);
+			}
+		});
+
+		// Leave log entries are unreliable and sometimes don't show up.
+		this._playerCheckInterval = setInterval(() => {
+			this._checkOnlinePlayers().catch(err => {
+				this.logger.error(`Error checking online players:\n${err.stack}`);
+			});
+		}, 60e3);
+	}
+
+	async _checkOnlinePlayers() {
+		if (this.playersOnline.size) {
+			let actualPlayers = (await this.sendRcon("/players online"))
+				.split("\n")
+				.slice(1, -1) // Remove header and trailing newline
+				.map(s => s.slice(2, -" (online)".length))
+			;
+			let left = new Set(this.playersOnline);
+			actualPlayers.map(player => left.delete(player));
+			let joined = new Set(actualPlayers);
+			this.playersOnline.forEach(player => joined.delete(player));
+
+			for (let player of left) {
+				this._recordPlayerLeave(player);
+			}
+
+			// Missing join messages is not supposed to happen.
+			if (joined.size) {
+				this.logger.warn(`Missed join message for ${[...joined].join(", ")}`);
+				for (let player of joined) {
+					this._recordPlayerJoin(player);
+				}
+			}
+		}
+	}
+
+	_recordPlayerJoin(name) {
+		if (this.playersOnline.has(name)) {
+			return;
+		}
+		this.playersOnline.add(name);
+
+		let stats = this.playerStats.get(name);
+		if (!stats) {
+			stats = { joinCount: 0, onlineTimeMs: 0 };
+			this.playerStats.set(name, stats);
+		}
+		stats.lastJoinAt = Date.now();
+		stats.joinCount += 1;
+
+		let event = {
+			instance_id: this.id,
+			type: "join",
+			name,
+		};
+		libLink.messages.playerEvent.send(this, event);
+		libPlugin.invokeHook(this.plugins, "onPlayerEvent", event);
+	}
+
+	_recordPlayerLeave(name) {
+		if (!this.playersOnline.delete(name)) {
+			return;
+		}
+
+		let stats = this.playerStats.get(name);
+		stats.lastLeaveAt = Date.now();
+		stats.onlineTimeMs += stats.lastLeaveAt - stats.lastJoinAt;
+		this._hadPlayersOnline = true;
+
+		let event = {
+			instance_id: this.id,
+			type: "leave",
+			name,
+		};
+		libLink.messages.playerEvent.send(this, event);
+		libPlugin.invokeHook(this.plugins, "onPlayerEvent", event);
 	}
 
 	async sendRcon(message, expectEmpty, plugin = "") {
@@ -302,13 +424,29 @@ class Instance extends libLink.Link {
 	async sendSaveListUpdate() {
 		libLink.messages.saveListUpdate.send(this, {
 			instance_id: this.id,
-			list: await Instance.listSaves(this.server.writePath("saves"), this._loadedSave),
+			list: await Instance.listSaves(this.path("saves"), this._loadedSave),
 		});
 	}
 
 	async _autosave(name) {
 		let stat = await fs.stat(this.path("saves", `${name}.zip`));
 		instanceFactorioAutosaveSize.labels(String(this.id)).set(stat.size);
+
+		if (
+			this.config.get("factorio.player_online_autosave_slots") > 0
+			&& (this._hadPlayersOnline || this.playersOnline.size)
+		) {
+			if (this._playerAutosaveSlot > this.config.get("factorio.player_online_autosave_slots")) {
+				this._playerAutosaveSlot = 1;
+			}
+			await fs.rename(
+				this.path("saves", `${name}.zip`),
+				this.path("saves", `_autosave_po${this._playerAutosaveSlot}.zip`),
+			);
+			this._playerAutosaveSlot += 1;
+			this._hadPlayersOnline = false;
+		}
+
 		await this.sendSaveListUpdate();
 	}
 
@@ -337,6 +475,7 @@ class Instance extends libLink.Link {
 		this.notifyStatus("stopped");
 
 		this.config.off("fieldChanged", this._configFieldChanged);
+		clearTimeout(this._playerCheckInterval);
 
 		// Clear metrics this instance is exporting
 		for (let collector of libPrometheus.defaultRegistry.collectors) {
@@ -352,6 +491,8 @@ class Instance extends libLink.Link {
 		for (let pluginInstance of this.plugins.values()) {
 			pluginInstance.onExit();
 		}
+
+		this._saveStats().catch(err => this.logger.error(`Error saving stats:\n${err.stack}`));
 	}
 
 	async _loadPlugin(pluginInfo, slave) {
@@ -365,9 +506,32 @@ class Instance extends libLink.Link {
 		this.logger.info(`Loaded plugin ${pluginInfo.name} in ${Date.now() - pluginLoadStarted}ms`);
 	}
 
+	async _loadStats() {
+		let stats;
+		try {
+			stats = JSON.parse(await fs.readFile(this.path("instance-stats.json")));
+		} catch (err) {
+			if (err.code === "ENOENT") {
+				return;
+			}
+			throw err;
+		}
+		this.playerStats = new Map(stats["players"]);
+		this._playerAutosaveSlot = stats["player_autosave_slot"] || 1;
+	}
+
+	async _saveStats() {
+		let content = JSON.stringify({
+			players: [...this.playerStats],
+			player_autosave_slot: this._playerAutosaveSlot,
+		}, null, 4);
+		await libFileOps.safeOutputFile(this.path("instance-stats.json"), content);
+	}
+
 	async init(pluginInfos) {
 		this.notifyStatus("starting");
 		try {
+			await this._loadStats();
 			await this.server.init();
 		} catch (err) {
 			this.notifyExit();
@@ -626,6 +790,8 @@ class Instance extends libLink.Link {
 		if (this.config.get("factorio.enable_save_patching")) {
 			await this.server.disableAchievements();
 			await this.updateInstanceData();
+		} else {
+			this._watchPlayerJoinsByChat();
 		}
 
 		await this.sendSaveListUpdate();
@@ -652,6 +818,7 @@ class Instance extends libLink.Link {
 
 		this.server.on("exit", () => this.notifyExit());
 		await this.server.startScenario(scenario, seed, mapGenSettings, mapSettings);
+		this._watchPlayerJoinsByChat();
 
 		await libPlugin.invokeHook(this.plugins, "onStart");
 
@@ -828,7 +995,7 @@ class Instance extends libLink.Link {
 
 	async listSavesRequestHandler(message) {
 		return {
-			list: await Instance.listSaves(this.server.writePath("saves"), this._loadedSave),
+			list: await Instance.listSaves(this.path("saves"), this._loadedSave),
 		};
 	}
 

packages/web_ui/src/components/LoadScenarioModal.jsx

@@ -60,7 +60,7 @@ export default function LoadScenarioModal(props) {
 		}).then(() => {
 			setVisible(false);
 		}).catch(
-			notifyErrorHandler("Error creating save")
+			notifyErrorHandler("Error loading scenario")
 		).finally(() => {
 			setLoadingScenario(false);
 		});

test/lib/factorio/lines.js

@@ -102,6 +102,36 @@ let testLines = new Map([
 			message: "User left the game",
 		},
 	],
+	[
+		"2019-01-20 15:46:34 [KICK] User was kicked by <server>. Reason: unspecified.",
+		{
+			format: "date",
+			time: "2019-01-20 15:46:34",
+			type: "action",
+			action: "KICK",
+			message: "User was kicked by <server>. Reason: unspecified.",
+		},
+	],
+	[
+		"2019-01-20 15:47:50 [BAN] User was banned by <server>. Reason: unspecified.",
+		{
+			format: "date",
+			time: "2019-01-20 15:47:50",
+			type: "action",
+			action: "BAN",
+			message: "User was banned by <server>. Reason: unspecified.",
+		},
+	],
+	[
+		"2019-01-20 15:48:28 [UNBANNED] User was unbanned by <server>.",
+		{
+			format: "date",
+			time: "2019-01-20 15:48:28",
+			type: "action",
+			action: "UNBANNED",
+			message: "User was unbanned by <server>.",
+		},
+	],
 	[
 		"Error while running event level::on_nth_tick(1)",
 		{

test/mock.js

@@ -242,6 +242,7 @@ module.exports = {
 	MockLogger,
 	MockSocket,
 	MockConnector,
+	MockServer,
 	MockInstance,
 	MockSlave,
 	MockControl,

test/slave.js

@@ -13,31 +13,6 @@ describe("Slave testing", function() {
 		libConfig.InstanceConfig.finalize();
 	});
 
-	describe("class Instance", function() {
-		let instance;
-		before(async function() {
-			let instanceConfig = new libConfig.InstanceConfig("slave");
-			await instanceConfig.init();
-			instanceConfig.set("instance.name", "foo");
-			instance = new Instance({}, new libLink.VirtualConnector(), "dir", "factorioDir", instanceConfig);
-		});
-
-		describe(".name", function() {
-			it("should give the name of the instance", function() {
-				assert.equal(instance.name, "foo");
-			});
-		});
-
-		describe(".path()", function() {
-			it("should give the path when called without arguments", function() {
-				assert.equal(instance.path(), "dir");
-			});
-			it("should join path with arguments", function() {
-				assert.equal(instance.path("bar"), path.join("dir", "bar"));
-			});
-		});
-	});
-
 	describe("checkFilename()", function() {
 		it("should allow a basic name", function() {
 			Slave._checkFilename("file");

test/slave/Instance.js

@@ -0,0 +1,156 @@
+"use strict";
+const assert = require("assert").strict;
+const path = require("path");
+
+const libConfig = require("@clusterio/lib/config");
+const { wait } = require("@clusterio/lib/helpers");
+const Instance = require("@clusterio/slave/src/Instance");
+const { MockConnector, MockServer } = require("../mock");
+
+
+describe("class Instance", function() {
+	before(function() {
+		libConfig.InstanceConfig.finalize();
+	});
+
+	let instance;
+	let connector;
+	beforeEach(async function() {
+		let instanceConfig = new libConfig.InstanceConfig("slave");
+		await instanceConfig.init();
+		instanceConfig.set("instance.name", "foo");
+		connector = new MockConnector();
+		instance = new Instance({}, connector, "dir", "factorioDir", instanceConfig);
+		instance.server = new MockServer();
+	});
+
+	describe(".name", function() {
+		it("should give the name of the instance", function() {
+			assert.equal(instance.name, "foo");
+		});
+	});
+
+	describe(".path()", function() {
+		it("should give the path when called without arguments", function() {
+			assert.equal(instance.path(), "dir");
+		});
+		it("should join path with arguments", function() {
+			assert.equal(instance.path("bar"), path.join("dir", "bar"));
+		});
+	});
+
+	describe("._recordPlayerJoin()", function() {
+		it("should add player to playersOnline", function() {
+			instance._recordPlayerJoin("player");
+			assert(instance.playersOnline.has("player"), "player was not added");
+		});
+
+		it("should create playerStats entry", function() {
+			assert(!instance.playerStats.has("player"));
+			instance._recordPlayerJoin("player");
+			assert(instance.playerStats.has("player"), "player was not added to stats");
+		});
+
+
+		it("should send player_event", function() {
+			instance._recordPlayerJoin("player");
+			assert.deepEqual(
+				connector.sentMessages[0],
+				{
+					seq: 1,
+					type: "player_event_event",
+					data: { type: "join", instance_id: instance.id, name: "player" },
+				},
+			);
+		});
+
+		it("should be idempotent", function() {
+			instance._recordPlayerJoin("player");
+			instance._recordPlayerJoin("player");
+			assert(instance.playersOnline.has("player"), "player was not added");
+			assert.equal(connector.sentMessages.length, 1);
+		});
+	});
+
+	describe("._recordPlayerLeave()", function() {
+		it("should remove player to playersOnline", function() {
+			instance._recordPlayerJoin("player");
+			instance._recordPlayerLeave("player");
+			assert(!instance.playersOnline.has("player"), "player was not removed");
+		});
+
+		it("should update playerStats", async function() {
+			instance._recordPlayerJoin("player");
+			await wait(10);
+			instance._recordPlayerLeave("player");
+			assert(instance.playerStats.has("player"), "playerStats record missing");
+			assert(instance.playerStats.get("player").onlineTimeMs > 0, "no onlineTimeMs recorded");
+		});
+
+		it("should send player_event", function() {
+			instance._recordPlayerJoin("player");
+			instance._recordPlayerLeave("player");
+			assert.deepEqual(
+				connector.sentMessages[1],
+				{
+					seq: 2,
+					type: "player_event_event",
+					data: { type: "leave", instance_id: instance.id, name: "player" },
+				},
+			);
+		});
+
+		it("should be idempotent", function() {
+			instance._recordPlayerJoin("player");
+			instance._recordPlayerLeave("player");
+			instance._recordPlayerLeave("player");
+			assert(!instance.playersOnline.has("player"), "player was not removed");
+			assert.equal(connector.sentMessages.length, 2);
+		});
+	});
+
+	describe("._checkOnlinePlayers()", function() {
+		it("should do nothing on empty server", async function() {
+			await instance._checkOnlinePlayers();
+			assert.equal(instance.server.rconCommands.length, 0, "commands were sent");
+			assert.equal(connector.sentMessages.length, 0, "messages were sent");
+		});
+
+		it("should do nothing on correct online presence", async function() {
+			instance.server.rconCommandResults.set("/players online", "Online Players (1):\n  player (online)\n");
+			instance.playersOnline.add("player");
+			await instance._checkOnlinePlayers();
+			assert.equal(connector.sentMessages.length, 0, "messages were sent");
+		});
+
+		it("should add missing players", async function() {
+			instance.server.rconCommandResults.set(
+				"/players online", "Online Players (2):\n  player (online)\n  foo (online)\n"
+			);
+			instance._recordPlayerJoin("player");
+			await instance._checkOnlinePlayers();
+			assert.deepEqual(
+				connector.sentMessages[1],
+				{
+					seq: 2,
+					type: "player_event_event",
+					data: { type: "join", instance_id: instance.id, name: "foo" },
+				},
+			);
+		});
+
+		it("should remove extra players", async function() {
+			instance.server.rconCommandResults.set("/players online", "Online Players (0):\n");
+			instance._recordPlayerJoin("player");
+			await instance._checkOnlinePlayers();
+			assert.deepEqual(
+				connector.sentMessages[1],
+				{
+					seq: 2,
+					type: "player_event_event",
+					data: { type: "leave", instance_id: instance.id, name: "player" },
+				},
+			);
+		});
+	});
+});