Marico's space
"同样的问题，今天花了四十秒。上周只要十秒。"
又是第2、3部分那位测试同学。她问Agent："我能退掉上一单的那件蓝色外套吗？"这个问题需要两次工具调用：一次查订单，一次读退换政策。上周大概十秒搞定。那天花了四十秒。
什么都没变。没有发布新版本，没有改配置，没有新数据。代码一周没动过。
但我解释不了，因为我没有任何一个步骤的具体耗时。我有日志，但那是一堆HTTP层的文本堆砌。我说不清那多出来的三十秒花在了记忆顾问、第1次模型调用、订单查询、政策查询还是最终模型调用。当你说不出时间花在哪，就没法修。最容易下的结论是"模型不行"，但通常这是个错误的判断。
那周晚些时候，Agent回答另一个问题也答错了。"给我看看蓝色外套"返回了毛衣。我又怪模型。结果发现是模型对关键词查询选了语义搜索工具，而语义搜索路径本来就是模糊的。我能搞清楚这个，是因为我终于能看到哪个工具被调用了、传了什么参数、按什么顺序执行的。
两个问题的答案其实一直都在我的应用内部。这篇文章就是把它们暴露出来。
我是达卡一家公司的高级软件工程师，用Spring Boot和Spring AI构建生产级AI Agent已经一年多了。下面所有内容都是我在第1、2、3部分那个Agent基础上加的（工具、记忆、流式响应）。没有新行为，只有可见性。
普通的REST调用是一个请求、一个响应、一个可以测量的耗时。Agent调用是一串链路。对于那个需要两个工具的问题，序列是：
这条链上任何一个环节都可能慢，也都可能错。用户只看到一个结果，但你需要看到每一步。
Spring AI已经为这些步骤埋好了监控点。查阅可观测性文档，Spring AI为核心组件记录了指标和链路：ChatClient（包括顾问）、ChatModel、EmbeddingModel和VectorStore。工具调用也有自己的观测数据。我在这部分做的主要是配置连接，不是写代码。
先解释两个术语。链路（trace）是用户一个问题完整的所有跨度（span）链条。跨度（span）是链条中的单个步骤，有名称、耗时和属性。观测（observation）是生成指标和跨度的命名测量。看到下面的gen_ai.前缀，那是跨AI工具的标准命名规范。
最省力的方式是让Spring AI做测量，你自己只接管道。两个pom.xml依赖：
<dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-actuator</artifactId>
</dependency>
<dependency> <groupId>io.micrometer</groupId> <artifactId>micrometer-registry-prometheus</artifactId>
</dependency>
application.yml里加一段暴露端点：
management: endpoints: web: exposure: include: health,info,prometheus
Spring Boot默认只通过HTTP暴露/actuator/health。上面的include行同时暴露了Prometheus抓取端点，这需要micrometer-registry-prometheus依赖（Spring Boot actuator文档确认了这两点）。
抓取/actuator/prometheus就能看到Spring AI的指标序列。我实际关注的三类：
gen_ai_chat_client_operation_seconds_* - 整个调用或流式响应，从提示词到最终答案。有spring_ai_chat_client_stream标签可以对比同步和流式调用。gen_ai_client_operation_seconds_* - 模型提供商的执行本身。gen_ai_client_token_usage_total - Token用量，按gen_ai_token_type标签区分input、output或total。检索还有第四类：db_vector_client_operation_seconds_*覆盖向量存储的添加、删除和查询，有db_system标签（我的显示simple，即内存存储）。
定时器在Prometheus里按标准后缀呈现。_seconds_sum和_seconds_count相除得到平均延迟，_seconds_max是最高水位，_active_count是当前在途的调用数。参考文档里有详细说明，平均延迟公式是sum / count。
我保存在备忘录里的查询：
# 每秒请求数（到模型提供商）
rate(gen_ai_client_operation_seconds_count[5m]) # 平均模型延迟
gen_ai_client_operation_seconds_sum / gen_ai_client_operation_seconds_count # 按方向统计token，每分钟
sum(rate(gen_ai_client_token_usage_total[5m])) by (gen_ai_token_type)
我环境里数据告诉我：工具从来不是瓶颈。数据库工具（searchProducts、getProductDetails、viewCart）每次只有几毫秒。语义搜索工具是个例外，因为SimpleVectorStore在搜索前要先给查询文本做Embedding（embedding），它本身也带了一次模型调用。那十到十二秒里其他一切都是模型调用，而且是两次。第3部分的流式响应是用户感受到的，这些指标才是实际计费的。
Token序列是最值得看的。看input token：记忆顾问每次都在开头拼接历史，对话每多一轮input token就涨一轮。这是第2部分滑动窗口的具体论据，也是成本讨论前要拿出来的数字，而不是事后诸葛亮。
指标告诉你Agent慢了。链路告诉你哪一步慢了。为此我加了OpenTelemetry链路追踪，配置方式按Spring Boot链路追踪文档：
<dependency> <groupId>io.micrometer</groupId> <artifactId>micrometer-tracing-bridge-otel</artifactId>
</dependency>
<dependency> <groupId>io.opentelemetry</groupId> <artifactId>opentelemetry-exporter-otlp</artifactId>
</dependency>
用management.opentelemetry.tracing.export.otlp.*属性指向任意OpenTelemetry采集器（Jaeger和Grafana Tempo都支持OTLP）。还有一个要主动设置的：采样。Spring Boot默认采样10%的请求，以保护链路后端。在追某个特定对话之前这样挺好，然后调高management.tracing.sampling.probability或在采集器里过滤。
那个两个工具问题的链路是一棵树，每个节点在可观测性文档里都有记录：
spring.ai.chat.client跨度覆盖整个调用，带有会话ID（spring.ai.chat.client.conversation.id）和工具名列表作为属性。我能搜到一个对话的完整链路。spring.ai.advisor跨度覆盖第2部分的记忆顾问，历史加载和保存是分开计时的。gen_ai.client.operation跨度覆盖每次模型调用，带有模型名、温度和Token用量作为属性。spring.ai.tool跨度。工具名是一级属性（spring.ai.tool.definition.name），操作是execute_tool，跨度计量工具完成的耗时。这就是"模型调用了错误的工具"从一种感觉变成链路里一行字的地方。一个开关要知道：spring.ai.tools.observations.include-content。设为true的话，工具跨度还携带输入参数和结果。对于购物Agent，这意味着收货地址和购物车内容。我生产环境关掉它，在dev profile里调试特定调用时才打开。文档警告了这个问题，他们是对的。
提示词日志开关同理：spring.ai.chat.client.observations.log-prompt和spring.ai.chat.observations.log-completion把完整提示词和补全结果写入日志。默认false，有充分理由。只在dev profile用。
一个已记录的特性要预期：对于OpenAI和Anthropic，流式调用的HTTP跨度不以模型跨度为父。因为SDK的异步流路径在到达HTTP客户端前跳上了一个共享线程池，观察上下文在边界处丢失了，HTTP跨度作为独立的根跨度出现。文档特别指出了OpenAI和Anthropic提供商。我的Agent目前跑Ollama，但教程的加固清单说模型提供商一换就行，到时候我知道不要把那个孤立跨度当作bug追。
链路是出问题时打开的。日志是凌晨三点grep用的。Spring AI记录HTTP和模型事件在INFO级别，但不记录Agent循环：哪个工具运行了、什么顺序、耗时多久。我自己在第3部分的用户控制工具循环里加了这些：
long requestStart = System.nanoTime(); while (true) { // ... stream and aggregate as in Part 3 ... if (response.chatResponse() == null || !response.chatResponse().hasToolCalls()) { break; } sendStatus(emitter, "Running a tool..."); long start = System.nanoTime(); ToolExecutionResult result = toolCallingManager.executeToolCalls(prompt, response.chatResponse()); long tookMs = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start); log.info("event=tool_call conversationId={} tookMs={}", conversationId, tookMs); prompt = new Prompt(result.conversationHistory(), chatOptions); ref.set(null);
} log.info("event=agent_reply conversationId={} tookMs={}", conversationId, TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - requestStart));
Key=value格式，每行一个事件，按会话ID可grep。实际长这样：
event=tool_call conversationId=8f3ac1f tookMs=41
event=tool_call conversationId=8f3ac1f tookMs=12
event=agent_reply conversationId=8f3ac1f tookMs=10430
这段代码有两个刻意为之的选择。我记会话ID，不记消息内容。我记耗时，不记参数。结账工具的参数是收货地址，我不希望那些进日志聚合。如果真需要，链路在dev环境里开了include-content后有，按需调用。
这层日志回答了那个四十秒的问题。数字终于在一处了，按步骤、按对话。我能看到模型调用才是那个账单项目，不用再猜了。
数字出来后发生了三件事，没一件我预见到了。
工具甩锅了。每次用户说"慢"，我先看模型跨度。工具跨度从来不是主角。这改变了我调试的方式，也改变了我跟非技术负责人沟通的方式：Agent的延迟就是模型的延迟，修复方法是第2、3部分那些（记忆窗口、流式响应、状态事件）。
错误工具调用Bug几分钟就定位了。链路显示semanticSearchProducts在"blue jacket"这类关键词查询上触发了，而应该用带过滤条件的searchProducts。语义路径返回模糊匹配，这就是毛衣的来源。修复不是改代码，是提示词工程：我重写了工具描述，说明什么时候用什么、什么时候不用。文档明确说模型根据描述选工具，项目里现在的描述体现了这个教训："当购物者给出具体标准如关键词时用这个"对比"当请求模糊或凭感觉时用这个"。没有链路，这个诊断要花一周，结论是"模型太蠢"。
Token指标让记忆成本变得具体。Input token随对话时长增加，因为历史每轮都被拼到开头。这个单一序列用数字证明了第2部分滑动窗口上限的必要性，这是任何人争论推理成本前要盯着的数字。
花一周建仪表盘太容易了。我只加了一个告警，就是能捕获四十秒回答的那个：
- alert: AgentReplySlow expr: rate(gen_ai_chat_client_operation_seconds_sum[5m]) / rate(gen_ai_chat_client_operation_seconds_count[5m]) > 30 for: 5m
这是过去五分钟的平均ChatClient耗时（文档里的sum/count平均，用rate表示成滑动窗口）。三十秒是我正常回答时间的三倍，所以足够早就触发，又足够稀有不会扰民。工具失败在观测的错误路径和异常日志里露出来；当这个Agent有真实流量后，我会加一个失败率告警，但不是现在。
如果这篇只记住一件事，记住这个清单：
spring.ai.tools.observations.include-content生产环境关掉，开发环境打开。我本来计划把多Agent模式塞进这篇，塞不下了。第5部分讲一个Agent委托给另一个的模式：一个监督Agent把任务交给专业Agent并等待结果，以及如何用同样的方式保持那条链的可观测性。