diff --git a/@omniroute/opencode-plugin/package.json b/@omniroute/opencode-plugin/package.json index 848bca4b3a..f096226d79 100644 --- a/@omniroute/opencode-plugin/package.json +++ b/@omniroute/opencode-plugin/package.json @@ -23,7 +23,7 @@ "scripts": { "build": "tsup", "clean": "rm -rf dist", - "test": "node --import tsx/esm --test tests/scaffold.test.ts tests/auth.test.ts tests/options-schema.test.ts tests/multi-instance.test.ts tests/fetch-interceptor.test.ts tests/provider.test.ts tests/gemini-sanitize.test.ts tests/combos.test.ts tests/config-shim.test.ts tests/features.test.ts tests/feature-defaults.test.ts tests/usable-combo.test.ts tests/disk-snapshot-perms.test.ts tests/fork-features.test.ts tests/auto-combo-context.test.ts tests/provider-id-routing.test.ts tests/management-read-token.test.ts tests/auto-sync.test.ts tests/model-allowlist.test.ts", + "test": "node --import tsx/esm --test tests/scaffold.test.ts tests/auth.test.ts tests/options-schema.test.ts tests/multi-instance.test.ts tests/fetch-interceptor.test.ts tests/provider.test.ts tests/gemini-sanitize.test.ts tests/combos.test.ts tests/config-shim.test.ts tests/features.test.ts tests/feature-defaults.test.ts tests/usable-combo.test.ts tests/disk-snapshot-perms.test.ts tests/fork-features.test.ts tests/auto-combo-context.test.ts tests/provider-id-routing.test.ts tests/management-read-token.test.ts tests/auto-sync.test.ts tests/model-allowlist.test.ts tests/log-level.test.ts", "prepublishOnly": "npm run clean && npm run build && npm test" }, "keywords": [ diff --git a/@omniroute/opencode-plugin/src/index.ts b/@omniroute/opencode-plugin/src/index.ts index ef07b3c112..09e3825676 100644 --- a/@omniroute/opencode-plugin/src/index.ts +++ b/@omniroute/opencode-plugin/src/index.ts @@ -57,7 +57,12 @@ import type { AuthHook, Config, Plugin, PluginOptions, ProviderHook } from "@ope import { tool } from "@opencode-ai/plugin"; import type { Model as ModelV2 } from "@opencode-ai/sdk/v2"; import { z } from "zod"; -import { logger as _logger, setLogLevel, type LogLevel as _LogLevel } from "./logger.js"; +import { + createLogger, + logger as _logger, + type Logger as _Logger, + type LogLevel as _LogLevel, +} from "./logger.js"; import { PROVIDER_TAG_SEPARATOR as _PROVIDER_TAG_SEPARATOR, shortProviderLabel as _shortProviderLabel, @@ -717,6 +722,7 @@ export async function forceSyncOmniRouteModels(args: { compressionMetaFetcher?: OmniRouteCompressionMetaFetcher; providersFetcher?: OmniRouteProvidersFetcher; now?: () => number; + logger?: _Logger; }): Promise<{ ok: boolean; count: number; @@ -737,6 +743,11 @@ export async function forceSyncOmniRouteModels(args: { const compressionMetaFetcher = args.compressionMetaFetcher ?? defaultOmniRouteCompressionMetaFetcher; const providersFetcher = args.providersFetcher ?? defaultOmniRouteProvidersFetcher; + const logger = + args.logger ?? + createLogger( + resolved.features?.startupDebug ? "debug" : (resolved.features?.logLevel ?? "warn") + ); const features = resolved.features ?? {}; const wantCombos = features.combos !== false; const wantAutoCombos = features.autoCombos !== false; @@ -847,8 +858,8 @@ export async function forceSyncOmniRouteModels(args: { } } - console.warn( - `[omniroute-plugin] force sync ok providerId=${resolved.providerId} ` + + logger.info( + `force sync ok providerId=${resolved.providerId} ` + `models=${rawModels.length} combos=${rawCombos.length} ` + `clearedMemory=${clearedMemory + clearedAll} disk=${clearedDisk}` ); @@ -880,6 +891,7 @@ export async function forceSyncOmniRouteModels(args: { export function createOmniRouteSyncModelsTool(args: { resolved: ResolvedOmniRoutePluginOptions; cache: OmniRouteFetchCache; + logger?: _Logger; }): ReturnType { const { resolved, cache } = args; return tool({ @@ -893,7 +905,7 @@ export function createOmniRouteSyncModelsTool(args: { .describe("Optional reason for the sync (logging only)"), }, async execute(toolArgs) { - const result = await forceSyncOmniRouteModels({ resolved, cache }); + const result = await forceSyncOmniRouteModels({ resolved, cache, logger: args.logger }); const reason = toolArgs.reason ? ` reason=${toolArgs.reason}` : ""; if (!result.ok) { return { @@ -932,10 +944,16 @@ export function startOmniRouteAutoSync(args: { resolved: ResolvedOmniRoutePluginOptions; cache: OmniRouteFetchCache; intervalMs?: number; + logger?: _Logger; }): () => void { const resolved = args.resolved; const cache = args.cache; const intervalMs = args.intervalMs ?? resolved.autoSyncIntervalMs; + const logger = + args.logger ?? + createLogger( + resolved.features?.startupDebug ? "debug" : (resolved.features?.logLevel ?? "warn") + ); if (!intervalMs || intervalMs <= 0) { return () => {}; } @@ -948,11 +966,9 @@ export function startOmniRouteAutoSync(args: { if (stopped) return; if (inFlight) return; inFlight = (async () => { - const result = await forceSyncOmniRouteModels({ resolved, cache }); + const result = await forceSyncOmniRouteModels({ resolved, cache, logger }); if (!result.ok) { - console.warn( - `[omniroute-plugin] auto-sync failed providerId=${resolved.providerId}: ${result.error}` - ); + logger.error(`auto-sync failed providerId=${resolved.providerId}: ${result.error}`); return; } if (lastCount === undefined) { @@ -960,15 +976,15 @@ export function startOmniRouteAutoSync(args: { return; } if (result.count !== lastCount) { - console.warn( - `[omniroute-plugin] auto-sync catalog size changed ${lastCount} → ${result.count} ` + + logger.info( + `auto-sync catalog size changed ${lastCount} → ${result.count} ` + `(providerId=${resolved.providerId})` ); lastCount = result.count; } })() .catch((err) => { - console.warn("[omniroute-plugin] auto-sync tick error", err); + logger.error(`auto-sync tick error: ${err instanceof Error ? err.message : String(err)}`); }) .finally(() => { inFlight = null; @@ -982,9 +998,7 @@ export function startOmniRouteAutoSync(args: { timer.unref(); } - console.warn( - `[omniroute-plugin] auto-sync enabled intervalMs=${intervalMs} providerId=${resolved.providerId}` - ); + logger.info(`auto-sync enabled intervalMs=${intervalMs} providerId=${resolved.providerId}`); return () => { stopped = true; @@ -994,6 +1008,9 @@ export function startOmniRouteAutoSync(args: { export const OmniRoutePlugin: Plugin = async (_input, options) => { const resolved = resolveOmniRoutePluginOptions(coercePluginOptions(options)); + const logger = createLogger( + resolved.features?.startupDebug ? "debug" : (resolved.features?.logLevel ?? "warn") + ); // T-07: a single per-plugin-instance cache shared between the provider // hook (T-03/T-05) and the config-shim hook (T-07). On OC ≥1.14.49 both // hooks fire within the same Plugin invocation, so a shared cache keeps @@ -1010,7 +1027,7 @@ export const OmniRoutePlugin: Plugin = async (_input, options) => { const _hash: string = ((globalThis as Record).__PLUGIN_GIT_HASH__ as string) ?? "unknown"; const _prefixes = resolved.features?.apiFormat?.anthropicPrefixes ?? DEFAULT_ANTHROPIC_PREFIXES; - _logger.always( + logger.info( `v${_ver} (${_hash}) initialized` + ` providerId=${resolved.providerId}` + ` baseURL=${resolved.baseURL ?? "(from auth.json)"}` + @@ -1020,14 +1037,11 @@ export const OmniRoutePlugin: Plugin = async (_input, options) => { ` logLevel=${resolved.features?.startupDebug ? "debug" : (resolved.features?.logLevel ?? "warn")}` ); - // Wire log level: startupDebug:true → "debug", explicit logLevel wins. - setLogLevel(resolved.features?.startupDebug ? "debug" : (resolved.features?.logLevel ?? "warn")); - // Background auto-discovery while the harness is running (Pi parity). // Interval 0 disables. TTL on-demand discovery still works via modelCacheTtl. - startOmniRouteAutoSync({ resolved, cache: sharedCache }); + startOmniRouteAutoSync({ resolved, cache: sharedCache, logger }); - const syncTool = createOmniRouteSyncModelsTool({ resolved, cache: sharedCache }); + const syncTool = createOmniRouteSyncModelsTool({ resolved, cache: sharedCache, logger }); const bareProviderId = resolved.omnirouteProviderId; // Config hook: keep existing catalog shim, and register slash command @@ -1035,6 +1049,7 @@ export const OmniRoutePlugin: Plugin = async (_input, options) => { // Pi-style registerCommand API; tools + command templates are the native path). const baseConfigHook = createOmniRouteConfigHook(resolved, { cache: sharedCache, + logger, diskSnapshotReader: defaultDiskSnapshotReader, diskSnapshotWriter: defaultDiskSnapshotWriter, }); @@ -5143,13 +5158,13 @@ export const defaultReadAuthJson: OmniRouteReadAuthJson = async () => { * `auth.json[providerId].baseURL`), * (e) `input.provider[providerId]` is ALREADY set (operator override * wins — we never clobber manually-curated catalogs). - * Each no-op path emits ONE debug-level breadcrumb to `console.warn` + * Each no-op path emits ONE debug-level breadcrumb through the leveled logger * so the operator can diagnose without log spam. Malformed `auth.json` * warns once and continues as if the file were missing. * - Fail-open on fetcher errors: a `/v1/models` failure → still publish * a stub `{models: {}}` provider block (so OC has a complete-shape * entry to render). A `/api/combos` failure → publish models-only. - * Both paths emit ONE `console.warn`. + * Both paths emit ONE error-level logger message. * - When the provider hook (T-03/T-05) has ALREADY populated the shared * cache for this (baseURL, apiKey) tuple, we reuse the raw payloads * directly — no second fetch. (And vice-versa: the config hook fires @@ -5172,8 +5187,8 @@ export const defaultReadAuthJson: OmniRouteReadAuthJson = async () => { * - `cache` — shared fetch-result cache (see * `OmniRouteFetchCache`). Pass the same Map the * provider hook owns to dedupe round-trips. - * - `logger` — `{warn}` sink for breadcrumb capture in tests. - * Defaults to `console`. + * - `logger` — injected sink for breadcrumb capture in tests. + * Defaults to the plugin's leveled logger. */ export function createOmniRouteConfigHook( opts?: OmniRoutePluginOptions, @@ -5189,7 +5204,11 @@ export function createOmniRouteConfigHook( diskSnapshotWriter?: OmniRouteDiskSnapshotWriter; now?: () => number; cache?: OmniRouteFetchCache; - logger?: { warn: (...args: unknown[]) => void }; + logger?: { + error?: (message: string, ...args: unknown[]) => void; + warn: (message: string, ...args: unknown[]) => void; + debug?: (message: string, ...args: unknown[]) => void; + }; } = {} ): (input: Config) => Promise { const resolved = resolveOmniRoutePluginOptions(opts); @@ -5205,7 +5224,11 @@ export function createOmniRouteConfigHook( const diskSnapshotWriter = deps.diskSnapshotWriter ?? noopDiskSnapshotWriter; const now = deps.now ?? Date.now; const cache: OmniRouteFetchCache = deps.cache ?? new Map(); - const logger = deps.logger ?? console; + const logger = deps.logger ?? _logger; + const logAt = (level: "error" | "warn" | "debug", message: string): void => { + const sink = logger[level] ?? logger.warn; + sink.call(logger, message); + }; const features = resolved.features ?? {}; const wantAutoCombos = features.autoCombos !== false; const wantEnrichment = features.enrichment !== false; @@ -5220,9 +5243,7 @@ export function createOmniRouteConfigHook( // generated block. Detect-and-respect before any I/O. const existingProviders = (input as { provider?: Record }).provider; if (existingProviders && existingProviders[resolved.providerId] !== undefined) { - logger.warn( - `[omniroute-plugin] config shim skipped: provider.${resolved.providerId} already set by user` - ); + logAt("debug", `config shim skipped: provider.${resolved.providerId} already set by user`); return; } @@ -5237,7 +5258,7 @@ export function createOmniRouteConfigHook( } if (authJson === null) { - logger.warn("[omniroute-plugin] config shim: auth.json failed to parse; treating as missing"); + logAt("warn", "config shim: auth.json failed to parse; treating as missing"); authJson = undefined; } @@ -5264,9 +5285,7 @@ export function createOmniRouteConfigHook( // (c) no apiKey — silent no-op (with debug breadcrumb). The operator // hasn't run `/connect ` yet, OR the stored credential // isn't api-flavored. OC will handle the `/connect` flow at runtime. - logger.warn( - `[omniroute-plugin] config shim skipped: no apiKey for providerId=${resolved.providerId}` - ); + logAt("debug", `config shim skipped: no apiKey for providerId=${resolved.providerId}`); return; } // Management-plane catalog reads may use a narrower read-only token. @@ -5279,9 +5298,7 @@ export function createOmniRouteConfigHook( const storedBaseURL = entry && typeof entry.baseURL === "string" ? entry.baseURL : undefined; const baseURL = resolved.baseURL ?? storedBaseURL ?? ""; if (!baseURL) { - logger.warn( - `[omniroute-plugin] config shim skipped: no baseURL for providerId=${resolved.providerId}` - ); + logAt("debug", `config shim skipped: no baseURL for providerId=${resolved.providerId}`); return; } @@ -5326,8 +5343,9 @@ export function createOmniRouteConfigHook( // Log snapshot age (accept any age — instant beats empty). const age = (snapshotResult as { writtenAt?: number }).writtenAt; const ageLabel = typeof age === "number" ? `${Math.round((Date.now() - age) / 3_600_000)}h` : "unknown"; - logger.warn( - `[omniroute-plugin] config shim: warm startup from disk snapshot (${snapshotResult.rawModels.length} models, age ${ageLabel})` + logAt( + "warn", + `config shim: warm startup from disk snapshot (${snapshotResult.rawModels.length} models, age ${ageLabel})` ); } } @@ -5353,9 +5371,9 @@ export function createOmniRouteConfigHook( try { localRawModels = await fetcher(baseURL, apiKey, 10_000); } catch (err) { - logger.warn( - "[omniroute-plugin] config shim: /v1/models fetch failed; publishing stub provider entry", - err + logAt( + "error", + `config shim: /v1/models fetch failed; publishing stub provider entry: ${err instanceof Error ? err.message : String(err)}` ); localRawModels = []; modelsFetchThrew = true; @@ -5366,9 +5384,9 @@ export function createOmniRouteConfigHook( try { localRawCombos = await combosFetcher(baseURL, managementReadToken, 10_000); } catch (err) { - logger.warn( - "[omniroute-plugin] config shim: /api/combos fetch failed; publishing models-only static catalog", - err + logAt( + "error", + `config shim: /api/combos fetch failed; publishing models-only static catalog: ${err instanceof Error ? err.message : String(err)}` ); } }; @@ -5387,9 +5405,9 @@ export function createOmniRouteConfigHook( try { localRawEnrichment = await enrichmentFetcher(baseURL, managementReadToken, 10_000); } catch (err) { - logger.warn( - "[omniroute-plugin] config shim: /api/pricing/models fetch failed; publishing raw-id static catalog", - err + logAt( + "error", + `config shim: /api/pricing/models fetch failed; publishing raw-id static catalog: ${err instanceof Error ? err.message : String(err)}` ); } }; @@ -5399,9 +5417,9 @@ export function createOmniRouteConfigHook( try { localRawCompressionCombos = await compressionMetaFetcher(baseURL, managementReadToken, 10_000); } catch (err) { - logger.warn( - "[omniroute-plugin] config shim: /api/context/combos fetch failed; publishing combos without compression suffix", - err + logAt( + "error", + `config shim: /api/context/combos fetch failed; publishing combos without compression suffix: ${err instanceof Error ? err.message : String(err)}` ); } }; @@ -5411,9 +5429,9 @@ export function createOmniRouteConfigHook( try { localRawConnections = await providersFetcher(baseURL, managementReadToken, 10_000); } catch (err) { - logger.warn( - "[omniroute-plugin] config shim: /api/providers fetch failed; usableOnly filter disabled for this refresh", - err + logAt( + "error", + `config shim: /api/providers fetch failed; usableOnly filter disabled for this refresh: ${err instanceof Error ? err.message : String(err)}` ); } }; @@ -5436,8 +5454,9 @@ export function createOmniRouteConfigHook( if (modelsFetchThrew && wantDiskCache && !warmSnapshot) { const snapshot = await diskSnapshotReader(resolved.providerId, snapshotFingerprint); if (snapshot && snapshot.rawModels.length > 0) { - logger.warn( - `[omniroute-plugin] config shim: /v1/models unreachable; using stale disk cache (${snapshot.rawModels.length} models)` + logAt( + "warn", + `config shim: /v1/models unreachable; using stale disk cache (${snapshot.rawModels.length} models)` ); localRawModels = snapshot.rawModels; localRawCombos = snapshot.rawCombos; @@ -5459,6 +5478,7 @@ export function createOmniRouteConfigHook( rawConnections: localRawConnections, expiresAt: now() + resolved.modelCacheTtl, }); + }); // Startup diagnostics (file-based) — fires at startup via config hook if (resolved.features?.startupDebug === true) { @@ -5537,7 +5557,10 @@ export function createOmniRouteConfigHook( } else { const refreshP = doRefresh() .catch((err: unknown) => { - logger.warn("[omniroute-plugin] config shim: background refresh failed", err); + logAt( + "error", + `config shim: background refresh failed: ${err instanceof Error ? err.message : String(err)}` + ); }) .finally(() => { _inflightRefresh.delete(cacheKey); @@ -5563,7 +5586,10 @@ export function createOmniRouteConfigHook( } else { const refreshP = doRefresh() .catch((err: unknown) => { - logger.warn("[omniroute-plugin] config shim: refresh failed", err); + logAt( + "error", + `config shim: refresh failed: ${err instanceof Error ? err.message : String(err)}` + ); }) .finally(() => { _inflightRefresh.delete(cacheKey); @@ -5618,8 +5644,9 @@ export function createOmniRouteConfigHook( if (features.mcpAutoEmit === true) { const mcpKey = features.mcpToken ?? apiKey; if (!mcpKey) { - logger.warn( - `[omniroute-plugin] mcp auto-emit skipped: no Bearer token for providerId=${resolved.providerId}` + logAt( + "debug", + `mcp auto-emit skipped: no Bearer token for providerId=${resolved.providerId}` ); } else { const inputWithMcp = input as { mcp?: Record }; @@ -5627,9 +5654,7 @@ export function createOmniRouteConfigHook( inputWithMcp.mcp = {}; } if (inputWithMcp.mcp[resolved.providerId] !== undefined) { - logger.warn( - `[omniroute-plugin] mcp auto-emit skipped: mcp.${resolved.providerId} already set by user` - ); + logAt("debug", `mcp auto-emit skipped: mcp.${resolved.providerId} already set by user`); } else { // Strip a trailing `/v1` from baseURL when present so we land on // the MCP transport at /api/mcp/stream, not /v1/api/mcp/stream. diff --git a/@omniroute/opencode-plugin/src/logger.ts b/@omniroute/opencode-plugin/src/logger.ts index de283c113c..cdf5a7855e 100644 --- a/@omniroute/opencode-plugin/src/logger.ts +++ b/@omniroute/opencode-plugin/src/logger.ts @@ -36,39 +36,47 @@ function fmt(level: LogLevel, msg: string, tag?: string): string { return `${prefix} [${level.toUpperCase()}] ${msg}`; } -export const logger = { - error(msg: string, ...args: unknown[]): void { - if (shouldLog(_level, "error")) console.error(fmt("error", msg), ...args); - }, - warn(msg: string, ...args: unknown[]): void { - if (shouldLog(_level, "warn")) console.warn(fmt("warn", msg), ...args); - }, - info(msg: string, ...args: unknown[]): void { - if (shouldLog(_level, "info")) console.warn(fmt("info", msg), ...args); - }, - debug(msg: string, ...args: unknown[]): void { - if (shouldLog(_level, "debug")) console.warn(fmt("debug", msg), ...args); - }, - /** Always emit regardless of level (for critical init breadcrumbs). */ - always(msg: string, ...args: unknown[]): void { - console.warn(TAG, msg, ...args); - }, +function buildLogger(getLevel: () => LogLevel) { + return { + error(msg: string, ...args: unknown[]): void { + if (shouldLog(getLevel(), "error")) console.error(fmt("error", msg), ...args); + }, + warn(msg: string, ...args: unknown[]): void { + if (shouldLog(getLevel(), "warn")) console.warn(fmt("warn", msg), ...args); + }, + info(msg: string, ...args: unknown[]): void { + if (shouldLog(getLevel(), "info")) console.warn(fmt("info", msg), ...args); + }, + debug(msg: string, ...args: unknown[]): void { + if (shouldLog(getLevel(), "debug")) console.warn(fmt("debug", msg), ...args); + }, + /** Always emit regardless of level (for critical init breadcrumbs). */ + always(msg: string, ...args: unknown[]): void { + console.warn(TAG, msg, ...args); + }, - // ── Tagged child loggers ────────────────────────────────────────────── - child(tag: string) { - return { - error: (msg: string, ...args: unknown[]) => - shouldLog(_level, "error") && - console.error(fmt("error", msg, tag), ...args), - warn: (msg: string, ...args: unknown[]) => - shouldLog(_level, "warn") && - console.warn(fmt("warn", msg, tag), ...args), - info: (msg: string, ...args: unknown[]) => - shouldLog(_level, "info") && - console.warn(fmt("info", msg, tag), ...args), - debug: (msg: string, ...args: unknown[]) => - shouldLog(_level, "debug") && - console.warn(fmt("debug", msg, tag), ...args), - }; - }, -}; + // ── Tagged child loggers ──────────────────────────────────────────── + child(tag: string) { + return { + error: (msg: string, ...args: unknown[]) => + shouldLog(getLevel(), "error") && console.error(fmt("error", msg, tag), ...args), + warn: (msg: string, ...args: unknown[]) => + shouldLog(getLevel(), "warn") && console.warn(fmt("warn", msg, tag), ...args), + info: (msg: string, ...args: unknown[]) => + shouldLog(getLevel(), "info") && console.warn(fmt("info", msg, tag), ...args), + debug: (msg: string, ...args: unknown[]) => + shouldLog(getLevel(), "debug") && console.warn(fmt("debug", msg, tag), ...args), + }; + }, + }; +} + +export type Logger = ReturnType; + +/** Create an instance-scoped logger whose level cannot be changed by other plugin instances. */ +export function createLogger(level: LogLevel): Logger { + return buildLogger(() => level); +} + +/** Backward-compatible module-global logger controlled by setLogLevel(). */ +export const logger: Logger = buildLogger(() => _level); diff --git a/@omniroute/opencode-plugin/tests/auto-sync.test.ts b/@omniroute/opencode-plugin/tests/auto-sync.test.ts index 95d52f1902..709fbdf317 100644 --- a/@omniroute/opencode-plugin/tests/auto-sync.test.ts +++ b/@omniroute/opencode-plugin/tests/auto-sync.test.ts @@ -13,6 +13,22 @@ import { forceSyncOmniRouteModels, type OmniRouteFetchCache, } from "../src/index.js"; +import { getLogLevel, setLogLevel } from "../src/logger.js"; + +async function captureConsole(run: () => Promise): Promise { + const lines: string[] = []; + const originalError = console.error; + const originalWarn = console.warn; + console.error = (...args: unknown[]) => lines.push(args.map(String).join(" ")); + console.warn = (...args: unknown[]) => lines.push(args.map(String).join(" ")); + try { + await run(); + } finally { + console.error = originalError; + console.warn = originalWarn; + } + return lines; +} test("sanitizeAutoSyncIntervalMs: unset → default 300000", () => { assert.equal(sanitizeAutoSyncIntervalMs(undefined), DEFAULT_AUTO_SYNC_INTERVAL_MS); @@ -35,7 +51,10 @@ test("sanitizeAutoSyncIntervalMs: keeps valid values", () => { test("parseOmniRoutePluginOptions accepts autoSyncIntervalMs including 0", () => { assert.equal(parseOmniRoutePluginOptions({ autoSyncIntervalMs: 0 }).autoSyncIntervalMs, 0); - assert.equal(parseOmniRoutePluginOptions({ autoSyncIntervalMs: 120_000 }).autoSyncIntervalMs, 120_000); + assert.equal( + parseOmniRoutePluginOptions({ autoSyncIntervalMs: 120_000 }).autoSyncIntervalMs, + 120_000 + ); }); test("resolveOmniRoutePluginOptions defaults autoSyncIntervalMs to 300000", () => { @@ -112,6 +131,76 @@ test("forceSyncOmniRouteModels: fetches, populates cache, returns count", async assert.equal(entry.expiresAt, 1_000_000 + resolved.modelCacheTtl); }); +test("forceSyncOmniRouteModels suppresses successful lifecycle output at error level", async () => { + const previousLevel = getLogLevel(); + const cache: OmniRouteFetchCache = new Map(); + const resolved = resolveOmniRoutePluginOptions({ + providerId: "omniroute", + baseURL: "https://omniroute.example/v1", + features: { + autoCombos: false, + combos: false, + compressionMetadata: false, + diskCache: false, + enrichment: false, + logLevel: "error", + usableOnly: false, + }, + }); + + try { + setLogLevel("error"); + const lines = await captureConsole(async () => { + const result = await forceSyncOmniRouteModels({ + resolved, + cache, + readAuthJson: async () => ({ omniroute: { type: "api", key: "test-key" } }), + fetcher: async () => [{ id: "model-a", object: "model" }], + }); + assert.equal(result.ok, true); + }); + + assert.deepEqual(lines, []); + } finally { + setLogLevel(previousLevel); + } +}); + +test("forceSyncOmniRouteModels preserves successful lifecycle output at info level", async () => { + const previousLevel = getLogLevel(); + const cache: OmniRouteFetchCache = new Map(); + const resolved = resolveOmniRoutePluginOptions({ + providerId: "omniroute", + baseURL: "https://omniroute.example/v1", + features: { + autoCombos: false, + combos: false, + compressionMetadata: false, + diskCache: false, + enrichment: false, + logLevel: "info", + usableOnly: false, + }, + }); + + try { + setLogLevel("info"); + const lines = await captureConsole(async () => { + const result = await forceSyncOmniRouteModels({ + resolved, + cache, + readAuthJson: async () => ({ omniroute: { type: "api", key: "test-key" } }), + fetcher: async () => [{ id: "model-a", object: "model" }], + }); + assert.equal(result.ok, true); + }); + + assert.equal(lines.filter((line) => line.includes("force sync ok")).length, 1); + } finally { + setLogLevel(previousLevel); + } +}); + test("forceSyncOmniRouteModels: missing auth returns error", async () => { const cache: OmniRouteFetchCache = new Map(); const resolved = resolveOmniRoutePluginOptions({ diff --git a/@omniroute/opencode-plugin/tests/log-level.test.ts b/@omniroute/opencode-plugin/tests/log-level.test.ts new file mode 100644 index 0000000000..7e73cb4eb8 --- /dev/null +++ b/@omniroute/opencode-plugin/tests/log-level.test.ts @@ -0,0 +1,218 @@ +import assert from "node:assert/strict"; +import { mkdtemp, rm } from "node:fs/promises"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; +import test from "node:test"; +import type { Config } from "@opencode-ai/plugin"; + +import { createOmniRouteConfigHook, OmniRoutePlugin } from "../src/index.js"; +import { getLogLevel, logger, setLogLevel, type LogLevel } from "../src/logger.js"; + +type ConsoleMethod = "error" | "info" | "log" | "warn"; +type ConsoleEntries = Record; + +const fakeInput = {} as Parameters[0]; +const consoleMethods: ConsoleMethod[] = ["error", "info", "log", "warn"]; + +async function captureConsole(run: () => Promise): Promise { + const entries: ConsoleEntries = { error: [], info: [], log: [], warn: [] }; + const originals = Object.fromEntries( + consoleMethods.map((method) => [method, console[method]]) + ) as Record; + + for (const method of consoleMethods) { + console[method] = (...args: unknown[]) => { + entries[method].push(args); + }; + } + + try { + await run(); + } finally { + for (const method of consoleMethods) console[method] = originals[method]; + } + + return entries; +} + +function rendered(entries: ConsoleEntries): string[] { + return consoleMethods.flatMap((method) => + entries[method].map((args) => args.map((arg) => String(arg)).join(" ")) + ); +} + +async function capturePluginLifecycle(args: { + level: LogLevel; + autoSyncIntervalMs: number; + invokeConfig?: boolean; +}): Promise { + const previousDataDir = process.env.OPENCODE_DATA_DIR; + const previousLevel = getLogLevel(); + const dataDir = await mkdtemp(join(tmpdir(), "omniroute-log-level-")); + process.env.OPENCODE_DATA_DIR = dataDir; + + try { + const entries = await captureConsole(async () => { + const hooks = await OmniRoutePlugin(fakeInput, { + autoSyncIntervalMs: args.autoSyncIntervalMs, + features: { logLevel: args.level }, + }); + if (args.invokeConfig) { + assert.equal(typeof hooks.config, "function"); + await hooks.config!({} as Config); + } + }); + return rendered(entries); + } finally { + setLogLevel(previousLevel); + if (previousDataDir === undefined) delete process.env.OPENCODE_DATA_DIR; + else process.env.OPENCODE_DATA_DIR = previousDataDir; + await rm(dataDir, { recursive: true, force: true }); + } +} + +test("logLevel error suppresses the initialization banner", async () => { + const lines = await capturePluginLifecycle({ level: "error", autoSyncIntervalMs: 0 }); + + assert.equal(lines.filter((line) => line.includes("initialized")).length, 0); +}); + +test("logLevel error suppresses the auto-sync enabled lifecycle message", async () => { + const lines = await capturePluginLifecycle({ level: "error", autoSyncIntervalMs: 60_000 }); + + assert.equal(lines.filter((line) => line.includes("auto-sync enabled")).length, 0); +}); + +test("logLevel error suppresses factory config-shim diagnostics", async () => { + const lines = await capturePluginLifecycle({ + level: "error", + autoSyncIntervalMs: 0, + invokeConfig: true, + }); + + assert.equal(lines.filter((line) => line.includes("config shim skipped")).length, 0); +}); + +test("logLevel debug preserves startup and config-shim diagnostics", async () => { + const lines = await capturePluginLifecycle({ + level: "debug", + autoSyncIntervalMs: 60_000, + invokeConfig: true, + }); + + assert.ok( + lines.some((line) => line.includes("initialized")), + "initialization banner emitted" + ); + assert.ok( + lines.some((line) => line.includes("auto-sync enabled")), + "auto-sync message emitted" + ); + assert.ok( + lines.some((line) => line.includes("config shim skipped")), + "config breadcrumb emitted" + ); +}); + +test("debug instance retains config diagnostics after an error instance is created", async () => { + const lines = rendered( + await captureConsole(async () => { + const debugHooks = await OmniRoutePlugin(fakeInput, { + autoSyncIntervalMs: 0, + features: { logLevel: "debug" }, + }); + await OmniRoutePlugin(fakeInput, { + autoSyncIntervalMs: 0, + features: { logLevel: "error" }, + }); + await debugHooks.config!({} as Config); + }) + ); + + assert.equal(lines.filter((line) => line.includes("config shim skipped")).length, 1); +}); + +test("error instance keeps config diagnostics suppressed after a debug instance is created", async () => { + const lines = rendered( + await captureConsole(async () => { + const errorHooks = await OmniRoutePlugin(fakeInput, { + autoSyncIntervalMs: 0, + features: { logLevel: "error" }, + }); + await OmniRoutePlugin(fakeInput, { + autoSyncIntervalMs: 0, + features: { logLevel: "debug" }, + }); + await errorHooks.config!({} as Config); + }) + ); + + assert.equal(lines.filter((line) => line.includes("config shim skipped")).length, 0); +}); + +test("error-level config fetch failures remain visible as concise injected-logger messages", async () => { + const entries: unknown[][] = []; + const hook = createOmniRouteConfigHook( + { + baseURL: "https://omniroute.example/v1", + features: { + autoCombos: false, + diskCache: false, + enrichment: false, + logLevel: "error", + }, + }, + { + readAuthJson: async () => ({ + "opencode-omniroute": { type: "api", key: "test-key" }, + }), + fetcher: async () => { + throw new Error("models unavailable"); + }, + combosFetcher: async () => { + throw new Error("combos unavailable"); + }, + logger: { + warn: (...args: unknown[]) => { + entries.push(args); + }, + }, + } + ); + + await hook({} as Config); + + assert.equal(entries.length, 2, "both genuine fetch failures remain visible"); + assert.deepEqual( + entries.map((args) => args.length), + [1, 1], + "each failure is emitted as one concise argument" + ); + const lines = entries.map(([message]) => String(message)); + assert.ok( + lines.some((line) => line.includes("/v1/models") && line.includes("models unavailable")) + ); + assert.ok( + lines.some((line) => line.includes("/api/combos") && line.includes("combos unavailable")) + ); + assert.equal( + entries.flat().some((arg) => arg instanceof Error), + false, + "no raw Error object emitted" + ); +}); + +test("logger error output remains visible at error level", async () => { + const previousLevel = getLogLevel(); + try { + setLogLevel("error"); + const lines = rendered( + await captureConsole(async () => { + logger.error("genuine startup failure"); + }) + ); + assert.ok(lines.some((line) => line.includes("genuine startup failure"))); + } finally { + setLogLevel(previousLevel); + } +});