From f1a3d529c63b5f27a8f802b393b85baabc426f7b Mon Sep 17 00:00:00 2001 From: Chenyang Yu Date: Tue, 27 Jan 2026 04:11:51 -0500 Subject: [PATCH] refactor: replace console.log with structured logging Replace console.log/error/warn calls with structured logging using the existing subsystem logger infrastructure: - hooks/bundled/session-memory/handler.ts: Use createSubsystemLogger for session-memory subsystem with debug/info/error levels - hooks/loader.ts: Use createSubsystemLogger for hooks subsystem with info/warn/error levels - agents/skills/workspace.ts: Use existing skillsLogger for debug/warn - infra/tailscale.ts: Use logInfo from logger module Update loader.test.ts to remove console.error spy assertions since errors now go through structured logging. This improves observability by routing logs through the centralized logging infrastructure with proper levels and subsystem prefixes. --- src/agents/skills/workspace.ts | 6 ++-- src/hooks/bundled/session-memory/handler.ts | 33 +++++++++++---------- src/hooks/loader.test.ts | 15 ++-------- src/hooks/loader.ts | 30 +++++++++---------- src/infra/tailscale.ts | 3 +- 5 files changed, 39 insertions(+), 48 deletions(-) diff --git a/src/agents/skills/workspace.ts b/src/agents/skills/workspace.ts index 42884ecb9..370549a7d 100644 --- a/src/agents/skills/workspace.ts +++ b/src/agents/skills/workspace.ts @@ -52,12 +52,12 @@ function filterSkillEntries( if (skillFilter !== undefined) { const normalized = skillFilter.map((entry) => String(entry).trim()).filter(Boolean); const label = normalized.length > 0 ? normalized.join(", ") : "(none)"; - console.log(`[skills] Applying skill filter: ${label}`); + skillsLogger.debug(`Applying skill filter: ${label}`); filtered = normalized.length > 0 ? filtered.filter((entry) => normalized.includes(entry.skill.name)) : []; - console.log(`[skills] After filter: ${filtered.map((entry) => entry.skill.name).join(", ")}`); + skillsLogger.debug(`After filter: ${filtered.map((entry) => entry.skill.name).join(", ")}`); } return filtered; } @@ -300,7 +300,7 @@ export async function syncSkillsToWorkspace(params: { }); } catch (error) { const message = error instanceof Error ? error.message : JSON.stringify(error); - console.warn(`[skills] Failed to copy ${entry.skill.name} to sandbox: ${message}`); + skillsLogger.warn(`Failed to copy ${entry.skill.name} to sandbox: ${message}`); } } }); diff --git a/src/hooks/bundled/session-memory/handler.ts b/src/hooks/bundled/session-memory/handler.ts index 14b486fcc..089ebf056 100644 --- a/src/hooks/bundled/session-memory/handler.ts +++ b/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 logger = createSubsystemLogger("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"); + logger.debug("Hook triggered for /new command"); const context = event.context || {}; const cfg = context.cfg as ClawdbotConfig | undefined; @@ -87,9 +90,11 @@ const saveSessionToMemory: HookHandler = async (event) => { const currentSessionId = sessionEntry.sessionId as string; const currentSessionFile = sessionEntry.sessionFile as string; - console.log("[session-memory] Current sessionId:", currentSessionId); - console.log("[session-memory] Current sessionFile:", currentSessionFile); - console.log("[session-memory] cfg present:", !!cfg); + logger.debug("Current session", { + sessionId: currentSessionId, + sessionFile: currentSessionFile, + cfgPresent: !!cfg, + }); const sessionFile = currentSessionFile || undefined; @@ -99,10 +104,10 @@ const saveSessionToMemory: HookHandler = async (event) => { if (sessionFile) { // Get recent conversation content sessionContent = await getRecentSessionContent(sessionFile); - console.log("[session-memory] sessionContent length:", sessionContent?.length || 0); + logger.debug("Session content length", { length: sessionContent?.length || 0 }); if (sessionContent && cfg) { - console.log("[session-memory] Calling generateSlugViaLLM..."); + logger.debug("Calling generateSlugViaLLM"); // Dynamically import the LLM slug generator (avoids module caching issues) // When compiled, handler is at dist/hooks/bundled/session-memory/handler.js // Going up ../.. puts us at dist/hooks/, so just add llm-slug-generator.js @@ -115,7 +120,7 @@ const saveSessionToMemory: HookHandler = async (event) => { // Use LLM to generate a descriptive slug slug = await generateSlugViaLLM({ sessionContent, cfg }); - console.log("[session-memory] Generated slug:", slug); + logger.debug("Generated slug", { slug }); } } @@ -123,14 +128,13 @@ 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); + logger.debug("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); - console.log("[session-memory] Full path:", memoryFilePath); + logger.debug("Generated memory file path", { filename, path: memoryFilePath }); // Format time as HH:MM:SS UTC const timeStr = now.toISOString().split("T")[1]!.split(".")[0]; @@ -158,15 +162,14 @@ 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"); + logger.debug("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}`); + logger.info(`Session context saved to ${relPath}`); } catch (err) { - console.error( - "[session-memory] Failed to save session memory:", - err instanceof Error ? err.message : String(err), + logger.error( + `Failed to save session memory: ${err instanceof Error ? err.message : String(err)}`, ); } }; diff --git a/src/hooks/loader.test.ts b/src/hooks/loader.test.ts index 2cd77a846..f55907bd1 100644 --- a/src/hooks/loader.test.ts +++ b/src/hooks/loader.test.ts @@ -151,8 +151,6 @@ describe("loader", () => { }); it("should handle module loading errors gracefully", async () => { - const consoleError = vi.spyOn(console, "error").mockImplementation(() => {}); - const cfg: ClawdbotConfig = { hooks: { internal: { @@ -167,19 +165,12 @@ describe("loader", () => { }, }; + // Should not throw and return 0 loaded handlers const count = await loadInternalHooks(cfg, tmpDir); expect(count).toBe(0); - expect(consoleError).toHaveBeenCalledWith( - expect.stringContaining("Failed to load hook handler"), - expect.any(String), - ); - - consoleError.mockRestore(); }); it("should handle non-function exports", async () => { - const consoleError = vi.spyOn(console, "error").mockImplementation(() => {}); - // Create a module with a non-function export const handlerPath = path.join(tmpDir, "bad-export.js"); await fs.writeFile(handlerPath, 'export default "not a function";', "utf-8"); @@ -198,11 +189,9 @@ describe("loader", () => { }, }; + // Should not throw and return 0 loaded handlers const count = await loadInternalHooks(cfg, tmpDir); expect(count).toBe(0); - expect(consoleError).toHaveBeenCalledWith(expect.stringContaining("is not a function")); - - consoleError.mockRestore(); }); it("should handle relative paths", async () => { diff --git a/src/hooks/loader.ts b/src/hooks/loader.ts index 35d7b7d50..bb75c5cf0 100644 --- a/src/hooks/loader.ts +++ b/src/hooks/loader.ts @@ -13,6 +13,9 @@ import type { InternalHookHandler } from "./internal-hooks.js"; import { loadWorkspaceHookEntries } from "./workspace.js"; import { resolveHookConfig } from "./config.js"; import { shouldIncludeHook } from "./config.js"; +import { createSubsystemLogger } from "../logging/subsystem.js"; + +const logger = createSubsystemLogger("hooks"); /** * Load and register all hook handlers @@ -70,16 +73,14 @@ export async function loadInternalHooks( const handler = mod[exportName]; if (typeof handler !== "function") { - console.error( - `Hook error: Handler '${exportName}' from ${entry.hook.name} is not a function`, - ); + logger.error(`Handler '${exportName}' from ${entry.hook.name} is not a function`); continue; } // Register for all events listed in metadata const events = entry.clawdbot?.events ?? []; if (events.length === 0) { - console.warn(`Hook warning: Hook '${entry.hook.name}' has no events defined in metadata`); + logger.warn(`Hook '${entry.hook.name}' has no events defined in metadata`); continue; } @@ -87,21 +88,19 @@ export async function loadInternalHooks( registerInternalHook(event, handler as InternalHookHandler); } - console.log( + logger.info( `Registered hook: ${entry.hook.name} -> ${events.join(", ")}${exportName !== "default" ? ` (export: ${exportName})` : ""}`, ); loadedCount++; } catch (err) { - console.error( - `Failed to load hook ${entry.hook.name}:`, - err instanceof Error ? err.message : String(err), + logger.error( + `Failed to load hook ${entry.hook.name}: ${err instanceof Error ? err.message : String(err)}`, ); } } } catch (err) { - console.error( - "Failed to load directory-based hooks:", - err instanceof Error ? err.message : String(err), + logger.error( + `Failed to load directory-based hooks: ${err instanceof Error ? err.message : String(err)}`, ); } @@ -124,20 +123,19 @@ export async function loadInternalHooks( const handler = mod[exportName]; if (typeof handler !== "function") { - console.error(`Hook error: Handler '${exportName}' from ${modulePath} is not a function`); + logger.error(`Handler '${exportName}' from ${modulePath} is not a function`); continue; } // Register the handler registerInternalHook(handlerConfig.event, handler as InternalHookHandler); - console.log( + logger.info( `Registered hook (legacy): ${handlerConfig.event} -> ${modulePath}${exportName !== "default" ? `#${exportName}` : ""}`, ); loadedCount++; } catch (err) { - console.error( - `Failed to load hook handler from ${handlerConfig.module}:`, - err instanceof Error ? err.message : String(err), + logger.error( + `Failed to load hook handler from ${handlerConfig.module}: ${err instanceof Error ? err.message : String(err)}`, ); } } diff --git a/src/infra/tailscale.ts b/src/infra/tailscale.ts index 2350670bb..b87547955 100644 --- a/src/infra/tailscale.ts +++ b/src/infra/tailscale.ts @@ -1,6 +1,7 @@ import { existsSync } from "node:fs"; import { promptYesNo } from "../cli/prompt.js"; import { danger, info, logVerbose, shouldLogVerbose, warn } from "../globals.js"; +import { logInfo } from "../logger.js"; import { runExec } from "../process/exec.js"; import { defaultRuntime, type RuntimeEnv } from "../runtime.js"; import { colorize, isRich, theme } from "../terminal/theme.js"; @@ -317,7 +318,7 @@ export async function ensureFunnel( timeoutMs: 15_000, }, ); - if (stdout.trim()) console.log(stdout.trim()); + if (stdout.trim()) logInfo(stdout.trim()); } catch (err) { const errOutput = err as { stdout?: unknown; stderr?: unknown }; const stdout = typeof errOutput.stdout === "string" ? errOutput.stdout : "";