场景Provider 端 SecurityFilter 拦截了非法请求返回了错误——但 ExceptionFilter 没写那行日志路径ProtocolFilterWrapper.buildInvokerChain() → ActivateComparator → FilterNode.invoke() → ExceptionFilter.onResponse()【遗迹】SecurityFilter 拦了请求ExceptionFilter 没日志上篇讲了 Dubbo 版本升级导致 Listener 注册了两次的问题这篇来看 filter 链顺序引起的一个更隐蔽的问题日志凭空消失。现象Consumer 收到了拒绝访问Provider 没日志一个自定义 SecurityFilter 负责校验调用方 IP 白名单。非法请求进来Consumer 收到了错误响应——但 Provider 日志里 ExceptionFilter 那行logger.error就是不出现。Dubbo2.7.23配置dubbo:providerfiltersecurityFilter,accesslog/accesslog 配置正确logback 级别也是 DEBUG。手工 telnet 调接口确认异常返回了——但 ExceptionFilter 就是没动笔。问题代码初现SecurityFilter 返回了干净 Result翻到 SecurityFilter 的实现看到了问题所在publicResultinvoke(Invoker?invoker,Invocationinv){if(!isAllowed(inv)){// ← 直接返回了一个没有异常的普通 ResultreturnAsyncRpcResult.newDefaultAsyncResult(inv);}returninvoker.invoke(inv);}它返回了一个不带异常的 Result。异常被吞了——框架层面没有报错Consumer 能拿到响应体但 ExceptionFilter 的onResponse()看不到异常信息。转向源码ExceptionFilter 确实有 logger.error检查 ExceptionFilter 源码Dubbo 2.7.23的第 79 行logger.error(Got unchecked and undeclared exception which called by RpcContext.getContext().getRemoteHost(). service: invoker.getInterface().getName(), method: invocation.getMethodName(), exception: exception.getClass().getName(): exception.getMessage(),exception);代码写死了logger.error为什么就是不走两种可能filter 没被加载或者异常根本没走到它这里。【发掘】① 构建 filter 链ProtocolFilterWrapper.buildInvokerChain()Layer 1: 构建入口——哪种协议都会走这Provider 被调用时Dubbo 通过ProtocolFilterWrapper.export()在真实 Invoker 外面包一层 filter 链ProtocolFilterWrapper.java#L51-L63privatestaticTInvokerTbuildInvokerChain(finalInvokerTinvoker,Stringkey,Stringgroup){InvokerTlastinvoker;ListFilterfiltersExtensionLoader.getExtensionLoader(Filter.class).getActivateExtension(invoker.getUrl(),key,group);if(!filters.isEmpty()){for(intifilters.size()-1;i0;i--){finalFilterfilterfilters.get(i);lastnewFilterNodeT(invoker,last,filter);}}returnlast;}Layer 2: ActivateComparator 决定 filter 内外顺序getActivateExtension返回按ActivateComparator升序排列的 filter 列表——order 小的在前order 大的在后。index0: ContextFilter(orderInteger.MIN_VALUE)index1: ClassLoaderFilter(order0)index2: ExceptionFilter(order0)... index n: SecurityFilter(order100)Layer 3: 从后往前遍历——第一个 filter 在最外层buildInvokerChain从列表末尾开始遍历。排在前面的 filterorder 小成为最外层节点最外层 ← ContextFilter(0)→... → ExceptionFilter(0)→... → SecurityFilter(100)→ 真实 Invokerorder 小的在外层order 大的在内层。SecurityFilterorder100在最内层ExceptionFilterorder0在 SecurityFilter 外层。这个顺序决定了一切RPC 调用从外层流向内层到达真实 Invoker异常和结果从内层流回外层。SecurityFilter 在内层意味着——它先拿到结果它有选择权决定向上层返回什么。【发掘】② FilterNode 回调路径ExceptionFilter 的信息源是上游喂给它的Layer 1: 每个 FilterNode 独立管理回调每个 FilterNode 在invoke()中处理 Listener 回调FilterNode.java#L58-L105。源码见截图。Layer 2: ExceptionFilter 的信任模型——它信任上游如实传递异常ExceptionFilter实现了Filter.Listener。它的invoke()纯透传真正的异常感知在onResponse()中同见截图publicvoidonResponse(ResultappResponse,Invoker?invoker,Invocationinvocation){if(appResponse.hasException()GenericService.class!invoker.getInterface()){// 只日志未在接口签名中声明的非受检异常...logger.error(Got unchecked and undeclared exception...,exception);}}这里有一个重要的设计假设ExceptionFilter 信任上游 filter即内层 filter会如实把异常状态填进 Result。appResponse.hasException()为 true 的前提是——上游 filter 在返回 Result 之前确实把异常放进去了。换句话说ExceptionFilter 没有主动侦查异常的能力它是被动接收的。上游给它什么结果它就信什么。Layer 3: 调用链——异常从内向外SecurityFilter 最先决定给什么调用顺序ContextFilter.invoke()→ ClassLoaderFilter.invoke()→ ExceptionFilter.invoke()→... → SecurityFilter.invoke()→ invoker.invoke()SecurityFilter 在内层最先拿到真实结果。它有两个选择如实传播把真实异常的 Result 往上抛消化掉自己构造一个干净的 Result 返回问题代码走的是第二条路——返回了不带异常的 Result。ExceptionFilter 拿到这个干净 ResultappResponse.hasException()为 falselogger.error不执行。这不是 ExceptionFilter 不工作——是它压根没收到异常信号。【解读】为什么 ExceptionFilter 不日志 怎么修Layer 1: 因果链——SecurityFilter 在内层做了无害化处理SecurityFilter(order100)在内层拦截非法请求 → 返回 AsyncRpcResult.newDefaultAsyncResult(inv)← 不含异常 → 异常不传播到外层 → ExceptionFilter.onResponse()收到 clean Result → appResponse.hasException()false→ logger.error 不执行 → 日志凭空消失Layer 2: 这不是 ExceptionFilter 的 bug——是信任模型被打破了ExceptionFilter 的设计哲学是被动感知——它相信上游 filter 会把异常如实传递到 Result 里。这个信任基于一条隐含规则每个 filter 要么通过invoker.invoke()传播异常要么把异常塞进 Result 再返回。SecurityFilter 违反的是这条规则——它既没有invoker.invoke()因为被拦截了也没有把异常塞进 Result。它返回了一个看起来正常的 Result从 ExceptionFilter 的视角看这次调用一切正常。“一个 filter 有 logger.error 不代表它每次都能输出——它依赖上游 filter 先把异常传到它这里。”Layer 3: 修复方案——让 SecurityFilter 如实传递异常方案 A推荐拦截后把异常设进 ResultpublicResultinvoke(Invoker?invoker,Invocationinv){if(!isAllowed(inv)){returnAsyncRpcResult.newDefaultAsyncResult(newRpcException(Access denied: inv.getMethodName()),inv);}returninvoker.invoke(inv);}RpcException 是未在接口签名中声明的非受检异常 → ExceptionFilter.onResponse() 看到hasExceptiontrue→ 执行logger.error。方案 BSecurityFilter 自行日志publicResultinvoke(Invoker?invoker,Invocationinv){if(!isAllowed(inv)){log.warn(Access denied: {},inv);returninvoker.invoke(inv);}returninvoker.invoke(inv);}方案 B 的问题在于如果多个 filter 都有类似的自己处理不留痕迹的逻辑异常信息就分散在各处无法统一归集到 ExceptionFilter。【收获】排查锚点下次遇到 Provider 端异常没被 ExceptionFilter 日志时确认异常是否到达 ExceptionFilter查看ExceptionFilter.onResponse()收到的appResponse是否包含异常没到达从内到外检查各 filter 的invoke()返回的 Result 是否如实传递了异常状态。AsyncRpcResult.newDefaultAsyncResult(inv)这种调用是吞异常的常见信号Dubbo2.7.23filter 排序规则Activate(order)升序。外层 order 小内层 order 大。自定义 filter 的 order 决定它在 ExceptionFilter 的哪一侧检查项类方法行号filter 链构建ProtocolFilterWrapperbuildInvokerChain51Listener 回调路径FilterNodeinvoke58异常日志入口ExceptionFilteronResponse56异常日志入口ExceptionFilteronResponse79一个 filter 有logger.error不代表它每次都能输出——它依赖上游 filter 先把异常传到它这里。下篇我们聊 Dubbo 服务版本管理不善导致灰度失败。