diff --git a/docs/configuration.md b/docs/configuration.md index 7166174e0..a4e5b9e10 100644 --- a/docs/configuration.md +++ b/docs/configuration.md @@ -46,10 +46,18 @@ If set, CLAWDIS derives defaults (only when you haven’t set them explicitly): - Default log file: `/tmp/clawdis/clawdis-YYYY-MM-DD.log` - If you want a stable path, set `logging.file` to `/tmp/clawdis/clawdis.log`. +- Console output can be tuned separately via: + - `logging.consoleLevel` (defaults to `info`, bumps to `debug` when `--verbose`) + - `logging.consoleStyle` (`pretty` | `compact` | `json`) ```json5 { - logging: { level: "info", file: "/tmp/clawdis/clawdis.log" } + logging: { + level: "info", + file: "/tmp/clawdis/clawdis.log", + consoleLevel: "info", + consoleStyle: "pretty" + } } ``` diff --git a/docs/logging.md b/docs/logging.md index 05209c3af..be0704df2 100644 --- a/docs/logging.md +++ b/docs/logging.md @@ -1,3 +1,10 @@ +--- +summary: "Logging surfaces, file logs, WS log styles, and console formatting" +read_when: + - Changing logging output or formats + - Debugging CLI or gateway output +--- + # Logging Clawdis has two log “surfaces”: @@ -53,3 +60,24 @@ clawdis gateway --verbose --ws-log compact # show all WS traffic (full meta) clawdis gateway --verbose --ws-log full ``` + +## Console formatting (subsystem logging) + +Clawdis formats console logs via a small wrapper on top of the existing stack: + +- **tslog** for structured file logs (`src/logging.ts`) +- **chalk** for colors (`src/globals.ts`) + +The console formatter is **TTY-aware** and prints consistent, prefixed lines. +Subsystem loggers are created via `createSubsystemLogger("gateway")`. + +Behavior: + +- **Subsystem prefixes** on every line (e.g. `[gateway]`, `[canvas]`, `[tailscale]`) +- **Color only when TTY** (`process.stdout.isTTY` + `NO_COLOR` respected) +- **Sub-loggers by subsystem** (auto prefix + structured field `{ subsystem }`) +- **`logRaw()`** for QR/UX output (no prefix, no formatting) +- **Console styles** (e.g. `pretty | compact | json`) +- **Console log level** separate from file log level (file keeps full detail) + +This keeps existing file logs stable while making interactive output scannable. diff --git a/src/cli/gateway-cli.coverage.test.ts b/src/cli/gateway-cli.coverage.test.ts index e043234e8..26b736d67 100644 --- a/src/cli/gateway-cli.coverage.test.ts +++ b/src/cli/gateway-cli.coverage.test.ts @@ -36,6 +36,7 @@ vi.mock("../gateway/server.js", () => ({ vi.mock("../globals.js", () => ({ info: (msg: string) => msg, + isVerbose: () => false, setVerbose: (enabled: boolean) => setVerbose(enabled), })); diff --git a/src/config/config.ts b/src/config/config.ts index cf04dedec..9f0bb55ea 100644 --- a/src/config/config.ts +++ b/src/config/config.ts @@ -20,6 +20,15 @@ export type SessionConfig = { export type LoggingConfig = { level?: "silent" | "fatal" | "error" | "warn" | "info" | "debug" | "trace"; file?: string; + consoleLevel?: + | "silent" + | "fatal" + | "error" + | "warn" + | "info" + | "debug" + | "trace"; + consoleStyle?: "pretty" | "compact" | "json"; }; export type WebReconnectConfig = { @@ -246,6 +255,20 @@ const ClawdisSchema = z.object({ ]) .optional(), file: z.string().optional(), + consoleLevel: z + .union([ + z.literal("silent"), + z.literal("fatal"), + z.literal("error"), + z.literal("warn"), + z.literal("info"), + z.literal("debug"), + z.literal("trace"), + ]) + .optional(), + consoleStyle: z + .union([z.literal("pretty"), z.literal("compact"), z.literal("json")]) + .optional(), }) .optional(), browser: z diff --git a/src/logger.ts b/src/logger.ts index 20d31452f..7f63b2fa7 100644 --- a/src/logger.ts +++ b/src/logger.ts @@ -6,15 +6,34 @@ import { success, warn, } from "./globals.js"; -import { getLogger } from "./logging.js"; +import { createSubsystemLogger, getLogger } from "./logging.js"; import { defaultRuntime, type RuntimeEnv } from "./runtime.js"; +const subsystemPrefixRe = /^([a-z][a-z0-9-]{1,20}):\s+(.*)$/i; + +function splitSubsystem(message: string) { + const match = message.match(subsystemPrefixRe); + if (!match) return null; + const [, subsystem, rest] = match; + return { subsystem, rest }; +} + export function logInfo(message: string, runtime: RuntimeEnv = defaultRuntime) { + const parsed = runtime === defaultRuntime ? splitSubsystem(message) : null; + if (parsed) { + createSubsystemLogger(parsed.subsystem).info(parsed.rest); + return; + } runtime.log(info(message)); getLogger().info(message); } export function logWarn(message: string, runtime: RuntimeEnv = defaultRuntime) { + const parsed = runtime === defaultRuntime ? splitSubsystem(message) : null; + if (parsed) { + createSubsystemLogger(parsed.subsystem).warn(parsed.rest); + return; + } runtime.log(warn(message)); getLogger().warn(message); } @@ -23,6 +42,11 @@ export function logSuccess( message: string, runtime: RuntimeEnv = defaultRuntime, ) { + const parsed = runtime === defaultRuntime ? splitSubsystem(message) : null; + if (parsed) { + createSubsystemLogger(parsed.subsystem).info(parsed.rest); + return; + } runtime.log(success(message)); getLogger().info(message); } @@ -31,6 +55,11 @@ export function logError( message: string, runtime: RuntimeEnv = defaultRuntime, ) { + const parsed = runtime === defaultRuntime ? splitSubsystem(message) : null; + if (parsed) { + createSubsystemLogger(parsed.subsystem).error(parsed.rest); + return; + } runtime.error(danger(message)); getLogger().error(message); } diff --git a/src/logging.ts b/src/logging.ts index 4b479bb20..0d3040ede 100644 --- a/src/logging.ts +++ b/src/logging.ts @@ -2,9 +2,11 @@ import fs from "node:fs"; import path from "node:path"; import util from "node:util"; +import chalk, { Chalk } from "chalk"; import { Logger as TsLogger } from "tslog"; import { type ClawdisConfig, loadConfig } from "./config/config.js"; import { isVerbose } from "./globals.js"; +import { defaultRuntime, type RuntimeEnv } from "./runtime.js"; // Pin to /tmp so mac Debug UI and docs match; os.tmpdir() can be a per-user // randomized path on macOS which made the “Open log” button a no-op. @@ -30,6 +32,8 @@ type Level = (typeof ALLOWED_LEVELS)[number]; export type LoggerSettings = { level?: Level; file?: string; + consoleLevel?: Level; + consoleStyle?: ConsoleStyle; }; type LogObj = { date?: Date } & Record; @@ -40,11 +44,27 @@ type ResolvedSettings = { }; export type LoggerResolvedSettings = ResolvedSettings; +export type ConsoleStyle = "pretty" | "compact" | "json"; +type ConsoleSettings = { + level: Level; + style: ConsoleStyle; +}; +export type ConsoleLoggerSettings = ConsoleSettings; + let cachedLogger: TsLogger | null = null; let cachedSettings: ResolvedSettings | null = null; +let cachedConsoleSettings: ConsoleSettings | null = null; let overrideSettings: LoggerSettings | null = null; let consolePatched = false; let forceConsoleToStderr = false; +let rawConsole: + | { + log: typeof console.log; + info: typeof console.info; + warn: typeof console.warn; + error: typeof console.error; + } + | null = null; function normalizeLevel(level?: string): Level { if (isVerbose()) return "trace"; @@ -62,11 +82,27 @@ function resolveSettings(): ResolvedSettings { return { level, file }; } +function resolveConsoleSettings(): ConsoleSettings { + const cfg: ClawdisConfig["logging"] | undefined = + overrideSettings ?? loadConfig().logging; + const level = normalizeConsoleLevel(cfg?.consoleLevel); + const style = normalizeConsoleStyle(cfg?.consoleStyle); + return { level, style }; +} + function settingsChanged(a: ResolvedSettings | null, b: ResolvedSettings) { if (!a) return true; return a.level !== b.level || a.file !== b.file; } +function consoleSettingsChanged( + a: ConsoleSettings | null, + b: ConsoleSettings, +) { + if (!a) return true; + return a.level !== b.level || a.style !== b.style; +} + function levelToMinLevel(level: Level): number { // tslog level ordering: fatal=0, error=1, warn=2, info=3, debug=4, trace=5 const map: Record = { @@ -81,6 +117,22 @@ function levelToMinLevel(level: Level): number { return map[level]; } +function normalizeConsoleLevel(level?: string): Level { + if (isVerbose()) return "debug"; + const candidate = level ?? "info"; + return ALLOWED_LEVELS.includes(candidate as Level) + ? (candidate as Level) + : "info"; +} + +function normalizeConsoleStyle(style?: string): ConsoleStyle { + if (style === "compact" || style === "json" || style === "pretty") { + return style; + } + if (!process.stdout.isTTY) return "compact"; + return "pretty"; +} + function buildLogger(settings: ResolvedSettings): TsLogger { fs.mkdirSync(path.dirname(settings.file), { recursive: true }); // Clean up stale rolling logs when using a dated log filename. @@ -115,6 +167,14 @@ export function getLogger(): TsLogger { return cachedLogger; } +export function getConsoleSettings(): ConsoleLoggerSettings { + const settings = resolveConsoleSettings(); + if (!cachedConsoleSettings || consoleSettingsChanged(cachedConsoleSettings, settings)) { + cachedConsoleSettings = settings; + } + return cachedConsoleSettings; +} + export function getChildLogger( bindings?: Record, opts?: { level?: Level }, @@ -171,6 +231,10 @@ export function getResolvedLoggerSettings(): LoggerResolvedSettings { return resolveSettings(); } +export function getResolvedConsoleSettings(): ConsoleLoggerSettings { + return getConsoleSettings(); +} + // Test helpers export function setLoggerOverride(settings: LoggerSettings | null) { overrideSettings = settings; @@ -181,6 +245,7 @@ export function setLoggerOverride(settings: LoggerSettings | null) { export function resetLogger() { cachedLogger = null; cachedSettings = null; + cachedConsoleSettings = null; overrideSettings = null; } @@ -208,6 +273,12 @@ export function enableConsoleCapture(): void { debug: console.debug, trace: console.trace, }; + rawConsole = { + log: original.log, + info: original.info, + warn: original.warn, + error: original.error, + }; const forward = (level: Level, orig: (...args: unknown[]) => void) => @@ -250,6 +321,147 @@ export function enableConsoleCapture(): void { console.trace = forward("trace", original.trace); } +type SubsystemLogger = { + subsystem: string; + trace: (message: string, meta?: Record) => void; + debug: (message: string, meta?: Record) => void; + info: (message: string, meta?: Record) => void; + warn: (message: string, meta?: Record) => void; + error: (message: string, meta?: Record) => void; + fatal: (message: string, meta?: Record) => void; + raw: (message: string) => void; + child: (name: string) => SubsystemLogger; +}; + +function shouldLogToConsole(level: Level, settings: ConsoleSettings): boolean { + const current = levelToMinLevel(level); + const min = levelToMinLevel(settings.level); + return current <= min; +} + +function getColorForConsole(): Chalk { + const supports = + process.stdout.isTTY && + !process.env.NO_COLOR && + Boolean(chalk.supportsColor); + return supports ? chalk : new Chalk({ level: 0 }); +} + +function formatConsoleLine(opts: { + level: Level; + subsystem: string; + message: string; + style: ConsoleStyle; + meta?: Record; +}): string { + if (opts.style === "json") { + return JSON.stringify({ + time: new Date().toISOString(), + level: opts.level, + subsystem: opts.subsystem, + message: opts.message, + ...opts.meta, + }); + } + const color = getColorForConsole(); + const prefix = `[${opts.subsystem}]`; + const levelColor = + opts.level === "error" || opts.level === "fatal" + ? color.red + : opts.level === "warn" + ? color.yellow + : opts.level === "debug" || opts.level === "trace" + ? color.gray + : color.cyan; + const time = + opts.style === "pretty" + ? color.gray(new Date().toISOString().slice(11, 19)) + : ""; + const prefixToken = + opts.style === "pretty" ? color.gray(prefix) : prefix; + const head = [time, prefixToken].filter(Boolean).join(" "); + return `${head} ${levelColor(opts.message)}`; +} + +function writeConsoleLine(level: Level, line: string) { + const sink = rawConsole ?? console; + if (forceConsoleToStderr || level === "error" || level === "fatal") { + (sink.error ?? console.error)(line); + } else if (level === "warn") { + (sink.warn ?? console.warn)(line); + } else { + (sink.log ?? console.log)(line); + } +} + +function logToFile( + fileLogger: TsLogger, + level: Level, + message: string, + meta?: Record, +) { + if (meta && Object.keys(meta).length > 0) { + (fileLogger[level] as (...args: unknown[]) => void)(meta, message); + } else { + (fileLogger[level] as (...args: unknown[]) => void)(message); + } +} + +export function createSubsystemLogger(subsystem: string): SubsystemLogger { + let fileLogger: TsLogger | null = null; + const getFileLogger = () => { + if (!fileLogger) fileLogger = getChildLogger({ subsystem }); + return fileLogger; + }; + const emit = (level: Level, message: string, meta?: Record) => { + logToFile(getFileLogger(), level, message, meta); + const consoleSettings = getConsoleSettings(); + if (!shouldLogToConsole(level, consoleSettings)) return; + const line = formatConsoleLine({ + level, + subsystem, + message, + style: consoleSettings.style, + meta, + }); + writeConsoleLine(level, line); + }; + + const logger: SubsystemLogger = { + subsystem, + trace: (message, meta) => emit("trace", message, meta), + debug: (message, meta) => emit("debug", message, meta), + info: (message, meta) => emit("info", message, meta), + warn: (message, meta) => emit("warn", message, meta), + error: (message, meta) => emit("error", message, meta), + fatal: (message, meta) => emit("fatal", message, meta), + raw: (message) => { + logToFile(getFileLogger(), "info", message, { raw: true }); + writeConsoleLine("info", message); + }, + child: (name) => createSubsystemLogger(`${subsystem}/${name}`), + }; + return logger; +} + +export function runtimeForLogger( + logger: SubsystemLogger, + exit: RuntimeEnv["exit"] = defaultRuntime.exit, +): RuntimeEnv { + return { + log: (message: string) => logger.info(message), + error: (message: string) => logger.error(message), + exit, + }; +} + +export function createSubsystemRuntime( + subsystem: string, + exit: RuntimeEnv["exit"] = defaultRuntime.exit, +): RuntimeEnv { + return runtimeForLogger(createSubsystemLogger(subsystem), exit); +} + function defaultRollingPathForToday(): string { const today = new Date().toISOString().slice(0, 10); // YYYY-MM-DD return path.join(DEFAULT_LOG_DIR, `${LOG_PREFIX}-${today}${LOG_SUFFIX}`);