diff --git a/packages/controller/src/HostConnection.ts b/packages/controller/src/HostConnection.ts index ec2f55d9..5bbc59e2 100644 --- a/packages/controller/src/HostConnection.ts +++ b/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; + // 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, }); diff --git a/test/controller/HostConnection.test.js b/test/controller/HostConnection.test.js index fde949d9..fe884c98 100644 --- a/test/controller/HostConnection.test.js +++ b/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" }]); + }); + }); });