From 474290081d2b99dbb51fffca64becd242b7ebace Mon Sep 17 00:00:00 2001 From: Anso Date: Fri, 22 May 2026 16:30:10 -0400 Subject: [PATCH] fix(mesh): log boot state to console so docker logs surfaces mesh status (#1159) MeshService records its boot summary and setup failures only through logActivity (in-memory ring buffer + WS listeners), which the Routing tab consumes. The docker-logs surface was silent for the mesh subsystem, so operators running Sencho-in-Docker had no boot-time visibility into whether the data plane came up cleanly. Mirror the existing logActivity entries to console without replacing them: - MeshService.start() success summary: console.log / console.warn / console.error gated on the summary level. Format: [Mesh] data plane ok, self attached at , subnet [Mesh] data plane unavailable (: ) - recordSetupFailure: console.warn for the expected dev-mode not_in_docker case, console.error for real failures. Format: [Mesh] data plane unavailable (, subnet ): The activity entries that already drive the Routing tab banner stay intact; the console lines are purely additive for the docker logs workflow. Two new unit tests assert the failure and not_in_docker console mirrors fire with the [Mesh] prefix. Fixes F-5. --- .../mesh-setup-error-classification.test.ts | 40 +++++++++++++++++++ backend/src/services/MeshService.ts | 21 +++++++++- docs/features/sencho-mesh.mdx | 2 + 3 files changed, 61 insertions(+), 2 deletions(-) diff --git a/backend/src/__tests__/mesh-setup-error-classification.test.ts b/backend/src/__tests__/mesh-setup-error-classification.test.ts index bd8c141c..e907af8a 100644 --- a/backend/src/__tests__/mesh-setup-error-classification.test.ts +++ b/backend/src/__tests__/mesh-setup-error-classification.test.ts @@ -441,3 +441,43 @@ describe('MeshService.setupMeshNetwork subnet auto-fallback', () => { expect(status.reason).toBe('subnet_mismatch'); }); }); + +describe('MeshService console.log mirror (F-5)', () => { + it('mirrors a setup failure to console.error with the [Mesh] prefix', async () => { + process.env.SENCHO_MESH_SUBNET = '10.42.0.0/24'; + process.env.HOSTNAME = 'sencho'; + const errSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); + mockDocker({ + createNetwork: vi.fn().mockRejectedValue( + Object.assign(new Error('Pool overlaps with other one on this address space'), { statusCode: 500 }), + ), + }); + + const svc = MeshService.getInstance(); + await callSetup(svc); + + const meshLines = errSpy.mock.calls + .map((args) => String(args[0])) + .filter((line) => line.startsWith('[Mesh] data plane unavailable')); + expect(meshLines.length).toBeGreaterThan(0); + expect(meshLines[0]).toContain('subnet_overlap'); + expect(meshLines[0]).toContain('10.42.0.0/24'); + expect(meshLines[0]).toMatch(/overlap/i); + }); + + it('mirrors a not_in_docker condition to console.warn (expected dev-mode case)', async () => { + process.env.SENCHO_MESH_SUBNET = '10.42.0.0/24'; + delete process.env.HOSTNAME; + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}); + mockDocker(); + + const svc = MeshService.getInstance(); + await callSetup(svc); + + const meshLines = warnSpy.mock.calls + .map((args) => String(args[0])) + .filter((line) => line.startsWith('[Mesh] data plane unavailable')); + expect(meshLines.length).toBeGreaterThan(0); + expect(meshLines[0]).toContain('not_in_docker'); + }); +}); diff --git a/backend/src/services/MeshService.ts b/backend/src/services/MeshService.ts index 48579bdd..e1010174 100644 --- a/backend/src/services/MeshService.ts +++ b/backend/src/services/MeshService.ts @@ -422,13 +422,22 @@ export class MeshService extends EventEmitter implements MeshForwarderHost { const dpReason = this.dataPlaneStatus.reason; const dataPlane = this.senchoIp ? 'ok' : `unavailable (${dpReason}: ${this.networkSetupError ?? 'unknown'})`; const subnetSuffix = this.senchoIp ? `, subnet ${this.meshSubnet}` : ''; + const ipSuffix = this.senchoIp ? `, self attached at ${this.senchoIp}` : ''; const summaryLevel: MeshActivityLevel = dpReason === 'ok' ? 'info' : dpReason === 'not_in_docker' ? 'warn' : 'error'; + const summaryMessage = `MeshService started (data plane ${dataPlane}${subnetSuffix}, self nodeId ${this.selfCentralNodeId})`; this.logActivity({ source: 'mesh', level: summaryLevel, type: 'mesh.enable', - message: `MeshService started (data plane ${dataPlane}${subnetSuffix}, self nodeId ${this.selfCentralNodeId})`, + message: summaryMessage, }); + // Mirror to console so `docker logs sencho` surfaces the boot state. + // The activity entry above feeds the Routing tab; this line feeds the + // operator's `docker logs` workflow. Same content, different surface. + const consoleLine = `[Mesh] data plane ${dataPlane}${ipSuffix}${subnetSuffix}`; + if (summaryLevel === 'error') console.error(consoleLine); + else if (summaryLevel === 'warn') console.warn(consoleLine); + else console.log(consoleLine); } public async stop(): Promise { @@ -554,13 +563,21 @@ export class MeshService extends EventEmitter implements MeshForwarderHost { this.networkSetupError = message; this.dataPlaneStatus = { ok: false, reason, message, subnet }; this.senchoIp = null; + const sanitized = sanitizeForLog(message); this.logActivity({ source: 'mesh', level, type: 'mesh.disable', - message: `mesh data plane unavailable (${reason}): ${sanitizeForLog(message)}`, + message: `mesh data plane unavailable (${reason}): ${sanitized}`, details: { reason, subnet }, }); + // Mirror to console so the failure shows in `docker logs sencho`. The + // start() summary will also emit a boot line after setupMeshNetwork + // returns; this per-failure line gives the specific reason + Docker + // error message for diagnostic purposes. + const consoleLine = `[Mesh] data plane unavailable (${reason}, subnet ${subnet}): ${sanitized}`; + if (level === 'warn') console.warn(consoleLine); + else console.error(consoleLine); } /** diff --git a/docs/features/sencho-mesh.mdx b/docs/features/sencho-mesh.mdx index 7421edfc..2c26da0a 100644 --- a/docs/features/sencho-mesh.mdx +++ b/docs/features/sencho-mesh.mdx @@ -216,6 +216,8 @@ These are the explicit boundaries of the v1 mesh. - `attach_failed`: the Docker daemon refused the network attachment for a reason that does not match the patterns above. The full error appears in the activity log entry and on `/api/health`. The `mesh.dataPlane.subnet` field shows the CIDR Sencho settled on (or the last candidate it tried), so the operator can verify which subnet is configured before changing anything. + + For the container-log view, `docker logs sencho 2>&1 | grep '\[Mesh\]'` shows the boot summary (one line) and any setup failures with the same reason discriminator: `[Mesh] data plane ok, self attached at 172.31.0.2, subnet 172.31.0.0/24` on success, or `[Mesh] data plane unavailable (subnet_overlap, subnet 172.30.0.0/24): Pool overlaps with other one on this address space` on failure.