diff --git a/scripts/analyze-prompt-cache-usage.ts b/scripts/analyze-prompt-cache-usage.ts new file mode 100644 index 000000000..21b70ff82 --- /dev/null +++ b/scripts/analyze-prompt-cache-usage.ts @@ -0,0 +1,692 @@ +#!/usr/bin/env bun +import { readFileSync } from "node:fs"; +import { homedir } from "node:os"; +import { join } from "node:path"; +import { + normalizePromptCacheRequestObservation, + type PromptCacheRequestObservation, +} from "../src/prompt-cache/observability"; + +type RangeName = "7d" | "30d" | "all"; +type CohortSignal = "write-heavy" | "low-reuse" | "healthy" | "mixed"; + +interface AnalyzerOptions { + source: string; + range: RangeName; + top: number; + nowMs: number; + jsonMode: boolean; + help: boolean; +} + +interface CacheUsage { + input: number; + read: number; + write: number; +} + +interface CohortDimensions { + adapter: string; + provider: string; + model: string; + surface: string; +} + +interface Cohort extends CohortDimensions { + requests: number; + reportedSuccess: number; + input: number; + cacheRead: number; + cacheWrite: number; + uncachedInput: number; + hitRequests: number; + writeRequests: number; + conversations: Map; +} + +interface CohortSummary extends CohortDimensions { + signal: CohortSignal; + requests: number; + reportedSuccess: number; + inputTokens: number; + cacheReadTokens: number; + cacheWriteTokens: number; + uncachedInputTokens: number; + cacheReadRatio: number; + cacheWriteRatio: number; + cacheHitRequestRatio: number; + cacheWriteRequestRatio: number; + conversations: number; + multiTurnConversations: number; +} + +interface ShapeBucket { + dimensions: CohortDimensions; + observation: PromptCacheRequestObservation; + rows: Record[]; +} + +interface ShapeSummary extends CohortDimensions { + mode: PromptCacheRequestObservation["mode"]; + ttl: PromptCacheRequestObservation["ttl"] | null; + keyPresent: boolean; + breakpointCount: number; + toolCount: number; + toolsFingerprint: string | null; + stablePrefixFingerprint: string | null; + textFormatFingerprint: string | null; + verbosity: string | null; + requests: number; + reportedSuccess: number; + inputTokens: number; + cacheReadTokens: number; + cacheWriteTokens: number; + cacheReadRatio: number; + cacheWriteRatio: number; +} + +/** Describe the analyzer CLI options and their defaults. */ +function usageText(): string { + return [ + "Usage: bun scripts/analyze-prompt-cache-usage.ts [usage.jsonl|-] [options]", + "", + "Options:", + " --range=7d|30d|all Analysis window (default: 7d)", + " --top=N Maximum cohorts/shapes to print, 1..200 (default: 20)", + " --now=ISO|epoch-ms Anchor relative windows for reproducible analysis", + " --json Emit JSON", + " --help Show this help", + ].join("\n"); +} + +/** Narrow parsed JSON values to non-null, non-array objects. */ +function isRecord(value: unknown): value is Record { + return !!value && typeof value === "object" && !Array.isArray(value); +} + +/** Check for an explicitly stored field without consulting the prototype chain. */ +function hasOwn(value: Record, key: string): boolean { + return Object.prototype.hasOwnProperty.call(value, key); +} + +/** Return finite, non-negative numeric usage values, or undefined for invalid data. */ +function nonNegativeNumber(value: unknown): number | undefined { + return typeof value === "number" && Number.isFinite(value) && value >= 0 + ? value + : undefined; +} + +/** Trim a string dimension, returning undefined when it is absent or blank. */ +function stringValue(value: unknown): string | undefined { + return typeof value === "string" && value.trim() ? value.trim() : undefined; +} + +/** Accept a supported analysis window; throw for an unknown range. */ +function parseRange(value: string): RangeName { + if (value === "7d" || value === "30d" || value === "all") return value; + throw new Error(`invalid --range value: ${value}`); +} + +/** Parse a decimal result limit from 1 through 200; throw for invalid input. */ +function parseTop(value: string): number { + if (!/^\d+$/u.test(value)) throw new Error(`invalid --top value: ${value}`); + const parsed = Number.parseInt(value, 10); + if (parsed < 1 || parsed > 200) + throw new Error("--top must be between 1 and 200"); + return parsed; +} + +/** Parse a non-negative epoch-millisecond or date-string anchor; throw if invalid. */ +function parseNow(value: string): number { + if (/^\d+$/u.test(value)) { + const numeric = Number(value); + if (Number.isSafeInteger(numeric) && numeric >= 0) return numeric; + } + const parsed = Date.parse(value); + if (Number.isFinite(parsed) && parsed >= 0) return parsed; + throw new Error(`invalid --now value: ${value}`); +} + +/** Resolve CLI options and the usage-log path; throw on invalid or extra arguments. */ +function parseArgs(args: string[]): AnalyzerOptions { + const defaultSource = join( + process.env.OPENCODEX_HOME?.trim() || join(homedir(), ".opencodex"), + "usage.jsonl", + ); + let source = defaultSource; + let positionalSeen = false; + let range: RangeName = "7d"; + let top = 20; + let nowMs = Date.now(); + let jsonMode = false; + let help = false; + + for (const arg of args) { + if (arg === "--json") { + jsonMode = true; + continue; + } + if (arg === "--help") { + help = true; + continue; + } + if (arg.startsWith("--range=")) { + range = parseRange(arg.slice("--range=".length)); + continue; + } + if (arg.startsWith("--top=")) { + top = parseTop(arg.slice("--top=".length)); + continue; + } + if (arg.startsWith("--now=")) { + nowMs = parseNow(arg.slice("--now=".length)); + continue; + } + if (arg.startsWith("--")) throw new Error(`unknown option: ${arg}`); + if (positionalSeen) + throw new Error("only one usage-log path may be supplied"); + source = arg; + positionalSeen = true; + } + + return { source, range, top, nowMs, jsonMode, help }; +} + +/** + * Read cache totals only from successful, provider-reported usage rows. + * Prefer explicit reads over legacy cached totals, subtract legacy writes when present, + * and reject malformed reads or cache totals exceeding input tokens. + */ +function cacheUsage(row: Record): CacheUsage | undefined { + if ( + row.status !== 200 || + row.usageStatus !== "reported" || + !isRecord(row.usage) + ) { + return undefined; + } + const input = nonNegativeNumber(row.usage.inputTokens); + if (input === undefined) return undefined; + const write = nonNegativeNumber(row.usage.cacheCreationInputTokens) ?? 0; + let read: number; + if (hasOwn(row.usage, "cacheReadInputTokens")) { + const explicitRead = nonNegativeNumber(row.usage.cacheReadInputTokens); + if (explicitRead === undefined) return undefined; + read = explicitRead; + } else { + const legacyCached = nonNegativeNumber(row.usage.cachedInputTokens); + read = + (legacyCached !== undefined && + row.usage.cacheCreationInputTokens !== undefined + ? Math.max(0, legacyCached - write) + : legacyCached) ?? 0; + } + if (read + write > input) return undefined; + return { input, read, write }; +} + +/** Compute the inclusive window start in milliseconds, using epoch zero for all history. */ +function sinceFor(range: RangeName, nowMs: number): number { + if (range === "all") return 0; + return nowMs - (range === "7d" ? 7 : 30) * 86_400_000; +} + +/** Extract cohort dimensions, preferring the resolved model and marking missing values unknown. */ +function dimensionsFrom(row: Record): CohortDimensions { + return { + adapter: stringValue(row.adapter) ?? "unknown", + provider: stringValue(row.provider) ?? "unknown", + model: + stringValue(row.resolvedModel) ?? stringValue(row.model) ?? "unknown", + surface: stringValue(row.surface) ?? "unknown", + }; +} + +/** Encode adapter, provider, model, and surface as an unambiguous cohort key. */ +function dimensionsKey(dimensions: CohortDimensions): string { + return JSON.stringify([ + dimensions.adapter, + dimensions.provider, + dimensions.model, + dimensions.surface, + ]); +} + +/** Initialize usage and conversation counters for a cohort. */ +function emptyCohort(dimensions: CohortDimensions): Cohort { + return { + ...dimensions, + requests: 0, + reportedSuccess: 0, + input: 0, + cacheRead: 0, + cacheWrite: 0, + uncachedInput: 0, + hitRequests: 0, + writeRequests: 0, + conversations: new Map(), + }; +} + +/** Divide by a positive denominator, returning zero when no measurable denominator exists. */ +function ratio(numerator: number, denominator: number): number { + return denominator > 0 ? numerator / denominator : 0; +} + +/** Classify measured reuse using cache-read, cache-write, and input-volume thresholds. */ +function signal(cohort: Cohort): CohortSignal { + const readRatio = ratio(cohort.cacheRead, cohort.input); + const writeRatio = ratio(cohort.cacheWrite, cohort.input); + if (writeRatio >= 0.5 && readRatio < 0.1) return "write-heavy"; + if (cohort.input >= 1_000_000 && readRatio < 0.25) return "low-reuse"; + if (readRatio >= 0.75) return "healthy"; + return "mixed"; +} + +/** Convert cohort counters into token totals, ratios, and conversation counts. */ +function summarizeCohort(cohort: Cohort): CohortSummary { + let multiTurnConversations = 0; + for (const count of cohort.conversations.values()) { + if (count > 1) multiTurnConversations += 1; + } + return { + adapter: cohort.adapter, + provider: cohort.provider, + model: cohort.model, + surface: cohort.surface, + signal: signal(cohort), + requests: cohort.requests, + reportedSuccess: cohort.reportedSuccess, + inputTokens: cohort.input, + cacheReadTokens: cohort.cacheRead, + cacheWriteTokens: cohort.cacheWrite, + uncachedInputTokens: cohort.uncachedInput, + cacheReadRatio: ratio(cohort.cacheRead, cohort.input), + cacheWriteRatio: ratio(cohort.cacheWrite, cohort.input), + cacheHitRequestRatio: ratio(cohort.hitRequests, cohort.reportedSuccess), + cacheWriteRequestRatio: ratio(cohort.writeRequests, cohort.reportedSuccess), + conversations: cohort.conversations.size, + multiTurnConversations, + }; +} + +/** Encode the cache settings and fingerprints used to group comparable request shapes. */ +function cacheShapeKey(observation: PromptCacheRequestObservation): string { + return JSON.stringify([ + observation.mode, + observation.ttl ?? null, + observation.keyPresent, + observation.breakpointCount, + observation.toolsFingerprint ?? null, + observation.stablePrefixFingerprint ?? null, + observation.textFormatFingerprint ?? null, + observation.verbosity ?? null, + ]); +} + +/** Summarize a shape bucket, measuring tokens only from valid reported-success rows. */ +function summarizeShape(bucket: ShapeBucket): ShapeSummary { + const pc = bucket.observation; + let input = 0; + let read = 0; + let write = 0; + let reportedSuccess = 0; + for (const row of bucket.rows) { + const usage = cacheUsage(row); + if (!usage) continue; + reportedSuccess += 1; + input += usage.input; + read += usage.read; + write += usage.write; + } + return { + ...bucket.dimensions, + mode: pc.mode, + ttl: pc.ttl ?? null, + keyPresent: pc.keyPresent, + breakpointCount: pc.breakpointCount, + toolCount: pc.toolCount, + toolsFingerprint: pc.toolsFingerprint ?? null, + stablePrefixFingerprint: pc.stablePrefixFingerprint ?? null, + textFormatFingerprint: pc.textFormatFingerprint ?? null, + verbosity: pc.verbosity ?? null, + requests: bucket.rows.length, + reportedSuccess, + inputTokens: input, + cacheReadTokens: read, + cacheWriteTokens: write, + cacheReadRatio: ratio(read, input), + cacheWriteRatio: ratio(write, input), + }; +} + +/** Render a fractional ratio as a percentage with one decimal place. */ +function formatPercent(value: number): string { + return (value * 100).toFixed(1) + "%"; +} + +interface ParsedUsageRows { + rows: Record[]; + invalidLines: number; +} + +interface AnalysisTotals { + reportedSuccess: number; + input: number; + read: number; + write: number; +} + +interface AnalysisState { + cohorts: Map; + shapeBuckets: Map; + totals: AnalysisTotals; +} + +/** Read UTF-8 usage JSONL from the selected file or stdin; propagate read errors. */ +function readUsageSource(options: AnalyzerOptions): string { + return options.source === "-" + ? readFileSync(0, "utf8") + : readFileSync(options.source, "utf8"); +} + +/** Parse JSONL objects, skipping blank lines and counting malformed or non-object rows. */ +function parseUsageRows(text: string): ParsedUsageRows { + const rows: Record[] = []; + let invalidLines = 0; + for (const line of text.split(/\r?\n/u)) { + if (!line.trim()) continue; + try { + const parsed: unknown = JSON.parse(line); + if (isRecord(parsed)) rows.push(parsed); + else invalidLines += 1; + } catch { + invalidLines += 1; + } + } + return { rows, invalidLines }; +} + +/** Select rows with valid timestamps inside the inclusive analysis window. */ +function rowsInWindow( + rows: readonly Record[], + since: number, + nowMs: number, +): Record[] { + return rows.filter((row) => { + const timestamp = nonNegativeNumber(row.timestamp); + return timestamp !== undefined && timestamp >= since && timestamp <= nowMs; + }); +} + +/** Increment a cohort conversation count when the row has a non-blank identifier. */ +function recordConversation( + cohort: Cohort, + row: Record, +): void { + const conversationId = stringValue(row.conversationId); + if (!conversationId) return; + cohort.conversations.set( + conversationId, + (cohort.conversations.get(conversationId) ?? 0) + 1, + ); +} + +/** Accumulate validated usage into cohort and global counters, ignoring absent measurements. */ +function recordCacheUsage( + cohort: Cohort, + usage: CacheUsage | undefined, + totals: AnalysisTotals, +): void { + if (!usage) return; + cohort.reportedSuccess += 1; + cohort.input += usage.input; + cohort.cacheRead += usage.read; + cohort.cacheWrite += usage.write; + cohort.uncachedInput += Math.max(0, usage.input - usage.read - usage.write); + if (usage.read > 0) cohort.hitRequests += 1; + if (usage.write > 0) cohort.writeRequests += 1; + totals.reportedSuccess += 1; + totals.input += usage.input; + totals.read += usage.read; + totals.write += usage.write; +} + +/** Validate a row observation and add it to the matching cohort and cache-shape bucket. */ +function recordCacheShape( + buckets: Map, + key: string, + dimensions: CohortDimensions, + row: Record, +): void { + const observation = normalizePromptCacheRequestObservation(row.promptCache); + if (!observation) return; + const shapeKey = JSON.stringify([key, cacheShapeKey(observation)]); + const existing = buckets.get(shapeKey); + if (existing) { + existing.rows.push(row); + return; + } + buckets.set(shapeKey, { dimensions, observation, rows: [row] }); +} + +/** Group selected rows into cohorts and shapes while accumulating valid usage totals. */ +function analyzeRows(rows: readonly Record[]): AnalysisState { + const cohorts = new Map(); + const shapeBuckets = new Map(); + const totals: AnalysisTotals = { + reportedSuccess: 0, + input: 0, + read: 0, + write: 0, + }; + + for (const row of rows) { + const dimensions = dimensionsFrom(row); + const key = dimensionsKey(dimensions); + const cohort = cohorts.get(key) ?? emptyCohort(dimensions); + cohorts.set(key, cohort); + cohort.requests += 1; + recordConversation(cohort, row); + recordCacheUsage(cohort, cacheUsage(row), totals); + recordCacheShape(shapeBuckets, key, dimensions, row); + } + + return { cohorts, shapeBuckets, totals }; +} + +/** Select cohorts with measured successes, ordered by descending input tokens and capped at top. */ +function topCohorts( + cohorts: Map, + top: number, +): CohortSummary[] { + return [...cohorts.values()] + .filter((cohort) => cohort.reportedSuccess > 0) + .sort((a, b) => b.input - a.input) + .slice(0, top) + .map(summarizeCohort); +} + +/** Select cache shapes with measured successes, ordered by descending input tokens and capped at top. */ +function topShapes( + buckets: Map, + top: number, +): ShapeSummary[] { + return [...buckets.values()] + .map(summarizeShape) + .filter((shape) => shape.reportedSuccess > 0) + .sort((a, b) => b.inputTokens - a.inputTokens) + .slice(0, top); +} + +/** Assemble window metadata, the measurement boundary, totals, and ranked summaries. */ +function buildOutput( + options: AnalyzerOptions, + since: number, + selectedRows: number, + invalidLines: number, + analysis: AnalysisState, +) { + const cohorts = topCohorts(analysis.cohorts, options.top); + const cacheShapes = topShapes(analysis.shapeBuckets, options.top); + const { reportedSuccess, input, read, write } = analysis.totals; + return { + source: options.source === "-" ? "stdin" : options.source, + range: options.range, + windowStartMs: since, + windowEndMs: options.nowMs, + windowStart: new Date(since).toISOString(), + windowEnd: new Date(options.nowMs).toISOString(), + rows: selectedRows, + invalidLines, + proofBoundary: "status=200 AND usageStatus=reported", + summary: { + reportedSuccess, + inputTokens: input, + cacheReadTokens: read, + cacheWriteTokens: write, + uncachedInputTokens: Math.max(0, input - read - write), + cacheReadRatio: ratio(read, input), + cacheWriteRatio: ratio(write, input), + }, + cohorts, + cacheShapes, + }; +} + +type AnalyzerOutput = ReturnType; + +/** Print the analysis window, aggregate usage, ranked cohorts, and cache shapes. */ +function printHumanOutput(output: AnalyzerOutput): void { + console.log("Prompt cache usage (" + output.range + ")"); + console.log("window: " + output.windowStart + " .. " + output.windowEnd); + console.log("proof: " + output.proofBoundary); + console.log( + "reported-success=" + + output.summary.reportedSuccess + + " input=" + + Math.round(output.summary.inputTokens) + + " read=" + + Math.round(output.summary.cacheReadTokens) + + " (" + + formatPercent(output.summary.cacheReadRatio) + + ")" + + " write=" + + Math.round(output.summary.cacheWriteTokens) + + " (" + + formatPercent(output.summary.cacheWriteRatio) + + ")", + ); + console.log(""); + console.log("Top cohorts by measured input:"); + for (const item of output.cohorts) { + console.log( + item.signal.padEnd(11) + + " " + + item.adapter + + "/" + + item.provider + + "/" + + item.model + + " surface=" + + item.surface + + " input=" + + item.inputTokens + + " read=" + + formatPercent(item.cacheReadRatio) + + " write=" + + formatPercent(item.cacheWriteRatio) + + " hits=" + + formatPercent(item.cacheHitRequestRatio) + + " n=" + + item.reportedSuccess + + "/" + + item.requests, + ); + } + printCacheShapes(output.cacheShapes); +} + +/** Print measured cache shapes or explain that the window contains no observations. */ +function printCacheShapes(shapes: readonly ShapeSummary[]): void { + console.log(""); + if (shapes.length === 0) { + console.log( + "No promptCache observations in this window (historical rows predate instrumentation).", + ); + return; + } + + console.log("Observed outbound cache shapes:"); + for (const item of shapes) { + console.log( + item.adapter + + "/" + + item.provider + + "/" + + item.model + + " surface=" + + item.surface + + " mode=" + + item.mode + + " tools=" + + item.toolCount + + " bp=" + + item.breakpointCount + + " input=" + + item.inputTokens + + " read=" + + formatPercent(item.cacheReadRatio) + + " write=" + + formatPercent(item.cacheWriteRatio) + + " n=" + + item.reportedSuccess + + "/" + + item.requests + + " prefix=" + + (item.stablePrefixFingerprint ?? "-") + + " toolsHash=" + + (item.toolsFingerprint ?? "-"), + ); + } +} + +/** Run the analyzer and return zero on success or help, or two for invalid CLI arguments. */ +function main(): number { + let options: AnalyzerOptions; + try { + options = parseArgs(Bun.argv.slice(2)); + } catch (error) { + const message = + error instanceof Error ? error.message : "invalid arguments"; + console.error(message); + console.error(usageText()); + return 2; + } + + if (options.help) { + console.log(usageText()); + return 0; + } + + const since = sinceFor(options.range, options.nowMs); + const parsed = parseUsageRows(readUsageSource(options)); + const selected = rowsInWindow(parsed.rows, since, options.nowMs); + const output = buildOutput( + options, + since, + selected.length, + parsed.invalidLines, + analyzeRows(selected), + ); + + if (options.jsonMode) { + process.stdout.write(JSON.stringify(output, null, 2) + "\n"); + return 0; + } + + printHumanOutput(output); + return 0; +} + +process.exitCode = main(); diff --git a/src/adapters/base.ts b/src/adapters/base.ts index 36fde6942..8cb49968e 100644 --- a/src/adapters/base.ts +++ b/src/adapters/base.ts @@ -1,5 +1,6 @@ import type { AdapterEvent, OcxParsedRequest } from "../types"; import type { UpstreamAttemptBudget } from "../lib/upstream-attempt-budget"; +import type { PromptCacheRequestObservation } from "../prompt-cache/observability"; /** Metadata about the caller's incoming request, for auth-forwarding adapters. */ export interface IncomingMeta { @@ -105,6 +106,8 @@ export interface AdapterRequest { inputTokens?: number; estimated?: boolean; }; + /** Structural prompt-cache diagnostics derived from the exact outbound body. */ + promptCacheLog?: PromptCacheRequestObservation; } export interface AdapterFetchContext { diff --git a/src/adapters/openai-responses.ts b/src/adapters/openai-responses.ts index 06506651e..b044bf415 100644 --- a/src/adapters/openai-responses.ts +++ b/src/adapters/openai-responses.ts @@ -9,6 +9,7 @@ import { decodeServerSentEvents } from "../lib/sse-decoder"; import { supportsNativeRemoteCompactionV2 } from "../providers/openai-tiers"; import { OCX_REASONING_PREFIX } from "../responses/reasoning-envelope"; import { modelRecordValue } from "../reasoning-effort"; +import { observeOpenAiResponsesPromptCache } from "../prompt-cache/observability"; // Headers relayed verbatim from the caller in OAuth-passthrough ("forward") mode. // Exported so the web-search sidecar reuses the exact same forwarded-auth set for its ChatGPT call. @@ -954,15 +955,17 @@ export function createResponsesPassthroughAdapter(provider: OcxProviderConfig): outBody = buildRoutedCompactionBody(outBody); } const sanitizedBody = stripSparkCompatibility(stripUnsupportedReasoningParams(stripItemIdsWhenUnstored(stripInvalidItemIds(stripUnsupportedHostedTools(sanitizeReasoningInputContent(scrubOcxCompactionItems(outBody))))))); + const finalBody = stripDisabledReasoningSummaries( + normalizeConfiguredReasoningSummaryDelivery(sanitizedBody, provider, parsed.modelId), + provider, + parsed.modelId, + ); return { url, method: "POST", headers, - body: JSON.stringify(stripDisabledReasoningSummaries( - normalizeConfiguredReasoningSummaryDelivery(sanitizedBody, provider, parsed.modelId), - provider, - parsed.modelId, - )), + body: JSON.stringify(finalBody), + promptCacheLog: observeOpenAiResponsesPromptCache(finalBody), }; }, diff --git a/src/prompt-cache/observability.ts b/src/prompt-cache/observability.ts new file mode 100644 index 000000000..edbec6a21 --- /dev/null +++ b/src/prompt-cache/observability.ts @@ -0,0 +1,318 @@ +import { createHash } from "node:crypto"; + +export type PromptCacheMode = "default" | "implicit" | "explicit"; +export type PromptCacheLegacyRetention = "in_memory" | "24h"; +export type PromptCacheVerbosity = "low" | "medium" | "high"; + +export interface PromptCacheRequestObservation { + version: 1; + keyPresent: boolean; + mode: PromptCacheMode; + ttl?: "30m"; + legacyRetention?: PromptCacheLegacyRetention; + prewarm: boolean; + comparisonRequested: boolean; + previousResponseIdPresent: boolean; + breakpointCount: number; + inputItemCount: number; + toolCount: number; + toolsFingerprint?: string; + stablePrefixFingerprint?: string; + textFormatFingerprint?: string; + verbosity?: PromptCacheVerbosity; +} + +/** Narrow a value to a non-null, non-array object before reading request fields. */ +function isRecord(value: unknown): value is Record { + return !!value && typeof value === "object" && !Array.isArray(value); +} + +/** + * Serialize JSON-compatible input with stable object-key ordering. + * Arrays retain their wire order and object keys such as "__proto__" remain ordinary data. + */ +function canonicalJson(value: unknown): string | undefined { + if (value === null) return "null"; + if (Array.isArray(value)) { + const items = value.map((item) => canonicalJson(item) ?? "null"); + return "[" + items.join(",") + "]"; + } + if (isRecord(value)) { + const fields: string[] = []; + for (const key of Object.keys(value).sort()) { + const child = canonicalJson(value[key]); + if (child === undefined) continue; + fields.push(JSON.stringify(key) + ":" + child); + } + return "{" + fields.join(",") + "}"; + } + if (typeof value === "number" && !Number.isFinite(value)) return "null"; + if ( + typeof value === "string" || + typeof value === "number" || + typeof value === "boolean" + ) { + return JSON.stringify(value); + } + return undefined; +} + +/** Hash canonical JSON to 24 lowercase hex characters, or return undefined for unsupported values. */ +function fingerprint(value: unknown): string | undefined { + const serialized = canonicalJson(value); + if (serialized === undefined) return undefined; + return createHash("sha256").update(serialized).digest("hex").slice(0, 24); +} + +/** Recursively count explicit prompt-cache breakpoints without descending into breakpoint metadata. */ +function countExplicitBreakpoints(value: unknown): number { + if (Array.isArray(value)) { + return value.reduce( + (total, item) => total + countExplicitBreakpoints(item), + 0, + ); + } + if (!isRecord(value)) return 0; + const breakpoint = value.prompt_cache_breakpoint; + let count = isRecord(breakpoint) && breakpoint.mode === "explicit" ? 1 : 0; + for (const [key, child] of Object.entries(value)) { + if (key === "prompt_cache_breakpoint") continue; + count += countExplicitBreakpoints(child); + } + return count; +} + +/** Collect instructions and consecutive leading developer/system messages for fingerprinting. */ +function stablePrefix(body: Record): unknown[] { + const prefix: unknown[] = []; + if (body.instructions !== undefined) { + prefix.push({ kind: "instructions", value: body.instructions }); + } + if (!Array.isArray(body.input)) return prefix; + + const initialDeveloperItems: unknown[] = []; + for (const item of body.input) { + if (!isRecord(item)) break; + if (item.role !== "developer" && item.role !== "system") break; + initialDeveloperItems.push(item); + } + if (initialDeveloperItems.length > 0) { + prefix.push({ + kind: "initial_developer_messages", + value: initialDeveloperItems, + }); + } + return prefix; +} + +/** Accept only supported verbosity labels so arbitrary caller text is omitted from diagnostics. */ +function promptCacheVerbosity( + value: unknown, +): PromptCacheVerbosity | undefined { + if (value === "low" || value === "medium" || value === "high") return value; + return undefined; +} + +/** Check for non-whitespace string content without retaining the string value. */ +function hasNonEmptyString(value: unknown): boolean { + return typeof value === "string" && value.trim().length > 0; +} + +/** Read a recognized outbound cache mode, falling back to default for absent or unknown values. */ +function promptCacheMode( + options: Record | undefined, +): PromptCacheMode { + if (options?.mode === "explicit") return "explicit"; + if (options?.mode === "implicit") return "implicit"; + return "default"; +} + +/** Extract the supported 30-minute TTL from outbound cache options. */ +function promptCacheTtl( + options: Record | undefined, +): PromptCacheRequestObservation["ttl"] { + return options?.ttl === "30m" ? "30m" : undefined; +} + +/** Accept only the supported legacy retention labels, omitting unknown values. */ +function promptCacheLegacyRetention( + value: unknown, +): PromptCacheLegacyRetention | undefined { + if (value === "in_memory" || value === "24h") return value; + return undefined; +} + +/** Count input-array items, treating absent input as zero and other input values as one. */ +function promptCacheInputItemCount(input: unknown): number { + if (Array.isArray(input)) return input.length; + return input === undefined ? 0 : 1; +} + +interface PromptCacheObservationExtras { + toolsFingerprint?: string; + stablePrefixFingerprint?: string; + textFormatFingerprint?: string; + verbosity?: PromptCacheVerbosity; +} + +/** Fingerprint present tools, stable prefix, and text format, and include supported verbosity. */ +function promptCacheObservationExtras(input: { + tools: unknown[]; + prefix: unknown[]; + textFormat: unknown; + verbosity: PromptCacheVerbosity | undefined; +}): PromptCacheObservationExtras { + const extras: PromptCacheObservationExtras = {}; + if (input.tools.length > 0) + extras.toolsFingerprint = fingerprint(input.tools); + if (input.prefix.length > 0) + extras.stablePrefixFingerprint = fingerprint(input.prefix); + if (input.textFormat !== undefined) { + extras.textFormatFingerprint = fingerprint(input.textFormat); + } + if (input.verbosity) extras.verbosity = input.verbosity; + return extras; +} + +/** + * Describe cache settings and request structure from the final outbound Responses body. + * Retain fingerprints and presence flags rather than raw content or cache keys. + * Return undefined for non-object input without changing the supplied body. + */ +export function observeOpenAiResponsesPromptCache( + value: unknown, +): PromptCacheRequestObservation | undefined { + if (!isRecord(value)) return undefined; + + const options = isRecord(value.prompt_cache_options) + ? value.prompt_cache_options + : undefined; + const ttl = promptCacheTtl(options); + const retention = promptCacheLegacyRetention(value.prompt_cache_retention); + const tools = Array.isArray(value.tools) ? value.tools : []; + const input = value.input; + const prefix = stablePrefix(value); + const text = isRecord(value.text) ? value.text : undefined; + const textFormat = text?.format; + const verbosity = promptCacheVerbosity(text?.verbosity); + + return { + version: 1, + keyPresent: hasNonEmptyString(value.prompt_cache_key), + mode: promptCacheMode(options), + ...(ttl ? { ttl } : {}), + ...(retention ? { legacyRetention: retention } : {}), + prewarm: options?.prewarm === true, + comparisonRequested: hasNonEmptyString(options?.comparison_response_id), + previousResponseIdPresent: hasNonEmptyString(value.previous_response_id), + breakpointCount: countExplicitBreakpoints(input), + inputItemCount: promptCacheInputItemCount(input), + toolCount: tools.length, + ...promptCacheObservationExtras({ tools, prefix, textFormat, verbosity }), + }; +} + +/** Check that a persisted fingerprint contains exactly 24 lowercase hexadecimal characters. */ +function isFingerprint(value: unknown): value is string { + return typeof value === "string" && /^[0-9a-f]{24}$/u.test(value); +} + +/** Accept persisted integer counts from zero through one million. */ +function isBoundedCount(value: unknown): value is number { + return ( + typeof value === "number" && + Number.isInteger(value) && + value >= 0 && + value <= 1_000_000 + ); +} + +interface PromptCacheObservationCore { + keyPresent: boolean; + prewarm: boolean; + comparisonRequested: boolean; + previousResponseIdPresent: boolean; + breakpointCount: number; + inputItemCount: number; + toolCount: number; +} + +/** Validate the required boolean flags and bounded counts of a persisted observation. */ +function hasPromptCacheObservationCore( + value: Record, +): value is Record & PromptCacheObservationCore { + return ( + typeof value.keyPresent === "boolean" && + typeof value.prewarm === "boolean" && + typeof value.comparisonRequested === "boolean" && + typeof value.previousResponseIdPresent === "boolean" && + isBoundedCount(value.breakpointCount) && + isBoundedCount(value.inputItemCount) && + isBoundedCount(value.toolCount) + ); +} + +/** Accept a persisted cache-mode label, returning undefined for unrecognized values. */ +function normalizedPromptCacheMode( + value: unknown, +): PromptCacheMode | undefined { + if (value === "default" || value === "implicit" || value === "explicit") + return value; + return undefined; +} + +/** Retain only the supported 30-minute TTL from a persisted observation. */ +function normalizedPromptCacheTtl( + value: unknown, +): PromptCacheRequestObservation["ttl"] { + return value === "30m" ? "30m" : undefined; +} + +/** Copy only well-formed fingerprints and supported verbosity from persisted metadata. */ +function normalizedPromptCacheExtras( + value: Record, +): PromptCacheObservationExtras { + const extras: PromptCacheObservationExtras = {}; + if (isFingerprint(value.toolsFingerprint)) { + extras.toolsFingerprint = value.toolsFingerprint; + } + if (isFingerprint(value.stablePrefixFingerprint)) { + extras.stablePrefixFingerprint = value.stablePrefixFingerprint; + } + if (isFingerprint(value.textFormatFingerprint)) { + extras.textFormatFingerprint = value.textFormatFingerprint; + } + const verbosity = promptCacheVerbosity(value.verbosity); + if (verbosity) extras.verbosity = verbosity; + return extras; +} + +/** + * Validate untrusted persisted metadata and rebuild an allowlisted version-1 observation. + * Reject invalid versions or required fields; omit unknown fields and invalid optional values. + */ +export function normalizePromptCacheRequestObservation( + value: unknown, +): PromptCacheRequestObservation | undefined { + if (!isRecord(value) || value.version !== 1) return undefined; + if (!hasPromptCacheObservationCore(value)) return undefined; + const mode = normalizedPromptCacheMode(value.mode); + if (!mode) return undefined; + + const ttl = normalizedPromptCacheTtl(value.ttl); + const legacyRetention = promptCacheLegacyRetention(value.legacyRetention); + return { + version: 1, + keyPresent: value.keyPresent, + mode, + ...(ttl ? { ttl } : {}), + ...(legacyRetention ? { legacyRetention } : {}), + prewarm: value.prewarm, + comparisonRequested: value.comparisonRequested, + previousResponseIdPresent: value.previousResponseIdPresent, + breakpointCount: value.breakpointCount, + inputItemCount: value.inputItemCount, + toolCount: value.toolCount, + ...normalizedPromptCacheExtras(value), + }; +} diff --git a/src/server/request-log.ts b/src/server/request-log.ts index 7693769ba..37db9d4da 100644 --- a/src/server/request-log.ts +++ b/src/server/request-log.ts @@ -39,6 +39,7 @@ import { } from "../usage/debug"; import { matchesLogConversationId } from "./request-log-conversation"; import { captureRequestTelemetry } from "../telemetry/posthog-server"; +import type { PromptCacheRequestObservation } from "../prompt-cache/observability"; export interface RequestLogContext { model: string; @@ -83,6 +84,8 @@ export interface RequestLogContext { /** Route adapter type ("cursor"/"kiro"/"anthropic"/…): drives estimated-usage detection * independent of the user-chosen provider NAME (devlog 130 B2). */ providerAdapter?: string; + /** Structural prompt-cache metadata captured from the exact outbound adapter body. */ + promptCache?: PromptCacheRequestObservation; /** * Stable store id for the OAuth account or key-pool entry that served this request. * Distinct from the display `account` label persisted on the usage row. @@ -113,6 +116,10 @@ export interface RequestLogEntry { timestamp: number; model: string; provider: string; + /** Adapter that produced the final upstream wire request. */ + adapter?: string; + /** Structural prompt-cache metadata captured from the exact outbound adapter body. */ + promptCache?: PromptCacheRequestObservation; /** Whether the client requested a streamed generation. */ stream?: boolean; /** TTFT: ms from request start to the first non-empty model output delta; unset for non-streaming/tool-only. */ @@ -277,6 +284,8 @@ export function requestLogEntryFromPersistedUsage(entry: PersistedUsageEntry): R timestamp: entry.timestamp, model: entry.model, provider: entry.provider, + ...(entry.adapter ? { adapter: entry.adapter } : {}), + ...(entry.promptCache ? { promptCache: { ...entry.promptCache } } : {}), ...(entry.firstOutputMs !== undefined ? { firstOutputMs: entry.firstOutputMs } : {}), ...(isKnownUsageSurface(entry.surface) ? { surface: entry.surface } : {}), ...(entry.conversationId ? { conversationId: entry.conversationId } : {}), @@ -394,6 +403,8 @@ export function addRequestLog(entry: RequestLogEntry) { timestamp: entry.timestamp, provider: entry.provider, model: entry.model, + ...(entry.adapter ? { adapter: entry.adapter } : {}), + ...(entry.promptCache ? { promptCache: { ...entry.promptCache } } : {}), ...(isKnownUsageSurface(entry.surface) ? { surface: entry.surface } : {}), ...(entry.conversationId ? { conversationId: entry.conversationId } : {}), ...(account ? { account } : {}), @@ -467,7 +478,7 @@ export function recordAttemptRequestedEffort(logCtx: RequestLogContext): void { } /** Copy the adapter's exact outbound reasoning parameter into the durable request log. */ -export function recordAdapterReasoning( +function recordAdapterReasoning( logCtx: RequestLogContext, request: AdapterRequest, ): void { @@ -517,6 +528,18 @@ export function recordAdapterReasoning( } } +/** Record all adapter-derived request diagnostics at one lifecycle seam. */ +export function recordAdapterRequestMetadata( + logCtx: RequestLogContext, + request: AdapterRequest, +): void { + recordAdapterReasoning(logCtx, request); + delete logCtx.promptCache; + if (request.promptCacheLog) { + logCtx.promptCache = { ...request.promptCacheLog }; + } +} + export function requestLogErrorCode(status: number, upstreamError?: string): string | undefined { if (status >= 200 && status < 400) return undefined; // Defense in depth: mid-stream web-search aborts used to land as 502 with this message. @@ -874,6 +897,9 @@ export function addFinalRequestLog( recoveryKinds: [...attempt.recoveryKinds], ...(attempt.usage ? { usage: { ...attempt.usage } } : {}), })); + const adapter = isCombo + ? attempts?.at(-1)?.adapter ?? logCtx.providerAdapter + : logCtx.providerAdapter; const aggregate = isCombo ? aggregateAttemptUsage(attempts ?? []) : null; const loggedUsage = aggregate?.usage ?? existing.usage; const usageStatus = aggregate?.status ?? existing.status; @@ -883,6 +909,8 @@ export function addFinalRequestLog( timestamp: start, model, provider, + ...(adapter ? { adapter } : {}), + ...(logCtx.promptCache ? { promptCache: { ...logCtx.promptCache } } : {}), ...(account ? { account } : {}), ...(providerAccountId ? { providerAccountId } : {}), ...(logCtx.surface ? { surface: logCtx.surface } : {}), diff --git a/src/server/responses/core.ts b/src/server/responses/core.ts index 0321ecbc7..9f4a9f699 100644 --- a/src/server/responses/core.ts +++ b/src/server/responses/core.ts @@ -147,7 +147,7 @@ import { inspectResponseLogJson, noteAttemptSend, readConfiguredCodexServiceTier, - recordAdapterReasoning, + recordAdapterRequestMetadata, recordAttemptRequestedEffort, requestLogSpeedLabel, sealRequestAttemptIdentity, @@ -398,7 +398,7 @@ async function retryCodexPoolOnAlternateAccount( } catch (err) { return { kind: "build-request-failed", response: resolveAdapterBuildRequestError(err, options.abortSignal) }; } - recordAdapterReasoning(logCtx, request); + recordAdapterRequestMetadata(logCtx, request); await firstResponse.body?.cancel().catch(() => undefined); options.onCodexAuthContextResolved?.(retryAuthCtx); @@ -1687,7 +1687,7 @@ export async function handleResponses( } catch (err) { return resolveAdapterBuildRequestError(err, options.abortSignal); } - recordAdapterReasoning(logCtx, request); + recordAdapterRequestMetadata(logCtx, request); const passthroughEstimate = typeof request.usageLog?.inputTokens === "number" ? request.usageLog.inputTokens : undefined; @@ -2125,7 +2125,7 @@ export async function handleResponses( connectTimeoutMs: config.connectTimeoutMs ?? 200_000, stallTimeoutSec: config.stallTimeoutSec, fetchImpl: providerFetch(route.provider), - onRequestBuilt: request => recordAdapterReasoning(logCtx, request), + onRequestBuilt: request => recordAdapterRequestMetadata(logCtx, request), ...(vidPlan?.timeoutMs ? { videoTimeoutMs: vidPlan.timeoutMs } : {}), onUsage: usage => { // Cursor may assign _cursorConversationId inside the image loop's first runTurn; @@ -2208,7 +2208,7 @@ export async function handleResponses( forceEmptyResponseId: true, abortSignal: options.abortSignal, ...(options.onFirstOutput ? { onFirstOutput: options.onFirstOutput } : {}), - onRequestBuilt: request => recordAdapterReasoning(logCtx, request), + onRequestBuilt: request => recordAdapterRequestMetadata(logCtx, request), onUsage: usage => { logCtx.usageFromBridge = true; if (usage) { @@ -2487,7 +2487,7 @@ export async function handleResponses( cleanupUpstreamAbort(); return resolveAdapterBuildRequestError(err, options.abortSignal); } - recordAdapterReasoning(logCtx, request); + recordAdapterRequestMetadata(logCtx, request); const inputTokenEstimate = typeof request.usageLog?.inputTokens === "number" ? request.usageLog.inputTokens : undefined; @@ -2563,7 +2563,7 @@ export async function handleResponses( cleanupUpstreamAbort(); return { failed: resolveAdapterBuildRequestError(err, options.abortSignal) }; } - recordAdapterReasoning(logCtx, retryRequest); + recordAdapterRequestMetadata(logCtx, retryRequest); const retryEstimate = typeof retryRequest.usageLog?.inputTokens === "number" ? retryRequest.usageLog.inputTokens : undefined; @@ -2907,7 +2907,7 @@ export async function handleResponses( }; return; } - recordAdapterReasoning(logCtx, continuationRequest); + recordAdapterRequestMetadata(logCtx, continuationRequest); const continuationEstimate = typeof continuationRequest.usageLog?.inputTokens === "number" ? continuationRequest.usageLog.inputTokens : undefined; diff --git a/src/usage/log.ts b/src/usage/log.ts index f37166115..57e720be1 100644 --- a/src/usage/log.ts +++ b/src/usage/log.ts @@ -4,6 +4,10 @@ import { getConfigDir } from "../config"; import { recordOwnedConfigPath } from "../lib/config-ownership"; import { usageDisplayTotalTokens } from "./totals"; import type { OcxUsage } from "../types"; +import { + normalizePromptCacheRequestObservation, + type PromptCacheRequestObservation, +} from "../prompt-cache/observability"; export type UsageStatus = "reported" | "unreported" | "unsupported" | "estimated"; @@ -50,6 +54,10 @@ export interface PersistedUsageEntry { timestamp: number; provider: string; model: string; + /** Adapter that produced the final upstream wire request. */ + adapter?: string; + /** Structural prompt-cache metadata from the final outbound request. */ + promptCache?: PromptCacheRequestObservation; surface?: "claude" | "claude-desktop" | "codex" | "grok"; /** Best-effort chat/session correlation for Logs grouping (#330). */ conversationId?: string; @@ -297,11 +305,16 @@ function capMetadataString(s: string): string { */ function normalizeUsageEntry(entry: PersistedUsageEntry): PersistedUsageEntry { const attempts = normalizedAttempts(entry.attempts); + const promptCache = normalizePromptCacheRequestObservation(entry.promptCache); return { requestId: entry.requestId, timestamp: entry.timestamp, provider: entry.provider, model: entry.model, + ...(typeof entry.adapter === "string" && entry.adapter.trim() + ? { adapter: capMetadataString(entry.adapter.trim()) } + : {}), + ...(promptCache ? { promptCache } : {}), ...(isKnownUsageSurface(entry.surface) ? { surface: entry.surface } : {}), ...(typeof entry.conversationId === "string" && entry.conversationId.trim() ? { conversationId: entry.conversationId.trim().slice(0, 128) } diff --git a/tests/openai-responses-passthrough.test.ts b/tests/openai-responses-passthrough.test.ts index fe7128bf5..4f9742449 100644 --- a/tests/openai-responses-passthrough.test.ts +++ b/tests/openai-responses-passthrough.test.ts @@ -416,6 +416,54 @@ describe("OpenAI Responses passthrough sanitization", () => { expect(body.prompt_cache_retention).toBe("24h"); }); + test("records structural prompt-cache metadata from the final outbound body", () => { + const adapter = createResponsesPassthroughAdapter(provider); + const request = adapter.buildRequest({ + modelId: "gpt-5.6-terra", + context: { messages: [] }, + stream: true, + options: { promptCacheKey: "private-cache-key" }, + _rawBody: { + model: "gpt-5.6-terra", + instructions: "private fixed instruction", + prompt_cache_key: "private-cache-key", + prompt_cache_options: { mode: "implicit", ttl: "30m" }, + text: { verbosity: "medium", format: { type: "text" } }, + tools: [{ type: "function", name: "shell", parameters: { type: "object" } }], + input: [{ + role: "developer", + content: [{ + type: "input_text", + text: "private developer text", + prompt_cache_breakpoint: { mode: "explicit" }, + }], + }, { + role: "user", + content: [{ type: "input_text", text: "private user text" }], + }], + }, + }, { headers: new Headers({ authorization: "Bearer token" }) }); + + expect(request.promptCacheLog).toMatchObject({ + version: 1, + keyPresent: true, + mode: "implicit", + ttl: "30m", + breakpointCount: 1, + inputItemCount: 2, + toolCount: 1, + verbosity: "medium", + }); + expect(request.promptCacheLog?.toolsFingerprint).toMatch(/^[0-9a-f]{24}$/); + expect(request.promptCacheLog?.stablePrefixFingerprint).toMatch(/^[0-9a-f]{24}$/); + expect(JSON.stringify(request.promptCacheLog)).not.toContain("private-cache-key"); + expect(JSON.stringify(request.promptCacheLog)).not.toContain("private developer text"); + expect(JSON.parse(request.body)).toMatchObject({ + prompt_cache_key: "private-cache-key", + prompt_cache_options: { mode: "implicit", ttl: "30m" }, + }); + }); + const expandedRawBody = { model: "gpt-5.5", previous_response_id: "resp_1", diff --git a/tests/prompt-cache-analyzer.test.ts b/tests/prompt-cache-analyzer.test.ts new file mode 100644 index 000000000..e97f67f02 --- /dev/null +++ b/tests/prompt-cache-analyzer.test.ts @@ -0,0 +1,193 @@ +import { afterEach, describe, expect, test } from "bun:test"; +import { mkdtempSync, rmSync, writeFileSync } from "node:fs"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; + +const script = join(import.meta.dir, "../scripts/analyze-prompt-cache-usage.ts"); +const tempDirs: string[] = []; + +function tempUsageFile(lines: unknown[]): string { + const dir = mkdtempSync(join(tmpdir(), "ocx-cache-analyzer-")); + tempDirs.push(dir); + const path = join(dir, "usage.jsonl"); + writeFileSync(path, lines.map(line => JSON.stringify(line)).join("\n") + "\n"); + return path; +} + +function run(path: string, ...args: string[]) { + return Bun.spawnSync([process.execPath, script, path, ...args], { + stdout: "pipe", + stderr: "pipe", + }); +} + +afterEach(() => { + for (const dir of tempDirs.splice(0)) { + rmSync(dir, { recursive: true, force: true }); + } +}); + +describe("prompt-cache usage analyzer", () => { + test("is reproducible with --now and keeps cache-shape cohort dimensions", () => { + const path = tempUsageFile([ + { + requestId: "r1", + timestamp: Date.parse("2026-10-02T10:00:00Z"), + provider: "openai", + adapter: "openai-responses", + model: "gpt-5.6-terra", + resolvedModel: "gpt-5.6-terra", + surface: "codex", + status: 200, + usageStatus: "reported", + usage: { + inputTokens: 100, + outputTokens: 1, + cacheReadInputTokens: 80, + }, + promptCache: { + version: 1, + keyPresent: false, + mode: "implicit", + ttl: "30m", + prewarm: false, + comparisonRequested: false, + previousResponseIdPresent: false, + breakpointCount: 0, + inputItemCount: 2, + toolCount: 1, + toolsFingerprint: "0123456789abcdef01234567", + stablePrefixFingerprint: "89abcdef0123456789abcdef", + }, + }, + { + requestId: "r2", + timestamp: Date.parse("2026-10-02T11:00:00Z"), + provider: "openai", + adapter: "openai-responses", + model: "gpt-5.6-terra", + resolvedModel: "gpt-5.6-terra", + surface: "codex", + status: 200, + usageStatus: "reported", + usage: { + inputTokens: 200, + outputTokens: 1, + cacheReadInputTokens: 160, + }, + promptCache: { + version: 1, + keyPresent: false, + mode: "implicit", + ttl: "30m", + prewarm: false, + comparisonRequested: false, + previousResponseIdPresent: false, + breakpointCount: 0, + inputItemCount: 3, + toolCount: 1, + toolsFingerprint: "0123456789abcdef01234567", + stablePrefixFingerprint: "89abcdef0123456789abcdef", + }, + }, + { + requestId: "old", + timestamp: Date.parse("2026-09-20T10:00:00Z"), + provider: "openai", + adapter: "openai-responses", + model: "gpt-5.6-terra", + status: 200, + usageStatus: "reported", + usage: { inputTokens: 999, outputTokens: 1, cacheReadInputTokens: 999 }, + }, + ]); + + const args = ["--range=7d", "--now=2026-10-03T12:00:00Z", "--json"]; + const first = run(path, ...args); + const second = run(path, ...args); + + expect(first.exitCode).toBe(0); + expect(second.exitCode).toBe(0); + expect(first.stdout.toString()).toBe(second.stdout.toString()); + + const output = JSON.parse(first.stdout.toString()); + expect(output.windowEnd).toBe("2026-10-03T12:00:00.000Z"); + expect(output.summary).toMatchObject({ + reportedSuccess: 2, + inputTokens: 300, + cacheReadTokens: 240, + cacheReadRatio: 0.8, + }); + expect(output.cacheShapes).toEqual([ + expect.objectContaining({ + adapter: "openai-responses", + provider: "openai", + model: "gpt-5.6-terra", + surface: "codex", + mode: "implicit", + ttl: "30m", + requests: 2, + reportedSuccess: 2, + }), + ]); + }); + + test("does not treat malformed explicit cache-read usage as legacy cache data", () => { + const path = tempUsageFile([ + { + requestId: "malformed-explicit", + timestamp: Date.parse("2026-10-02T10:00:00Z"), + provider: "openai", + model: "gpt-5.6-terra", + status: 200, + usageStatus: "reported", + usage: { + inputTokens: 100, + outputTokens: 1, + cacheReadInputTokens: "not-a-number", + cachedInputTokens: 90, + }, + }, + { + requestId: "legacy-valid", + timestamp: Date.parse("2026-10-02T11:00:00Z"), + provider: "openai", + model: "gpt-5.6-terra", + status: 200, + usageStatus: "reported", + usage: { + inputTokens: 100, + outputTokens: 1, + cachedInputTokens: 60, + }, + }, + ]); + + const result = run( + path, + "--range=7d", + "--now=2026-10-03T12:00:00Z", + "--json", + ); + expect(result.exitCode).toBe(0); + const output = JSON.parse(result.stdout.toString()); + expect(output.rows).toBe(2); + expect(output.summary).toMatchObject({ + reportedSuccess: 1, + inputTokens: 100, + cacheReadTokens: 60, + cacheReadRatio: 0.6, + }); + }); + + test("rejects invalid CLI arguments instead of silently changing the analysis", () => { + const path = tempUsageFile([]); + const invalidRange = run(path, "--range=week"); + expect(invalidRange.exitCode).toBe(2); + expect(invalidRange.stderr.toString()).toContain("invalid --range value: week"); + + const unknown = run(path, "--bogus"); + expect(unknown.exitCode).toBe(2); + expect(unknown.stderr.toString()).toContain("unknown option: --bogus"); + }); +}); diff --git a/tests/prompt-cache-observability.test.ts b/tests/prompt-cache-observability.test.ts new file mode 100644 index 000000000..a0d246dda --- /dev/null +++ b/tests/prompt-cache-observability.test.ts @@ -0,0 +1,240 @@ +import { describe, expect, test } from "bun:test"; +import { mkdtempSync, readFileSync, rmSync } from "node:fs"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; +import { createResponsesPassthroughAdapter } from "../src/adapters/openai-responses"; +import { + normalizePromptCacheRequestObservation, + observeOpenAiResponsesPromptCache, +} from "../src/prompt-cache/observability"; +import { + addFinalRequestLog, + clearRequestLogsForTests, + recordAdapterRequestMetadata, + type RequestLogContext, +} from "../src/server/request-log"; +import { + readUsageEntries, + resetUsageReadCacheForTests, + usageLogPath, +} from "../src/usage/log"; +import type { OcxProviderConfig } from "../src/types"; + +describe("prompt cache observability", () => { + test("captures structural cache dimensions without retaining request content", () => { + const observation = observeOpenAiResponsesPromptCache({ + model: "gpt-5.6-terra", + instructions: "private instruction marker", + prompt_cache_key: "private-cache-key", + prompt_cache_options: { + mode: "implicit", + ttl: "30m", + prewarm: true, + comparison_response_id: "resp_private", + }, + previous_response_id: "resp_previous", + text: { + verbosity: "medium", + format: { type: "json_schema", name: "private-format" }, + }, + tools: [{ + type: "function", + name: "lookup_private_tool", + parameters: { type: "object", properties: { secret: { type: "string" } } }, + }], + input: [{ + role: "developer", + content: [{ + type: "input_text", + text: "private developer prefix", + prompt_cache_breakpoint: { mode: "explicit" }, + }], + }, { + role: "user", + content: [{ type: "input_text", text: "private user content" }], + }], + }); + + expect(observation).toMatchObject({ + version: 1, + keyPresent: true, + mode: "implicit", + ttl: "30m", + prewarm: true, + comparisonRequested: true, + previousResponseIdPresent: true, + breakpointCount: 1, + inputItemCount: 2, + toolCount: 1, + verbosity: "medium", + }); + expect(observation?.toolsFingerprint).toMatch(/^[0-9a-f]{24}$/); + expect(observation?.stablePrefixFingerprint).toMatch(/^[0-9a-f]{24}$/); + expect(observation?.textFormatFingerprint).toMatch(/^[0-9a-f]{24}$/); + const serialized = JSON.stringify(observation); + expect(serialized).not.toContain("private-cache-key"); + expect(serialized).not.toContain("private instruction marker"); + expect(serialized).not.toContain("private developer prefix"); + expect(serialized).not.toContain("private user content"); + expect(serialized).not.toContain("lookup_private_tool"); + expect(serialized).not.toContain("private-format"); + }); + + test("only persists supported Responses verbosity values", () => { + expect(observeOpenAiResponsesPromptCache({ + text: { verbosity: "low" }, + })?.verbosity).toBe("low"); + expect(observeOpenAiResponsesPromptCache({ + text: { verbosity: "medium" }, + })?.verbosity).toBe("medium"); + expect(observeOpenAiResponsesPromptCache({ + text: { verbosity: "high" }, + })?.verbosity).toBe("high"); + + const unsupported = observeOpenAiResponsesPromptCache({ + text: { verbosity: "private caller-controlled marker" }, + }); + expect(unsupported).not.toHaveProperty("verbosity"); + expect(normalizePromptCacheRequestObservation({ + ...unsupported, + verbosity: "private persisted marker", + })).not.toHaveProperty("verbosity"); + }); + + test("fingerprints are stable for object-key order but preserve tool array order", () => { + const a = observeOpenAiResponsesPromptCache({ + instructions: "stable", + tools: [ + { type: "function", name: "a", parameters: { type: "object", properties: { x: { type: "string" } } } }, + { type: "function", name: "b", parameters: { type: "object" } }, + ], + }); + const same = observeOpenAiResponsesPromptCache({ + tools: [ + { name: "a", parameters: { properties: { x: { type: "string" } }, type: "object" }, type: "function" }, + { parameters: { type: "object" }, name: "b", type: "function" }, + ], + instructions: "stable", + }); + const reordered = observeOpenAiResponsesPromptCache({ + instructions: "stable", + tools: [ + { type: "function", name: "b", parameters: { type: "object" } }, + { type: "function", name: "a", parameters: { type: "object", properties: { x: { type: "string" } } } }, + ], + }); + + expect(a?.toolsFingerprint).toBe(same?.toolsFingerprint); + expect(a?.stablePrefixFingerprint).toBe(same?.stablePrefixFingerprint); + expect(a?.toolsFingerprint).not.toBe(reordered?.toolsFingerprint); + }); + + test("preserves __proto__ as ordinary schema data when fingerprinting", () => { + const firstTool: unknown = JSON.parse( + '{"type":"function","name":"x","parameters":{"type":"object","properties":{"__proto__":{"const":"a"}}}}', + ); + const secondTool: unknown = JSON.parse( + '{"type":"function","name":"x","parameters":{"type":"object","properties":{"__proto__":{"const":"b"}}}}', + ); + + const first = observeOpenAiResponsesPromptCache({ tools: [firstTool] }); + const second = observeOpenAiResponsesPromptCache({ tools: [secondTool] }); + + expect(first?.toolsFingerprint).toMatch(/^[0-9a-f]{24}$/); + expect(second?.toolsFingerprint).toMatch(/^[0-9a-f]{24}$/); + expect(first?.toolsFingerprint).not.toBe(second?.toolsFingerprint); + }); + + test("normalizer accepts generated observations and rejects malformed persisted data", () => { + const observation = observeOpenAiResponsesPromptCache({ + prompt_cache_options: { mode: "explicit", ttl: "30m" }, + input: [{ content: [{ prompt_cache_breakpoint: { mode: "explicit" } }] }], + }); + expect(normalizePromptCacheRequestObservation(observation)).toEqual(observation); + expect(normalizePromptCacheRequestObservation({ + ...observation, + breakpointCount: -1, + })).toBeUndefined(); + expect(normalizePromptCacheRequestObservation({ + version: 1, + keyPresent: true, + mode: "invalid", + prewarm: false, + comparisonRequested: false, + previousResponseIdPresent: false, + breakpointCount: 0, + inputItemCount: 0, + toolCount: 0, + })).toBeUndefined(); + }); + + test("flows the final outbound observation through request logging into usage.jsonl", () => { + const dir = mkdtempSync(join(tmpdir(), "ocx-cache-observation-")); + const previousHome = process.env.OPENCODEX_HOME; + process.env.OPENCODEX_HOME = dir; + resetUsageReadCacheForTests(); + clearRequestLogsForTests(); + + try { + const provider: OcxProviderConfig = { + adapter: "openai-responses", + baseUrl: "https://api.openai.com/v1", + authMode: "key", + apiKey: "test-key", + }; + const adapter = createResponsesPassthroughAdapter(provider); + const request = adapter.buildRequest({ + modelId: "gpt-5.6-terra", + context: { messages: [] }, + stream: true, + options: { promptCacheKey: "private-cache-key" }, + _rawBody: { + model: "gpt-5.6-terra", + instructions: "private fixed prefix", + input: [{ role: "user", content: "hello" }], + tools: [{ type: "function", name: "shell", parameters: { type: "object" } }], + prompt_cache_key: "private-cache-key", + prompt_cache_options: { mode: "implicit", ttl: "30m" }, + }, + }); + const logCtx: RequestLogContext = { + model: "gpt-5.6-terra", + provider: "openai-apikey", + providerAdapter: adapter.name, + usage: { + inputTokens: 100, + outputTokens: 5, + cacheReadInputTokens: 80, + }, + }; + recordAdapterRequestMetadata(logCtx, request); + addFinalRequestLog("ocx-cache-e2e", 1_000, logCtx, 200); + + const entries = readUsageEntries(); + expect(entries).toHaveLength(1); + expect(entries[0]).toMatchObject({ + requestId: "ocx-cache-e2e", + adapter: "openai-responses", + usageStatus: "reported", + usage: { inputTokens: 100, cacheReadInputTokens: 80 }, + promptCache: { + version: 1, + keyPresent: true, + mode: "implicit", + ttl: "30m", + toolCount: 1, + }, + }); + const persisted = readFileSync(usageLogPath(), "utf8"); + expect(persisted).not.toContain("private-cache-key"); + expect(persisted).not.toContain("private fixed prefix"); + expect(persisted).not.toContain("\"shell\""); + } finally { + clearRequestLogsForTests(); + resetUsageReadCacheForTests(); + if (previousHome === undefined) delete process.env.OPENCODEX_HOME; + else process.env.OPENCODEX_HOME = previousHome; + rmSync(dir, { recursive: true, force: true }); + } + }); +}); diff --git a/tests/request-log.test.ts b/tests/request-log.test.ts index 90fcb5179..04d562e71 100644 --- a/tests/request-log.test.ts +++ b/tests/request-log.test.ts @@ -20,7 +20,7 @@ import { getRequestLogEntries, hydrateRequestLogsFromDisk, noteAttemptSend, - recordAdapterReasoning, + recordAdapterRequestMetadata, recordFirstOutput, requestLogEntryFromPersistedUsage, sealRequestAttemptIdentity, @@ -120,7 +120,7 @@ describe("request log metadata", () => { activeAttempt: attempt, }; - recordAdapterReasoning(logCtx, { + recordAdapterRequestMetadata(logCtx, { url: "https://api.x.ai/v1/chat/completions", method: "POST", headers: {}, @@ -146,7 +146,7 @@ describe("request log metadata", () => { }); const sensitiveAlias = ["sk", "proj", "redaction-fixture"].join("-"); - recordAdapterReasoning(logCtx, { + recordAdapterRequestMetadata(logCtx, { url: "https://provider.test/v1/chat/completions", method: "POST", headers: {}, @@ -163,6 +163,59 @@ describe("request log metadata", () => { expect(attempt.reasoningWireValue).not.toContain("redaction-fixture"); }); + test("records and replaces outbound prompt-cache metadata at the adapter seam", () => { + const logCtx: RequestLogContext = { + model: "gpt-5.6-terra", + provider: "openai", + promptCache: { + version: 1, + keyPresent: false, + mode: "default", + prewarm: false, + comparisonRequested: false, + previousResponseIdPresent: false, + breakpointCount: 0, + inputItemCount: 0, + toolCount: 0, + }, + }; + + recordAdapterRequestMetadata(logCtx, { + url: "https://api.openai.com/v1/responses", + method: "POST", + headers: {}, + body: "{}", + promptCacheLog: { + version: 1, + keyPresent: true, + mode: "implicit", + ttl: "30m", + prewarm: false, + comparisonRequested: false, + previousResponseIdPresent: true, + breakpointCount: 1, + inputItemCount: 3, + toolCount: 2, + toolsFingerprint: "0123456789abcdef01234567", + }, + }); + expect(logCtx.promptCache).toMatchObject({ + keyPresent: true, + mode: "implicit", + previousResponseIdPresent: true, + breakpointCount: 1, + toolCount: 2, + }); + + recordAdapterRequestMetadata(logCtx, { + url: "https://strict-provider.test/v1/responses", + method: "POST", + headers: {}, + body: "{}", + }); + expect(logCtx.promptCache).toBeUndefined(); + }); + test("malformed adapter reasoning metadata never interrupts request logging", () => { const malformed = [ { effectiveEffort: 123, wireField: "reasoning_effort", wireValue: 123 }, @@ -193,7 +246,7 @@ describe("request log metadata", () => { reasoningWireValue: "stale", }); - expect(() => recordAdapterReasoning(logCtx, { + expect(() => recordAdapterRequestMetadata(logCtx, { url: "https://provider.test/v1/chat/completions", method: "POST", headers: {}, @@ -317,7 +370,7 @@ describe("request log metadata", () => { test("final combo logging keeps one logical row and finalizes its active attempt", () => { const entries: RequestLogEntry[] = []; const a = beginRequestAttempt(1, "a", "model-a", "openai-chat"); - recordAdapterReasoning({ + recordAdapterRequestMetadata({ model: "model-a", provider: "a", requestedEffort: "minimal", @@ -355,7 +408,7 @@ describe("request log metadata", () => { activeAttempt: b, activeAttemptStartedAt: start, }; - recordAdapterReasoning(logCtx, { + recordAdapterRequestMetadata(logCtx, { url: "https://provider.test/v1/chat/completions", method: "POST", headers: {}, diff --git a/tests/usage-log.test.ts b/tests/usage-log.test.ts index 487ad2d02..a3929b7a4 100644 --- a/tests/usage-log.test.ts +++ b/tests/usage-log.test.ts @@ -102,6 +102,60 @@ describe("usage log", () => { })]); }); + test("persists adapter and bounded prompt-cache observations", () => { + appendUsageEntry({ + requestId: "ocx-cache-observation", + timestamp: 1, + provider: "openai", + model: "gpt-5.6-terra", + adapter: "openai-responses", + promptCache: { + version: 1, + keyPresent: true, + mode: "implicit", + ttl: "30m", + prewarm: false, + comparisonRequested: false, + previousResponseIdPresent: false, + breakpointCount: 0, + inputItemCount: 2, + toolCount: 1, + toolsFingerprint: "0123456789abcdef01234567", + stablePrefixFingerprint: "89abcdef0123456789abcdef", + }, + status: 200, + durationMs: 1, + usageStatus: "reported", + usage: { inputTokens: 100, outputTokens: 1, cacheReadInputTokens: 80 }, + totalTokens: 101, + }); + expect(readUsageEntries()).toEqual([expect.objectContaining({ + adapter: "openai-responses", + promptCache: expect.objectContaining({ + mode: "implicit", + ttl: "30m", + toolCount: 1, + toolsFingerprint: "0123456789abcdef01234567", + }), + })]); + }); + + test("drops malformed prompt-cache observations from hand-edited logs", () => { + writeFileSync(usageLogPath(), JSON.stringify({ + requestId: "bad-cache-shape", + timestamp: 1, + provider: "openai", + model: "gpt-5.6-terra", + adapter: "openai-responses", + promptCache: { version: 1, mode: "implicit", keyPresent: true }, + status: 200, + durationMs: 1, + usageStatus: "reported", + usage: { inputTokens: 1, outputTokens: 1 }, + }) + "\n"); + expect(readUsageEntries()[0]).not.toHaveProperty("promptCache"); + }); + test("persists providerAccountId separately from the display account label", () => { appendUsageEntry({ requestId: "ocx-account-id",