给一个老系统加日志最让人头疼的往往不是“加”这个动作而是“不能改”。我之前在某个维护中的项目里遇到过这么个需求核心业务模块的每个方法都得有操作日志包括入参、返回值、耗时、异常信息但项目当时的现状是Service层代码已经迭代了三年多谁也不敢为了加日志去大面积改动业务源码一怕改出回归二怕上线窗口不够用。那时候动态代理就成了最合适的选择我花了一个下午把日志拦截器写好通过代理工厂统一替换服务对象业务代码一行都没动后续所有核心方法自动带上了完整日志。这篇文章会把我用Java动态代理实现日志记录的完整思路、核心代码、踩过的坑和方案选型过程一次说清楚。不堆概念全部是能在真实项目里直接落地的做法。适合正在给老项目做可观测性改造、或者想彻底搞懂动态代理原理的开发者。1. 动态代理原理入门为什么它能不动业务代码就加日志1.1 从手动打日志到静态代理常规方案的三层困境先聊聊最直觉的方案——在业务方法里手动加日志。项目初期代码量小每个方法加几行logger.info没毛病但一旦业务膨胀到几百个方法这条路就走不通了。第一是侵入性太强日志代码和业务代码完全搅在一起你想看一段业务逻辑满屏都是log输出阅读成本急剧上升。第二是容易遗漏人不是机器写新方法的时候可能顺手写了日志改老方法的时候大概率忘了。第三是回归风险改代码就意味着重新测试、重新发布对老系统来说每一次改动都像在雷区里走路。后来有人想到用静态代理模式解决。给每个业务实现类配一个对应的代理类由代理去调真实对象在代理里加日志。这个思路的逻辑是对的把日志关注点和业务关注点拆开了。但它的问题也同样明显——类数量爆炸。每个接口都得多维护一个代理类里面全是重复模板代码而且接口一旦加新方法代理类也得同步改。维护代理类的成本很快会超过维护日志本身。这两条常规路径都不顺于是大家的注意力自然转向了运行时动态生成代理对象也就是动态代理。它能在不写死代理类的情况下在运行时给任意接口生成一个代理实例所有方法调用都会被统一的拦截器接管。日志逻辑只要写在拦截器里一份所有被代理的方法就都能复用。1.2 JDK动态代理的两个核心角色Proxy和InvocationHandlerJDK动态代理的核心机制是运行时生成字节码不需要编译期手写代理类。它只围绕两个关键角色工作。一个是InvocationHandler一个接口里面只有一个invoke方法。代理对象上任何方法的调用最终都会转发到这个invoke方法里。invoke方法能拿到三个关键参数proxy代理对象本身、method被调用的Method对象、args实际参数列表。有了这三样你可以在目标方法执行前后做几乎任何事情——记录入参、统计耗时、捕获异常、修改返回值。另一个是ProxyJDK提供的工具类通过newProxyInstance静态方法为指定接口动态生成代理对象。这个方法接收三个参数类加载器ClassLoader、接口数组interfaces、InvocationHandler实现。生成的代理对象实现了传入的全部接口但接口方法内部的逻辑统一转发给InvocationHandler处理。打个生活化的比方真实对象是公司老板代理对象是前台。外面的人找老板办事必须先经过前台登记。前台知道谁来了、办了什么事、办了多久甚至能决定放不放行。老板完全感知不到前台的存在业务代码本身没有被改动。注意JDK动态代理有个硬性限制——只能代理接口。如果目标对象没有实现任何接口或者你想代理的是某个具体类JDK动态代理会直接抛异常。这个限制对方案选型影响很大下一节细说。2. 动态代理方案选型JDK动态代理、CGLIB与字节码增强怎么选2.1 JDK动态代理的限制决定你的技术路线JDK动态代理用起来轻量不引入额外的依赖JDK自带就能搞定。但前面说了它只支持接口代理。真实项目里总会有一些不那么“标准”的代码——第三方库返回的是具体类老代码压根没抽象出接口或者某些内部工具类直接用类来承载业务能力。遇到这些情况硬用JDK动态代理就会很尴尬。我见过不少人为了适配JDK动态代理去给具体类硬抽接口然后改所有引用处。这个动作在数据量大的老代码里非常危险因为改了类型关系牵一发动全身。更合理的做法是入口处保留具体类换用支持类代理的方案。这时候CGLIB就登场了。2.2 CGLIB基于继承的代理机制CGLIB的核心原理是生成目标类的子类通过重写父类方法来实现拦截。它底层用ASM字节码框架在运行时动态生成子类字节码再通过MethodInterceptor回调来接管被重写方法的逻辑。一个最简单的CGLIB代理例子Enhancer enhancer new Enhancer(); enhancer.setSuperclass(UserServiceImpl.class); enhancer.setCallback((MethodInterceptor) (obj, method, args, proxy) - { long start System.nanoTime(); try { Object result proxy.invokeSuper(obj, args); long costMs TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start); System.out.println(方法耗时: costMs ms); return result; } catch (Throwable e) { System.out.println(方法异常: e.getMessage()); throw e; } }); UserServiceImpl proxyService (UserServiceImpl) enhancer.create();这段代码里enhancer.setSuperclass指定父类enhancer.setCallback设置拦截回调proxy.invokeSuper负责调用父类的真实方法。看起来很简单但CGLIB的边界条件比JDK动态代理更严格目标类不能是final否则没法生成子类目标方法不能是final或static否则没法重写目标方法不能是private否则子类不可见如果目标类是接口或者抽象类也受各自限制CGLIB在Spring早期的版本里作为默认的动态代理实现因为当时很多Service并没有严格遵循接口设计。后来Spring才调整策略判断目标对象有接口就默认走JDK动态代理没有接口才走CGLIB。2.3 选型对照表与建议我根据自己的项目经验把几个常见方案整理成对照表方案代理机制能力范围依赖适用场景JDK动态代理接口 Proxy类仅接口方法JDK自带面向接口设计的Service层、Controller代理CGLIB继承 子类重写非final类的非private方法cglib依赖无接口的具体类、Spring AOP默认字节码增强JavaAgent修改类字节码几乎全部类和方法ASM / ByteBuddy全链路监控、框架级打点、无侵入埋点我的建议很简单优先用JDK动态代理但前提是项目里的核心业务对象都面向接口。如果代码里有大量没有接口的具体类或者你正在接入Spring容器这种会自动决策的框架那就直接选CGLIB路线。至于字节码增强除非是要做全链路监控或者给第三方jar包里的类埋点否则日常业务日志用不上杀鸡不用牛刀。3. 实操手写一个可落地的动态代理日志记录器3.1 场景定义与需求拆解假设项目里有一个UserService接口包含几个典型的用户操作public interface UserService { User getUserById(Long userId); boolean updateUserName(Long userId, String name); ListUser batchQueryUsers(ListLong userIds); }我的日志需求有三条每个方法调用都自动记录入参和返回值方法执行耗时必须体现在日志里方法抛异常时要有完整异常堆栈。同时业务代码本身不允许改动调用方只需要持有代理对象。这三个需求正好是动态代理的强项入参和返回值可以在invoke方法里拿到耗时用System.nanoTime统计异常在catch块里完整记录后重新抛出。3.2 核心实现LogInvocationHandler先写最核心的InvocationHandlerpublic class LogInvocationHandler implements InvocationHandler { private static final Logger log LoggerFactory.getLogger(LogInvocationHandler.class); private final Object target; private final String serviceTag; private final ThreadLocalInteger depthHolder new ThreadLocal(); public LogInvocationHandler(Object target, String serviceTag) { this.target target; this.serviceTag serviceTag; } Override public Object invoke(Object proxy, Method method, Object[] args) throws Throwable { // Object类的方法直接放行不记录日志 if (method.getDeclaringClass() Object.class) { return method.invoke(target, args); } // 防止递归日志刷屏 int depth getDepth(); if (depth 2) { return method.invoke(target, args); } depthHolder.set(depth 1); long start System.nanoTime(); String traceId UUID.randomUUID().toString().substring(0, 8); try { log.info([{}][{}] enter method{}, args{}, serviceTag, traceId, method.getName(), toJson(args)); Object result method.invoke(target, args); long costMs TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start); log.info([{}][{}] exit method{}, result{}, cost{}ms, serviceTag, traceId, method.getName(), toJson(result), costMs); return result; } catch (Throwable e) { long costMs TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start); log.error([{}][{}] error method{}, cost{}ms, serviceTag, traceId, method.getName(), costMs, unwrap(e)); throw unwrap(e); } finally { depthHolder.remove(); } } private Throwable unwrap(Throwable e) { // method.invoke会把业务异常包在InvocationTargetException里需要解开 if (e instanceof java.lang.reflect.InvocationTargetException) { Throwable cause e.getCause(); return cause ! null ? cause : e; } return e; } private int getDepth() { Integer depth depthHolder.get(); return depth null ? 0 : depth; } }几个重要设计点解释一下。第一method.getDeclaringClass() Object.class的判断是必需的因为toString、hashCode、equals这些Object方法也会被拦截如果不放行打印日志时调用代理对象的toString会再次进入invoke形成死循环。第二depthHolder用来防止代理方法内部递归触发重复日志这在方法互相调用的服务里很关键后面第五部分会细讲。第三异常日志必须打完整堆栈log.error的最后一个参数传异常对象这样日志文件里能保留完整栈信息排查问题才能定位到具体行号。3.3 代理工厂与集成方式有了Handler还不够还要一个统一的代理工厂避免业务代码每次都去手动拼Proxy.newProxyInstancepublic final class LogProxyFactory { private LogProxyFactory() {} public static T T wrap(ClassT interfaceType, T target) { return wrap(interfaceType, target, SERVICE); } public static T T wrap(ClassT interfaceType, T target, String serviceTag) { if (interfaceType null || !interfaceType.isInterface()) { throw new IllegalArgumentException(interfaceType必须是接口); } if (target null) { throw new IllegalArgumentException(target不能为null); } LogInvocationHandler handler new LogInvocationHandler(target, serviceTag); return (T) Proxy.newProxyInstance( target.getClass().getClassLoader(), new Class?[]{interfaceType}, handler); } }使用的时候只需要在创建服务对象的地方做一次替换UserService realService new UserServiceImpl(); UserService userService LogProxyFactory.wrap(UserService.class, realService, USER-SERVICE);之后所有注入到Controller或者别的Service里的userService引用全部换成代理对象。原有调用代码不需要任何改动。这是动态代理最吸引人的地方日志逻辑在代理工厂里集中维护业务代码完全不感知。在Spring项目里更常见的做法是将代理对象的创建放在Bean初始化阶段通过BeanPostProcessor或者FactoryBean来实现这样整个容器内部自动替换业务代码连创建对象的代码都不用改。不过那是另一个话题了手写的方案在理解原理上更直观。4. 动态代理日志记录的4个关键细节参数序列化、耗时、异常与递归4.1 参数序列化别直接调toString给日志系统写序列化方法时最容易踩的坑就是直接调args.toString()。有些对象没重写toString打出来是com.example.model.User1a2b3c这种毫无价值的信息。更危险的是某些实体的toString方法里会触发懒加载查询或者在toString里引用了其他复杂对象调用它可能直接抛异常。我习惯的做法是优先用JSON序列化失败再降级private String toJson(Object obj) { if (obj null) { return null; } if (obj.getClass().isArray()) { return Arrays.deepToString((Object[]) obj); } if (obj instanceof Collection || obj instanceof Map) { try { return ObjectMapperHolder.get().writeValueAsString(obj); } catch (Exception e) { return String.valueOf(obj); } } try { return ObjectMapperHolder.get().writeValueAsString(obj); } catch (Exception e) { return String.valueOf(obj); } }在使用JSON序列化时还需要考虑循环引用问题。比如两个实体互相持有对方引用直接序列化会抛异常需要在ObjectMapper里配置深度限制或者在序列化时忽略掉某些字段。我的做法是在序列化之前判断一下对象类型如果已经出现在当前序列化链路上就不再展开。4.2 耗时统计用System.nanoTime而不是currentTimeMillis日志记录中耗时统计必不可少。但不少初学者会用System.currentTimeMillis()来算耗时这个API返回的是JVM当前墙钟时间它的值会受到系统时间调整、NTP时间同步等因素影响。如果线上服务器做了时钟同步你可能会看到方法耗时出现负数这种诡异现象。正确选择是System.nanoTime()。它返回的是JVM内部单调时钟的值专门用来测量时间间隔不受墙钟时间调整影响。用nanoTime计算耗时的标准写法long start System.nanoTime(); // 执行目标方法 long costMs TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start);在日志输出时建议统一转成毫秒不然纳秒级别的数字可读性太差排查问题的时候一眼看过去全是十几位数字没有任何意义。4.3 异常日志捕获之后必须重新抛出代理里处理异常时最容易犯的错误是catch住异常记录完日志就return了不再继续抛出。这个错误后果极其严重——业务代码可能根据异常做回滚、补偿或者返回错误提示而你吞掉异常等于告诉调用方“方法正常执行完”会导致事务不回滚、数据不一致、接口返回错误结果线上出问题都找不到原因。正确写法我在前面的Handler代码里已经展示catch住异常记录完整堆栈然后throw unwrap(e)重新抛出。还有一个细节method.invoke(target, args)底层的实现会把业务方法抛出的异常包一层InvocationTargetException直接打印e.getMessage()往往得不到真正有用的业务异常信息。所以我在Handler里单独写了unwrap方法把InvocationTargetException拆开取真正的业务异常再打印和抛出。4.4 防止日志递归刷屏动态代理日志最隐蔽的坑就是递归。假如被代理的方法内部又调用了另一个同样被代理的方法而代理Handler内部记录日志时又触发了对代理对象的方法调用就可能在日志系统里形成无限递归。我遇到过一种场景业务方法里调了另一个服务方法而第一个方法的返回值里包含另一个服务的对象日志序列化这个返回值的时候序列化器尝试访问对象属性的getter而getter内部又调用了代理方法日志直接刷到OutOfMemoryError。解决思路有三个。一是在Handler里用ThreadLocal记录递归深度超过设定阈值就不再记录这个方案最简单可靠我在上面代码里已经实现了。二是日志记录代码里坚决不调用任何可能经过代理的方法。三是序列化对象时配置忽略某些属性或限制深度。建议第一和第三个结合使用双保险。5. 动态代理日志记录常见问题排查实录5.1 代理不生效final类、final方法导致的静默失败用CGLIB时如果目标类是final的Enhancer会在运行时抛异常这个错误还算明显。但如果目标类不是final、只是某个方法被final修饰CGLIB不会报错而是直接让代理对该方法的拦截不生效。问题就来了日志时有时无排查半天发现是final方法绕过了拦截。我的排查建议是上线前写一个最小化验证用例把核心方法全部打一遍检查哪些方法没有日志输出。如果有遗漏去确认方法是不是final、private或者static。5.2 ClassCastException代理对象不能强转成实现类JDK动态代理生成的代理类和业务实现类是兄弟关系它们都实现了同一个接口但代理类不是业务实现类的子类。如果你在代码里写了这样的强转UserServiceImpl impl (UserServiceImpl) LogProxyFactory.wrap(UserService.class, realService);运行时会直接抛ClassCastException。这个问题的根源在于对代理对象类型边界的理解有偏差。代理对象的类型是Proxy与接口的交集不是目标实现类本身。我在项目里曾经因为这个问题排查了一整晚后来把所有引用处从实现类改成接口类型问题立刻消失。5.3 日志重复重复代理导致的重复记录如果一个已经包了代理的服务对象又被包了一层代理日志就会出现双份。我在某个聚合服务里遇到过这种场景服务A被外层代理包装后注入到服务B服务B又被代理包装后注入到上层最终一个方法调用打出了四份日志。解决办法是在代理工厂里做防重复包装可以记录当前对象是否已经是代理对象如果是就直接返回不再二次包装。更稳妥的方案是在项目启动时统一完成代理创建之后所有注入都使用代理对象避免在不同代码层反复包装。5.4 类内部自调用绕过代理动态代理有个著名的边界问题如果类内部的某个方法通过this去调用另一个方法这个内部调用不会经过代理。因为代理对象只是给外部调用方使用的内部this调用的目标仍然是原始对象不是代理对象。这意味着如果你用动态代理给Service加事务或日志A方法调用本类的B方法时B方法的日志不会记录、事务注解不会生效。我之前给老项目做日志改造时就踩过这个坑排查了很久最后定位到是因为自调用绕过了代理。有两个解决方案。一是把内部自调用改成注入代理对象通过代理对象去调B方法。二是把需要代理的方法拆分到独立对象里通过组合代替继承避免自调用。第一种方案改动小但要注意注入的必须是代理对象否则还是白搭。6. 从手写动态代理到生产级方案Spring AOP与MDC6.1 动态代理与Spring AOP的关系Spring AOP底层就是动态代理规则是默认优先使用JDK动态代理目标对象没有接口时自动切换CGLIB。理解了前面这些内容再去看Spring AOP的Around、Before、After注解会发现它们本质上都是包在不同InvocationHandler里的拦截逻辑Spring只是把创建代理的过程封装成了声明式API。如果项目里已经在用Spring框架我不建议还去手写代理工厂。直接用Spring AOP更合适声明一个切面业务代码零侵入。操作步骤很简单定义一个Aspect类用Around定义环绕通知在方法执行前后记录日志。Aspect Component public class LogAspect { private static final Logger log LoggerFactory.getLogger(LogAspect.class); Around(execution(* com.example.service..*.*(..))) public Object logAround(ProceedingJoinPoint joinPoint) throws Throwable { long start System.nanoTime(); try { Object result joinPoint.proceed(); log.info(method{}, args{}, result{}, cost{}ms, joinPoint.getSignature().getName(), Arrays.toString(joinPoint.getArgs()), result, TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start)); return result; } catch (Throwable e) { log.error(method{} error, joinPoint.getSignature().getName(), e); throw e; } } }6.2 生产级日志落地建议MDC串联请求链路手写动态代理得到的每一条日志是独立的前后没有关联。在真实的分布式系统里需要把同一次用户请求经过的所有方法串联起来这时候单靠动态代理就不够了还得引入MDCMapped Diagnostic Context机制。方案是在请求入口生成一个traceId放进SLF4J的MDC上下文里日志pattern里配置%X{traceId}这样所有日志输出都会自动带上这个traceId。动态代理Handler里只需要在invoke时读取MDC里的traceId就能把链路信息带进日志。这个方法不需要对业务代码做改造和动态代理天然搭配。在生产环境落地时我会把三个层次组合使用请求入口用Filter生成traceId写入MDCService层用动态代理或Spring AOP统一记录参数与耗时异常统一由全局异常处理器捕获并记录。这三层各司其职日志可读性会大幅提升。最后再给一个建议日志内容也要注意安全边界。动态代理会把方法入参和返回值全部打出来如果参数里包含手机号、身份证这类敏感字段日志文件本身就可能成为数据泄露的入口。生产环境要么在序列化时做字段脱敏要么在代理Handler里配置哪些方法不记录参数。我在项目里落地时特意在工厂类里加了一个方法名单列表对特殊方法只记录方法名和耗时不记录参数与返回值。这个细节平时没人注意等真出安全审计的时候能帮你省掉很多麻烦。