More comprehensive prompt cache debugging logs

Author: jahooma

common/src/types/contracts/llm.ts

@@ -40,7 +40,13 @@ export type PromptAiSdkStreamFn = (
     agentId?: string
     maxRetries?: number
     onCostCalculated?: (credits: number) => Promise<void>
+    onCacheDebugProviderRequestBuilt?: (params: {
+      provider: string
+      rawBody: unknown
+      normalizedBody?: unknown
+    }) => void
     includeCacheControl?: boolean
+    cacheDebugCorrelation?: string
     agentProviderOptions?: OpenRouterProviderRoutingOptions
     /** List of agents that can be spawned - used to transform agent tool calls */
     spawnableAgents?: string[]
@@ -68,7 +74,13 @@ export type PromptAiSdkFn = (
     chargeUser?: boolean
     agentId?: string
     onCostCalculated?: (credits: number) => Promise<void>
+    onCacheDebugProviderRequestBuilt?: (params: {
+      provider: string
+      rawBody: unknown
+      normalizedBody?: unknown
+    }) => void
     includeCacheControl?: boolean
+    cacheDebugCorrelation?: string
     agentProviderOptions?: OpenRouterProviderRoutingOptions
     maxRetries?: number
     /** Cost mode - 'free' mode means 0 credits charged for all agents */
@@ -97,7 +109,13 @@ export type PromptAiSdkStructuredInput<T> = {
   chargeUser?: boolean
   agentId?: string
   onCostCalculated?: (credits: number) => Promise<void>
+  onCacheDebugProviderRequestBuilt?: (params: {
+    provider: string
+    rawBody: unknown
+    normalizedBody?: unknown
+  }) => void
   includeCacheControl?: boolean
+  cacheDebugCorrelation?: string
   agentProviderOptions?: OpenRouterProviderRoutingOptions
   maxRetries?: number
   sendAction: SendActionFn

common/src/util/cache-debug.ts

@@ -0,0 +1,168 @@
+import type { JSONValue } from '../types/json'
+
+type SerializableValue = JSONValue
+
+type SerializableRecord = Record<string, SerializableValue>
+
+export type CacheDebugCorrelation = {
+  projectRoot: string
+  filename: string
+  snapshotId: string
+}
+
+function normalizeForJson(value: unknown): SerializableValue {
+  if (
+    value === null ||
+    typeof value === 'string' ||
+    typeof value === 'number' ||
+    typeof value === 'boolean'
+  ) {
+    return value
+  }
+
+  if (value instanceof URL) {
+    return value.toString()
+  }
+
+  if (value instanceof Uint8Array) {
+    return {
+      type: 'Uint8Array',
+      byteLength: value.byteLength,
+    }
+  }
+
+  if (Array.isArray(value)) {
+    return value.map((item) => normalizeForJson(item))
+  }
+
+  if (typeof value === 'object') {
+    return Object.fromEntries(
+      Object.entries(value as Record<string, unknown>).map(([key, entryValue]) => [
+        key,
+        normalizeForJson(entryValue),
+      ]),
+    )
+  }
+
+  return String(value)
+}
+
+function summarizeDataUrl(value: string): SerializableValue {
+  const firstComma = value.indexOf(',')
+  const header = firstComma >= 0 ? value.slice(0, firstComma) : value
+  const payload = firstComma >= 0 ? value.slice(firstComma + 1) : ''
+  return {
+    type: 'data-url',
+    mediaType: header.slice(5).split(';')[0] || 'unknown',
+    payloadLength: payload.length,
+    preview: payload.slice(0, 32),
+  }
+}
+
+function summarizeLargeValue(value: SerializableValue): SerializableValue {
+  if (Array.isArray(value)) {
+    return value.map((item) => summarizeLargeValue(item))
+  }
+
+  if (!value || typeof value !== 'object') {
+    if (typeof value === 'string' && value.startsWith('data:')) {
+      return summarizeDataUrl(value)
+    }
+    return value
+  }
+
+  if ('url' in value && typeof value.url === 'string' && value.url.startsWith('data:')) {
+    return {
+      ...value,
+      url: summarizeDataUrl(value.url),
+    }
+  }
+
+  return Object.fromEntries(
+    Object.entries(value).map(([key, entryValue]) => {
+      if (key === 'file_data' && typeof entryValue === 'string' && entryValue.startsWith('data:')) {
+        return [key, summarizeDataUrl(entryValue)]
+      }
+      if (key === 'arguments' && typeof entryValue === 'string') {
+        return [key, entryValue]
+      }
+      return [key, summarizeLargeValue(entryValue)]
+    }),
+  )
+}
+
+function parseRequestBody(body: unknown): unknown {
+  if (typeof body !== 'string') {
+    return body
+  }
+
+  try {
+    return JSON.parse(body)
+  } catch {
+    return body
+  }
+}
+
+export function serializeCacheDebugCorrelation(
+  correlation: CacheDebugCorrelation,
+): string {
+  return JSON.stringify(correlation)
+}
+
+export function parseCacheDebugCorrelation(
+  value: unknown,
+): CacheDebugCorrelation | undefined {
+  if (typeof value !== 'string') {
+    return undefined
+  }
+
+  try {
+    const parsed = JSON.parse(value) as Partial<CacheDebugCorrelation>
+    if (
+      typeof parsed.projectRoot === 'string' &&
+      typeof parsed.filename === 'string' &&
+      typeof parsed.snapshotId === 'string'
+    ) {
+      return {
+        projectRoot: parsed.projectRoot,
+        filename: parsed.filename,
+        snapshotId: parsed.snapshotId,
+      }
+    }
+  } catch {
+    return undefined
+  }
+
+  return undefined
+}
+
+export function normalizeProviderRequestBodyForCacheDebug(params: {
+  provider: string
+  body: unknown
+}): SerializableValue {
+  const parsed = parseRequestBody(params.body)
+  const body = normalizeForJson(parsed)
+
+  if (!body || typeof body !== 'object' || Array.isArray(body)) {
+    return body
+  }
+
+  const record = body as SerializableRecord
+  const normalized: SerializableRecord = {}
+
+  for (const key of ['model', 'messages', 'tools', 'tool_choice', 'response_format', 'reasoning', 'reasoning_effort', 'verbosity', 'provider']) {
+    if (key in record) {
+      normalized[key] = summarizeLargeValue(record[key])
+    }
+  }
+
+  if (params.provider === 'openrouter') {
+    for (const key of ['models', 'plugins', 'web_search_options', 'include_reasoning']) {
+      if (key in record) {
+        normalized[key] = summarizeLargeValue(record[key])
+      }
+    }
+  }
+
+  return normalized
+}

packages/agent-runtime/src/prompt-agent-stream.ts

@@ -26,6 +26,12 @@ export const getAgentStreamFromTemplate = (params: {
   tools: ToolSet
   userId: string | undefined
   userInputId: string
+  cacheDebugCorrelation?: string
+  onCacheDebugProviderRequestBuilt?: (params: {
+    provider: string
+    rawBody: unknown
+    normalizedBody?: unknown
+  }) => void
 
   onCostCalculated?: (credits: number) => Promise<void>
   promptAiSdkStream: PromptAiSdkStreamFn
@@ -47,6 +53,8 @@ export const getAgentStreamFromTemplate = (params: {
     tools,
     userId,
     userInputId,
+    cacheDebugCorrelation,
+    onCacheDebugProviderRequestBuilt,
 
     sendAction,
     onCostCalculated,
@@ -80,6 +88,8 @@ export const getAgentStreamFromTemplate = (params: {
     tools,
     userId,
     userInputId,
+    cacheDebugCorrelation,
+    onCacheDebugProviderRequestBuilt,
 
     onCostCalculated,
     sendAction,

packages/agent-runtime/src/run-agent-step.ts

@@ -1,10 +1,9 @@
-import { createHash } from 'crypto'
-
 import { AnalyticsEvent } from '@codebuff/common/constants/analytics-events'
 import { supportsCacheControl } from '@codebuff/common/old-constants'
 import { TOOLS_WHICH_WONT_FORCE_NEXT_STEP } from '@codebuff/common/tools/constants'
 import { buildArray } from '@codebuff/common/util/array'
 import { AbortError, getErrorObject, isAbortError } from '@codebuff/common/util/error'
+import { serializeCacheDebugCorrelation } from '@codebuff/common/util/cache-debug'
 import { systemMessage, userMessage } from '@codebuff/common/util/messages'
 import { APICallError, type ToolSet } from 'ai'
 import { cloneDeep, mapValues } from 'lodash'
@@ -21,7 +20,10 @@ import { getAgentPrompt } from './templates/strings'
 import { getToolSet } from './tools/prompts'
 import { processStream } from './tools/stream-parser'
 import { getAgentOutput } from './util/agent-output'
-import { writeCacheDebugSnapshot } from './util/cache-debug'
+import {
+  createCacheDebugSnapshot,
+  enrichCacheDebugSnapshotWithProviderRequest,
+} from './util/cache-debug'
 import {
   withSystemInstructionTags,
   withSystemTags as withSystemTags,
@@ -259,6 +261,52 @@ export const runAgentStep = async (
   const iterationNum = agentState.messageHistory.length
   const systemTokens = countTokensJson(system)
 
+  const cacheDebugCorrelation = CACHE_DEBUG_FULL_LOGGING
+    ? createCacheDebugSnapshot({
+        agentType: String(agentType),
+        system,
+        toolDefinitions: params.tools
+          ? Object.fromEntries(
+              Object.entries(params.tools).map(([name, tool]) => [
+                name,
+                {
+                  description: tool.description,
+                  inputSchema: tool.inputSchema as {},
+                },
+              ]),
+            )
+          : {},
+        messages: [systemMessage(system), ...agentState.messageHistory],
+        logger,
+        projectRoot: fileContext.projectRoot,
+        runId: agentState.runId,
+        userInputId,
+        agentStepId,
+        model,
+      })
+    : undefined
+
+  const onCacheDebugProviderRequestBuilt =
+    cacheDebugCorrelation
+      ? ({
+          provider,
+          rawBody,
+          normalizedBody,
+        }: {
+          provider: string
+          rawBody: unknown
+          normalizedBody?: unknown
+        }) => {
+          enrichCacheDebugSnapshotWithProviderRequest({
+            correlation: cacheDebugCorrelation,
+            provider,
+            rawBody,
+            normalized: normalizedBody ?? rawBody,
+            logger,
+          })
+        }
+      : undefined
+
   logger.debug(
     {
       iteration: iterationNum,
@@ -286,6 +334,10 @@ export const runAgentStep = async (
       model,
       n: params.n,
       onCostCalculated,
+      cacheDebugCorrelation: cacheDebugCorrelation
+        ? serializeCacheDebugCorrelation(cacheDebugCorrelation)
+        : undefined,
+      onCacheDebugProviderRequestBuilt,
     })
 
     if (result.aborted) {
@@ -336,8 +388,12 @@ export const runAgentStep = async (
     ...params,
     agentId: agentState.parentId ? agentState.agentId : undefined,
     costMode: params.costMode,
+    cacheDebugCorrelation: cacheDebugCorrelation
+      ? serializeCacheDebugCorrelation(cacheDebugCorrelation)
+      : undefined,
     includeCacheControl: supportsCacheControl(agentTemplate.model),
     messages: [systemMessage(system), ...agentState.messageHistory],
+    onCacheDebugProviderRequestBuilt,
     template: agentTemplate,
     onCostCalculated,
   })
@@ -715,36 +771,6 @@ export async function loopAgentSteps(
     inputSchema: tool.inputSchema as {},
   }))
 
-  if (CACHE_DEBUG_FULL_LOGGING) {
-    // Debug: hash the system prompt and tool definitions to detect prompt cache invalidation
-    const systemHash = createHash('sha256').update(system).digest('hex').slice(0, 8)
-    const sortedToolDefs = Object.keys(toolDefinitions).sort().reduce((acc, key) => {
-      acc[key] = toolDefinitions[key]
-      return acc
-    }, {} as Record<string, unknown>)
-    const toolsHash = createHash('sha256').update(JSON.stringify(sortedToolDefs)).digest('hex').slice(0, 8)
-    logger.debug(
-      {
-        systemHash,
-        toolsHash,
-        systemLength: system.length,
-        toolCount: Object.keys(toolDefinitions).length,
-        toolNames: Object.keys(toolDefinitions).sort(),
-        agentType,
-      },
-      `[Cache Debug] System prompt hash: ${systemHash}, Tools hash: ${toolsHash}`,
-    )
-
-    writeCacheDebugSnapshot({
-      agentType: String(agentType),
-      system,
-      toolDefinitions: sortedToolDefs,
-      messages: initialMessages,
-      logger,
-      projectRoot: fileContext.projectRoot,
-    })
-  }
-
   const additionalToolDefinitionsWithCache = async () => {
     if (!cachedAdditionalToolDefinitions) {
       cachedAdditionalToolDefinitions = await additionalToolDefinitions({