diff --git a/src/commands/debug/brain.test.ts b/src/commands/debug/brain.test.ts index 7ea7ca4..c4c697c 100644 --- a/src/commands/debug/brain.test.ts +++ b/src/commands/debug/brain.test.ts @@ -136,6 +136,8 @@ describe("runDebugBrainInit", () => { ); expect(result.extractedFacts).toEqual(EXTRACTED_FACTS); + expect(typeof result.elapsedMs).toBe("number"); + expect(result.elapsedMs).toBeGreaterThanOrEqual(0); }); test("B2: invokes the LLM exactly 3 times — PERSONA_INIT, PERSONA_BASE_SYSTEM_PROMPT, fact-extractor", async () => { @@ -194,6 +196,8 @@ describe("runDebugBrainInit", () => { expect(result.ok).toBe(false); if (result.ok) throw new Error("expected !ok"); expect(result.error).toMatch(/Brain initialization failed/); + expect(typeof result.elapsedMs).toBe("number"); + expect(result.elapsedMs).toBeGreaterThanOrEqual(0); }); test("B5: with no DB_PATH / BRAINDB_PATH env, runDebugBrainInit still works (no env dependency)", async () => { @@ -202,6 +206,9 @@ describe("runDebugBrainInit", () => { seed: "no env", }); expect(result.ok).toBe(true); + if (!result.ok) throw new Error("expected ok"); + expect(typeof result.elapsedMs).toBe("number"); + expect(result.elapsedMs).toBeGreaterThanOrEqual(0); }); }); diff --git a/src/commands/debug/brain.ts b/src/commands/debug/brain.ts index e771cae..f91e5d0 100644 --- a/src/commands/debug/brain.ts +++ b/src/commands/debug/brain.ts @@ -6,6 +6,7 @@ import type { Command } from "commander"; import ora from "ora"; import type { ExtractedFact } from "identitydb"; import { Brain } from "@/brain"; +import { formatDuration } from "@/utils/duration"; import { logger } from "@/utils/logger"; export interface BrainInitOptions { @@ -23,8 +24,9 @@ export type BrainInitResult = description: string; baseSystemPrompt: string; extractedFacts: ExtractedFact[]; + elapsedMs: number; } - | { ok: false; error: string }; + | { ok: false; error: string; elapsedMs: number }; /** * Exercise the full `Brain.create` flow (PERSONA_INIT → PERSONA_BASE_SYSTEM_PROMPT @@ -44,6 +46,7 @@ export type BrainInitResult = export async function runDebugBrainInit( opts: BrainInitOptions, ): Promise { + const startTime = Date.now(); const braindbPath = join( tmpdir(), `brainbox-debug-brain-${randomUUID()}.json`, @@ -60,7 +63,8 @@ export async function runDebugBrainInit( }); if (!result) { spinner.fail("Brain initialization failed"); - return { ok: false, error: "Brain initialization failed" }; + const elapsedMs = Date.now() - startTime; + return { ok: false, error: "Brain initialization failed", elapsedMs }; } const { brain, @@ -101,7 +105,10 @@ export async function runDebugBrainInit( } console.log(); - logger.info("Debug run complete. Nothing was written to real disk."); + const elapsedMs = Date.now() - startTime; + logger.info( + `Debug run complete in ${formatDuration(elapsedMs)}. Nothing was written to real disk.`, + ); return { ok: true, @@ -112,11 +119,13 @@ export async function runDebugBrainInit( description, baseSystemPrompt, extractedFacts: extractedFacts ?? [], + elapsedMs, }; } catch (error) { const reason = error instanceof Error ? error.message : String(error); spinner.fail("Brain initialization failed"); - return { ok: false, error: reason }; + const elapsedMs = Date.now() - startTime; + return { ok: false, error: reason, elapsedMs }; } finally { try { await unlink(braindbPath); diff --git a/src/commands/debug/schedule.test.ts b/src/commands/debug/schedule.test.ts index e5df047..42817c3 100644 --- a/src/commands/debug/schedule.test.ts +++ b/src/commands/debug/schedule.test.ts @@ -110,6 +110,8 @@ describe("runDebugScheduleDaily", () => { expect(result.schedule.items).toHaveLength(48); expect(result.availability.items.length).toBeGreaterThan(0); expect(result.dateKey).toMatch(/^\d{4}-\d{2}-\d{2}$/); + expect(typeof result.elapsedMs).toBe("number"); + expect(result.elapsedMs).toBeGreaterThanOrEqual(0); const dailyCall = llmCalls.find( (c) => c.options.jsonSchemaName === "daily-schedule", @@ -133,6 +135,8 @@ describe("runDebugScheduleDaily", () => { expect(result.ok).toBe(false); if (result.ok) throw new Error("expected !ok"); expect(result.error).toMatch(/Daily schedule generation failed/); + expect(typeof result.elapsedMs).toBe("number"); + expect(result.elapsedMs).toBeGreaterThanOrEqual(0); }); }); @@ -149,6 +153,8 @@ describe("runDebugScheduleMonthly", () => { expect(result.kind).toBe("monthly"); expect(result.schedule.items).toHaveLength(result.daysInMonth); expect(result.monthKey).toMatch(/^\d{4}-\d{2}$/); + expect(typeof result.elapsedMs).toBe("number"); + expect(result.elapsedMs).toBeGreaterThanOrEqual(0); const call = llmCalls.find( (c) => c.options.jsonSchemaName === "monthly-schedule", @@ -167,6 +173,8 @@ describe("runDebugScheduleMonthly", () => { expect(result.ok).toBe(false); if (result.ok) throw new Error("expected !ok"); expect(result.error).toMatch(/Monthly schedule generation failed/); + expect(typeof result.elapsedMs).toBe("number"); + expect(result.elapsedMs).toBeGreaterThanOrEqual(0); }); }); diff --git a/src/commands/debug/schedule.ts b/src/commands/debug/schedule.ts index f7f1be6..5ebcdcf 100644 --- a/src/commands/debug/schedule.ts +++ b/src/commands/debug/schedule.ts @@ -6,6 +6,7 @@ import { type DailySchedule, type MonthlySchedule, } from "@/openrouter/schema"; +import { formatDuration } from "@/utils/duration"; import { logger } from "@/utils/logger"; import { formatDateKey, nextMonth, pad2 } from "@/brain/schedule"; @@ -22,8 +23,9 @@ export type DailyRunResult = tomorrow: Date; schedule: DailySchedule; availability: AvailabilityWindows; + elapsedMs: number; } - | { ok: false; error: string }; + | { ok: false; error: string; elapsedMs: number }; export type MonthlyRunResult = | { @@ -32,12 +34,14 @@ export type MonthlyRunResult = monthKey: string; daysInMonth: number; schedule: MonthlySchedule; + elapsedMs: number; } - | { ok: false; error: string }; + | { ok: false; error: string; elapsedMs: number }; export async function runDebugScheduleDaily( opts: ScheduleOptions, ): Promise { + const startTime = Date.now(); const today = new Date(); const tomorrow = new Date( today.getFullYear(), @@ -54,7 +58,12 @@ export async function runDebugScheduleDaily( const schedule = await brain.createDailySchedule(today, opts.message); if (!schedule) { scheduleSpinner.fail("Daily schedule generation failed"); - return { ok: false, error: "Daily schedule generation failed" }; + const elapsedMs = Date.now() - startTime; + return { + ok: false, + error: "Daily schedule generation failed", + elapsedMs, + }; } scheduleSpinner.succeed( `Daily schedule generated (${schedule.items.length} slots)`, @@ -69,7 +78,12 @@ export async function runDebugScheduleDaily( const availability = await brain.deriveAvailabilityFromSchedule(schedule); if (!availability) { availSpinner.fail("Availability derivation failed"); - return { ok: false, error: "Availability derivation failed" }; + const elapsedMs = Date.now() - startTime; + return { + ok: false, + error: "Availability derivation failed", + elapsedMs, + }; } availSpinner.succeed( `Availability derived (${availability.items.length} windows)`, @@ -78,7 +92,10 @@ export async function runDebugScheduleDaily( printSection(`Availability — ${dateKey}`); console.log(JSON.stringify(availability, null, 2)); - logger.info("Debug run complete. Nothing was written to disk."); + const elapsedMs = Date.now() - startTime; + logger.info( + `Debug run complete in ${formatDuration(elapsedMs)}. Nothing was written to disk.`, + ); return { ok: true, @@ -87,12 +104,14 @@ export async function runDebugScheduleDaily( tomorrow, schedule, availability, + elapsedMs, }; } export async function runDebugScheduleMonthly( opts: ScheduleOptions, ): Promise { + const startTime = Date.now(); const today = new Date(); const next = nextMonth(today); const monthKey = `${next.year}-${pad2(next.month + 1)}`; @@ -105,7 +124,12 @@ export async function runDebugScheduleMonthly( const schedule = await brain.createMonthlySchedule(today, opts.message); if (!schedule) { scheduleSpinner.fail("Monthly schedule generation failed"); - return { ok: false, error: "Monthly schedule generation failed" }; + const elapsedMs = Date.now() - startTime; + return { + ok: false, + error: "Monthly schedule generation failed", + elapsedMs, + }; } scheduleSpinner.succeed( `Monthly schedule generated (${schedule.items.length} day summaries)`, @@ -114,8 +138,9 @@ export async function runDebugScheduleMonthly( printSection(`Monthly Schedule — ${monthKey} (${next.daysInMonth} days)`); console.log(JSON.stringify(schedule, null, 2)); + const elapsedMs = Date.now() - startTime; logger.info( - "Debug run complete. Nothing was written to disk. (Availability applies per-day and is not generated for the monthly view.)", + `Debug run complete in ${formatDuration(elapsedMs)}. Nothing was written to disk. (Availability applies per-day and is not generated for the monthly view.)`, ); return { @@ -124,6 +149,7 @@ export async function runDebugScheduleMonthly( monthKey, daysInMonth: next.daysInMonth, schedule, + elapsedMs, }; } diff --git a/src/utils/duration.ts b/src/utils/duration.ts new file mode 100644 index 0000000..968f375 --- /dev/null +++ b/src/utils/duration.ts @@ -0,0 +1,15 @@ +/** + * Format a millisecond duration as a human-readable string. + * - < 1s: "450ms" + * - < 60s: "1.23s" + * - >= 60s: "2m 5s" + */ +export function formatDuration(ms: number): string { + if (ms < 0 || !Number.isFinite(ms)) return "0ms"; + if (ms < 1000) return `${Math.round(ms)}ms`; + const seconds = ms / 1000; + if (seconds < 60) return `${seconds.toFixed(2)}s`; + const minutes = Math.floor(seconds / 60); + const remainingSeconds = Math.floor(seconds % 60); + return `${minutes}m ${remainingSeconds}s`; +}