21.04-AI调用日志

要点

  • AI 调用日志需要记录完整的请求参数和响应结果
  • 模型、温度、token 数等参数是排查质量问题的关键
  • 流式响应需要特殊处理：记录首次响应时间和完整响应时间
  • 敏感内容（用户输入、模型输出）需要脱敏或单独存储

内容

1. AI 调用日志的特殊性

普通 HTTP 请求日志只记录 method/path/status/duration，但 AI 调用需要更多信息：

字段为什么需要
model哪个模型（gpt-4、claude-opus-4-6 等）
messages用户输入（排查质量问题）
temperature / top_p生成参数（影响输出多样性）
max_tokens限制参数（影响成本和截断）
usage.total_tokens实际消耗的 token 数
usage.prompt_tokens输入 token 数
usage.completion_tokens输出 token 数
finish_reason为什么停止（stop/length/content_filter）
response_time首 token 延迟（流式）或完整响应时间

这些信息对于排查以下问题至关重要：

  • 质量问题：用户反馈「回答很烂」，你需要看 messages 和 temperature
  • 成本问题：某个用户的 token 消耗异常，需要看 usage
  • 性能问题：响应很慢，需要看 response_time 和模型负载
  • 截断问题：回答不完整，需要看 finish_reason 和 max_tokens

2. 基础 AI 调用日志

// src/routes/chat.ts
import { Hono } from 'hono'
import { log } from '../lib/logger'
 
const app = new Hono()
 
app.post('/v1/chat/completions', async (c) => {
  const requestId = c.get('requestId')
  const userId = c.get('userId')
  const startedAt = Date.now()
 
  const body = await c.req.json()
 
  try {
    const result = await callLLM(body)
 
    log.info('llm.call.success', {
      requestId,
      userId,
 
      // 请求参数
      request: {
        model: body.model,
        temperature: body.temperature,
        max_tokens: body.max_tokens,
        messages_count: body.messages?.length,
      },
 
      // 响应结果
      response: {
        usage: result.usage,
        finish_reason: result.choices[0]?.finish_reason,
        model: result.model,
      },
 
      // 性能指标
      duration: Date.now() - startedAt,
    })
 
    return c.json(result)
  } catch (err) {
    log.error('llm.call.failed', {
      requestId,
      userId,
 
      request: {
        model: body.model,
        temperature: body.temperature,
        max_tokens: body.max_tokens,
      },
 
      error: {
        message: err.message,
        status: err.status,
      },
 
      duration: Date.now() - startedAt,
    })
 
    throw err
  }
})

3. 记录 messages 的取舍

messages 是 AI 调用的核心输入，但也是最大的日志来源。是否记录取决于场景：

记录 messages 的场景：

  • 调试阶段：需要看用户输入和模型输出的对应关系
  • 质量问题排查：用户反馈「回答错误」，需要看原始 prompt
  • 安全审计：需要追溯用户是否输入了违规内容

不记录 messages 的场景：

  • 生产环境高流量：messages 可能很大，日志成本太高
  • 隐私敏感：用户输入可能包含个人信息
  • 成本敏感：Workers Observability 按日志量计费

折中方案：只记录 messages 的长度和关键特征：

log.info('llm.call.success', {
  requestId,
  userId,
 
  request: {
    model: body.model,
    messages_count: body.messages?.length,
    messages_total_length: body.messages?.reduce((sum, m) => sum + m.content.length, 0),
    has_system_prompt: body.messages?.[0]?.role === 'system',
    has_images: body.messages?.some(m => m.images?.length > 0),
  },
 
  // ...
})

如果需要完整 messages，可以单独存储到 R2 或数据库：

// 只在调试模式下记录完整 messages
if (process.env.LOG_MESSAGES === 'true') {
  await c.env.MESSAGES_BUCKET.put(
    `requests/${requestId}.json`,
    JSON.stringify({
      requestId,
      userId,
      messages: body.messages,
      response: result.choices[0]?.message,
    }),
    { expirationTtl: 86400 }  // 保留 24 小时
  )
}

4. 流式响应的日志

流式响应（stream: true）的日志更复杂，因为响应是分块返回的。需要记录：

  • 首次响应时间：从请求发出到第一个 token 返回（TTFT，Time To First Token）
  • 完整响应时间：从请求发出到所有 token 返回完毕
  • 实际 token 数：流式响应的 usage 可能在最后一个 chunk 里
// src/routes/chat-stream.ts
app.post('/v1/chat/completions', async (c) => {
  const requestId = c.get('requestId')
  const userId = c.get('userId')
  const startedAt = Date.now()
 
  const body = await c.req.json()
  const isStream = body.stream === true
 
  const result = await callLLM(body)
 
  if (isStream) {
    let firstTokenAt: number | null = null
    let totalTokens = 0
 
    const stream = new ReadableStream({
      async start(controller) {
        const reader = result.body.getReader()
        const decoder = new TextDecoder()
 
        while (true) {
          const { done, value } = await reader.read()
          if (done) break
 
          if (!firstTokenAt) {
            firstTokenAt = Date.now()
            log.info('llm.stream.first_token', {
              requestId,
              userId,
              ttft: firstTokenAt - startedAt,
            })
          }
 
          // 解析 SSE 数据，提取 usage
          const text = decoder.decode(value)
          const lines = text.split('\n').filter(l => l.startsWith('data: '))
 
          for (const line of lines) {
            const data = JSON.parse(line.slice(6))
            if (data.usage) {
              totalTokens = data.usage.total_tokens
            }
          }
 
          controller.enqueue(value)
        }
 
        const completedAt = Date.now()
        log.info('llm.stream.completed', {
          requestId,
          userId,
          model: body.model,
          ttft: firstTokenAt - startedAt,
          total_duration: completedAt - startedAt,
          total_tokens: totalTokens,
        })
 
        controller.close()
      },
    })
 
    return new Response(stream, {
      headers: { 'Content-Type': 'text/event-stream' },
    })
  }
 
  // 非流式响应
  log.info('llm.call.success', {
    requestId,
    userId,
    model: body.model,
    usage: result.usage,
    duration: Date.now() - startedAt,
  })
 
  return c.json(result)
})

