From 3e04b81c1b6cf3aa022ebb021fc3a45f3ac60850 Mon Sep 17 00:00:00 2001 From: can1357 Date: Fri, 12 Jun 2026 04:01:47 +0200 Subject: [PATCH] fix(mnemopi): surfaced silent embedding pipeline failures with structured logs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - Replaced the bare `catch {}` blocks in `runEmbedding()` (`beam/helpers.ts`), `getLocalModel()`, and the local-model path of `embed()` (`embeddings.ts`) with structured `logger.debug` entries carrying the error plus per-site context (item count, model name); failure semantics stay best-effort. - Threaded `MnemopiOptions.debug` through `resolveRuntimeOptions()` in `memory.ts` so `mnemopiDebugEnabled()` escalates these logs to `warn` when `mnemopi.debug` is set. - Passed `mnemopi.debug` from coding-agent settings into provider options (`debug` added to the `MnemopiProviderOptions` pick in `src/mnemopi/config.ts`). - Added `embedding-failure-logging.test.ts` asserting the logged context on a real local-model load failure and the debug→warn escalation; the changelog entry landed with the previous commit (same contiguous run). Fixes #2322: Mnemopi: runEmbedding() and getLocalModel() silently swallow errors — mnemopi.debug produces no diagnostic output --- packages/coding-agent/src/mnemopi/config.ts | 3 +- packages/mnemopi/src/core/beam/helpers.ts | 11 +- packages/mnemopi/src/core/embeddings.ts | 19 ++- packages/mnemopi/src/core/memory.ts | 7 +- .../test/embedding-failure-logging.test.ts | 109 ++++++++++++++++++ 5 files changed, 140 insertions(+), 9 deletions(-) create mode 100644 packages/mnemopi/test/embedding-failure-logging.test.ts diff --git a/packages/coding-agent/src/mnemopi/config.ts b/packages/coding-agent/src/mnemopi/config.ts index 22ed99753..27253e41a 100644 --- a/packages/coding-agent/src/mnemopi/config.ts +++ b/packages/coding-agent/src/mnemopi/config.ts @@ -10,7 +10,7 @@ export type MnemopiScoping = "global" | "per-project" | "per-project-tagged"; export type MnemopiProviderOptions = Pick< MnemopiOptions, - "noEmbeddings" | "embeddingModel" | "embeddingApiUrl" | "embeddingApiKey" | "llm" + "noEmbeddings" | "embeddingModel" | "embeddingApiUrl" | "embeddingApiKey" | "llm" | "debug" >; export interface MnemopiBackendConfig { @@ -64,6 +64,7 @@ export function loadMnemopiConfig(settings: Settings, agentDir: string): Mnemopi debug: settings.get("mnemopi.debug"), providerOptions: { noEmbeddings: settings.get("mnemopi.noEmbeddings"), + debug: settings.get("mnemopi.debug"), embeddingModel: settings.get("mnemopi.embeddingModel"), embeddingApiUrl: settings.get("mnemopi.embeddingApiUrl"), embeddingApiKey: settings.get("mnemopi.embeddingApiKey"), diff --git a/packages/mnemopi/src/core/beam/helpers.ts b/packages/mnemopi/src/core/beam/helpers.ts index 6e89c2244..0e2047645 100644 --- a/packages/mnemopi/src/core/beam/helpers.ts +++ b/packages/mnemopi/src/core/beam/helpers.ts @@ -1,7 +1,8 @@ import type { Database } from "bun:sqlite"; +import { logger } from "@oh-my-pi/pi-utils"; import { generateId as generateTimedId, sha256Hex16, stableMemoryId } from "../../util/ids"; import { currentEmbeddingModel, embed } from "../embeddings"; -import { getMnemopiRuntimeOptions, withMnemopiRuntimeOptions } from "../runtime-options"; +import { getMnemopiRuntimeOptions, mnemopiDebugEnabled, withMnemopiRuntimeOptions } from "../runtime-options"; import { buildExactVectorIndex, searchExactVectorIndex } from "../vector-index"; import type { BeamMemoryState, JsonValue, Metadata } from "./types"; @@ -932,12 +933,16 @@ async function runEmbedding(beam: BeamMemoryState, items: readonly EmbedItem[]): } }); insertMany(items); - } catch { + } catch (error) { // Background embedding generation is best-effort: a failing provider, a closed DB // during shutdown, or a transient API error must never disrupt the synchronous // remember()/consolidate() that scheduled it. Production recall silently degrades // to FTS-only for the affected rows, which is the same shape as a misconfigured - // provider. + // provider. Log so the failure is diagnosable (#2322). + logger[mnemopiDebugEnabled() ? "warn" : "debug"]("mnemopi: background embedding failed", { + itemCount: items.length, + error: String(error), + }); } } diff --git a/packages/mnemopi/src/core/embeddings.ts b/packages/mnemopi/src/core/embeddings.ts index 673fa701b..e1aaee5c9 100644 --- a/packages/mnemopi/src/core/embeddings.ts +++ b/packages/mnemopi/src/core/embeddings.ts @@ -12,7 +12,12 @@ import { import type { EmbeddingModel } from "fastembed"; import { LRUCache } from "lru-cache/raw"; import packageJson from "../../package.json" with { type: "json" }; -import { type EmbeddingOutput, getMnemopiRuntimeOptions, resolveEmbeddingProvider } from "./runtime-options"; +import { + type EmbeddingOutput, + getMnemopiRuntimeOptions, + mnemopiDebugEnabled, + resolveEmbeddingProvider, +} from "./runtime-options"; export type { EmbeddingOutput } from "./runtime-options"; export { cosineSimilarity } from "./vector-math"; @@ -245,7 +250,11 @@ async function getLocalModel(): Promise { localModelPromise = loading; try { return await loading; - } catch { + } catch (error) { + logger[mnemopiDebugEnabled() ? "warn" : "debug"]("mnemopi: local embedding model failed to load", { + model: modelName, + error: String(error), + }); if (localModelPromise === loading) localModelPromise = null; return null; } @@ -426,7 +435,11 @@ export async function embed(texts: readonly string[]): Promise; readonly llm?: false | MnemopiLlmRuntimeOptions | Model | MnemopiLlmCompletion; + /** Escalate best-effort failure logs (embedding pipeline) from debug to warn. */ + readonly debug?: boolean; } export interface RememberInput extends MemoryInput { @@ -219,10 +221,11 @@ function resolveRuntimeOptions(options: MnemopiOptions): ResolvedMnemopiRuntimeO } } - if (embeddings === undefined && llm === undefined) { + const debug = options.debug ? true : undefined; + if (embeddings === undefined && llm === undefined && debug === undefined) { return undefined; } - return { embeddings, llm }; + return { embeddings, llm, debug }; } let defaultInstance: Mnemopi | null = null; diff --git a/packages/mnemopi/test/embedding-failure-logging.test.ts b/packages/mnemopi/test/embedding-failure-logging.test.ts new file mode 100644 index 000000000..4303f29df --- /dev/null +++ b/packages/mnemopi/test/embedding-failure-logging.test.ts @@ -0,0 +1,109 @@ +import { afterEach, describe, expect, it, spyOn } from "bun:test"; +import { logger } from "@oh-my-pi/pi-utils"; +import "./setup"; +import { + embed, + resetEmbeddingProviderForTests, + setLocalModelInitializerForTests, +} from "@oh-my-pi/pi-mnemopi/core/embeddings"; +import { withMnemopiRuntimeOptions } from "@oh-my-pi/pi-mnemopi/core/runtime-options"; + +const ENV_KEYS = [ + "NODE_ENV", + "BUN_ENV", + "MNEMOPI_NO_EMBEDDINGS", + "MNEMOPI_EMBEDDING_MODEL", + "MNEMOPI_EMBEDDING_API_URL", + "MNEMOPI_EMBEDDING_API_KEY", + "OPENROUTER_BASE_URL", + "OPENROUTER_API_KEY", + "OPENAI_API_KEY", +] as const; + +type EnvKey = (typeof ENV_KEYS)[number]; + +/** Force the local-fastembed path: not a test runtime, local model, no API config. */ +async function withLocalModelEnv(fn: () => Promise): Promise { + const snapshot: Partial> = {}; + for (const key of ENV_KEYS) { + const value = process.env[key]; + if (value !== undefined) snapshot[key] = value; + delete process.env[key]; + } + process.env.MNEMOPI_EMBEDDING_MODEL = "BAAI/bge-small-en-v1.5"; + resetEmbeddingProviderForTests(); + try { + return await fn(); + } finally { + for (const key of ENV_KEYS) { + const value = snapshot[key]; + if (value === undefined) { + delete process.env[key]; + } else { + process.env[key] = value; + } + } + resetEmbeddingProviderForTests(); + } +} + +afterEach(() => { + resetEmbeddingProviderForTests(); +}); + +describe("embedding failure logging (#2322)", () => { + it("logs local model load failures at debug level with model context", async () => { + const debugSpy = spyOn(logger, "debug").mockImplementation(() => {}); + const warnSpy = spyOn(logger, "warn").mockImplementation(() => {}); + try { + await withLocalModelEnv(async () => { + setLocalModelInitializerForTests(async () => { + throw new Error("onnx init blew up"); + }); + + expect(await embed(["hello"])).toBeNull(); + + expect(debugSpy).toHaveBeenCalledWith( + "mnemopi: local embedding model failed to load", + expect.objectContaining({ + model: expect.any(String), + error: expect.stringContaining("onnx init blew up"), + }), + ); + expect(warnSpy).not.toHaveBeenCalledWith( + "mnemopi: local embedding model failed to load", + expect.anything(), + ); + }); + } finally { + debugSpy.mockRestore(); + warnSpy.mockRestore(); + } + }); + + it("escalates the same failure to warn when runtime debug is enabled", async () => { + const debugSpy = spyOn(logger, "debug").mockImplementation(() => {}); + const warnSpy = spyOn(logger, "warn").mockImplementation(() => {}); + try { + await withLocalModelEnv(async () => { + setLocalModelInitializerForTests(async () => { + throw new Error("onnx init blew up again"); + }); + + expect(await withMnemopiRuntimeOptions({ debug: true }, () => embed(["hello"]))).toBeNull(); + + expect(warnSpy).toHaveBeenCalledWith( + "mnemopi: local embedding model failed to load", + expect.objectContaining({ error: expect.stringContaining("onnx init blew up again") }), + ); + expect(debugSpy).not.toHaveBeenCalledWith( + "mnemopi: local embedding model failed to load", + expect.anything(), + ); + }); + } finally { + debugSpy.mockRestore(); + warnSpy.mockRestore(); + } + }); +});