cache-smoke.ts 20 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616
  1. /**
  2. * Cache smoke — live end-to-end probe answering "is provider prompt caching
  3. * working in my setup right now?"
  4. *
  5. * Starts a real `opencode serve` using your normal global config, auth, and
  6. * plugin, runs scripted conversations against your default (or given)
  7. * provider/model, and reads the provider-reported cache telemetry that
  8. * OpenCode stores on every assistant message (`tokens.cache.read/write`,
  9. * normalized from Anthropic's cache_control usage fields and OpenAI's
  10. * `prompt_tokens_details.cached_tokens`).
  11. *
  12. * The scenarios are designed to trigger this plugin's payload-touching
  13. * machinery on purpose — phase reminders, the post-file-tool nudge, todo
  14. * churn, background job board injection/reconciliation, repeated specialist
  15. * delegation with session reuse — so each injection path is validated
  16. * against a real provider, including the subagent child sessions it spawns.
  17. *
  18. * Usage:
  19. * bun run cache:smoke [-- options]
  20. *
  21. * Options:
  22. * --server URL Use an already-running OpenCode server instead of
  23. * starting one (skips spawn/cleanup of the server).
  24. * --provider ID Route turns to this provider (requires --model).
  25. * --model ID Route turns to this model (requires --provider).
  26. * --agent NAME Agent for each turn (default: server default).
  27. * --scenario LIST Comma list of scenario names, or "extensive"/"all"
  28. * (default: plain,tools — the cheap probe).
  29. * --turn-timeout-ms N Per-turn timeout (default 300000).
  30. * --keep-sessions Don't delete the probe sessions afterwards.
  31. *
  32. * Exit codes: 0 caching works · 1 bust detected · 2 inconclusive (provider
  33. * reported no cache telemetry) · 3 setup/runtime error.
  34. *
  35. * Each run costs real requests against your provider; the extensive set also
  36. * spawns background specialist sessions and takes several minutes. This is a
  37. * manual/operational probe, not a CI test — the CI-side guarantees live in
  38. * the cache-safety suites (see docs/cache-verification.md).
  39. */
  40. import { spawn } from 'node:child_process';
  41. import { mkdtempSync, rmSync, writeFileSync } from 'node:fs';
  42. import { createServer } from 'node:http';
  43. import { tmpdir } from 'node:os';
  44. import path from 'node:path';
  45. interface Args {
  46. server?: string;
  47. provider?: string;
  48. model?: string;
  49. agent?: string;
  50. scenarios: string[];
  51. turnTimeoutMs: number;
  52. keepSessions: boolean;
  53. }
  54. interface Turn {
  55. text: string;
  56. /** Wait after the turn completes (lets background work land). */
  57. pauseAfterMs?: number;
  58. }
  59. interface Scenario {
  60. name: string;
  61. description: string;
  62. /** Plugin machinery this scenario is designed to fire. */
  63. triggers: string;
  64. turns: (nonce: string) => Turn[];
  65. }
  66. interface RequestRow {
  67. messageID: string;
  68. input: number;
  69. output: number;
  70. cacheRead: number;
  71. cacheWrite: number;
  72. }
  73. interface SessionReport {
  74. label: string;
  75. rows: RequestRow[];
  76. }
  77. type Verdict = 'ok' | 'bust' | 'inconclusive';
  78. /**
  79. * Requests at or above this input size with zero cache reads (after the
  80. * first request of their session) count as suspect — comfortably above
  81. * every provider's minimum cacheable prefix (OpenAI 1024, Anthropic ≤4096).
  82. */
  83. const SUSPECT_INPUT_THRESHOLD = 4096;
  84. const NO_TOOLS = 'Do not use any tools.';
  85. const SCENARIOS: Scenario[] = [
  86. {
  87. name: 'plain',
  88. description: 'multi-turn conversation, no tools',
  89. triggers: 'phase reminder, skills filter, system transform',
  90. turns: (nonce) => [
  91. {
  92. text: `Cache smoke probe ${nonce}. Reply with exactly "ack 1" and nothing else. ${NO_TOOLS}`,
  93. },
  94. { text: `Reply with exactly "ack 2" and nothing else. ${NO_TOOLS}` },
  95. { text: `Reply with exactly "ack 3" and nothing else. ${NO_TOOLS}` },
  96. ],
  97. },
  98. {
  99. name: 'tools',
  100. description: 'tool loop within and across turns',
  101. triggers: 'tool-result growth across steps',
  102. turns: (nonce) => [
  103. {
  104. text: `Cache smoke probe ${nonce}. Read the file package.json in the current directory and reply with only the value of its "name" field.`,
  105. },
  106. { text: `Reply with exactly "ack done" and nothing else. ${NO_TOOLS}` },
  107. ],
  108. },
  109. {
  110. name: 'nudge',
  111. description: 'direct file read arms the post-file-tool nudge',
  112. triggers: 'post-file-tool-nudge injection, then phase-reminder equilibrium',
  113. turns: (nonce) => [
  114. {
  115. text: `Cache smoke probe ${nonce}. Do not delegate: use your read tool yourself on package.json and reply with only its "name" value.`,
  116. },
  117. { text: `Reply with exactly "ack nudged" and nothing else. ${NO_TOOLS}` },
  118. {
  119. text: `Reply with exactly "ack settled" and nothing else. ${NO_TOOLS}`,
  120. },
  121. ],
  122. },
  123. {
  124. name: 'todos',
  125. description: 'todo list created, updated, and completed across turns',
  126. triggers: 'todowrite churn, todo hygiene',
  127. turns: (nonce) => [
  128. {
  129. text: `Cache smoke probe ${nonce}. Use the todowrite tool to create exactly three todos named alpha, beta, gamma. Then reply with exactly "ack todos".`,
  130. },
  131. {
  132. text: 'Mark the todo alpha as completed and add a new todo named delta. Then reply with exactly "ack updated".',
  133. },
  134. {
  135. text: 'Mark every remaining todo as completed. Then reply with exactly "ack cleared".',
  136. },
  137. { text: `Reply with exactly "ack final" and nothing else. ${NO_TOOLS}` },
  138. ],
  139. },
  140. {
  141. name: 'long',
  142. description: 'six-turn conversation, growing history',
  143. triggers: 'sliding cache breakpoints over a long same-session history',
  144. turns: (nonce) => [
  145. {
  146. text: `Cache smoke probe ${nonce}. Reply with exactly "ack 1" and nothing else. ${NO_TOOLS}`,
  147. },
  148. { text: `Name one prime number below 10. One word only. ${NO_TOOLS}` },
  149. { text: `Name one planet. One word only. ${NO_TOOLS}` },
  150. { text: `Name one color. One word only. ${NO_TOOLS}` },
  151. { text: `Name one weekday. One word only. ${NO_TOOLS}` },
  152. {
  153. text: `Reply with exactly "ack long done" and nothing else. ${NO_TOOLS}`,
  154. },
  155. ],
  156. },
  157. {
  158. name: 'board',
  159. description:
  160. 'background task launched without waiting; board appears, completion lands, reconcile',
  161. triggers:
  162. 'background job board trailing injection, injected completion message, reconciliation',
  163. turns: (nonce) => [
  164. {
  165. text: `Cache smoke probe ${nonce}. Launch exactly one background @explorer task that lists the files in the current directory. Do not wait for it — reply immediately with exactly "ack launched".`,
  166. pauseAfterMs: 30_000,
  167. },
  168. {
  169. text: 'Reconcile any completed background tasks now, then reply with exactly "ack reconciled".',
  170. },
  171. {
  172. text: `Reply with exactly "ack board done" and nothing else. ${NO_TOOLS}`,
  173. },
  174. ],
  175. },
  176. {
  177. name: 'agents',
  178. description:
  179. 'repeated delegation: same specialist twice (session reuse), then a second specialist',
  180. triggers:
  181. 'board churn across multiple tasks, task session reuse by alias, @mention rewriting, subagent session caching',
  182. turns: (nonce) => [
  183. {
  184. text: `Cache smoke probe ${nonce}. Launch a background @explorer task to list the files in the current directory. Wait for it to complete, then reply with exactly "ack explorer 1".`,
  185. },
  186. {
  187. text: 'Give @explorer one more task: report how many lines package.json has. Wait for completion, then reply with exactly "ack explorer 2".',
  188. },
  189. {
  190. text: 'Now launch a background @fixer task to create a file named hello.txt containing the single word "hi". Wait for completion, then reply with exactly "ack fixer".',
  191. },
  192. {
  193. text: `Reply with exactly "ack agents done" and nothing else. ${NO_TOOLS}`,
  194. },
  195. ],
  196. },
  197. ];
  198. const CHEAP_SET = ['plain', 'tools'];
  199. const EXTENSIVE_SET = SCENARIOS.map((scenario) => scenario.name);
  200. function fail(message: string): never {
  201. console.error(`\ncache-smoke: ${message}`);
  202. process.exit(3);
  203. }
  204. function parseArgs(argv: string[]): Args {
  205. const args: Args = {
  206. scenarios: CHEAP_SET,
  207. turnTimeoutMs: 300_000,
  208. keepSessions: false,
  209. };
  210. for (let i = 0; i < argv.length; i += 1) {
  211. const flag = argv[i];
  212. const value = () => {
  213. const next = argv[i + 1];
  214. if (next === undefined) fail(`missing value for ${flag}`);
  215. i += 1;
  216. return next;
  217. };
  218. switch (flag) {
  219. case '--server':
  220. args.server = value().replace(/\/$/, '');
  221. break;
  222. case '--provider':
  223. args.provider = value();
  224. break;
  225. case '--model':
  226. args.model = value();
  227. break;
  228. case '--agent':
  229. args.agent = value();
  230. break;
  231. case '--scenario': {
  232. const requested = value();
  233. if (requested === 'all' || requested === 'extensive') {
  234. args.scenarios = EXTENSIVE_SET;
  235. break;
  236. }
  237. const names = requested.split(',');
  238. for (const name of names) {
  239. if (!SCENARIOS.some((scenario) => scenario.name === name)) {
  240. fail(
  241. `unknown scenario "${name}" (${EXTENSIVE_SET.join(' | ')} | extensive | all)`,
  242. );
  243. }
  244. }
  245. args.scenarios = names;
  246. break;
  247. }
  248. case '--turn-timeout-ms':
  249. args.turnTimeoutMs = Number(value());
  250. break;
  251. case '--keep-sessions':
  252. args.keepSessions = true;
  253. break;
  254. default:
  255. fail(`unknown flag ${flag}`);
  256. }
  257. }
  258. if (!!args.provider !== !!args.model) {
  259. fail('--provider and --model must be given together');
  260. }
  261. if (!Number.isFinite(args.turnTimeoutMs) || args.turnTimeoutMs <= 0) {
  262. fail('--turn-timeout-ms must be a positive number');
  263. }
  264. return args;
  265. }
  266. function getFreePort(): Promise<number> {
  267. return new Promise((resolve, reject) => {
  268. const server = createServer();
  269. server.once('error', reject);
  270. server.listen(0, '127.0.0.1', () => {
  271. const address = server.address();
  272. if (!address || typeof address === 'string') {
  273. server.close();
  274. reject(new Error('failed to allocate a port'));
  275. return;
  276. }
  277. server.close((error) => (error ? reject(error) : resolve(address.port)));
  278. });
  279. });
  280. }
  281. function isRecord(value: unknown): value is Record<string, unknown> {
  282. return !!value && typeof value === 'object' && !Array.isArray(value);
  283. }
  284. function finiteNumber(value: unknown): number {
  285. return typeof value === 'number' && Number.isFinite(value) ? value : 0;
  286. }
  287. async function request(
  288. base: string,
  289. method: string,
  290. route: string,
  291. body?: unknown,
  292. timeoutMs = 30_000,
  293. ): Promise<unknown> {
  294. const response = await fetch(`${base}${route}`, {
  295. method,
  296. headers: body === undefined ? {} : { 'content-type': 'application/json' },
  297. body: body === undefined ? undefined : JSON.stringify(body),
  298. signal: AbortSignal.timeout(timeoutMs),
  299. });
  300. if (!response.ok) {
  301. throw new Error(`${method} ${route} returned HTTP ${response.status}`);
  302. }
  303. const text = await response.text();
  304. if (!text) return undefined;
  305. try {
  306. return JSON.parse(text);
  307. } catch {
  308. return undefined;
  309. }
  310. }
  311. async function waitForHealth(base: string): Promise<void> {
  312. const deadline = Date.now() + 40_000;
  313. while (Date.now() < deadline) {
  314. try {
  315. const response = await fetch(`${base}/global/health`, {
  316. signal: AbortSignal.timeout(2_000),
  317. });
  318. if (response.ok) return;
  319. } catch {
  320. // keep polling
  321. }
  322. await new Promise((resolve) => setTimeout(resolve, 400));
  323. }
  324. throw new Error('server did not become healthy within 40s');
  325. }
  326. function extractAssistantRows(rawMessages: unknown): RequestRow[] {
  327. if (!Array.isArray(rawMessages)) return [];
  328. const rows: RequestRow[] = [];
  329. for (const raw of rawMessages) {
  330. const info = isRecord(raw) && isRecord(raw.info) ? raw.info : undefined;
  331. if (info?.role !== 'assistant') continue;
  332. const tokens = isRecord(info.tokens) ? info.tokens : undefined;
  333. if (!tokens) continue;
  334. const cache = isRecord(tokens.cache) ? tokens.cache : undefined;
  335. rows.push({
  336. messageID: typeof info.id === 'string' ? info.id : '?',
  337. input: finiteNumber(tokens.input),
  338. output: finiteNumber(tokens.output),
  339. cacheRead: finiteNumber(cache?.read),
  340. cacheWrite: finiteNumber(cache?.write),
  341. });
  342. }
  343. return rows;
  344. }
  345. async function fetchSessionRows(
  346. base: string,
  347. sessionID: string,
  348. ): Promise<RequestRow[]> {
  349. const rawMessages = await request(
  350. base,
  351. 'GET',
  352. `/session/${encodeURIComponent(sessionID)}/message`,
  353. );
  354. return extractAssistantRows(rawMessages);
  355. }
  356. async function listChildSessions(
  357. base: string,
  358. parentID: string,
  359. ): Promise<Array<{ id: string; title: string }>> {
  360. const raw = await request(base, 'GET', '/session').catch(() => undefined);
  361. if (!Array.isArray(raw)) return [];
  362. const children: Array<{ id: string; title: string }> = [];
  363. for (const item of raw) {
  364. if (!isRecord(item)) continue;
  365. if (item.parentID !== parentID || typeof item.id !== 'string') continue;
  366. children.push({
  367. id: item.id,
  368. title: typeof item.title === 'string' ? item.title : item.id,
  369. });
  370. }
  371. return children;
  372. }
  373. /** Suspect = non-first request with a sizeable prompt and zero cache reads. */
  374. function suspectRows(rows: RequestRow[]): RequestRow[] {
  375. return rows
  376. .slice(1)
  377. .filter(
  378. (row) => row.cacheRead === 0 && row.input >= SUSPECT_INPUT_THRESHOLD,
  379. );
  380. }
  381. function judge(reports: SessionReport[]): Verdict {
  382. const allRows = reports.flatMap((report) => report.rows);
  383. if (allRows.length < 2) return 'inconclusive';
  384. const anyTelemetry = allRows.some(
  385. (row) => row.cacheRead > 0 || row.cacheWrite > 0,
  386. );
  387. if (!anyTelemetry) return 'inconclusive';
  388. const suspects = reports.flatMap((report) => suspectRows(report.rows));
  389. return suspects.length > 0 ? 'bust' : 'ok';
  390. }
  391. function coverage(rows: RequestRow[]): string {
  392. const later = rows.slice(1);
  393. const read = later.reduce((sum, row) => sum + row.cacheRead, 0);
  394. const input = later.reduce((sum, row) => sum + row.input, 0);
  395. const denominator = read + input;
  396. return denominator > 0
  397. ? `${((read / denominator) * 100).toFixed(1)}%`
  398. : 'n/a';
  399. }
  400. function printSessionTable(report: SessionReport): void {
  401. console.log(` ${report.label}`);
  402. if (report.rows.length === 0) {
  403. console.log(' no assistant requests with token telemetry recorded');
  404. return;
  405. }
  406. console.log(
  407. ' req input output cache-read cache-write read-coverage',
  408. );
  409. const suspects = new Set(suspectRows(report.rows));
  410. report.rows.forEach((row, index) => {
  411. const denominator = row.input + row.cacheRead;
  412. const rowCoverage =
  413. denominator > 0
  414. ? `${((row.cacheRead / denominator) * 100).toFixed(1)}%`
  415. : 'n/a';
  416. const marker = suspects.has(row) ? ' ← SUSPECT' : '';
  417. console.log(
  418. ` #${String(index + 1).padEnd(3)}${String(row.input).padEnd(11)}${String(row.output).padEnd(9)}${String(row.cacheRead).padEnd(12)}${String(row.cacheWrite).padEnd(13)}${rowCoverage}${marker}`,
  419. );
  420. });
  421. console.log(
  422. ` cache-read coverage after first request: ${coverage(report.rows)}`,
  423. );
  424. }
  425. function printScenarioReport(
  426. scenario: Scenario,
  427. reports: SessionReport[],
  428. verdict: Verdict,
  429. ): void {
  430. console.log(`\n━━ scenario: ${scenario.name} (${scenario.description})`);
  431. console.log(` triggers: ${scenario.triggers}`);
  432. for (const report of reports) {
  433. printSessionTable(report);
  434. }
  435. const labels: Record<Verdict, string> = {
  436. ok: '✅ every sizeable follow-up request read the provider cache',
  437. bust: '❌ SUSPECT requests above read 0 cached tokens — the prompt prefix changed between requests',
  438. inconclusive:
  439. '⚠️ provider reported no cache telemetry — cannot verify (provider may not support or report caching)',
  440. };
  441. console.log(` verdict: ${labels[verdict]}`);
  442. }
  443. async function runScenario(
  444. base: string,
  445. args: Args,
  446. scenario: Scenario,
  447. ): Promise<{ reports: SessionReport[]; verdict: Verdict }> {
  448. const created = await request(base, 'POST', '/session', {});
  449. const sessionID = isRecord(created) ? String(created.id ?? '') : '';
  450. if (!sessionID) throw new Error('POST /session returned no session id');
  451. const cleanupIDs = [sessionID];
  452. try {
  453. const nonce = crypto.randomUUID();
  454. for (const turn of scenario.turns(nonce)) {
  455. await request(
  456. base,
  457. 'POST',
  458. `/session/${encodeURIComponent(sessionID)}/message`,
  459. {
  460. ...(args.agent ? { agent: args.agent } : {}),
  461. ...(args.provider && args.model
  462. ? { model: { providerID: args.provider, modelID: args.model } }
  463. : {}),
  464. parts: [{ type: 'text', text: turn.text }],
  465. },
  466. args.turnTimeoutMs,
  467. );
  468. if (turn.pauseAfterMs) {
  469. console.log(
  470. ` (waiting ${Math.round(turn.pauseAfterMs / 1000)}s for background work…)`,
  471. );
  472. await new Promise((resolve) => setTimeout(resolve, turn.pauseAfterMs));
  473. }
  474. }
  475. const reports: SessionReport[] = [
  476. {
  477. label: `session ${sessionID} (main)`,
  478. rows: await fetchSessionRows(base, sessionID),
  479. },
  480. ];
  481. for (const child of await listChildSessions(base, sessionID)) {
  482. cleanupIDs.push(child.id);
  483. reports.push({
  484. label: `session ${child.id} (subagent: ${child.title})`,
  485. rows: await fetchSessionRows(base, child.id),
  486. });
  487. }
  488. return { reports, verdict: judge(reports) };
  489. } finally {
  490. if (!args.keepSessions) {
  491. for (const id of cleanupIDs.reverse()) {
  492. await request(
  493. base,
  494. 'DELETE',
  495. `/session/${encodeURIComponent(id)}`,
  496. ).catch(() => {});
  497. }
  498. } else {
  499. console.log(` sessions kept: ${cleanupIDs.join(', ')}`);
  500. }
  501. }
  502. }
  503. async function main(): Promise<void> {
  504. const args = parseArgs(process.argv.slice(2));
  505. let base = args.server;
  506. let child: ReturnType<typeof spawn> | undefined;
  507. let scratch: string | undefined;
  508. if (!base) {
  509. const binary = process.env.OPENCODE_BIN ?? Bun.which('opencode');
  510. if (!binary) {
  511. fail(
  512. 'opencode binary not found — install opencode or set OPENCODE_BIN, or pass --server URL',
  513. );
  514. }
  515. scratch = mkdtempSync(path.join(tmpdir(), 'cache-smoke-'));
  516. writeFileSync(
  517. path.join(scratch, 'package.json'),
  518. `${JSON.stringify({ name: 'cache-smoke-fixture', version: '0.0.0' }, null, 2)}\n`,
  519. );
  520. const port = await getFreePort();
  521. base = `http://127.0.0.1:${port}`;
  522. console.log(`starting opencode serve on ${base} (cwd: ${scratch})`);
  523. child = spawn(
  524. binary,
  525. ['serve', '--hostname', '127.0.0.1', '--port', String(port)],
  526. {
  527. cwd: scratch,
  528. stdio: ['ignore', 'pipe', 'pipe'],
  529. },
  530. );
  531. const stderrChunks: string[] = [];
  532. child.stderr?.on('data', (chunk: Buffer) => {
  533. stderrChunks.push(String(chunk));
  534. });
  535. child.once('exit', (code) => {
  536. if (code !== null && code !== 0) {
  537. console.error(stderrChunks.join('').slice(-2000));
  538. fail(`opencode serve exited early with code ${code}`);
  539. }
  540. });
  541. await waitForHealth(base);
  542. }
  543. const cleanup = () => {
  544. child?.kill('SIGTERM');
  545. if (scratch) rmSync(scratch, { recursive: true, force: true });
  546. };
  547. try {
  548. const scenarios = SCENARIOS.filter((scenario) =>
  549. args.scenarios.includes(scenario.name),
  550. );
  551. const verdicts: Verdict[] = [];
  552. for (const scenario of scenarios) {
  553. console.log(`\nrunning scenario: ${scenario.name}…`);
  554. const { reports, verdict } = await runScenario(base, args, scenario);
  555. printScenarioReport(scenario, reports, verdict);
  556. verdicts.push(verdict);
  557. }
  558. console.log('');
  559. if (verdicts.includes('bust')) {
  560. console.log(
  561. 'RESULT: ❌ cache bust detected. Cross-check the plugin build (bun run build), then use docs/cache-verification.md to localize the changing prefix byte.',
  562. );
  563. process.exitCode = 1;
  564. } else if (verdicts.every((verdict) => verdict === 'inconclusive')) {
  565. console.log(
  566. 'RESULT: ⚠️ inconclusive — the provider reported no cache telemetry for any request.',
  567. );
  568. process.exitCode = 2;
  569. } else {
  570. console.log(
  571. 'RESULT: ✅ provider prompt caching is working across the tested scenarios.',
  572. );
  573. }
  574. } finally {
  575. cleanup();
  576. }
  577. }
  578. main().catch((error) => {
  579. fail(error instanceof Error ? error.message : String(error));
  580. });