fix(db): dedupe lazy-decrypt-view failure logging across sync cycles (#11500)

changelog.d/fixes/11500-decrypt-log-dedup.md

@@ -0,0 +1 @@
+- **fix(db):** dedupe the raw `[Encryption] Decryption failed...` log line emitted by the lazy-decrypt views (`createLazyRowProxy`/`createLazyConnectionView`), which power `getProviderConnections()` and were re-triggering that line on every CredentialHealth/model-sync cycle for the same corrupt or stale-key credential — a fresh Proxy over a fresh row on every cycle meant the per-proxy memoization never suppressed it, unlike the dedup `decryptConnectionFields()` already had since [#9927](https://github.com/diegosouzapw/OmniRoute/issues/9927). Now shares that dedupe tracking so the line logs at most once per credential ([#11500](https://github.com/diegosouzapw/OmniRoute/issues/11500)).

src/lib/db/encryption.ts

@@ -288,6 +288,36 @@ export function decrypt(
   }
 }
 
+/**
+ * #11500 — decrypt() wrapper for callers outside decryptConnectionFields()
+ * (the lazy-decrypt views in providers/lazyConnectionView.ts, which call
+ * decrypt() directly on every fresh getProviderConnections() cycle). A
+ * fresh Proxy wraps a fresh row object each cycle, so per-proxy memoization
+ * never survives across cycles — without this wrapper the raw
+ * "[Encryption] Decryption failed..." line re-fires every single cycle for
+ * the same corrupt/stale-key credential. Shares the loggedDecryptFailures
+ * Set with decryptConnectionFields() so a credential already flagged via one
+ * path does not re-log via the other, and logs the SAME raw message
+ * decrypt() would emit (unlike decryptConnectionFields()'s enriched
+ * message) — just deduped to once per (provider + connection + field +
+ * ciphertext) instead of once per cycle.
+ */
+export function decryptQuiet(
+  ciphertext: string | null | undefined,
+  meta: { connectionId: string; provider: string; field: string }
+): string | null | undefined {
+  if (!looksEncrypted(ciphertext)) {
+    return decrypt(ciphertext);
+  }
+  const signature = `${meta.provider}::${meta.connectionId}::${meta.field}:${ciphertext}`;
+  const alreadyLogged = loggedDecryptFailures.has(signature);
+  const result = decrypt(ciphertext, { quiet: alreadyLogged });
+  if (result === null && !alreadyLogged) {
+    loggedDecryptFailures.add(signature);
+  }
+  return result;
+}
+
 /**
  * Encrypt sensitive fields in a connection object (mutates in-place).
  * After decryption that required legacy key, re-encrypt with static key

src/lib/db/providers/lazyConnectionView.ts

@@ -9,7 +9,7 @@
  * admin, and catalog callers during Phase 2/3 of the lazy-decrypt rollout.
  */
 
-import { decrypt } from "../encryption";
+import { decryptQuiet } from "../encryption";
 
 type JsonRecord = Record<string, unknown>;
 
@@ -119,10 +119,18 @@ export function createLazyConnectionView(row: Record<string, unknown>): Provider
 
   const ensureDecrypted = () => {
     if (!decrypted) {
+      const connectionId = base.id;
+      const provider = base.provider;
       decrypted = {
-        apiKey: toStringOrNull(decrypt(base.apiKey)),
-        accessToken: toStringOrNull(decrypt(base.accessToken)),
-        refreshToken: toStringOrNull(decrypt(base.refreshToken)),
+        apiKey: toStringOrNull(
+          decryptQuiet(base.apiKey, { connectionId, provider, field: "apiKey" })
+        ),
+        accessToken: toStringOrNull(
+          decryptQuiet(base.accessToken, { connectionId, provider, field: "accessToken" })
+        ),
+        refreshToken: toStringOrNull(
+          decryptQuiet(base.refreshToken, { connectionId, provider, field: "refreshToken" })
+        ),
       };
     }
     return decrypted;
@@ -154,11 +162,13 @@ export function createLazyRowProxy(row: Record<string, unknown>): Record<string,
 
   const ensureDecrypted = () => {
     if (!decrypted) {
+      const connectionId = typeof row.id === "string" ? row.id : "";
+      const provider = typeof row.provider === "string" ? row.provider : "unknown";
       decrypted = {
-        apiKey: lazyDecrypt(row.apiKey),
-        accessToken: lazyDecrypt(row.accessToken),
-        refreshToken: lazyDecrypt(row.refreshToken),
-        idToken: lazyDecrypt(row.idToken),
+        apiKey: lazyDecrypt(row.apiKey, { connectionId, provider, field: "apiKey" }),
+        accessToken: lazyDecrypt(row.accessToken, { connectionId, provider, field: "accessToken" }),
+        refreshToken: lazyDecrypt(row.refreshToken, { connectionId, provider, field: "refreshToken" }),
+        idToken: lazyDecrypt(row.idToken, { connectionId, provider, field: "idToken" }),
       };
     }
     return decrypted;
@@ -189,7 +199,10 @@ export function createLazyRowProxy(row: Record<string, unknown>): Record<string,
   });
 }
 
