chore(observability): prefix log lines with an ISO-8601 UTC timestamp

src/logger.ts

@@ -26,16 +26,21 @@
 
 type Fields = Record<string, unknown> | undefined;
 
+function ts(): string {
+  return new Date().toISOString();
+}
+
 function fmt(level: string, msg: string, fields: Fields): string {
+  const prefix = `${ts()} [agentmemory] ${level}`;
   if (!fields || Object.keys(fields).length === 0) {
-    return `[agentmemory] ${level} ${msg}`;
+    return `${prefix} ${msg}`;
   }
   try {
-    return `[agentmemory] ${level} ${msg} ${JSON.stringify(fields)}`;
+    return `${prefix} ${msg} ${JSON.stringify(fields)}`;
   } catch {
-    // Fields contained a circular reference or a BigInt — fall back
+    // Fields contained a circular reference or a BigInt - fall back
     // to the plain message so a log line never throws.
-    return `[agentmemory] ${level} ${msg}`;
+    return `${prefix} ${msg}`;
   }
 }
 
@@ -88,7 +93,7 @@ export function isBootVerbose(): boolean {
 export function bootLog(msg: string): void {
   if (bootVerbose) {
     try {
-      process.stderr.write(`[agentmemory] ${msg}\n`);
+      process.stderr.write(`${ts()} [agentmemory] ${msg}\n`);
     } catch {
       // stderr unavailable — drop.
     }
@@ -101,7 +106,7 @@ export function bootWarn(msg: string): void {
   // Warnings always surface; they're rare and the user needs to see
   // them even when the rest of the boot log is suppressed.
   try {
-    process.stderr.write(`[agentmemory] warn ${msg}\n`);
+    process.stderr.write(`${ts()} [agentmemory] warn ${msg}\n`);
   } catch {}
 }
 

test/logger.test.ts

@@ -0,0 +1,68 @@
+import { describe, it, expect, vi, afterEach } from "vitest";
+
+import { logger, bootLog, bootWarn, setBootVerbose } from "../src/logger.js";
+
+const ISO_PREFIX = /^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z \[agentmemory\] /;
+
+function spyStderr() {
+  return vi.spyOn(process.stderr, "write").mockImplementation(() => true);
+}
+
+describe("logger timestamps", () => {
+  afterEach(() => {
+    vi.restoreAllMocks();
+    setBootVerbose(false);
+  });
+
+  it("prefixes info lines with an ISO-8601 UTC timestamp", () => {
+    const spy = spyStderr();
+    logger.info("hello world");
+    expect(spy).toHaveBeenCalledTimes(1);
+    const line = spy.mock.calls[0][0] as string;
+    expect(line).toMatch(ISO_PREFIX);
+    expect(line).toContain("[agentmemory] info hello world");
+    expect(line.endsWith("\n")).toBe(true);
+  });
+
+  it("keeps serialized fields after the message", () => {
+    const spy = spyStderr();
+    logger.warn("with fields", { a: 1, b: "two" });
+    const line = spy.mock.calls[0][0] as string;
+    expect(line).toMatch(ISO_PREFIX);
+    expect(line).toContain('[agentmemory] warn with fields {"a":1,"b":"two"}');
+  });
+
+  it("never throws on non-serializable fields and still timestamps", () => {
+    const spy = spyStderr();
+    const circular: Record<string, unknown> = {};
+    circular["self"] = circular;
+    logger.error("boom", circular);
+    const line = spy.mock.calls[0][0] as string;
+    expect(line).toMatch(ISO_PREFIX);
+    expect(line).toContain("[agentmemory] error boom");
+  });
+
+  it("prefixes bootWarn lines with a timestamp", () => {
+    const spy = spyStderr();
+    bootWarn("boot problem");
+    const line = spy.mock.calls[0][0] as string;
+    expect(line).toMatch(ISO_PREFIX);
+    expect(line).toContain("[agentmemory] warn boot problem");
+  });
+
+  it("prefixes verbose bootLog lines with a timestamp", () => {
+    setBootVerbose(true);
+    const spy = spyStderr();
+    bootLog("feature enabled");
+    const line = spy.mock.calls[0][0] as string;
+    expect(line).toMatch(ISO_PREFIX);
+    expect(line).toContain("[agentmemory] feature enabled");
+  });
+
+  it("does not write quiet bootLog lines to stderr", () => {
+    setBootVerbose(false);
+    const spy = spyStderr();
+    bootLog("buffered line");
+    expect(spy).not.toHaveBeenCalled();
+  });
+});