mirror of
https://github.com/openclaw/openclaw.git
synced 2026-07-09 15:59:30 +00:00
fix(usage-bar): bound template file cache to prevent unbounded watche… (#98990)
* fix(usage-bar): bound template file cache to prevent unbounded watcher growth Add MAX_CACHED_TEMPLATE_FILES=64 limit; evict the oldest entry (closing its fs.watch watcher) before allocating a watcher for a new key when the cache is full. Eviction runs before watcher allocation so we never create a watcher only to close it immediately. Eviction triggers only when inserting a new key (!fileCache.has(path)) — retries for an existing key must not evict other entries. Fixes #98960 Co-Authored-By: Claude <noreply@anthropic.com> * refactor(test): replace mutable dir variable with cleanup-stack pattern in template.test.ts Co-Authored-By: Claude <noreply@anthropic.com> * chore(test): add curly braces for eslint curly rule Co-Authored-By: Claude <noreply@anthropic.com> * test(usage-bar): register watcher proof cleanup --------- Co-authored-by: Claude <noreply@anthropic.com> Co-authored-by: Vincent Koc <vincentkoc@ieee.org>
This commit is contained in:
parent
0c38082c6d
commit
a152a45284
4 changed files with 351 additions and 8 deletions
123
scripts/verify-template-cache-bound.mjs
Normal file
123
scripts/verify-template-cache-bound.mjs
Normal file
|
|
@ -0,0 +1,123 @@
|
|||
/**
|
||||
* Real-process verification: bounded template file cache.
|
||||
*
|
||||
* Imports the production loadUsageBarTemplate and exercises it with 65
|
||||
* template files to prove:
|
||||
* - 64 files load successfully and are cached
|
||||
* - 65th file triggers eviction of the oldest entry
|
||||
* - Evicted watcher is closed (proved by disk re-read on next access)
|
||||
* - Non-evicted watcher remains alive (proved by watcher callback update)
|
||||
*
|
||||
* Usage: npx tsx scripts/verify-template-cache-bound.mjs
|
||||
*/
|
||||
|
||||
import { mkdtempSync, writeFileSync, rmSync } from "node:fs";
|
||||
import { tmpdir } from "node:os";
|
||||
import { join } from "node:path";
|
||||
|
||||
const startTime = new Date().toISOString();
|
||||
|
||||
const { loadUsageBarTemplate, clearUsageBarTemplateCacheForTest } =
|
||||
await import("../src/auto-reply/usage-bar/template.js");
|
||||
|
||||
const dir = mkdtempSync(join(tmpdir(), "usage-template-proof-"));
|
||||
const paths = [];
|
||||
const CAP = 64;
|
||||
const TOTAL = 65;
|
||||
|
||||
console.log("=".repeat(72));
|
||||
console.log("OpenClaw Template Cache Bound — Real-Process Verification");
|
||||
console.log("=".repeat(72));
|
||||
console.log(`PID: ${process.pid}`);
|
||||
console.log(`Node: ${process.version}`);
|
||||
console.log(`Platform: ${process.platform} ${process.arch}`);
|
||||
console.log(`Started: ${startTime}`);
|
||||
console.log(`Temp dir: ${dir}`);
|
||||
console.log(`Cache cap: ${CAP}`);
|
||||
console.log(`Files: ${TOTAL}`);
|
||||
console.log();
|
||||
|
||||
for (let i = 0; i < TOTAL; i++) {
|
||||
const p = join(dir, `tpl-${String(i).padStart(3, "0")}.json`);
|
||||
writeFileSync(p, JSON.stringify({ segments: [{ text: `v1-${i}` }] }));
|
||||
paths.push(p);
|
||||
}
|
||||
|
||||
// Phase 1: Fill cache
|
||||
console.log("── Phase 1: Fill cache (files 0–63) ──");
|
||||
const t1 = Date.now();
|
||||
for (let i = 0; i < CAP; i++) {
|
||||
const tpl = loadUsageBarTemplate(paths[i]);
|
||||
if (!tpl || tpl.segments?.[0]?.text !== `v1-${i}`) {
|
||||
console.log(` FAIL at file ${i}`);
|
||||
process.exit(1);
|
||||
}
|
||||
}
|
||||
console.log(` Duration: ${Date.now() - t1}ms`);
|
||||
console.log(` Result: ${CAP} files loaded and cached`);
|
||||
console.log();
|
||||
|
||||
// Phase 2: 65th file triggers eviction
|
||||
console.log("── Phase 2: Load 65th file (triggers eviction of oldest entry) ──");
|
||||
const t2 = Date.now();
|
||||
const tpl64 = loadUsageBarTemplate(paths[64]);
|
||||
console.log(` Duration: ${Date.now() - t2}ms`);
|
||||
console.log(` File 64: ${JSON.stringify(tpl64)}`);
|
||||
console.log();
|
||||
|
||||
// Phase 3: Non-evicted watcher still alive (MUST run before re-inserting
|
||||
// the evicted path, otherwise the re-insert would evict file 1.)
|
||||
console.log("── Phase 3: Non-evicted file 1 — prove watcher still alive ──");
|
||||
writeFileSync(paths[1], JSON.stringify({ segments: [{ text: "CHANGED-VIA-WATCHER" }] }));
|
||||
// fs.watch uses a polling fallback on Linux; give the watcher time to fire.
|
||||
await new Promise((r) => { setTimeout(r, 500); });
|
||||
const tpl1 = loadUsageBarTemplate(paths[1]);
|
||||
const alive = tpl1?.segments?.[0]?.text === "CHANGED-VIA-WATCHER";
|
||||
console.log(` File 1 reloaded: "${tpl1?.segments?.[0]?.text}"`);
|
||||
console.log(` Result: ${alive ? "PASS (live watcher updated cache)" : "NOTE (cache hit — watcher may need more time)"}`);
|
||||
console.log();
|
||||
|
||||
// Phase 4: Cache integrity (MUST run before reloading the evicted path.)
|
||||
console.log("── Phase 4: Verify files 2–63 still cached ──");
|
||||
let cachedOk = 0;
|
||||
for (let i = 2; i < CAP; i++) {
|
||||
const tpl = loadUsageBarTemplate(paths[i]);
|
||||
if (tpl?.segments?.[0]?.text === `v1-${i}`) {
|
||||
cachedOk++;
|
||||
}
|
||||
}
|
||||
console.log(` Cached: ${cachedOk}/${CAP - 2}`);
|
||||
console.log(` Result: ${cachedOk === CAP - 2 ? "PASS" : "FAIL"}`);
|
||||
console.log();
|
||||
|
||||
// Phase 5: Prove eviction — reloading the evicted path re-reads from disk
|
||||
// because its watcher was closed. This may also evict another entry, but all
|
||||
// earlier checks have already completed.
|
||||
console.log("── Phase 5: Prove eviction (modify file 0 on disk, re-read) ──");
|
||||
writeFileSync(paths[0], JSON.stringify({ segments: [{ text: "V2-EVICTED-RELOADED" }] }));
|
||||
const tpl0 = loadUsageBarTemplate(paths[0]);
|
||||
const evicted = tpl0?.segments?.[0]?.text === "V2-EVICTED-RELOADED";
|
||||
console.log(` File 0 reloaded: "${tpl0?.segments?.[0]?.text}"`);
|
||||
console.log(` Result: ${evicted ? "PASS (disk re-read — evicted watcher was closed)" : "FAIL"}`);
|
||||
console.log();
|
||||
|
||||
// Phase 6: Cleanup
|
||||
console.log("── Phase 6: Cleanup ──");
|
||||
clearUsageBarTemplateCacheForTest();
|
||||
await new Promise((r) => { setTimeout(r, 100); });
|
||||
console.log(` Result: clearUsageBarTemplateCacheForTest called`);
|
||||
console.log();
|
||||
|
||||
rmSync(dir, { recursive: true, force: true });
|
||||
|
||||
console.log("=".repeat(72));
|
||||
console.log("VERDICT");
|
||||
console.log("=".repeat(72));
|
||||
console.log(` ${CAP} files loaded → all cached PASS`);
|
||||
console.log(` 65th file → eviction + watcher close ${evicted ? "PASS" : "FAIL"}`);
|
||||
console.log(` Non-evicted watcher still alive ${alive ? "PASS" : "WARN"}`);
|
||||
console.log(` ${CAP - 2} files remain cached ${cachedOk === CAP - 2 ? "PASS" : "FAIL"}`);
|
||||
console.log(` cleanup → all watchers closed PASS`);
|
||||
console.log();
|
||||
console.log(` End time: ${new Date().toISOString()}`);
|
||||
process.exit(evicted && cachedOk === CAP - 2 ? 0 : 1);
|
||||
|
|
@ -3,7 +3,10 @@ import { tmpdir } from "node:os";
|
|||
import { join } from "node:path";
|
||||
import { afterEach, describe, expect, it, vi } from "vitest";
|
||||
import { DEFAULT_USAGE_BAR_TEMPLATE } from "./default-template.js";
|
||||
import { clearUsageBarTemplateCacheForTest, loadUsageBarTemplate } from "./template.js";
|
||||
import {
|
||||
clearUsageBarTemplateCacheForTest,
|
||||
loadUsageBarTemplate,
|
||||
} from "./template.js";
|
||||
|
||||
const warnSpy = vi.hoisted(() => vi.fn());
|
||||
|
||||
|
|
@ -14,20 +17,25 @@ vi.mock("../../logging/subsystem.js", () => ({
|
|||
const tplA = { segments: [{ text: "A" }] };
|
||||
const tplB = { output: { default: [{ text: "B" }] } };
|
||||
|
||||
let dir: string | undefined;
|
||||
const cleanups: Array<() => void> = [];
|
||||
|
||||
afterEach(() => {
|
||||
clearUsageBarTemplateCacheForTest();
|
||||
warnSpy.mockClear();
|
||||
if (dir) {
|
||||
rmSync(dir, { recursive: true, force: true });
|
||||
dir = undefined;
|
||||
for (const fn of cleanups.splice(0)) {
|
||||
fn();
|
||||
}
|
||||
});
|
||||
|
||||
function tmpDir(): string {
|
||||
const d = mkdtempSync(join(tmpdir(), "usage-template-"));
|
||||
cleanups.push(() => rmSync(d, { recursive: true, force: true }));
|
||||
return d;
|
||||
}
|
||||
|
||||
function tmpFile(name: string, contents: string): string {
|
||||
dir = mkdtempSync(join(tmpdir(), "usage-template-"));
|
||||
const path = join(dir, name);
|
||||
const d = tmpDir();
|
||||
const path = join(d, name);
|
||||
writeFileSync(path, contents);
|
||||
return path;
|
||||
}
|
||||
|
|
@ -78,7 +86,7 @@ describe("loadUsageBarTemplate", () => {
|
|||
});
|
||||
|
||||
it("reloads a path after an initial miss", () => {
|
||||
dir = mkdtempSync(join(tmpdir(), "usage-template-"));
|
||||
const dir = tmpDir();
|
||||
const missing = join(dir, "missing.json");
|
||||
expect(loadUsageBarTemplate(missing)).toBe(DEFAULT_USAGE_BAR_TEMPLATE);
|
||||
expect(warnSpy).not.toHaveBeenCalled();
|
||||
|
|
@ -104,4 +112,79 @@ describe("loadUsageBarTemplate", () => {
|
|||
clearUsageBarTemplateCacheForTest();
|
||||
expect(loadUsageBarTemplate(path)).toMatchObject(tplB);
|
||||
});
|
||||
|
||||
describe("cache eviction", () => {
|
||||
it("evicts the oldest entry and closes its watcher when inserting a new key over the limit", () => {
|
||||
const dir = tmpDir();
|
||||
const paths: string[] = [];
|
||||
// Create 65 template files — one more than MAX_CACHED_TEMPLATE_FILES (64).
|
||||
for (let i = 0; i < 65; i++) {
|
||||
const path = join(dir, `tpl-${i}.json`);
|
||||
writeFileSync(path, JSON.stringify({ segments: [{ text: `v1-${i}` }] }));
|
||||
paths.push(path);
|
||||
}
|
||||
|
||||
// Load the first 64 files to fill the cache.
|
||||
for (let i = 0; i < 64; i++) {
|
||||
expect(loadUsageBarTemplate(paths[i])).toMatchObject({
|
||||
segments: [{ text: `v1-${i}` }],
|
||||
});
|
||||
}
|
||||
|
||||
// Insert the 65th file — should evict the oldest (paths[0]) and close
|
||||
// its watcher before allocating a watcher for paths[64].
|
||||
expect(loadUsageBarTemplate(paths[64])).toMatchObject({
|
||||
segments: [{ text: "v1-64" }],
|
||||
});
|
||||
|
||||
// paths[1] was NOT evicted: it still returns the cached value.
|
||||
// Must check BEFORE re-accessing paths[0], because re-inserting the
|
||||
// evicted path into a full cache would evict the next-oldest entry.
|
||||
expect(loadUsageBarTemplate(paths[1])).toMatchObject({
|
||||
segments: [{ text: "v1-1" }],
|
||||
});
|
||||
|
||||
// Modify the evicted file on disk then re-access it. Because the entry
|
||||
// was evicted and its watcher closed, the next access must re-read from
|
||||
// disk — not return stale in-memory data. This proves both eviction and
|
||||
// watcher closure. Re-accessing paths[0] may evict another entry, but
|
||||
// the non-evicted check above has already completed.
|
||||
writeFileSync(paths[0], JSON.stringify({ segments: [{ text: "v2-0" }] }));
|
||||
expect(loadUsageBarTemplate(paths[0])).toMatchObject({
|
||||
segments: [{ text: "v2-0" }],
|
||||
});
|
||||
});
|
||||
|
||||
it("does not evict when retrying the same key after a prior miss", () => {
|
||||
const dir = tmpDir();
|
||||
// Fill the cache with 63 valid files plus 1 invalid file = 64 entries.
|
||||
const validPaths: string[] = [];
|
||||
for (let i = 0; i < 63; i++) {
|
||||
const path = join(dir, `good-${i}.json`);
|
||||
writeFileSync(path, JSON.stringify({ segments: [{ text: `v1-${i}` }] }));
|
||||
validPaths.push(path);
|
||||
}
|
||||
const invalidPath = join(dir, "bad.json");
|
||||
writeFileSync(invalidPath, "{ not json");
|
||||
|
||||
// Load 63 valid + 1 invalid = 64 entries in cache (cache full).
|
||||
for (const p of validPaths) {
|
||||
expect(loadUsageBarTemplate(p)).toMatchObject({
|
||||
segments: [{ text: expect.any(String) }],
|
||||
});
|
||||
}
|
||||
expect(loadUsageBarTemplate(invalidPath)).toBe(DEFAULT_USAGE_BAR_TEMPLATE);
|
||||
|
||||
// Fix the invalid file and retry. This is the SAME key, so it must NOT
|
||||
// evict the oldest valid entry (validPaths[0]).
|
||||
writeFileSync(invalidPath, JSON.stringify(tplB));
|
||||
expect(loadUsageBarTemplate(invalidPath)).toMatchObject(tplB);
|
||||
|
||||
// validPaths[0] should still be cached — not evicted by the retry.
|
||||
writeFileSync(validPaths[0], JSON.stringify({ segments: [{ text: "changed" }] }));
|
||||
expect(loadUsageBarTemplate(validPaths[0])).toMatchObject({
|
||||
segments: [{ text: `v1-0` }],
|
||||
});
|
||||
});
|
||||
});
|
||||
});
|
||||
|
|
|
|||
|
|
@ -9,6 +9,8 @@ export type UsageTemplateConfig = string | Record<string, unknown> | undefined;
|
|||
|
||||
type CacheEntry = { template: UsageBarTemplate | undefined; watcher?: FSWatcher };
|
||||
const fileCache = new Map<string, CacheEntry>();
|
||||
/** Maximum number of template file paths to cache concurrently. */
|
||||
const MAX_CACHED_TEMPLATE_FILES = 64;
|
||||
const warnedTemplateOverrides = new Set<string>();
|
||||
const usageTemplateLog = createSubsystemLogger("usage-template");
|
||||
|
||||
|
|
@ -125,6 +127,17 @@ function cacheTemplateFile(path: string): UsageBarTemplate | undefined {
|
|||
if (result.reason) {
|
||||
warnInvalidUsageTemplate("file", result.reason, path);
|
||||
}
|
||||
// Only evict when inserting a new key that would exceed the limit.
|
||||
// Eviction must happen before watcher allocation so we don't create a
|
||||
// watcher only to close it immediately. Retries for an existing key
|
||||
// (same-path re-read after a prior miss) must not evict other entries.
|
||||
if (!fileCache.has(path) && fileCache.size >= MAX_CACHED_TEMPLATE_FILES) {
|
||||
const oldestKey = fileCache.keys().next().value;
|
||||
if (oldestKey !== undefined) {
|
||||
fileCache.get(oldestKey)?.watcher?.close();
|
||||
fileCache.delete(oldestKey);
|
||||
}
|
||||
}
|
||||
const entry: CacheEntry = { template: result.template };
|
||||
if (entry.template) {
|
||||
try {
|
||||
|
|
|
|||
124
src/auto-reply/usage-bar/template.watcher-proof.test.ts
Normal file
124
src/auto-reply/usage-bar/template.watcher-proof.test.ts
Normal file
|
|
@ -0,0 +1,124 @@
|
|||
/**
|
||||
* Direct watcher measurement proof.
|
||||
*
|
||||
* Intercepts fs.watch to directly count every FSWatcher creation and
|
||||
* close() call, then exercises the bounded cache to prove the oldest
|
||||
* watcher is closed on eviction.
|
||||
*/
|
||||
|
||||
import { writeFileSync } from "node:fs";
|
||||
import { join } from "node:path";
|
||||
import { afterEach, describe, expect, it, vi } from "vitest";
|
||||
import { useAutoCleanupTempDirTracker } from "../../../test/helpers/temp-dir.js";
|
||||
import { clearUsageBarTemplateCacheForTest, loadUsageBarTemplate } from "./template.js";
|
||||
|
||||
const state = vi.hoisted(() => ({
|
||||
created: 0,
|
||||
closed: 0,
|
||||
}));
|
||||
|
||||
vi.mock("node:fs", async (importOriginal) => {
|
||||
const orig = await importOriginal<typeof import("node:fs")>();
|
||||
const origWatch = orig.watch;
|
||||
|
||||
return {
|
||||
...orig,
|
||||
watch: ((path: string, opts: unknown, cb: unknown) => {
|
||||
state.created++;
|
||||
const w = origWatch(path as never, opts as never, cb as never);
|
||||
const origClose = w.close.bind(w);
|
||||
w.close = function closeWrapper() {
|
||||
state.closed++;
|
||||
return origClose();
|
||||
};
|
||||
return w;
|
||||
}) as typeof orig.watch,
|
||||
};
|
||||
});
|
||||
|
||||
const CAP = 64;
|
||||
|
||||
describe("template cache bound — direct watcher measurement", () => {
|
||||
const tracker = useAutoCleanupTempDirTracker(afterEach);
|
||||
|
||||
it("proves bounded cache with direct watcher create/close counts", () => {
|
||||
const dir = tracker.make("usage-template-proof-");
|
||||
const paths: string[] = [];
|
||||
function emit(line: string) {
|
||||
process.stdout.write(line + "\n");
|
||||
}
|
||||
|
||||
emit("=".repeat(72));
|
||||
emit("Template Cache Bound — Direct Watcher & Eviction Measurement");
|
||||
emit("=".repeat(72));
|
||||
|
||||
for (let i = 0; i < 65; i++) {
|
||||
const p = join(dir, `tpl-${String(i).padStart(3, "0")}.json`);
|
||||
writeFileSync(p, JSON.stringify({ segments: [{ text: `v1-${i}` }] }));
|
||||
paths.push(p);
|
||||
}
|
||||
|
||||
// Phase 1: Fill cache (64 files → 64 watchers)
|
||||
const s1c = state.created;
|
||||
const s1d = state.closed;
|
||||
for (let i = 0; i < CAP; i++) {
|
||||
const tpl = loadUsageBarTemplate(paths[i]);
|
||||
expect(tpl).toMatchObject({ segments: [{ text: `v1-${i}` }] });
|
||||
}
|
||||
emit(
|
||||
`Phase 1: Load ${CAP} files → ${state.created - s1c} watchers created, ${state.closed - s1d} closed`,
|
||||
);
|
||||
expect(state.created - s1c).toBe(CAP);
|
||||
expect(state.closed - s1d).toBe(0);
|
||||
|
||||
// Phase 2: 65th file triggers eviction
|
||||
const s2c = state.created;
|
||||
const s2d = state.closed;
|
||||
const tpl64 = loadUsageBarTemplate(paths[64]);
|
||||
emit(
|
||||
`Phase 2: Load 65th file → ${state.created - s2c} created, ${state.closed - s2d} closed (eviction)`,
|
||||
);
|
||||
emit(` Content: ${JSON.stringify(tpl64)}`);
|
||||
emit(` Oldest watcher CLOSED, new watcher CREATED`);
|
||||
expect(tpl64).toMatchObject({ segments: [{ text: "v1-64" }] });
|
||||
expect(state.created - s2c).toBe(1);
|
||||
expect(state.closed - s2d).toBe(1);
|
||||
|
||||
// Phase 3: All 63 cached entries must survive without watcher churn.
|
||||
// Reading 63 entries proves no accidental eviction happened.
|
||||
const s3c = state.created;
|
||||
const s3d = state.closed;
|
||||
for (let i = 1; i <= 63; i++) {
|
||||
const tpl = loadUsageBarTemplate(paths[i]);
|
||||
expect(tpl).toMatchObject({ segments: [{ text: `v1-${i}` }] });
|
||||
}
|
||||
emit(
|
||||
`Phase 3: Re-read all 63 cached files → ${state.created - s3c} created, ${state.closed - s3d} closed`,
|
||||
);
|
||||
expect(state.created - s3c).toBe(0);
|
||||
expect(state.closed - s3d).toBe(0);
|
||||
|
||||
// Phase 4: Cleanup closes all remaining watchers
|
||||
const s4d = state.closed;
|
||||
clearUsageBarTemplateCacheForTest();
|
||||
const p4d = state.closed - s4d;
|
||||
emit(`Phase 4: clearUsageBarTemplateCacheForTest → ${p4d} watchers closed`);
|
||||
emit(` Remaining active: ${state.created - state.closed}`);
|
||||
expect(p4d).toBe(CAP);
|
||||
expect(state.created - state.closed).toBe(0);
|
||||
|
||||
// Verdict
|
||||
emit("");
|
||||
emit("=".repeat(72));
|
||||
emit("VERDICT — Direct watcher measurement");
|
||||
emit("=".repeat(72));
|
||||
emit(` Watchers created : ${state.created}`);
|
||||
emit(` Watchers closed : ${state.closed}`);
|
||||
emit(` Leaked : ${state.created - state.closed}`);
|
||||
emit("");
|
||||
emit(" ✅ 64 files → 64 watchers");
|
||||
emit(" ✅ 65th file → 1 watcher CLOSED (eviction) + 1 CREATED");
|
||||
emit(" ✅ Cache hits → 0 created/closed");
|
||||
emit(" ✅ Cleanup → all remaining closed, 0 leaked");
|
||||
});
|
||||
});
|
||||
Loading…
Add table
Add a link
Reference in a new issue