-function lazyDecrypt(value: unknown): string | null | undefined {
+function lazyDecrypt(
+  value: unknown,
+  meta: { connectionId: string; provider: string; field: string }
+): string | null | undefined {
   if (typeof value !== "string") return undefined;
-  return decrypt(value);
+  return decryptQuiet(value, meta);
 }

tests/unit/lazy-connection-view-decrypt-dedupe.test.ts

@@ -0,0 +1,140 @@
+import test from "node:test";
+import assert from "node:assert/strict";
+import { createCipheriv, randomBytes, scryptSync } from "node:crypto";
+import path from "node:path";
+import { pathToFileURL } from "node:url";
+
+// #11500 — the #9927 fix deduped raw decrypt-failure logging only inside
+// decryptConnectionFields(). The lazy-decrypt rollout (createLazyRowProxy /
+// createLazyConnectionView in src/lib/db/providers/lazyConnectionView.ts,
+// used by getProviderConnections() on every CredentialHealth/model-sync
+// cycle) called decrypt() directly with no quiet option and no dedup
+// tracking, so the raw "[Encryption] Decryption failed..." line re-fired on
+// every cycle for the same corrupt/stale-key credential.
+
+const ORIGINAL_STORAGE_KEY = process.env.STORAGE_ENCRYPTION_KEY;
+
+async function importFresh(modulePath: string) {
+  const url = pathToFileURL(path.resolve(modulePath)).href;
+  return import(`${url}?test=${Date.now()}-${Math.random().toString(16).slice(2)}`);
+}
+
+function encryptWithStaticSalt(secret: string, salt: string, plaintext: string): string {
+  const key = scryptSync(secret, salt, 32);
+  const iv = randomBytes(16);
+  const cipher = createCipheriv("aes-256-gcm", key, iv);
+  let encrypted = cipher.update(plaintext, "utf8", "hex");
+  encrypted += cipher.final("hex");
+  const authTag = cipher.getAuthTag().toString("hex");
+  return `enc:v1:${iv.toString("hex")}:${encrypted}:${authTag}`;
+}
+
+test.after(() => {
+  if (ORIGINAL_STORAGE_KEY === undefined) {
+    delete process.env.STORAGE_ENCRYPTION_KEY;
+  } else {
+    process.env.STORAGE_ENCRYPTION_KEY = ORIGINAL_STORAGE_KEY;
+  }
+});
+
+function captureConsoleError(fn: () => void): string[] {
+  const original = console.error;
+  const logs: string[] = [];
+  console.error = (...args: unknown[]) => {
+    logs.push(args.map(String).join(" "));
+  };
+  try {
+    fn();
+  } finally {
+    console.error = original;
+  }
+  return logs;
+}
+
+test("#11500 — createLazyRowProxy dedupes decrypt-failure logging across sync cycles", async () => {
+  process.env.STORAGE_ENCRYPTION_KEY = "probe-11500-current-key";
+
+  const { createLazyRowProxy } = await importFresh("src/lib/db/providers/lazyConnectionView.ts");
+
+  // Credential encrypted with a DIFFERENT key than the one currently
+  // configured (stale STORAGE_ENCRYPTION_KEY / corrupted row) — produces
+  // exactly "Auth tag validation likely failed."
+  const staleCiphertext = encryptWithStaticSalt(
+    "some-other-key-that-was-rotated-away",
+    "omniroute-field-encryption-v1",
+    "sk-super-secret-api-key"
+  );
+
+  const rawRow = {
+    id: "conn-zai-1",
+    provider: "zai",
+    apiKey: staleCiphertext,
+    accessToken: null,
+    refreshToken: null,
+    idToken: null,
+  };
+
+  const capturedLines = captureConsoleError(() => {
+    // Simulate 3 separate CredentialHealth / model-sync cycles, each of
+    // which calls getProviderConnections() fresh and gets a brand-new
+    // createLazyRowProxy() over a brand-new row object for the SAME
+    // underlying corrupt DB row.
+    for (let cycle = 0; cycle < 3; cycle++) {
+      const view = createLazyRowProxy({ ...rawRow });
+      void view.apiKey;
+    }
+  });
+
+  const rawDecryptFailureLines = capturedLines.filter((line) =>
+    line.includes("[Encryption] Decryption failed. Ciphertext prefix:")
+  );
+
+  assert.equal(
+    rawDecryptFailureLines.length,
+    1,
+    `expected the raw decrypt-failure line to be logged at most once across 3 sync cycles for the ` +
+      `same corrupt credential, but it was logged ${rawDecryptFailureLines.length} times: ` +
+      JSON.stringify(rawDecryptFailureLines, null, 2)
+  );
+});
+
+test("#11500 — createLazyConnectionView dedupes decrypt-failure logging across sync cycles", async () => {
+  process.env.STORAGE_ENCRYPTION_KEY = "probe-11500-current-key-view";
+
+  const { createLazyConnectionView } = await importFresh(
+    "src/lib/db/providers/lazyConnectionView.ts"
+  );
+
+  const staleCiphertext = encryptWithStaticSalt(
+    "some-other-key-that-was-rotated-away-view",
+    "omniroute-field-encryption-v1",
+    "sk-super-secret-api-key-view"
+  );
+
+  const rawRow = {
+    id: "conn-glm-1",
+    provider: "glm",
+    apiKey: staleCiphertext,
+    accessToken: null,
+    refreshToken: null,
+  };
+
+  const capturedLines = captureConsoleError(() => {
+    for (let cycle = 0; cycle < 3; cycle++) {
+      const view = createLazyConnectionView({ ...rawRow });
+      void view.apiKey;
+    }
+  });
+
+  const rawDecryptFailureLines = capturedLines.filter((line) =>
+    line.includes("[Encryption] Decryption failed. Ciphertext prefix:")
+  );
+
+  assert.equal(
+    rawDecryptFailureLines.length,
+    1,
+    `expected the raw decrypt-failure line to be logged at most once across 3 sync cycles for the ` +
+      `same corrupt credential, but it was logged ${rawDecryptFailureLines.length} times: ` +
+      JSON.stringify(rawDecryptFailureLines, null, 2)
+  );
+});