From c903fe58c74836b3cb8b5fd2aa36c18b43888151 Mon Sep 17 00:00:00 2001 From: Claude Date: Tue, 22 Sep 2026 20:36:10 -0700 Subject: [PATCH 1/2] fix: a failed index reload keeps what recall has, says so, and retries (GIT-118) loadScarsFromSupabase returned [] on any error with no flag. flushCache (fired after every create_learning, and every 15 min) reinitialised the index and overwrote hook-scars.json with it, logged "N -> 0", and reported success. A failed init was cached as ensureInitialized's promise, so it was never retried. - loadScarsFromSupabase reports ok/error; on failure it offers the last disk vector cache (stale) instead of [], and never as "the store is empty". - A failed reload keeps the index and the hook cache (an empty index takes the stale disk copy) and returns success: false with the cause. - A failed load retries with backoff (30 s, doubling, 10 min cap); ensureInitialized forgets a failed init; an init after a stale start replaces the stale rows (initialize() is a no-op once initialized). - create_learning awaits a refresh and its display says when the recall index could not be refreshed (index_refreshed: false). The post-write refresh uses the per-row delta (GIT-98), not the disk-bypassing flush. +7 startup tests (6 fail on main), +2 create_learning display tests. Three test files mocked startup.js without refreshIndexAfterWrite; the missing export threw inside create_learning's try and every call reported "NOT refreshed" unseen. Their mocks now provide it. Co-Authored-By: Claude Opus 5.5 --- src/services/startup.ts | 154 ++++++++++++++-- src/tools/create-learning.ts | 27 ++- src/types/index.ts | 2 + .../services/startup-reload-failure.test.ts | 170 ++++++++++++++++++ .../unit/tools/create-learning-errors.test.ts | 25 +++ .../create-learning-field-persistence.test.ts | 1 + tests/unit/tools/variants-dev-only.test.ts | 5 +- 7 files changed, 360 insertions(+), 24 deletions(-) create mode 100644 tests/unit/services/startup-reload-failure.test.ts diff --git a/src/services/startup.ts b/src/services/startup.ts index f9bee20..65f6820 100644 --- a/src/services/startup.ts +++ b/src/services/startup.ts @@ -149,7 +149,14 @@ async function deltaSyncFromCache(storeKey: string, fingerprint: StoreFingerprin export async function loadScarsFromSupabase(options: { bypassDiskCache?: boolean } = {}): Promise<{ scars: ScarWithEmbedding[]; latestUpdatedAt: string | null; - source: "disk" | "network"; + source: "disk" | "network" | "disk-stale"; + /** + * GIT-118: false when the store could not be read. `scars` is then the last + * disk cache (possibly stale) or [] — never to be mistaken for "the store is + * empty", which is ok: true with no rows. + */ + ok: boolean; + error?: string; }> { const startTime = Date.now(); @@ -167,7 +174,7 @@ export async function loadScarsFromSupabase(options: { bypassDiskCache?: boolean `[startup] Vector cache HIT: ${cached.rows.length} learnings from disk in ${Date.now() - startTime}ms ` + `(${cached.bytesOnDisk} bytes on disk, bulk download skipped)` ); - return { scars: cached.rows, latestUpdatedAt: fingerprint.latestUpdatedAt, source: "disk" }; + return { scars: cached.rows, latestUpdatedAt: fingerprint.latestUpdatedAt, source: "disk", ok: true }; } console.error(`[startup] Vector cache MISS: ${cached.reason}`); } @@ -183,7 +190,7 @@ export async function loadScarsFromSupabase(options: { bypassDiskCache?: boolean console.error( `[startup] Vector cache HIT (via leader): ${fromLeader.rows.length} learnings in ${Date.now() - startTime}ms, bulk download skipped` ); - return { scars: fromLeader.rows, latestUpdatedAt: fingerprint.latestUpdatedAt, source: "disk" }; + return { scars: fromLeader.rows, latestUpdatedAt: fingerprint.latestUpdatedAt, source: "disk", ok: true }; } console.error("[startup] Leader did not produce a usable cache — downloading"); } @@ -195,7 +202,7 @@ export async function loadScarsFromSupabase(options: { bypassDiskCache?: boolean if (!options.bypassDiskCache && fingerprint.count >= 0) { const synced = await deltaSyncFromCache(storeKey, fingerprint); if (synced) { - return { scars: synced, latestUpdatedAt: synced[0]?.updated_at || null, source: "network" }; + return { scars: synced, latestUpdatedAt: synced[0]?.updated_at || null, source: "network", ok: true }; } } @@ -221,10 +228,18 @@ export async function loadScarsFromSupabase(options: { bypassDiskCache?: boolean writeVectorCache(storeKey, fingerprint, learnings); } - return { scars: learnings, latestUpdatedAt, source: "network" }; + return { scars: learnings, latestUpdatedAt, source: "network", ok: true }; } catch (error) { - console.error("[startup] Failed to load learnings:", error); - return { scars: [], latestUpdatedAt: null, source: "network" }; + // GIT-118: this returned [] with no flag, and every caller reinitialised + // the index and the hooks' scar cache with it — one failed request emptied + // recall until the next successful load. Say it failed, and offer the last + // disk cache (possibly stale) for a caller that has nothing better. + const message = error instanceof Error ? error.message : String(error); + console.error("[startup] Failed to load learnings:", message); + const stale = readVectorCacheBase(storeKey); + return stale && stale.length > 0 + ? { scars: stale, latestUpdatedAt: stale[0]?.updated_at || null, source: "disk-stale", ok: false, error: message } + : { scars: [], latestUpdatedAt: null, source: "network", ok: false, error: message }; } finally { releaseLock(); } @@ -312,10 +327,33 @@ export async function initializeGitMem(_project?: Project): Promise<{ try { // Load ALL scars from Supabase (cross-project unified cache) - const { scars, latestUpdatedAt } = await loadScarsFromSupabase(); + const loaded = await loadScarsFromSupabase(); + const { scars, latestUpdatedAt } = loaded; + + if (!loaded.ok) { + // GIT-118: the store could not be read. Serve the last disk cache if + // there is one (stale beats empty), leave the hooks' cache alone, report + // failure so ensureInitialized tries again, and retry in the background. + if (scars.length > 0) await initializeLocalSearch(scars, undefined, latestUpdatedAt || undefined); + scheduleReloadRetry(loaded.error ?? "store unreachable"); + return { + success: false, + scar_count: getLocalVectorSearch().getScarCount(), + elapsed_ms: Date.now() - startTime, + search_mode: "local", + error: `could not load learnings from the store (${loaded.error})${scars.length > 0 ? `; serving ${scars.length} from the disk cache, possibly stale` : ""}`, + }; + } - // Initialize unified local vector search - await initializeLocalSearch(scars, undefined, latestUpdatedAt || undefined); + // Initialize unified local vector search. GIT-118: if an earlier failed + // start left the stale disk copy in the index, replace it — initialize() + // is a no-op on an index that is already initialized. + if (getLocalVectorSearch().getScarCount() > 0) { + await reinitializeLocalSearch(scars, undefined, latestUpdatedAt || undefined); + } else { + await initializeLocalSearch(scars, undefined, latestUpdatedAt || undefined); + } + clearReloadRetry(); // Persist scars to disk for hook processes (no embeddings) persistScarsForHooks(scars); @@ -370,6 +408,9 @@ export async function ensureInitialized(_project?: Project): Promise { startupCompleted.set(UNIFIED_KEY, result.success); if (!result.success) { console.warn(`[startup] GitMem not fully initialized: ${result.error}`); + // GIT-118: a failed init was cached as this promise forever, so no later + // call ever tried again. Forget it; the next call (or the retry) loads. + startupPromises.delete(UNIFIED_KEY); } })(); @@ -653,9 +694,29 @@ async function checkThreadHealth(project?: Project): Promise } /** - * Flush and reload the cache + * Flush and reload the cache. A flush is the user saying "I do not trust what + * you have": the disk cache is bypassed (GIT-98) and rewritten. */ export async function flushCache(_project?: Project): Promise { + return reloadIndex({ bypassDiskCache: true }); +} + +/** + * GIT-118: bring the index up to date after a write (create_learning). Uses + * the per-row delta (GIT-98), so a new learning costs its own row rather than + * the whole index — cheap enough for the tool to await and report. + */ +export async function refreshIndexAfterWrite(_project?: Project): Promise { + return reloadIndex({ bypassDiskCache: false }); +} + +/** + * Reload the index from the store — or, if the store cannot be read, keep + * what is there (GIT-118). A failed load used to reinitialise the index and + * overwrite the hooks' scar cache with [] and report success, so one failed + * request emptied recall until the next successful load. + */ +async function reloadIndex(options: { bypassDiskCache: boolean }): Promise { const startTime = Date.now(); const config = getConfig(); @@ -672,15 +733,32 @@ export async function flushCache(_project?: Project): Promise const previousCount = getLocalVectorSearch().getScarCount(); try { - // Load ALL fresh scars (cross-project). A flush is the user saying "I do not - // trust what you have" — bypass the disk cache (GIT-98) and rewrite it. - const { scars, latestUpdatedAt } = await loadScarsFromSupabase({ bypassDiskCache: true }); + const loaded = await loadScarsFromSupabase({ bypassDiskCache: options.bypassDiskCache }); + + if (!loaded.ok) { + // Keep the index and the hooks' cache. Only an EMPTY index takes the + // stale disk copy: it has nothing better to lose. + if (previousCount === 0 && loaded.scars.length > 0) { + await reinitializeLocalSearch(loaded.scars, undefined, loaded.latestUpdatedAt || undefined); + } + scheduleReloadRetry(loaded.error ?? "store unreachable"); + const kept = getLocalVectorSearch().getScarCount(); + console.error(`[cache] Reload failed (${loaded.error}); kept ${kept} scars, hook cache unchanged`); + return { + success: false, + previous_scar_count: previousCount, + new_scar_count: kept, + elapsed_ms: Date.now() - startTime, + error: loaded.error ?? "store unreachable", + }; + } // Reinitialize the unified index - await reinitializeLocalSearch(scars, undefined, latestUpdatedAt || undefined); + await reinitializeLocalSearch(loaded.scars, undefined, loaded.latestUpdatedAt || undefined); // Update disk cache for hook processes too - persistScarsForHooks(scars); + persistScarsForHooks(loaded.scars); + clearReloadRetry(); const newCount = getLocalVectorSearch().getScarCount(); const elapsed = Date.now() - startTime; @@ -697,17 +775,59 @@ export async function flushCache(_project?: Project): Promise const elapsed = Date.now() - startTime; const errorMsg = error instanceof Error ? error.message : String(error); console.error("[cache] Flush failed:", errorMsg); + scheduleReloadRetry(errorMsg); return { success: false, previous_scar_count: previousCount, - new_scar_count: previousCount, + new_scar_count: getLocalVectorSearch().getScarCount(), elapsed_ms: elapsed, error: errorMsg, }; } } +// --------------------------------------------------------------------------- +// GIT-118: retry a failed load with backoff (30 s, doubling, capped at 10 min) +// --------------------------------------------------------------------------- + +const RELOAD_RETRY_BASE_MS = 30_000; +const RELOAD_RETRY_MAX_MS = 10 * 60_000; +let reloadRetryTimer: ReturnType | null = null; +let reloadRetryAttempt = 0; + +function scheduleReloadRetry(reason: string): void { + if (reloadRetryTimer) return; // one pending retry at a time + const delay = Math.min(RELOAD_RETRY_BASE_MS * 2 ** reloadRetryAttempt, RELOAD_RETRY_MAX_MS); + reloadRetryAttempt++; + console.error(`[startup] Index reload failed (${reason}); retry ${reloadRetryAttempt} in ${Math.round(delay / 1000)} s`); + reloadRetryTimer = setTimeout(() => { + reloadRetryTimer = null; + reloadIndex({ bypassDiskCache: false }) + .then((r) => { + if (r.success) startupCompleted.set(UNIFIED_KEY, true); + }) + .catch(() => { /* reloadIndex reschedules itself */ }); + }, delay); + reloadRetryTimer.unref?.(); +} + +function clearReloadRetry(): void { + if (reloadRetryTimer) clearTimeout(reloadRetryTimer); + reloadRetryTimer = null; + reloadRetryAttempt = 0; +} + +/** For tests and health. */ +export function getReloadRetryState(): { pending: boolean; attempt: number } { + return { pending: reloadRetryTimer !== null, attempt: reloadRetryAttempt }; +} + +/** For tests. */ +export function resetReloadRetry(): void { + clearReloadRetry(); +} + /** * Check if cache needs refresh based on TTL or staleness * Returns true if a refresh is recommended diff --git a/src/tools/create-learning.ts b/src/tools/create-learning.ts index db9b929..ac36a4e 100644 --- a/src/tools/create-learning.ts +++ b/src/tools/create-learning.ts @@ -13,7 +13,7 @@ import * as supabase from "../services/supabase-client.js"; import { embed, isEmbeddingAvailable } from "../services/embedding.js"; import { getAgentIdentity } from "../services/agent-detection.js"; import { wrapDisplay, TYPE, SEV } from "../services/display-protocol.js"; -import { flushCache } from "../services/startup.js"; +import { refreshIndexAfterWrite } from "../services/startup.js"; import { writeTriplesForLearning } from "../services/triple-writer.js"; import { generateVariantsForScar } from "../services/variant-generation.js"; import { getEffectTracker } from "../services/effect-tracker.js"; @@ -182,6 +182,9 @@ export async function createLearning( learningData.severity = params.severity || "medium"; } + // GIT-118: set when the recall index could not be refreshed after the write. + let indexNotRefreshed: string | null = null; + try { let embeddingGenerated = false; const breakdown: PerformanceBreakdown = {}; @@ -272,11 +275,17 @@ export async function createLearning( ); } - // Invalidate local cache so next recall picks up the new learning + // Refresh the local index so the next recall sees the new learning. + // GIT-118: awaited and reported. It was fire-and-forget, and a failed + // reload emptied the index while create_learning said nothing. The + // learning itself is saved either way; only recall's view of it waits. const project = (params.project || getProject() || "default") as Project; - flushCache(project).catch((err) => { - console.warn("[create_learning] Cache invalidation failed (non-fatal):", err); - }); + try { + const refreshed = await refreshIndexAfterWrite(project); + if (!refreshed.success) indexNotRefreshed = refreshed.error ?? "reload failed"; + } catch (err) { + indexNotRefreshed = err instanceof Error ? err.message : String(err); + } } else { // Free tier: Store locally without embedding console.error(`[create_learning] Storing locally: ${learningId}`); @@ -319,7 +328,13 @@ export async function createLearning( learning_id: learningId, embedding_generated: embeddingGenerated, performance: perfData, - display: wrapDisplay(`${te} Created ${params.learning_type}: "${params.title}"\n${se}ID: ${learningId}`), + ...(indexNotRefreshed !== null && { index_refreshed: false }), + display: wrapDisplay( + `${te} Created ${params.learning_type}: "${params.title}"\n${se}ID: ${learningId}` + + (indexNotRefreshed !== null + ? `\nRecall index NOT refreshed (${indexNotRefreshed}). The learning is saved; recall will find it after the next successful reload (retrying in the background).` + : "") + ), }; } catch (error) { const errorMsg = error instanceof Error ? error.message : String(error); diff --git a/src/types/index.ts b/src/types/index.ts index 6de5c9b..c372436 100644 --- a/src/types/index.ts +++ b/src/types/index.ts @@ -346,6 +346,8 @@ export interface CreateLearningParams { export interface CreateLearningResult extends WriteResult { learning_id: string; embedding_generated: boolean; + /** GIT-118: false when the recall index could not be refreshed after the write. */ + index_refreshed?: boolean; /** Error details when success=false */ errors?: string[]; display?: string; diff --git a/tests/unit/services/startup-reload-failure.test.ts b/tests/unit/services/startup-reload-failure.test.ts new file mode 100644 index 0000000..9a2b1a9 --- /dev/null +++ b/tests/unit/services/startup-reload-failure.test.ts @@ -0,0 +1,170 @@ +/** + * GIT-118: a failed load never empties recall. + * + * loadScarsFromSupabase returned [] on any error with no flag, and every + * caller reinitialised the index and overwrote the hooks' scar cache with it. + * create_learning triggers a reload after every write, so one failed request + * emptied recall — and reported success — until the next good load, which a + * failed init never retried. + * + * Store mocked at the supabase-client boundary; the disk vector cache, the + * local index and the hook cache are real (temp GITMEM_DIR). Each test gets a + * fresh module graph, i.e. a fresh process. + */ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; +import * as fs from "fs"; +import * as os from "os"; +import * as path from "path"; + +const store = vi.hoisted(() => ({ + rows: [] as Array<{ id: string; title: string; description: string; severity: string; learning_type: string; updated_at: string; embedding: number[] }>, + down: false, + calls: { bulk: 0, manifest: 0 }, +})); +const active = () => [...store.rows].sort((a, b) => b.updated_at.localeCompare(a.updated_at)); +const fail = () => { throw new TypeError("fetch failed: ECONNRESET"); }; + +vi.mock("../../../src/services/supabase-client.js", () => ({ + isConfigured: () => true, + getSupabaseUrl: () => "https://venue.example.supabase.co", + getLearningsFingerprint: vi.fn(async () => { + if (store.down) return { count: -1, latestUpdatedAt: null }; // the real one's failure shape + const r = active(); + return { count: r.length, latestUpdatedAt: r[0]?.updated_at ?? null }; + }), + loadLearningsManifest: vi.fn(async () => { store.calls.manifest++; if (store.down) fail(); return active().map(({ id, updated_at }) => ({ id, updated_at })); }), + loadLearningsByIds: vi.fn(async (ids: string[]) => { if (store.down) fail(); return active().filter((r) => ids.includes(r.id)); }), + loadScarsWithEmbeddings: vi.fn(async () => { store.calls.bulk++; if (store.down) fail(); return active().map((r) => ({ ...r })); }), + directQuery: vi.fn(async () => []), +})); + +let dir: string; +const ts = (n: number) => new Date(Date.UTC(2026, 8, 21, 0, 0, n)).toISOString(); +const vec = (i: number) => Array.from({ length: 1536 }, (_, k) => Math.sin(i + k)); // the index keeps only 1536-dim rows +const seed = (n: number, at = 0) => { + store.rows = Array.from({ length: n }, (_, i) => ({ + id: `id-${String(i).padStart(3, "0")}`, title: `scar ${i}`, description: "d", severity: "medium", + learning_type: "scar", updated_at: ts(at + i), embedding: vec(i), + })); +}; +const hookCache = () => JSON.parse(fs.readFileSync(path.join(dir, "cache", "hook-scars.json"), "utf-8")); + +async function freshProcess() { + vi.resetModules(); + const startup = await import("../../../src/services/startup.js"); + const lvs = await import("../../../src/services/local-vector-search.js"); + return { startup, count: () => lvs.getLocalVectorSearch().getScarCount() }; +} + +beforeEach(() => { + dir = fs.mkdtempSync(path.join(os.tmpdir(), "gitmem-git118-")); + vi.stubEnv("GITMEM_DIR", dir); + vi.stubEnv("GITMEM_TIER", "pro"); + vi.stubEnv("SUPABASE_URL", "https://venue.example.supabase.co"); + vi.stubEnv("SUPABASE_SERVICE_ROLE_KEY", "k"); + vi.stubEnv("GITMEM_SEARCH_MODE", "local"); + vi.stubEnv("GITMEM_VECTOR_DISK_CACHE", ""); + store.down = false; + store.calls = { bulk: 0, manifest: 0 }; + seed(20); +}); + +afterEach(async () => { + const { resetReloadRetry } = await import("../../../src/services/startup.js"); + resetReloadRetry?.(); + vi.useRealTimers(); + vi.unstubAllEnvs(); + fs.rmSync(dir, { recursive: true, force: true }); +}); + +describe("GIT-118: a failed reload keeps what recall has", () => { + it("flush with the store down: success false, index and hook cache kept", async () => { + const { startup, count } = await freshProcess(); + expect((await startup.initializeGitMem()).success).toBe(true); + expect(count()).toBe(20); + expect(hookCache()).toHaveLength(20); + + store.down = true; + const r = await startup.flushCache(); + + expect(r.success).toBe(false); + expect(r.error).toMatch(/ECONNRESET/); + expect(count()).toBe(20); + expect(hookCache()).toHaveLength(20); + }); + + it("the post-write refresh uses the per-row delta, not a full download", async () => { + const { startup } = await freshProcess(); + await startup.initializeGitMem(); + store.calls = { bulk: 0, manifest: 0 }; + store.rows.push({ ...store.rows[0], id: "id-new", updated_at: ts(999) }); + + const r = await startup.refreshIndexAfterWrite(); + expect(r.success).toBe(true); + expect(r.new_scar_count).toBe(21); + expect(store.calls).toEqual({ bulk: 0, manifest: 1 }); + }); + + it("cold start with the store down serves the disk cache (stale) and says it failed", async () => { + const first = await freshProcess(); + await first.startup.initializeGitMem(); // leaves a disk cache behind + + store.down = true; + const { startup, count } = await freshProcess(); + const r = await startup.initializeGitMem(); + + expect(r.success).toBe(false); + expect(r.error).toMatch(/serving 20 from the disk cache/); + expect(count()).toBe(20); + }); + + it("a genuinely empty store is success with 0, not a failure", async () => { + store.rows = []; + const { startup, count } = await freshProcess(); + const r = await startup.initializeGitMem(); + expect(r.success).toBe(true); + expect(count()).toBe(0); + }); + + it("a failed load retries with backoff and recovers when the store does", async () => { + vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] }); + const { startup, count } = await freshProcess(); + await startup.initializeGitMem(); + store.down = true; + await startup.flushCache(); + expect(startup.getReloadRetryState()).toEqual({ pending: true, attempt: 1 }); + + store.down = false; + seed(25, 100); + await vi.advanceTimersByTimeAsync(30_000); + + expect(count()).toBe(25); + expect(startup.getReloadRetryState()).toEqual({ pending: false, attempt: 0 }); + }); + + it("the second retry waits twice as long", async () => { + vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] }); + const { startup } = await freshProcess(); + await startup.initializeGitMem(); + store.down = true; + await startup.flushCache(); + await vi.advanceTimersByTimeAsync(30_000); // retry 1 fails, schedules retry 2 at 60 s + expect(startup.getReloadRetryState()).toEqual({ pending: true, attempt: 2 }); + store.calls = { bulk: 0, manifest: 0 }; + await vi.advanceTimersByTimeAsync(59_000); + expect(store.calls.manifest + store.calls.bulk).toBe(0); + await vi.advanceTimersByTimeAsync(1_000); + expect(store.calls.manifest + store.calls.bulk).toBeGreaterThan(0); + }); + + it("ensureInitialized tries again after a failed init (it cached the failure forever)", async () => { + store.down = true; + const { startup, count } = await freshProcess(); + await startup.ensureInitialized(); + expect(count()).toBe(0); + + store.down = false; + await startup.ensureInitialized(); + expect(count()).toBe(20); + }); +}); diff --git a/tests/unit/tools/create-learning-errors.test.ts b/tests/unit/tools/create-learning-errors.test.ts index 3db0a6b..a6e116d 100644 --- a/tests/unit/tools/create-learning-errors.test.ts +++ b/tests/unit/tools/create-learning-errors.test.ts @@ -40,6 +40,9 @@ vi.mock("../../../src/services/display-protocol.js", () => ({ vi.mock("../../../src/services/startup.js", () => ({ flushCache: vi.fn(() => Promise.resolve()), + // GIT-118: create_learning awaits this; omitting it made every call report + // "index NOT refreshed" through a swallowed mock-export error. + refreshIndexAfterWrite: vi.fn(() => Promise.resolve({ success: true, previous_scar_count: 0, new_scar_count: 1, elapsed_ms: 1 })), })); vi.mock("../../../src/services/triple-writer.js", () => ({ @@ -190,3 +193,25 @@ describe("create_learning: DB error surfacing", () => { expect(result.errors).toBeUndefined(); }); }); + +// GIT-118: the post-write index refresh is awaited and its failure reported. +describe("create_learning: recall index refresh after the write (GIT-118)", () => { + it("says so in the display when the index could not be refreshed; the learning is still saved", async () => { + const startup = await import("../../../src/services/startup.js"); + vi.mocked(startup.refreshIndexAfterWrite).mockResolvedValueOnce({ + success: false, previous_scar_count: 5, new_scar_count: 5, elapsed_ms: 1, error: "fetch failed: ECONNRESET", + }); + const result = await createLearning({ + learning_type: "win", title: "t", description: "d", + } as never); + expect(result.success).toBe(true); + expect(result.index_refreshed).toBe(false); + expect(result.display).toMatch(/Recall index NOT refreshed \(fetch failed: ECONNRESET\)\. The learning is saved/); + }); + + it("says nothing extra when the refresh succeeds", async () => { + const result = await createLearning({ learning_type: "win", title: "t", description: "d" } as never); + expect(result.index_refreshed).toBeUndefined(); + expect(result.display).not.toMatch(/NOT refreshed/); + }); +}); diff --git a/tests/unit/tools/create-learning-field-persistence.test.ts b/tests/unit/tools/create-learning-field-persistence.test.ts index 6275ade..97a0267 100644 --- a/tests/unit/tools/create-learning-field-persistence.test.ts +++ b/tests/unit/tools/create-learning-field-persistence.test.ts @@ -55,6 +55,7 @@ vi.mock("../../../src/services/display-protocol.js", () => ({ vi.mock("../../../src/services/startup.js", () => ({ flushCache: vi.fn(() => Promise.resolve()), + refreshIndexAfterWrite: vi.fn(() => Promise.resolve({ success: true, previous_scar_count: 0, new_scar_count: 1, elapsed_ms: 1 })), // GIT-118 })); vi.mock("../../../src/services/triple-writer.js", () => ({ diff --git a/tests/unit/tools/variants-dev-only.test.ts b/tests/unit/tools/variants-dev-only.test.ts index 0bc6bc7..8f7c244 100644 --- a/tests/unit/tools/variants-dev-only.test.ts +++ b/tests/unit/tools/variants-dev-only.test.ts @@ -49,7 +49,10 @@ vi.mock("../../../src/services/embedding.js", () => ({ embed: async () => null, isEmbeddingAvailable: () => false, })); -vi.mock("../../../src/services/startup.js", () => ({ flushCache: async () => undefined })); +vi.mock("../../../src/services/startup.js", () => ({ + flushCache: async () => undefined, + refreshIndexAfterWrite: async () => ({ success: true, previous_scar_count: 0, new_scar_count: 1, elapsed_ms: 1 }), // GIT-118 +})); vi.mock("../../../src/services/triple-writer.js", () => ({ writeTriplesForLearning: async () => 0 })); const { resetTier, hasVariants } = await import("../../../src/services/tier.js"); From 848f8c934974aab6e1abb3b030eb1603aa43f7e6 Mon Sep 17 00:00:00 2001 From: Claude Date: Tue, 22 Sep 2026 20:36:10 -0700 Subject: [PATCH 2/2] test: venue flow fails the index reads through a proxy and checks recall survives (GIT-118) A forwarding proxy in front of the venue fails GET gitmem_learnings* on demand while writes pass. On 1.11.0: "Flushed and reloaded: 5 -> 0", create_learning silent, recall empty; exit 1. Co-Authored-By: Claude Opus 5.5 --- tests/e2e/blank-supabase.mjs | 60 +++++++++++++++++++++++++++++++++++- 1 file changed, 59 insertions(+), 1 deletion(-) diff --git a/tests/e2e/blank-supabase.mjs b/tests/e2e/blank-supabase.mjs index 0a16761..3cfc90e 100644 --- a/tests/e2e/blank-supabase.mjs +++ b/tests/e2e/blank-supabase.mjs @@ -200,7 +200,7 @@ function isolatedHome(tag) { return { home, gitmemDir }; } const STRIP = /^(OPENAI_API_KEY|OPENROUTER_API_KEY|GITMEM_|SUPABASE_|OLLAMA_|NODE_OPTIONS$|CLAUDE_CODE_ENTRYPOINT$)/; -async function startServer({ home, gitmemDir, ollamaUrl, netlog, stderrSink }) { +async function startServer({ home, gitmemDir, ollamaUrl, netlog, stderrSink, extraEnv = {} }) { const env = Object.fromEntries(Object.entries(process.env).filter(([k]) => !STRIP.test(k))); Object.assign(env, { HOME: home, @@ -216,6 +216,7 @@ async function startServer({ home, gitmemDir, ollamaUrl, netlog, stderrSink }) { GITMEM_NETLOG: netlog, NODE_OPTIONS: `--import=${pathToFileURL(NETLOG_PRELOAD).href}`, NO_COLOR: "1", + ...extraEnv, }); const transport = new StdioClientTransport({ command: process.execPath, args: [SERVER], env, cwd: home, stderr: "pipe" }); transport.stderr?.on("data", (d) => stderrSink.push(d.toString())); @@ -422,6 +423,56 @@ async function flow() { const relevance = relevanceRows.map((m) => ({ tool: m.tool_name, memories_applied: m.metadata.memories_applied, memory_relevance: m.metadata.memory_relevance })); await waitQuiet(netlog, { minMs: 1000, quietMs: 2000 }); await srv.close(); + + // GIT-118: the store fails the index READS while writes still land. A + // forwarding proxy in front of the venue fails GET gitmem_learnings… on + // demand. create_learning must save and say its index refresh failed; a + // recall right after must still find the seeded scars (index kept). + const reloadFailureProbe = async () => { + let failIndexReads = false; + const proxy = createServer(async (req, res) => { + const chunks = []; + for await (const c of req) chunks.push(c); + if (failIndexReads && req.method === "GET" && /^\/rest\/v1\/gitmem_learnings(\?|$)/.test(req.url)) { + res.writeHead(503, { "content-type": "application/json" }); + res.end('{"message":"injected by the venue driver (GIT-118)"}'); + return; + } + const headers = Object.fromEntries(Object.entries(req.headers).filter(([k]) => !["host", "connection", "content-length", "accept-encoding"].includes(k))); + const upstream = await fetch(`${SUPABASE_URL}${req.url}`, { method: req.method, headers, body: chunks.length ? Buffer.concat(chunks) : undefined }); + const body = Buffer.from(await upstream.arrayBuffer()); + const out = {}; + upstream.headers.forEach((v, k) => { if (!["content-encoding", "content-length", "transfer-encoding", "connection"].includes(k)) out[k] = v; }); + res.writeHead(upstream.status, out); + res.end(body); + }); + await new Promise((r) => proxy.listen(0, "127.0.0.1", r)); + const h = isolatedHome(`${label}-reload`); + const probeLog = join(outDir, `netlog-${label}-reload.jsonl`); + writeFileSync(probeLog, ""); + const errs = []; + const p = await startServer({ home: h.home, gitmemDir: h.gitmemDir, ollamaUrl: ollama.url, netlog: probeLog, stderrSink: errs, + extraEnv: { SUPABASE_URL: `http://127.0.0.1:${proxy.address().port}`, GITMEM_SEARCH_MODE: "local" } }); + await p.call("session_start", { project: PROJECT, agent_identity: "cli", force: true }); + for (let i = 0; i < 60 && !/GitMem initialized: [1-9]\d* scars/.test(errs.join("")); i++) await new Promise((r) => setTimeout(r, 500)); + failIndexReads = true; + const created = await p.call("create_learning", { learning_type: "win", title: `Reload probe win (${label}) ${randomUUID().slice(0, 8)}`, description: "written while the index reads fail", project: PROJECT }); + // Let any background reload the write started finish before the next + // prompt's recall (1.11.0 did not await it; a user's next prompt comes later). + await waitQuiet(probeLog, { minMs: 3000, quietMs: 2500 }); + const recall = await p.call("recall", { plan: "Supabase migrations must be dry-run before push", project: PROJECT, match_count: 3 }); + failIndexReads = false; + await p.close(); + proxy.close(); + writeFileSync(join(outDir, `stderr-${label}-reload.log`), errs.join("")); + return { + learning_saved: /Created win/.test(created), + create_says_not_refreshed: /Recall index NOT refreshed/.test(created), + recall_still_finds_seeded_scar: /Supabase migrations must be dry-run/.test(recall), + create_head: created.split("\n").slice(0, 3).join(" | ").slice(0, 240), + }; + }; + const reloadFailure = await reloadFailureProbe(); ollama.close(); const reqs = readNet(netlog); @@ -441,6 +492,7 @@ async function flow() { remote_sessions_after: await count("gitmem_sessions"), remote_scar_usage_after: await count("gitmem_scar_usage"), session_close_persisted: closedRows.length === 1 && closedRows[0].closing_reflection != null, + reload_failure: reloadFailure, missing_payload_named: missingPayloadNamed, resolve_thread_durable: resolveDurable, close_warns: closeWarns, @@ -648,6 +700,12 @@ if (mode === "flow" && !result.thread_triples_linked) { if (mode === "flow" && result.false_stranded_notice) { failureCheck.unexpected.push("session_start reported the store it reads as 'NOT being read' (GIT-107)"); } +if (mode === "flow") { + const r = result.reload_failure; + if (!(r.learning_saved && r.create_says_not_refreshed && r.recall_still_finds_seeded_scar)) { + failureCheck.unexpected.push(`a failed index reload was hidden or emptied recall (GIT-118): ${JSON.stringify(r)}`); + } +} if (mode === "flow" && !result.session_close_persisted) { failureCheck.unexpected.push(`session_close did not persist session ${result.session_id} (closing_reflection missing)`); }