Rework RCON statistics gathering

Add a sendRcon method to BaseInstancePlugin and the slave's Instance
class.  This servers two purposes, one is to reduce the repetition when
send RCON commands particularly from plugins, and the other is to
instrument the RCON commands sent with metrics about duration and size.

docs/writing-plugins.md

@@ -230,11 +230,11 @@ Communicating with Factorio
 
 For pushing data into Factorio there's RCON, which lets you send
 arbitrary Lua commands to invoke whatever code you want in the game.
-This is done by calling the `sendRcon` method on the instance's server object.
+This is done by calling the `sendRcon` method on the plugin object.
 For example:
 
     async onStart() {
-        let response = await this.instance.server.sendRcon(
+        let response = await this.sendRcon(
             "/sc rcon.print('data')"
         );
 

packages/lib/plugin.js

@@ -192,6 +192,10 @@ class BaseInstancePlugin {
 	 * @param {string} event.name - Name of the player that joined/left.
 	 */
 	async onPlayerEvent(event) { }
+
+	async sendRcon(message, expectEmpty) {
+		return await this.instance.sendRcon(message, expectEmpty, this.info.name);
+	}
 }
 
 /**

packages/slave/slave.js

@@ -36,12 +36,21 @@ const libConfig = require("@clusterio/lib/config");
 const libSharedCommands = require("@clusterio/lib/shared_commands");
 
 
-const instanceRconCommandsCounter = new libPrometheus.Counter(
-	"clusterio_instance_rcon_commands_total",
-	"How many commands have been sent to the instance",
+const instanceRconCommandDuration = new libPrometheus.Histogram(
+	"clusterio_instance_rcon_command_duration_seconds",
+	"Histogram of the RCON command duration from request to response.",
 	{ labels: ["instance_id"] }
 );
 
+const instanceRconCommandSize = new libPrometheus.Histogram(
+	"clusterio_instance_rcon_command_size_bytes",
+	"Histogram of the RCON command sizes that are sent.",
+	{
+		labels: ["instance_id", "plugin"],
+		buckets: libPrometheus.Histogram.exponential(16, 2, 12),
+	}
+);
+
 const instanceFactorioCpuTime = new libPrometheus.Gauge(
 	"clusterio_instance_factorio_cpu_time_total",
 	"Factorio CPU time spent in seconds.",
@@ -61,7 +70,7 @@ const instanceFactorioAutosaveSize = new libPrometheus.Gauge(
 );
 
 function applyAsConfig(name) {
-	return async function action(server, value) {
+	return async function action(instance, value) {
 		if (name === "tags" && value instanceof Array) {
 			// Replace spaces with non-break spaces and delimit by spaces.
 			// This does change the defined tags, but there doesn't seem to
@@ -69,7 +78,7 @@ function applyAsConfig(name) {
 			value = value.map(tag => tag.replace(/ /g, "\u00a0")).join(" ");
 		}
 		try {
-			await server.sendRcon(`/config set ${name} ${value}`);
+			await instance.sendRcon(`/config set ${name} ${value}`);
 		} catch (err) {
 			console.error(`Error applying server setting ${name}`, err);
 		}
@@ -91,11 +100,11 @@ const serverSettingsActions = {
 	"game_password": applyAsConfig("password"),
 	"require_user_verification": applyAsConfig("require-user-verification"),
 	"tags": applyAsConfig("tags"),
-	"visibility": async (server, value) => {
+	"visibility": async (instance, value) => {
 		for (let scope of ["lan", "public", "steam"]) {
 			try {
 				let enabled = Boolean(value[scope]);
-				await server.sendRcon(`/config set visibility-${scope} ${enabled}`);
+				await instance.sendRcon(`/config set visibility-${scope} ${enabled}`);
 			} catch (err) {
 				console.error(`Error applying visibility ${scope}`, err);
 			}
@@ -149,12 +158,6 @@ class Instance extends libLink.Link{
 			factorioDir, this._dir, serverOptions
 		);
 
-		let originalSendRcon = this.server.sendRcon;
-		this.server.sendRcon = (...args) => {
-			instanceRconCommandsCounter.labels(String(this.config.get("instance.id"))).inc();
-			return originalSendRcon.call(this.server, ...args);
-		};
-
 		this.server.on("output", (output) => {
 			libLink.messages.instanceOutput.send(this, { instance_id: this.config.get("instance.id"), output });
 
@@ -180,6 +183,17 @@ class Instance extends libLink.Link{
 		});
 	}
 
+	async sendRcon(message, expectEmpty, plugin = "") {
+		let instanceId = String(this.config.get("instance.id"));
+		let observeDuration = instanceRconCommandDuration.labels(instanceId).startTimer();
+		try {
+			return await this.server.sendRcon(message, expectEmpty);
+		} finally {
+			observeDuration();
+			instanceRconCommandSize.labels(instanceId, plugin).observe(Buffer.byteLength(message, "utf8"));
+		}
+	}
+
 	async _autosave(name) {
 		let stat = await fs.stat(this.path("saves", `${name}.zip`));
 		instanceFactorioAutosaveSize.labels(String(this.config.get("instance.id"))).set(stat.size);
@@ -519,7 +533,7 @@ class Instance extends libLink.Link{
 	async updateInstanceData() {
 		let name = libLuaTools.escapeString(this.config.get("instance.name"));
 		let id = this.config.get("instance.id");
-		await this.server.sendRcon(`/sc clusterio_private.update_instance(${id}, "${name}")`, true);
+		await this.sendRcon(`/sc clusterio_private.update_instance(${id}, "${name}")`, true);
 	}
 
 	async updateFactorioSettings(current, previous) {
@@ -528,7 +542,7 @@ class Instance extends libLink.Link{
 
 		for (let [key, action] of Object.entries(serverSettingsActions)) {
 			if (current[key] !== undefined && !util.isDeepStrictEqual(current[key], previous[key])) {
-				await action(this.server, current[key]);
+				await action(this, current[key]);
 			}
 		}
 	}
@@ -541,18 +555,18 @@ class Instance extends libLink.Link{
 	 */
 	async updateFactorioWhitelist(enable) {
 		if (!enable) {
-			await this.server.sendRcon("/whitelist disable");
+			await this.sendRcon("/whitelist disable");
 		}
 
 		if (this.config.get("factorio.sync_whitelist")) {
-			await this.server.sendRcon("/whitelist clear");
+			await this.sendRcon("/whitelist clear");
 			for (let player of this._slave.whitelist) {
-				await this.server.sendRcon(`/whitelist ${player}`);
+				await this.sendRcon(`/whitelist ${player}`);
 			}
 		}
 
 		if (enable) {
-			await this.server.sendRcon("/whitelist enable");
+			await this.sendRcon("/whitelist enable");
 		}
 	}
 
@@ -563,7 +577,7 @@ class Instance extends libLink.Link{
 
 		let { name, admin } = message.data;
 		let command = admin ? `/promote ${name}` : `/demote ${name}`;
-		await this.server.sendRcon(command);
+		await this.sendRcon(command);
 	}
 
 	async banlistUpdateEventHandler(message) {
@@ -573,7 +587,7 @@ class Instance extends libLink.Link{
 
 		let { name, banned, reason } = message.data;
 		let command = banned ? `/ban ${name} ${reason}` : `/unban ${name}`;
-		await this.server.sendRcon(command);
+		await this.sendRcon(command);
 	}
 
 	async whitelistUpdateEventHandler(message) {
@@ -583,7 +597,7 @@ class Instance extends libLink.Link{
 
 		let { name, whitelisted } = message.data;
 		let command = whitelisted ? `/whitelist add ${name}` : `/whiteliste remove ${name}`;
-		await this.server.sendRcon(command);
+		await this.sendRcon(command);
 	}
 
 
@@ -723,7 +737,7 @@ class Instance extends libLink.Link{
 	}
 
 	async sendRconRequestHandler(message) {
-		let result = await this.server.sendRcon(message.data.command);
+		let result = await this.sendRcon(message.data.command);
 		return { result };
 	}
 

plugins/global_chat/instance.js

@@ -33,7 +33,7 @@ class InstancePlugin extends libPlugin.BaseInstancePlugin {
 	async chatEventHandler(message) {
 		// TODO check if cross server chat is enabled
 		let content = `[${message.data.instance_name}] ${removeTags(message.data.content)}`;
-		await this.instance.server.sendRcon(`/sc game.print('${libLuaTools.escapeString(content)}')`, true);
+		await this.sendRcon(`/sc game.print('${libLuaTools.escapeString(content)}')`, true);
 	}
 
 	sendChat(message) {

plugins/research_sync/instance.js

@@ -29,7 +29,7 @@ class InstancePlugin extends libPlugin.BaseInstancePlugin {
 
 	async progressEventHandler(message) {
 		let techsJson = libLuaTools.escapeString(JSON.stringify(message.data.technologies));
-		await this.instance.server.sendRcon(`/sc research_sync.update_progress("${techsJson}")`, true);
+		await this.sendRcon(`/sc research_sync.update_progress("${techsJson}")`, true);
 	}
 
 	async researchFinished(tech) {
@@ -38,13 +38,13 @@ class InstancePlugin extends libPlugin.BaseInstancePlugin {
 
 	async finishedEventHandler(message) {
 		let { name, level, researched } = message.data;
-		await this.instance.server.sendRcon(
+		await this.sendRcon(
 			`/sc research_sync.research_technology("${libLuaTools.escapeString(name)}", ${level})`, true
 		);
 	}
 
 	async onStart() {
-		let dumpJson = await this.instance.server.sendRcon("/sc research_sync.dump_technologies()");
+		let dumpJson = await this.sendRcon("/sc research_sync.dump_technologies()");
 		let techsToSend = [];
 		let instanceTechs = new Map();
 		for (let tech of JSON.parse(dumpJson)) {
@@ -74,7 +74,7 @@ class InstancePlugin extends libPlugin.BaseInstancePlugin {
 
 		if (techsToSync.length) {
 			let syncJson = libLuaTools.escapeString(JSON.stringify(techsToSync));
-			await this.instance.server.sendRcon(`/sc research_sync.sync_technologies("${syncJson}")`, true);
+			await this.sendRcon(`/sc research_sync.sync_technologies("${syncJson}")`, true);
 		}
 	}
 }

plugins/statistics_exporter/instance.js

@@ -30,7 +30,7 @@ class InstancePlugin extends libPlugin.BaseInstancePlugin {
 	}
 
 	async gatherMetrics() {
-		let string = await this.instance.server.sendRcon("/sc statistics_exporter.export()");
+		let string = await this.sendRcon("/sc statistics_exporter.export()");
 		let stats;
 		try {
 			stats = JSON.parse(string);

plugins/subspace_storage/instance.js

@@ -22,7 +22,7 @@ class InstancePlugin extends libPlugin.BaseInstancePlugin {
 
 	async onStart() {
 		this.pingId = setInterval(() => {
-			this.instance.server.sendRcon(
+			this.sendRcon(
 				"/sc __subspace_storage__ global.ticksSinceMasterPinged = 0", true
 			).catch(unexpectedError);
 		}, 5000);
@@ -30,7 +30,7 @@ class InstancePlugin extends libPlugin.BaseInstancePlugin {
 		let response = await this.info.messages.getStorage.send(this.instance);
 		// TODO Diff with dump of invdata produce minimal command to sync
 		let itemsJson = libLuaTools.escapeString(JSON.stringify(response.items));
-		await this.instance.server.sendRcon(`/sc __subspace_storage__ UpdateInvData("${itemsJson}", true)`, true);
+		await this.sendRcon(`/sc __subspace_storage__ UpdateInvData("${itemsJson}", true)`, true);
 	}
 
 	onExit() {
@@ -68,7 +68,7 @@ class InstancePlugin extends libPlugin.BaseInstancePlugin {
 		}
 
 		let itemsJson = libLuaTools.escapeString(JSON.stringify(response.items));
-		await this.instance.server.sendRcon(`/sc __subspace_storage__ Import("${itemsJson}")`, true);
+		await this.sendRcon(`/sc __subspace_storage__ Import("${itemsJson}")`, true);
 	}
 
 	// combinator signals ---------------------------------------------------------
@@ -87,7 +87,7 @@ class InstancePlugin extends libPlugin.BaseInstancePlugin {
 		items.push(["signal-unixtime", Math.floor(Date.now()/1000)]);
 
 		let itemsJson = libLuaTools.escapeString(JSON.stringify(items));
-		await this.instance.server.sendRcon(`/sc __subspace_storage__ UpdateInvData("${itemsJson}")`, true);
+		await this.sendRcon(`/sc __subspace_storage__ UpdateInvData("${itemsJson}")`, true);
 	}
 }
 

test/mock.js

@@ -92,6 +92,10 @@ class MockInstance extends libLink.Link {
 			},
 		};
 	}
+
+	async sendRcon(command, expectEmpty, plugin) {
+		return await this.server.sendRcon(command);
+	}
 }
 
 class MockSlave extends libLink.Link {