AOP日志切面实战：让日志成为可复盘的证据链

一开始纯粹是为了少开几次“扯皮会”，我才写了这套日志切面。当时在某核心交易系统里，接口日志散落在各个业务模块，有的打印了入参，有的只留一句“请求进入”，异常堆栈更是看运气。每次线上出问题，第一件事不是排查，而是开会对齐三件事：“你到底调没调？”“传参到底是什么？”“失败到底发生在哪一环？”——三个问题都没有答案，因为服务端根本没有留下可还原的现场。

后来我花了几个晚上，基于AOP做了一层统一的日志切面，把关键业务方法的调用入参、出参、耗时、异常和链路标识全部采集下来，一行JSON一条记录。说白了就一个目的：把一次请求的完整现场拍下来。这套东西上线快半年，最大的感受不是“日志好看了”，而是排障效率肉眼可见地提升，扯皮会议少了八成。

这篇文章我想把设计思路、核心代码、以及那些文档里根本不写的坑都讲一遍。适合正在业务系统里想搭日志切面的人，也特别适合那些觉得日志乱成一锅粥、天天被其他团队追着问“到底是谁的问题”的倒霉蛋。

1. 先把问题讲清楚：日志切面到底解决了什么

1.1 一次线上事故里的“罗生门”

先还原一个我经历过的经典场景。

A团队说“我们已经调用了你们的接口，但你们没有返回正确结果”，B团队说“我们根本没收到你那个参数”。服务端的日志只有一句“收到请求”，没有入参，没有报文，没有时间戳，连请求来源的链路ID都没有。两边都拿不出证据，只能开会，会上反复说同一句话：“反正我们这边是对的。”

数据库里还有一条脏数据，谁写的不知道，谁在什么时间写的也不知道，因为业务代码没有统一记录操作人、操作时间和变更内容。

最后这事查了整整一天，靠的是在网关日志、Nginx访问日志、应用日志三个地方人工拼接时间线和IP，才把问题勉强对齐。效率低得令人绝望，更可怕的是，这种“罗生门”隔三差五就来一次。

1.2 “甩锅”的本质是缺乏可复盘的证据

很多人觉得扯皮是态度问题，其实不是。扯皮的根源是现场没了。

就像两辆车剐蹭，没有行车记录仪，也没有照片，双方各执一词，交警来了也只能看痕迹猜。日志切面就是技术系统的行车记录仪，它记录的不是“我觉得发生了什么”，而是“确实发生了什么”：谁在什么时间，调用了哪个方法，带了什么参数，得到什么结果，耗时多少，异常堆栈是什么。

业务代码里散落的log为什么撑不起这个职责？因为风格不统一。有人打info，有人打debug，有人只打印静态字符串，有人连logger都没声明。更重要的是，散落的日志没办法把“一次请求”串起来。你根本不知道那条“收到请求”和那条“扣款成功”是不是同一次调用。

切面则完全不同。它把采集点统一收敛到方法边界，在方法执行前记录入参，执行后记录出参，异常时记录堆栈，天然具备“一次调用一条完整记录”的特征。这正是证据链最需要的结构。

1.3 什么样的日志才叫“能甩锅的日志”

我把这套日志上线前，先给自己定了四条验收标准，达不到就不算完事。

第一，一条traceId贯穿全程。从请求进入系统开始，所有相关日志都带着同一个链路ID，跨线程、跨服务也能串起来，否则查问题只能靠猜。

第二，入参和出参可还原。参数丢了，你就没法判断是调用方传错还是接收方读错；出参丢了，你就没法判断结果是正确还是被下游篡改。

第三，异常带完整堆栈。只记一句“error happened”等于没记，必须把异常类型、消息和堆栈打出来，最好还能标记是哪一个方法抛出来的。

第四，能定位到机器、线程和耗时。这主要用于排查环境差异和性能瓶颈，比如“只有一台机器超时”，那你得知道是哪一台。

再加一条隐性标准：可检索。如果日志写进文件之后翻不出来，那和没写没区别。后面我会专门讲结构化输出和检索配套。

2. 切面总体设计与选型：这活儿别一上来就写代码

2.1 先选切面载体：注解、全局拦截，还是两边都要

很多人一听说日志切面，就想当然用Spring AOP把所有Controller方法拦一遍。这么做当然能跑，但坑也不少——所有接口都记录全量参数，日志量能把你磁盘打满；低频方法压根没必要记；个别接口参数里有大文件、流对象，直接序列化能让接口崩掉。

我最终采用“全局入口拦截 + 关键方法注解”双通道方案：

