1. 从一次线上排障说起:为什么AI应用的链路追踪比普通服务更难
去年冬天,我接手了一个基于Spring AI搭建的智能问答服务。上线第三天,用户反馈"回答到一半突然断了,重试又好了"。我打开日志平台,看到的是这样的场景:一次请求在网关层有一个traceId,到了业务服务层变成了另一个,调用大模型的那段代码里压根没有traceId,流式返回的每个chunk散落在不同线程的日志里,根本拼不出一次完整的对话。更麻烦的是,用户说"它想了一半不说了",可我在日志里只能看到最终结果,中间模型到底输出了什么、在哪一步被截断,完全是个黑盒。
这件事让我意识到一个被很多人忽略的事实:AI应用的可观测性,和传统微服务的可观测性,根本不是一回事。传统服务调用是"请求-响应"的确定性链路,一次调用要么成功要么失败,链路清晰。而AI应用,尤其是接入大模型之后,一次用户请求背后可能是:提示词组装、向量检索、多轮工具调用、流式token生成、后处理过滤,每一步都可能是异步的、流式的、耗时的,而且模型输出本身带有不确定性。你如果还用老一套的日志埋点思路,最后拿到的就是一堆碎片。
这篇内容我想聊的就是怎么用Spring AI把这条链路真正串起来,核心抓手是traceId贯穿全链路,以及一个很多人想做但没做好的事情——把模型的思考过程实时"直播"给用户看。所谓直播,不是真的把模型内部权重暴露出来,而是把推理过程中的关键节点、工具调用、阶段性输出,通过流式通道实时推给前端,让用户看到"AI正在想什么"。这两件事合在一起,就是标题里说的"可观测与透明化"。
适合读这篇的人:正在用Spring AI或类似框架做AI应用的后端开发,被链路追踪和流式输出折磨过的;想给产品加"思考过程展示"但不知道怎么落地的;以及单纯想搞清楚AI应用可观测性该怎么设计的架构同学。我会从原理讲到代码,从踩坑讲到优化,尽量把每个"为什么这么设计"说透。
2. traceId贯穿全链路:从网关到模型调用的完整埋点方案
2.1 为什么MDC那套老办法在AI场景下会失效
传统Java服务里,我们习惯用SLF4J的MDC(Mapped Diagnostic Context)来传递traceId,配合拦截器在请求入口塞进去,线程内一路透传。这套东西在同步阻塞的MVC服务里工作得很好,因为一个请求从头到尾基本在一个线程里跑完。但AI应用有几个特性直接把它打穿了。
第一,流式返回天然跨线程。Spring AI的流式接口返回的是Flux<ChatResponse>或者StreamingResponseBody,数据在Reactor的调度器线程上产生,和你处理HTTP请求的线程不是同一个。MDC是基于ThreadLocal的,线程一换,traceId就丢了。第二,工具调用可能触发新的异步任务。模型决定调用某个工具时,这个工具执行可能是异步的,甚至可能再发起一次HTTP请求,链路在这里分叉。第三,多轮对话的上下文跨越多次请求。用户第一轮问、第二轮追问,这两次HTTP请求在服务端是两个独立trace,但业务上它们是同一条会话链路,需要有个sessionId或者conversationId把它们关联起来。
我踩过的第一个坑就是:以为在Controller入口塞了MDC就万事大吉,结果流式接口的日志里traceId全是空的。排查了半天才发现是Reactor线程切换导致的。
2.2 用Reactor Context替代ThreadLocal做上下文传递
正确的做法是拥抱Reactor的上下文机制。Reactor提供了一个Context,它能在响应式链路中自动传递,不依赖线程。核心思路是:在请求入口把traceId写入Reactor Context,然后在需要的地方通过Mono.deferContextual或者contextWrite读取。
具体落地分几步。首先定义一个上下文键和工具类:
public final class TraceContext { public static final String TRACE_ID_KEY = "traceId"; public static final String CONVERSATION_ID_KEY = "conversationId"; public static Mono<String> getTraceId() { return Mono.deferContextual(ctx -> Mono.justOrEmpty(ctx.getOrEmpty(TRACE_ID_KEY))); } }然后在WebFilter里生成并写入。这里要注意,WebFilter对流的处理要用contextWrite而不是直接操作:
@Component public class TraceWebFilter implements WebFilter { @Override public Mono<Void> filter(ServerWebExchange exchange, WebFilterChain chain) { String traceId = exchange.getRequest().getHeaders() .getFirst("X-Trace-Id"); if (traceId == null || traceId.isBlank()) { traceId = UUID.randomUUID().toString().replace("-", ""); } String conversationId = exchange.getRequest().getHeaders() .getFirst("X-Conversation-Id"); final String finalTraceId = traceId; final String finalConvId = conversationId; return chain.filter(exchange) .contextWrite(ctx -> ctx .put(TraceContext.TRACE_ID_KEY, finalTraceId) .put(TraceContext.CONVERSATION_ID_KEY, finalConvId == null ? "" : finalConvId)); } }关键点在于contextWrite是作用在返回的Mono上的,它会把上下文向下游传递。这样即使后面线程切换了,只要还在这个响应式链路里,traceId就能取到。
2.3 把traceId注入到日志和模型调用参数里
光有上下文还不够,日志里得能看到。因为MDC在异步场景失效,我采用的方式是在日志输出时动态拼接。可以写一个工具方法,在记录日志前从Context取traceId。但更省事的做法是自定义一个Logback的Converter,或者干脆在关键日志点手动带上。
我实际项目里用的是组合方案:对于同步代码块,仍然用MDC(在进入响应式链路前设置好);对于响应式链路,用doOnEach在信号发出时把traceId塞进MDC再清理:
public static <T> Mono<T> withTraceLogging(Mono<T> mono, String operation) { return mono.doOnEach(signal -> { if (signal.isOnNext() || signal.isOnError() || signal.isOnComplete()) { TraceContext.getTraceId().subscribe(traceId -> { MDC.put("traceId", traceId); log.info("operation={} signal={}", operation, signal.getType()); MDC.remove("traceId"); }); } }); }注意:
doOnEach里再subscribe一个Mono是有副作用的,生产环境更推荐用Hooks.onEachOperator做全局处理,或者用Micrometer的Observation API,它原生支持响应式上下文。我这里为了讲清楚原理用了简化写法,实际项目建议直接上Observation。
另一个重点是把traceId传给模型调用。Spring AI的ChatClient支持在请求里带metadata,很多模型服务商支持在请求头里带自定义字段用于对账。即使模型侧不消费,你在自己的调用日志里带上traceId,排查时也能把"用户请求"和"模型调用"对上。
2.4 跨服务传递:HTTP头与消息队列两条路径
如果AI服务不是单体,而是拆成了"网关-编排服务-模型代理服务",traceId还得跨进程传。HTTP场景下最简单,用请求头X-Trace-Id透传,下游服务在WebFilter里优先读这个头,读不到再生成。这里有个细节:不要用W3C traceparent格式硬套,除非你整套链路都接了OpenTelemetry。如果只是自己排查用,自定义头更灵活,还能顺便带上conversationId。
消息队列场景(比如异步的批量推理任务)稍微麻烦点。我的做法是把traceId写进消息的header里,消费端在反序列化时先取出traceId写入Reactor Context,再处理业务。Kafka的话可以用ProducerRecord.headers(),RocketMQ用Message.putUserProperty()。核心原则就一条:traceId必须在业务逻辑开始执行之前就进入上下文,否则后面所有埋点都是白搭。
3. 思考过程实时直播:把流式输出拆成可读的阶段事件
3.1 "直播思考过程"到底直播什么
先澄清一个概念。很多人一听"直播思考过程",以为要把模型的chain-of-thought原文吐给用户。这里有两个问题:一是很多模型的思维链并不对外暴露,二是直接把原始推理过程给用户看,体验未必好,可能又长又乱。我理解的"透明化直播",是把一次AI响应的生命周期拆成若干个语义清晰的阶段,每个阶段实时推送状态和阶段性内容。
具体来说,一次典型的AI问答可以拆成这些阶段:接收请求并组装提示词、检索相关知识(RAG场景)、模型开始生成、模型决定调用工具、工具执行中、工具返回结果、模型继续生成、生成完成、后处理过滤。每个阶段都可以作为一个事件推给前端。用户看到的不再是"转圈等待然后突然蹦出一大段字",而是"正在检索资料...找到了3篇相关文档...正在组织回答...(文字逐字出现)"。
这种体验上的差异是巨大的。我做过对比测试,同样的响应时间,有阶段提示的版本用户主观等待感明显更低,中途放弃率下降了不少。这就是透明化的价值——它不改变实际耗时,但改变了用户对耗时的感知。
3.2 用SSE还是WebSocket:流式通道的选型逻辑
Spring AI的流式输出默认走SSE(Server-Sent Events),也就是text/event-stream。选SSE而不是WebSocket,理由很实在:AI问答是典型的"服务端单向推送"场景,用户发一次请求,服务端持续推流,不需要双向实时通信。SSE基于HTTP,天然支持断线重连、天然穿透大多数代理和网关,实现成本低。WebSocket虽然更灵活,但要处理心跳、连接管理、负载均衡的粘性问题,对AI问答来说是过度设计。
不过SSE有个坑:默认的EventSource不支持自定义请求头。这意味着你没法在浏览器原生EventSource里带Authorization或者X-Conversation-Id。解决方案有两个:一是用fetch + ReadableStream手动解析SSE流,二是把认证信息放到URL参数或者Cookie里。我推荐前者,虽然要多写点解析代码,但可控性强。下面是一个前端消费SSE的简化示例:
async function streamChat(prompt, conversationId, onEvent) { const response = await fetch('/api/chat/stream', { method: 'POST', headers: { 'Content-Type': 'application/json', 'X-Conversation-Id': conversationId, 'Accept': 'text/event-stream' }, body: JSON.stringify({ prompt }) }); const reader = response.body.getReader(); const decoder = new TextDecoder(); let buffer = ''; while (true) { const { done, value } = await reader.read(); if (done) break; buffer += decoder.decode(value, { stream: true }); const lines = buffer.split('\n\n'); buffer = lines.pop(); for (const line of lines) { if (line.startsWith('data:')) { onEvent(JSON.parse(line.slice(5).trim())); } } } }3.3 定义事件协议:让前端能区分"阶段"和"内容"
直播的核心是事件协议设计。我建议把推送的每条消息都包装成一个统一的事件对象,用type字段区分类型。这样前端可以根据type决定是显示状态提示,还是追加正文,还是渲染工具调用卡片。
| 事件类型 | 含义 | 前端处理 |
|---|---|---|
stage | 阶段状态变更 | 更新顶部状态条文字 |
content | 正文增量token | 追加到回答区域 |
tool_call | 模型发起工具调用 | 渲染工具调用卡片 |
tool_result | 工具返回结果 | 更新卡片为完成态 |
thinking | 阶段性思考摘要 | 折叠区展示 |
done | 流结束 | 关闭loading,展示耗时 |
error | 出错 | 展示错误提示 |
后端在Spring AI里怎么产出这些事件?ChatClient的流式接口返回Flux<ChatResponse>,每个ChatResponse里包含增量的文本。但工具调用、检索这些阶段,框架不会自动帮你发事件,需要你自己在编排逻辑里手动往流里merge。
3.4 在Spring AI编排层手动注入阶段事件
我的做法是用Flux.merge或者Flux.concat把不同来源的事件流拼起来。假设一次请求先做检索,再调模型,代码结构大致是这样:
public Flux<ChatEvent> streamWithStages(String prompt, String conversationId) { Flux<ChatEvent> retrievalStage = Flux.just( ChatEvent.stage("正在检索相关知识") ); Mono<ChatEvent> retrievalResult = retrieveDocuments(prompt) .map(docs -> ChatEvent.stage( "找到 " + docs.size() + " 篇相关文档")) .onErrorReturn(ChatEvent.stage("检索失败,直接回答")); Flux<ChatEvent> modelStream = chatClient.prompt() .user(prompt) .stream() .chatResponse() .map(resp -> { String text = resp.getResult().getOutput().getText(); return ChatEvent.content(text); }); return Flux.concat( retrievalStage, retrievalResult.flux(), Flux.just(ChatEvent.stage("正在组织回答")), modelStream, Flux.just(ChatEvent.done()) ); }这里有个关键细节:阶段事件和内容事件必须严格有序。如果用merge,检索阶段的事件可能和模型输出交错,前端就乱了。所以用concat保证顺序。但concat的代价是串行,如果检索和模型准备可以并行,那就要用更复杂的编排,比如先并行发起,但用concatMap控制事件发射顺序。
提示:工具调用的直播是最容易出彩的地方。当模型决定调用某个工具时,你可以推一个
tool_call事件,前端渲染成"正在查询天气...",工具返回后再推tool_result,前端更新为"查询完成:北京今天晴,25度"。用户会觉得AI真的在"做事",而不是在"编"。
4. 可观测性落地:指标、日志、追踪三件套怎么配
4.1 该采集哪些指标:别只盯着响应时间
AI应用的指标体系和普通服务有重叠也有差异。重叠的是QPS、错误率、P99延迟这些基础项。差异在于,AI应用需要额外关注:首token延迟(TTFT)、token生成速率、单次请求token消耗量、工具调用次数与成功率、检索命中率。这几个指标直接决定用户体验和成本。
首token延迟尤其重要。用户感知的"快慢"很大程度上取决于第一个字什么时候出现,而不是整段回答什么时候结束。我见过响应总耗时5秒但首token 0.5秒的服务,用户觉得"挺快";也见过总耗时3秒但首token 2.5秒的服务,用户觉得"卡死了"。所以TTFT必须单独埋点。
用Micrometer的话,可以这样记录:
Timer.Sample sample = Timer.start(meterRegistry); // ... 发起模型调用 sample.stop(Timer.builder("ai.chat.ttft") .tag("model", modelName) .tag("conversation", conversationId) .register(meterRegistry));token消耗量则从ChatResponse的metadata里取,Spring AI的ChatResponse.getMetadata().getUsage()能拿到prompt tokens和completion tokens。把这些数据按traceId打点,既能做成本核算,也能在排查"为什么这次特别慢"时提供线索——比如发现是prompt太长导致的。
4.2 日志怎么打才有用:结构化是底线
AI应用的日志如果还是log.info("调用模型成功")这种,基本等于没打。必须结构化,至少包含:traceId、conversationId、阶段名、耗时、token数、模型名。我习惯用JSON格式输出,方便日志平台检索。
一个典型的模型调用日志长这样:
{ "ts": "2025-01-15T10:23:45.123Z", "level": "INFO", "traceId": "a1b2c3d4e5f6", "conversationId": "conv-789", "stage": "model_call", "model": "gpt-4o-mini", "promptTokens": 1250, "completionTokens": 340, "ttftMs": 480, "totalMs": 3200, "toolCalls": 1, "status": "success" }这里有个经验:不要把完整的prompt和response原文打进日志。一是体积大,二是可能含敏感信息。我的做法是只记录长度和hash,需要排查时再根据traceId去专门的审计存储里捞原文,且审计存储要有访问控制和脱敏。
4.3 追踪:OpenTelemetry接入的取舍
如果你的团队已经有OpenTelemetry体系,那Spring AI的调用应该作为span接入。Spring AI本身对Micrometer Observation有支持,可以自动为ChatClient调用生成span。但要注意,流式调用的span结束时机是个坑。普通调用是请求发出到响应返回,span就结束了。流式调用如果等整个流结束才结束span,那span时长会很长,而且中途出错不好标记。我的处理是把span拆成两段:一段是"建立连接并收到首token",一段是"流式消费完成"。这样TTFT和总时长在追踪里都能看到。
如果没有OTel体系,用traceId + 结构化日志也能满足大部分排查需求。不必为了追踪而追踪,工具要服务于实际排障场景。
4.4 一个真实的排障案例:从traceId到根因
回到开头那个"回答到一半断了"的问题。接入完整可观测之后,我通过traceId把链路拼了出来,发现日志里是这样的序列:模型调用成功、首token 400ms、生成了120个token、然后突然出现一个stage=post_process的日志、接着流就结束了。问题出在后处理环节——我们有个敏感词过滤逻辑,它在流式过程中逐段检查,遇到疑似敏感内容时直接中断了流,但没有给前端发任何结束事件,前端就一直等。
根因找到后,修复很简单:后处理中断时也要发一个error或done事件,并带上中断原因。但如果没有traceId把"模型输出"和"后处理中断"这两段日志关联起来,我可能还在怀疑是模型服务的问题。这就是可观测性的价值——它不能防止bug,但能让bug无处遁形。
5. 性能与体验的平衡:直播带来的额外开销怎么控
5.1 事件推送的频率控制
直播思考过程听起来美好,但如果每个token都推一个事件,网络开销和前端渲染压力都会上来。一个中文字大约1-2个token,一段500字的回答就是近千个事件。SSE虽然轻量,但频繁的小包推送在弱网环境下体验很差。
我的做法是对内容事件做批量合并。在服务端用一个缓冲区,每积累N个token或者每过M毫秒推一次。N取5-10,M取50-100ms,实测下来既保证了"逐字出现"的观感,又把事件数量降了一个数量级。阶段事件则实时推,因为它们数量少且重要。
Flux<ChatEvent> batched = modelStream .bufferTimeout(8, Duration.ofMillis(80)) .map(list -> ChatEvent.content( list.stream().map(ChatEvent::getText) .collect(Collectors.joining())));bufferTimeout这个操作符正好满足需求:攒够8个或者超过80ms就发一批,两个条件谁先满足用谁。
5.2 阶段事件的粒度:太细反而干扰
阶段划分不是越细越好。我一开始把"组装提示词""序列化请求""建立连接"都做成阶段推给用户,结果用户看到状态条疯狂闪烁,反而焦虑。后来精简成用户能理解的几个大阶段:理解问题、检索资料、思考中、组织回答、完成。每个阶段至少停留几百毫秒,状态条变化才有意义。
这里的原则是:阶段要对应"用户能理解的工作单元",而不是"代码里的函数调用"。用户不关心你序列化了什么,用户关心"它有没有在为我干活"。
5.3 断线重连与状态恢复
SSE断线是常态,尤其是移动网络。如果断了之后用户刷新页面,之前直播到一半的内容就没了,体验很割裂。解决方案是服务端把已生成的内容按conversationId缓存一段时间,重连时带上Last-Event-ID或者conversationId,服务端从断点继续推。
SSE协议本身支持Last-Event-ID,每条事件可以带id:字段。服务端收到重连请求时读取这个头,从对应位置继续。实现上可以用一个带TTL的缓存(比如Caffeine)存每个conversation的已发事件列表。注意缓存时间别太长,几分钟足够覆盖大多数重连场景,太长会占内存。
5.4 成本视角:透明化会不会推高token消耗
有人担心,把思考过程展示出来,是不是意味着要让模型输出更多内容,从而增加token成本。其实不会,因为阶段事件大部分是编排层产生的,不是模型产生的。"正在检索""找到3篇文档"这些是你在代码里根据实际动作发的,不消耗模型token。真正消耗token的只有模型生成的内容本身,而这部分无论你展不展示都要生成。
唯一需要注意的是,如果你为了让模型"说出思考过程"而特意在提示词里要求它输出推理步骤,那确实会增加token。但这是产品设计选择,和可观测性本身无关。我的建议是:推理过程用编排层的事件来表达,而不是让模型自己复述。前者可控、便宜、稳定,后者又贵又不可控。
6. 几个容易翻车的细节和我的处理习惯
6.1 上下文丢失的三个高发位置
即使按上面的方案做了,实际项目里还是有三个地方特别容易丢traceId。第一个是自定义线程池,如果你在业务里用了@Async或者手动提交任务到线程池,Reactor Context不会自动传过去,需要手动捕获再传递。第二个是工具调用的回调,工具执行完的回调如果不在原响应式链路里,上下文就断了。第三个是异常处理分支,onErrorResume里如果重新发起调用,要确保上下文被重新写入。
我的习惯是在这些位置统一加一个contextWrite,把当前traceId显式写进去。宁可多写一行,也不要事后排查时抓瞎。
6.2 前端渲染的性能陷阱
直播内容逐字追加,如果前端用简单的字符串拼接然后innerHTML,长回答会导致频繁重排,页面卡顿。正确做法是用requestAnimationFrame批量更新,或者用虚拟DOM框架的响应式更新。另外,自动滚动到底部这个功能要小心,如果用户正在往上翻看历史内容,你强制滚动会让人抓狂。我的处理是:只有当用户已经在底部附近时才自动滚动,否则显示一个"有新内容"的提示按钮。
6.3 敏感内容的实时过滤与直播的冲突
直播意味着内容边生成边展示,但敏感内容过滤往往需要看到完整上下文才能判断。这两者有天然矛盾。我的折中方案是:对明显的敏感模式做实时拦截,对需要上下文的判断做延迟过滤。实时拦截命中时立即中断并替换,延迟过滤则在流结束后异步检查,发现问题再撤回或标记。这个策略不是完美的,但比"要么全放要么全拦"要实用。
6.4 我个人的配置清单
最后分享一份我在多个项目里复用的基础配置清单,可以直接抄:
- traceId生成:UUID去横线,16字节够用,别用自增ID(会泄露业务量)
- 上下文传递:Reactor Context为主,MDC为辅(仅同步段)
- 事件批量:8个token或80ms,二选一先到先发
- 阶段数量:控制在5个以内,每个阶段有明确用户语义
- 缓存TTL:重连缓存5分钟,审计日志30天
- 指标重点:TTFT、token速率、工具调用成功率,这三个优先于总耗时
- 日志脱敏:prompt和response只存hash和长度,原文进加密审计库
这套东西不是一次设计出来的,是踩了无数坑之后慢慢收敛的。每个参数背后都有具体的翻车经历,比如80ms这个值,是因为试过50ms太频繁、150ms又显得卡顿,最后定在中间。你在自己项目里落地时,也建议先跑起来,再根据实际体感调参,别一上来就追求完美配置。