JAVA中用AOP打日志，偷个懒

日志记录

在写接口时，为了方便后续问题排查，需要记录接口的入参和出参(结果)。

常用的方法是使用slf4j的.info方法打日志。

如：

public class TestAopLogServiceImpl implements TestAopLogService {
 
    private static final Logger log = LoggerFactory.getLogger(TestAopLogServiceImpl.class);
 
    @Override
    public TestAopLogRespDTO testAopLog(TestAopLogReqDTO reqDTO) {
        // 记录入参
        log.info("methodName = {}, parameters = {}", "testAopLog", JSON.toJSONString(reqDTO));
        // 此处开始调用服务获取响应DTO
        // mock一个
        TestAopLogRespDTO respDTO = new TestAopLogRespDTO();
        respDTO.setRespCode(200);
        respDTO.setRespMsg("success");
        respDTO.setRespData("this is data");
        // 记录结果
        log.info("methodName = {}, result = {}", "testAopLog", JSON.toJSONString(respDTO));
        return respDTO;
    }
}

方法逻辑很清晰，包含记录入参，获取结果，记录结果，返回。

日志记录就不再展示了。

然而，每个接口都需要记录入参和结果，略微有点小麻烦。

于是，使用AOP搞定。

注：AOP可以搞定这个问题，本次试验不保证也不认为这是一个完美的方案，只能说是一种思路。

@Around("execution(* com.XXX.service.impl..*.*(..))")
public Object aopLog(ProceedingJoinPoint joinPoint) throws Throwable {
    // 反射调用方法所在类
    Class clz = joinPoint.getTarget().getClass();
    String methodName = joinPoint.getSignature().getName();
    Object[] paramValues = joinPoint.getArgs();
    log.info("className = {}, methodName = {}, parameters = {}", clz.getSimpleName(), methodName, JSON.toJSONString(paramValues));
    // 获取方法结果
    Object result = joinPoint.proceed();
    log.info("className = {}, methodName = {}, parameters = {}", clz.getSimpleName(), methodName, JSON.toJSONString(result));
    // 返回
    return result;
}

关于AOP的内容略过。

一顿操作猛如虎。该方法通过joinPoint获取对应的类，方法名，入参等，并调用其proceed方法计算出结果。

加入此AOP之后，service.impl下所有包下的所有类的所有方法都会被代理。
接口的代码量减少。

public TestAopLogRespDTO testAopLog(TestAopLogReqDTO reqDTO) {
    // 此处开始调用服务获取响应DTO
    // mock一个
    TestAopLogRespDTO respDTO = new TestAopLogRespDTO();
    respDTO.setRespCode(200);
    respDTO.setRespMsg("success");
    respDTO.setRespData(((TestAopLogService) AopContext.currentProxy()).test());
    return respDTO;
}

然而，这样的操作会让之后的维护者以为是没打日志，存在重复加日志的可能性。

此外，并不是所有接口都需要打日志。有些QPS超高的接口，打了日志反而消耗存储。

如果在方法上加需要打日志的注解，既可以表示打了日志，也可以做到选择性打日志。

新建两个注解，对应需要记录入参和记录结果。

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
@Documented
public @interface AddParamLog {
}
  
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
@Documented
public @interface AddResultLog {
}

此时，AOP修改为：

@Around("execution(* com.XXX.service.impl..*.*(..))")
public Object aopLog(ProceedingJoinPoint joinPoint) throws Throwable {
    // 反射调用方法所在类
    Class clz = joinPoint.getTarget().getClass();
 
    // 反射出被拦截的方法,以判断是否包含注解
    String methodName = joinPoint.getSignature().getName();
    Class[] parameterTypes = ((MethodSignature) joinPoint.getSignature()).getMethod().getParameterTypes();
    Method method = clz.getMethod(methodName, parameterTypes);
    //
 
    if (method.getAnnotation(AddParamLog.class) != null) {
        // 获取当前方法入参,打日志用
        Object[] paramValues = joinPoint.getArgs();
        log.info("className = {}, methodName = {}, parameters = {}", clz.getSimpleName(), methodName, JSON.toJSONString(paramValues));
    }
    // 获取方法结果
    Object result = joinPoint.proceed();
    if (method.getAnnotation(AddResultLog.class) != null) {
        log.info("className = {}, methodName = {}, parameters = {}", clz.getSimpleName(), methodName, JSON.toJSONString(result));
    }
    // 返回
    return result;
}

