docs+perf: 定位 API 慢的真实瓶颈并移除 new-api 残留

- 新增 docs/6 openclaw-API响应性能分析与优化.md:两天 419 次调用 / 69 段交互实测,
  deepseek-flash p50 302ms 而模型耗时仅占 5.4%,94.6% 花在串行工具循环;
  new-api 慢 5 倍(p50 1463ms)已消除;含 P0/P1/P2 优化建议与未验证项声明
- 新增 scripts/perf-analyze.py:复现时间预算分析的配套脚本
- 5 个 agent 的 models.json 移除残留 new-api provider(含指向 192.168.2.74:3000
  与 100.115.195.188:3000 的条目及明文 key),主模型回退 deepseek-flash
- README 登记第 6 份文档
This commit is contained in:
yangxuan
2026-09-16 16:23:32 +08:00
parent 5ac4289f66
commit 5328320396
8 changed files with 417 additions and 852 deletions
+1 -116
View File
@@ -1,118 +1,3 @@
{ {
"providers": { "providers": {}
"openai": {
"baseUrl": "http://192.168.2.74:3000/v1",
"apiKey": "sk-vaYyq9RwzyLlvAvHHUXzOTWkbioP76YW58vKuplq2npSkfZr",
"api": "openai-completions"
},
"new-api": {
"baseUrl": "http://192.168.2.74:3000/v1",
"apiKey": "sk-vaYyq9RwzyLlvAvHHUXzOTWkbioP76YW58vKuplq2npSkfZr",
"api": "openai-completions",
"request": {
"allowPrivateNetwork": true
},
"models": [
{
"id": "qwen3.7-max",
"name": "Qwen 3.7 Max",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "deepseek-v4-pro",
"name": "DeepSeek V4 Pro",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "deepseek-v4-flash",
"name": "DeepSeek V4 Flash",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 8192
},
{
"id": "glm-5.1",
"name": "GLM 5.1",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "kim-k2.6",
"name": "Kimi K2.6",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "qwen3.5-plus",
"name": "Qwen 3.5 Plus",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
}
]
}
}
} }
-289
View File
@@ -138,295 +138,6 @@
} }
} }
] ]
},
"qwen35-plus": {
"baseUrl": "http://192.168.2.74:3000/v1",
"apiKey": "sk-vaYyq9RwzyLlvAvHHUXzOTWkbioP76YW58vKuplq2npSkfZr",
"api": "openai-completions",
"request": {
"allowPrivateNetwork": true
},
"models": [
{
"id": "qwen3.7-max",
"name": "Qwen 3.7 Max",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "deepseek-v4-pro",
"name": "DeepSeek V4 Pro",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "deepseek-v4-flash",
"name": "DeepSeek V4 Flash",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 8192
},
{
"id": "glm-5.1",
"name": "GLM 5.1",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "kim-k2.6",
"name": "Kimi K2.6",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "qwen3.5-plus",
"name": "Qwen 3.5 Plus",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
}
]
},
"new-api": {
"baseUrl": "http://192.168.2.74:3000/v1",
"apiKey": "sk-vaYyq9RwzyLlvAvHHUXzOTWkbioP76YW58vKuplq2npSkfZr",
"api": "openai-completions",
"request": {
"allowPrivateNetwork": true
},
"models": [
{
"id": "qwen3.7-max",
"name": "Qwen 3.7 Max",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768,
"api": "openai-completions"
},
{
"id": "deepseek-v4-pro",
"name": "DeepSeek V4 Pro",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768,
"api": "openai-completions"
},
{
"id": "deepseek-v4-flash",
"name": "DeepSeek V4 Flash",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 8192,
"api": "openai-completions"
},
{
"id": "glm-5.1",
"name": "GLM 5.1",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768,
"api": "openai-completions"
},
{
"id": "kim-k2.6",
"name": "Kimi K2.6",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768,
"api": "openai-completions"
},
{
"id": "qwen3.5-plus",
"name": "Qwen 3.5 Plus",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768,
"api": "openai-completions"
}
]
},
"openai": {
"baseUrl": "http://192.168.2.74:3000/v1",
"apiKey": "sk-vaYyq9RwzyLlvAvHHUXzOTWkbioP76YW58vKuplq2npSkfZr",
"api": "openai-completions",
"models": []
},
"newapi": {
"baseUrl": "http://100.115.195.188:3000/v1",
"apiKey": "NEW_API_KEY",
"api": "openai-completions",
"models": [
{
"id": "qwen3.5-plus",
"name": "Qwen 3.5 Plus",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 8192,
"api": "openai-completions"
},
{
"id": "deepseek-v4-flash",
"name": "DeepSeek V4 Flash",
"reasoning": false,
"compat": {
"supportsTools": false
},
"input": [
"text"
],
"cost": {
"input": 1,
"output": 2,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 1000000,
"maxTokens": 384000
},
{
"id": "qwen3.7-plus",
"name": "Qwen 3.7 Plus",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 1,
"output": 2,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 1000000,
"maxTokens": 384000
}
]
} }
} }
} }
-277
View File
@@ -138,283 +138,6 @@
} }
} }
] ]
},
"qwen35-plus": {
"baseUrl": "http://192.168.2.74:3000/v1",
"apiKey": "sk-vaYyq9RwzyLlvAvHHUXzOTWkbioP76YW58vKuplq2npSkfZr",
"api": "openai-completions",
"request": {
"allowPrivateNetwork": true
},
"models": [
{
"id": "qwen3.7-max",
"name": "Qwen 3.7 Max",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "deepseek-v4-pro",
"name": "DeepSeek V4 Pro",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "deepseek-v4-flash",
"name": "DeepSeek V4 Flash",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 8192
},
{
"id": "glm-5.1",
"name": "GLM 5.1",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "kim-k2.6",
"name": "Kimi K2.6",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "qwen3.5-plus",
"name": "Qwen 3.5 Plus",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
}
]
},
"new-api": {
"baseUrl": "http://192.168.2.74:3000/v1",
"apiKey": "sk-vaYyq9RwzyLlvAvHHUXzOTWkbioP76YW58vKuplq2npSkfZr",
"api": "openai-completions",
"request": {
"allowPrivateNetwork": true
},
"models": [
{
"id": "qwen3.7-max",
"name": "Qwen 3.7 Max",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "deepseek-v4-pro",
"name": "DeepSeek V4 Pro",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "deepseek-v4-flash",
"name": "DeepSeek V4 Flash",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 8192
},
{
"id": "glm-5.1",
"name": "GLM 5.1",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "kim-k2.6",
"name": "Kimi K2.6",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "qwen3.5-plus",
"name": "Qwen 3.5 Plus",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
}
]
},
"newapi": {
"baseUrl": "http://100.115.195.188:3000/v1",
"apiKey": "sk-vaYyq9RwzyLlvAvHHUXzOTWkbioP76YW58vKuplq2npSkfZr",
"api": "openai-completions",
"models": [
{
"id": "qwen3.5-plus",
"name": "Qwen 3.5 Plus",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 8192,
"api": "openai-completions"
},
{
"id": "deepseek-v4-flash",
"name": "DeepSeek V4 Flash",
"reasoning": false,
"compat": {
"supportsTools": false
},
"input": [
"text"
],
"cost": {
"input": 1,
"output": 2,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 1000000,
"maxTokens": 384000
},
{
"id": "qwen3.7-plus",
"name": "Qwen 3.7 Plus",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 1,
"output": 2,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 1000000,
"maxTokens": 384000
}
]
} }
} }
} }
+1 -61
View File
@@ -1,63 +1,3 @@
{ {
"providers": { "providers": {}
"newapi": {
"baseUrl": "http://100.115.195.188:3000/v1",
"apiKey": "sk-vaYyq9RwzyLlvAvHHUXzOTWkbioP76YW58vKuplq2npSkfZr",
"api": "openai-completions",
"models": [
{
"id": "qwen3.5-plus",
"name": "Qwen 3.5 Plus",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 8192,
"api": "openai-completions"
},
{
"id": "deepseek-v4-flash",
"name": "DeepSeek V4 Flash",
"reasoning": false,
"compat": {
"supportsTools": false
},
"input": [
"text"
],
"cost": {
"input": 1,
"output": 2,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 1000000,
"maxTokens": 384000
},
{
"id": "qwen3.7-plus",
"name": "Qwen 3.7 Plus",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 1,
"output": 2,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 1000000,
"maxTokens": 384000
}
]
}
}
} }
-109
View File
@@ -1,114 +1,5 @@
{ {
"providers": { "providers": {
"new-api": {
"baseUrl": "http://192.168.2.74:3000/v1",
"apiKey": "sk-vaYyq9RwzyLlvAvHHUXzOTWkbioP76YW58vKuplq2npSkfZr",
"api": "openai-completions",
"request": {
"allowPrivateNetwork": true
},
"models": [
{
"id": "qwen3.7-max",
"name": "Qwen 3.7 Max",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "deepseek-v4-pro",
"name": "DeepSeek V4 Pro",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "deepseek-v4-flash",
"name": "DeepSeek V4 Flash",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 8192
},
{
"id": "glm-5.1",
"name": "GLM 5.1",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "kim-k2.6",
"name": "Kimi K2.6",
"reasoning": false,
"input": [
"text"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
},
{
"id": "qwen3.5-plus",
"name": "Qwen 3.5 Plus",
"reasoning": false,
"input": [
"text",
"image"
],
"cost": {
"input": 0,
"output": 0,
"cacheRead": 0,
"cacheWrite": 0
},
"contextWindow": 131072,
"maxTokens": 32768
}
]
},
"deepseek": { "deepseek": {
"baseUrl": "https://api.deepseek.com/v1", "baseUrl": "https://api.deepseek.com/v1",
"api": "openai-completions", "api": "openai-completions",
+1
View File
@@ -10,6 +10,7 @@
| 3 | `agent-创建规范与自动化-设计.md` | **待实现的设计**:新建 agent 的命名规范(id 用 ASCII / 展示层全中文)、每 agent 专属 MySQL 库与专用账号、中文模板四件套、每日备份改造(硬编码→动态发现)、技能强制性(档①)与决策记录 | | 3 | `agent-创建规范与自动化-设计.md` | **待实现的设计**:新建 agent 的命名规范(id 用 ASCII / 展示层全中文)、每 agent 专属 MySQL 库与专用账号、中文模板四件套、每日备份改造(硬编码→动态发现)、技能强制性(档①)与决策记录 |
| 4 | `agent-创建规范-实现计划.md` | 上述设计的实现计划:任务切分(A 脚本+模板 / B skill / C 备份改造 / D 红线 / E 存量)、关键代码与验收标准 | | 4 | `agent-创建规范-实现计划.md` | 上述设计的实现计划:任务切分(A 脚本+模板 / B skill / C 备份改造 / D 红线 / E 存量)、关键代码与验收标准 |
| 5 | `agent-juaner-卷儿-检查报告.md` | juaner(卷儿)检查报告与决策:基本档案、职责设定 vs 实际行为、权限边界、**4 项发现**(记账零数据 / 无定时提醒 / bash 中文变量名不可用 / DREAMS 语言无配置解)、**2026-09-16 安全放宽决策**、邮箱登记与未决待办 | | 5 | `agent-juaner-卷儿-检查报告.md` | juaner(卷儿)检查报告与决策:基本档案、职责设定 vs 实际行为、权限边界、**4 项发现**(记账零数据 / 无定时提醒 / bash 中文变量名不可用 / DREAMS 语言无配置解)、**2026-09-16 安全放宽决策**、邮箱登记与未决待办 |
| 6 | `openclaw-API响应性能分析与优化.md` | **「API 响应很慢」的实测结论**:两天 419 次调用 / 69 段交互,deepseek-flash p50 **302ms** 而模型耗时仅占 **5.4%**(94.6% 花在串行工具循环);new-api 慢 5 倍已移除;含瓶颈定位、P0/P1/P2 优化建议、验收指标与**未验证项声明**。配套脚本 `scripts/perf-analyze.py` |
## 目录约定 ## 目录约定
@@ -0,0 +1,295 @@
# openclaw API 响应性能分析与优化
> **用途**:回答「openclaw API 响应很慢」这个问题——用网关日志实测定位瓶颈,给出可执行的优化清单。
> **配套**`bk02-openclaw-系统说明.md`(接手入口)、`openclaw-升级与维护.md`2026-09-16 升级记录)
> **主机**bk02 / `xuan-asus-nj` · 分析日期 2026-09-16 · 样本 `2026-09-15 ~ 2026-09-16` 两天全量网关日志
> ⚠️ 本目录**不含明文口令**(凭据位置见系统说明 §6)。
---
## 0. 结论速览(先看这段)
| 问题 | 结论 |
|---|---|
| **deepseek-flash API 慢吗?** | **不慢**。两天 383 次真实调用:p50 **302ms**、p90 510ms、均值 353ms。直连实测首字节 73ms |
| **那为什么感觉慢?** | **94.6% 的时间没花在模型上**。419 次调用、69 段交互实测:模型耗时合计 199.8s / 总跨度 3669.1s = **5.4%** |
| **真正的瓶颈** | **串行工具循环**。一次交互会连续调用模型几十次(实测单段最多 58 次),每次调用之间等工具/IO 平均 6 秒 |
| **new-api 网关慢吗?** | **慢 5 倍**`newapi/qwen3.5-plus` p50 **1463ms**、p90 3602ms vs deepseek-flash p50 302ms(已于 2026-09-16 删除) |
| **单次简单问答快吗?** | **快**。只有 2 次调用的短交互,模型占比 13%–26%,端到端 1.82.7 秒 |
**一句话**:慢的不是 API,是 **agent 的工具循环轮次 × 每轮工具耗时**。优化方向是「减少轮次」和「降低单轮工具等待」,不是换模型。
---
## 1. 实测数据
### 1.1 模型调用延迟分布(2026-09-15 ~ 09-16,全量)
| provider / model | 调用数 | p50 | p90 | max | 均值 | status |
|---|---|---|---|---|---|---|
| `deepseek/deepseek-flash` | 383 | **302ms** | 510ms | 3930ms | 353ms | 200 |
| `newapi/qwen3.5-plus` | 36 | **1463ms** | 3602ms | 6130ms | 2114ms | 200 |
### 1.2 直连 DeepSeek 官方 API 的网络实测
| 场景 | 结果 |
|---|---|
| `GET /v1/models` | `dns=2.3ms conn=10.9ms tls=69ms ttfb=137ms` |
| 极简请求(20 token 输出) | `ttfb=69ms total=881ms` |
| 流式输出 2000 token | `ttfb=73ms total=2.0s` |
| **长输入 234KB(约 3.2 万字符)** | `ttfb=88ms total=1.55s` |
→ 网络链路与 API 侧均无问题,**长上下文也不构成延迟**。
### 1.3 时间预算(核心证据)
按「响应间隔 > 120s」把 419 次调用切成 69 段交互,统计每段的模型耗时与总跨度:
| 交互开始 | 调用次数 | 模型耗时 | 总跨度 | **模型占比** |
|---|---|---|---|---|
| 16:02:57 | 32 | 19.4s | 450.0s | **4.3%** |
| 13:23:22 | 58 | 16.7s | 338.1s | **5.0%** |
| 12:31:47 | 50 | 18.0s | 695.0s | **2.6%** |
| 13:01:08 | 42 | 14.5s | 475.5s | **3.1%** |
| 00:12:54 | 33 | 16.0s | 302.3s | **5.3%** |
| 12:00:03 | 12 | 23.2s | 147.9s | 15.7%(走 new-api |
| 11:12:08 | 8 | 15.6s | 57.3s | 27.3%(走 new-api |
| 13:32:53 | 2 | 0.5s | 1.8s | **26.0%** |
| 15:02:53 | 2 | 0.5s | 2.3s | **19.9%** |
```
★ 合计:模型 199.8s / 跨度 3669.1s = 5.4% 非模型时间 94.6%
```
**规律非常清楚**
- **轮次少的交互(2 次调用)→ 模型占比 20%–26%,端到端 2 秒左右,体验流畅**;
- **轮次多的交互(32–58 次调用)→ 模型占比跌到 2.6%–5.4%,端到端 511 分钟**。
也就是说,用户感知的「慢」几乎全部落在模型调用**之间**的等待里。
### 1.4 单次交互的详细时间线(16:02:57 那段,共 450 秒)
```
+ 0.00s START deepseek-flash
+ 0.23s RESP 200 232ms ← 模型极快
+ 72.47s START deepseek-flash ← 中间 72 秒在装技能(ClawHub 安全审计+安装)
+ 76.40s RESP 200 3930ms
+ 77.76s START deepseek-flash
+ 78.06s RESP 200 305ms
+ 82.94s START ... ← 间隔 4.9s(工具执行)
+ 89.24s START ... ← 间隔 6.1s
+ 96.25s START ... ← 间隔 6.6s
+104.36s START ... ← 间隔 8.6s
+130.29s START ... ← 间隔 25.5s
+182.33s START ... ← 间隔 37.5s
+276.53s START ... ← 间隔 50.5s
+385.69s START ... ← 间隔 39.3s
+403.61s RESP 200 422ms ← 最后一次
```
该段共 32 次模型调用,模型自身合计 19.4 秒,其余 430 秒是工具执行、技能安装、上下文装配与网关等待。
### 1.5 调用量背景(为什么"慢"会被放大)
- 09-16 单日 140 次调用中,**12 次集中在同一分钟**(如 09:35 的 12 次、12:01 的 12 次)——即一次用户提问可触发十余次模型往返。
- 每分钟调用次数分布:1 次 = 34 分钟,3–5 次 = 10 分钟,**712 次 = 7 分钟**。
---
## 2. 瓶颈定位
### 2.1 主因:串行工具循环(占 94.6%)
openclaw 的 agent 是 ReAct 式循环:**模型判断 → 调工具 → 结果回灌 → 再问模型**,全程串行。实测典型循环步骤:
```
模型(0.3s) → 工具(3-30s) → 模型(0.4s) → 工具(5-40s) → ... → 最终回答
```
单轮工具的耗时来源(按实测出现频率排序):
| 来源 | 实测耗时 | 说明 |
|---|---|---|
| ClawHub 技能审计+安装 | 13.5s / 14s | 含安全审计、下载、安装、技能优先级冲突解析 |
| 文件读写 / 记忆检索 | 数秒 | `memory_search` 一次 `toolMs=639ms`,但多轮叠加 |
| 命令执行(exec) | 数秒至数十秒 | 如 `docker exec mysql ...`、脚本执行 |
| 外网请求 | 1040s | 搜索、抓取(searxng、邮件) |
| 上下文装配 | 单次约 150ms | `context_assembled``model_call_started` 差值 |
> 注意:**「94.6%」是两天混合负载的口径**,其中含技能安装、定时任务等批处理。日常纯问答型交互模型占比约 20%–26%(见 §1.3 最后两行)。**结论方向不变:瓶颈在模型之外。**
### 2.2 次因:new-api 网关慢 5 倍(已消除)
`newapi/qwen3.5-plus``100.115.195.188:3000`p50 1463ms,是 deepseek-flash 的 4.8 倍;两段走 new-api 的交互模型占比虽高(15.7%、27.3%),但**绝对耗时明显更差**12 次调用耗 23.2s,而 deepseek 32 次才 19.4s)。该 provider 已于 2026-09-16 全部移除。
### 2.3 已记录的异常事件
| 事件 | 次数 | 详情 | 影响 |
|---|---|---|---|
| `empty-error-retry` | 3 | `agent:juaner` 的 skill-workshop 评价任务报 `Cannot read properties of undefined (reading 'trim')`,重试 attempt 1/3→3/3 | 每次失败后重发请求,**额外增加延迟**;且最终仍失败 |
| DeepSeek 服务端 503 | 2 | 03:00:16 `elapsedMs=185`、03:01:14 `elapsedMs=77`(均为 03:00 定时任务期间) | 上游短暂不可用,openclaw 自行恢复;**当前无 failover 配置**`modelPolicy.allow` 仅 1 项) |
| `liveness heartbeat delayed` | 3 | `overdue≈1.01.5s elapsed≈31s` | 网关事件循环被阻塞约 31 秒,期间必须推迟恢复决策 |
### 2.4 配置层待确认项
| 项 | 当前值 | 问题 |
|---|---|---|
| `models.providers.deepseek.models[0].contextWindow` | `1000000` | 声明 1M 上下文,**未与 DeepSeek 官方实际能力核对**;配大了会让 openclaw 少触发压缩,长会话越跑越慢 |
| 同 `maxTokens` | `384000` | 同上,疑似超出上游上限(未验证) |
| 同 `reasoning` | `false` | 实测 `deepseek-flash` **会返回 `reasoning_content`**(是推理模型),此处语义与实际不符 |
| 模型请求 `timeoutMs` | `undefined` | 日志中 `timeoutMs=undefined`,**模型 HTTP 请求无显式超时**;挂住时只能靠 `agents.defaults.timeoutSeconds=3600`1 小时)兜底 |
| `agents.defaults.maxConcurrent` | `2` | 单 agent 并发上限 211 个 agent 共用同一 gateway 进程) |
| `tools.profile` | `full` | 全量工具集,工具越多模型越容易多轮试探 |
| CLI 运行时 | Node **22.23.1** | 非交互 shell 的 PATH 不含 nvm`node` 落到系统 `/usr/bin/node`(22),导致 `openclaw models list` **直接报错拒跑**(详见 §4 建议 P0-1 |
---
## 3. 优化建议
按「收益/成本」排序。**P0 = 立刻做;P1 = 值得做;P2 = 观察后再定。**
### P0-1 修 CLI 的 Node 版本(成本最低,先消除工具链故障)
**现象**`openclaw models list`
`Node 22.23.1: node:sqlite truncates TEXT at embedded NUL (nodejs/node#61954); use 24.16+/26.1+`
**根因(2026-09-16 核实)**:系统级 `/usr/bin/node`**v22.23.1**nvm 的 26.8.2 只在 `~/.nvm/versions/node/v26.8.2/bin/`。**非交互式 SSH(或任何未加载 nvm 的 shellPATH 不含 nvm 目录**,于是 `node` 落到 `/usr/bin/node` = 22
```
$ ssh bk02 'echo $PATH' → /home/yangxuan/.cargo/bin:/usr/local/bin:/usr/bin:/bin:...
$ ssh bk02 'node -v' → v22.23.1 ← 落到系统 node
$ ssh bk02 '~/.nvm/versions/node/v26.8.2/bin/node -v' → v26.8.2
```
> 与 `.nvmrc` **无关**(已验证 `~/.openclaw/.nvmrc`、`~/deepseek-harness/.nvmrc` 均不存在)。已确认 `nvm alias default` 本就是 `26`——**问题只在 PATH 未加载 nvm**。
**动作**:凡脚本 / 非交互调用 openclaw,都必须先加载 nvm 或用绝对路径,不要裸调 `node`
```bash
export NVM_DIR=$HOME/.nvm; . $NVM_DIR/nvm.sh # 交互式登录先做(系统说明 §0 已要求)
node -v # 期望 v26.8.2
openclaw models list --provider deepseek # 期望能正常列出
# 非交互/脚本场景:直接给绝对路径,绕开 PATH
~/.nvm/versions/node/v26.8.2/bin/node --version
```
### P0-2 减少工具循环轮次(针对 94.6%,收益最大)
轮次是延迟的乘数:**每减少一轮,省下「一次模型往返 + 一次工具等待」(实测中位 6 秒)**。
| 手段 | 动作 | 预期 |
|---|---|---|
| 收敛工具集 | 把高频 agent 的 `tools.profile``full` 收窄,或填写 `tools.allow` 白名单 | 模型少做无效试探,轮次下降(⚠️ 需实测,见 §5) |
| 提升单轮信息密度 | 在 agent 的 `AGENTS.md` 中要求「一次调用批量取证」:合并多次 `read`/`memory_search` 为一次 | 显著减少往返 |
| 并行取证 | 把可并行的只读操作交给 `subagents`(当前 `subagents.maxConcurrent=4` | 串行改并行 |
| 技能不必现装现用 | 需要什么技能**提前装好**,避免在对话中触发 ClawHub 审计+安装(实测单次 13.5–14s) | 消除最大单点等待 |
> ⚠️ 日志已显示 `tools.profile (full) allowlist contains unknown entries (feishu_*)`——存在**注册不上的工具条目**。先按系统说明排查清单清理,避免无效工具占位。
### P1-3 补上模型请求超时与 failover
- **显式超时**:当前 `timeoutMs=undefined`。建议为 provider 或模型显式设置请求超时(例如 120–300s),避免单次请求无限挂起拖满 `timeoutSeconds=3600`
- **failover**`modelPolicy.allow` 现仅 `deepseek/deepseek-flash` 一项,上游 503 时无备选。实测已出现 2 次 503。可考虑把已保留的 `siliconflow`(内容不冲突)登记为降级候选,或至少确认失败时的用户可见行为。
### P1-4 核对 deepseek-flash 的上下文与推理声明
按官方 `/v1/models` 与文档核对 `contextWindow` / `maxTokens`,把 `1000000` / `384000` 改成真实值;并把 `reasoning: false` 与实测「会返回 reasoning_content」的语义对齐(两者不一致时,reasoning token 的计费与展示都可能不符合预期)。
```bash
# 核对官方模型清单
curl -s https://api.deepseek.com/v1/models -H "Authorization: Bearer $DEEPSEEK_API_KEY"
```
### P1-5 处理 `empty-error-retry` 的 trim 崩溃
`agent:juaner` 的 skill-workshop 评价任务连续 3 次撞 `Cannot read properties of undefined (reading 'trim')`。这是 **openclaw 侧错误处理缺陷**(非模型问题):失败后重发 3 次,既慢又无效。建议升级 openclaw 后复测;若仍复现,向官方报 issue(附 `runId=skill-workshop-review:70d7e357-...`)。
### P2-6 降低定时任务对交互的干扰
`liveness heartbeat delayed`(事件循环阻塞 31 秒)+ 03:00 的 503,都出现在**定时任务窗口**。若仍有交互卡顿,检查 `cron.triggers` 的具体任务,避免定时任务与用户交互抢占同一 gateway(`maxConcurrent=2`)。
---
## 4. 验收与监控(改完怎么确认有效)
**核心指标:模型的「时间占比」而非「绝对延迟」。** 目标是把它从 5.4% 抬升上去(说明等待被消除),而不是继续压低已经很快的 302ms。
```bash
# 1) 复跑本次分析(脚本:~/.openclaw/scripts/perf-analyze.py,见 §7
python3 ~/.openclaw/scripts/perf-analyze.py
# 2) 看某次调用的实际延迟
grep "model-fetch] response" /tmp/openclaw/openclaw-$(date +%F).log | tail -5
# 3) 健康检查
openclaw doctor
```
**验收标准(建议)**
| 指标 | 现状 | 目标 |
|---|---|---|
| 纯问答型交互端到端 | 1.8–2.7s | ≤ 3s(已达标,保持) |
| 多轮任务型交互端到端 | 450s / 32 次调用 | **调用次数下降 ≥ 30%** 或端到端下降 ≥ 30% |
| 模型时间占比 | 5.4% | 上升(等待被消除的直接体现) |
| `empty-error-retry` | 3 次/2 天 | 0 |
| 技能现装现用 | 13.5–14s/次 | 0(预先安装) |
---
## 5. 未验证项(诚实声明)
本文所有数字都来自 **网关日志与直连 curl 实测**,但以下为**推断,尚未实测**,落地前请按标注方法验证:
| 未验证项 | 为何未验证 | 怎么验证 |
|---|---|---|
| 收窄 `tools.profile` 能提升速度 | 会改变 agent 能力,属行为变更,未擅自改 | 复制一个 agent 做 A/B,对比同一提示词的调用次数 |
| `contextWindow=1000000` 是错的 | 未拿到 DeepSeek 官方对该模型上下文的权威说明 | 官方文档/控制台核对,或用超长输入试探边界 |
| 工具耗时的精确归因 | 网关日志**未记录工具级耗时**(仅有工具失败记录),§2.1 的外部耗时来自会话内实际动作与时间线对齐 | 开启更详细日志级别后重测 |
| `maxConcurrent=2` 是否构成瓶颈 | 无并发排队记录 | 压测:并发发起 3 个会话观察排队 |
---
## 6. 附录:本次分析用到的命令
```bash
# 定位网关日志(注意:不在 ~/.openclaw/logs,而在 /tmp
ls -la /tmp/openclaw/openclaw-$(date +%F).log
# 统计模型调用延迟
grep "model-fetch] response" /tmp/openclaw/openclaw-2026-09-16.log \
| grep -oE "model=[^ ]+|elapsedMs=[0-9]+|status=[0-9]+"
# 找慢调用
grep "model-fetch] response" /tmp/openclaw/openclaw-2026-09-16.log \
| sed -E 's/.*elapsedMs=([0-9]+).*/\1 &/' | sort -rn | head -20
# 异常事件
grep -c "empty-error-retry" /tmp/openclaw/openclaw-2026-09-16.log
grep -oE "liveness heartbeat delayed[^\"]{0,60}" /tmp/openclaw/openclaw-2026-09-16.log
grep -oE "status=50[0-9][^\"]{0,60}" /tmp/openclaw/openclaw-2026-09-16.log
```
---
## 7. 配套脚本
`~/.openclaw/scripts/perf-analyze.py` —— 复现本文 §1.3 的时间预算分析:
```bash
python3 ~/.openclaw/scripts/perf-analyze.py [日志1 日志2 ...]
# 缺省分析 /tmp/openclaw/openclaw-<前一天>.log 与 <当天>.log
```
---
## 8. 附:2026-09-16 的配置变更(本文分析期间的改动)
| 变更 | 内容 | 生效方式 |
|---|---|---|
| 主配置 | 删除 `models.providers.newapi``modelPolicy.allow` 收敛为 `deepseek/deepseek-flash``sql` agent 主模型改为 deepseek | 配置热重载(日志:`config hot reload applied` |
| agent 级 `models.json` | `finances`/`main`/`resume`/`sql`/`travel` 各自残留的 new-api provider(含指向 `192.168.2.74:3000``100.115.195.188:3000` 的条目,含**明文 key**)全部移除 | 下次 gateway 启动生效 |
| 备份 | `~/.openclaw/openclaw.json.bak-20260916-161323-pre-newapi-removal``~/.openclaw/backups/agent-models-json-2026-09-16T0816/` | — |
> `agent` 级 `models.json` 是**第二套模型定义**(被 `loadCustomModels()` 读取),与主配置 `openclaw.json` 并行生效——排查模型问题时**两处都要看**,这是本次分析的第一个教训。
+119
View File
@@ -0,0 +1,119 @@
#!/usr/bin/env python3
"""openclaw API 响应性能分析 —— 复现 docs/6 的时间预算结论。
用法:
python3 ~/.openclaw/scripts/perf-analyze.py [日志文件 ...]
缺省分析 /tmp/openclaw/openclaw-<前一天>.log 与 <当天>.log。
核心指标: 模型调用耗时的「时间占比」(占比低 = 时间花在模型之外)。
"""
import json, re, sys, datetime, glob, os
from collections import defaultdict, Counter
IDLE_GAP = 120 # 秒: 超过此空闲视为新的一段交互
def default_logs():
today = datetime.date.today()
out = []
for d in (today - datetime.timedelta(days=1), today):
p = "/tmp/openclaw/openclaw-%s.log" % d.isoformat()
if os.path.exists(p):
out.append(p)
return out or sorted(glob.glob("/tmp/openclaw/openclaw-*.log"))
def sec(ts):
return datetime.datetime.fromisoformat(ts).timestamp()
def main():
logs = sys.argv[1:] or default_logs()
if not logs:
sys.exit("找不到日志: /tmp/openclaw/openclaw-*.log")
resps, starts, retries, delays = [], [], [], []
for L in logs:
with open(L, encoding="utf-8", errors="replace") as fh:
for line in fh:
if '"[model-fetch]' not in line and "empty-error-retry" not in line \
and "heartbeat delayed" not in line:
continue
try:
o = json.loads(line)
except Exception:
continue
t, m = o.get("time", ""), o.get("message", "")
if not t:
continue
if "[model-fetch] start" in m:
p = dict(re.findall(r"(\w+)=(\S+)", m))
starts.append((t, p.get("provider"), p.get("model")))
elif "[model-fetch] response" in m:
p = dict(re.findall(r"(\w+)=(\S+)", m))
try:
e = int(p.get("elapsedMs", 0))
except ValueError:
e = 0
resps.append((t, p.get("provider"), p.get("model"), e, p.get("status")))
if "empty-error-retry" in m:
retries.append(m[:150])
if "heartbeat delayed" in m:
delays.append(m[:100])
resps.sort()
starts.sort()
if not resps:
sys.exit("日志中无 model-fetch 记录")
print("日志文件: %s" % ", ".join(logs))
print("调用总数: start=%d response=%d" % (len(starts), len(resps)))
print("status 分布: %s" % dict(Counter(r[4] for r in resps)))
print("\n== 按 provider/model 的延迟(ms) ==")
g = defaultdict(list)
for _, pv, mo, e, _ in resps:
g["%s/%s" % (pv, mo)].append(e)
for k, v in sorted(g.items()):
v.sort()
print(" %-28s n=%-4d p50=%-6d p90=%-6d max=%-6d mean=%d"
% (k, len(v), v[len(v) // 2], v[int(len(v) * 0.9)], v[-1], sum(v) // len(v)))
print("\n== 时间预算(交互段, 空闲 > %ds 切分)==" % IDLE_GAP)
sessions, cur = [], [resps[0]]
for a, b in zip(resps, resps[1:]):
if sec(b[0]) - sec(a[0]) > IDLE_GAP:
sessions.append(cur)
cur = [b]
else:
cur.append(b)
sessions.append(cur)
print(" %-10s %5s %9s %9s %7s %s" % ("开始", "调用", "模型s", "跨度s", "模型占比", "主模型"))
tm = ts = 0.0
for s in sessions:
if len(s) < 2:
continue
span = sec(s[-1][0]) - sec(s[0][0])
if span <= 0:
continue
mod = sum(x[3] for x in s) / 1000.0
tm += mod
ts += span
top, n = Counter("%s/%s" % (x[1], x[2]) for x in s).most_common(1)[0]
print(" %-10s %5d %9.1f %9.1f %6.1f%% %s x%d"
% (s[0][0][11:19], len(s), mod, span, 100 * mod / span, top, n))
if ts > 0:
print("\n ★ 合计: 模型 %.1fs / 跨度 %.1fs = %.1f%%"
% (tm, ts, 100 * tm / ts))
print(" 非模型时间(工具/IO/上下文/等待) %.1f%% <- 高即说明瓶颈不在 API"
% (100 - 100 * tm / ts))
print("\n== 异常事件 ==")
print(" empty-error-retry: %d" % len(retries))
for r, c in Counter(retries).most_common(3):
print(" %dx %s" % (c, r))
print(" heartbeat delayed: %d" % len(delays))
for r, c in Counter(delays).most_common(3):
print(" %dx %s" % (c, r))
if __name__ == "__main__":
main()