5. 多模型切换的日志

如果你的 AI 网关支持多模型（OpenAI、Anthropic、本地模型等），日志需要记录实际使用的模型：

// src/lib/llm-router.ts
export async function callLLM(body: ChatRequest, env: Env) {
  const startedAt = Date.now()
 
  // 根据模型名称路由到不同提供商
  let provider: 'openai' | 'anthropic' | 'local'
  let actualModel: string
 
  if (body.model.startsWith('gpt-')) {
    provider = 'openai'
    actualModel = body.model
  } else if (body.model.startsWith('claude-')) {
    provider = 'anthropic'
    actualModel = body.model
  } else {
    provider = 'local'
    actualModel = 'llama-3'
  }
 
  try {
    const result = await fetchFromProvider(provider, body, env)
 
    log.info('llm.provider.call', {
      provider,
      actualModel,
      requestedModel: body.model,
      duration: Date.now() - startedAt,
    })
 
    return result
  } catch (err) {
    log.error('llm.provider.failed', {
      provider,
      actualModel,
      requestedModel: body.model,
      error: err.message,
      duration: Date.now() - startedAt,
    })
 
    throw err
  }
}

这样你可以看到：

  • 用户请求的是 gpt-4-turbo，实际调用的是 gpt-4-0125-preview
  • 某个 provider 的错误率突然升高
  • 不同 provider 的延迟差异

6. 敏感内容脱敏

AI 调用的输入输出可能包含敏感信息：

  • 用户输入：身份证号、手机号、密码
  • 模型输出：可能包含训练数据中的隐私信息

脱敏策略：

// src/lib/sanitize.ts
export function sanitizeContent(content: string): string {
  // 手机号：13812345678 → 138****5678
  content = content.replace(/(\d{3})\d{4}(\d{4})/g, '$1****$2')
 
  // 身份证号：110101199001011234 → 110101********1234
  content = content.replace(/(\d{6})\d{8}(\d{4})/g, '$1********$2')
 
  // 邮箱：[email protected] → t***@example.com
  content = content.replace(/(\w)\w+(@\w+)/g, '$1***$2')
 
  return content
}
log.info('llm.call.success', {
  requestId,
  userId,
 
  // 脱敏后的 messages
  messages_preview: body.messages?.map(m => ({
    role: m.role,
    content_preview: sanitizeContent(m.content).slice(0, 100),
  })),
 
  // ...
})

7. 实战：完整的 AI 调用日志

// src/routes/chat.ts
import { Hono } from 'hono'
import { log } from '../lib/logger'
import { callLLM } from '../lib/llm-router'
import { sanitizeContent } from '../lib/sanitize'
 
const app = new Hono()
 
app.post('/v1/chat/completions', async (c) => {
  const requestId = c.get('requestId')
  const userId = c.get('userId')
  const startedAt = Date.now()
 
  const body = await c.req.json()
 
  try {
    const result = await callLLM(body, c.env)
 
    // 成功日志
    log.info('llm.call.success', {
      requestId,
      userId,
 
      // 请求摘要（不记录完整 messages）
      request: {
        model: body.model,
        temperature: body.temperature,
        max_tokens: body.max_tokens,
        stream: body.stream,
        messages_count: body.messages?.length,
      },
 
      // 响应结果
      response: {
        usage: result.usage,
        finish_reason: result.choices[0]?.finish_reason,
        actual_model: result.model,
      },
 
      // 性能指标
      duration: Date.now() - startedAt,
    })
 
    // Analytics Engine 埋点
    c.env.ANALYTICS.writeDataPoint({
      blobs: [body.model, userId, 'success'],
      doubles: [
        result.usage.total_tokens,
        result.usage.prompt_tokens,
        result.usage.completion_tokens,
        Date.now() - startedAt,
      ],
      indexes: [userId],
    })
 
    return c.json(result)
  } catch (err) {
    // 失败日志
    log.error('llm.call.failed', {
      requestId,
      userId,
 
      request: {
        model: body.model,
        temperature: body.temperature,
        max_tokens: body.max_tokens,
      },
 
      error: {
        message: err.message,
        status: err.status,
        provider: err.provider,
      },
 
      duration: Date.now() - startedAt,
    })
 
    // Analytics Engine 记录失败
    c.env.ANALYTICS.writeDataPoint({
      blobs: [body.model, userId, 'error'],
      doubles: [0, 0, 0, Date.now() - startedAt],
      indexes: [userId],
    })
 
    throw err
  }
})

8. 小结

AI 调用日志的关键点：

  1. 完整参数：记录 model、temperature、max_tokens、usage 等关键参数
  2. messages 取舍：根据场景决定是否记录完整 messages，或只记录摘要
  3. 流式响应：记录 TTFT（首 token 延迟）和完整响应时间
  4. 多模型路由：记录请求模型和实际调用模型
  5. 敏感脱敏：对输入输出做脱敏处理，避免隐私泄露

下一节讲 Token 消耗日志，看看怎么追踪和计费 AI 调用的成本。