该方法反射出对应方法，判断其是否包含注解，以决定是否需要记录日志。

此外，可以使用更简单的注解方式，直接在@Around注解中指定只有使用了AddParamLog注解的方法才会被代理。

@Around("@annotation(AddParamLog)")

也可在注解中增加属性，进一步扩展功能。如在AddParamLog注解中增加time属性，表示只在某时间段内才打日志。

用AOP打日志就基本搞定了。

---

疑问：
如果在接口中调用另一个会被代理的接口，两个接口的日志都会被记录么？

答案是否定的，因为AOP生成的是代理类，在代理类中调用test()或者this.test()方法，指向的都是原类，不会记录日志。
如下：

@AddParamLog
@Override
public TestAopLogRespDTO testAopLog(TestAopLogReqDTO reqDTO) {
    // 此处开始调用服务获取响应DTO
    // mock一个
    TestAopLogRespDTO respDTO = new TestAopLogRespDTO();
    respDTO.setRespCode(200);
    respDTO.setRespMsg("success");
    // 此处调用另一个理论上会被代理的接口
    respDTO.setRespData(test());
    return respDTO;
}
 
@AddParamLog
@Override
public String test() {
    return "ceshi";
}

testAopLog方法在调用test时候，test不会记录日志，而直接调用test方法时，会记录。

那么如何解决呢，有两个方法。主要操作是拿到代理的引用，再进行test方法调用。

方法一：
更新xml配置为

<aop:aspectj-autoproxy expose-proxy="true" />

更新调用方法为

((TestAopLogService) AopContext.currentProxy()).test()

方法二：
注入本身

public class TestAopLogServiceImpl implements TestAopLogService {
  
    @Autowirde
    private TestAopLogService self;
  
    @AddParamLog
    @Override
    public TestAopLogRespDTO testAopLog(TestAopLogReqDTO reqDTO) {
        // 此处开始调用服务获取响应DTO
        // mock一个
        TestAopLogRespDTO respDTO = new TestAopLogRespDTO();
        respDTO.setRespCode(200);
        respDTO.setRespMsg("success");
        // 此处调用另一个理论上会被代理的接口
        respDTO.setRespData(self.test());
        return respDTO;
    }
 
    @AddParamLog
    @Override
    public String test() {
        return "ceshi";
    }
}

当然，这两种操作都是不优雅的。

最棒的方法是避免在接口中调用另外接口的方法。

---

AOP注解的value配置参考，即切面Pointcut配置：
使用最频繁的是execution和@annotation。

举例：
任意公共方法的执行：
execution(public * *(..))
任何一个以“set”开始的方法的执行：
execution(* set*(..))
AccountService 接口的任意方法的执行：
execution(* com.xyz.service.AccountService.*(..))
定义在service包里的任意类的任意方法的执行：
execution(* com.xyz.service.*.*(..))
定义在service包和所有子包里的任意类的任意方法的执行：
execution(* com.xyz.service..*.*(..))
定义在pointcutexp包和所有子包里的JoinPointObjP2类的任意方法的执行：
execution(* com.test.spring.aop.pointcutexp..JoinPointObjP2.*(..))")

@annotation(org.springframework.transaction.annotation.Transactional)

此外切点表达式支持与或非运算，很强大。

---

参考：

• Spring AOP中pointcut expression表达式解析 http://blog.csdn.net/kkdelta/article/details/7441829
• AOP实现拦截对象以及获取切入目标方法和注解 http://blog.csdn.net/guan_shijie/article/details/52573189
• 在同一个类中调用另一个方法没有触发 Spring AOP 的问题 https://segmentfault.com/a/1190000008379179
• Spring AOP无法拦截内部方法调用 http://www.jianshu.com/p/6534945eb3b5