• 全局入口：用Filter/HandlerInterceptor拦截所有HTTP请求，生成traceId，记录基础访问信息（路径、IP、耗时、状态码），这部分粗粒度且必须轻量。
• 关键方法注解：自定义@BizLog注解，加在需要精细排障的业务方法上，比如支付、下单、对账、状态机流转等核心方法，全量记录入参出参。

这个组合的好处是：基础日志天然全覆盖，关键路径日志能做得非常深，两不耽误。如果你只想用一种，我建议优先做注解方式，因为业务方法层才是问题最集中的地方，只拦Controller往往连参数被谁改了都看不出来。

2.2 一路追踪：traceId怎么把一次调用串起来

traceId是日志证据链的灵魂。我用的方案很简单：

• 在Web入口Filter里，如果上游请求头带traceId就沿用，否则用UUID生成一个新的，然后塞进MDC。
• 日志框架（比如Logback）在输出Pattern里加上%X{traceId}，这样所有同线程内的日志都自动带上这个ID。
• 切面代码里直接MDC.get("traceId")取出，放进结构化日志字段。
• 如果这个方法要异步执行，子线程默认拿不到父线程的MDC，需要额外处理，这个坑后面专门讲。

MQ消费场景同理：消息投递时把traceId放进消息头，消费时取出来放回MDC。HTTP调用下游时，用traceId请求头透传。这么一串，整条链路的日志就能串成一棵树。

有人会问：“这不是分布式链路追踪系统干的事吗？我直接用现成的不行？”可以，但很多团队的体量其实用不上完整链路追踪平台。自己维护一个traceId成本极低，却能解决80%的跨模块问题排查需求，对现有代码的侵入也几乎为零。

2.3 日志结构设计：一行一条JSON，不是给人看的

传统日志是一串可读文本，人眼看着舒服，机器检索起来很痛苦。日志切面的产出我统一设计成“一行一条JSON”，每个字段都有固定含义，既方便Filebeat这类采集器消费，也方便在日志平台里按字段过滤。

我常用的字段结构是这样的：

这里有个经验：args和result千万不要无脑全量塞进去，尤其是大对象。我先在各字段上做“摘要化”处理，比如只保留对象id和几个关键业务字段，见后面第4章。字段统一命名，保证你换日志平台的时候不用改切面代码。

3. 核心代码实现：从注解到切面再到落盘

3.1 定义注解：把控制权交回业务方法

先看注解定义：

@Target(ElementType.METHOD) @Retention(RetentionPolicy.RUNTIME) public @interface BizLog { /** 业务类型，用于检索，比如 order、pay、refund */ String bizType() default ""; /** 是否记录入参，默认记录 */ boolean logArgs() default true; /** 是否记录出参，默认记录 */ boolean logResult() default true; /** 忽略的入参字段名（按参数名匹配），用于敏感信息 */ String[] ignoreArgs() default {}; }

注解要解决的问题是“不同方法想记录的程度不一样”。比如查询类方法，入参就一个id，全量记录没毛病；但上传文件方法，参数里有MultipartFile，你必须选择不记录或只记录文件名；密码修改方法，参数里有密码明文，你得强制忽略。

把选择权交给业务方法owner，比在切面里写死一套规则要灵活得多——每个方法最清楚自己哪些参数能记录。

3.2 切面类的核心逻辑：为什么用环绕通知而不是前置加后置

切面实现的核心是@Around环绕通知，原因很简单：一次调用最需要的是“入参+出参+耗时”这三者之间的对应关系，只有环绕通知能把它们放在同一个作用域里，前置通知和后置通知拆成两段，很难保证关联，还得自建上下文传递。

直接看核心代码：

