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.
This commit is contained in:
Chenyang Yu 2026-01-27 04:11:51 -05:00
parent d7a00dc823
commit f1a3d529c6
5 changed files with 39 additions and 48 deletions

View File

@ -52,12 +52,12 @@ function filterSkillEntries(
if (skillFilter !== undefined) { if (skillFilter !== undefined) {
const normalized = skillFilter.map((entry) => String(entry).trim()).filter(Boolean); const normalized = skillFilter.map((entry) => String(entry).trim()).filter(Boolean);
const label = normalized.length > 0 ? normalized.join(", ") : "(none)"; const label = normalized.length > 0 ? normalized.join(", ") : "(none)";
console.log(`[skills] Applying skill filter: ${label}`); skillsLogger.debug(`Applying skill filter: ${label}`);
filtered = filtered =
normalized.length > 0 normalized.length > 0
? filtered.filter((entry) => normalized.includes(entry.skill.name)) ? 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; return filtered;
} }
@ -300,7 +300,7 @@ export async function syncSkillsToWorkspace(params: {
}); });
} catch (error) { } catch (error) {
const message = error instanceof Error ? error.message : JSON.stringify(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}`);
} }
} }
}); });

View File

@ -12,6 +12,9 @@ import type { ClawdbotConfig } from "../../../config/config.js";
import { resolveAgentWorkspaceDir } from "../../../agents/agent-scope.js"; import { resolveAgentWorkspaceDir } from "../../../agents/agent-scope.js";
import { resolveAgentIdFromSessionKey } from "../../../routing/session-key.js"; import { resolveAgentIdFromSessionKey } from "../../../routing/session-key.js";
import type { HookHandler } from "../../hooks.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 * Read recent messages from session file for slug generation
@ -64,7 +67,7 @@ const saveSessionToMemory: HookHandler = async (event) => {
} }
try { try {
console.log("[session-memory] Hook triggered for /new command"); logger.debug("Hook triggered for /new command");
const context = event.context || {}; const context = event.context || {};
const cfg = context.cfg as ClawdbotConfig | undefined; const cfg = context.cfg as ClawdbotConfig | undefined;
@ -87,9 +90,11 @@ const saveSessionToMemory: HookHandler = async (event) => {
const currentSessionId = sessionEntry.sessionId as string; const currentSessionId = sessionEntry.sessionId as string;
const currentSessionFile = sessionEntry.sessionFile as string; const currentSessionFile = sessionEntry.sessionFile as string;
console.log("[session-memory] Current sessionId:", currentSessionId); logger.debug("Current session", {
console.log("[session-memory] Current sessionFile:", currentSessionFile); sessionId: currentSessionId,
console.log("[session-memory] cfg present:", !!cfg); sessionFile: currentSessionFile,
cfgPresent: !!cfg,
});
const sessionFile = currentSessionFile || undefined; const sessionFile = currentSessionFile || undefined;
@ -99,10 +104,10 @@ const saveSessionToMemory: HookHandler = async (event) => {
if (sessionFile) { if (sessionFile) {
// Get recent conversation content // Get recent conversation content
sessionContent = await getRecentSessionContent(sessionFile); 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) { if (sessionContent && cfg) {
console.log("[session-memory] Calling generateSlugViaLLM..."); logger.debug("Calling generateSlugViaLLM");
// Dynamically import the LLM slug generator (avoids module caching issues) // Dynamically import the LLM slug generator (avoids module caching issues)
// When compiled, handler is at dist/hooks/bundled/session-memory/handler.js // 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 // 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 // Use LLM to generate a descriptive slug
slug = await generateSlugViaLLM({ sessionContent, cfg }); 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) { if (!slug) {
const timeSlug = now.toISOString().split("T")[1]!.split(".")[0]!.replace(/:/g, ""); const timeSlug = now.toISOString().split("T")[1]!.split(".")[0]!.replace(/:/g, "");
slug = timeSlug.slice(0, 4); // HHMM 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 // Create filename with date and slug
const filename = `${dateStr}-${slug}.md`; const filename = `${dateStr}-${slug}.md`;
const memoryFilePath = path.join(memoryDir, filename); const memoryFilePath = path.join(memoryDir, filename);
console.log("[session-memory] Generated filename:", filename); logger.debug("Generated memory file path", { filename, path: memoryFilePath });
console.log("[session-memory] Full path:", memoryFilePath);
// Format time as HH:MM:SS UTC // Format time as HH:MM:SS UTC
const timeStr = now.toISOString().split("T")[1]!.split(".")[0]; const timeStr = now.toISOString().split("T")[1]!.split(".")[0];
@ -158,15 +162,14 @@ const saveSessionToMemory: HookHandler = async (event) => {
// Write to new memory file // Write to new memory file
await fs.writeFile(memoryFilePath, entry, "utf-8"); 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) // Log completion (but don't send user-visible confirmation - it's internal housekeeping)
const relPath = memoryFilePath.replace(os.homedir(), "~"); const relPath = memoryFilePath.replace(os.homedir(), "~");
console.log(`[session-memory] Session context saved to ${relPath}`); logger.info(`Session context saved to ${relPath}`);
} catch (err) { } catch (err) {
console.error( logger.error(
"[session-memory] Failed to save session memory:", `Failed to save session memory: ${err instanceof Error ? err.message : String(err)}`,
err instanceof Error ? err.message : String(err),
); );
} }
}; };

View File

@ -151,8 +151,6 @@ describe("loader", () => {
}); });
it("should handle module loading errors gracefully", async () => { it("should handle module loading errors gracefully", async () => {
const consoleError = vi.spyOn(console, "error").mockImplementation(() => {});
const cfg: ClawdbotConfig = { const cfg: ClawdbotConfig = {
hooks: { hooks: {
internal: { internal: {
@ -167,19 +165,12 @@ describe("loader", () => {
}, },
}; };
// Should not throw and return 0 loaded handlers
const count = await loadInternalHooks(cfg, tmpDir); const count = await loadInternalHooks(cfg, tmpDir);
expect(count).toBe(0); 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 () => { it("should handle non-function exports", async () => {
const consoleError = vi.spyOn(console, "error").mockImplementation(() => {});
// Create a module with a non-function export // Create a module with a non-function export
const handlerPath = path.join(tmpDir, "bad-export.js"); const handlerPath = path.join(tmpDir, "bad-export.js");
await fs.writeFile(handlerPath, 'export default "not a function";', "utf-8"); 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); const count = await loadInternalHooks(cfg, tmpDir);
expect(count).toBe(0); expect(count).toBe(0);
expect(consoleError).toHaveBeenCalledWith(expect.stringContaining("is not a function"));
consoleError.mockRestore();
}); });
it("should handle relative paths", async () => { it("should handle relative paths", async () => {

View File

@ -13,6 +13,9 @@ import type { InternalHookHandler } from "./internal-hooks.js";
import { loadWorkspaceHookEntries } from "./workspace.js"; import { loadWorkspaceHookEntries } from "./workspace.js";
import { resolveHookConfig } from "./config.js"; import { resolveHookConfig } from "./config.js";
import { shouldIncludeHook } from "./config.js"; import { shouldIncludeHook } from "./config.js";
import { createSubsystemLogger } from "../logging/subsystem.js";
const logger = createSubsystemLogger("hooks");
/** /**
* Load and register all hook handlers * Load and register all hook handlers
@ -70,16 +73,14 @@ export async function loadInternalHooks(
const handler = mod[exportName]; const handler = mod[exportName];
if (typeof handler !== "function") { if (typeof handler !== "function") {
console.error( logger.error(`Handler '${exportName}' from ${entry.hook.name} is not a function`);
`Hook error: Handler '${exportName}' from ${entry.hook.name} is not a function`,
);
continue; continue;
} }
// Register for all events listed in metadata // Register for all events listed in metadata
const events = entry.clawdbot?.events ?? []; const events = entry.clawdbot?.events ?? [];
if (events.length === 0) { 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; continue;
} }
@ -87,21 +88,19 @@ export async function loadInternalHooks(
registerInternalHook(event, handler as InternalHookHandler); registerInternalHook(event, handler as InternalHookHandler);
} }
console.log( logger.info(
`Registered hook: ${entry.hook.name} -> ${events.join(", ")}${exportName !== "default" ? ` (export: ${exportName})` : ""}`, `Registered hook: ${entry.hook.name} -> ${events.join(", ")}${exportName !== "default" ? ` (export: ${exportName})` : ""}`,
); );
loadedCount++; loadedCount++;
} catch (err) { } catch (err) {
console.error( logger.error(
`Failed to load hook ${entry.hook.name}:`, `Failed to load hook ${entry.hook.name}: ${err instanceof Error ? err.message : String(err)}`,
err instanceof Error ? err.message : String(err),
); );
} }
} }
} catch (err) { } catch (err) {
console.error( logger.error(
"Failed to load directory-based hooks:", `Failed to load directory-based hooks: ${err instanceof Error ? err.message : String(err)}`,
err instanceof Error ? err.message : String(err),
); );
} }
@ -124,20 +123,19 @@ export async function loadInternalHooks(
const handler = mod[exportName]; const handler = mod[exportName];
if (typeof handler !== "function") { 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; continue;
} }
// Register the handler // Register the handler
registerInternalHook(handlerConfig.event, handler as InternalHookHandler); registerInternalHook(handlerConfig.event, handler as InternalHookHandler);
console.log( logger.info(
`Registered hook (legacy): ${handlerConfig.event} -> ${modulePath}${exportName !== "default" ? `#${exportName}` : ""}`, `Registered hook (legacy): ${handlerConfig.event} -> ${modulePath}${exportName !== "default" ? `#${exportName}` : ""}`,
); );
loadedCount++; loadedCount++;
} catch (err) { } catch (err) {
console.error( logger.error(
`Failed to load hook handler from ${handlerConfig.module}:`, `Failed to load hook handler from ${handlerConfig.module}: ${err instanceof Error ? err.message : String(err)}`,
err instanceof Error ? err.message : String(err),
); );
} }
} }

View File

@ -1,6 +1,7 @@
import { existsSync } from "node:fs"; import { existsSync } from "node:fs";
import { promptYesNo } from "../cli/prompt.js"; import { promptYesNo } from "../cli/prompt.js";
import { danger, info, logVerbose, shouldLogVerbose, warn } from "../globals.js"; import { danger, info, logVerbose, shouldLogVerbose, warn } from "../globals.js";
import { logInfo } from "../logger.js";
import { runExec } from "../process/exec.js"; import { runExec } from "../process/exec.js";
import { defaultRuntime, type RuntimeEnv } from "../runtime.js"; import { defaultRuntime, type RuntimeEnv } from "../runtime.js";
import { colorize, isRich, theme } from "../terminal/theme.js"; import { colorize, isRich, theme } from "../terminal/theme.js";
@ -317,7 +318,7 @@ export async function ensureFunnel(
timeoutMs: 15_000, timeoutMs: 15_000,
}, },
); );
if (stdout.trim()) console.log(stdout.trim()); if (stdout.trim()) logInfo(stdout.trim());
} catch (err) { } catch (err) {
const errOutput = err as { stdout?: unknown; stderr?: unknown }; const errOutput = err as { stdout?: unknown; stderr?: unknown };
const stdout = typeof errOutput.stdout === "string" ? errOutput.stdout : ""; const stdout = typeof errOutput.stdout === "string" ? errOutput.stdout : "";