AOP拦截日志及统一日志处理

AOP日志打印

当调用外部接口或者接口被外部访问时，为了方便解决问题，加入了切面来拦截所有日志，因为使用StringBuilder可以来加快速度，(springmvc的Component注解默认是单例的，会有数据共享的问题。)，即使有相同的共享数据问题也不大。并且使用logback这种异步写日志的方式来处理。

logger.info("Hello {}", user.getName());

对于不知道要不要输出的日志，交给slf4j在真的需要输出时才去拼接的确能省节约成本。

但对于一定要输出的日志，直接自己用StringBuilder拼接更快。因为看看slf4j的实现，实际上就是不断的indexof("{}"), 不断的subString()，再不断的用StringBuilder拼起来而已，没有银弹。

AOP实现代码

@Aspect
@Component
@Order(2)
@Slf4j
public class LogAopConfig {
    private static final String POINT_CUT = "execution(* com.xxx.xxx.xxx.xxx..*.*(..))";
    private static final String SEPARATOR = System.getProperty("line.separator");

    @Pointcut(POINT_CUT)
    private void pointcut() {
    }


    @Before(value = "pointcut()")
    public void allBefore(JoinPoint joinPoint) {
        String className = joinPoint.getTarget().getClass().getSimpleName();
        String methodName = joinPoint.getSignature().getName();
        StringBuilder sb = new StringBuilder();
        //日志打印
        sb.append("所属类方法:" + className)
                .append("." + methodName)
                .append("输入参数params:");

        Object[] args = joinPoint.getArgs();
        Object[] arguments  = new Object[args.length];
        for (int i = 0; i < args.length; i++) {
            if (args[i] instanceof ServletRequest || args[i] instanceof ServletResponse || args[i] instanceof MultipartFile) {
                //ServletRequest不能序列化，从入参里排除，否则报异常：java.lang.IllegalStateException: It is illegal to call this method if the current request is not in asynchronous mode (i.e. isAsyncStarted() returns false)
                //ServletResponse不能序列化 从入参里排除，否则报异常：java.lang.IllegalStateException: getOutputStream() has already been called for this response
                continue;
            }
            arguments[i] = args[i];
        }
        if (arguments != null) {
            try {
                sb.append(JSONObject.toJSONString(arguments));
            } catch (Exception e) {
                sb.append(arguments.toString());
            }
        }
        log.info(sb.toString());
    }

    @AfterReturning(value = "pointcut()", returning = "returnObj")
    public void afterReturn(Object returnObj) {
        StringBuilder sb = new StringBuilder();
        sb.append(SEPARATOR);
        if (returnObj != null) {
            String result = JSONObject.toJSONString(returnObj);
            sb.append("返回参数params: " + result);
        }
        log.info(sb.toString());
    }


    @AfterThrowing(value = "pointcut()", throwing = "e")
    public void afterThrowing(Throwable e) {
        log.error(e.getMessage(), e);
    }

    @Around(value = "pointcut()")
    public Object allAround(ProceedingJoinPoint joinPoint) throws Throwable {
        String className = joinPoint.getTarget().getClass().getName();
        String methodName = joinPoint.getSignature().getName();
        Long begin = System.currentTimeMillis();
        StringBuilder sb = new StringBuilder();
        Object result = joinPoint.proceed();
        Long end = System.currentTimeMillis();
        sb.append(SEPARATOR)
                .append("所属类方法:" + className)
                .append("." + methodName)
                .append(SEPARATOR)
                .append("环绕通知: ")
                .append("执行时间: ").append(end - begin).append("ms");
        log.info(sb.toString());
        return result;
    }

}

统一异常处理

关于扫描范围

1. 如果启动类Applicaiton.java文件中没有@ComponentScan注解，则默认只扫码Application.java类同级目录及以下的包中的类。
2. 如果有@ComponentScan注解，则会增加@ComponentScan配置的包文件。如下，会增加扫描类，还可以排除某些类。

@EnableEncryptableProperties
@SpringBootApplication
@EnableTransactionManagement(proxyTargetClass = true)
@ComponentScans({
        @ComponentScan(value = "com.xxx.common", excludeFilters = 
            {@Filter(type = FilterType.REGEX, pattern = {"com.xxx.common.config.DruidConfig"})}),
        @ComponentScan("com.xxx.xxx.database"),
        @ComponentScan("com.xxx.xxx.cache")
})
@EnableDiscoveryClient
@EnableFeignClients

关于执行顺序

1. AOP先执行。
2. 统一日志处理后执行。
   如下，虽然全部是Controller的切面，但AOP会先执行这个切面方法，然后跳转到@RestControllerAdvice切面处理异常。

全局异常类：

@RestControllerAdvice
@Slf4j
public class GlobalExceptionHandler {

    /**
     * 基础异常
     */
    @ExceptionHandler(BaseException.class)
    public AjaxResult baseException(BaseException e) {
        return AjaxResult.error(e.getMessage());
    }

