diff options
Diffstat (limited to 'packages/host-bin/src/mem-telemetry.test.ts')
| -rw-r--r-- | packages/host-bin/src/mem-telemetry.test.ts | 225 |
1 files changed, 225 insertions, 0 deletions
diff --git a/packages/host-bin/src/mem-telemetry.test.ts b/packages/host-bin/src/mem-telemetry.test.ts new file mode 100644 index 0000000..20237ef --- /dev/null +++ b/packages/host-bin/src/mem-telemetry.test.ts @@ -0,0 +1,225 @@ +import type { Attributes, Logger } from "@dispatch/kernel"; +import type { MemorySample } from "@dispatch/session-orchestrator"; +import { describe, expect, it } from "vitest"; +import { + buildGcAttributes, + buildPeriodicAttributes, + type MemoryTelemetryDeps, + startMemoryTelemetry, +} from "./mem-telemetry.js"; + +/** Minimal capturing logger — records every info/debug/warn/error call. */ +interface CapturedLog { + readonly level: string; + readonly msg: string; + readonly attrs?: Attributes; +} + +function capturingLogger(): { logger: Logger; logs: CapturedLog[] } { + const logs: CapturedLog[] = []; + const record = (level: string) => (msg: string, attrs?: Attributes) => { + logs.push({ level, msg, attrs }); + }; + const logger: Logger = { + debug: record("debug"), + info: record("info"), + warn: record("warn"), + error: () => {}, + child: () => logger, + span: () => ({ + id: "s", + log: logger, + setAttributes: () => {}, + addLink: () => {}, + child: () => ({}) as never, + end: () => {}, + }), + }; + return { logger, logs }; +} + +const SAMPLE_A: MemorySample = { + rss: 100 * 1024 * 1024, + heapUsed: 40 * 1024 * 1024, + heapTotal: 60 * 1024 * 1024, + external: 5 * 1024 * 1024, + arrayBuffers: 2 * 1024 * 1024, +}; +const SAMPLE_B: MemorySample = { + rss: 300 * 1024 * 1024, + heapUsed: 80 * 1024 * 1024, + heapTotal: 60 * 1024 * 1024, + external: 5 * 1024 * 1024, + arrayBuffers: 6 * 1024 * 1024, +}; + +describe("buildPeriodicAttributes", () => { + it("formats the sample as MB and tags the active-conversation count", () => { + const attrs = buildPeriodicAttributes(SAMPLE_A, 3); + expect(attrs).toEqual({ + rssMB: 100, + heapUsedMB: 40, + heapTotalMB: 60, + externalMB: 5, + arrayBuffersMB: 2, + activeConversations: 3, + }); + }); +}); + +describe("buildGcAttributes", () => { + it("carries absolute after values plus reclaimed (before-after) delta", () => { + const attrs = buildGcAttributes(SAMPLE_A, SAMPLE_B); + // Absolute "after" values (SAMPLE_B). + expect(attrs.rssMB).toBe(300); + expect(attrs.heapUsedMB).toBe(80); + // Reclaimed delta: before - after is negative here (memory GREW), so + // reclaimedRssMB = round((100-300) MB) = -200. + expect(attrs.reclaimedRssMB).toBe(-200); + expect(attrs.reclaimedHeapUsedMB).toBe(-40); + expect(attrs.reclaimedHeapTotalMB).toBe(0); + expect(attrs.reclaimedArrayBuffersMB).toBe(-4); + }); + + it("shows a positive reclaimed value when GC freed memory", () => { + const attrs = buildGcAttributes(SAMPLE_B, SAMPLE_A); + expect(attrs.reclaimedRssMB).toBe(200); + }); +}); + +describe("startMemoryTelemetry", () => { + function fakeTimers(): { + setInterval: MemoryTelemetryDeps["setInterval"]; + clearInterval: MemoryTelemetryDeps["clearInterval"]; + tick: (name: "sample" | "gc") => void; + cleared: { sample: number; gc: number }; + } { + // Store the callbacks keyed by interval so we can drive either one. The + // gc interval is always larger than the sample interval, so route the + // larger ms to the gc callback. + let sampleCb: (() => void) | undefined; + let gcCb: (() => void) | undefined; + let firstMs = 0; + const cleared = { sample: 0, gc: 0 }; + return { + setInterval: (fn, ms) => { + if (firstMs === 0) { + firstMs = ms; + sampleCb = fn; + return "sample" as never; + } + // The second timer registered is the gc one (larger interval). + gcCb = fn; + return "gc" as never; + }, + clearInterval: (handle) => { + if (handle === "sample") cleared.sample++; + else if (handle === "gc") cleared.gc++; + }, + tick: (name) => { + if (name === "sample") sampleCb?.(); + else gcCb?.(); + }, + cleared, + }; + } + + it("logs a periodic sample tagged with the active-conversation count", () => { + const { logger, logs } = capturingLogger(); + let active = 2; + const timers = fakeTimers(); + const handle = startMemoryTelemetry({ + logger, + sampleMemory: () => SAMPLE_A, + gc: () => {}, + getActiveConversationCount: () => active, + setInterval: timers.setInterval, + clearInterval: timers.clearInterval, + }); + + timers.tick("sample"); + const periodic = logs.find((l) => l.msg === "memory:periodic"); + expect(periodic).toBeDefined(); + expect(periodic?.attrs?.rssMB).toBe(100); + expect(periodic?.attrs?.activeConversations).toBe(2); + + // The count is read live (re-evaluated each tick). + active = 5; + timers.tick("sample"); + const periodic2 = logs.filter((l) => l.msg === "memory:periodic"); + expect(periodic2).toHaveLength(2); + expect(periodic2[1]?.attrs?.activeConversations).toBe(5); + + handle.stop(); + expect(timers.cleared.sample).toBe(1); + expect(timers.cleared.gc).toBe(1); + }); + + it("runs gc and logs RSS before/after on the gc interval", () => { + const { logger, logs } = capturingLogger(); + let calls = 0; + const samples = [SAMPLE_A, SAMPLE_B]; + const timers = fakeTimers(); + const handle = startMemoryTelemetry({ + logger, + sampleMemory: () => samples[calls++] as MemorySample, + gc: () => {}, + getActiveConversationCount: () => 0, + setInterval: timers.setInterval, + clearInterval: timers.clearInterval, + }); + + timers.tick("gc"); + const gcLog = logs.find((l) => l.msg === "memory:gc"); + expect(gcLog).toBeDefined(); + // before=SAMPLE_A (call 0), after=SAMPLE_B (call 1) — rss grew 100→300. + expect(gcLog?.attrs?.rssMB).toBe(300); + expect(gcLog?.attrs?.reclaimedRssMB).toBe(-200); + + handle.stop(); + }); + + it("actually calls the injected gc function", () => { + const { logger } = capturingLogger(); + let gcCalls = 0; + const timers = fakeTimers(); + const handle = startMemoryTelemetry({ + logger, + sampleMemory: () => SAMPLE_A, + gc: () => { + gcCalls++; + }, + getActiveConversationCount: () => 0, + setInterval: timers.setInterval, + clearInterval: timers.clearInterval, + }); + + timers.tick("gc"); + expect(gcCalls).toBe(1); + // Periodic ticks do NOT trigger gc. + timers.tick("sample"); + expect(gcCalls).toBe(1); + + handle.stop(); + }); + + it("stop is idempotent (clearing twice is harmless)", () => { + const { logger } = capturingLogger(); + const timers = fakeTimers(); + const handle = startMemoryTelemetry({ + logger, + sampleMemory: () => SAMPLE_A, + gc: () => {}, + getActiveConversationCount: () => 0, + setInterval: timers.setInterval, + clearInterval: timers.clearInterval, + }); + + handle.stop(); + handle.stop(); + // Both timers cleared exactly once each (second stop is a no-op on the + // same handles — clear count stays at 1 per handle). + expect(timers.cleared.sample).toBe(1); + expect(timers.cleared.gc).toBe(1); + }); +}); |
