refactor(logging): add subsystem console formatting

This commit is contained in:
Peter Steinberger
2025-12-21 13:23:42 +00:00
parent bcd3c13e2c
commit 5b2e7d4464
6 changed files with 303 additions and 2 deletions

View File

@@ -46,10 +46,18 @@ If set, CLAWDIS derives defaults (only when you havent 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"
}
}
```

View File

@@ -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.

View File

@@ -36,6 +36,7 @@ vi.mock("../gateway/server.js", () => ({
vi.mock("../globals.js", () => ({
info: (msg: string) => msg,
isVerbose: () => false,
setVerbose: (enabled: boolean) => setVerbose(enabled),
}));

View File

@@ -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

View File

@@ -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);
}

View File

@@ -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<string, unknown>;
@@ -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<LogObj> | 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<Level, number> = {
@@ -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<LogObj> {
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<LogObj> {
return cachedLogger;
}
export function getConsoleSettings(): ConsoleLoggerSettings {
const settings = resolveConsoleSettings();
if (!cachedConsoleSettings || consoleSettingsChanged(cachedConsoleSettings, settings)) {
cachedConsoleSettings = settings;
}
return cachedConsoleSettings;
}
export function getChildLogger(
bindings?: Record<string, unknown>,
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<string, unknown>) => void;
debug: (message: string, meta?: Record<string, unknown>) => void;
info: (message: string, meta?: Record<string, unknown>) => void;
warn: (message: string, meta?: Record<string, unknown>) => void;
error: (message: string, meta?: Record<string, unknown>) => void;
fatal: (message: string, meta?: Record<string, unknown>) => 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, unknown>;
}): 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<LogObj>,
level: Level,
message: string,
meta?: Record<string, unknown>,
) {
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<LogObj> | null = null;
const getFileLogger = () => {
if (!fileLogger) fileLogger = getChildLogger({ subsystem });
return fileLogger;
};
const emit = (level: Level, message: string, meta?: Record<string, unknown>) => {
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}`);