From 1e304505d3b9093e83375ac5ce8e75485bb65ba4 Mon Sep 17 00:00:00 2001 From: umaru Date: Sat, 23 May 2026 23:11:56 +0800 Subject: [PATCH] =?UTF-8?q?docs(usage):=20fill=20phase=202=20final=203=20?= =?UTF-8?q?=E2=80=94=20logs-stats=20+=20recording=20+=20troubleshooting=20?= =?UTF-8?q?(#167)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 收尾使用侧 9 篇，至此 Phase 2 使用指南全部完成。 - logs-stats：request_logs 40+ 列分组列出，重点讲 PR #170/#171 的 duration_ms INT4 clamp、stale reconcile (status_code=520) 兜底； /api/admin/logs 的 query 参数集（无 model 过滤）、/api/admin/logs/live SSE 与多副本下的进程内 pub/sub 限制；overview / timeseries / leaderboard 三类聚合的实时计算口径，特别是 TPS 的多重过滤条件；明确指出 LOG_RETENTION_DAYS 当前无后台清理任务消费、表实际无限增长，给出手动 DELETE 的兜底方案。 - request-recording：Runtime Settings 主控（env 已弃用，shouldRecordFixture 只读 DB），默认 enabled=false / mode=failure；磁盘布局含 latest.json 双写、16 MiB 截断、compactSSEChunks 对 OpenAI Responses 大型快照事件 的 instructions/tools 替换；脱敏的 SENSITIVE_HEADER_NAMES 全列；hook 时机 fire-and-forget、tee() 分叉不影响 client 延迟；/api/mock 回放仅 NODE_ENV !== production 生效。同时纠正 .env.example 注释里 tests/fixtures 与源码实际默认 data/traffic-recordings 的不一致。 - troubleshooting：按客户端 Key / 路由 / SSE / CLIProxyAPI / 计费 / 日志 六类组织 symptom→error code→源码定位→排查方向表格。覆盖 API_KEY_MODEL_NOT_ALLOWED、NO_AUTHORIZED_UPSTREAMS、NO_HEALTHY_CANDIDATES、 CONCURRENCY_FULL、QUEUE_WAIT_TIMEOUT、CLIENT_DISCONNECTED、queue_full、 REQUEST_TIMEOUT、STREAM_ERROR、CliproxyConnectionStatus 四态、 CliproxyInstanceInUseError、duration_ms 24.8 天、status_code=520、 UnbillableReason 四类等，并明确划分与部署侧 troubleshooting / circuit breaker 长篇 / cliproxy 长篇的边界，避免主题重叠。 Phase 2 使用侧 6/9 → 9/9，剩部署 0/6、架构 0/9。 --- docs/guide/usage/logs-stats.md | 265 ++++++++++++++++++++++++-- docs/guide/usage/request-recording.md | 210 +++++++++++++++++++- docs/guide/usage/troubleshooting.md | 165 ++++++++++++++-- 3 files changed, 608 insertions(+), 32 deletions(-) diff --git a/docs/guide/usage/logs-stats.md b/docs/guide/usage/logs-stats.md index 13e8f524..fad4ee29 100644 --- a/docs/guide/usage/logs-stats.md +++ b/docs/guide/usage/logs-stats.md @@ -5,19 +5,262 @@ outline: deep # 请求日志与统计 -::: warning 撰写中 -此文档目前为占位，正文尚未填充。完整撰写进度跟踪见 [issue #167](https://github.com/g1331/AutoRouter/issues/167)。 -::: +AutoRouter 的可观测性建立在两张表上：`request_logs` 记录每一次代理请求的完整过程，`request_billing_snapshots` 与它 1:1 关联存计费快照。两张表通过统一的 admin API 暴露给管理后台与外部脚本，三类聚合 API（overview / timeseries / leaderboard）在它们之上做实时计算，无任何预聚合。本页讲清字段语义、写入时机、统计口径、live SSE、以及 `LOG_RETENTION_DAYS` 当前实际的执行情况。 + +## request_logs 表 + +`src/lib/db/schema-pg.ts:279-342` 定义。**40 多列**，按功能分组列出关键字段： + +### 调用方与上游标识 + +| 列 | 类型 | 说明 | +| ---------------- | ------------------------------ | ------------------------------------------------ | +| `api_key_id` | uuid FK → api_keys (set null) | Key 被删除后置 NULL，但 prefix/name 快照仍可用 | +| `api_key_name` | varchar(255) | Key 名称快照（冗余写入，避免 join 时被改名误导） | +| `api_key_prefix` | varchar(16) | Key 前缀快照 | +| `upstream_id` | uuid FK → upstreams (set null) | 实际命中的上游 | + +### 请求 / 响应骨架 + +| 列 | 类型 | 说明 | +| --------------------- | ------------ | --------------------------------------------------------------------------- | +| `method` | varchar(10) | HTTP 方法 | +| `path` | text | 完整路径 | +| `model` | varchar(128) | 模型名（来自请求体或响应体） | +| `status_code` | integer | HTTP 状态码；**in-progress 时为 NULL**，请求完成后才回填 | +| `duration_ms` | integer | 总耗时（ms），写入时 clamp 到 INT4 上限 2,147,483,647（约 24.8 天）防止溢出 | +| `routing_duration_ms` | integer | 路由选择耗时（ms），同样 clamp | +| `ttft_ms` | integer | Time-To-First-Byte（首字节时延 ms） | +| `is_stream` | boolean | 是否为流式请求 | +| `error_message` | text | 错误描述（仅失败时填） | + +### Token 与缓存计费维度 + +| 列 | 含义 | +| -------------------------- | ------------------------------------- | +| `prompt_tokens` | 输入 token | +| `completion_tokens` | 输出 token | +| `total_tokens` | 总数（通常 = prompt + completion） | +| `cached_tokens` | OpenAI 侧 `usage.cached_tokens` | +| `reasoning_tokens` | 推理 token | +| `cache_creation_tokens` | Anthropic cache 写入（通用） | +| `cache_creation_5m_tokens` | Anthropic 5 分钟 ephemeral cache 写入 | +| `cache_creation_1h_tokens` | Anthropic 1 小时 ephemeral cache 写入 | +| `cache_read_tokens` | Anthropic cache 命中 | + +Token 数据由 `extractNormalizedUsage`（`src/lib/services/proxy-client.ts:450`）从多家协议的 `usage` / `usageMetadata` 字段统一抽取，覆盖 OpenAI / Anthropic / Gemini / OpenAI Responses streaming。 + +### 路由与决策审计 + +| 列 | 说明 | +| ------------------------ | -------------------------------------------------------------------- | +| `routing_type` | `direct` / `provider_type` / `tiered` | +| `priority_tier` | 命中上游所在 tier | +| `failover_attempts` | 该请求做了几次 failover | +| `failover_history` | text（JSON array），每次尝试的上游 + 失败原因 | +| `routing_decision` | text（JSON object），完整决策上下文 | +| `session_id` | session affinity 提取出的 ID | +| `affinity_hit` | 是否命中亲和缓存 | +| `affinity_migrated` | 是否触发亲和迁移 | +| `session_id_compensated` | 是否补偿了 session header | +| `header_diff` | JSON，记录 inbound / outbound / dropped 的 header 差异 | +| `reasoning_effort` | 请求推理强度：none / minimal / low / medium / high / xhigh / enabled | +| `thinking_config` | JSON，请求的推理配置原值 | + +### 索引（行 336-341） + +| 索引 | 用途 | +| ------------------------------- | -------------------------------------- | +| `request_logs_api_key_id_idx` | 按 key 检索 / 计费配额聚合 | +| `request_logs_upstream_id_idx` | 按上游检索 / 统计 | +| `request_logs_created_at_idx` | 时间窗扫描（list / timeseries 全走它） | +| `request_logs_routing_type_idx` | 按路由类型分组 | + +### 关联：request_billing_snapshots + +每条 request_log 有一条对应的 `request_billing_snapshots` 行（1:1，`ON DELETE CASCADE`），存 `finalCost` / `priceSource` / `billingStatus` / `unbillableReason` 等。统计接口的 cost 维度直接 LEFT JOIN 这张表。 + +## 写入路径 + +`src/lib/services/request-logger.ts`，**两阶段同步写**，无 sampling / 无截断 / 无 batching： + +``` +client request + ↓ +proxy route 决策完毕（route.ts:2959） + ↓ +logRequestStart() — INSERT 一行，status_code=NULL，duration_ms=NULL + ↓ +转发到上游 / 接收响应 + ↓ +updateRequestLog(id, {...}) — UPDATE，回填 status_code / duration_ms / tokens / errorMessage / failover_history / ttft 等 + ↓ +calculateAndPersistRequestBillingSnapshot() — 在 request_billing_snapshots 写计费快照 + ↓ +publishRequestLogLiveUpdate() — 广播 SSE 事件给 /api/admin/logs/live 订阅者 +``` + +部分非流式入口直接调 `logRequest()`（`request-logger.ts:467-519`）一次性 INSERT，跳过 in-progress 中间态。 + +### duration_ms 与 routing_duration_ms 的 clamp + +```ts +Math.min(Math.max(0, input.durationMs), INT4_MAX); // INT4_MAX = 2_147_483_647 +``` + +源码见 `request-logger.ts:21,411-417,489-491`。这层保护是 PR #170 / #171 的修复：早期版本 `duration_ms` 没有上界，长时间 stuck 的流式请求写入会超过 PostgreSQL `INT4` 上限直接 INSERT 失败，整条 log 丢失。clamp 之后超时请求虽然 `duration_ms` 失真为 24.8 天封顶，但日志能正常写入。 + +### Stale reconcile：520 兜底 + +如果 in-progress 行长时间没被 update 回填（服务重启 / 进程 crash / 异常路径漏写），会留下永远 `status_code IS NULL` 的孤儿行。`request-logger.ts:524-569` 的 `reconcileStaleInProgressRequestLogs` 做兜底： + +| 常量 | 值 | 说明 | +| ------------------------------ | --- | ------------------------------------------- | +| `REQUEST_LOG_STALE_MINUTES` | 15 | 超过 15 分钟仍是 NULL 即视为 stale | +| `REQUEST_LOG_STALE_SCAN_LIMIT` | 200 | 单次扫描上限，避免一次性处理过多行 | +| stale status code | 520 | 标记为 HTTP 520 + `errorMessage` 写明超时窗 | + +触发时机：每次 `listRequestLogs()` 与各 stats 函数被调用前自动跑（非 test 环境）。失败仅 warn 不中断（`:706-710`）。 + +读到 `status_code = 520` 不代表上游真返了 520，而是 reconcile 兜底标记，需要人工排查上一次重启 / crash 时是否有未回填的日志。 + +## 管理 API + +### `GET /api/admin/logs` — 分页列表 + +`src/app/api/admin/logs/route.ts`。Query 参数： + +| 参数 | 含义 | +| ------------- | --------------------------------------------- | +| `page` | 页号，默认 1 | +| `page_size` | 每页条数，默认 20，上限 100 | +| `id` | 精确匹配 log ID（前端 `focus=` 跳转场景） | +| `api_key_id` | 精确匹配 Key | +| `upstream_id` | 精确匹配上游 | +| `status_code` | 精确匹配整数 | +| `start_time` | ISO datetime，`created_at >=` | +| `end_time` | ISO datetime，`created_at <=` | + +返回 `{items, total, page, pageSize, totalPages}`，`items` 中每条带完整字段 + billing snapshot。 + +**注意没有 `model` 过滤参数**——按模型筛要么走 stats leaderboard，要么在客户端做。 -## 计划覆盖的内容 +### `GET /api/admin/logs/live` — SSE 实时 -查看日志的方式、过滤条件、`LOG_RETENTION_DAYS` 与请求录制的关系。 +`src/app/api/admin/logs/live/route.ts`。 -## 在正文就绪前的临时建议 +- Content-Type `text/event-stream` +- 连接即推 `event: connected` +- 每 15 秒一条 `:keep-alive ` 注释保活 +- 每次日志变更（INSERT / UPDATE）推送 `event: request-log-changed`，payload `{type, logId, statusCode, occurredAt}` + +实现是**进程内 in-memory pub/sub**（`src/lib/services/request-log-live-updates.ts:10`）。**多进程部署下不跨实例**——instance A 写的日志，只有连到 instance A 的 SSE 订阅者会收到事件，连到 instance B 的不会。多副本场景下 live 模式实际可用性取决于负载均衡的粘性，详情见 [架构 / 请求生命周期](../architecture/request-lifecycle)。 + +### `GET /api/admin/stats` — 统一聚合入口 + +`src/app/api/admin/stats/route.ts`，按 `type` 参数分发到三个子路由： + +| `type` 取值 | 行为 | +| ------------------ | ------------------------------------------------------------------------- | +| `type=overview` | 当日 + 昨日对比 | +| `type=timeseries` | `range=today\|7d\|30d&metric=requests\|ttft\|tps\|tokens\|duration\|cost` | +| `type=leaderboard` | `range=today\|7d\|30d&limit=5`（上限 50） | + +也可以分别直接调子路由 `/api/admin/stats/overview`、`/api/admin/stats/timeseries`、`/api/admin/stats/leaderboard`。 + +## 统计聚合 + +`src/lib/services/stats-service.ts`。**全部实时聚合**——每次 API 调用走一次 SQL，无定时预聚合任务。 + +### Overview（当日 + 昨日对比） + +`getOverviewStats`（`stats-service.ts:265`）。当日与昨日各执行一次聚合查询，LEFT JOIN `request_billing_snapshots`。计算： + +| 指标 | 口径 | +| ---------------------------- | -------------------------------------------------------------- | +| `totalRequests` | 当日 count(\*) | +| `avgDuration` | **仅 2xx** 的 `duration_ms` 平均 | +| `avgTtft` | **仅 2xx** 的 `ttft_ms` 平均 | +| `totalTokens` | 当日 sum(total_tokens) | +| `successCount` | 当日 count where 2xx | +| `totalCacheReadTokens` | 当日 sum(cache_read_tokens) | +| `totalEffectivePromptTokens` | 当日 sum(effective prompt，含 cache 抵扣) | +| `totalCost` | 当日 sum(final_cost) where `billing_status='billed'` | +| `cacheHitRate` | `cacheReadTokens / effectivePromptTokens * 100`，clamp [0,100] | + +### Timeseries（时间序列） + +`getTimeseriesStats`（`stats-service.ts:368`）： + +| `range` | 时间桶粒度 | +| ------------ | ---------------------------- | +| `today` | hour | +| `7d` / `30d` | day | +| `custom` | 差值 ≤ 2 天 → hour，否则 day | + +PG 用 `date_trunc('hour'/'day', created_at)` 分桶（`stats-service.ts:150-158`），并行查 per-upstream + 全量 total 两组。 + +| `metric` | 计算口径 | +| ---------- | ------------------------------------------------------------------------------------ | +| `requests` | count(\*) | +| `tokens` | sum(total_tokens) | +| `duration` | avg(duration_ms) | +| `ttft` | avg(ttft_ms) | +| `tps` | tokens / second，**仅** is_stream + 2xx + completion_tokens ≥ 10 + duration_ms > 100 | +| `cost` | sum(final_cost) where `billing_status='billed'`（需 LEFT JOIN billing_snapshots） | + +TPS 的过滤条件（`stats-service.ts:109-115`）是为了避免短请求 / 非流式 / 已抛错的样本污染分母。 + +### Leaderboard（排行榜） + +`getLeaderboardStats`（`stats-service.ts:525`）。三个维度并行： + +| 维度 | 主排序 | 附加分布（top-5，超出归入 "Others"） | +| --------- | ------ | ------------------------------------ | +| API Keys | top-N | 每个 key 的 model 分布 | +| Upstreams | top-N | 直接列出 | +| Models | top-N | 每个 model 的 upstream 分布 | + +上游 providerType 通过 `getPrimaryProviderByCapabilities(routeCapabilities)` 推导，因此即使上游没有显式 providerType 字段也能归类。 + +## 前端：`/logs` 页面与 live 模式 + +- 页面：`src/app/[locale]/(dashboard)/logs/page.tsx` +- Hook：`src/hooks/use-request-log-live.ts` + +Hook 行为： + +| 状态 | 含义 | +| ------------ | --------------------------------------------------------------------------------- | +| `connecting` | SSE 连接建立中 | +| `live` | 已收到 `connected` 事件，每次 `request-log-changed` 触发 250ms debounced 列表刷新 | +| `fallback` | SSE 断开，回落到 3000ms 轮询 | + +断线后 10 秒重连一次（`use-request-log-live.ts:23`）。 + +实际操作建议： + +- 排查单条请求 → 列表直接按 `id` 过滤（管理后台支持 focus=<id> 跳转 URL）。 +- 排查某个 Key 的最近一批请求 → 列表按 `api_key_id` + 时间窗。 +- 排查上游故障期间的失败分布 → list 取数据 + leaderboard 取 top-N 错误来源。 + +## 保留策略：当前实际情况 + +::: warning LOG_RETENTION_DAYS 当前没有自动清理任务在跑 +`.env` 里的 `LOG_RETENTION_DAYS`（默认 90）被 `config.ts:35,82` 解析存到运行时配置对象，但 **整个 `src` 目录里没有任何代码读取这个配置值去清理 `request_logs` 表**。Background sync 注册表（`src/lib/services/background-sync-registry.ts`）当前只有三个任务：billing price sync、upstream model catalog sync、traffic recording cleanup，**不含 request_log 清理**。 + +也就是说目前 request_logs 表是**无限增长**的，靠 `LOG_RETENTION_DAYS` 不会让它停下来。需要按日期清理时，目前的手段是： + +1. 直接对 DB 执行：`DELETE FROM request_logs WHERE created_at < NOW() - INTERVAL '90 days';` +2. 由于 `request_billing_snapshots` 通过 `ON DELETE CASCADE` 关联，会跟着一起被清。 +3. 生产环境建议加入 `LIMIT` 分批 + 索引 `request_logs_created_at_idx` 走顺序扫描，避免一次性锁表。 + +后续若添加 request_log retention 后台任务，再更新本节。 +::: -在该文档正文上线之前，可以参考以下材料获取等价信息： +## 不在本页范围内 -- 项目仓库根目录的 [README.md](https://github.com/g1331/AutoRouter/blob/master/README.md) -- 现有长篇 [`docs/cliproxy-deployment.md`](/cliproxy-deployment) -- 现有长篇 [`docs/circuit-breaker.md`](/circuit-breaker) -- 项目 [Issue 列表](https://github.com/g1331/AutoRouter/issues) 与 [OpenSpec 提案](https://github.com/g1331/AutoRouter/tree/master/openspec) +- 录制请求 / 响应原始体（fixture）：见 [请求录制](./request-recording)。 +- 计费规则、价格来源、unbillable 细化原因：后续「计费」相关文档（仓库内可参考 `billing-cost-service.ts:432-449` 的 `UnbillableReason` 列表）。 +- 上游模型与 routing decision 的字段语义：见 [请求生命周期](../architecture/request-lifecycle) 与 [模型路由规则](./model-routing)。 +- 部署侧的日志收集 / 监控集成（Prometheus / Grafana 等）：后续部署侧 troubleshooting 章节，目前未覆盖。 diff --git a/docs/guide/usage/request-recording.md b/docs/guide/usage/request-recording.md index ef18f3c6..ef449442 100644 --- a/docs/guide/usage/request-recording.md +++ b/docs/guide/usage/request-recording.md @@ -5,19 +5,209 @@ outline: deep # 请求录制 -::: warning 撰写中 -此文档目前为占位，正文尚未填充。完整撰写进度跟踪见 [issue #167](https://github.com/g1331/AutoRouter/issues/167)。 +请求录制（Traffic Recording）把每次代理请求的入站请求体、上游响应体、SSE chunks 整体快照成一个 JSON fixture 写到磁盘，索引信息写到 `traffic_recordings` 表。用途主要是事后排查 / 回归测试 / 喂给 `/api/mock` 做本地回放，**默认关闭**，开启后所有写盘走 fire-and-forget 不影响请求延迟。本页讲清开关位置、磁盘布局、脱敏规则、回放端点的边界。 + +## 默认关闭，运行时开关 + +录制行为由数据库表 `traffic_recording_settings` 单行（id = `"default"`）控制，**不再受 env 变量直接控制**。环境里仍然存在历史遗留的 `RECORDER_ENABLED` / `RECORDER_MODE` / `RECORDER_REDACT_SENSITIVE`（`.env.example:81-98`），但 [环境变量参考](../deployment/env-reference) 已经明确这三个 env 不再控制运行期行为——`shouldRecordFixture()` 只从 Runtime Settings 读值。 + +默认值（`src/lib/services/traffic-recording-service.ts:169-178`，`src/lib/db/schema-pg.ts:347-355`）： + +| 字段 | 默认值 | 含义 | +| ------------------ | ----------- | --------------------------------------- | +| `enabled` | `false` | 总开关；`false` 时整个录制管道短路 | +| `mode` | `"failure"` | 录制粒度：`all` / `success` / `failure` | +| `redact_sensitive` | `true` | 是否对敏感 header / base URL 脱敏 | +| `retention_days` | `7` | 录制保留天数，超期由后台任务清理 | + +判定逻辑（`traffic-recording-service.ts:219-224`）： + +```ts +shouldRecordTraffic(outcome) === enabled && (mode === "all" || mode === outcome); +``` + +每次代理请求单独调一次 `getTrafficRecordingSettings()`（`route.ts:2481`，每请求新查 DB，无 in-memory 缓存），所以**改设置立即生效，不需要重启**。 + +入口：管理后台 **系统 → 流量录制**（`/system/traffic-recording`，页面文件 `src/app/[locale]/(dashboard)/system/traffic-recording/page.tsx`）。 + +## 磁盘布局与文件命名 + +### 目录 + +由 env 变量 `RECORDER_FIXTURES_DIR` 指定，未设置时默认 `data/traffic-recordings`（`src/lib/services/traffic-recording-service.ts:10`）。 + +::: warning .env.example 注释与实际默认值不一致 +`.env.example:92` 的注释里把默认目录写成 `tests/fixtures`，但源码常量 `DEFAULT_TRAFFIC_RECORDING_ROOT` 是 `data/traffic-recordings`。实际生效值以源码为准——env 不设时录制写到 `data/traffic-recordings`，不是 `tests/fixtures`。 ::: -## 计划覆盖的内容 +### 文件路径与命名 + +`buildFixturePath`（`src/lib/services/traffic-recorder.ts:249-254`）： + +``` +{RECORDER_FIXTURES_DIR}/{provider}/{route}/{timestamp}.json +``` + +- `provider` 与 `route` 经 `sanitizePathSegment()` 处理：非字母数字字符 → `_` +- `timestamp` 来自 `fixture.meta.createdAt`，`:` 与 `.` → `-` +- 同目录额外写 `latest.json`，每次覆盖，永远指向最新一次录制 + +每次请求落 **2 个文件**（时间戳文件 + `latest.json`），**内容相同**，都是整体 JSON。流式 SSE 的 chunks 在内存里全部读完后以 `streamChunks: string[]` 数组形式写入同一个 JSON，**不是逐 chunk 落盘**。 + +### 单次 fixture 大小上限 + +`traffic-recorder.ts:122` 常量 `MAX_RECORDING_BYTES = 16 MiB`。超过后录制侧追加 `"[RECORDING_TRUNCATED]"` 标记并取消录制流，**client 侧的响应不受影响**——录制和响应是两个独立的 `tee()` 分支。 + +### 大型 SSE 事件的瘦身 + +`compactSSEChunks`（`traffic-recorder.ts:354-384`）对 OpenAI Responses 的 `response.created` / `response.in_progress` / `response.completed` 这几个携带完整 instructions / tools 的快照事件做特殊处理：把 `instructions` 与 `tools` 字段替换为 `"[STRIPPED:see_inbound_body]"`，避免一份 fixture 重复保存若干份相同的 system prompt。完整 instructions / tools 仍可以从 `inboundRequestBody` 字段里取到。 + +## traffic_recordings 表 + +`src/lib/db/schema-pg.ts:360-390`。**索引层**：每条 fixture 一行 DB 索引，fixture JSON 本体在磁盘上。 + +| 字段 | 类型 | 说明 | +| --------------------- | ---------------------- | ------------------------------- | +| `id` | uuid PK | | +| `request_log_id` | uuid FK → request_logs | 关联到 [请求日志](./logs-stats) | +| `api_key_id` | uuid FK → api_keys | | +| `upstream_id` | uuid FK → upstreams | | +| `method` | varchar(10) | | +| `path` | text | | +| `model` | varchar(128) | | +| `status_code` | integer | | +| `outcome` | varchar(16) NOT NULL | `"success"` / `"failure"` | +| `fixture_path` | text NOT NULL UNIQUE | 磁盘绝对路径 | +| `fixture_size_bytes` | integer | | +| `request_size_bytes` | integer | | +| `response_size_bytes` | integer | | +| `redacted` | boolean NOT NULL | 该 fixture 是否经过脱敏 | +| `created_at` | timestamptz | | + +设置表 `traffic_recording_settings` 单行（id = `"default"`），字段 `enabled` / `mode` / `redact_sensitive` / `retention_days` / 时间戳，对应 Runtime Settings。 + +## 录制管道 + +### 入口与执行时机 + +`src/app/api/proxy/v1/[...path]/route.ts`： + +| 行 | 行为 | +| --------- | --------------------------------------------------------------------------------------------------- | +| 2481 | `await getTrafficRecordingSettings()` —— 每请求一次 DB 查询 | +| 2482-2485 | 计算 `shouldRecordSuccess` / `shouldRecordFailure` / `recorderEnabled` | +| 2485 | `recorderEnabled === true` 时才 `await readRequestBody(request)` 把请求体读进内存 | +| 3202 | `teeStreamForRecording(originalStream)` —— `ReadableStream.tee()` 分叉流，一路给 client，一路给录制 | +| 3597 | 流式成功路径：`return recordTrafficFixture(...)`，落盘在后台 `.then()` 里，client 响应已先行返回 | +| 3796 | 非流式成功路径：`void recordTrafficFixture(...).catch(...)` 显式 fire-and-forget | +| 4034 | 失败路径：`void recordTrafficFixture(...).catch(...)` 同上 | + +**所有落盘均为 fire-and-forget**，client 端不阻塞等磁盘写入。读取请求体只在 `recorderEnabled === true` 时才发生，关闭录制时**不会**多产生 body 读取开销。 + +### 脱敏规则 + +`traffic-recorder.ts:124-136` 的 `SENSITIVE_HEADER_NAMES`： + +``` +authorization, proxy-authorization, x-forwarded-authorization, +x-api-key, x-goog-api-key, cookie, set-cookie, session_id, +x-codex-turn-metadata, x-codex-beta-features +``` + +`redactSensitive === true` 时： + +- 上表所有 header 的值替换为 `"[REDACTED]"`（key 名保留）。 +- 上游 base URL 的 host 部分替换为 `"[REDACTED]"`，路径保留。 +- fixture 的 `meta.redacted = true`，DB 行的 `redacted` 列同步为 `true`。 + +`redactSensitive === false` 时上述字段保留原值。**强烈建议**生产环境保持默认 `true`——fixture 是写到磁盘的明文 JSON，关掉脱敏意味着 auth 头、cookie、CPA management key 等都会留在文件里。 + +### 保留期与清理 + +后台任务 `traffic recording cleanup`（已注册到 background sync 注册表，`src/lib/services/background-sync-registry.ts`）按 `retention_days` 字段定期跑，删除超期的 DB 行与对应磁盘文件。 + +手动触发： + +``` +POST /api/admin/traffic-recordings/cleanup +``` + +返回 `{deleted_count, failure_count, error_summary}`。 + +## 管理 API + +全部要求 `Authorization: Bearer `。 + +| Method | Path | 行为 | +| -------- | --------------------------------------- | -------------------------------------------------------------------------------------------------------------------- | +| `GET` | `/api/admin/traffic-recording/settings` | 读 Runtime Settings | +| `PATCH` | `/api/admin/traffic-recording/settings` | 更新 Runtime Settings（字段任意可选） | +| `GET` | `/api/admin/traffic-recordings` | 分页列表；过滤 `api_key_id` / `upstream_id` / `request_log_id` / `status_code` / `model` / `start_time` / `end_time` | +| `GET` | `/api/admin/traffic-recordings/[id]` | 返回单条索引元数据 + 内联 `fixture` 字段（磁盘 JSON 内容） | +| `DELETE` | `/api/admin/traffic-recordings/[id]` | 删 DB 行 + 删磁盘文件 | +| `POST` | `/api/admin/traffic-recordings/cleanup` | 立即清理所有超 `retention_days` 的录制 | + +源文件分别是 `src/app/api/admin/traffic-recording/settings/route.ts`、`src/app/api/admin/traffic-recordings/route.ts`、`.../[id]/route.ts`、`.../cleanup/route.ts`。 + +**没有独立的下载端点**——fixture 内容是通过详情 GET 的 `fixture` 字段内联返回，前端 UI 直接渲染。 + +## 回放：`/api/mock/[...path]` + +`src/app/api/mock/[...path]/route.ts`。 + +::: warning 仅非 production 生效 +`NODE_ENV !== "production"` 才放行，否则返回 404。**生产环境不可用**。 +::: + +工作流：以请求路径定位 `provider/route` 目录，`readLatestFixture()` 读 `latest.json`，按 fixture 内容回放响应。**无需 auth**，靠 NODE_ENV 隔离。 + +查询参数： + +| 参数 | 行为 | +| -------------------------- | -------------------------------------- | +| `provider=` | 切换 provider，默认 `"default"` | +| `mock_stream=1` | 按 SSE chunks 回放 | +| `mock_error=429` | 直接以指定状态码失败响应 | +| `mock_delay_ms=` | 在响应前注入延迟 | +| `mock_interrupt_after=` | 流式模式专用，回放 `n` 个 chunk 后中断 | + +主要用于： + +- 复现某次失败：找到对应 fixture，用 mock 端点重放给开发环境的客户端。 +- 离线 / 弱网调试：让客户端连到 mock 端点，不消耗真实 Key。 +- 压测协议层：让 client 反复打 mock 端点测自身解析能力，绕开上游配额。 + +## 前端：`/system/traffic-recording` 页面 + +UI 操作（`src/app/[locale]/(dashboard)/system/traffic-recording/page.tsx`）： + +- **Settings 卡片**：enabled 开关 / mode 下拉（`failure` / `success` / `all`）/ `redact_sensitive` 开关 / `retention_days` 输入框 / Save 按钮。保存即生效。 +- **统计面板**：记录总数 / 磁盘用量（formatBytes）/ 当前 mode / 最新录制时间。 +- **过滤列表**：状态码（200/400/401/429/500/all）/ model 模糊搜索 / api_key_id 精确 / upstream_id 精确 / 时间范围（today/7d/30d/自定义）。 +- **列表列**：时间 / 状态码 badge / model / method+path / fixture 大小 / 脱敏 badge / 操作。 +- **操作按钮**：「查看详情」（内联展开 fixture JSON）/「打开来源日志」（跳到 `/logs?focus=`，仅有 request_log_id 时显示）/「删除」（二次确认）。 +- **「清理过期」**：触发 `POST /api/admin/traffic-recordings/cleanup`。 + +## 实用配方 + +### 我只想录制失败请求做事后排查 + +默认配置就是。把 `enabled` 切到 `true`、`mode` 保持 `failure` 即可。开启后未来失败的请求都会被录制，已发生的请求不会回溯录制。 + +### 我想给某次故障录一份完整快照 + +短时间打开 `mode = all`，定向触发问题请求，结束后改回 `failure`。注意 `all` 模式磁盘占用涨得很快，不要忘记切回。 + +### 我想用录制 fixture 在开发环境回放 -录制规则配置、敏感字段脱敏开关（`RECORDER_REDACT_SENSITIVE`）、用途。 +1. 把 fixture 文件 / 目录从生产环境拷到开发环境的 `RECORDER_FIXTURES_DIR` 下，保持 `provider/route` 目录结构。 +2. 在 dev server 上请求 `/api/mock/<原 path>?provider=&mock_stream=1`。 +3. mock 端点会读对应目录的 `latest.json` 回放。 -## 在正文就绪前的临时建议 +如果想精确回放某个时间戳文件，把它 rename 成 `latest.json` 覆盖原文件即可。mock 端点目前不支持按时间戳精确选择。 -在该文档正文上线之前，可以参考以下材料获取等价信息： +## 不在本页范围内 -- 项目仓库根目录的 [README.md](https://github.com/g1331/AutoRouter/blob/master/README.md) -- 现有长篇 [`docs/cliproxy-deployment.md`](/cliproxy-deployment) -- 现有长篇 [`docs/circuit-breaker.md`](/circuit-breaker) -- 项目 [Issue 列表](https://github.com/g1331/AutoRouter/issues) 与 [OpenSpec 提案](https://github.com/g1331/AutoRouter/tree/master/openspec) +- 字段级到底落了哪些计费维度：见 [请求日志与统计](./logs-stats)。 +- 上游模型与 routing decision 的字段语义：见 [请求生命周期](../architecture/request-lifecycle)。 +- CLIProxyAPI 管理 API 的 fixture / OAuth credentials 备份：见 [CLIProxyAPI 出站代理配置](./cliproxy-egress-proxy) 与 [CI 部署后追加 CLIProxyAPI sidecar](../deployment/cliproxy-sidecar)。 diff --git a/docs/guide/usage/troubleshooting.md b/docs/guide/usage/troubleshooting.md index 076e8852..835b51cb 100644 --- a/docs/guide/usage/troubleshooting.md +++ b/docs/guide/usage/troubleshooting.md @@ -5,19 +5,162 @@ outline: deep # 故障排查手册 -::: warning 撰写中 -此文档目前为占位，正文尚未填充。完整撰写进度跟踪见 [issue #167](https://github.com/g1331/AutoRouter/issues/167)。 -::: +本手册按「客户端可见症状 → 错误码 / 字段 → 根因 → 排查路径」组织，覆盖部署成功后**运行期**会遇到的常见问题：客户端 Key、路由 / 候选上游、流式中断、CLIProxyAPI、计费、日志兜底。每条尽可能给出源码位置以便深入。 -## 计划覆盖的内容 +部署期问题（容器起不来、healthcheck 失败、`ENCRYPTION_KEY` 丢失等）在 [部署侧排查](../deployment/troubleshooting) 中处理，本页不重复。熔断状态机的细节排查在 [现有长篇 `docs/circuit-breaker.md`](/circuit-breaker) 的 Troubleshooting 一节，本页只列**用户可见的入口**。 -常见错误码、上游 5xx、SSE 中断、计费异常等场景的排查路径。 +## 一、客户端 Key 相关 -## 在正文就绪前的临时建议 +| 客户端看到的响应 | 触发位置 | 根因 / 排查方向 | +| ------------------------------------------------------------------------------------ | ----------------------------------------------------- | --------------------------------------------------------------------------------------------------------------------------------------------------- | +| `401 {"error":"Missing API key"}` | `route.ts:2446-2449` | 三个 header（`Authorization` / `x-api-key` / `x-goog-api-key`）都没值。检查客户端 SDK 是否真的把 Key 注入到请求 | +| `401 {"error":"Invalid API key"}` | `route.ts:2454-2473` | 按 keyPrefix 找不到激活 key，或 hash 校验失败。先在管理后台用前缀搜确认 key 存在且 active | +| `401 {"error":"API key has expired"}` | `route.ts:2463-2465` | `candidate.expiresAt < new Date()`。如要延期，到管理后台改 `expires_at` | +| `403 {error:{code:"API_KEY_MODEL_NOT_ALLOWED", ...}}` | `route.ts:2507-2542` | Key 的 `allowedModels` 列表不含请求模型。要么把模型加进 allowedModels，要么换 Key | +| `403 {error:{code:"NO_AUTHORIZED_UPSTREAMS"}}` | `route.ts:2726-2745`、`load-balancer.ts:39-44` | Restricted 模式 Key 未绑定任何能匹配的上游，或绑定上游全被 model rule 排除。检查 Key→Upstream 绑定与上游 model_rules | +| `429 {error:{code:"API_KEY_QUOTA_EXCEEDED", user_hint:"当前密钥已达到消费限额..."}}` | `route.ts:163-280`、`api-key-quota-tracker.ts:62-133` | Key 已超 spending quota；仅 streaming + 可定价模型触发主动拒绝。In-memory tracker 同步周期：80% 以下 5 min，80%+ 紧急 1 min。涨额度后等下次同步生效 | -在该文档正文上线之前，可以参考以下材料获取等价信息： +排查 Key 维度问题，最快路径是 `/logs?api_key_id=` 看最近一批请求的 status_code 与 `error_message`。 -- 项目仓库根目录的 [README.md](https://github.com/g1331/AutoRouter/blob/master/README.md) -- 现有长篇 [`docs/cliproxy-deployment.md`](/cliproxy-deployment) -- 现有长篇 [`docs/circuit-breaker.md`](/circuit-breaker) -- 项目 [Issue 列表](https://github.com/g1331/AutoRouter/issues) 与 [OpenSpec 提案](https://github.com/g1331/AutoRouter/tree/master/openspec) +## 二、路由 / 候选上游 + +| 响应 | 触发位置 | 根因 / 排查方向 | +| -------------------------------------------------------------------------------- | ---------------------------------------- | ----------------------------------------------------------------------------------------------------------------- | +| `503 {error:{code:"NO_UPSTREAMS_CONFIGURED"}}`（reason：路径不支持） | `route.ts:2547-2625` | `resolveRouteCapability` 返回 null。请求 method+path 不在已知 capability 列表里 | +| `503 {error:{code:"NO_UPSTREAMS_CONFIGURED"}}`（reason：池为空） | `route.ts:2703-2724` | 活跃上游中没有一条声明匹配的 `route_capabilities`。检查上游列表 + `is_active` | +| `503 {error:{code:"NO_UPSTREAMS_CONFIGURED", reason:"NO_HEALTHY_CANDIDATES"}}` | `route.ts:2749-2813`、`route.ts:591-624` | Key 绑定上游或 capability 池在 model rule 过滤后为空。检查 `model_rules` 与拼写 | +| `503 {error:{code:"ALL_UPSTREAMS_UNAVAILABLE", reason:"NO_HEALTHY_CANDIDATES"}}` | `load-balancer.ts:1141-1144`、`:243-303` | 所有 tier 遍历完毕：上游或熔断 OPEN 未到期，或 quota 耗尽。看每个上游的 circuit_breaker_states 与上游绑定的 quota | +| `503 {error:{code:"ALL_UPSTREAMS_UNAVAILABLE", reason:"CONCURRENCY_FULL"}}` | `load-balancer.ts:49-62, 1129-1144` | `max_concurrency` 全打满且未启用队列 | +| `504 {error:{code:"QUEUE_WAIT_TIMEOUT"}}` | `upstream-queue-admission.ts:89-118` | 进入队列但 `timeout_ms` 内未拿到槽位 | +| `499 {error:{code:"CLIENT_DISCONNECTED"}}` | `upstream-queue-admission.ts:89-118` | 客户端在排队期间断开了连接 | +| `503 {error:{code:"QUEUE_FULL", reason:"queue_full"}}` | `upstream-queue-admission.ts:189-197` | 队列已达 `max_queue_length`，直接拒绝 | + +### HALF_OPEN 探针失败循环（症状不直接报错，但成功率低） + +熔断 `HALF_OPEN` 时按 `probeInterval` 间隔放一条探针请求，失败立即回 OPEN（`load-balancer.ts:282-296`）。表现为： + +- 客户端偶发收到 5xx / 超时，成功率波动。 +- `request_logs.failover_history` 里能看到对该上游的尝试 → 失败 → 跳到下一个。 +- 上游的 `circuit_breaker_states` 在 OPEN 与 HALF_OPEN 间反复切。 + +排查：先看该上游的实际健康状态（直接对它发一个最小测试请求），不是熔断的锅而是上游本身在恢复。详细的熔断状态机参考 [现有长篇 `docs/circuit-breaker.md`](/circuit-breaker) 的 Troubleshooting 节。 + +### `routing_decision` 字段拿不准 + +每条 `request_logs` 都有一个 `routing_decision`（JSON），完整记录了候选池、被过滤的原因、最终选择。排查路由层问题时优先看它，而不是凭推测。字段语义在 [请求生命周期](../architecture/request-lifecycle) 里展开。 + +## 三、流式 / SSE 中断 + +| 客户端看到 | 错误码 | 根因 | +| -------------------------------------------------------------------- | ----------------------------- | --------------------------------------------------------------------------------------------------------------------------------------------------------- | +| 流途中收到 `event: error` 后断流，data 含 `"code":"REQUEST_TIMEOUT"` | `REQUEST_TIMEOUT`（HTTP 504） | `streamIdleTimeout` 内未收到新数据块。`route.ts:2082-2084`、`proxy-client.ts` 的 `StreamIdleTimeoutError` | +| 流途中收到 `event: error`，data 含 `"code":"STREAM_ERROR"` | `STREAM_ERROR`（HTTP 502） | 流中其他读取异常（连接重置 / 协议错误等） | +| 流开始前失败 | 走普通 5xx | 还能 failover，参见上一节 | +| 流开始**后**中断 | 仅 SSE error event | **不可重试**——AutoRouter 不会做 mid-stream failover，因为已经向客户端发送了头与部分 body。详见 [请求生命周期](../architecture/request-lifecycle) 第六阶段 | + +`is_stream=true` 的请求一旦写出第一个字节，AutoRouter 失去重试机会；这是协议层面的硬约束，不是 bug。如果客户端要在中断时换上游，需要客户端自己负责重新建连。 + +## 四、CLIProxyAPI 相关 + +四态判定（`cliproxy-connection-tester.ts:83-123`，详见 [CLIProxyAPI 首次使用指南](./cliproxy-first-time)）： + +| 状态 | 触发 | 客户端可见 | 排查方向 | +| --------------- | ----------------------------- | ------------------------------------------------------ | ---------------------------------------------------------------------- | +| `unreachable` | 10 秒超时、DNS 失败、拒绝连接 | 上游同步失败、账号列表为空；调用走 failover 或全部熔断 | sidecar 服务名拼错、CPA 容器未起、网络不通 | +| `auth_failed` | HTTP 401 / 403 | 管理 API 操作全部失败 | `management_key` 与 CPA 容器 env 中的 `CLIPROXY_MANAGEMENT_KEY` 不一致 | +| `service_error` | 其他非 2xx | 同上 | 看 CPA 容器日志，可能是 CPA 内部异常 | +| `success` | 2xx | 正常 | — | + +### OAuth 账号失效 + +`cliproxy_auth_accounts` 表的字段： + +| 字段 | 含义 | +| ------------------------- | ---------------------------------------------- | +| `disabled` | 账号被显式 disable（管理后台启停按钮触发） | +| `rawMetadata.unavailable` | CPA 侧自己标记为不可用 | +| `modelCount` | 同步时拉到的模型数；查询失败时回落到上次值或 0 | + +判定（`cliproxy-auth-account-service.ts:29, 149-156`）：disabled / unavailable 的账号，CPA 拒绝转发，AutoRouter 看到失败后 failover 到下一条池上游。 + +排查：管理后台 **CLIProxyAPI 实例 → 账号列表** 查 disabled / unavailable / modelCount=0 的账号，必要时重新走一次 OAuth 登录刷新。 + +### 删除 CLIProxy 实例时报「仍在使用」 + +`409 CliproxyInstanceInUseError` —— 实例下仍有引用未清理。删除顺序与原因见 [CLIProxyAPI 外部 vs sidecar 选择](./cliproxy-modes) 的「删除实例的影响」一节。 + +### CPA 出站代理改了不生效 + +`CLIPROXY_PROXY_URL` 是容器启动期 env 注入，`docker compose restart` 不会重读 `.env`。要重建容器，详见 [CLIProxyAPI 出站代理配置](./cliproxy-egress-proxy)。 + +## 五、计费相关 + +### FK 违例自动重试 + +写 `request_billing_snapshots` 时 PG 抛 `23503` 外键违例（API key 或 upstream 在 snapshot 写入与请求处理之间被并发删除），`billing-cost-service.ts:109-144` 会把违反的 `api_key_id` 或 `upstream_id` 置 NULL 后重试，**最终行能写进去**。 + +判定逻辑（PR #170 / #172 / #173 三次叠加）：同时检查顶层 `.code` 与 `.cause.code`，以及 error message 文本——同一类问题不同库版本错误结构不一样。 + +如果日志里大量出现 `billing snapshot FK violation retried with NULL` warning，说明有 key 或上游在被频繁删除，应该查删除来源（人工删 / 脚本 / 测试串到生产？）。 + +### duration_ms 显示约 24.8 天 + +`Math.min(Math.max(0, durationMs), INT4_MAX)` 的 clamp 上限是 2,147,483,647 ms ≈ 24.8 天（`request-logger.ts:21,411-417`）。读到这个值通常意味着原始 duration 异常大或溢出过 INT4，clamp 之后才能写库，**不是真的跑了 24.8 天**。配合 status_code 一起看，多半是 520（见下）或上游长时间 stuck。 + +### `status_code = 520`：stale 兜底 + +`reconcileStaleInProgressRequestLogs`（`request-logger.ts:524-569`）把 15 分钟内仍是 `status_code IS NULL` 的非流式行标记为 520，`errorMessage = "Request did not settle before the stale reconciliation timeout window"`。 + +读到 520 **不是上游真的返了 520**，而是 reconcile 兜底。排查： + +1. 看这批 520 集中在哪个时间点 → 大概率是上一次服务重启 / crash。 +2. 看具体行的 `upstream_id` → 是否有特定上游在那段时间长时间无响应。 +3. 如果 520 持续出现，说明有代码路径漏写 update（应该是 bug，去 grep `logRequestStart` 但没有对应 `updateRequestLog` 的分支）。 + +### 计费快照标记 unbilled + +`billing-cost-service.ts:432-449` 的 `UnbillableReason`： + +| reason | 含义 | +| ------------------- | --------------------------------------------------- | +| `model_missing` | `model` 字段为空 | +| `usage_missing` | prompt / completion / total 三个 token 都为 0 | +| `price_not_found` | 模型在 manual / openrouter / litellm 价表中都没命中 | +| `calculation_error` | 算价过程异常 | + +`price_not_found` 是最常见的——新模型 / 自定义模型需要在管理后台「定价管理」补一条 manual 价格，或等价表 sync。 + +## 六、日志加载相关 + +| 症状 | 根因 / 排查 | +| ------------------------------------------ | --------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| `/logs` 列表偶发卡顿，第一页 1-2 秒才出 | `listRequestLogs` 调用前会先跑一次 `reconcileStaleInProgressRequestLogs`（`request-logger.ts:706-710`），若上次 stale 行较多会拖慢首响应。失败仅 warn，不影响列表本身 | +| Live 模式连不上 / 一直 `fallback` | `/api/admin/logs/live` SSE 是进程内 pub/sub，**多副本部署**下不跨实例。检查 LB 是否启用了粘性会话；本机直连测试 SSE 端点 | +| 列表里出现一批 520 + duration_ms ≈ 24.8 天 | 见上一节「status_code = 520」 | +| 列表过滤参数说不支持 model | `/api/admin/logs` 的 query 参数确实没有 `model`（`route.ts`）。按模型查只能走 leaderboard 或客户端 | + +## 七、什么时候开请求录制 + +录制是事后排查最有力的工具，但默认关。开启场景： + +- 复现某次只发生在生产的失败：临时 `mode = failure`（默认就是），等待发生后取 fixture 在 dev 用 `/api/mock` 回放。 +- 调试新接入的客户端协议层 / 上游变体：`mode = all` 短时间打开，定向触发若干请求，**结束后立即切回 failure**——`all` 模式磁盘占用涨得很快。 + +完整设置见 [请求录制](./request-recording)。 + +## 八、什么时候要看 `routing_decision` / `failover_history` + +| 场景 | 优先看 | +| -------------------------------------- | --------------------------------------------------- | +| 客户端报 5xx，想知道是哪条上游挂了 | `failover_history` | +| 客户端报「为什么没选我希望的那条上游」 | `routing_decision`（候选池 / 过滤原因 / 选中原因） | +| Session affinity 没生效 | `session_id` / `affinity_hit` / `affinity_migrated` | +| 想知道某次请求做了几次 failover | `failover_attempts` | + +字段位置见 [请求日志与统计](./logs-stats)。 + +## 不在本页范围内 + +- 部署期问题（容器无法启动、healthcheck 失败、`ENCRYPTION_KEY` 丢失、数据库连接失败）：见 [部署侧排查](../deployment/troubleshooting)。 +- 熔断状态机细节、failover 不工作、failover 高延迟：见 [现有长篇 `docs/circuit-breaker.md`](/circuit-breaker) 的 Troubleshooting 节。 +- CLIProxyAPI 部署侧问题（sidecar 起不来、CPA 自身配置）：见 [现有长篇 `docs/cliproxy-deployment.md`](/cliproxy-deployment) 与 [CI 部署后追加 CLIProxyAPI sidecar](../deployment/cliproxy-sidecar)。