使用Spring AOP实现对外接口的日志自动打印

一、引言

相信我们都有过这样的经历，在提供第三方对外接口时，为了防止推诿扯皮，我们会在自己接口被调用时日志打印一下第三方的调用参数，再在业务逻辑结束返回时再打印一下给第三方的返回参数，这样在后续遇到bug时，能用日志方便排（shuai）查（guo）。
如果老老实实的手动打印日志，我们的代码将会是这个样子

publish Response queryTask(RequestParam param) {
	// 打印第三方请求参数
	LOGGER.info("queryTask param:{}", JSON.toJSONString(param));
	
	// Response为执行查询业务后的结果
	Response rsp = null;
	
	// 打印返回给第三方的结果
	LOGGER.info("queryTask response:{}", JSON.toJSONString(rsp))
	return rsp;
}

每个接口都这样去写，又麻烦又怕自己忘记，如此机械化的简单行为，有没有什么办法能够让程序帮我们做这份工作？让我们的代码变得更加优雅呢？Spring的AOP是一个不错的思想。

二、使用AOP实现日志打印

1. 定义一个api注解，它所标注的方法均能够打印入参和返回

@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
public @interface ApiLog {

}

2. 定义我们的切面和切点

@Component
@Aspect
public class ApiLogAspect {
	// 切入点
    @Pointcut("@annotation(com.yangyungang.open.aspect.log.anno.ApiLog)")
    private void apiLogPointCut() {
    }

	// 环绕通知
    @Around("apiLogPointCut()")
    public Object around(ProceedingJoinPoint joinPoint) throws Throwable {
        MethodSignature signature = (MethodSignature) joinPoint.getSignature();

        // 类名
        String className = joinPoint.getTarget().getClass().getName();
        // 方法名
        String methodName = signature.getName();
        // 参数
        Object[] args = joinPoint.getArgs();

        StringBuffer requestInfo = new StringBuffer();
        requestInfo.append("the api method (")
                .append(className)
                .append(":")
                .append(methodName)
                .append(") called, request param: ");

        if (AdaptorCommonUtil.checkSafe(args)) {
            Arrays.stream(args).forEach(p -> requestInfo.append(JSON.toJSONString(p)).append(" "));
        }

		// 在方法执行前打印
        LOGGER.info(requestInfo.toString());
        // 执行方法
        Object result = joinPoint.proceed();
        // 在方法执行后打印
        LOGGER.info("the api ({}:{}) method return:{}", className, methodName, JSON.toJSONString(result));

        return result;
    }
}

ApiLogAspect这个类为一个切面，@Pointcut代表切入点，这里我的注解ApiLog就为切入点，@Around(“apiLogPointCut()”)代表在切入点附近进行环绕通知，也就是要执行我们前面说的日志打印，我们在方法执行前后都进行了拦截，进行日志打印，joinPoint.proceed()才真正执行我们的业务逻辑。
写好该切面后，我们要做的仅仅只是在api方法上加入注解就可以了

@ApiLog
publish Response queryTask(RequestParam param) {
	// Response为执行查询业务后的结果
	Response rsp = null;

	return rsp;
}

所达到的效果和“引言”中的代码块一致。

三、logback单独打印api调用信息

当我写好接口后，又发现api调用日志和我们的业务日志完全糅杂在了一起，即使将来排查，也难以进行区分，由于我们项目使用的是logback，可以让我们的api包（通常第三方api会单独写到一个包里）单独打印到一个日志文件中，这样日志不就很清爽了吗，只需要改一下logback的配置文件即可

<!-- api调用的日志单独打印 -->
    <logger name="com.yangyungang.open.aspect.log.aop.ApiLogAspect" level="INFO" additivity="false">
        <appender-ref ref="OPENAPI" />
        <appender-ref ref="STDOUT" />
    </logger>

<!-- api日志Appender -->
    <appender name="OPENAPI" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
        <File>${LOG_HOME}/${COMPONENT_ID}.${SEGMENT_ID}.openApi.debug.log</File>
        <rollingPolicy class="logback.rolling.log.gather.TimeBasedBackUpRollingPolicy">
            <FileNamePattern>${LOG_HOME}/${COMPONENT_ID}.${SEGMENT_ID}.openApi.debug.log.%i.zip</FileNamePattern>
            <MinIndex>1</MinIndex>
            <!--最多十个文件 -->
            <MaxIndex>${log.max.index}</MaxIndex>
        </rollingPolicy>
        <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <MaxFileSize>${log.openApi.max.size}</MaxFileSize>
        </triggeringPolicy>
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
            <charset>${log.charset}</charset>
        </encoder>
    </appender>