【系统日志笔记二】——撸起袖子写个自定义日志注解

背景

最近手头一个项目进入转测阶段，测试组长提出要求把所有http请求的入参以及相应的json报文详细输出到日志文件，为了方便测试组小伙伴对每一个接口的验证。虽说不是功能性的需求，但是这样的要求确实有道理，让我无法抗拒啊。

步骤详解

自定义注解

• Logc.java

import java.lang.annotation.Documented;
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

/**
 * <Description> 自定义日志记录注解<br>
 *
 * @author xubin<br>
 * @version 1.0<br>
 * @taskId <br>
 * @CreateDate 2019/4/12 <br>
 */

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
@Documented
public @interface Logc {

    /**
     * Description: <br>
     * 
     * @author xubin<br>
     * @taskId <br>
     * @return <br>
     */
    String value() default "";
}

使用AOP

• pom.xml 引入依赖

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-aop</artifactId>
    <exclusions>
         <exclusion>
              <groupId>ch.qos.logback</groupId>
              <artifactId>logback-classic</artifactId>
         </exclusion>
    </exclusions>
</dependency>

• MainLogAspect.java

import javax.servlet.http.HttpServletRequest;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.AfterThrowing;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

import lombok.extern.slf4j.Slf4j;

/**
 * <Description> 日志切面<br>
 *
 * @author xubin<br>
 * @version 1.0<br>
 * @taskId <br>
 * @CreateDate 2019/4/12 <br>
 */

@Aspect
@Slf4j
@Component
public class MainLogAspect {

    /**
     * Description: 自定义切点<br>
     * 
     * @author xubin <br>
     * @taskId <br>
     */
    @Pointcut("@annotation(com.minicore.salmon.aop.Logc)")
    public void pointCut() {
    }

    /**
     * Description: 前置通知-记录请求信息<br>
     * 
     * @author xubin <br>
     * @taskId <br>
     * @param joinPoint <br>
     */
    @Before("pointCut()")
    public void doBeforeAdvice(JoinPoint joinPoint) {
        Signature signature = joinPoint.getSignature();
        ServletRequestAttributes sra = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = sra.getRequest();
        // 获取目标方法的参数信息
        Object[] obj = joinPoint.getArgs();
        log.info("[MainLogAspect]-request url:{}, class: {}, method: {}, param: {}", request.getRequestURI(), signature
                .getDeclaringTypeName(), signature.getName(), obj[0].toString());

    }

    /**
     * Description: 后置通知-记录返回信息<br>
     * 
     * @author xubin <br>
     * @taskId <br>
     * @param joinPoint <br>
     * @param result <br>
     */
    @AfterReturning(returning = "result", pointcut = "pointCut()")
    public void doAfterReturningAdvice(JoinPoint joinPoint, Object result) {
        Signature signature = joinPoint.getSignature();
        ServletRequestAttributes sra = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = sra.getRequest();
        log.info("[MainLogAspect]-response url:{}, class: {}, method: {}, param: {}", request.getRequestURI(), signature
                .getDeclaringTypeName(), signature.getName(), result.toString());
    }

    /**
     * Description: 后置异常通知-记录返回出现异常<br>
     * 
     * @author xubin <br>
     * @taskId <br>
     * @param joinPoint <br>
     * @param exception <br>
     */
    @AfterThrowing(value = "pointCut()", throwing = "exception")
    public void doAfterThrowingAdvice(JoinPoint joinPoint, Throwable exception) {
        Signature signature = joinPoint.getSignature();
        ServletRequestAttributes sra = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = sra.getRequest();
        log.info("[MainLogAspect]-response exception url:{}, class: {}, method: {}", request.getRequestURI(), signature
                .getDeclaringTypeName(), signature.getName());
    }
}

使用示例

• 在web层需要输出日志的方法上加上注解@Logc

   /**
     * Description: 分页查询设备列表-无层级<br>
     * 
     * @author xubin<br>
     * @taskId <br>
     * @param queryDeviceParamReq 查询条件
     * @param request HttpServletRequest
     * @return <br>
     */
    @Logc
    @PostMapping(value = "/queryDeviceListByPage")
    public String queryDeviceListByPage(@RequestBody QueryDeviceInfoReq queryDeviceParamReq, HttpServletRequest request) {
        try {
            ValidateUtil.validate(queryDeviceParamReq);
        } catch (Exception e) {
            log.error("[DeviceApi]-queryDeviceList fail, param : {}, exception : {}", queryDeviceParamReq.toString(), e.getMessage());
            return JsonUtil.getErrorJson(WebConstant.PARAM_EXCEPTION);
        }
        DeviceInfoBO deviceInfoBO = new DeviceInfoBO();
        BeanUtils.copyProperties(queryDeviceParamReq, deviceInfoBO);
        deviceInfoBO.setAppKey(request.getHeader(CommonConstant.APP_KEY));
        PageInfo<DeviceInfoBO> page = deviceInfoService.queryDeviceListByPage(deviceInfoBO,
                Optional.ofNullable(queryDeviceParamReq.getPageNum()).orElse(CommonConstant.DEFAULT_PAGE_NUM),
                Optional.ofNullable(queryDeviceParamReq.getPageSize()).orElse(CommonConstant.DEFAULT_PAGE_SIZE));
        return JsonUtil.getSucc4data(Optional.ofNullable(page).orElse(new PageInfo<DeviceInfoBO>()));
    }

