用AOP统一管理Web请求日志：原理、实战与性能优化

搞Java Web开发这些年最让我烦躁的事情之一就是不同模块打日志的方式五花八门。有人习惯在每个Controller方法里手动写log.info(入参: ...)有人只在自己出错的地方顺手打个e.printStackTrace()还有人压根不打日志。等到线上出了故障要排查你得翻好几个系统的日志文件对着时间戳手工拼凑完整链路效率低得想摔键盘。后来我下决心用AOP统一处理WEB请求日志一次改造所有接口的请求信息、响应结果、耗时情况全走同一套管线和格式排查问题再也不用靠猜了。这篇文章就是我在项目里落地这套方案的全过程记录包括核心原理、完整代码、性能优化和生产环境踩过的坑。内容适合已经会用Spring Boot做接口开发、但还没系统性搞过AOP日志的开发者也适合那些正在犹豫要不要用AOP统一管理日志的团队参考。1. 为什么请求日志值得用AOP集中接管1.1 手动打日志的最大问题不是懒而是不可信很多人觉得日志没写好是因为团队懒这话对了一半。更本质的原因是在Controller方法里手动打日志本质上依赖人的纪律性。而人的纪律性在赶工期、改需求、修线上Bug的时候是不可靠的。我见过一个很典型的案例某个订单查询接口线上报错后端日志里能看到请求进来了但查不到入参。原因就是写这个方法的同事当时只复制了上一个方法的日志模板字段名没改结果打印出来的参数和实际业务参数对不上。这种日志别说辅助排查反而会误导方向比没有日志更可怕。还有一个隐藏问题手动打日志经常漏掉方法执行结果。很多开发者在入口打了日志但方法内部有多个return分支有的分支有日志有的分支没有。最后这条请求到底走了哪个分支、返回了什么完全靠猜。AOP接管之后切面统一在方法执行前后采集信息不管方法内部有多少个返回点日志都能完整记录最终结果。1.2 AOP的核心机制代理模式织入业务代码零侵入要理解AOP是怎么做到统一接管的最关键的词是代理。Spring AOP在运行期会给被切面拦截的Bean生成一个代理对象你的Controller实际上拿到的Bean可能已经是一个经过代理包装后的对象。调用Controller方法的时候请求先进代理代理在调用真正方法之前执行切面逻辑方法跑完了再执行切面后置逻辑。这个在执行前后插入动作的过程专业术语叫织入。生活化一点理解AOP就像在办公楼入口装了一台安检机。以前每个房间的人都要自己站岗检查进出的人现在只需要在必经入口统一装好设备就行。Controller里的业务代码完全不需要知道自己被监控了切面对业务是零侵入的。Spring AOP默认支持两种代理方式接口代理JDK动态代理和类代理CGLIB。JDK动态代理要求目标类实现接口生成的是接口的代理对象CGLIB通过生成目标类的子类来实现代理不要求接口。Spring Boot 2.x之后默认使用CGLIB原因很简单很多Controller、Service并没有实现接口用JDK代理反而容易出问题。1.3 切点表达式告诉AOP拦谁AOP必须知道该拦截哪些方法。这里需要写切点表达式我常用的是execution表达式Aspect Component public class WebLogAspect { // 拦截controller包下所有类的所有方法 Pointcut(execution(public * com.example.demo.controller..*.*(..))) public void webLog() { } }这个表达式的含义拆开看是execution()固定的表达式开头public表示只拦截public方法第一个*表示任意返回类型com.example.demo.controller..*表示controller包及其子包下的所有类.*(..)表示类的任意方法(..)表示任意参数如果你的项目里接口定义和实现分离也可以把切点定义在Service实现类上或者直接切到自定义注解上。我最推荐的方式是用自定义注解控制粒度这个后面会专门讲。2. 完整实现一个可复用的Web请求日志切面2.1 引入依赖我用的是Spring Boot 2.7 Java 8的工程核心依赖只需要一个Spring AOP的starterdependency groupIdorg.springframework.boot/groupId artifactIdspring-boot-starter-aop/artifactId /dependencySpring Boot会自动装配AOP功能不需要额外写配置类。如果你的项目是纯Spring Framework的老工程需要手动引入spring-aop、aspectjweaver依赖并确保XML里配置了aop:aspectj-autoproxy/但Spring Boot工程就省事多了。2.2 切面类完整代码下面是我在生产环境用的一个精简版切面核心逻辑都包含在内import com.fasterxml.jackson.databind.ObjectMapper; import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.Around; import org.aspectj.lang.annotation.Aspect; import org.aspectj.lang.annotation.Pointcut; import org.aspectj.lang.reflect.MethodSignature; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.stereotype.Component; import org.springframework.web.context.request.RequestContextHolder; import org.springframework.web.context.request.ServletRequestAttributes; import org.springframework.web.multipart.MultipartFile; import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; import java.time.Duration; import java.time.Instant; Aspect Component public class WebLogAspect { private static final Logger log LoggerFactory.getLogger(WebLogAspect.class); private static final ObjectMapper objectMapper new ObjectMapper(); // 自定义注解只拦截标注了WebLog的接口 Pointcut(annotation(com.example.demo.annotation.WebLog)) public void webLog() { } Around(webLog()) public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable { // 记录开始时间 Instant startTime Instant.now(); // 从RequestContextHolder获取当前请求的HttpServletRequest ServletRequestAttributes attributes (ServletRequestAttributes) RequestContextHolder.getRequestAttributes(); HttpServletRequest request attributes ! null ? attributes.getRequest() : null; String requestUrl request ! null ? request.getRequestURI() : ; String httpMethod request ! null ? request.getMethod() : ; String clientIp request ! null ? getClientIp(request) : ; String userAgent request ! null ? request.getHeader(User-Agent) : ; // 从方法签名上拿到方法名和类名 MethodSignature signature (MethodSignature) joinPoint.getSignature(); String className signature.getDeclaringTypeName(); String methodName signature.getName(); Object result null; Throwable catchException null; try { result joinPoint.proceed(); return result; } catch (Throwable e) { catchException e; throw e; } finally { Instant endTime Instant.now(); long costMs Duration.between(startTime, endTime).toMillis(); // 组装日志对象 RequestLog logInfo new RequestLog(); logInfo.setUrl(requestUrl); logInfo.setHttpMethod(httpMethod); logInfo.setClientIp(clientIp); logInfo.setClassName(className); logInfo.setMethodName(methodName); logInfo.setArgs(buildArgs(joinPoint.getArgs())); logInfo.setResult(catchException null ? buildResult(result) : null); logInfo.setException(catchException null ? null : catchException.getClass().getName() : catchException.getMessage()); logInfo.setCostMs(costMs); // 统一输出JSON格式日志 try { log.info(web-request-log: {}, objectMapper.writeValueAsString(logInfo)); } catch (Exception e) { log.error(web-request-log serialize error, e); } } } /** * 构建入参过滤掉无法序列化的对象 */ private Object buildArgs(Object[] args) { if (args null || args.length 0) { return null; } // 只记录前5个参数防止参数过多刷屏 Object[] filtered new Object[Math.min(args.length, 5)]; for (int i 0; i filtered.length; i) { Object arg args[i]; if (arg instanceof MultipartFile) { MultipartFile file (MultipartFile) arg; filtered[i] String.format(MultipartFile[name%s,size%s], file.getOriginalFilename(), file.getSize()); } else if (arg instanceof HttpServletRequest || arg instanceof HttpServletResponse) { filtered[i] arg.getClass().getSimpleName(); } else { filtered[i] arg; } } return filtered; } /** * 构建返回结果失败时不记录结果避免误导 */ private Object buildResult(Object result) { if (result null) { return null; } // 如果是响应体只截取前500字符 String json; try { json objectMapper.writeValueAsString(result); } catch (Exception e) { return [serialize-error] result.toString(); } if (json.length() 500) { return json.substring(0, 500) ...[truncated]; } return json; } /** * 获取真实客户端IP处理负载均衡转发 */ private String getClientIp(HttpServletRequest request) { String ip request.getHeader(X-Forwarded-For); if (ip null || ip.isEmpty() || unknown.equalsIgnoreCase(ip)) { ip request.getHeader(X-Real-IP); } if (ip null || ip.isEmpty() || unknown.equalsIgnoreCase(ip)) { ip request.getRemoteAddr(); } // X-Forwarded-For格式可能是client, proxy1, proxy2只取第一个 if (ip ! null ip.contains(,)) { ip ip.split(,)[0].trim(); } return ip; } /** * 日志对象字段就是我们要记录的信息 */ public static class RequestLog { private String url; private String httpMethod; private String clientIp; private String className; private String methodName; private Object args; private Object result; private String exception; private Long costMs; // getter/setter 此处省略实际代码中需要补全 public String getUrl() { return url; } public void setUrl(String url) { this.url url; } // ... 其他字段getter/setter } }再定义一个自定义注解import java.lang.annotation.ElementType; import java.lang.annotation.Retention; import java.lang.annotation.RetentionPolicy; import java.lang.annotation.Target; Target(ElementType.METHOD) Retention(RetentionPolicy.RUNTIME) public interface WebLog { }然后在需要记录日志的接口方法上加上WebLogRestController RequestMapping(/api/order) public class OrderController { PostMapping(/query) WebLog public Result queryOrder(RequestBody OrderQuery query) { // 业务逻辑... return Result.success(); } }2.3 几个必须留意的关键设计第一必须用Around而不是BeforeAfterReturning。因为我们需要拿到方法执行耗时和返回结果只有Around能把整个过程包起来在finally里做统一采集。第二异常必须重新抛出。在catch块里记录异常信息之后一定要throw e把异常抛给上层否则接口的异常语义就变了。这个问题我在生产环境看到过不止一次——有人在切面里把异常吃掉结果业务层不知道方法失败继续往下走数据一致性问题都出来了。第三入参和出参要做序列化保护。Controller方法的入参可能是MultipartFile、HttpServletRequest这类不能直接转JSON的对象方法返回值也可能超长或者有循环引用。直接调用JSON.toJSONString(args)大概率会踩坑所以需要像我上面代码里那样先过滤不能序列化的类型再对超长内容做截断。3. 日志不只是打出来格式规范、链路追踪与性能开销3.1 日志格式统一成JSON查询起来才省心很多人写日志就是log.info(url: url , cost: cost ms)这种字符串拼接的日志线上想用Elasticsearch或者Loki做检索字段拆分都费劲。我强烈建议把日志统一输出成JSON格式。上面的代码里我把一个请求的完整信息封装成RequestLog对象然后通过objectMapper.writeValueAsString转成JSON输出。这样在日志平台里可以直接按url、costMs、clientIp做字段筛选比正则匹配字符串高效太多。只要在日志开头统一加一个web-request-log前缀后续通过关键字过滤时也方便。3.2 用MDC实现traceId全链路追踪日志有了但如果一个请求会经过网关、多个微服务、多个异步线程单看某一台服务的日志还是拼不出完整链路。解决办法是引入链路追踪ID。最简单的利用方式是在切面入口生成一个traceId把它塞进SLF4J的MDCMapped Diagnostic Context日志框架会自动把它拼到日志里。然后在finally里边MDC.remove防止线程池复用导致traceId串号。Around(webLog()) public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable { String traceId UUID.randomUUID().toString().replace(-, ).substring(0, 16); MDC.put(traceId, traceId); // ... 其他逻辑 try { return joinPoint.proceed(); } finally { // 拿到完整日志后移除traceId MDC.remove(traceId); } }同时在logback.xml里加一个输出项pattern%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} [%X{traceId}] - %msg%n/pattern注意一个坑MDC的值要在线程池场景下特别小心。如果你在切面里把traceId放进MDC但后续这个请求把任务丢给了线程池处理新线程的MDC是空的traceId就会丢失。如果需要跨线程传递要么用CombinedOutput配合装饰器要么干脆引入SkyWalking这类全链路组件后者对团队实施成本更高但结果也更可靠。3.3 异步记日志别让日志拖慢接口切面里的objectMapper.writeValueAsString在数据量大的时候其实是有开销的一次序列化大对象可能耗时几十毫秒。最坏的情况下1000个并发请求同时在日志线程里做序列化和IO接口RT直接上涨。我的处理方案是日志打印的入参出参内容控制在合理范围内并且把日志落盘交给异步线程。最简单的异步化方式是用Spring的Async但注意要自己定义一个线程池避免所有异步任务公用一个默认池Configuration public class AsyncConfig { Bean(logAsyncExecutor) public Executor logAsyncExecutor() { ThreadPoolTaskExecutor executor new ThreadPoolTaskExecutor(); executor.setCorePoolSize(2); executor.setMaxPoolSize(4); executor.setQueueCapacity(1000); executor.setThreadNamePrefix(log-async-); executor.setRejectedExecutionHandler(new ThreadPoolExecutor.DiscardOldestPolicy()); executor.initialize(); return executor; } }然后在切面里把日志打印改成异步执行Async(logAsyncExecutor) public void saveLog(RequestLog logInfo) { // 省略序列化逻辑 log.info(web-request-log: {}, objectMapper.writeValueAsString(logInfo)); }注意异步不要无脑用。如果你在接口方法退出后就异步打印日志而返回结果里的对象是懒加载的ORM实体线程池里的序列化可能触发LazyInitializationException。所以异步记录的话最好只传一个独立的日志对象不要持有ORM实体引用。3.4 脱敏不能漏日志里的手机号身份证必须处理统一日志的另一个隐藏收益是集中脱敏。以前每个开发自己打日志的时候出现了手机号、身份证号、银行卡号基本都是明文出了安全事故才想起来去库删日志根本删不完。有了AOP切面之后可以在序列化之前对入参出参做脱敏处理。比如定义一个脱敏策略手机号保留前3后4中间用*代替身份证号保留前1后1中间全用*邮箱保留首字母和后面的域名其余用*实现方式可以通过自定义Jackson的Serializer更简单的做法是写一个工具类在把RequestLog转JSON之前对敏感字段做替换。不过说实话最省心的还是配合fastjson2的Sensitive注解方案或者直接引入类似Log4j2的lookup脱敏组件。但不管用哪种核心原则是日志里的敏感字段必须在切面这层就被处理掉不要指望业务代码自己注意。4. 生产环境踩坑记录切面失效、异常吞掉、接口响应变了4.1 同类调用导致的切面失效排查了一下午Spring AOP是基于代理实现的这意味着只有外部调用走代理类内部的this调用不会经过代理。我第一次踩到这个坑是在一个Controller里写了两个方法一个方法加了WebLog另一个方法在同类里直接调用了这个方法结果日志只打了一条。一开始我还以为是切点表达式写错了后来翻源码才知道this.method()调用的是原生对象的方法代理对象根本拦不到。解决办法有几个按推荐程度排序把需要被切面拦截的方法放到不同的Bean里通过注入另一个Bean调用。自己注入自己即Autowired private OrderController self;然后调用self.queryOrder()。使用AopContext.currentProxy()获取当前代理对象。最优雅的还是第一种不要把切面拦截的方法和内部调用方法放在同一个类里。这类问题在Spring事务注解Transactional上也常见其实本质是同一个坑。4.2 Around里方法返回类型不一致的坑Spring AOP对方法返回类型是有校验的虽然切面可以返回任意Object但代理方法桥接的时候会检查类型一致性。如果你的Controller方法返回类型是Result而切面在异常分支里返回了一个null某些情况下会触发类型转换异常。我建议所有切面都遵循一个铁律正常或异常情况都不要改变原始方法的返回值和抛出的异常。切面只负责记录业务方法返回什么就原样返回什么该抛什么错就抛什么错。一旦在切面里尝试修复返回结果或把异常转换成另一个异常后面排查问题的难度会翻倍。4.3 序列化超大响应对象导致OOM风险有一次线上告警发现接口的堆内存频繁波动排查之后发现是切面日志造成的。原因是一个导出报表的接口方法返回值是一个几百万个对象的List我的切面在finally里把这个List整个做JSON序列化内存一下爆了。后来我把buildResult逻辑改成用result.toString()先看一眼对象的大概内容如果对象本身就是集合直接只记录集合大小记录结果时限制序列化深度只序列化第一层字段对于超过特定大小的方法直接用WebLog(ignoreResult true)注解控制我给自定义注解加了一些属性Target(ElementType.METHOD) Retention(RetentionPolicy.RUNTIME) public interface WebLog { // 是否记录入参 boolean logArgs() default true; // 是否记录返回结果 boolean logResult() default true; // 入参最大长度 int maxArgLength() default 500; // 是否排除某些参数名 String[] ignoreArgNames() default {}; }这样每个接口可以根据数据量大小调整日志策略切面代码也可以针对注解属性做动态判断。4.4 MultiValueMap和MultipartFile的处理如果接口有文件上传org.springframework.web.multipart.MultipartFile对象不能直接序列化必须取getOriginalFilename()和getSize()。HttpServletRequest和HttpServletResponse也是直接序列化会报错或产生无意义的内容。我在编写切面时把这些Web基础设施对象统一转换成了字符串描述不参与完整JSON序列化。4.5 双重代理问题如果你的项目同时有Spring AOP和CGLIB代理或者你在同一个类上加了多个自定义切面可能出现切面嵌套执行多次的情况。多个切面都命中同一个方法时执行顺序由Order注解控制数字越小越先执行。如果你发现日志打印了两遍先检查是不是同一个切面类被注册了多次或是有多个符合的切点表达式同时命中。5. AOP的边界它还能解决哪些同类问题5.1 接口耗时监控与慢请求告警日志切面顺手就能做的事情还有耗时统计。我已经在RequestLog里记了costMs那就可以再扩展一层当耗时超过某个阈值时输出一个告警级别的日志方便提前发现性能问题。if (logInfo.getCostMs() 1000) { log.warn(slow-request: {} {} cost {}ms, logInfo.getHttpMethod(), logInfo.getUrl(), logInfo.getCostMs()); }这个看似简单的逻辑价值很大。线上系统经常有最近一两周响应变慢但没人注意到的问题。有了慢请求日志每天看看规律基本能在用户投诉之前把问题定位到具体接口。5.2 统一鉴权与参数校验AOP也可以用来做接口鉴权和参数校验。核心思路是自定义一个RequirePermission注解在切面里根据当前用户的角色权限判断是否有权访问。和Spring Security的过滤器相比注解方式的粒度更细、更灵活也更容易在少数接口上做特殊处理。5.3 接口限流限流也是AOP很经典的场景。定义一个RateLimit注解在切面里基于Guava RateLimiter或Redis计数器实现限流逻辑。我用Redis做过一版简单限流核心逻辑是在切面里拼接出一个key当前用户ID 接口路径使用Redis的INCR和EXPIRE命令实现时间窗口内的计数超过阈值直接抛异常。这样无需在业务代码里插入任何限流逻辑后期修改限流阈值也只需要改注解参数。5.4 重试机制与降级处理对某些不稳定的外部接口调用也可以用AOP做重试。自定义一个RetryOnFailure注解切面里捕获指定异常并执行最多N次重试每次重试之间间隔一定时间。不过要提醒的是重试要小心幂等性问题——不是所有接口都能盲目重试下单、转账这类接口如果没做幂等控制重试可能造成重复数据。5.5 数据权限与审计日志企业内部系统经常有谁在什么时间查了什么数据的审计需求。AOP可以轻松实现切面在业务方法执行前把当前用户、请求时间、访问的业务对象信息记录到独立的审计表里。这个场景下切面的价值不只是少写几行代码而是审计数据的完整性得到了保证——你不需要依赖开发人员记得在每个查询方法里手动写审计代码。最后再分享几个实际操作中的小建议做了这套AOP日志之后我自己在使用层面也有几条体会一是日志不是越多越好。如果每个接口都打印全量入参和全量出参日志量会非常大存储成本和检索效率都会变差。我现在的策略是正常流程只记录URL、类方法、耗时、异常信息这些轻量字段入参出参按需开启错误日志单独打完整堆栈。说白了日志设计的目标是出问题时能定位不是把所有的运行细节都留底。二是切面逻辑要保持极简。AOP切面是横切在业务方法之外的如果切面代码自身抛出异常会直接影响业务方法的执行。所以切面里任何可能出错的逻辑比如序列化、Redis操作都要try-catch保护确保切面出问题也最多只是日志丢了不能把接口搞挂。三是建议团队把AOP日志做成一个独立的starter或公共模块。如果你的公司有多个Java服务完全可以把这个切面抽取成一个公共包发布到私有仓库每个服务引入依赖在配置里指定需要扫描的包路径就能生效。这样日志格式、脱敏规则、traceId策略就全局统一了哪怕有十来个微服务也只需要维护一套代码。四是不要只盯着请求日志这一个落点。当你把AOP的思维建立起来之后你会发现在鉴权、限流、审计、重试、耗时监控这些方面都能快速落地。我现在的项目里AOP已经承担了七八种横切逻辑业务代码反而越来越干净排查问题的时候所有信息又都在日志里有据可查这是我觉得最值得投入的一套基础设施。