Fix: use structured logging in session-memory hook (AI-assisted)

src/hooks/bundled/session-memory/handler.test.ts

@@ -0,0 +1,171 @@
+import { describe, it, expect, vi, beforeEach, afterEach } from "vitest";
+import path from "node:path";
+import os from "node:os";
+
+// Helper to get mocked modules
+const { mockFs, mockLogger } = vi.hoisted(() => {
+  return {
+    mockFs: {
+      readFile: vi.fn(),
+      mkdir: vi.fn(),
+      writeFile: vi.fn(),
+    },
+    mockLogger: {
+      info: vi.fn(),
+      debug: vi.fn(),
+      error: vi.fn(),
+      child: vi.fn().mockReturnValue({
+        info: vi.fn(),
+        debug: vi.fn(),
+        error: vi.fn(),
+      }),
+    },
+  };
+});
+
+// Mock modules with hoisted implementations
+vi.mock("node:fs/promises", () => ({
+  default: mockFs,
+}));
+
+vi.mock("../../../logging/subsystem.js", () => ({
+  createSubsystemLogger: () => mockLogger,
+}));
+
+// Mock LLM slug generator dynamic import
+vi.mock("../../llm-slug-generator.js", () => ({
+  generateSlugViaLLM: vi.fn().mockResolvedValue("mock-slug"),
+}));
+
+import saveSessionToMemory from "./handler.js";
+
+describe("session-memory handler", () => {
+  beforeEach(async () => {
+    vi.clearAllMocks();
+  });
+
+  afterEach(() => {
+    vi.resetModules();
+  });
+
+  it("should ignore non-new commands", async () => {
+    await saveSessionToMemory({
+      type: "command",
+      action: "stop",
+      sessionKey: "test-session",
+      context: {},
+      timestamp: new Date(),
+      messages: [],
+    });
+
+    expect(mockLogger.info).not.toHaveBeenCalled();
+    expect(mockFs.writeFile).not.toHaveBeenCalled();
+  });
+
+  it("should handle basic /new command execution with fallback slug", async () => {
+    const timestamp = new Date("2024-01-01T12:00:00Z");
+    const event = {
+      type: "command" as const,
+      action: "new",
+      sessionKey: "test-session",
+      context: {
+        cfg: {},
+        sessionEntry: {
+          sessionId: "sid-123",
+          sessionFile: "/tmp/session.jsonl",
+        },
+      },
+      timestamp,
+      messages: [],
+    };
+
+    // Setup fs mocks
+    // Return empty content to trigger fallback
+    mockFs.readFile.mockResolvedValue("");
+
+    await saveSessionToMemory(event);
+
+    expect(mockLogger.info).toHaveBeenCalledWith("Hook triggered for /new command");
+    expect(mockFs.mkdir).toHaveBeenCalled();
+
+    // Verify fallback slug usage (time based)
+    expect(mockLogger.info).toHaveBeenCalledWith(
+      expect.stringContaining("Using fallback timestamp slug"),
+    );
+
+    // Verify file write
+    expect(mockFs.writeFile).toHaveBeenCalled();
+    const [filePath, content] = mockFs.writeFile.mock.calls[0];
+
+    // Check filename structure: YYYY-MM-DD-HHMM.md
+    expect(filePath).toContain("2024-01-01-1200.md");
+    expect(content).toContain("# Session: 2024-01-01 12:00:00 UTC");
+    expect(content).toContain("- **Session ID**: sid-123");
+
+    expect(mockLogger.info).toHaveBeenCalledWith("Memory file written successfully");
+  });
+
+  it("should handle LLM slug generation when content is available", async () => {
+    const timestamp = new Date("2024-01-01T12:00:00Z");
+    const event = {
+      type: "command" as const,
+      action: "new",
+      sessionKey: "test-session",
+      context: {
+        cfg: {}, // Config present enables LLM
+        sessionEntry: {
+          sessionId: "sid-123",
+          sessionFile: "/tmp/session.jsonl",
+        },
+      },
+      timestamp,
+      messages: [],
+    };
+
+    // Valid JSONL session content
+    const sessionContent = `
+      {"type":"message","message":{"role":"user","content":"hello"}}
+      {"type":"message","message":{"role":"assistant","content":"hi there"}}
+    `.trim();
+
+    mockFs.readFile.mockResolvedValue(sessionContent);
+
+    // Dynamic import mock setup for this specific test
+    // Note: We need to mock the import result for the handler's dynamic import
+    // This is tricky with vitest, but since we mocked the module path above,
+    // we rely on the implementation detail that it tries to import from ../../llm-slug-generator.js
+
+    await saveSessionToMemory(event);
+
+    // Check for specific calls by inspecting mock history
+    const infoCalls = mockLogger.info.mock.calls.map((call: any[]) => call[0]);
+
+    // Assert no errors first - if this fails, we want to see the error message
+    expect(mockLogger.error).not.toHaveBeenCalled();
+
+    expect(infoCalls).toContainEqual(expect.stringContaining("Hook triggered for /new command"));
+    expect(infoCalls).toContainEqual(expect.stringContaining("Calling generateSlugViaLLM..."));
+    expect(infoCalls).toContainEqual(expect.stringContaining("Generated slug: mock-slug"));
+
+    // Verify file write with mock slug
+    const [filePath] = mockFs.writeFile.mock.calls[0];
+    expect(filePath).toContain("2024-01-01-mock-slug.md");
+  });
+
+  it("should log errors cleanly", async () => {
+    mockFs.mkdir.mockRejectedValue(new Error("Disk error"));
+
+    await saveSessionToMemory({
+      type: "command",
+      action: "new",
+      sessionKey: "test-session",
+      context: {},
+      timestamp: new Date(),
+      messages: [],
+    });
+
+    expect(mockLogger.error).toHaveBeenCalledWith(
+      expect.stringContaining("Failed to save session memory: Disk error"),
+    );
+  });
+});

