Guard forwarded log messages by instance assignment

Log messages share the root cause with the save details updates fixed in
the previous commit: the controller trusted host supplied instance
fields. LogMessageEvent only declares level and message in its schema,
but the Ajv instance is built without removeAdditional and the schema
does not set additionalProperties, so instance_id and instance_name sent
by a host survive validation and pass through fromJSON untouched. A host
could tag a log line with an instance assigned to another host and have
the controller store and serve it as that instance's output.

Lift the assignment check out of handleInstanceSaveDetailsUpdatesEvent
into a private method and use it from both handlers.

Strip the instance fields instead of dropping the line. A host racing a
reassignment does emit instance log lines for an instance the controller
has already moved, and dropping those loses real output exactly when a
migration is going wrong. The line is still genuine output from the host,
so it is recorded as a host level message, which grants the host nothing
it could not already log directly. Warn once per connection so a
misbehaving host cannot flood the log.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

packages/controller/src/HostConnection.ts

@@ -18,6 +18,8 @@ import HostRecord from "./HostRecord.js";
 export default class HostConnection extends BaseConnection {
 	private info: HostRecord;
 	plugins: Map<string, string>;
+	// Warn once per connection, a misbehaving host could log in a loop.
+	private _warnedBogusLogMessage = false;
 
 	constructor(
 		registerData: lib.RegisterHostData,
@@ -295,20 +297,22 @@ export default class HostConnection extends BaseConnection {
 		await this.send(new lib.SyncUserListsEvent(adminlist, banlist, whitelist));
 	}
 
-	async handleInstanceSaveDetailsUpdatesEvent(event: lib.InstanceSaveDetailsUpdatesEvent) {
-		// A host may only report saves for instances assigned to it. Otherwise
-		// any host could inject save records for, or wipe the save list of, an
-		// instance on a different host. See handleInstanceStatusChangedEvent.
-		const assignedHere = (instanceId: number) => {
-			const instance = this._controller.instances.get(instanceId);
-			return instance !== undefined && instance.config.get("instance.assigned_host") === this.id;
-		};
+	// A host may only report on instances assigned to it. Otherwise any host
+	// could speak for an instance on a different host. See
+	// handleInstanceStatusChangedEvent.
+	private _assignedHere(instanceId: number) {
+		const instance = this._controller.instances.get(instanceId);
+		return instance !== undefined && instance.config.get("instance.assigned_host") === this.id;
+	}
 
-		if (event.instanceId !== undefined && !assignedHere(event.instanceId)) {
+	async handleInstanceSaveDetailsUpdatesEvent(event: lib.InstanceSaveDetailsUpdatesEvent) {
+		// Otherwise any host could inject save records for, or wipe the save
+		// list of, an instance on a different host.
+		if (event.instanceId !== undefined && !this._assignedHere(event.instanceId)) {
 			logger.warn(`Got bogus save updates for instance id ${event.instanceId}`);
 			return;
 		}
-		if (event.updates.some(save => !assignedHere(save.instanceId))) {
+		if (event.updates.some(save => !this._assignedHere(save.instanceId))) {
 			logger.warn(`Got bogus save updates from host id ${this.id}`);
 			return;
 		}
@@ -337,8 +341,23 @@ export default class HostConnection extends BaseConnection {
 	}
 
 	async handleLogMessageEvent(event: lib.LogMessageEvent) {
+		// Fields beyond level and message survive schema validation, so the
+		// instance a log line claims to come from is whatever the host sent.
+		const info: typeof event.info & { instance_id?: number, instance_name?: string } = { ...event.info };
+		if (info.instance_id !== undefined && !this._assignedHere(info.instance_id)) {
+			// Demote to a host level line instead of dropping it. The host did
+			// log this, it just does not get to pin it on someone else's
+			// instance, and a host racing a reassignment still gets heard.
+			if (!this._warnedBogusLogMessage) {
+				this._warnedBogusLogMessage = true;
+				logger.warn(`Got bogus log message for instance id ${info.instance_id}`);
+			}
+			delete info.instance_id;
+			delete info.instance_name;
+		}
+
 		this._controller.clusterLogger.log({
-			...event.info,
+			...info,
 			host_id: this.id,
 			host_name: this.info.name,
 		});

test/controller/HostConnection.test.js

@@ -39,13 +39,14 @@ describe("controller/src/HostConnection", function() {
 		// Instance 1 is on host 10, instance 2 is on host 20.
 		const assignments = new Map([[1, 10], [2, 20]]);
 
+		// Inherit the prototype, handlers call other methods on this.
 		function run(hostId, saves, event) {
 			const saveStore = new MockSaves(saves);
-			const ctx = {
-				id: hostId,
+			const ctx = Object.assign(Object.create(HostConnection.prototype), {
+				info: { id: hostId },
 				_controller: { instances: makeInstances(assignments), saves: saveStore },
-			};
-			HostConnection.prototype.handleInstanceSaveDetailsUpdatesEvent.call(ctx, event);
+			});
+			ctx.handleInstanceSaveDetailsUpdatesEvent(event);
 			return saveStore;
 		}
 
@@ -75,4 +76,50 @@ describe("controller/src/HostConnection", function() {
 			assert.deepEqual([...store.values()], []);
 		});
 	});
+
+	describe(".handleLogMessageEvent()", function() {
+		// Instance 1 is on host 10, instance 2 is on host 20.
+		const assignments = new Map([[1, 10], [2, 20]]);
+
+		function run(hostId, info) {
+			const logged = [];
+			const ctx = Object.assign(Object.create(HostConnection.prototype), {
+				info: { id: hostId, name: `host-${hostId}` },
+				_controller: {
+					instances: makeInstances(assignments),
+					clusterLogger: { log(entry) { logged.push(entry); } },
+				},
+			});
+			ctx.handleLogMessageEvent(new lib.LogMessageEvent(info));
+			return logged;
+		}
+
+		it("keeps instance fields for an instance assigned to this host", async function() {
+			const logged = run(10, { level: "info", message: "hello", instance_id: 1, instance_name: "one" });
+			assert.deepEqual(logged, [{
+				level: "info", message: "hello", instance_id: 1, instance_name: "one",
+				host_id: 10, host_name: "host-10",
+			}]);
+		});
+
+		it("logs host level messages unchanged", async function() {
+			const logged = run(10, { level: "info", message: "hello" });
+			assert.deepEqual(logged, [{ level: "info", message: "hello", host_id: 10, host_name: "host-10" }]);
+		});
+
+		it("strips instance fields claiming an instance on another host", async function() {
+			const logged = run(30, { level: "info", message: "hi", instance_id: 1, instance_name: "one" });
+			assert.deepEqual(logged, [{ level: "info", message: "hi", host_id: 30, host_name: "host-30" }]);
+		});
+
+		it("strips instance fields claiming a nonexistent instance", async function() {
+			const logged = run(30, { level: "info", message: "hi", instance_id: 999, instance_name: "ghost" });
+			assert.deepEqual(logged, [{ level: "info", message: "hi", host_id: 30, host_name: "host-30" }]);
+		});
+
+		it("overrides host fields sent by the host", async function() {
+			const logged = run(10, { level: "info", message: "hi", host_id: 99, host_name: "spoofed" });
+			assert.deepEqual(logged, [{ level: "info", message: "hi", host_id: 10, host_name: "host-10" }]);
+		});
+	});
 });