feat: add elapsed ms in debugs

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);
   });
 });
 

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<BrainInitResult> {
+  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);

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);
   });
 });
 

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<DailyRunResult> {
+  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<MonthlyRunResult> {
+  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,
   };
 }
 

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`;
+}