src/hooks/bundled/session-memory/handler.ts

@@ -12,6 +12,9 @@ import type { ClawdbotConfig } from "../../../config/config.js";
 import { resolveAgentWorkspaceDir } from "../../../agents/agent-scope.js";
 import { resolveAgentIdFromSessionKey } from "../../../routing/session-key.js";
 import type { HookHandler } from "../../hooks.js";
+import { createSubsystemLogger } from "../../../logging/subsystem.js";
+
+const log = createSubsystemLogger("hooks/session-memory");
 
 /**
  * Read recent messages from session file for slug generation
@@ -64,7 +67,7 @@ const saveSessionToMemory: HookHandler = async (event) => {
   }
 
   try {
-    console.log("[session-memory] Hook triggered for /new command");
+    log.info("Hook triggered for /new command");
 
     const context = event.context || {};
     const cfg = context.cfg as ClawdbotConfig | undefined;
@@ -87,9 +90,9 @@ const saveSessionToMemory: HookHandler = async (event) => {
     const currentSessionId = sessionEntry.sessionId as string;
     const currentSessionFile = sessionEntry.sessionFile as string;
 
-    console.log("[session-memory] Current sessionId:", currentSessionId);
+    log.debug(`Current sessionId: ${currentSessionId}`);
-    console.log("[session-memory] Current sessionFile:", currentSessionFile);
+    log.debug(`Current sessionFile: ${currentSessionFile}`);
-    console.log("[session-memory] cfg present:", !!cfg);
+    log.debug(`cfg present: ${!!cfg}`);
 
     const sessionFile = currentSessionFile || undefined;
 
@@ -99,23 +102,34 @@ const saveSessionToMemory: HookHandler = async (event) => {
     if (sessionFile) {
       // Get recent conversation content
       sessionContent = await getRecentSessionContent(sessionFile);
-      console.log("[session-memory] sessionContent length:", sessionContent?.length || 0);
+      log.debug(`sessionContent length: ${sessionContent?.length || 0}`);
 
       if (sessionContent && cfg) {
-        console.log("[session-memory] Calling generateSlugViaLLM...");
+        log.info("Calling generateSlugViaLLM...");
         // Dynamically import the LLM slug generator (avoids module caching issues)
-        // When compiled, handler is at dist/hooks/bundled/session-memory/handler.js
+        // In test environment, we need to match the key used in vi.mock
-        // Going up ../.. puts us at dist/hooks/, so just add llm-slug-generator.js
+        // The mock key is "../../../llm-slug-generator.js"
-        const clawdbotRoot = path.resolve(
+        // We can use a try-catch to fallback or just use a relative path that works for both
-          path.dirname(import.meta.url.replace("file://", "")),
+
-          "../..",
+        let generateSlugViaLLM;
-        );
+        try {
-        const slugGenPath = path.join(clawdbotRoot, "llm-slug-generator.js");
+          // Try importing using the relative path that matches the mock key
-        const { generateSlugViaLLM } = await import(slugGenPath);
+          const mod = await import("../../llm-slug-generator.js");
+          generateSlugViaLLM = mod.generateSlugViaLLM;
+        } catch {
+          // Fallback for runtime if the relative import above fails (e.g. bundler issues)
+          const clawdbotRoot = path.resolve(
+            path.dirname(import.meta.url.replace("file://", "")),
+            "../..",
+          );
+          const slugGenPath = path.join(clawdbotRoot, "llm-slug-generator.js");
+          const mod = await import(slugGenPath);
+          generateSlugViaLLM = mod.generateSlugViaLLM;
+        }
 
         // Use LLM to generate a descriptive slug
         slug = await generateSlugViaLLM({ sessionContent, cfg });
-        console.log("[session-memory] Generated slug:", slug);
+        log.info(`Generated slug: ${slug}`);
       }
     }
 
@@ -123,14 +137,14 @@ const saveSessionToMemory: HookHandler = async (event) => {
     if (!slug) {
       const timeSlug = now.toISOString().split("T")[1]!.split(".")[0]!.replace(/:/g, "");
       slug = timeSlug.slice(0, 4); // HHMM
-      console.log("[session-memory] Using fallback timestamp slug:", slug);
+      log.info(`Using fallback timestamp slug: ${slug}`);
     }
 
     // Create filename with date and slug
     const filename = `${dateStr}-${slug}.md`;
     const memoryFilePath = path.join(memoryDir, filename);
-    console.log("[session-memory] Generated filename:", filename);
+    log.info(`Generated filename: ${filename}`);
-    console.log("[session-memory] Full path:", memoryFilePath);
+    log.debug(`Full path: ${memoryFilePath}`);
 
     // Format time as HH:MM:SS UTC
     const timeStr = now.toISOString().split("T")[1]!.split(".")[0];
@@ -158,16 +172,13 @@ const saveSessionToMemory: HookHandler = async (event) => {
 
     // Write to new memory file
     await fs.writeFile(memoryFilePath, entry, "utf-8");
-    console.log("[session-memory] Memory file written successfully");
+    log.info("Memory file written successfully");
 
     // Log completion (but don't send user-visible confirmation - it's internal housekeeping)
     const relPath = memoryFilePath.replace(os.homedir(), "~");
-    console.log(`[session-memory] Session context saved to ${relPath}`);
+    log.info(`Session context saved to ${relPath}`);
   } catch (err) {
-    console.error(
+    log.error(`Failed to save session memory: ${err instanceof Error ? err.message : String(err)}`);
-      "[session-memory] Failed to save session memory:",
-      err instanceof Error ? err.message : String(err),
-    );
   }
 };