    /**
     * 业务异常
     */
    @ExceptionHandler(CustomException.class)
    public AjaxResult businessException(CustomException e) {
        if (StringUtils.isNull(e.getCode())) {
            return AjaxResult.error(e.getMessage());
        }
        return AjaxResult.error(e.getCode(), e.getMessage());
    }

    @ExceptionHandler(NoHandlerFoundException.class)
    public AjaxResult handlerNoFoundException(Exception e) {
        log.error(e.getMessage(), e);
        return AjaxResult.error(HttpStatus.NOT_FOUND, "路径不存在，请检查路径是否正确");
    }


    @ExceptionHandler(Exception.class)
    public AjaxResult handleException(Exception e) {
        log.error(e.getMessage(), e);
        return AjaxResult.error("系统内部错误");
    }

    /**
     * 自定义验证异常
     */
    @ExceptionHandler(BindException.class)
    public AjaxResult validatedBindException(BindException e) {
        log.error(e.getMessage(), e);
        String message = e.getAllErrors().get(0).getDefaultMessage();
        return AjaxResult.error(message);
    }

    /**
     * 自定义验证异常
     */
    @ExceptionHandler(MethodArgumentNotValidException.class)
    public Object validExceptionHandler(MethodArgumentNotValidException e) {
        log.error(e.getMessage(), e);
        String message = e.getBindingResult().getFieldError().getDefaultMessage();
        return AjaxResult.error(message);
    }

}

一个线上问题

今天客户反馈线上APP的界面出现了一大串SQL代码，我跟了下问题，发现是某个开发工程师自己做了切面，但是直接将e.getMessage()方法的内容反馈给了前端。导致出现了此问题。下面说下具体流程。

1. 客户反馈问题如下。

2. 查找执行的类。发现全局异常没有起作用，可能是没有抛异常，可能是全局异常没配置好。
（1）如果是全局异常没配置好，那修改代码，直接抛出异常测试。

try {
            proceed = point.proceed(point.getArgs());
        }catch(InterfaceServiceException ex){
            log.error("返回结果异常：【异常码：{}，异常信息：{}】", ex.getRespMesg(), ex.getRespCode(), ex);
            //proceed = new YmTransResponse(ex);
            throw new Exception(ex);
        }catch(ServiceException ex){
            log.error("返回结果异常：【异常信息：{}】", ex.getMessage(), ex);
            //proceed = new YmTransResponse(ex);
            throw new Exception(ex);
        }catch(Exception ex){
            log.error("返回结果异常：【异常信息：{}】", ex.getMessage(), ex);
            //proceed = new YmTransResponse(ex);
            throw new Exception(ex);
        }

将上面的代码全部抛出异常。将会在GlobalExceptionHandler 处理到。

@ResponseStatus(HttpStatus.OK)
    @ExceptionHandler(Exception.class)
    public Result globalException(final HttpServletRequest request, final Throwable e) {
        log.error("全局异常 => {}", e.getMessage(), e);
        return ResultGenerator.genInternalServerErrorResult(SYSTEM_ERROR);//注意这里不能用e.getMessage()，像上面的数据库超长，e.getMessage()就会很长。
    }

return ResultGenerator.genInternalServerErrorResult(SYSTEM_ERROR);//注意这里不能用e.getMessage()，像上面的数据库超长，e.getMessage()就会很长。

调用接口测试，返回如下。说明排除了这种可能性。

（2）如果是没有抛异常，那是为啥没有抛到全局异常处理类去处理呢？
重点还是回到AOP方法，代码如下。

    try {
            proceed = point.proceed(point.getArgs());
        }catch(InterfaceServiceException ex){
            log.error("返回结果异常：【异常码：{}，异常信息：{}】", ex.getRespMesg(), ex.getRespCode(), ex);
            proceed = new TransResponse(ex);
        }catch(ServiceException ex){
            log.error("返回结果异常：【异常信息：{}】", ex.getMessage(), ex);
            proceed = new TransResponse(ex);
        }catch(Exception ex){
            log.error("返回结果异常：【异常信息：{}】", ex.getMessage(), ex);
            proceed = new TransResponse(ex);
        }

上面的测试说明已经执行到了该方法，并且error日志也打印了。只能看下 proceed = new YmTransResponse(ex);这段代码。发现果然有问题。

public TransResponse(Exception ex){
        super();
        ResponseHeader header = new ResponseHeader();
        header.setRetCode(RetCode.SYSTEM_ERROR.getCode());
        header.setRetMsg(ex.getMessage() == null ? RetCode.SYSTEM_ERROR.getMsg() : ex.getMessage());
        header.setRetDateTime(DateUtils.getTime());
        header.setReqNo("");
        header.setSerialNo("");
        this.header = header;
        this.data = Collections.emptyMap();
    }

其实很明显了，问题就出现这个ex.getMessage()方法。

总结

1. 建议service层处理各种已知异常。可以参考我写的阿里巴巴编码相关的内容。
2. 建议controller层自己不写AOP处理。即减少一层AOP，AOP的实质是反射，太多的反射会导致程序执行效率低下。
3. 如果2中的controller不做切面，那将直接使用@RestControllerAdvice做统一切面处理。