OpenClaw 如何打印大模型请求响应时间？
最近在排查 OpenClaw 响应速度时遇到一个很典型的问题：
用户明明只问了一句话，为什么 AI 过了几十秒才回复？
第一反应通常是：
是不是大模型接口太慢了？
但“用户等了 30 秒”和“大模型请求花了 30 秒”完全是两回事。
一次 OpenClaw 请求，中间可能经历：
用户发送消息
↓
WeCom / Telegram / Slack
↓
OpenClaw 接收消息
↓
Agent 路由
↓
Context 构建
↓
请求大模型
↓
Tool / MCP 调用
↓
再次请求大模型
↓
生成最终答案
↓
发送给用户
所以想知道到底哪里慢，最直接的方法就是：
把每一次大模型 HTTP 请求的开始时间和响应时间打印出来。
一、开启模型 Transport 调试
OpenClaw 提供了模型 Transport 调试能力。
在 Docker 部署环境中，可以在 .env 中加入：
OPENCLAW_DEBUG_MODEL_TRANSPORT=1
如果还想进一步观察流式响应，可以加入：
OPENCLAW_DEBUG_SSE=events
例如：
OPENCLAW_DEBUG_MODEL_TRANSPORT=1
OPENCLAW_DEBUG_SSE=events
如果使用 docker-compose.yml，还要确认这些环境变量真正传进 Gateway：
environment:
OPENCLAW_DEBUG_MODEL_TRANSPORT: ${OPENCLAW_DEBUG_MODEL_TRANSPORT}
OPENCLAW_DEBUG_SSE: ${OPENCLAW_DEBUG_SSE}
修改完成后重新创建 Gateway：
docker-compose up -d --force-recreate openclaw-gateway
确认环境变量已经生效：
docker-compose exec openclaw-gateway env | grep OPENCLAW_DEBUG
正常情况下应该看到：
OPENCLAW_DEBUG_MODEL_TRANSPORT=1
OPENCLAW_DEBUG_SSE=events
二、发送一条测试消息
配置完成以后，通过企业微信等渠道发送一条消息。
例如：
北京朝阳未来7天的天气
然后查看 Gateway 日志：
docker-compose logs -f openclaw-gateway
或者只过滤模型请求：
docker-compose logs --since=10m openclaw-gateway \
| grep "model-fetch"
这时候就能看到非常关键的日志。
例如：
2026-08-20T01:53:36.046+00:00
[provider-transport-fetch] [model-fetch] start
provider=deepseek-v4-pro
api=openai-completions
model=deepseek-v4-pro
method=POST
url=https://api.example.com/v1/chat/completions
几秒后：
2026-08-20T01:53:39.405+00:00
[provider-transport-fetch] [model-fetch] response
provider=deepseek-v4-pro
model=deepseek-v4-pro
status=200
elapsedMs=3360
contentType=text/event-stream
这里最重要的字段就是：
elapsedMs=3360
也就是：
这次模型 HTTP 请求大约 3.36 秒拿到 HTTP 响应。
三、一次对话可能请求模型很多次
这是排查过程中最容易忽略的地方。
例如我测试一个天气问题时，日志中竟然出现了 4 次模型请求：
第 1 次
start 01:53:36.046
response 01:53:39.405
elapsedMs=3360
第 2 次
start 01:53:42.192
response 01:53:44.625
elapsedMs=2433
第 3 次
start 01:53:46.907
response 01:53:49.281
elapsedMs=2374
第 4 次
start 01:53:51.386
response 01:53:54.405
elapsedMs=3019
单独看每一次请求：
3.360 秒
2.433 秒
2.374 秒
3.019 秒
其实都不算特别慢。
但是四次加起来已经：
11.186 秒
这时候真正的问题可能就不是：
“为什么模型一次请求这么慢？”
而是：
“为什么这么简单的问题请求了四次模型？”
这两个问题的优化方向完全不同。
四、为什么 Agent 会连续请求模型？
Agent 和普通 ChatGPT API 调用最大的区别之一，就是：
一次用户请求 ≠ 一次模型请求。
例如一个天气问题可能经历：
用户：
北京朝阳未来7天的天气
↓
模型调用 #1
判断需要查询天气
↓
调用 Weather Tool
↓
模型调用 #2
分析 Tool 返回结果
↓
再次调用 Tool
↓
模型调用 #3
整理数据
↓
模型调用 #4
生成最终回答
↓
发送给用户
所以最终用户可能等待了 30 秒，但并不存在某一次：
模型请求 = 30 秒
真正的情况可能是：
模型 #1 3.36 秒
Tool 2.79 秒
模型 #2 2.43 秒
Tool 2.28 秒
模型 #3 2.37 秒
Tool 2.11 秒
模型 #4 3.02 秒
最终处理 9.37 秒
所有环节叠加起来，用户才感觉“AI 怎么这么慢”。
五、怎么判断到底是不是模型慢？
可以把一次完整请求拆成几个阶段。
例如：
01:53:31.757
OpenClaw 收到用户请求
01:53:36.046
模型请求 #1 开始
01:53:39.405
模型请求 #1 收到响应
01:53:42.192
模型请求 #2 开始
01:53:44.625
模型请求 #2 收到响应
01:53:46.907
模型请求 #3 开始
01:53:49.281
模型请求 #3 收到响应
01:53:51.386
模型请求 #4 开始
01:53:54.405
模型请求 #4 收到响应
01:54:03.775
最终回答发送给企业微信
整个过程大约：
32 秒
其中四次模型 HTTP 请求的 elapsedMs 合计：
11.186 秒
也就是说，至少从目前能观察到的 HTTP 时序看：
整个响应：约 32 秒
模型 HTTP 响应等待：
约 11.2 秒
其他环节：
约 20.8 秒
这时候就不能简单下结论：
“大模型接口太慢。”
因为模型请求之外还有大量时间消耗。
六、elapsedMs 也不等于模型完整生成时间
这一点尤其重要。
日志：
[model-fetch] response
elapsedMs=3360
contentType=text/event-stream
因为返回的是：
text/event-stream
说明这里使用的是流式响应。
所以这个 response elapsedMs 更接近：
从开始 HTTP 请求，到拿到 HTTP Response / 开始建立流式响应所经历的时间。
它并不一定代表：
模型把整篇回答全部生成完成花了 3.36 秒。
如果需要进一步判断模型速度，还应该关注：
Request Start
↓
HTTP Response
↓
First SSE Event
↓
Last SSE Event
↓
Stream Complete
其中两个指标尤其有价值：
TTFT / TTFB
首 Token 等待时间
Total Duration
完整生成耗时
比如：
模型请求开始：10:00:00
首 Token：
10:00:06
完整结束：
10:00:10
意味着：
首 Token 等待 ≈ 6 秒
完整模型调用 ≈ 10 秒
如果用户感觉慢，这时候基本可以确认模型 Provider 本身就是主要原因之一。
反过来：
首 Token：0.6 秒
完整生成：2.8 秒
用户最终收到：
15 秒
那模型就不应该背锅。
应该继续排查：
Agent 调度
Context 构建
Tool Call
MCP
知识库
插件
消息队列
企业微信发送
七、最简单的排查命令
平时排查问题，我现在最常用的就是：
docker-compose logs --since=10m openclaw-gateway \
| grep "model-fetch"
如果输出：
[model-fetch] start ...
[model-fetch] response ... elapsedMs=3360
[model-fetch] start ...
[model-fetch] response ... elapsedMs=2433
[model-fetch] start ...
[model-fetch] response ... elapsedMs=2374
[model-fetch] start ...
[model-fetch] response ... elapsedMs=3019
马上就能知道：
一次用户请求调用了多少次模型；
每次请求的是哪个 Provider；
使用的是什么模型；
请求哪个 API；
HTTP 状态码是多少；
每次 HTTP 请求多久拿到响应。
这已经足够解决大量“OpenClaw 为什么这么慢”的问题。
八、真正应该优化的可能不是模型速度
以前排查 Agent 响应慢，很容易第一时间怀疑：
模型不行，换个更快的模型。
但把 model-fetch 打出来以后，会发现很多时候问题并不是单次模型请求慢。
例如：
单次模型请求：2～3 秒
一次用户问题：
模型被调用 4 次
最终用户等待：
30+ 秒
这种情况下，即使把模型性能提高一倍：
3 秒 → 1.5 秒
四次模型调用也仍然存在。
真正值得优化的反而可能是：
4 次模型调用
↓
2 次模型调用
或者减少：
无意义 Tool Call
重复推理
重复 Context 构建
不必要的 Agent Loop
收益可能比单纯换模型更明显。
最后
Agent 系统的“响应速度”不能只看模型。
真正完整的链路应该是：
用户消息
↓
渠道接收
↓
OpenClaw 路由
↓
Agent
↓
模型请求 #1
↓
Tool
↓
模型请求 #2
↓
Tool
↓
模型请求 #3
↓
模型请求 #4
↓
生成最终回答
↓
渠道发送
↓
用户收到
开启：
OPENCLAW_DEBUG_MODEL_TRANSPORT=1
然后观察：
[model-fetch] start
[model-fetch] response
elapsedMs=xxxx
至少可以先回答一个非常重要的问题：
到底是大模型接口本身慢，还是整个 Agent 链路慢？
而当你发现一个简单问题竟然触发了四五次模型请求时，下一步真正值得研究的，可能已经不是“换哪个更快的大模型”，而是：
为什么 Agent 需要思考这么多轮才能把答案交给用户？
正文到此结束
热门推荐
相关文章
Loading...
![[HBLOG]公众号](https://www.harries.blog/img/qrcode_gzh.jpg)
