AgentScope第13式·经脉中间件
AgentScope第13式·洋葱中间件
横切逻辑塞进 Tool，日志越写越多，链路却越来越断。
[读者] 用 AgentScope Java 做数字人的 Java 后端工程师
[痛点] TraceId、耗时、审计散落在每个 Tool 里，改一处漏三处
[现在读] 五阶段中间件正好能把横切能力收口到一处
[读完] 能给数字人接上一条完整、可闭合、可审计的调用链
[旧方案] 每个 Tool 里手写日志、计时、租户拼接
|
v
[新需求] 统一 TraceId、模型耗时、Tool 审计、答案过滤、租户注入
|
v
[冲突] 横切逻辑与业务逻辑长在一起，顺序、异常、上下文全靠口头约定
|
v
[后果] 链路缺口、耗时失真、审计遗漏，排障回到人肉比对
我是老李，最近带着一个小团队，把数字人 Demo 从“能跑”往“能查”推。项目不大：Spring Boot 管项目配置，MySQL 存数据，LiveKit 扛实时音视频，Realtime Bridge 做最薄的媒体适配，推理全部交给 AgentScope Java。
第12式结束时，数字人已经能按项目配置切换 systemPrompt、按租户切模型、按会话带上下文。能力是通的，但每加一个能力，就要回到每个 Tool 里补一段日志。
我们把日志粗分成两类：业务日志，谁写的谁负责；链路日志，谁都需要但没人负责。第二类日志在代码库里以复制粘贴的形式存在了十几处，而且没有一处能回答“这次请求的模型调用花了多久”——模型调用是框架内部发起的，业务代码根本没有位置插进去。
当横切逻辑和业务逻辑共用同一个函数体，谁来保证顺序不会因为一次重构而颠倒？
当模型调用藏在框架内部，业务 Tool 看不见它，耗时到底该记在哪里？
如果 TraceId 只在正常路径上传递，异常一来链路就断，这样的链路还叫链路吗？
01、故事
内测那天，会议室里坐着三个人：我一个，运营一个，还有一个刚入职的 Java 工程师。
系统是这样跑的：运营在管理端建项目，填名称、标题、主题色、背景图、开场白、结束语，再配一个 agentName、一个 model、一段 systemPrompt；用户在 /run/{projectId} 打开运行页说话；LiveKit 负责 WebRTC Room 与实时音频传输；Realtime Bridge 把媒体消息适配成 Agent 的输入；AgentScope Java 里的 Agent 负责推理；答案再一路回传成语音。闭环是通的。
不通的是“看得见”。
这次内测的任务是：让每一次用户说话，都能在日志里还原成一条从入口到最终答案的完整链路——哪个租户、哪次模型调用花了多久、调了哪个 Tool、Tool 收到什么、最终答案有没有被改过。
第12式结束时我们的做法很朴素：在 Tool 里加日志。查项目配置的 Tool 加一行 log.info，改配置的 Tool 再加一行。模型调用看不到，就干脆不记。内测第一天，运营问“刚才那句话为什么答错了”，我们三台机器 grep 了四个小时，最后靠时间戳猜出是哪一次请求。
那天晚上我盯着那堆日志想明白一件事：链路不是缺日志，是缺位置。
链路本无痕
横切自成环
一处收万象
先后定乾坤
02、问题
旧做法有五条，现在回头看，每一条都是同一个病的不同症状。
第一，Tool 内手写日志：TraceId、耗时、租户、审计字段，每个 Tool 各写各的。
第二，Controller 生成 TraceId，塞进参数，一路透传到 Service 再到 Tool。
第三，Service 里用 System.currentTimeMillis 打点算耗时。
第四，租户信息从请求头读到之后，在每个 Tool 里再读一次。
第五，答案过滤写在流式回调的收尾处，靠“约定这是最后一段”。
为什么不够？四个原因，都能在本机上验证。
一是位置不对。模型调用由框架内部发起，业务代码没有钩子可以插进去，模型耗时在 Tool 里永远量不到。
二是签名污染。为了让每个 Tool 都能写 TraceId，方法签名被迫带上上下文参数，Tool 的接口越来越像管道。
三是顺序靠约定。答案过滤必须在所有加工之后、输出之前，但只要有人在中间新增一步，顺序就可能颠倒，而没有任何编译期或运行期约束会提醒你。
四是异常先跑。工具抛异常时，函数提前返回，写在后面的日志一律不执行——链路正好在出问题的那一次断掉。
可验证的风险清单：
在任意一个 Tool 里抛一个 RuntimeException，TraceId 的结束日志立刻消失。
模型耗时字段长期为空，或者被误填成工具耗时。
换一个人写新的 Tool，审计字段必然缺两三个，因为没有统一模板。
一次重构把答案过滤挪到流式回调中间，问题不会报错，只会静默地过滤不干净。
本章的完成标准，我定成五条可验收的：
一次请求只有一个 TraceId，并且它同时出现在 onAgent、onReasoning、onActing、onModelCall、onSystemPrompt 五个阶段。
模型耗时与工具耗时分别统计，字段互不覆盖。
异常路径同样输出 trace.end，并带上错误类型。
业务 Tool 内不再出现任何 trace、耗时、租户、审计相关的代码。
代码落在分支 chapter/13-middleware，一次提交：feat(ch13): add middleware tracing audit and guards。
散落易失序
一改即失真
收口方成链
闭合才可信
03、原理
先给边界：AgentScope Java 里的 Middleware（中间件），是挂在 Agent 执行管线上的钩子，它不改变 Agent 的推理逻辑，只在阶段边界插入横切行为。本章只讲这五个钩子：onAgent、onReasoning、onActing、onModelCall、onSystemPrompt。官方对五阶段的说明与示例在 https://github.com/agentscope-ai/agentscope-java/blob/v2.0.3/docs/v2/zh/docs/building-blocks/middleware.md ，源码入口在 agentscope-core 的 io/agentscope/core/middleware/MiddlewareBase.java。
第一件事：钩子的粒度不一样。
onAgent 是整次 Agent 执行，一次请求只进一次。
onReasoning 是一次推理步（ReAct 循环里的一轮），一次请求可能进多次。
onActing 是工具执行阶段，只有发生工具调用时才进。
onModelCall 是模型调用，每一轮需要问模型时都会进。
onSystemPrompt 是系统提示构建阶段，负责把最终送进模型的 system prompt 拼出来。
第二件事：洋葱模型。
进入顺序按注册顺序从外到内，返回顺序从内到外。外层钩子在 next 之前做的事，是所有内层的前置；在 next 之后做的事，是所有内层的后置。于是有四个推论：
要统计“整次请求”，放在最外层。
要统计“单次模型调用”，只能放 onModelCall。
要修改最终答案，必须放在比所有加工逻辑都外层的位置，因为只有那里拿得到最终结果。
要往 system prompt 里注入租户信息，必须放 onSystemPrompt，因为再往外，提示词就已经定型了。
第三件事：异常。
内层抛出的异常会沿调用栈向外冒泡。外层钩子想在异常时也留下记录，就必须用 try/finally，而不是把日志写在 next 之后。这和上一条是同一件事的两面：后置逻辑写在 next 之后，异常路径上就不会执行。
第四件事：上下文传递。
一次请求的 TraceId、租户、阶段耗时这些状态，要放在请求级上下文对象里随链传递。不要用 ThreadLocal——Agent 的执行可能是异步的、可能切线程、可能是流式的，ThreadLocal 在这些场景下会丢值或者串值。
反直觉判断：五个钩子不是“同一个东西的五个副本”，它们能看到的数据面完全不同。最外层看得到最终答案，但看不到模型请求；最内层看得到模型请求，却拿不到最终答案。所以“把日志统一写在最外层”看起来最省事，实际是拿不到要审计的东西——审计必须发生在看得见被审计对象的那一层。
最后一个必须说清的边界：本文按五阶段的名称与语义展开，但方法签名、返回类型、是否支持 Reactor 流式返回、默认实现是否为空方法，需要以 v2.0.3 的 MiddlewareBase.java 和对应 tag 的官方文档为准，本文未在当前环境逐行核对该源码。教程基线固定在 v2.0.3；写作时若官方 Releases 已出现更新的正式版，请以 https://github.com/agentscope-ai/agentscope-java/releases 为准，本文结论只对 v2.0.3 负责复现。
层层包一层
内外各所见
进出自有序
异常不乱纲
04、架构
[输入] 用户语音（LiveKit Room → Realtime Bridge）
|
v
[模块] AgentScope Java Agent + Middleware 链（六条中间件）
|
v
[数据/状态] RequestContext：traceId、tenantId、阶段耗时、审计事件
|
v
[处理] onAgent → onReasoning → onSystemPrompt → onModelCall → onActing
|
v
[输出] 最终答案 + 结构化链路日志 + 审计记录
注册顺序（外层到内层）：
- TraceIdMiddleware（onAgent）：开链、关链、生成或读取 TraceId。
- AnswerGuardMiddleware（onAgent）：在最外层持有最终答案，统一过滤。
- ReasoningTraceMiddleware（onReasoning）：推理步计数与步耗时。
- TenantPromptMiddleware（onSystemPrompt）：把租户信息写进系统提示。
- ModelCostMiddleware（onModelCall）：单次模型调用耗时。
- ToolAuditMiddleware（onActing）：工具名、参数摘要、状态、耗时。
边界：中间件只处理“每个请求都要做、且与业务语义无关”的横切能力。凡是需要读业务字段做决策的逻辑，一律不入链。
收益：横切逻辑只写一次；顺序由注册顺序显式表达，而不是靠口头约定；模型耗时与工具耗时天然分离；异常路径也有收尾点。
代价：多一层间接，调用栈变深；排查一个问题要在中间件与业务代码之间来回跳；中间件顺序变成隐性契约，必须写进文档并纳入 code review。
适用条件：阶段边界稳定、横切能力与业务无关、链路需要被审计或统计。
不适用条件：只影响单个 Tool 的临时逻辑；阶段边界还在频繁变动；判断依赖业务状态（例如配额、风控）。
涉及 AgentScope 内部机制时，本章的定位依据是 v2.0.3 的 agentscope-core/src/main/java/io/agentscope/core/middleware/MiddlewareBase.java 以及同一 tag 的 middleware 文档；若两者描述不一致，以源码与测试为准，并在文中写明核验依据。
边界先画清
钩子各守位
上下文同行
日志自成链
05、实战一次
环境与版本：教程基线 AgentScope Java v2.0.3，依赖与 JDK 版本沿用第2式已经固定的环境，本章不引入任何新的第三方依赖。
依赖：只用到 agentscope-core 与 slf4j，pom 无需改动。
分支：从第12式所在分支继续创建本章分支。
# 先确认上一式分支名
git branch --list "chapter/12-*"
# 再切出本章分支
git checkout -b chapter/13-middleware <第12式分支>
配置：日志格式里补上 traceId，便于 grep。
<pattern>%d{HH:mm:ss.SSS} %-5level [%X{traceId:-no-trace}] %logger{20} - %msg%n</pattern>
核心实现：先把请求级上下文定义出来。
package com.example.digitalhuman.middleware;
import java.util.List;
import java.util.Map;
import java.util.UUID;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.CopyOnWriteArrayList;
import java.util.concurrent.atomic.AtomicInteger;
public class TraceContext {
private final String traceId = UUID.randomUUID().toString().replace("-", "");
private final AtomicInteger reasoningStep = new AtomicInteger();
private final Map<String, Long> stageNanos = new ConcurrentHashMap<>();
private final List<String> auditEvents = new CopyOnWriteArrayList<>();
private volatile String tenantId = "unknown";
public String traceId() {
return traceId;
}
public String tenantId() {
return tenantId;
}
public void tenantId(String tenantId) {
this.tenantId = tenantId;
}
public int nextReasoningStep() {
return reasoningStep.incrementAndGet();
}
public void record(String stage, long nanos) {
stageNanos.merge(stage, nanos, Long::sum);
}
public Map<String, Long> stageNanos() {
return stageNanos;
}
public void audit(String event) {
auditEvents.add(event);
}
public List<String> auditEvents() {
return auditEvents;
}
}
再写六条中间件。下面代码块中出现的 log，均为各自文件里声明的 private static final Logger log = LoggerFactory.getLogger(...)；Digest 与 GuardRules 是教程仓库同包下的工具类；AgentContext 与 MiddlewareChain 是按 v2.0.3 MiddlewareBase.java 描述的钩子形态书写的类型名，落地前请先打开该文件，把方法签名、返回类型与流式支持方式对齐后再编译。以下代码未在当前环境实测，行为为预期结果。
public class TraceIdMiddleware extends MiddlewareBase {
@Override
public void onAgent(AgentContext ctx, MiddlewareChain chain) {
TraceContext trace = ctx.computeIfAbsent(TraceContext.class, TraceContext::new);
trace.tenantId(ctx.header("X-Tenant-Id", "unknown"));
long start = System.nanoTime();
try {
log.info("trace.start traceId={} tenantId={}", trace.traceId(), trace.tenantId());
chain.proceed(ctx);
} catch (RuntimeException e) {
trace.audit("agent.error=" + e.getClass().getSimpleName());
throw e;
} finally {
long nanos = System.nanoTime() - start;
trace.record("agent.total", nanos);
log.info("trace.end traceId={} costMs={} stages={} audit={}",
trace.traceId(), nanos / 1_000_000, trace.stageNanos(), trace.auditEvents());
}
}
}
public class AnswerGuardMiddleware extends MiddlewareBase {
@Override
public void onAgent(AgentContext ctx, MiddlewareChain chain) {
chain.proceed(ctx);
String answer = ctx.finalAnswer();
if (answer == null || answer.isEmpty()) {
return;
}
String filtered = GuardRules.filter(answer);
if (!filtered.equals(answer)) {
ctx.finalAnswer(filtered);
ctx.get(TraceContext.class).audit("answer.filtered");
}
}
}
public class ReasoningTraceMiddleware extends MiddlewareBase {
@Override
public void onReasoning(AgentContext ctx, MiddlewareChain chain) {
TraceContext trace = ctx.get(TraceContext.class);
int step = trace.nextReasoningStep();
long start = System.nanoTime();
try {
chain.proceed(ctx);
} finally {
long nanos = System.nanoTime() - start;
trace.record("reasoning#" + step, nanos);
log.info("reasoning.step traceId={} step={} costMs={}", trace.traceId(), step, nanos / 1_000_000);
}
}
}
public class TenantPromptMiddleware extends MiddlewareBase {
private final TenantConfig tenantConfig;
public TenantPromptMiddleware(TenantConfig tenantConfig) {
this.tenantConfig = tenantConfig;
}
@Override
public void onSystemPrompt(AgentContext ctx, MiddlewareChain chain) {
TraceContext trace = ctx.get(TraceContext.class);
String brand = tenantConfig.brandOf(trace.tenantId());
ctx.appendSystemPrompt("\n[租户信息] 你正在为 " + brand + " 提供服务，回答中不要提及其他品牌。");
chain.proceed(ctx);
}
}
public class ModelCostMiddleware extends MiddlewareBase {
@Override
public void onModelCall(AgentContext ctx, MiddlewareChain chain) {
long start = System.nanoTime();
try {
chain.proceed(ctx);
} finally {
long nanos = System.nanoTime() - start;
TraceContext trace = ctx.get(TraceContext.class);
trace.record("model.call", nanos);
log.info("model.call traceId={} model={} costMs={}", trace.traceId(), ctx.modelName(), nanos / 1_000_000);
}
}
}
public class ToolAuditMiddleware extends MiddlewareBase {
@Override
public void onActing(AgentContext ctx, MiddlewareChain chain) {
String tool = ctx.toolName();
String argsDigest = Digest.sha256(ctx.toolArguments());
long start = System.nanoTime();
String status = "OK";
try {
chain.proceed(ctx);
} catch (RuntimeException e) {
status = "ERROR:" + e.getClass().getSimpleName();
throw e;
} finally {
long nanos = System.nanoTime() - start;
TraceContext trace = ctx.get(TraceContext.class);
trace.record("tool." + tool, nanos);
trace.audit("tool=" + tool + " args=" + argsDigest + " status=" + status + " costMs=" + nanos / 1_000_000);
}
}
}
注册顺序决定洋葱层次，这一行代码就是本章最重要的一行。builder 的注册方法名以 v2.0.3 为准。
ReActAgent agent = ReActAgent.builder()
.name(project.getAgentName())
.sysPrompt(project.getSystemPrompt())
.model(modelFactory.of(tenant))
.middleware(new TraceIdMiddleware())
.middleware(new AnswerGuardMiddleware())
.middleware(new ReasoningTraceMiddleware())
.middleware(new TenantPromptMiddleware(tenantConfig))
.middleware(new ModelCostMiddleware())
.middleware(new ToolAuditMiddleware())
.build();
启动：沿用第2式的启动方式，本地起 Spring Boot，同时确保 LiveKit 与 Bridge 已经可连。
请求：先用文本入口验证链路，再回到语音入口。
curl -X POST http://localhost:8080/api/run/1001/chat \
-H "Content-Type: application/json" \
-H "X-Tenant-Id: t-1001" \
-d '{"sessionId":"s-1","text":"帮我看看项目主题色是什么"}'
验证：下面是与上面实现配套的预期日志（示例输出，未在当前环境实测，字段以实际实现为准）。
INFO [9f2c4a1b] dh.middleware - trace.start traceId=9f2c4a1b tenantId=t-1001
INFO [9f2c4a1b] dh.middleware - model.call traceId=9f2c4a1b model=qwen-max costMs=812
INFO [9f2c4a1b] dh.middleware - reasoning.step traceId=9f2c4a1b step=1 costMs=830
INFO [9f2c4a1b] dh.middleware - model.call traceId=9f2c4a1b model=qwen-max costMs=121
INFO [9f2c4a1b] dh.middleware - tool audit tool=queryProject args=3f9a1c status=OK costMs=6
INFO [9f2c4a1b] dh.middleware - reasoning.step traceId=9f2c4a1b step=2 costMs=140
INFO [9f2c4a1b] dh.middleware - trace.end traceId=9f2c4a1b costMs=1094 stages={agent.total=1094, model.call=933, reasoning#1=830, reasoning#2=140, tool.queryProject=6} audit=[tool=queryProject args=3f9a1c status=OK costMs=6]
对照验收清单逐条勾：一条 TraceId 贯穿五阶段；model.call 与 tool.queryProject 分开统计；异常用例下 trace.end 仍然出现；Tool 代码里搜不到 log 与 traceId；分支与提交信息符合约定。
五钩接一处
一链贯始终
耗时分开记
异常也要关
06、排查
本章的两条排查，一条关于位置，一条关于异常。
证据链一：模型耗时永远是 0，或者等于工具耗时
现象：内测日志里 modelCostMs 要么是空的，要么和 toolCostMs 一模一样。
怀疑一：模型没被调用，走了缓存或短路。
怀疑二：System.currentTimeMillis 精度不够，短调用被计成 0。
怀疑三：打点位置本身不对。
检查：在 Tool 里把计时前后各打一行时间戳，和框架侧日志中模型返回的时刻对照；同时确认模型调用发生在 Agent 内部，而不是 Tool 内部。
证据：工具执行时间只有几毫秒，而一次请求的端到端耗时是秒级；差值全部落在 Agent 内部，也就是模型调用上。说明“在 Tool 里测模型耗时”这个位置从一开始就不成立。
错误尝试： 我们一度在 onActing 里加了一个分支——“如果这一轮没有调用工具，就自己开始计时，等到下一次工具调用时再减掉”。这个改法错在两处：其一，它把 onActing 的语义（工具阶段）偷偷扩成了“整个推理阶段”；其二，没有工具调用的那一轮推理恰恰最容易漏统计，因为那个分支根本不会被触发，账面数字反而更漂亮。根因不是计时精度，是计时位置。
根因：模型调用的时间只有在 onModelCall 的前后才能量准。
修复：模型耗时整体搬到 onModelCall，工具耗时留在 onActing。
证据链二：异常一来链路就断
现象：正常请求日志里有 trace.start 和 trace.end；只要 Tool 抛异常，trace.end 就不见了。
怀疑一：中间件没注册上（不成立，因为正常路径生效了）。
怀疑二：异步日志没来得及刷盘。
怀疑三：异常被内层吞掉，链路其实还在跑。
检查：写一个必然抛 RuntimeException 的调试 Tool 触发一次；把 traceId 放进 MDC 观察；同时确认框架是否把异常重新抛出到最外层。
证据：日志确实停在 tool 之前，异常被抛回最外层，进程没挂，但 trace.end 没打。说明结束逻辑写在 next 之后，而不是 finally 里。
错误尝试： 我们把 trace.end 从处理函数末尾挪到 Controller 的 finally——错在把链路收尾和 HTTP 收尾混为一谈：LiveKit 侧的消息是异步进出的，Controller 早就返回了，收尾时机完全对不上。
根因：中间件缺 finally，后置逻辑在异常路径上不执行。
修复：所有中间件的后置逻辑统一放进 try/finally；审计事件结构化，不再字符串拼接。
上游贡献判断：这两条都是我们自己实现的位置问题，没有指向框架行为。若今后怀疑是框架语义问题（例如异常时钩子的调用约定），流程是：先在教程仓库做最小复现 → 对比 v2.0.3 与官方 main → 搜索官方 Issues/PR/Discussions → 再决定是否提 Issue。本章没有找到符合这个流程的候选。
现象先固化
证据再说话
根因不在表
位置定生死
07、优化
基于第06章的两条根因，V2 收敛成六条规则。
规则一：请求级状态全部收进 TraceContext（traceId、tenantId、阶段耗时、审计事件、推理步序号），随 middleware 链传递，不用 ThreadLocal。
规则二：每个钩子只做“只有它那一层看得见”的事。模型耗时只在 onModelCall，租户注入只在 onSystemPrompt，最终答案过滤只在最外层。
规则三：所有后置逻辑进 try/finally，异常路径与正常路径走同一套收尾代码。
规则四：注册顺序固定为 TraceId → AnswerGuard → ReasoningTrace → TenantPrompt → ModelCost → ToolAudit，并把这段顺序写进仓库文档。
规则五：审计输出结构化事件（tool、argsDigest、status、costMs），只落参数摘要，不落原始参数。
规则六：答案过滤只做一次，且必须发生在最外层。
把规则三落成代码，收尾逻辑就只有一种写法。
private static void withTiming(TraceContext trace, String stage, Runnable body) {
long start = System.nanoTime();
try {
body.run();
} finally {
trace.record(stage, System.nanoTime() - start);
}
}
把规则六落成代码，过滤只在一处发生。
public final class GuardRules {
private static final Pattern PHONE = Pattern.compile("1[3-9]\\d{9}");
private static final Pattern INTERNAL_LINK = Pattern.compile("https?://(\\w+\\.)*internal\\.[a-z]+");
private GuardRules() {
}
public static String filter(String answer) {
String masked = PHONE.matcher(answer).replaceAll("***");
return INTERNAL_LINK.matcher(masked).replaceAll("[内部链接已隐藏]");
}
}
新行为与验证方法：准备三类用例——正常请求、工具抛错请求、无工具请求（纯模型回答）。三类都必须满足同一条：日志里有且只有一条 trace.start 与一条 trace.end，且 stages 里同时出现 model.call 与（当次实际发生的）tool.* 键。第三类用例是专门用来抓“工具里计时”这个老毛病的：如果耗时不出现，说明你又把统计写回了工具里。
位置即语义
收尾放最外
一事一钩子
验证看异常
08、演进
[同一输入] 用户一句语音 → 数字人一次回答
|
+--[V1] 横切逻辑写在 Tool 内 / 日志零散、模型耗时缺失、异常断链
|
+--[V2] 五阶段中间件收口 / 一条 traceId 贯穿、异常也闭合
|
[Trade-off]
得到：统一链路、可审计、可回归；失去：多一层间接、调试要跨文件；适用边界：只放与业务无关的横切能力
| 维度 | V1：Tool 内手写 | V2：五阶段中间件 |
|---|---|---|
| 正确性 | 模型耗时量不到 | 模型耗时与工具耗时分离 |
| 稳定性 | 异常路径断链 | try/finally 闭合，异常也收尾 |
| 复杂度 | 单点简单，全局失控 | 单点多一层，全局一致 |
| 成本 | 每新增一个 Tool 就重复写一遍 | 一次注册，长期受益 |
| 适用范围 | 单个 Tool 的临时验证 | 多能力、多租户、需要审计 |
| 遗留问题 | 无统一模板，字段随人变 | 中间件顺序成为隐性契约，必须文档化 |
值得注意的是，V2 的复杂度并没有减少，只是从“十几个地方各一点点”变成了“一个地方多一点”。这对单个开发者是负担，对频繁迭代的团队是收益——因为变更成本从 N 处收敛到了 1 处，回归成本也跟着收敛。
旧写散如沙
新束成一链
得失各有价
边界是前提
09、洞见
9.1 顺序就是契约
中间件的注册顺序不是实现细节，而是对外契约的一部分。把 AnswerGuard 挪进内层，答案过滤就会漏掉内层加工产生的内容；把 TraceId 挪进内层，外层就可能出现没有 traceId 的日志。这类改动应该和改 API 一样，进 code review、进变更记录。
反直觉判断：团队通常把“中间件顺序”当成可以随时调整的排列组合，但对链路能力来说，它可以随时调整的排列组合，恰恰是不该混进业务变更里的那种改动。
9.2 只有它能做的事，才放进它的钩子
一个简单的判据：这件事除了这一层，还有谁能做？如果没有别的地方能做，就放这里；如果很多地方都能做，说明它不属于中间件。模型耗时只有 onModelCall 能做得准，租户注入只有 onSystemPrompt 能做得对，最终答案过滤只有最外层能做得全——这三件事都是“只有它能做”，因此位置是唯一的。
9.3 异常路径才是链路的验收标准
反直觉判断：链路的正确性不应该用成功请求来验收。成功请求在 V1 里也是通的，所以它能证明的东西很少；真正的验收标准是异常请求同样有 trace.end。把异常用例写进验收清单，是这一章最便宜也最容易被省掉的一步。
9.4 什么时候不该用中间件
三种情况。其一，这条横切逻辑只影响一个 Tool，没有第二处会用到，那它就还是业务代码。其二，阶段边界还没稳定，团队还在改推理流程，此时把逻辑钉在钩子上，会跟着边界一起晃动。其三，判断需要业务语义，例如“这个租户今天还能不能聊”“这段内容算不算违规”，那属于业务规则，应该放在进入 Agent 之前或业务层，而不是让模型调用阶段承担业务决策。
顺序即契约
内外各有责
直觉常出错
边界即自由
10、系统落地
原来有什么：第12式的数字人已经能按项目配置切换提示词、按租户切模型、按会话带上下文，但链路能力为零，排障靠 grep 和时间戳。
本篇新增什么：六条中间件、一个请求级上下文、一套结构化审计事件、一条答案守卫。业务 Tool 里不再出现 trace、耗时、租户、审计相关代码。
现在能做什么：一次请求一条 TraceId；模型耗时与工具耗时分开统计；异常路径也输出闭合记录；租户信息在 systemPrompt 阶段注入；最终答案在输出前统一过滤。
还缺什么：链路日志还只落在本地文件，没有统一的观测面；审计事件还没有留存与查询策略；答案过滤还没有回归用例，无法判断是否误伤；多实例部署时 TraceId 还缺跨服务传播约定。
下一步如何演进：把链路日志接到统一观测；把审计事件变成可查询记录；给答案过滤建一组固定用例做回归；在进入分布式部署前，先定好 TraceId 的跨服务传播格式。
开源参与点：本章未发现明确上游问题。
原有能跑通
今添可追溯
缺的是观测
下一步接上
11、小结
Q1 → 顺序由谁保证：由注册顺序与洋葱模型共同保证，收口之后不再依赖口头约定
Q2 → 模型耗时记在哪：onModelCall，只有它在模型调用前后都经过
Q3 → 异常链路：后置逻辑统一 try/finally，异常路径同样要有 trace.end
状态 → chapter/13-middleware 可交付：一次请求的完整调用链 + 模型/工具耗时分离统计
本章的交付物不是“多了一个日志框架”，而是给横切逻辑找到了唯一该待的位置。位置定下来之后，后续加审计字段、加埋点、加护栏，都只需要改一个文件，而不是改十几个 Tool。
一问顺序谁定
二问耗时何记
三问异常怎收
一链贯通收工
12、作业
12.1 理解题：五阶段钩子的进入顺序与返回顺序是什么关系？为什么叫洋葱模型？
参考答案：进入按注册顺序由外到内，返回由内到外；同一份请求上下文在“进入”和“返回”两个时刻看到的状态不同，所以计时、过滤、收尾这类逻辑天然适合写在返回路径上。具体嵌套关系（例如 onSystemPrompt 相对 onModelCall 的位置）请打开 v2.0.3 的 io/agentscope/core/middleware/MiddlewareBase.java 与同 tag 的 middleware 文档逐条核对，不要只背本文。
12.2 实战题：把 TraceId 中间件改成支持流式输出——逐 token 返回时，仍然只在结束时打印一次 trace.end。
参考答案：把收尾逻辑放在流的终止信号上（onComplete/onError）或 finally 中，而不是每个 token 的回调里；若需跨线程，把请求上下文显式传给订阅者，别依赖 ThreadLocal；同时在 onError 分支补一次 trace.end，保证错误流也闭合。具体用哪个终止回调，要以 v2.0.3 源码里中间件钩子的返回类型为准。
12.3 排障题：日志里出现了两次 trace.start，只有一次 trace.end，先查什么？
参考答案：先数注册次数——是否存在同一中间件被注册两遍（例如 builder 里一次、全局配置里一次）；再查是否存在嵌套执行（Subagent 或子 Agent 复用了同一上下文对象），此时子链路的开始应该带独立的 span 标识，而不是复用外层 traceId 的开闭。定位手段是把 traceId 与中间件注册顺序一起打进日志。
12.4 架构判断题：要不要把“租户配额校验”放进中间件？
参考答案：不应该放进内层钩子。配额校验依赖业务状态（用量、套餐、时间窗），属于业务准入；放进 onModelCall 会让“调用模型”这件事承担业务决策。更合适的做法是在进入 Agent 之前或在最外层 onAgent 做准入，中间件只保留与业务无关的横切能力。
理解看源码
实战改流式
排障数日志
判断问边界
13、思考
回到开篇那个冲突：横切逻辑和业务逻辑长在一起，谁也说不清顺序、异常和上下文该谁负责。中间件给出的不是一个新的日志工具，而是一个位置——一个“每个请求都要做、且和业务无关”的逻辑唯一该待的位置。
可复用的判断只有两句：凡是每个请求都要做、和业务无关、需要看见阶段边界的，收口到中间件；凡是需要读业务字段做决策的，留在业务层。判断不清的时候，先问一句：这件事，除了这一层，还有谁能做？
这也是“会用框架”和“能参与框架演进”的差别：前者照着钩子名把代码塞进去，能跑就行；后者会先确认这些钩子在异常、并发、流式三种情况下的语义，再决定塞什么、塞在哪一层。
横切归一处
先后即契约
异常也闭合
方寸见真章
浙公网安备 33010602011771号