diff --git a/src/review/rag-index.ts b/src/review/rag-index.ts index a1bfb98f82..16c1a8221c 100644 --- a/src/review/rag-index.ts +++ b/src/review/rag-index.ts @@ -27,6 +27,7 @@ import { createInstallationToken } from "../github/app"; import { githubRateLimitAdmissionKeyForInstallation, timeoutFetch, type GitHubRateLimitAdmissionKey } from "../github/client"; +import { incr } from "../selfhost/metrics"; import { isConfigFile, isDependencyManifestFile } from "../signals/path-matchers"; import { repoParts } from "../utils/json"; import { createReviewAdapters } from "./adapters"; @@ -315,7 +316,11 @@ export async function indexRepo( ); return { indexed: upserted, files: filesIndexed, capped }; } catch (error) { - console.log(JSON.stringify({ ev: "rag_index_repo_error", repo: repo.fullName, message: String(error).slice(0, 200) })); + // ERROR level + counter (#3894): previously a no-`level` console.log invisible to Sentry, and this + // failure class had no metric at all -- gittensory_qdrant_errors_total only fires inside the Qdrant + // adapter itself, so an upstream failure here (GitHub tree/contents fetch, chunking) never counted. + console.error(JSON.stringify({ level: "error", event: "rag_index_repo_error", ev: "rag_index_repo_error", repo: repo.fullName, message: String(error).slice(0, 200) })); + incr("gittensory_rag_pipeline_errors_total", { op: "index_repo" }); return empty; } } @@ -378,7 +383,9 @@ export async function reindexChangedPaths( ); return { indexed: upserted, files: filesIndexed, capped }; } catch (error) { - console.log(JSON.stringify({ ev: "rag_reindex_paths_error", repo: repo.fullName, message: String(error).slice(0, 200) })); + // ERROR level + counter (#3894): see indexRepo's catch above -- same invisible-to-Sentry, no-metric fix. + console.error(JSON.stringify({ level: "error", event: "rag_reindex_paths_error", ev: "rag_reindex_paths_error", repo: repo.fullName, message: String(error).slice(0, 200) })); + incr("gittensory_rag_pipeline_errors_total", { op: "reindex_paths" }); return empty; } } diff --git a/src/review/rag.ts b/src/review/rag.ts index e65653a6d6..552ed41003 100644 --- a/src/review/rag.ts +++ b/src/review/rag.ts @@ -300,7 +300,11 @@ export async function embedTexts(inference: InferenceAdapter | undefined, texts: } return out; } catch (error) { - console.log(JSON.stringify({ ev: "rag_embed_error", message: String(error).slice(0, 200) })); + // ERROR level (#3894): an embedding-provider failure previously logged at console.log with no `level`, + // invisible to the central Sentry forwarder -- mirrors the already-fixed retrieveContextWithMetrics + // catch below. Shares its `review_context_fetch_failed`/contextType:"rag" umbrella so both are + // searchable together, plus the specific `ev` tag for log continuity. + console.error(JSON.stringify({ level: "error", event: "review_context_fetch_failed", contextType: "rag", ev: "rag_embed_error", message: String(error).slice(0, 200) })); return null; } } @@ -332,7 +336,8 @@ export async function upsertChunks(infra: RagInfra, project: string, repo: strin await db.batch(stmts); return chunks.length; } catch (error) { - console.log(JSON.stringify({ ev: "rag_upsert_error", message: String(error).slice(0, 200) })); + // ERROR level (#3894): see embedTexts's catch above -- same invisible-to-Sentry fix, same umbrella. + console.error(JSON.stringify({ level: "error", event: "review_context_fetch_failed", contextType: "rag", ev: "rag_upsert_error", message: String(error).slice(0, 200) })); return 0; } } @@ -360,7 +365,8 @@ export async function deleteChunksForPaths(infra: RagInfra, project: string, rep await db.prepare(`DELETE FROM repo_chunks WHERE id IN (${batch.map(() => "?").join(",")})`).bind(...batch).run(); } } catch (error) { - console.log(JSON.stringify({ ev: "rag_delete_error", message: String(error).slice(0, 200) })); + // ERROR level (#3894): see embedTexts's catch above -- same invisible-to-Sentry fix, same umbrella. + console.error(JSON.stringify({ level: "error", event: "review_context_fetch_failed", contextType: "rag", ev: "rag_delete_error", message: String(error).slice(0, 200) })); } } @@ -565,7 +571,8 @@ export async function readChunkTexts(storage: StorageAdapter, ids: string[]): Pr .all<{ id: string; text: string }>(); for (const r of rows.results ?? []) map.set(r.id, r.text); } catch (error) { - console.log(JSON.stringify({ ev: "rag_chunk_read_error", message: String(error).slice(0, 200) })); + // ERROR level (#3894): see embedTexts's catch above -- same invisible-to-Sentry fix, same umbrella. + console.error(JSON.stringify({ level: "error", event: "review_context_fetch_failed", contextType: "rag", ev: "rag_chunk_read_error", message: String(error).slice(0, 200) })); } return map; } diff --git a/src/selfhost/metrics.ts b/src/selfhost/metrics.ts index 25b2a21a74..c6b9c38512 100644 --- a/src/selfhost/metrics.ts +++ b/src/selfhost/metrics.ts @@ -97,6 +97,7 @@ const DEFAULT_METRIC_META: readonly (readonly [string, MetricMeta])[] = [ ["gittensory_qdrant_queries_total", { help: "Qdrant vector query attempts.", type: "counter" }], ["gittensory_qdrant_upserts_total", { help: "Qdrant vector upserted item count.", type: "counter" }], ["gittensory_qdrant_errors_total", { help: "Qdrant vector operation errors.", type: "counter" }], + ["gittensory_rag_pipeline_errors_total", { help: "RAG index-population pipeline errors (repo/path indexing), by op.", type: "counter" }], ["gittensory_orb_events_exported_total", { help: "Orb events exported from the self-host runtime.", type: "counter" }], ["gittensory_orb_export_errors_total", { help: "Orb event export errors.", type: "counter" }], ["gittensory_orb_relay_drains_total", { help: "Orb relay drain outcomes.", type: "counter" }], diff --git a/test/unit/rag-index.test.ts b/test/unit/rag-index.test.ts index 0bc8eb11ab..3e519778dd 100644 --- a/test/unit/rag-index.test.ts +++ b/test/unit/rag-index.test.ts @@ -6,6 +6,7 @@ import { upsertRepositoryFromGitHub } from "../../src/db/repositories"; import { upsertRepoFocusManifest } from "../../src/signals/focus-manifest-loader"; import * as githubApp from "../../src/github/app"; import { githubRateLimitAdmissionKeyForInstallation, latestGitHubRestRateLimitObservation } from "../../src/github/client"; +import { renderMetrics, resetMetrics } from "../../src/selfhost/metrics"; import { createTestEnv, TestD1Database } from "../helpers/d1"; // A valid bge-m3-width (1024-d) embedding vector — embedTexts rejects any other width. @@ -279,6 +280,26 @@ describe("indexRepo: full repo index (tree → chunk → embed → upsert)", () allReturn = {}; await expect(indexRepo(env, PROJECT, REPO)).resolves.toEqual({ indexed: 0, files: 0, capped: false }); }); + + it("a Cloudflare binding access that throws degrades to nothing indexed (indexRepo's own outer catch) + surfaces it at ERROR for Sentry with a counter (#3894)", async () => { + const { env } = indexEnv(); + resetMetrics(); + const errSpy = vi.spyOn(console, "error").mockImplementation(() => {}); + // A binding CAN throw on access in real Workers runtime edge cases (revoked/misconfigured binding). + // Every I/O step inside indexRepo already self-catches (fetchRepoTree, fetchFileText, upsertChunks, + // resolveReadToken, ...), so this is the one realistic way to reach the function's own outer catch. + const throwingEnv = new Proxy(env, { + get(target, prop, receiver) { + if (prop === "VECTORIZE") throw new Error("binding access boom"); + return Reflect.get(target, prop, receiver); + }, + }); + await expect(indexRepo(throwingEnv as typeof env, PROJECT, REPO)).resolves.toEqual({ indexed: 0, files: 0, capped: false }); + const parsed = errSpy.mock.calls.map((c) => JSON.parse(c[0] as string)); + expect(parsed.some((p) => p.level === "error" && p.event === "rag_index_repo_error" && p.ev === "rag_index_repo_error")).toBe(true); + expect(await renderMetrics()).toContain('gittensory_rag_pipeline_errors_total{op="index_repo"}'); + errSpy.mockRestore(); + }); }); describe("indexRepo: MAX_CHUNKS_PER_REPO cap holds", () => { @@ -570,6 +591,25 @@ describe("reindexChangedPaths: delete + re-upsert only the changed paths", () => expect(vec.deleted.length).toBe(0); expect(vec.upserted.length).toBe(0); }); + + it("a Cloudflare binding access that throws degrades to nothing indexed (reindexChangedPaths' own outer catch) + surfaces it at ERROR for Sentry with a counter (#3894)", async () => { + const { env } = indexEnv(); + resetMetrics(); + const errSpy = vi.spyOn(console, "error").mockImplementation(() => {}); + // Same rationale as indexRepo's equivalent test above: every I/O step here already self-catches, so a + // binding access throw is the one realistic way to reach this function's own outer catch. + const throwingEnv = new Proxy(env, { + get(target, prop, receiver) { + if (prop === "VECTORIZE") throw new Error("binding access boom"); + return Reflect.get(target, prop, receiver); + }, + }); + await expect(reindexChangedPaths(throwingEnv as typeof env, PROJECT, REPO, ["src/a.ts"])).resolves.toEqual({ indexed: 0, files: 0, capped: false }); + const parsed = errSpy.mock.calls.map((c) => JSON.parse(c[0] as string)); + expect(parsed.some((p) => p.level === "error" && p.event === "rag_reindex_paths_error" && p.ev === "rag_reindex_paths_error")).toBe(true); + expect(await renderMetrics()).toContain('gittensory_rag_pipeline_errors_total{op="reindex_paths"}'); + errSpy.mockRestore(); + }); }); describe("flag-off / missing-infra is a no-op (no GitHub fetch, no adapter use)", () => { diff --git a/test/unit/rag.test.ts b/test/unit/rag.test.ts index 8dee900309..3114cef0d3 100644 --- a/test/unit/rag.test.ts +++ b/test/unit/rag.test.ts @@ -1,4 +1,4 @@ -import { describe, expect, it } from "vitest"; +import { describe, expect, it, vi } from "vitest"; import { bm25Rerank, bm25Scores, @@ -469,8 +469,13 @@ describe("rag: upsertChunks (embed + vector upsert + chunk-text store)", () => { }); it("returns 0 (no throw) when the vector upsert fails (#fail-safe)", async () => { + const errSpy = vi.spyOn(console, "error").mockImplementation(() => {}); const vector = { upsert: async () => { throw new Error("vectorize down"); } } as unknown as VectorAdapter; expect(await upsertChunks({ storage: storageStub(), vector, inference: ai1024 }, "p", "o/r", chunks)).toBe(0); + // #3894: previously a no-level console.log, invisible to Sentry. + const parsed = errSpy.mock.calls.map((c) => JSON.parse(c[0] as string)); + expect(parsed.some((p) => p.level === "error" && p.event === "review_context_fetch_failed" && p.contextType === "rag" && p.ev === "rag_upsert_error")).toBe(true); + errSpy.mockRestore(); }); }); @@ -510,8 +515,13 @@ describe("rag: deleteChunksForPaths (incremental re-index of changed files)", () }); it("swallows a storage failure (fail-safe; never throws)", async () => { + const errSpy = vi.spyOn(console, "error").mockImplementation(() => {}); const storage = { prepare: () => { throw new Error("d1 down"); }, batch: async () => undefined } as unknown as StorageAdapter; await expect(deleteChunksForPaths({ storage }, "p", "o/r", ["src/a.ts"])).resolves.toBeUndefined(); + // #3894: previously a no-level console.log, invisible to Sentry. + const parsed = errSpy.mock.calls.map((c) => JSON.parse(c[0] as string)); + expect(parsed.some((p) => p.level === "error" && p.event === "review_context_fetch_failed" && p.contextType === "rag" && p.ev === "rag_delete_error")).toBe(true); + errSpy.mockRestore(); }); it("treats a SELECT result with NO `results` key as zero ids (the `rows.results ?? []` fallback)", async () => { @@ -535,14 +545,24 @@ describe("rag: storage/inference catch paths return their fail-safe defaults", ( }); it("embedTexts returns null when inference throws", async () => { + const errSpy = vi.spyOn(console, "error").mockImplementation(() => {}); const inference: InferenceAdapter = { run: async () => { throw new Error("ai down"); } }; expect(await embedTexts(inference, ["hi"])).toBeNull(); + // #3894: previously a no-level console.log, invisible to Sentry. + const parsed = errSpy.mock.calls.map((c) => JSON.parse(c[0] as string)); + expect(parsed.some((p) => p.level === "error" && p.event === "review_context_fetch_failed" && p.contextType === "rag" && p.ev === "rag_embed_error")).toBe(true); + errSpy.mockRestore(); }); it("readChunkTexts returns an empty Map when the storage read throws", async () => { + const errSpy = vi.spyOn(console, "error").mockImplementation(() => {}); const storage = { prepare: () => { throw new Error("d1 down"); }, batch: async () => undefined } as unknown as StorageAdapter; const map = await readChunkTexts(storage, ["id-1"]); expect(map.size).toBe(0); + // #3894: previously a no-level console.log, invisible to Sentry. + const parsed = errSpy.mock.calls.map((c) => JSON.parse(c[0] as string)); + expect(parsed.some((p) => p.level === "error" && p.event === "review_context_fetch_failed" && p.contextType === "rag" && p.ev === "rag_chunk_read_error")).toBe(true); + errSpy.mockRestore(); }); it("readChunkTexts short-circuits on an empty id list", async () => {