From 40ee97c447ab09f41779b59e17e02808ae757641 Mon Sep 17 00:00:00 2001 From: Burak Yigit Kaya Date: Mon, 2 Mar 2026 20:49:44 +0000 Subject: [PATCH] Suppress informational log messages in TUI mode All log messages used console.error() which renders as red text in the TUI, making routine status messages (distillation, pruning, consolidation) look like errors. This confuses users who don't know if something is wrong. Add src/log.ts with three levels: - log.info(): suppressed by default, shown with LORE_DEBUG=1 - log.warn(): suppressed by default, shown with LORE_DEBUG=1 - log.error(): always visible (actual failures) Replace all console.error() calls with the appropriate level: - Informational (log.info): imported knowledge, pruned entries, incremental distillation, context overflow recovery steps, consolidation results, temporal pruning stats - Warnings (log.warn): dropping trailing assistant messages - Errors (log.error): import/export failures, distillation errors, curator errors, consolidation errors, pruning errors, recovery failures --- AGENTS.md | 10 +++++---- src/distillation.ts | 5 +++-- src/index.ts | 53 +++++++++++++++++++++++---------------------- src/log.ts | 27 +++++++++++++++++++++++ 4 files changed, 63 insertions(+), 32 deletions(-) create mode 100644 src/log.ts diff --git a/AGENTS.md b/AGENTS.md index d89f28b..dc3c613 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -28,15 +28,17 @@ * **Stuck compaction loops leave orphaned user+assistant message pairs in DB**: When OpenCode compaction overflows, it creates paired user+assistant messages per retry (assistant has error.name:'ContextOverflowError', mode:'compaction'). These accumulate and worsen the session. Recovery: find last good assistant message (has tokens, no error), delete all messages after it from both \`message\` and \`part\` tables. Use json\_extract(data, '$.error.name') to identify compaction debris. -* **Lore test suite uses live DB — no test isolation for db.test.ts**: The lore test suite (test/db.test.ts, test/ltm.test.ts) uses the live DB at ~/.local/share/opencode-lore/lore.db — no LORE\_DB\_PATH override. Test fixtures create entries with 019c9026-\* UUIDs that persist and leak into AGENTS.md exports. Known leaked entries: 'Kubernetes deployment pattern', 'TypeScript strict mode caveat', 'React useState async pitfall', 'Fine entry'. These require periodic manual cleanup from the DB. Fix needed: set LORE\_DB\_PATH to a temp file in tests. +* **Lore test suite uses live DB — no test isolation for db.test.ts**: Lore test suite (test/db.test.ts, test/ltm.test.ts) uses the live DB at ~/.local/share/opencode-lore/lore.db — no LORE\_DB\_PATH override. Test fixtures create entries with 019c9026-\* UUIDs that persist and leak into AGENTS.md exports. Known leaked entries: 'Kubernetes deployment pattern', 'TypeScript strict mode caveat', 'React useState async pitfall', 'Fine entry'. Require periodic manual cleanup. Fix needed: LORE\_DB\_PATH temp file in tests. -### Preference +### Pattern - -* **Code style**: User prefers no backwards-compat shims — fix callers directly. Prefer explicit error handling over silent failures. Derive thresholds from existing constants rather than hardcoding magic numbers (e.g., use \`raw.length <= COL\_COUNT\` instead of \`n < 10\_000\`). In CI, define shared env vars at workflow level, not per-job. + +* **Lore logging: LORE\_DEBUG gating for info/warn, always-on for errors**: src/log.ts provides three levels: log.info() and log.warn() are suppressed unless LORE\_DEBUG=1 or LORE\_DEBUG=true; log.error() always emits. All write to stderr with \[lore] prefix. This exists because OpenCode TUI renders all stderr as red error text — routine status messages (distillation counts, pruning stats, consolidation) were alarming users. Rule: use log.info() for successful operations and status, log.warn() for non-actionable oddities (e.g. dropping trailing messages), log.error() only in catch blocks for real failures. Never use console.error directly in plugin source files. ### Preference * **Always dry-run before bulk DB deletes**: Never execute bulk DELETE/destructive operations without first running the equivalent SELECT to verify row count and inspect affected rows. A hardcoded timestamp off by one year caused deletion of all 1638 messages + 5927 parts instead of 5 debris rows. Pattern: (1) SELECT with same WHERE, (2) verify count, (3) then DELETE. Applies to any destructive op — DB mutations, git reset, file deletion. + +* **Code style**: User prefers no backwards-compat shims — fix callers directly. Prefer explicit error handling over silent failures. Derive thresholds from existing constants rather than hardcoding magic numbers (e.g., use \`raw.length <= COL\_COUNT\` instead of \`n < 10\_000\`). In CI, define shared env vars at workflow level, not per-job. diff --git a/src/distillation.ts b/src/distillation.ts index 38562b8..51a565c 100644 --- a/src/distillation.ts +++ b/src/distillation.ts @@ -2,6 +2,7 @@ import type { createOpencodeClient } from "@opencode-ai/sdk"; import { db, ensureProject } from "./db"; import { config } from "./config"; import * as temporal from "./temporal"; +import * as log from "./log"; import { DISTILLATION_SYSTEM, distillationUser, @@ -273,8 +274,8 @@ export async function run(input: { // Reset orphaned messages (marked distilled by a deleted/migrated distillation) const orphans = resetOrphans(input.projectPath, input.sessionID); if (orphans > 0) { - console.error( - `[lore] Reset ${orphans} orphaned messages for re-observation`, + log.info( + `Reset ${orphans} orphaned messages for re-observation`, ); } diff --git a/src/index.ts b/src/index.ts index d55a33a..4718340 100644 --- a/src/index.ts +++ b/src/index.ts @@ -18,6 +18,7 @@ import { import { formatKnowledge, formatDistillations } from "./prompt"; import { createRecallTool } from "./reflect"; import { shouldImport, importFromFile, exportToFile } from "./agents-file"; +import * as log from "./log"; /** * Detect whether an error from session.error is a context overflow ("prompt too long"). @@ -85,9 +86,9 @@ export const LorePlugin: Plugin = async (ctx) => { if (shouldImport({ projectPath, filePath })) { try { importFromFile({ projectPath, filePath }); - console.error("[lore] imported knowledge from", cfg.agentsFile.path); + log.info("imported knowledge from", cfg.agentsFile.path); } catch (e) { - console.error("[lore] agents-file import error:", e); + log.error("agents-file import error:", e); } } } @@ -99,7 +100,7 @@ export const LorePlugin: Plugin = async (ctx) => { if (config().knowledge.enabled) { const pruned = ltm.pruneOversized(1200); if (pruned > 0) { - console.error(`[lore] pruned ${pruned} oversized knowledge entries (confidence set to 0)`); + log.info(`pruned ${pruned} oversized knowledge entries (confidence set to 0)`); } } @@ -168,7 +169,7 @@ export const LorePlugin: Plugin = async (ctx) => { }); } } catch (e) { - console.error("[lore] distillation error:", e); + log.error("distillation error:", e); } finally { distilling = false; } @@ -185,7 +186,7 @@ export const LorePlugin: Plugin = async (ctx) => { model: cfg.model, }); } catch (e) { - console.error("[lore] curator error:", e); + log.error("curator error:", e); } } @@ -240,8 +241,8 @@ export const LorePlugin: Plugin = async (ctx) => { ) { const pending = temporal.undistilledCount(projectPath, msg.sessionID); if (pending >= config().distillation.maxSegment) { - console.error( - `[lore] incremental distillation: ${pending} undistilled messages in ${msg.sessionID.substring(0, 16)}`, + log.info( + `incremental distillation: ${pending} undistilled messages in ${msg.sessionID.substring(0, 16)}`, ); backgroundDistill(msg.sessionID); } @@ -271,11 +272,11 @@ export const LorePlugin: Plugin = async (ctx) => { // Detect "prompt is too long" API errors and auto-recover. const rawError = (event.properties as Record).error; - console.error("[lore] session.error received:", JSON.stringify(rawError, null, 2)); + log.info("session.error received:", JSON.stringify(rawError, null, 2)); if (isContextOverflow(rawError) && errorSessionID) { - console.error( - `[lore] detected context overflow — auto-recovering (session: ${errorSessionID.substring(0, 16)})`, + log.info( + `detected context overflow — auto-recovering (session: ${errorSessionID.substring(0, 16)})`, ); // 1. Force layer 2 on next transform (persisted to DB — survives restarts). @@ -294,8 +295,8 @@ export const LorePlugin: Plugin = async (ctx) => { summaries.map(s => ({ observations: s.observations, generation: s.generation })), ); - console.error( - `[lore] sending auto-recovery message to session ${errorSessionID.substring(0, 16)}`, + log.info( + `sending auto-recovery message to session ${errorSessionID.substring(0, 16)}`, ); await ctx.client.session.prompt({ path: { id: errorSessionID }, @@ -303,14 +304,14 @@ export const LorePlugin: Plugin = async (ctx) => { parts: [{ type: "text", text: recoveryText, synthetic: true }], }, }); - console.error( - `[lore] auto-recovery message sent successfully`, + log.info( + `auto-recovery message sent successfully`, ); } catch (recoveryError) { // Recovery is best-effort — don't let it crash the event handler. // The persisted forceMinLayer will still help on the user's next message. - console.error( - `[lore] auto-recovery failed (forceMinLayer still persisted):`, + log.error( + `auto-recovery failed (forceMinLayer still persisted):`, recoveryError, ); } @@ -343,8 +344,8 @@ export const LorePlugin: Plugin = async (ctx) => { if (cfg.knowledge.enabled) try { const allEntries = ltm.forProject(projectPath); if (allEntries.length > cfg.curator.maxEntries) { - console.error( - `[lore] entry count ${allEntries.length} exceeds maxEntries ${cfg.curator.maxEntries} — running consolidation`, + log.info( + `entry count ${allEntries.length} exceeds maxEntries ${cfg.curator.maxEntries} — running consolidation`, ); const { updated, deleted } = await curator.consolidate({ client: ctx.client, @@ -353,11 +354,11 @@ export const LorePlugin: Plugin = async (ctx) => { model: cfg.model, }); if (updated > 0 || deleted > 0) { - console.error(`[lore] consolidation: ${updated} updated, ${deleted} deleted`); + log.info(`consolidation: ${updated} updated, ${deleted} deleted`); } } } catch (e) { - console.error("[lore] consolidation error:", e); + log.error("consolidation error:", e); } // Prune temporal messages after distillation and curation have run. @@ -371,12 +372,12 @@ export const LorePlugin: Plugin = async (ctx) => { maxStorageMB: cfg.pruning.maxStorage, }); if (ttlDeleted > 0 || capDeleted > 0) { - console.error( - `[lore] pruned temporal messages: ${ttlDeleted} by TTL, ${capDeleted} by size cap`, + log.info( + `pruned temporal messages: ${ttlDeleted} by TTL, ${capDeleted} by size cap`, ); } } catch (e) { - console.error("[lore] pruning error:", e); + log.error("pruning error:", e); } // Export curated knowledge to AGENTS.md after distillation + curation. @@ -387,7 +388,7 @@ export const LorePlugin: Plugin = async (ctx) => { exportToFile({ projectPath, filePath }); } } catch (e) { - console.error("[lore] agents-file export error:", e); + log.error("agents-file export error:", e); } } }, @@ -508,8 +509,8 @@ export const LorePlugin: Plugin = async (ctx) => { break; } const dropped = result.messages.pop()!; - console.error( - "[lore] WARN: dropping trailing pure-text", + log.warn( + "dropping trailing pure-text", dropped.info.role, "message to prevent prefill error. id:", dropped.info.id, diff --git a/src/log.ts b/src/log.ts new file mode 100644 index 0000000..ad6c96b --- /dev/null +++ b/src/log.ts @@ -0,0 +1,27 @@ +/** + * Lightweight logger that suppresses informational messages by default. + * + * In TUI mode, all stderr output renders as red "error" text — confusing + * for routine status messages like "incremental distillation" or "pruned + * temporal messages". Only actual errors should be visible by default. + * + * Set LORE_DEBUG=1 to see informational messages (useful when debugging + * the plugin itself). + */ + +const isDebug = !!process.env.LORE_DEBUG; + +/** Log an informational status message. Suppressed unless LORE_DEBUG=1. */ +export function info(...args: unknown[]): void { + if (isDebug) console.error("[lore]", ...args); +} + +/** Log a warning. Suppressed unless LORE_DEBUG=1. */ +export function warn(...args: unknown[]): void { + if (isDebug) console.error("[lore] WARN:", ...args); +} + +/** Log an error. Always visible — these indicate real failures. */ +export function error(...args: unknown[]): void { + console.error("[lore]", ...args); +}