• 日志输出

2019-05-29 14:40:52.223 INFO  http-nio-55001-exec-5 [com.minicore.salmon.aop.MainLogAspect:56]-[MainLogAspect]-request url:/salmon_device/deviceInfoApi/queryDeviceListByPage, class: com.minicore.salmon.rest.api.DeviceApi, method: queryDeviceListByPage, param: QueryDeviceInfoReq(pageNum=1, pageSize=20, deviceName=null, deviceCode=1559068230635, deviceType=null, deviceState=null, deviceMac=null, isOnline=null, isActivated=null)
2019-05-29 14:40:52.263 DEBUG http-nio-55001-exec-5 [com.minicore.salmon.mapper.DeviceInfoEntityMapper.queryDeviceInfoList_COUNT:159]-==>  Preparing: SELECT count(0) FROM t_device_info d LEFT JOIN t_device_state ds ON d.device_state = ds.id LEFT JOIN t_device_type dt ON d.device_type = dt.id WHERE d.is_delete = 0 AND d.device_code = ? 
2019-05-29 14:40:52.264 DEBUG http-nio-55001-exec-5 [com.minicore.salmon.mapper.DeviceInfoEntityMapper.queryDeviceInfoList_COUNT:159]-==> Parameters: 1559068230635(String)
2019-05-29 14:40:52.265 DEBUG http-nio-55001-exec-5 [com.minicore.salmon.mapper.DeviceInfoEntityMapper.queryDeviceInfoList_COUNT:159]-<==      Total: 1
2019-05-29 14:40:52.266 DEBUG http-nio-55001-exec-5 [com.minicore.salmon.mapper.DeviceInfoEntityMapper.queryDeviceInfoList:159]-==>  Preparing: SELECT d.id, d.app_key, d.device_name, d.device_code, d.device_desc, d.device_type, dt.type_name AS device_type_name, dt.type_code AS device_type_code, d.is_online, d.is_online_upd_time, d.is_activated, d.activate_time, d.device_state, d.version, ds.state_name AS device_state_name, ds.state_code AS device_state_code, d.device_ipv4, d.device_mac, d.p_id, d.is_delete, d.create_time, d.creator, d.creator_id, d.update_time, d.modifier, d.modifier_id FROM t_device_info d LEFT JOIN t_device_state ds ON d.device_state = ds.id LEFT JOIN t_device_type dt ON d.device_type = dt.id WHERE d.is_delete = 0 AND d.device_code = ? ORDER BY d.create_time DESC LIMIT 20 
2019-05-29 14:40:52.267 DEBUG http-nio-55001-exec-5 [com.minicore.salmon.mapper.DeviceInfoEntityMapper.queryDeviceInfoList:159]-==> Parameters: 1559068230635(String)
2019-05-29 14:40:52.270 DEBUG http-nio-55001-exec-5 [com.minicore.salmon.mapper.DeviceInfoEntityMapper.queryDeviceInfoList:159]-<==      Total: 1
2019-05-29 14:40:52.272 INFO  http-nio-55001-exec-5 [com.minicore.salmon.aop.MainLogAspect:74]-[MainLogAspect]-response url:/salmon_device/deviceInfoApi/queryDeviceListByPage, class: com.minicore.salmon.rest.api.DeviceApi, method: queryDeviceListByPage, param: {"resCode":1,"resData":{"pageNum":1,"pageSize":20,"rows":[{"activateTime":null,"appKey":"7bbf10d0bdca560edb30dabb1254964d","createTime":"2019-05-29 02:30:31","creator":"","creatorId":"","deviceCode":"1559068230635","deviceDesc":"","deviceIpv4":"","deviceMac":"","deviceName":"1559068230635","deviceState":"","deviceStateCode":"","deviceStateName":"","deviceType":"6188028fb7f24f90a91e4c6ccd06798f","deviceTypeCode":"box","deviceTypeName":"anfang-pad","id":"0e26a36fd614467d8c3d7c8e9e99402b","isActivated":"1","isDelete":"0","isOnline":"1","isOnlineUpdTime":1559068230676,"modifier":"","modifierId":"","pId":"-1","subDeviceList":[],"updateTime":"2019-05-29 02:30:30","version":""}],"total":1},"resMsg":[]}

上面的日志会输出控制台，如何输出到指定的日志文件，可以参考另一篇log4j2配置示例【系统日志笔记一】——丰富Log4j2配置

总结

     aop的灵活应用确实可以为我们省下很多重复性的工作，注解的使用让代码更加规范、简洁，这种代码动手撸一把真的可以让自己很放松???