@Aspect @Component public class BizLogAspect { private static final Logger log = LoggerFactory.getLogger(BizLogAspect.class); @Around("@annotation(bizLog)") public Object around(ProceedingJoinPoint joinPoint, BizLog bizLog) throws Throwable { long start = System.currentTimeMillis(); boolean success = true; Throwable error = null; Object result = null; MethodSignature signature = (MethodSignature) joinPoint.getSignature(); String methodStr = signature.getDeclaringTypeName() + "#" + signature.getName(); String traceId = MDC.get("traceId"); Object[] args = joinPoint.getArgs(); try { result = joinPoint.proceed(); return result; } catch (Throwable t) { success = false; error = t; throw t; } finally { try { long costMs = System.currentTimeMillis() - start; Map<String, Object> logEntry = new LinkedHashMap<>(); logEntry.put("timestamp", LocalDateTime.now().format(DateTimeFormatter.ISO_LOCAL_DATE_TIME)); logEntry.put("traceId", traceId); logEntry.put("type", "bizLog"); logEntry.put("method", methodStr); logEntry.put("bizType", bizLog.bizType()); logEntry.put("success", success); logEntry.put("costMs", costMs); logEntry.put("thread", Thread.currentThread().getName()); if (bizLog.logArgs()) { logEntry.put("args", safeConvertArgs(args, bizLog.ignoreArgs())); } if (bizLog.logResult()) { logEntry.put("result", safeConvert(result)); } if (error != null) { logEntry.put("errorType", error.getClass().getName() + ": " + error.getMessage()); logEntry.put("errorStack", getStackSummary(error)); } log.info(JSON.toJSONString(logEntry)); } catch (Throwable ignore) { // 日志采集绝不能影响业务主流程，这里兜底吃掉所有异常 } } } }

几个关键设计点：

• joinPoint.proceed()后立刻return result，但finally照常执行记录逻辑。这样返回值先回去，日志异步还是同步都不阻塞主流程。
• finally里整个日志逻辑包了try-catch，而且catch的是Throwable。为什么？因为日志模块一旦序列化出问题，绝不能把原本正常的业务请求带崩。这个兜底是日志切面的底线。
• errorStack我没存完整字符串，而是取前若干行，避免一条日志几MB。后面会细说。

3.3 参数安全转换：别让日志炸掉业务

safeConvert是实现里最容易出问题的一环。我见过线上接口突然失败，最后定位到是日志切面尝试序列化HttpServletRequest时抛了异常，业务接口直接被日志带崩。

所以safeConvert的处理逻辑是：先判断常见框架类型，能摘要就摘要，不能序列化的直接降级成字符串描述。

private Object safeConvert(Object obj) { if (obj == null) { return null; } // 流、请求响应对象只保留类型名和toString摘要 if (obj instanceof HttpServletRequest || obj instanceof HttpServletResponse || obj instanceof MultipartFile || obj instanceof InputStream || obj instanceof OutputStream) { return obj.getClass().getSimpleName() + "@" + Integer.toHexString(obj.hashCode()); } if (obj instanceof MultipartFile) { MultipartFile file = (MultipartFile) obj; return "MultipartFile(" + file.getOriginalFilename() + ", size=" + file.getSize() + ")"; } try { String json = JSON.toJSONString(obj); return json.length() > 2000 ? json.substring(0, 2000) + "...[truncated]" : json; } catch (Throwable t) { return "<unserializable: " + obj.getClass().getName() + ">"; } }

MultipartFile在上面的顺序里会先命中第一个instanceof吗？会，MultipartFile不是InputStream，所以顺序OK。HttpServletRequest实现了多个接口，也许换个顺序会更好，但这里先用一个概括性的实现。重要的是思路：每一个分支都要保证不抛异常。

3.4 落盘与检索：logback配置别偷懒

切面打完日志，剩下就是落盘。我用Logback的pattern输出，把traceId和机器IP打进去：

<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{40} [%X{traceId}] - %msg%n</pattern>

JSON已经是“一行一条”，滚动策略按天滚动，保留30天。采集端我用的Filebeat把日志推给日志检索平台（自家运维搭的基础设施，不是多复杂的系统），重点是把message字段按JSON解析成结构化字段，这样就能在检索页面上直接过滤traceId、method、success了。

如果没有日志平台，只想本地排查，那至少确保你可以用grep "traceId"把一次调用的所有日志捞出来。有总比没有强，结构化的价值是后面慢慢体现的。

4. 真正拉开差距的细节：脱敏、性能与边界

4.1 敏感字段脱敏：这条红线不能碰

日志切面最大的隐患不是技术风险，而是合规风险。把手机号、身份证号、密码、token直接打进日志，等审计或安全团队找你喝茶，那时候说什么都晚了。

我的处理分三层：

• 注解层的ignoreArgs：调用方明确指定某个参数不记录。
• 字段名黑名单：不管参数嵌套多深，碰到password、idCard、mobile、token、secret这些名字，一律脱敏或丢弃。
• 通用的脱敏工具：对字符串值做规则替换。手机号变138****1234，银行卡保留后四位，身份证保留前3后4。

示例：

public static String mask(String fieldName, String value) { if (value == null || value.isEmpty()) { return value; } String lower = fieldName.toLowerCase(); if (lower.contains("password") || lower.contains("secret") || lower.contains("token") || lower.contains("pwd")) { return "******"; } if (lower.contains("mobile") || lower.contains("phone")) { return value.replaceAll("(\\d{3})\\d{4}(\\d{4})", "$1****$2"); } // 其他规则按需扩展 return value; }

注意，嵌套对象序列化时，最麻烦的是字段在JOSN里已经变成字符串key-value，你得递归遍历处理或者序列化前改用自定义序列化器。这个改造量不小，但必须做。经验是：宁可日志不完整，也不能把明文敏感信息写进日志文件。出了问题，“演示功能很完善”救不了你。

4.2 序列化与性能：大参数、高并发要防一手

日志切面是同步代码，每写一条日志就多一次序列化和IO。如果你的接口本身只有30毫秒，日志序列化又花了20毫秒，那这个切面就是在给系统帮倒忙。

我的降噪策略：

• 大对象截断。args和result超过2000字符就截断，保留头尾加“省略号”。
• 高频低价值接口不开全量参数。注解默认logArgs和logResult都是true，但高频纯查询接口我会显式设成false，只保留方法名、耗时和success。
• 采样开关。给切面加一个可配置的采样率，比如1%的请求才打全量参数，保证异常时能基本还原现场，同时日志量可控。
• 控制日志级别。正常成功路径用INFO，业务异常也用INFO，只有系统异常才用ERROR。ERROR日志要接告警，如果业务异常大量刷ERROR，告警会变成狼来了，运维反而不再认真看。

高并发场景下一开始可以同步写入，观察磁盘IO和接口RT，如果明显受影响再改异步写入。异步写入要考虑线程池大小、队列长度、日志丢失容忍度，这些要看业务场景，不能无脑异步。

4.3 异常分支处理：切面里throw出来的异常怎么记

一个常见的错误写法：在@Around里用catch捕获Throwable，然后直接吞掉，不重新抛出。

后果很严重：业务代码明明抛了异常，调用方没收到任何信号，还以为执行成功，最终出现更难排查的数据不一致问题。日志切面绝不能改变业务流程的异常语义。

我的做法是上面已经展示过的：catch里先把异常记到局部变量，然后throw t原样抛出。finally里根据局部变量判断是否成功，再决定输出那条日志的success、errorType、errorStack字段。

业务异常和系统异常要分流：

• 业务异常（比如参数校验失败、余额不足）是预期内分支，记录INFO日志即可，保留业务码和消息文本。
• 系统异常（比如数据库连接超时、外部服务宕机）需要完整堆栈，用ERROR级别输出，方便告警规则直接按error级别聚合。

这个分流不是切面能自动完成的，需要业务方法配合——业务异常建议在代码里先捕获加工，再抛出统一业务异常类型。切面里根据异常类型做不同级别的处理，让日志既完整又不吵。

5. 实测踩坑记录：这些坑我都是拿上线事故换来的

5.1 异步线程里traceId丢失，链路断了一半

第一版切面上线后，有运维同事反馈：部分日志的traceId是null。查了半天，发现问题是业务代码用了线程池异步处理任务，而子线程里MDC Context根本不会自动从父线程传过来。

解决办法是自定义线程池装饰器，提交任务时把父线程的MDC快照带进去，执行时设置回来，结束后清理：

public class MdcTaskDecorator implements TaskDecorator { @Override public Runnable decorate(Runnable runnable) { Map<String, String> contextMap = MDC.getCopyOfContextMap(); return () -> { if (contextMap != null) { MDC.setContextMap(contextMap); } try { runnable.run(); } finally { MDC.clear(); } }; } }

使用Spring的ThreadPoolTaskExecutor时，直接设置setTaskDecorator(new MdcTaskDecorator())即可。排查这类问题时，我的经验是：先在测试环境人为制造一个异步场景，打日志验证traceId是否贯穿。别等上线后才发现子线程日志全部串线。

5.2 日志量爆炸：一次活动接口把磁盘打满

有一次做秒杀活动，我以为已经控制得不错了，结果上线一小时磁盘告警。一看日志量，每秒几千条，每条JSON平均2KB，磁盘IO直接拉满。

分析下来，问题出在接口本身QPS高，而我又在方法上开了全量参数，等于每个请求都多写2KB。解决思路是分场景降噪：

• 活动类高QPS接口默认只记异常，正常路径不记录。
• 抽样记录：比如每100个请求记一条，用于日常巡检和性能统计。
• 日志文件按天滚动，保留最近3天热数据，其他归档到冷存储。

采样逻辑建议做成可配置的，不要写死在代码里。我后来配了配置中心，线上动态调整采样率，再也没发生过日志追着磁盘跑的尴尬。

5.3 循环引用导致序列化栈溢出，业务接口直接被日志拖死

另一个大坑：业务对象里出现了循环引用，Father对象里有个Son，Son里又有Father引用。日志切面一序列化，Jackson直接抛StackOverflowError，然后被我在finally里捕获吞掉——虽然业务没受影响，但日志完全没写出来。更糟的一次是我还没加整体兜底的时候，序列化异常直接跟着日志调用链冒出去，把原本正常的接口打挂。

解决手段：

• 对复杂业务对象，不要全量序列化，只记录关键id字段。
• 序列化时统一配置禁止循环引用检测或使用引用标记，比如Fastjson的SerializerFeature.DisableCircularReferenceDetect。
• 最稳妥的一招：参数对象必须重写toString，返回业务自定义的摘要信息，切面优先用toString，toString有问题再走JSON序列化。

这个坑告诉我们：日志切面本身的健壮性必须高于业务代码。你可以业务写得糙，但日志模块必须精细，否则它只会添乱。

5.4 切面没生效：同一个类里的“自调用”静默失忆

还有一个经典问题：我在同一个Service里写了方法A和方法B，A内部调用B，B上加了@BizLog。上线后发现B的日志完全没打。

原因是Spring AOP基于动态代理，自调用不会经过代理对象，所以注解根本不会被切面识别。解决方式有三种：

• 把B方法拆到另一个Bean里，让外部代理生效。
• 在A内部获取当前代理对象再调用B，比如((OrderService) AopContext.currentProxy()).b()。
• 干脆在A方法上也加@BizLog，把关键调用提升到入口记录。

这个限制不是日志系统独有的，Spring事务注解也一样，但日志场景更容易被忽略。我的建议是：关键方法尽量从外部入口打进切面，别依赖同类内部相互调用的链路。

6. 日志上线之后，排障从“扯皮”变成了“翻记录”

6.1 一次跨团队问题定位的完整复盘

日志切面上线两个月后，遇到一次典型的跨团队问题。一个对接费率的接口偶发失败，外部团队说他们调用了，我们服务端却一直没找到失败日志。之前碰到这种问题，第一反应是叫双方排查，但这次我们直接翻切面日志。

用traceId搜索，十几秒就找到了那条完整调用：入参里传过来的金额是0.1234567891，十位小数，费率服务在解析时对精度做了截断，导致后续计算偏离预期。切面日志里的args字段完整记录了这笔请求的入参，errorType准确记录了异常抛出的位置。整个定位过程不到20分钟，没有开会，没有扯皮，直接贴日志给对方。

这个案例给了我很大信心：日志切面投入不大，但产生的数据质量，决定了整个团队线上排障的下限。

6.2 把日志变成“责任判定书”的几个配套动作

光有日志还不够，我把“查询”也做了配套才真正好用。

• 保留策略：热数据7天，全文保留30天，超期清理。这个策略既能满足大多数问题追溯需求，又不会让存储成本无脑膨胀。
• 检索模板：在日志平台里保存一个固定查询模板，输入traceId就能拉出整个调用链，不需要每次重新拼查询语句。
• 告警入口：把ERROR级别日志按分钟聚合，超过阈值触发内部告警，日志切面从“事后翻记录”升级到“事中发现问题”。
• 敏感信息巡检：每周跑一个脚本，扫描日志文件里的手机号、身份证号明文，有就直接报警。合规这块别抱侥幸心理。

这些动作不是一次性做完，而是上线后根据实际排障反馈逐步加的。先让日志能用，再让它好用。

6.3 一个忠告：日志系统是给你自己用的，不是表演给领导看的

最后说点实在话。日志切面这种东西，“能跑”和“有用”之间隔着一道巨大的鸿沟。如果你只是为了汇报PPT里写一句“搭建了统一日志体系”，然后从不关注日志质量，那这套系统很快会变成数据垃圾场。

我现在的习惯是每季度审视一次：哪些接口还在打全量参数但根本没人查？哪些日志字段从来用不上？哪些异常一直在刷ERROR但告警没人看？该关的关，该减的减，该修的修。时刻提醒自己，这套日志是写给自己和团队里的倒霉蛋看的，不是写给领导看的。

还有一个一直在用的习惯：默认情况下不无脑记日志，等到哪个接口真的需要深入排查，再把这个接口的全量参数打开，集中观测一段时间，定位完再关掉。这样日常日志量很干净，排障时又能精准出击。

结语不写了，就送大家一句最近常跟同事说的话吧：把现场记得够清楚，你不需要甩锅，因为锅在谁头上，一眼就能看出来。