我做了快十年的Java后端,有一个感慨越来越深:程序员可以接受系统有bug,但几乎不能接受"用户干了什么"这件事查不到。尤其是金融、政务、企业内部系统里,操作日志一旦缺失,出了问题往上追的时候,那种无力感真的能把人逼疯。这些年见过太多项目,日志还是靠各业务方法里手动塞几行代码来记录,方法一多就漏记、错记、格式乱,最后日志表比业务表还难维护。所以今天想认认真真聊一下Spring AOP的五大通知类型,以及怎么利用它们从零搭一套企业级操作日志系统。这篇文章的核心不是贴一段切面代码就完事,而是会讲清楚五个通知类型各自在日志链路里扮演什么角色、为什么这么用、落地时有哪些坑,让读者能真正在自己的项目里复现出来。
1. 为什么操作日志系统都用AOP来做:手动埋点的三个死穴
1.1 手动记录日志的痛点:漏记、侵入、没法统一
先说一个反直觉的现象:很多团队不是不会写日志,而是被手动埋点坑得太惨。我刚工作那阵接过一个老项目,记录用户操作的方式是每个业务方法里复制粘贴一段logUtil.saveLog()的代码。表面上看没什么问题,但三个月后我数了一下,全项目这种散落的埋点有四百多处,格式还不统一:有人记的是"用户修改了订单",有人记的是"order.update: id=123",还有人只记了参数没有记结果。排查一个线上问题的时候,要在几十个文件里翻来覆去找日志入口,效率低得吓人。
手动埋点有三个死穴是绕不过去的。
第一,漏记。只要新增一个业务方法,开发人员就得记得手动加埋点代码,版本一多、人员一流转,漏记几乎是必然的。别跟我提"我们团队纪律好",纪律在现实中就是用来被打破的。第二,侵入性强。日志逻辑和业务逻辑耦合在一起,业务方法里塞的日志代码越多,方法就越臃肿,维护成本直线上升。有一个很直观的指标:当埋点代码行数超过业务代码行数三分之一的时候,这个方法的可读性已经废了,后面谁改谁骂娘。第三,没法统一处理。你需要统一记录当前登录用户、统一格式化请求参数、统一处理异常堆栈的时候,手动埋点根本没得谈——你只能在几百个埋点里一个个去改。
1.2 AOP解决逻辑横切问题的原理:约定大于配置
AOP解决的就是这种横切关注点。日志、鉴权、性能监控、事务这些逻辑不隶属于某一个业务模块,而是横跨所有业务模块,如果用传统OOP的思路去写,就会散落得到处都是。AOP的核心思想很简单:你告诉框架"哪些方法的哪些时机需要做哪些事",框架在运行时帮你织入这些逻辑,业务方法本身完全不需要知道日志的存在。
打个生活化的比方你就明白了。手动埋点就像每家每户自己安装雨棚,张三装的铁皮的、李四装的塑料的,有的还漏雨;AOP呢,相当于小区物业统一做一个玻璃幕墙,整栋楼的风雨问题一次性解决,每家每户连一根螺丝都不用拧。操作日志、操作鉴权、接口幂等等级校验,天生就适合用AOP来做横切处理。
Spring AOP在实现上走的是动态代理的路子。某个Bean被容器创建的时候,Spring发现这个Bean的类匹配了某个切面,就会为该Bean生成一个代理对象——如果你这个类实现了接口,默认采用JDK动态代理;如果没实现接口,则采用CGLIB子类代理。代理对象里面编织了我们定义的增强逻辑,调用方实际拿到的就是这个代理,所以你在业务类内部用this调用方法的时候,AOP也不会生效,这些年我遇到很多新手在这一步栽跟头。
1.3 企业级操作日志系统的核心需求拆解
在动手写切面之前,先理清楚一套"企业级"操作日志系统到底需要满足哪些要求,这样才能知道自己写的每个组件是在解决什么问题。
第一个要求是完整性。所有需要审计的操作,不管成功失败,都要有记录。很多系统只记成功日志,失败操作不记,结果线上出问题一查,发现用户报错时的操作根本没日志,这个锅甩都甩不出去。第二个要求是幂等可靠。日志记录本身不能影响主业务流程,更不能因为日志模块出了问题导致业务操作失败。这就要求日志处理尽量异步化,并且要捕获处理过程中可能出现的异常。第三个要求是易追溯。每一条日志要能够把"谁、在什么时间、对什么、做了什么、结果如何"这五个维度完整记录下来。这四个字在企业里通常就是审计的基本要求。第四个要求是低侵入。新接手的业务开发人员只需要一个注解就可以完成埋点,不需要关心日志框架内部怎么工作。
基于这四点,我觉得用Spring AOP的五个通知类型各司其职来支撑整个架构,是非常顺手的选择。接下来就把这五个通知类型掰开揉碎讲清楚。
2. 五大通知类型核心原理:每一个类型在日志链路里的真实角色
2.1 前置通知在日志系统里负责什么
前置通知用Around通知可以完全替代它做的事情,但为什么还要单独认识它?因为它是理解AOP执行模型的最佳入口,而且如果你只需要做"方法执行前记录一笔标记"这类极简逻辑,直接用前置通知就够了,代码最简洁。
前置通知在目标方法运行之前执行,在Spring里通过@Before注解声明,默认只能在方法执行前做增强,无法控制目标方法是否执行、无法改动目标方法的入参、更无法改变返回值。它适合做前置校验、准备上下文数据、计数器累加这类操作。
在我们这套操作日志系统里,前置通知有一个很有价值的用途:生成一个唯一的操作流水号。请求进来的时候,先不管后面成不成,先生成一个UUID塞进请求上下文里,后面所有环节共用这个流水号,这样日志记录和业务异常就能通过同一个traceId关联起来。如果翻车了,先检查一下前置通知包含的方法签名——JoinPoint里能取到目标方法、目标对象、参数列表,这个信息是整个日志系统后续所有数据的基础。
2.2 后置通知与返回通知的区别:成功失败分流从这里开始
很多初学者会把后置通知和返回通知搞混,这俩其实差别非常大。
后置通知用@After声明,它的语义是"无论目标方法正常返回还是抛异常,我都执行"。注意是"无论",没有条件,用大白话说就是"我不管你是死是活,方法结束后我都要来收尸"。而返回通知用@AfterReturning声明,它的语义是"只有目标方法正常返回了我才执行"。如果目标方法抛了异常,返回通知的逻辑根本不会被触发。
在操作日志系统里,这两个通知是成功日志和失败日志分流的关键:
- 返回通知里记录成功操作:拿到正常返回的结果,生成"操作成功"的日志记录。
- 异常通知里记录失败操作:拿到异常信息及堆栈,生成"操作失败"的日志记录。
- 后置通知里做统一的收尾工作:比如释放资源、清理ThreadLocal上下文,防止线程池场景下的上下文污染。
要注意的是,返回通知的returning属性和目标方法返回值类型如果不匹配,Spring启动或运行时会有类型匹配的约束,实际运用时要留意返回值类型兼容的问题,不匹配时通知不会被调用。
2.3 异常通知与后置通知如何配合完成失败审计
异常通知用@AfterThrowing声明,通常搭配throwing属性指定异常参数的名称,通过这个参数就能拿到目标方法抛出的异常对象。在操作日志系统里,异常通知专门负责失败日志的生成。
不过异常通知有一个非常隐蔽的坑:默认情况下,目标方法抛出的异常会继续向外传递,异常通知感知到了也不会吞掉异常。换句话说,异常通知拦不住异常,你不加处理的话,该抛到哪一层还是抛到哪一层。
那什么场景下异常通知和后置通知需要配合呢?我建议这样分工:
- 后置通知负责资源清理和上下文复位:比如把TraceId生成器里的线程局部变量清掉,以免线程复用时串数据。
- 异常通知负责记录失败日志:记录异常类型、异常消息、堆栈前几行,还有当时的请求参数快照。
这两者配合起来,一套操作日志系统才能做到既记录完整又不会出现脏数据。另外值得注意的一点是:如果异常被方法内部catch住吞掉了,那么异常通知不会触发,对外表现为操作成功。所以在设计切面时,对于需要严格审计的方法,我倾向于不在业务方法内部随便吞异常,让异常顺着调用链抛上来,交给AOP异常通知统一处理,这样才能保证失败审计的准确性。
2.4 环绕通知为什么是操作日志系统的首选实现
接下来谈到环绕通知,它是五个通知类型里唯一一个能"掌控全局"的存在。环绕通知用@Around声明,内部通过ProceedingJoinPoint.proceed()显式触发目标方法的执行,在这个proceed()调用前后,你可以做任何增强逻辑。
环绕通知厉害在哪里?它天然集成了前置、后置、返回、异常四类通知的能力,还额外具备了修改方法入参、修改返回值、控制目标方法是否执行的能力。正因为它能力太强,反而需要更谨慎地使用。
就操作日志系统来说,环绕通知几乎是首选的通知类型。原因有三点。第一,它可以在同一处代码块里以顺序化结构完成"前置准备、调用业务、成功记录、异常记录、最终清理"全部流程,代码可读性和维护成本远低于把逻辑拆到四五个通知方法里。第二,它对方法的执行具备完全的控制力,可以catch异常后再决定是抛出去还是记录后吞掉。第三,因为所有逻辑都在一个方法里,ThreadLocal上下文变量的生命周期管理非常直观,不用的变量在finally块里清掉就行。
我们实际做日志切面的时候,90%的场景一个环绕通知就全部搞定了。那为什么要在一篇文章里详细讲五个通知类型?因为理解了每一种通知的语义边界,你才知道环绕通知里的哪个代码块对应哪类通知时机,写出来的代码才可能是逻辑清晰的。而且有些场景确实需要多个通知配合,比如既要针对特定异常做单独处理、又希望后置通知统一做资源回收,混合使用@Around和@After也是常见组合。
2.5 五大通知类型的语义对查表
综合来看,五个通知类型的语义边界下表已经很清楚了。
| 通知类型 | 注解 | 触发时机 | 能力边界 | 操作日志场景中的典型职责 |
|---|---|---|---|---|
| 前置通知 | @Before | 目标方法执行前 | 不能阻止方法执行,不能改参数 | 生成操作流水号、校验权限、记录开始时间 |
| 返回通知 | @AfterReturning | 目标方法正常返回后 | 可读取返回值,仅正常返回触发 | 记录成功日志,格式化返回摘要 |
| 异常通知 | @AfterThrowing | 目标方法抛出异常后 | 可读取异常,异常仍向外抛 | 记录失败日志、异常堆栈快照 |
| 后置通知 | @After | 目标方法结束之后,无论何种结束 | 拿不到返回值 | 清理上下文、释放资源、兜底计数 |
| 环绕通知 | @Around | 完全自主控制目标方法执行 | 可改参数、可改返回、可控执行、可控异常 | 全套日志流程的推荐实现方案 |
这张表建议收藏。后面你在面试和工作中讨论AOP,基本逃不出这五行字。
3. 从零落地操作日志系统的完整过程:一个可以抄作业的切面方案
3.1 先定方案:注解标记而非全局切点扫描
在动手写切面之前,必须做一个关键的架构决策:切点要扫哪些方法?
方案A是全局扫描。比如execution(* com.demo.controller..*(..))这一句,把所有Controller方法都纳入切面。好处是埋点零成本,坏处是很多接口你根本不需要记日志,比如查询下拉列表、字典数据这类读操作记了只会给日志表灌水,而且全局扫描还会把一些工具接口也纳入,容易造成误记。
方案B是注解标记。先自定义一个@OpLog注解,加在需要记录操作日志的方法上,切点定义为"方法上有这个注解才织入"。好处是精准、语义清晰、可携带参数配置;坏处是要求业务开发人员记得加注解。
在真实企业项目里,我几乎总是建议用方案B。操作日志系统最怕的就是"什么都记",哪怕牺牲一点自动化,也要保证记录内容的可控性。所以我定义的注解里通常会带上模块名、操作类型、操作描述这三个扩展属性,业务开发人员在使用的时候配置一下即可。
3.2 自定义注解和日志实体的设计细节
先看自定义注解怎么设计。我会推荐这样一段代码:
@Target(ElementType.METHOD) @Retention(RetentionPolicy.RUNTIME) @Documented public @interface OpLog { /** 所属模块,如“订单管理” */ String module() default ""; /** 操作类型,如“新增”“修改”“删除”“导出” */ String type() default ""; /** 操作描述,支持占位符,例如“修改订单:{#orderId}” */ String description() default ""; /** 是否记录操作结果,默认记录 */ boolean recordResult() default true; }这里有三个设计要点我要特别说一下。
第一,@Retention必须设置为RUNTIME,否则运行时反射拿不到注解,切面白搭。很多新手会把注解的保留策略漏掉或者用错成CLASS,结果程序运行时切面怎么都不触发,查半个下午才反应过来,这种问题我在代码评审里见过很多次。
第二,description里设计成支持占位符。比如"修改订单:{#orderId}",切面在解析的时候用SpEL表达式从方法参数中解析出orderId的实际值,塞进日志描述里。这样做出来的日志才具备可读性,否则"用户修改了一条记录"这种描述对排查问题根本没有价值。
第三,模块、类型都不要用中文硬编码,而是用枚举或常量管理。因为在做审计报表的时候,你需要按模块、类型去聚合统计,硬编码会导致后面统计非常痛苦,你总不能在一坨中文里挨个匹配模糊查询。
日志实体类我建议这么设计:
public class OperationLog { private String traceId; // 链路唯一标识 private String module; // 模块 private String type; // 操作类型 private String description; // 操作描述 private String operatorName; // 操作人 private String operatorId; // 操作人ID private String methodName; // 请求方法名 private String className; // 请求类名 private String requestParams; // 请求参数快照 private String resultInfo; // 返回结果摘要 private String errorMessage; // 异常信息 private String ipAddress; // 操作来源IP private Long costTime; // 耗时(毫秒) private Date createTime; // 操作时间 }字段的取舍标准很简单:将来审计要用的、排障要用的、统计报表要用的,才值得留。不要什么字段都往里塞,日志表字段太多不仅存储浪费,维表查询性能也会下降。
3.3 用环绕通知实现日志切面的核心代码
日志切面的核心代码,我基于环绕通知来实现,整体结构如下:
@Aspect @Component @Slf4j public class OperationLogAspect { private static final String TRACE_ID_KEY = "traceId"; private static final String START_TIME_KEY = "startTime"; @Pointcut("@annotation(com.demo.log.annotation.OpLog)") public void opLogPointcut() {} @Around("opLogPointcut()") public Object around(ProceedingJoinPoint joinPoint) throws Throwable { // 1. 前置阶段:生成traceId,记录开始时间 MethodSignature signature = (MethodSignature) joinPoint.getSignature(); Method method = signature.getMethod(); OpLog opLog = method.getAnnotation(OpLog.class); String traceId = UUID.randomUUID().toString().replace("-", ""); long startTime = System.currentTimeMillis(); setContext(traceId, startTime); // 2. 记录请求上下文快照 String params = buildParams(joinPoint.getArgs(), method.getParameterNames()); // 3. 定义返回值和异常标志 Object result = null; Throwable error = null; try { result = joinPoint.proceed(); return result; } catch (Throwable e) { error = e; throw e; // 业务异常继续向外抛,不要吞 } finally { // 4. 后置阶段:无论成败都执行,统一生成日志 try { long costTime = System.currentTimeMillis() - startTime; OperationLog logEntry = buildLog(opLog, traceId, params, result, error, costTime); saveLogAsync(logEntry); } catch (Exception ex) { log.error("操作日志记录失败, traceId={}", traceId, ex); } finally { clearContext(); } } } private void setContext(String traceId, long startTime) { // 这里用TransmittableThreadLocal,避免异步链路丢失上下文 } private void clearContext() { // 清理ThreadLocal,避免线程复用导致数据污染 } private void saveLogAsync(OperationLog logEntry) { // 异步提交到日志服务或消息队列 } }这段代码里有几个地方我要重点解释一下,因为它们直接决定了这套日志系统能不能在企业环境里真正跑起来。
第一,catch之后又重新throw。这是环绕通知最容易被忽略的原则:默认情况下,环绕通知不应该吞掉业务异常。一旦吞掉异常,外层的事务拦截器会认为方法执行成功了,事务就提交了,这可能导致数据没回滚、日志却显示成功的严重事故。切面里的catch块是为了捕获并记录异常信息,然后一定要把这个异常重新抛出去,让Spring事务和上层调用者继续处理。
第二,日志构造放在了finally块里。不管业务方法是成功还是抛异常,finally块里的代码都会执行。我在finally块里根据error变量是否为空来判断记成功日志还是失败日志,这样就用一个环绕通知完成了后置通知和异常通知的职责整合,同时保留了完整的上下文信息。
第三,日志记录本身一定要try-catch兜底。最坏的情况是日志模块挂了,主流程不能跟着挂,业务操作应该照常执行。日志记录失败只输出一行错误日志即可,绝不能让它影响核心业务链路。这一点在方案设计时就要作为一条铁律写进团队规范里。
3.4 参数快照的序列化:不要踩Jackson循环引用的坑
参数快照是整个日志系统里最容易出bug的地方,没有之一。
实体类往往存在双向关联——用户关联订单、订单关联用户,一旦用默认的Jackson序列化去toString,很可能触发无限递归,直接抛StackOverflowError,然后被日志切面的catch捕获。运气好的时候日志没记录成功,主流程还算正常;运气不好的时候,异常被误吞,事务就乱了。
我的解决方案是三层防御策略。
第一层,统一使用Jackson序列化工具,并配置好循环引用处理规则。在这里我会将默认的序列化行为调整为FAIL_ON_EMPTY_BEANS关闭、使用@JsonInclude标记非空字段,且对常见的基础类型包装和双向关联做辅助配置。特别地,对于Object对象,我用writeValueAsString之前先做一层深拷贝或剥离冗余引用的预处理,尽量避免把整个业务大对象完整序列化。
第二层,在注解里增加一个"是否需要记录参数"的开关,以及一个"参数过滤"的SpEL表达式属性。导出的接口、批量下载接口这类参数又大又敏感的,可以不记录请求体或只记录关键字段。比如:
@OpLog( module = "报表中心", type = "导出", description = "导出报表", ignoreArgs = true )第三层,在序列化工具里增加一个长度上限,超过阈值进行截断。有些接口的参数确实很大,比如批量审核接口一次传几百个ID,全部序列化又大又没意义,截断到保留核心信息即可。
我见过有团队因为参数序列化问题直接把日志功能关了,这其实是因噎废食。大家要记住,企业级系统的日志功能必须对"日志本身引发的异常"有极强的防御能力,宁可记不全,不能记出问题。
3.5 用SpEL表达式动态组装日志描述
前面提到description里支持占位符,这里展开讲一下具体实现。
比如这样一个业务方法:
@OpLog( module = "订单管理", type = "修改", description = "修改订单状态:{#orderId}:{#status}" ) public void updateOrderStatus(Long orderId, Integer status) { // 业务实现 }切面里要把{#orderId}和{#status}替换成实际值。实现方式是用Spring自带的SpelExpressionParser去解析"#orderId"这种表达式:
public String parseDescription(String template, Object[] args, String[] paramNames) { if (template.indexOf("{#") < 0) { return template; } StandardEvaluationContext context = new StandardEvaluationContext(); for (int i = 0; i < paramNames.length; i++) { context.setVariable(paramNames[i], args[i]); } String pattern = "\\{#([^}]*)}"; Matcher matcher = Pattern.compile(pattern).matcher(template); StringBuilder sb = new StringBuilder(); while (matcher.find()) { String expr = matcher.group(1).trim(); try { Object value = parser.parseExpression(expr).getValue(context); matcher.appendReplacement(sb, value == null ? "null" : value.toString()); } catch (Exception e) { matcher.appendReplacement(sb, "解析失败:" + expr); } } matcher.appendTail(sb); return sb.toString(); }这套方案的精髓在于利用SpEL的表达式解析能力,让日志描述的组装彻底脱离硬编码。参数的字段嵌套也能支持,比如参数对象里有user.name,就可以写成{#user.name}。这里提醒一下,SpEL解析性能虽然尚可,但建议在切面里做一层缓存,同一个方法描述模板不要每次都重新编译表达式。用ConcurrentHashMap把模板字符串作为key、Expression对象作为value缓存起来就好。
4. 五个通知类型组合实战:执行顺序与事务嵌套的细节推演
4.1 一个方法上有多个通知时,执行顺序到底是什么
企业级系统里,一个方法上往往不止一个切面:先是操作日志切面、再是幂等校验切面、然后是数据权限校验切面。多个切面时,通知的执行顺序就需要弄清楚。
Spring AOP支持用@Order注解或Ordered接口来控制多个切面的执行顺序。我把操作日志切面通常排在比较外层的位置,也就是说先记录日志上下文,再让业务继续往下走。这样设计的原因是:日志切面应该尽可能早地捕获到请求上下文和参数快照,并且尽可能晚地结束,覆盖完整的业务链路。
具体到单个切面方法里的执行顺序,上面环绕通知的代码顺序已经清楚了,但不妨再推演一下,如果你同时用了多个通知类型,比如:
@Around("opLogPointcut()") public Object around(ProceedingJoinPoint pjp) throws Throwable { ... } @Before("opLogPointcut()") public void before(JoinPoint joinPoint) { ... } @AfterReturning("opLogPointcut()", returning = "result") public void afterReturning(JoinPoint joinPoint, Object result) { ... } @AfterThrowing("opLogPointcut()", throwing = "e") public void afterThrowing(JoinPoint joinPoint, Exception e) { ... }默认同一切面内的多个通知执行顺序,在Spring 5.2.4及之后的版本里,主要通知类型在同一切面内有明确定义,但为了不给自己埋坑,建议大家对复杂场景直接使用环绕通知统一编排,而不是把逻辑拆到四个方法里依赖框架的隐式顺序。我见过一个项目就因为这个隐式顺序,在Spring版本升级之后,日志记录从"先记成功再清理"变成了"先清理再记成功",日志直接少了一半,排查了很久才定位到是版本升级导致的顺序变化。
4.2 环绕通知与事务代理的执行关系
事务和日志切面的执行顺序,是一个特别隐秘但特别关键的问题。
Spring的事务也是通过AOP实现的,事务拦截器本身就是一个方法拦截器。如果日志切面排在最外层,那么调用链大致是:日志环绕通知开始 -> 事务代理开始 -> 执行业务方法 -> 事务提交 -> 日志环绕通知结束。这种场景下,你在日志环绕通知的finally块里记录日志时,事务已经提交了,日志里记录到的数据状态是最终状态,不会出现"日志里写了成功但事务回滚了"的错位。
如果日志切面排在最内层,那日志记录点在事务提交之前,有可能出现"日志记录方法执行完毕,但后续事务提交失败,最终数据没落库"的情况。这个时候日志和实际数据不一致,审计起来非常痛苦。
所以我在实践里的建议是:操作日志切面的@Order值要比事务管理器的Order值更大,也就是日志切面更外层。默认情况下Spring事务的Order是LowestPrecedence,这时我们可以显式给日志切面设置一个更小的Order,让它更外包。配置方式很简单:
@Aspect @Component @Order(100) public class OperationLogAspect { ... }事务切面的优先级低于日志切面时(数字更大),事务代理会先进入,这个问题值得在实际项目里验证一下。简单记住一句话:日志的边界要包住事务的边界。这样链路时空上,日志一定是在业务最终结果定论之后才生成。
4.3 方法内部自调用导致日志不生效的问题
这是搜索"Spring AOP 不生效"时命中率最高的问题,没有之一。原因是:
@Service public class OrderService { public void foo() { this.bar(); // 这里是普通方法调用,不会经过代理对象 } @OpLog(...) public void bar() { // 业务实现 } }Spring AOP的代理机制决定了:只有通过代理对象调用方法时,切面才会生效。而类内部this调用绕过代理,直接进了原始对象的方法体,所以注解切面根本不会执行。实际开发中我至少见过五种表现形式:
- 自己在同类里调用自己的另一个方法,日志不生效;
- 通过this.method()调用,日志不生效;
- 通过内部类方式调用外部类方法,日志不生效;
- 在事务方法里调用另一个加了注解的方法,日志不生效;
- 异步线程里直接调用目标Bean的方法,日志不生效。
解决方案有几个。一是避免自调用,把被调用方法拆分到另一个Spring Bean里,通过注入Bean的方式调用;二是从Spring容器里拿到代理对象后再调用,即AopContext.currentProxy(),但需要在配置里开启exposeProxy=true;三是把日志注解加在最外层的入口方法上,不在内层方法上做文章。
在我设计的方案里,我会在切面解析方法注解前校验一下该方法是否运行在代理执行链路上。如果发现被调用的类没有被代理,直接输出一条告警日志提醒开发者,避免"以为自己记了日志,实际上没记"这种最危险的情况。
4.4 异常通知中获取到异常参数后,日志怎么记录才更有价值
异常通知的典型写法是:
@AfterThrowing(pointcut = "opLogPointcut()", throwing = "ex") public void doAfterThrowing(JoinPoint joinPoint, Exception ex) { // 记录异常日志 }但这里有个值得注意的细节:如果只有一个异常通知,你能拿到异常对象,却拿不到正常返回时的result;如果你还想拿到耗时、请求上下文,就得依赖ThreadLocal从方法入口处一路带过来。所以我的做法是,虽然介绍了异常通知,但在实际复杂的日志方案中并不直接用@AfterThrowing,而是用一个环绕通知在catch块里做失败日志记录。
什么情况我会单独用异常通知呢?比如只希望针对特定类型异常做独立的日志旁路,或者在某些外围框架中,你无法控制方法调用源,只能用异常通知做被动感知。理解异常通知的语义边界,主要是为了在别人写的旧代码里能看懂它的意图,以及在一套系统里如果遇到了多个切面协作的场景知道如何归因。
5. 从开发到上线:操作日志系统的企业级打磨与演进
5.1 日志链路中的用户身份获取和IP归属地
操作日志最核心的五要素之一是"谁"。用户身份的获取在不同架构里方案完全不同:
单体Spring MVC架构中,最常用的是从请求上下文中取登录用户。我倾向于用Spring MVC的HandlerInterceptor,在请求进入Controller之前把解析出来的用户信息放进RequestContextHolder的attribute里,日志切面再从这里取出来。这样做的好处是切面不依赖具体的登录框架,登录方式换了也不影响日志模块。
Spring Cloud微服务架构中,网关层解析完用户身份后,通过Header向下游传递,例如X-User-Id、X-User-Name。日志切面需要增加一个从RequestAttributes里读取Header并解析的逻辑。注意在异步线程里RequestContextHolder默认是拿不到请求上下文的,需要提前把用户信息快照到ThreadLocal或方法参数里。
还有一套相对省力的方案是引入用户上下文模块,用一个TransmittableThreadLocal来传递用户信息。在网关或拦截器里写入,在切面里读取,在线程池切换任务的时候通过TtlRunnable包装,保证异步场景下也能拿到正确的用户。这块代码不算复杂,但对于企业级系统来说价值很高,推荐有机会就落地。
IP归属地我之前在自建方案里踩过坑。内网系统记录的IP大部分是Nginx转发后的IP,如果没配置X-Forwarded-For解析,日志里看到的永远是负载均衡器的地址。正确的做法是优先读取X-Forwarded-For的第一个非unknown地址,再依次读取X-Real-IP、RemoteAddr。相关细节网上资料很多,这里只提醒一句:不要直接拿IpUtils.getIpAddr(request)的返回值就往日志里塞。
5.2 异步化落库:直接写入数据库为什么不能选
日志记录本身不应该阻塞业务链路。如果每次操作都同步写一次数据库,在高并发场景下日志表会成为瓶颈点。尤其是删除操作、导出操作后面的日志记录,不等它落库,用户响应时间直接增加几十毫秒,这种体验是没人愿意接受的。
异步化方案在企业项目里一般有两条路线:
路线一是线程池异步提交。在日志切面里获取到日志实体后,丢到一个有界队列里,由后台线程池批量写入数据库。这个方案优点是实现简单、不引入额外中间件;缺点是要自己处理队列积压、线程池满后的降级策略。我一般会配置核心线程数4、最大线程数8、队列容量10000,拒绝策略设置为调用者执行——注意是CallerRunsPolicy而不是DiscardPolicy。调用者直接执行的意思是线程池满了之后,当前线程自己同步写日志,宁可慢一点也不能丢日志,这个策略在企业审计系统里比丢弃更可靠。
路线二是通过消息队列异步解耦。日志切面把日志实体发到消息队列,另一个消费者服务专门负责写库。优点是可以缓冲海量日志、削峰填谷;缺点是多了一个中间件依赖,运维成本上升。如果公司已经有了消息队列基础设施,我推荐用这条路线;如果没有,用线程池就够了,别为了日志功能硬上一套消息队列。
5.3 配置化开关与灰度发布时的降级处理
日志模块要不要提供开关?答案是必须的。
我经历过一次比较惨痛的线上事故,日志切面里一个参数序列化的bug导致所有涉及上传的接口全部报错,当时那个切面还没做try-catch兜底,结果整个服务不可用,后来紧急关掉切面才恢复。这件事让我学乖了,从此之后公司内部的日志切面统一通过配置中心控制总开关,哪怕代码里写死了注解,配置项一关,切面立即失效:
operation-log: enabled: true在切面最前面加一道判断:
if (!operationLogProperties.isEnabled()) { return joinPoint.proceed(); }除了总开关,我还建议加两个子开关:参数记录开关和结果记录开关。有些敏感业务比如密码重置、手机号变更,可能出于隐私考虑不想把参数全量写进日志,这时候通过注解或配置单独关掉参数记录就很有必要。
灰度发布时日志系统怎么做降级?核心思路是隔离。日志切面里的每个外部依赖——比如用户身份解析服务、消息队列生产者——都必须允许失败不影响主流程。我惯用的做法是每一类外部调用都包一个独立的try-catch,并对耗时做限制。用户身份解析如果超过200毫秒直接返回"未知用户",不让它拖慢接口响应。这些细节,往往才是企业级系统和Demo级项目最大的分水岭。
5.4 日志数据的分表存储与清理策略
操作日志属于典型的写多读少、增量无限增长的数据,如果不做治理,一两年后日志表能撑爆磁盘。
我建议的方案是:按月分表。日志表命名为operation_log_202501、operation_log_202502这样,查询时根据时间范围自动路由到对应月份的表。实现上可以借助分库分表中间件,也可以在业务代码里做动态表名。对于大多数中大型系统,分库分表中间件是更好的选择,因为不需要改动切面代码,运维侧配置一下路由规则即可。
数据保留周期也要提前定好。合规要求和业务需求可能不同,一般企业默认在线日志保留一年,超过一年的归档到冷存储或者直接删除。需要做审计报表的月份单独备份出来,防止清理任务误删。
这里有个实操建议:清理任务放在业务低峰期每天执行一次,删除策略采用小批量循环删除而不是一次DELETE全表。一次DELETE大量数据不仅会锁表、产生巨大Binlog,还可能拖垮数据库主从同步。按主键ID范围每次删5000条,删除一批sleep一会儿,对生产库的冲击会小很多。
5.5 日志详情查询的页面设计要素
日志系统落到最后还是要给人用的,查询页面做得好不好直接影响运营和研发排查问题的效率。我个人认为最核心的查询维度有五个:操作人、操作时间范围、模块、操作类型、关键字(模糊匹配描述信息或请求参数)。列表展示尽量精简,详情页再展示完整的字段快照。
特别容易被忽略的一个功能是"按TraceId串联上下游"。一次用户操作在微服务架构里可能产生多条日志,分别记录在不同的服务里,查询时用TraceId聚合成一条链路视图,排查问题时能省大量时间。如果你们的日志切面里已经生成了traceId,就可以把traceId作为核心索引字段,查询时直接按它聚合。
页面不需要设计得花哨,但要保证两个体验:第一,列表刷新要快,分页查询的SQL要走到索引上;第二,详情查看时原始参数的展示要做语法高亮和格式化,别把一整串JSON塞在一个文本框里。
6. 一次真实线上问题复盘:AOP日志链路中"错误日志丢失"的完整排查过程
6.1 故障现象:用户反馈操作失败,日志表却没有异常记录
前阵子接到一个线上问题:用户反馈在某个页面上执行导入操作时,页面提示"导入失败",但操作日志表里只有一条"导入成功"的记录。这条日志显然与用户的实际体验产生了矛盾,如果拿这条日志去做审计,那就会被判定为系统撒谎了。
我当时第一反应是怀疑日志切面自身的逻辑有问题。于是直接去查导入接口的代码,发现方法上确实加了@OpLog注解,日志切面的环绕通知也确实包裹了该方法。那为什么异常没有被记录?
6.2 逐步排查链路:异常通知不触发的真相
我按三个方向逐步排查,最终定位到根因。
第一步,确认异常是怎么产生的。查看业务系统监控,发现导入接口在处理Excel时抛了自定义业务异常。但奇怪的是,这个业务异常在Controller层被一个全局异常处理器捕获了,全局异常处理器把异常转换成了统一的错误结果,然后返回给了前端。问题就出在这里:异常虽然发生了,但在传递到AOP切面之前,已经被全局异常处理器拦住了。因为日志切面是从Controller方法开始织入的,目标方法正常返回了一个对象,所以在环绕通知看来,这段执行并没有抛异常,走到了成功日志的记录分支。
第二步,确认日志切面的切入点。我们的@OpLog注解加在Controller方法上,全局异常处理器通过@RestControllerAdvice捕获异常并转换返回。所以Controller方法作为目标方法,其执行过程并没有把异常往外抛,目标方法本身是正常返回的。因此切面里catch不到任何异常,自然也就走不到失败分支。
第三步,设计修复方案。我把日志注解从Controller方法移动到Service层方法上,并且让Service层的方法不吞异常、直接向上抛。Controller的全局异常处理器继续做它的异常转换,但此时Service层方法已经被切面包裹,异常经过切面时会被切面感知并记录失败日志。修复之后,同样的场景下日志表里终于出现了"导入失败"的异常记录。
这里我总结一个规律性的判断方法:AOP只能感知到它织入的那个方法边界内发生的事情。如果你的切点切在Controller方法上,那么Controller里被try-catch吞掉的异常、被全局异常处理器处理的异常,切面都是感知不到的。要记录真实的业务失败,尽量把切点下沉到Service甚至更底层,让异常信息在到达Controller之前就先过一次日志切面。
6.3 这次事故后我对切面设计的三条教训总结
第一条教训:切点位置的选择优先级高于通知类型的选择。操作日志切面放在哪一层,直接决定了你能记录到什么样的真实信息。我建议把操作日志注解放在Service层入口方法上,因为Service层是业务操作真正发生的地方,一个Service方法往往对应一个完整的业务用例,粒度最合适。
第二条教训:日志模块的兜底机制要双保险。不仅要在切面内部对日志记录过程做try-catch,还要在日志框架层面增加一个监控报警。如果日志记录失败率达到一定阈值,直接报警给研发群,别让日志故障藏在暗处。没有监控的日志系统就是给自己埋雷。
第三条教训:异常处理链路和日志链路要提前规划好。全局异常处理器、AOP通知、事务拦截器三者之间的边界很容易模糊,建议在设计阶段画一张简单的调用顺序图,明确谁先谁后、谁负责记录什么、谁负责向外抛。别等着上线出了问题再去推演调用链,那时候排查成本已经很高了。
7. 写在最后的扩展思路:从操作日志到审计中台
当你把上面这套基于Spring AOP的日志系统跑通之后,可以再往前多看一步:企业需要的往往不只是"操作日志",而是一套审计中台。
操作日志仅仅是审计体系里的一个维度。完整的审计还应该覆盖登录日志、权限变更日志、数据变更日志(记录某个字段从旧值变成新值)、系统配置变更日志等。这些日志的采集手段不一定全是AOP,但AOP至少能覆盖其中很大一部分——尤其是数据变更痕迹,用AOP切在数据持久化的方法上,在环绕通知里分别取出旧值和新值,生成diff记录,是很好的做法。
再往下走,日志数据沉淀之后可以做安全分析:比如检测某个用户短时间内高频执行删除操作,检测非工作时段的大量导出行为,这些都可以基于日志数据做规则引擎。日志的价值只有被分析和利用,才能真正发挥出来,而今天的这套AOP方案就是这一切的地基。
如果项目刚开始,直接用代码中我给出的注解和切面跑通最小闭环,再逐步加上异步化、配置化、分表存储这些企业级能力即可。如果已经有一套日志方案,可以重点对照第五部分的内容做一些补强——尤其是切点下沉和日志失败兜底这两件事,值得优先处理。
最后分享一个实际体会:日志系统建设不怕慢,就怕不做。哪怕只是先定义一个注解加一个切面,记录最基础的五要素,也比等一个"完美方案"迟迟不动手强。我见过太多团队在方案评审上花了三个月、最后日志还是靠手动埋点,这种本末倒置在技术管理里真的不少见。动手实现一套AOP操作日志系统,我前前后后做过好几种版本,目前这套方案在公司内部压过几个高并发核心链路,稳定性是经过了线上考验的。你可以直接参照落地,然后把运行时遇到的问题反馈、调整,形成自己的版本。