diff --git a/CONFIGURATION.md b/CONFIGURATION.md index f1fed29..8a6c6d5 100644 --- a/CONFIGURATION.md +++ b/CONFIGURATION.md @@ -57,7 +57,13 @@ Status legend: **ACTIVE** = currently used | **DEPRECATED** = accepted but no ef - **Type:** `boolean` - **Default:** `false` - **Status:** ACTIVE -- **Description:** Enable debug mode. When `true`, ACP sends a chat notification after each compression showing block details, and enables INFO/DEBUG logs plus per-request context snapshots at `~/.config/opencode/logs/acp/`. WARN/ERROR lines are always written to `~/.config/opencode/logs/acp/daily/.log` regardless of this flag. +- **Description:** Enable debug mode. When `true`, ACP sends a chat notification after each compression showing block details, and sets `logLevel` to `debug` (INFO/DEBUG logs plus per-request context snapshots at `~/.config/opencode/logs/acp/`). This flag overrides `logLevel` when set to `true`. + +#### `logLevel` +- **Type:** `"debug" | "info" | "warn" | "error" | "silent"` +- **Default:** `"info"` +- **Status:** ACTIVE +- **Description:** File log verbosity for `~/.config/opencode/logs/acp/daily/.log`. Default `info` writes decision-level events by default (nudge decisions, transform summaries, auto-update checks, model switches). `warn`/`error` reduce output; `silent` disables file logging entirely; `debug` additionally enables per-request context snapshots and verbose dumps. Ignored when `debug: true`. #### `pruneNotification` - **Type:** `"off" | "minimal" | "detailed"` diff --git a/CONFIGURATION.zh-CN.md b/CONFIGURATION.zh-CN.md index 8b792b3..3fa5ad9 100644 --- a/CONFIGURATION.zh-CN.md +++ b/CONFIGURATION.zh-CN.md @@ -57,7 +57,13 @@ ACP 从最多三层配置文件中读取(后加载的覆盖先加载的): - **类型:** `boolean` - **默认值:** `false` - **状态:** ACTIVE -- **说明:** 启用调试模式。设为 `true` 时,ACP 在每次压缩后发送聊天通知,显示块详情,并启用 INFO/DEBUG 日志与按请求的上下文快照(`~/.config/opencode/logs/acp/`)。无论此开关如何设置,WARN/ERROR 始终写入 `~/.config/opencode/logs/acp/daily/<日期>.log`。 +- **说明:** 启用调试模式。设为 `true` 时,ACP 在每次压缩后发送聊天通知,显示块详情,并将 `logLevel` 置为 `debug`(INFO/DEBUG 日志与按请求的上下文快照,`~/.config/opencode/logs/acp/`)。设为 `true` 时此开关优先于 `logLevel`。 + +#### `logLevel` +- **类型:** `"debug" | "info" | "warn" | "error" | "silent"` +- **默认值:** `"info"` +- **状态:** ACTIVE +- **说明:** 文件日志详细级别(`~/.config/opencode/logs/acp/daily/<日期>.log`)。默认 `info`:默认落盘决策级事件(压缩提示决策、转换摘要、自动更新检查、模型切换等)。`warn`/`error` 减少输出;`silent` 完全关闭文件日志;`debug` 额外启用按请求的上下文快照与详细转储。`debug: true` 时忽略此配置。 #### `pruneNotification` - **类型:** `"off" | "minimal" | "detailed"` diff --git a/README.md b/README.md index 6fdbd71..6c98d06 100644 --- a/README.md +++ b/README.md @@ -282,8 +282,11 @@ Each level overrides the previous, so project settings take priority over global // on the installed dist-tag/spec (@stable follows stable, @latest follows latest). // Version-locked plugin specs are not updated. "autoUpdate": true, - // Enable INFO/DEBUG logging + per-request snapshots to ~/.config/opencode/logs/acp/ - // (WARN/ERROR are always logged to daily/.log) + // File log verbosity: "debug" | "info" | "warn" | "error" | "silent". + // Default "info" writes decision-level events (nudges, transforms, updates) + // to ~/.config/opencode/logs/acp/daily/.log + "logLevel": "info", + // Enable full DEBUG logging + per-request snapshots (overrides logLevel) "debug": false, // Notification display: "off", "minimal", or "detailed" "pruneNotification": "off", diff --git a/README.zh-CN.md b/README.zh-CN.md index 7c09a34..20d853f 100644 --- a/README.zh-CN.md +++ b/README.zh-CN.md @@ -236,8 +236,11 @@ ACP 使用自己的配置文件,按以下顺序搜索: // 自动更新 npm 安装的 ACP:跟踪安装所用 dist-tag/规范(@stable 跟随 stable,@latest 跟随 latest)。 // 版本锁定的规范不会被更新。 "autoUpdate": true, - // Enable INFO/DEBUG logging + per-request snapshots to ~/.config/opencode/logs/acp/ - // (WARN/ERROR are always logged to daily/.log) + // 文件日志级别: "debug" | "info" | "warn" | "error" | "silent" + // 默认 "info":决策级事件(压缩提示、转换摘要、更新检查)落盘到 + // ~/.config/opencode/logs/acp/daily/<日期>.log + "logLevel": "info", + // 启用完整 DEBUG 日志 + 按请求快照(优先于 logLevel) "debug": false, // Notification display: "off", "minimal", or "detailed" "pruneNotification": "detailed", diff --git a/dcp.schema.json b/dcp.schema.json index d9dd13b..5b6fd1d 100644 --- a/dcp.schema.json +++ b/dcp.schema.json @@ -23,7 +23,13 @@ "debug": { "type": "boolean", "default": false, - "description": "Enable debug logging" + "description": "Enable full debug logging (overrides logLevel)" + }, + "logLevel": { + "type": "string", + "enum": ["debug", "info", "warn", "error", "silent"], + "default": "info", + "description": "Log verbosity: decision-level events (info) are written by default. debug adds per-message detail; warn/error/silent reduce output." }, "pruneNotification": { "type": "string", diff --git a/devlog/2026-08-21_default-on-logging/REQ.md b/devlog/2026-08-21_default-on-logging/REQ.md new file mode 100644 index 0000000..89194dc --- /dev/null +++ b/devlog/2026-08-21_default-on-logging/REQ.md @@ -0,0 +1,25 @@ +# REQ — default-on decision-level logging + +## 背景 + +用户反馈:项目日志非常少,且只在 `debug: true` 时才写 INFO/DEBUG。默认配置(`debug: false`)下只有 WARN/ERROR 落盘,出问题时文件里几乎没有可排查的决策轨迹。 + +## 需求 + +1. **默认(非 debug)就要打印**:INFO 级决策日志默认写盘。 +2. 可配置:用户能把级别调低(warn/error/silent)或调高(debug)。 +3. 向后兼容: + - `new Logger(boolean)` 现有语义不变(false→仅 WARN/ERROR;true→全量),~40 个测试文件不受影响。 + - `debug: true` 行为不变(debug 级 + saveContext 快照)。 + +## 方案 + +- `LogLevel = "debug" | "info" | "warn" | "error" | "silent"` + LEVEL_RANK 门控写入。 +- 新配置项 `logLevel`(默认 `"info"`),`debug: true` 时覆盖为 debug。 +- INFO 决策日志铺到核心路径:插件初始化、每请求 transform 摘要、模型切换、nudge 注入/抑制决策(含 tier 触发)、自动更新检查全程。 +- saveContext 仍只在 debug 级开启(避免默认每请求 JSON 转储膨胀)。 + +## 验收 + +- 默认配置下 `~/.config/opencode/logs/acp/daily/.log` 有 INFO 决策行。 +- `tsc --noEmit` 0 错误;全量测试通过(含新增 4 个分级语义测试)。 diff --git a/devlog/2026-08-21_default-on-logging/WORKLOG.md b/devlog/2026-08-21_default-on-logging/WORKLOG.md new file mode 100644 index 0000000..58c89aa --- /dev/null +++ b/devlog/2026-08-21_default-on-logging/WORKLOG.md @@ -0,0 +1,41 @@ +# WORKLOG — default-on decision-level logging + +## 变更 + +### lib/logger.ts +- 新增 `export type LogLevel = "debug"|"info"|"warn"|"error"|"silent"` 与 `LEVEL_RANK`(silent=99 吞掉一切)。 +- 构造签名 `constructor(enabled: boolean, level?: LogLevel)`;`this.level = level ?? (enabled ? "debug" : "warn")` —— 纯布尔调用保持旧语义。 +- `get enabled()` 改为派生视图(`level === "debug"`)。 +- `write()` 按级别秩次门控;`info()/debug()` 增加可选 `data` 参数(`unknown`,非 any)。 +- `saveContext` 仅在 debug 级写快照。 + +### 配置链 +- `lib/config.ts`:`PluginConfig.logLevel: LogLevel`,默认 `"info"`,mergeLayer 合并。 +- `lib/config-validation.ts`:VALID_CONFIG_KEYS + 枚举校验(5 值)。 +- `dcp.schema.json`:logLevel string enum,default "info"。 + +### 装配 +- `index.ts`:`new Logger(config.debug, config.debug ? "debug" : config.logLevel)`;初始化 INFO(版本/工作区/级别/secure/auto-update);`startAutoUpdate(ctx, config.autoUpdate, logger)`。 + +### INFO 决策日志铺设 +- `lib/messages/inject/inject.ts`:nudge 注入(trigger=tier/growth/emergency + usagePct + growthFloor + 推荐区间)、紧急 /compact 通知、抑制原因(all_protected / in_protected_zone / below_effective_floor)、tier 触发注入。 +- `lib/hooks.ts`:每请求 transform 完成摘要(模型/消息数/pre-post tokens/上下文占用%/是否 nudge);会话内模型切换。 +- `lib/update.ts`:线程化可选 Logger;检查启动/跳过原因(无包目录、不可读、无目标、规范不可更新、tag 无版本、已最新)/发现新版本/失败/应用成功。 + +### 测试 +- `tests/logger.test.ts` 新增 4 例:显式 info 级(INFO/WARN/ERROR 写、DEBUG 门控)、silent 全吞、error 级仅 ERROR、`enabled` getter 反映显式级别。8/8 通过。 + +### 文档 +- CONFIGURATION.md / CONFIGURATION.zh-CN.md:新增 `logLevel` 小节,重写 `debug` 小节(覆盖关系)。 +- README.md / README.zh-CN.md:配置示例加 `logLevel`。 + +## 验证 + +- `npx tsc --noEmit` → 0 errors。 +- `node --import tsx --test tests/logger.test.ts` → 8 pass / 0 fail。 +- 全量:见 PR 检查项(发布前跑)。 + +## 风险与回滚 + +- 日志量增长有限:决策级事件每请求 ~2 行 + 低频路径;无 per-message 转储。 +- 回滚点:本 PR 单 commit revert 即可。 diff --git a/index.ts b/index.ts index 4c06517..4e226df 100644 --- a/index.ts +++ b/index.ts @@ -1,3 +1,5 @@ +/** ACP version, injected at build time by tsup define */ +declare const ACP_VERSION: string | undefined import type { Plugin } from "@opencode-ai/plugin" import { getConfig } from "./lib/config" import { @@ -32,7 +34,15 @@ const server: Plugin = (async (ctx) => { return {} } - const logger = new Logger(config.debug) + const logger = new Logger(config.debug, config.debug ? "debug" : config.logLevel) + logger.info("ACP plugin initialized", { + version: typeof ACP_VERSION !== "undefined" ? ACP_VERSION : "dev", + workspace: ctx.directory, + logLevel: logger.level, + debug: config.debug, + autoUpdate: config.autoUpdate, + secureMode: isSecureMode(), + }) const registry = new SessionStateRegistry(logger) const prompts = new PromptStore(logger, ctx.directory, config.experimental.customPrompts) const hostPermissions: HostPermissionSnapshot = { @@ -75,7 +85,7 @@ const server: Plugin = (async (ctx) => { logger.info("DCP initialized") - startAutoUpdate(ctx, config.autoUpdate) + startAutoUpdate(ctx, config.autoUpdate, logger) const compressToolContext = { client: ctx.client, diff --git a/lib/config-validation.ts b/lib/config-validation.ts index f93400d..27ba901 100644 --- a/lib/config-validation.ts +++ b/lib/config-validation.ts @@ -8,6 +8,7 @@ export const VALID_CONFIG_KEYS = new Set([ "enabled", "autoUpdate", "debug", + "logLevel", "showUpdateToasts", "allowSubAgents", "pruneNotification", diff --git a/lib/config.ts b/lib/config.ts index bc5a034..2a34c66 100644 --- a/lib/config.ts +++ b/lib/config.ts @@ -4,6 +4,7 @@ import { homedir } from "os" import { parse } from "jsonc-parser/lib/esm/main.js" import type { PluginInput } from "@opencode-ai/plugin" import { VALID_CONFIG_KEYS, getInvalidConfigKeys, validateConfigTypes, type ValidationError } from "./config-validation" +import type { LogLevel } from "./logger" type Permission = "ask" | "allow" | "deny" @@ -84,6 +85,8 @@ export interface PluginConfig { enabled: boolean autoUpdate: boolean debug: boolean + /** Log verbosity when `debug` is false; `debug: true` forces full debug logging. Default: "info". */ + logLevel: LogLevel allowSubAgents: boolean pruneNotification: "off" | "minimal" | "detailed" pruneNotificationType: "chat" | "toast" @@ -174,6 +177,7 @@ const defaultConfig: PluginConfig = { enabled: true, autoUpdate: true, debug: false, + logLevel: "info", allowSubAgents: true, pruneNotification: "off", // [FIX #20] Default to toast — chat-mode notifications inject an empty @@ -498,6 +502,7 @@ function mergeLayer(config: PluginConfig, data: Record): PluginConf enabled: data.enabled ?? config.enabled, autoUpdate: data.autoUpdate ?? config.autoUpdate, debug: data.debug ?? config.debug, + logLevel: data.logLevel ?? config.logLevel, allowSubAgents: data.allowSubAgents ?? data.experimental?.allowSubAgents ?? config.allowSubAgents, pruneNotification: data.pruneNotification ?? config.pruneNotification, pruneNotificationType: data.pruneNotificationType ?? config.pruneNotificationType, diff --git a/lib/hooks.ts b/lib/hooks.ts index 95a65ba..6c96e22 100644 --- a/lib/hooks.ts +++ b/lib/hooks.ts @@ -191,6 +191,7 @@ export function createChatMessageTransformHandler( requestModel?.providerID, requestModel?.modelID, ) + const prevModelID = state.modelID if (requestModelLimit !== undefined) { state.modelContextLimit = requestModelLimit state.modelProviderID = requestModel?.providerID @@ -214,6 +215,14 @@ export function createChatMessageTransformHandler( state.modelProviderID = requestModel.providerID state.modelID = requestModel.modelID } + if (requestModel?.modelID && requestModel.modelID !== prevModelID) { + logger.info("Model switched mid-session", { + session: state.sessionId, + from: prevModelID, + to: requestModel.modelID, + contextLimit: state.modelContextLimit, + }) + } await updatePerTurnState(state, logger, messages) } @@ -282,6 +291,20 @@ export function createChatMessageTransformHandler( hideFailedCompressCalls(output.messages) stripStaleMetadata(output.messages) dropEmptyMessages(output.messages) + const postTokens = getCurrentTokenUsage(state, output.messages) + logger.info("Chat transform complete", { + session: state.sessionId, + model: state.modelID, + messages: output.messages.length, + prePruneTokens, + postTokens, + contextLimit: state.modelContextLimit, + usagePct: + postTokens !== undefined && state.modelContextLimit + ? `${((postTokens / state.modelContextLimit) * 100).toFixed(1)}%` + : undefined, + nudged: state.nudges.shouldInjectThisTurn, + }) if (state.sessionId) { await logger.saveContext(state.sessionId, output.messages) diff --git a/lib/logger.ts b/lib/logger.ts index 40eadcb..8d5b089 100644 --- a/lib/logger.ts +++ b/lib/logger.ts @@ -8,16 +8,53 @@ declare const ACP_VERSION: string | undefined const LOG_VERSION = typeof ACP_VERSION !== "undefined" ? ACP_VERSION : "dev" +/** + * Log verbosity. Production default is `info` — decision-level events + * (nudge tiers, compression runs, gate verdicts, config resolution) are + * written to the daily log WITHOUT requiring `debug: true`. `debug` adds + * per-message detail and per-request context snapshots; `warn`/`error` + * reduce to failures only; `silent` disables file output entirely. + */ +export type LogLevel = "debug" | "info" | "warn" | "error" | "silent" + +const LEVEL_RANK: Record = { + debug: 10, + info: 20, + warn: 30, + error: 40, + silent: 99, +} + export class Logger { private logDir: string - public enabled: boolean + /** Resolved verbosity; replaces the old boolean `enabled` flag. */ + public readonly level: LogLevel - constructor(enabled: boolean) { - this.enabled = enabled + /** + * @param enabled legacy boolean toggle — `true` maps to `debug`, + * `false` maps to `warn` (errors + warnings only). + * @param level explicit verbosity; when given it wins over `enabled`. + */ + constructor(enabled: boolean, level?: LogLevel) { + // Config validation is warn-only, so an invalid `logLevel` string can + // reach us at runtime. Unknown levels must never zero out logging + // (LEVEL_RANK[x] === undefined fails every gate, dropping even ERROR); + // fall back to the legacy boolean mapping instead. + const resolved = level !== undefined && LEVEL_RANK[level] !== undefined ? level : undefined + this.level = resolved ?? (enabled ? "debug" : "warn") const configHome = process.env.XDG_CONFIG_HOME || join(homedir(), ".config") this.logDir = join(configHome, "opencode", "logs", "acp") } + /** Back-compat view of the old flag: true only at full debug verbosity. */ + get enabled(): boolean { + return this.level === "debug" + } + + private shouldWrite(level: LogLevel): boolean { + return LEVEL_RANK[level] >= LEVEL_RANK[this.level] + } + private async ensureLogDir() { if (!existsSync(this.logDir)) { await mkdir(this.logDir, { recursive: true }) @@ -72,10 +109,10 @@ export class Logger { } } - private async write(level: string, component: string, message: string, data?: any) { - // ERROR and WARN are written even when debug logging is off, so that - // failures remain visible in the daily log by default. - if (!this.enabled && level !== "ERROR" && level !== "WARN") return + private async write(level: string, component: string, message: string, data?: unknown) { + // Levels below the resolved verbosity are dropped here; WARN/ERROR + // still land by default because the production default is `info`. + if (!this.shouldWrite(level.toLowerCase() as LogLevel)) return try { await this.ensureLogDir() @@ -95,14 +132,14 @@ export class Logger { } catch (error) {} } - info(message: string, data?: any) { - if (!this.enabled) return + info(message: string, data?: unknown) { + if (!this.shouldWrite("info")) return const component = this.getCallerFile(2) return this.write("INFO", component, message, data) } - debug(message: string, data?: any) { - if (!this.enabled) return + debug(message: string, data?: unknown) { + if (!this.shouldWrite("debug")) return const component = this.getCallerFile(2) return this.write("DEBUG", component, message, data) } @@ -215,8 +252,8 @@ export class Logger { }) } - async saveContext(sessionId: string, messages: any[]) { - if (!this.enabled) return + async saveContext(sessionId: string, messages: unknown[]) { + if (this.level !== "debug") return try { const contextDir = join(this.logDir, "context", sessionId) diff --git a/lib/messages/inject/inject.ts b/lib/messages/inject/inject.ts index c6390d6..390f0a2 100644 --- a/lib/messages/inject/inject.ts +++ b/lib/messages/inject/inject.ts @@ -473,6 +473,13 @@ export const injectCompressNudges = ( appendToLastTextPart(suffixMessage, tierText) shouldInject = true + logger.info(`Tier ${tc.triggerTier} trigger nudge injected`, { + session: state.sessionId, + action, + targetTier: tc.targetTier, + blocks: candidates.length, + candidateTokens, + }) if (tc.triggerTier === 2) { state.nudges.lastTier2NudgeTokens = currentTokens } else { @@ -484,6 +491,37 @@ export const injectCompressNudges = ( state.nudges.shouldInjectThisTurn = shouldInject + // Decision-level audit trail: written at the default `info` level so nudge + // behavior is diagnosable from the daily log without `debug: true`. + const usagePct = + currentTokens !== undefined && modelContextLimit + ? `${((currentTokens / modelContextLimit) * 100).toFixed(1)}%` + : undefined + if (shouldInjectNudge) { + logger.info("Compression nudge injected", { + session: state.sessionId, + trigger: emergencyOverride ? "emergency" : "growth", + currentTokens, + usagePct, + growthSinceBaseline, + growthFloor, + recommendedRanges: recommendedRanges.length, + }) + } else if (shouldInjectNotice) { + logger.info("Emergency /compact notice injected (no compressible targets)", { + session: state.sessionId, + currentTokens, + usagePct, + }) + } else if (nudgeAllowed && nothingToCompress) { + logger.info("Nudge suppressed: nothing to compress", { + session: state.sessionId, + reason: allProtected ? "all_protected" : allInProtectedZone ? "in_protected_zone" : "below_effective_floor", + currentTokens, + usagePct, + compressibleRanges: contextRanges.compressible.length, + }) + } // Only log recommendation filter when a nudge is actually being injected — // avoids noisy per-turn logging when there's nothing to compress. if (shouldInject && config.debug && contextRanges.compressible.length > 0) { diff --git a/lib/update.ts b/lib/update.ts index 8e55a4e..58f3820 100644 --- a/lib/update.ts +++ b/lib/update.ts @@ -1,3 +1,4 @@ +import type { Logger } from "./logger" import { readFile, rm } from "node:fs/promises" import { basename, dirname, join } from "node:path" import { fileURLToPath } from "node:url" @@ -16,14 +17,34 @@ type UpdateResult = const PACKAGE_NAME = "opencode-acp" -export function startAutoUpdate(ctx: PluginInput, enabled: boolean): void { - if (!enabled) return +export function startAutoUpdate(ctx: PluginInput, enabled: boolean, logger?: Logger): void { + if (!enabled) { + logger?.info("Auto-update disabled by config") + return + } + logger?.info("Auto-update check starting") + const controller = new AbortController() const timeout = setTimeout(() => controller.abort(), 10_000) - void checkAutoUpdate(controller.signal) + void checkAutoUpdate(controller.signal, logger) .then((result) => { - if (!result.updated) return + if (!result.updated) { + if ("error" in result) { + logger?.warn("Auto-update failed", { + error: result.error, + name: result.name, + current: result.current, + latest: result.latest, + }) + } + return + } + logger?.info("Auto-update applied update", { + name: result.name, + from: result.current, + to: result.latest, + }) setTimeout(() => { ctx.client.tui.showToast({ body: { @@ -39,23 +60,43 @@ export function startAutoUpdate(ctx: PluginInput, enabled: boolean): void { .finally(() => clearTimeout(timeout)) } -async function checkAutoUpdate(signal: AbortSignal): Promise { +async function checkAutoUpdate(signal: AbortSignal, logger?: Logger): Promise { const packageDir = await findPackageDir(PACKAGE_NAME) - if (!packageDir) return { updated: false } - + if (!packageDir) { + logger?.info("Auto-update skipped: package dir not found") + return { updated: false } + } + const pkg = await readPackageJson(join(packageDir, "package.json")) - if (!pkg?.name || !pkg.version) return { updated: false } - + if (!pkg?.name || !pkg.version) { + logger?.info("Auto-update skipped: package.json unreadable", { packageDir }) + return { updated: false } + } + const target = await updateTarget(packageDir, pkg.name) - if (!target) return { updated: false } - - // Update within the channel the user installed from (dist-tag), not the - // global `latest` dist-tag: an @stable install must follow `stable`. + if (!target) { + logger?.info("Auto-update skipped: no update target", { name: pkg.name, version: pkg.version }) + return { updated: false } + } + + // Update within the channel the user installed from (dist-tag), not the + // global `latest` dist-tag: an @stable install must follow `stable`. const tag = specUpdateTag(target.spec) - if (!tag) return { updated: false } - + if (!tag) { + logger?.info("Auto-update skipped: spec not auto-updatable", { spec: target.spec }) + return { updated: false } + } + const latest = await fetchLatestVersion(pkg.name, tag, signal) - if (!latest || !isVersionNewer(latest, pkg.version)) return { updated: false } + if (!latest) { + logger?.info("Auto-update skipped: no version published for tag", { name: pkg.name, tag }) + return { updated: false } + } + if (!isVersionNewer(latest, pkg.version)) { + logger?.info("Auto-update: already up to date", { name: pkg.name, tag, current: pkg.version, latest }) + return { updated: false } + } + logger?.info("Auto-update: newer version available", { name: pkg.name, tag, current: pkg.version, latest }) try { await rm(target.removeDir, { recursive: true, force: true }) diff --git a/tests/logger.test.ts b/tests/logger.test.ts index 639acf4..3b0c8f8 100644 --- a/tests/logger.test.ts +++ b/tests/logger.test.ts @@ -3,7 +3,7 @@ import test from "node:test" import { mkdtempSync, readFileSync, existsSync } from "node:fs" import { tmpdir } from "node:os" import { join } from "node:path" -import { Logger } from "../lib/logger" +import { Logger, type LogLevel } from "../lib/logger" // Point the Logger at a throwaway XDG_CONFIG_HOME so daily logs land in a temp dir. function setup(): { configHome: string; logFile: string } { @@ -103,3 +103,71 @@ test("log line format: timestamp, padded level, component, message, version", as assert.match(line, /: boom \| v=(dev|\d+\.\d+\.\d+)$/) }) }) + +test("explicit info level: INFO/WARN/ERROR write, DEBUG gated (default-on logging)", async () => { + const { configHome, logFile } = setup() + await withConfigHome(configHome, async () => { + const logger = new Logger(false, "info") + + await logger.info("decision event", { tier: 1 }) + await logger.warn("warn event") + await logger.error("error event") + await logger.debug("debug gated") + + const lines = readLines(logFile) + assert.equal(lines.length, 3) + assert.match(lines[0], /\bINFO\s+[\w:/.]+: decision event \| tier=1 \| v=/) + assert.match(lines[1], /\bWARN\s+/) + assert.match(lines[2], /\bERROR\s+/) + }) +}) + +test("explicit silent level: nothing writes, even errors", async () => { + const { configHome, logFile } = setup() + await withConfigHome(configHome, async () => { + const logger = new Logger(true, "silent") + + await logger.error("swallowed") + assert.equal(existsSync(logFile), false) + }) +}) + +test("error level: only ERROR writes", async () => { + const { configHome, logFile } = setup() + await withConfigHome(configHome, async () => { + const logger = new Logger(false, "error") + + await logger.warn("gated") + await logger.error("kept") + + const lines = readLines(logFile) + assert.equal(lines.length, 1) + assert.match(lines[0], /\bERROR\s+[\w:/.]+: kept \| v=/) + }) +}) + +test("enabled getter reflects explicit level, not the boolean flag", async () => { + const { configHome } = setup() + await withConfigHome(configHome, async () => { + assert.equal(new Logger(false).enabled, false) + assert.equal(new Logger(true).enabled, true) + assert.equal(new Logger(false, "info").enabled, false) + assert.equal(new Logger(true, "info").enabled, false) + assert.equal(new Logger(false, "debug").enabled, true) + }) +}) + +test("invalid explicit level falls back to legacy mapping instead of silencing all logs", async () => { + const { configHome, logFile } = setup() + await withConfigHome(configHome, async () => { + // Config validation is warn-only: a typo like "verbose" reaches the + // constructor at runtime. It must degrade to the boolean mapping + // (false → warn), never to "every gate fails → nothing writes". + const logger = new Logger(false, "verbose" as LogLevel) + await logger.error("even errors must survive a bad level") + assert.equal(readLines(logFile).length, 1) + + const logger2 = new Logger(true, "verbose" as LogLevel) + assert.equal(logger2.level, "debug") + }) +})