diff --git a/packages/loopover-mcp/bin/loopover-mcp.ts b/packages/loopover-mcp/bin/loopover-mcp.ts index cebff0b461..dbbf931509 100644 --- a/packages/loopover-mcp/bin/loopover-mcp.ts +++ b/packages/loopover-mcp/bin/loopover-mcp.ts @@ -1712,9 +1712,10 @@ export const server = new McpServer({ // Reads the opt-in flag HERE, at module scope, on purpose: registerStdioTool's second parameter is the TOOL's // config and shadows the module-level `config` this resolves from, so a read inside that function would silently // see the wrong object and never fire. -function recordStdioToolTelemetry(tool: any, ok: any, durationMs: any) { +async function recordStdioToolTelemetry(tool: any, ok: any, durationMs: any) { try { - recordLocalMcpToolCall({ telemetryEnabled: telemetryState().enabled }, { tool, callerType: "local", ok, durationMs }); + // Await flush so a short-lived stdio disconnect cannot drop the in-flight PostHog POST (#8690). + await recordLocalMcpToolCall({ telemetryEnabled: telemetryState().enabled }, { tool, callerType: "local", ok, durationMs }); } catch { // Telemetry must never affect the tool response (#6238). } @@ -1727,10 +1728,10 @@ function registerStdioTool(name: any, config: any, handler: any) { const result = await handler(...args); // Mirror the remote's caller-visible outcome (`response.status < 400`): a handler that reports failure by // returning an error result is not a success, even though it never threw. - recordStdioToolTelemetry(name, result?.isError !== true, Date.now() - startedAt); + await recordStdioToolTelemetry(name, result?.isError !== true, Date.now() - startedAt); return result; } catch (error) { - recordStdioToolTelemetry(name, false, Date.now() - startedAt); + await recordStdioToolTelemetry(name, false, Date.now() - startedAt); throw error; } }); diff --git a/packages/loopover-mcp/lib/telemetry.ts b/packages/loopover-mcp/lib/telemetry.ts index 122805dce9..bf6eac273d 100644 --- a/packages/loopover-mcp/lib/telemetry.ts +++ b/packages/loopover-mcp/lib/telemetry.ts @@ -29,8 +29,18 @@ export type McpToolCallEvent = { tool: string; callerType?: "local"; ok: boolean * Record a single local MCP tool call to PostHog. Safe no-op unless `telemetryEnabled` is explicitly * `true` (the caller's resolved, persisted opt-in flag, default OFF -- #6236) AND * LOOPOVER_MCP_POSTHOG_API_KEY is configured; never throws. + * + * Returns a promise that resolves once the event has actually been flushed to PostHog (#8690) — + * mirroring the remote `src/mcp/telemetry.ts` fix (#7233). `capture()` itself is fire-and-forget and + * returns before the network POST lands; awaiting `client.flush()` lets the stdio server (and any + * short-lived CLI path) hold the process open until the event is sent or definitively failed. + * + * Client lifetime: constructs a fresh PostHog client per call (same as the remote wrapper) rather than + * reusing one across the process. That keeps each call's flush/shutdown self-contained and avoids + * holding an idle long-lived client in a long-running `--stdio` session; the flush-before-return + * guarantee does not depend on process-exit hooks. */ -export function recordMcpToolCall(options: RecordMcpToolCallOptions, event: McpToolCallEvent): void { +export async function recordMcpToolCall(options: RecordMcpToolCallOptions, event: McpToolCallEvent): Promise { // Opt-in default OFF (#6236, per #6228's privacy decision) -- unlike the remote wrapper, presence of an // API key alone is not enough; the user must have explicitly enabled telemetry. if (options?.telemetryEnabled !== true) return; @@ -55,9 +65,10 @@ export function recordMcpToolCall(options: RecordMcpToolCallOptions, event: McpT // No IP-based geo enrichment: the event is anonymous fleet telemetry, not a user location. disableGeoip: true, }); + await client.flush(); } catch { - // Telemetry is best-effort and MUST NOT throw into the CLI (#6236): a PostHog init/capture failure - // degrades to recording nothing, identical to the unconfigured path above. + // Telemetry is best-effort and MUST NOT throw into the CLI (#6236): a PostHog init/capture/flush + // failure degrades to recording nothing, identical to the unconfigured path above. } } diff --git a/test/unit/mcp-local-telemetry.test.ts b/test/unit/mcp-local-telemetry.test.ts index 5eb1149c89..cf9d2a988d 100644 --- a/test/unit/mcp-local-telemetry.test.ts +++ b/test/unit/mcp-local-telemetry.test.ts @@ -1,12 +1,19 @@ import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; -// Mock the PostHog Node SDK so nothing hits the network: the class records every constructor + capture call -// on hoisted spies, and per-test flags let us force an init/capture failure to exercise the never-throw path. -// Mirrors test/unit/mcp-telemetry.test.ts's mock for the remote wrapper (#6235). +// Mock the PostHog Node SDK so nothing hits the network: the class records every constructor + capture + +// flush call on hoisted spies, and per-test flags let us force an init/capture/flush failure to exercise +// the never-throw path. Mirrors test/unit/mcp-telemetry.test.ts's mock for the remote wrapper (#6235/#7233). const h = vi.hoisted(() => ({ constructSpy: vi.fn(), captureSpy: vi.fn(), - state: { throwOnConstruct: false, throwOnCapture: false }, + flushSpy: vi.fn(), + state: { + throwOnConstruct: false, + throwOnCapture: false, + throwOnFlush: false, + /** Optional deferred flush body for proving await-before-resolve (#8690). */ + flushImpl: null as null | (() => Promise), + }, })); vi.mock("posthog-node", () => ({ @@ -19,6 +26,11 @@ vi.mock("posthog-node", () => ({ h.captureSpy(message); if (h.state.throwOnCapture) throw new Error("posthog capture failed"); } + async flush(): Promise { + h.flushSpy(); + if (h.state.throwOnFlush) throw new Error("posthog flush failed"); + if (h.state.flushImpl) await h.state.flushImpl(); + } }, })); @@ -33,45 +45,52 @@ describe("recordMcpToolCall (local MCP wrapper, #6236)", () => { beforeEach(() => { h.constructSpy.mockClear(); h.captureSpy.mockClear(); + h.flushSpy.mockClear(); h.state.throwOnConstruct = false; h.state.throwOnCapture = false; + h.state.throwOnFlush = false; + h.state.flushImpl = null; }); afterEach(() => { vi.unstubAllEnvs(); }); - it("is a safe no-op when telemetry is not opted in, even with an API key configured", () => { + it("is a safe no-op when telemetry is not opted in, even with an API key configured", async () => { vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", "phc_test"); - recordMcpToolCall({ telemetryEnabled: false }, EVENT); + await recordMcpToolCall({ telemetryEnabled: false }, EVENT); expect(h.constructSpy).not.toHaveBeenCalled(); expect(h.captureSpy).not.toHaveBeenCalled(); + expect(h.flushSpy).not.toHaveBeenCalled(); }); - it("is a safe no-op when telemetryEnabled is omitted (default OFF)", () => { + it("is a safe no-op when telemetryEnabled is omitted (default OFF)", async () => { vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", "phc_test"); - recordMcpToolCall({}, EVENT); + await recordMcpToolCall({}, EVENT); expect(h.constructSpy).not.toHaveBeenCalled(); expect(h.captureSpy).not.toHaveBeenCalled(); + expect(h.flushSpy).not.toHaveBeenCalled(); }); - it("is a safe no-op when opted in but LOOPOVER_MCP_POSTHOG_API_KEY is unset", () => { + it("is a safe no-op when opted in but LOOPOVER_MCP_POSTHOG_API_KEY is unset", async () => { vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", undefined); - recordMcpToolCall({ telemetryEnabled: true }, EVENT); + await recordMcpToolCall({ telemetryEnabled: true }, EVENT); expect(h.constructSpy).not.toHaveBeenCalled(); expect(h.captureSpy).not.toHaveBeenCalled(); + expect(h.flushSpy).not.toHaveBeenCalled(); }); - it("treats a blank/whitespace API key as unconfigured", () => { + it("treats a blank/whitespace API key as unconfigured", async () => { vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", " "); - recordMcpToolCall({ telemetryEnabled: true }, EVENT); + await recordMcpToolCall({ telemetryEnabled: true }, EVENT); expect(h.constructSpy).not.toHaveBeenCalled(); expect(h.captureSpy).not.toHaveBeenCalled(); + expect(h.flushSpy).not.toHaveBeenCalled(); }); - it("captures exactly the allowlisted fields against the US-cloud default host when opted in and configured", () => { + it("captures exactly the allowlisted fields against the US-cloud default host when opted in and configured", async () => { vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", "phc_test"); - recordMcpToolCall({ telemetryEnabled: true }, EVENT); + await recordMcpToolCall({ telemetryEnabled: true }, EVENT); expect(h.constructSpy).toHaveBeenCalledTimes(1); expect(h.constructSpy).toHaveBeenCalledWith("phc_test", { @@ -93,11 +112,40 @@ describe("recordMcpToolCall (local MCP wrapper, #6236)", () => { }); // The allowlist is the whole payload -- no argument/source/wallet/hotkey/trust-score field can ride along. expect(Object.keys(message.properties).sort()).toEqual(["caller_type", "duration_ms", "ok", "tool"]); + // #8690: the event is actually flushed, not just queued, before recordMcpToolCall's promise resolves. + expect(h.flushSpy).toHaveBeenCalledTimes(1); }); - it("defaults callerType to local when the caller omits it", () => { + it("does not resolve until a delayed flush completes (#8690)", async () => { vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", "phc_test"); - recordMcpToolCall({ telemetryEnabled: true }, { tool: "status", ok: false, durationMs: 0 }); + let releaseFlush!: () => void; + const flushGate = new Promise((resolve) => { + releaseFlush = resolve; + }); + h.state.flushImpl = async () => { + await flushGate; + }; + + let settled = false; + const pending = recordMcpToolCall({ telemetryEnabled: true }, EVENT).then(() => { + settled = true; + }); + + // Give the capture/flush path a turn on the microtask queue without releasing flush. + await Promise.resolve(); + await Promise.resolve(); + expect(h.captureSpy).toHaveBeenCalledTimes(1); + expect(h.flushSpy).toHaveBeenCalledTimes(1); + expect(settled).toBe(false); + + releaseFlush(); + await pending; + expect(settled).toBe(true); + }); + + it("defaults callerType to local when the caller omits it", async () => { + vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", "phc_test"); + await recordMcpToolCall({ telemetryEnabled: true }, { tool: "status", ok: false, durationMs: 0 }); const message = h.captureSpy.mock.calls[0]![0] as CapturedMessage; expect(message.properties).toEqual({ @@ -108,10 +156,10 @@ describe("recordMcpToolCall (local MCP wrapper, #6236)", () => { }); }); - it("honors a LOOPOVER_MCP_POSTHOG_HOST override and carries a failed call verbatim", () => { + it("honors a LOOPOVER_MCP_POSTHOG_HOST override and carries a failed call verbatim", async () => { vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", "phc_test"); vi.stubEnv("LOOPOVER_MCP_POSTHOG_HOST", "https://eu.i.posthog.com"); - recordMcpToolCall({ telemetryEnabled: true }, { tool: "check_slop_risk", callerType: "local", ok: false, durationMs: 7 }); + await recordMcpToolCall({ telemetryEnabled: true }, { tool: "check_slop_risk", callerType: "local", ok: false, durationMs: 7 }); expect(h.constructSpy).toHaveBeenCalledWith("phc_test", { host: "https://eu.i.posthog.com", @@ -127,10 +175,10 @@ describe("recordMcpToolCall (local MCP wrapper, #6236)", () => { }); }); - it("trims surrounding whitespace from the API key and host", () => { + it("trims surrounding whitespace from the API key and host", async () => { vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", " phc_test "); vi.stubEnv("LOOPOVER_MCP_POSTHOG_HOST", " https://eu.i.posthog.com "); - recordMcpToolCall({ telemetryEnabled: true }, EVENT); + await recordMcpToolCall({ telemetryEnabled: true }, EVENT); expect(h.constructSpy).toHaveBeenCalledWith("phc_test", { host: "https://eu.i.posthog.com", flushAt: 1, @@ -138,10 +186,10 @@ describe("recordMcpToolCall (local MCP wrapper, #6236)", () => { }); }); - it("falls back to the default host when LOOPOVER_MCP_POSTHOG_HOST is blank", () => { + it("falls back to the default host when LOOPOVER_MCP_POSTHOG_HOST is blank", async () => { vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", "phc_test"); vi.stubEnv("LOOPOVER_MCP_POSTHOG_HOST", " "); - recordMcpToolCall({ telemetryEnabled: true }, EVENT); + await recordMcpToolCall({ telemetryEnabled: true }, EVENT); expect(h.constructSpy).toHaveBeenCalledWith("phc_test", { host: "https://us.i.posthog.com", flushAt: 1, @@ -149,17 +197,28 @@ describe("recordMcpToolCall (local MCP wrapper, #6236)", () => { }); }); - it("never throws when the PostHog client fails to initialize", () => { + it("never throws when the PostHog client fails to initialize", async () => { vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", "phc_test"); h.state.throwOnConstruct = true; - expect(() => recordMcpToolCall({ telemetryEnabled: true }, EVENT)).not.toThrow(); + await expect(recordMcpToolCall({ telemetryEnabled: true }, EVENT)).resolves.toBeUndefined(); expect(h.captureSpy).not.toHaveBeenCalled(); + expect(h.flushSpy).not.toHaveBeenCalled(); }); - it("never throws when capture itself fails", () => { + it("never throws when capture itself fails", async () => { vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", "phc_test"); h.state.throwOnCapture = true; - expect(() => recordMcpToolCall({ telemetryEnabled: true }, EVENT)).not.toThrow(); + await expect(recordMcpToolCall({ telemetryEnabled: true }, EVENT)).resolves.toBeUndefined(); + expect(h.captureSpy).toHaveBeenCalledTimes(1); + // capture() threw, so flush() is never reached — same catch branch as the constructor failure above. + expect(h.flushSpy).not.toHaveBeenCalled(); + }); + + it("never throws when flush itself fails (#8690) — the event was captured/queued regardless", async () => { + vi.stubEnv("LOOPOVER_MCP_POSTHOG_API_KEY", "phc_test"); + h.state.throwOnFlush = true; + await expect(recordMcpToolCall({ telemetryEnabled: true }, EVENT)).resolves.toBeUndefined(); expect(h.captureSpy).toHaveBeenCalledTimes(1); + expect(h.flushSpy).toHaveBeenCalledTimes(1); }); });