首页 > 编程入门 文章详情

走进Java接口测试之日志管理之AOP统一日志

编程入门 行业动态 更新时间:2024-10-07 14:26:51

走进Java接口测试之<a href=https://www.elefans.com/category/jswz/34/1770796.html style=日志管理之AOP统一日志"/>

走进Java接口测试之日志管理之AOP统一日志


文章目录

    • 一、引言
    • 二、什么是AOP？
    • 三、AOP基本概念
    • 四、代理机制
    • 五、切入点指示符介绍
    • 六、MDC requestUUID，一种多线程下日志管理实践方式
    • 七、统一日志记录
      • 1、加入Aop依赖
      • 2、自定义拦截器 logback requestUUID
      • 3、拦截器配置
      • 4、自定义日志注解
      • 5、日志切面
      • 6、配置启动
      • 7、控制层
    • 八、测试 logback
      • 1、测试统一拦截日志
      • 2、测试忽略拦截日志
    • 九、工程目录
    • 十、总结

一、引言

上一文中，介绍了目前接口测试框架中常见的 logback 日志框架的整合知识。在很多时候，我们在开发一个测试框架时，不管出于何种考虑，比如是审计要求，还是调试的角度，一般都会有个全局记录日志的模块功能。此模块一般上会记录每个对数据有进行变更的操作记录，若是在web测试平台上，还会记录请求的url,请求的IP,及当前的操作人，操作的方法说明等等。在很多时候，我们需要记录请求的参数信息时，通常是利用拦截器、过滤器或者AOP等来进行统一拦截。本文主要来说一说如何利用AOP实现统一的日志记录。

二、什么是AOP？

AOP全称：Aspect Oriented Programming。是一种面向切面编程的，利用预编译方式和运行期动态代理实现程序功能统一的一种技术。它也是Spring 很重要的一部分，和 IOC一样重要。利用AOP可以很好的对业务逻辑的各个部分进行隔离，从而使得业务逻辑各部分之间的耦合度降低，提高程序的可重用性，同时提高了开发的效率。

简单来说，就是 AOP 可以在既有的程序基础上，在无代码嵌入前提下完成对相关业务的处理，业务方可以只关注自身业务的逻辑，而无需关系一些和业务无关的事项，比如最常见的日志、事务、权限检验、性能统计、统一异常处理等等。

三、AOP基本概念

以下简单的说明下：

  • 切面（Aspect）：切面是一个关注点的模块化，这个关注点可能是横切多个对象；

  • 连接点（Join Point）：连接点是指在程序执行过程中某个特定的点，比如某方法调用的时候或者处理异常的时候；

  • 通知（Advice）：指在切面的某个特定的连接点上执行的动作。Spring切面可以应用5中通知：

  • 前置通知（Before）:在目标方法或者说连接点被调用前执行的通知；

  • 后置通知（After）：指在某个连接点完成后执行的通知；

  • 返回通知（After-returning）：指在某个连接点成功执行之后执行的通知；

  • 异常通知（After-throwing）：指在方法抛出异常后执行的通知；

  • 环绕通知（Around）：指包围一个连接点通知，在被通知的方法调用之前和之后执行自定义的方法。

  • 切点（Pointcut）：指匹配连接点的断言。通知与一个切入点表达式关联，并在满足这个切入的连接点上运行，例如：当执行某个特定的名称的方法。

  • 引入（Introduction）：引入也被称为内部类型声明，声明额外的方法或者某个类型的字段。

  • 目标对象（Target Object）：目标对象是被一个或者多个切面所通知的对象。

  • AOP代理（AOP Proxy）：AOP代理是指AOP框架创建的对对象，用来实现切面契约（包括通知方法等功能）

  • 织入（Wearving）：指把切面连接到其他应用出程序类型或者对象上，并创建一个被通知的对象。或者说形成代理对象的方法的过程。

以下这张图，对以上部分概念进行简单介绍：

四、代理机制

Spring 的 AOP 的动态代理实现机制有两种，分别是：JDK 动态代理和CGLib 动态代理。简单介绍下两种代理机制。

JDK动态代理
JDK 动态代理是面向接口的代理模式，如果被代理目标没有接口那么Spring也无能为力，Spring 通过 java 的反射机制生产被代理接口的新的匿名实现类，重写了其中AOP的增强方法。

CGLib动态代理
CGLib 是一个强大、高性能的 Code 生产类库，可以实现运行期动态扩展java类，Spring 在运行期间通过 CGlib 继承要被动态代理的类，重写父类的方法，实现AOP面向切面编程。

两者对比：

  • JDK动态代理是面向接口，在创建代理实现类时比CGLib要快，创建代理速度快。而且JDK动态代理只能对实现了接口的类生成代理，而不能针对类。
  • CGLib动态代理是通过字节码底层继承要代理类来实现（如果被代理类被final关键字所修饰，那么抱歉会失败），在创建代理这一块没有JDK动态代理快，但是运行速度比JDK动态代理要快。

至于相关原理，大家自行谷歌下~

五、切入点指示符介绍

为了能够灵活定义切入点位置，Spring AOP 提供了多种切入点指示符。以下简单的介绍下。

  • execution：匹配执行方法的连接点

    可以从上图中，看见切入点指示符 execution的 语法结构为：execution（modifiers-pattern? ret-type-pattern declaring-type-pattern? name-pattern（param-pattern） throws-pattern?）。这也是最常使用的一个指示符了。

  • within：用于匹配指定类型内的方法执行；

  • this：用于匹配当前AOP代理对象类型的执行方法；注意是AOP代理对象的类型匹配，这样就可能包括引入接口也类型匹配；

  • target：用于匹配当前目标对象类型的执行方法；注意是目标对象的类型匹配，这样就不包括引入接口也类型匹配；

  • args：用于匹配当前执行的方法传入的参数为指定类型的执行方法；

  • @within：用于匹配所以持有指定注解类型内的方法；

  • @target：用于匹配当前目标对象类型的执行方法，其中目标对象持有指定的注解；

  • @args：用于匹配当前执行的方法传入的参数持有指定注解的执行；

  • @annotation：用于匹配当前执行方法持有指定注解的方法；

  • bean：Spring AOP扩展的，AspectJ没有对于指示符，用于匹配特定名称的Bean对象的执行方法；

  • reference pointcut：表示引用其他命名切入点，只有@ApectJ风格支持，Schema风格不支持。

对于相关的语法和使用，大家可行谷歌搜索，这里就不多加阐述了。

六、MDC requestUUID，一种多线程下日志管理实践方式

MDC（Mapped Diagnostic Context，映射调试上下文）是 log4j 和 logback 提供的一种方便在多线程条件下记录日志的功能。某些应用程序采用多线程的方式来处理多个用户的请求。在一个用户的使用过程中，可能有多个不同的线程来进行处理。典型的例子是 Web 应用服务器。当用户访问某个页面时，应用服务器可能会创建一个新的线程来处理该请求，也可能从线程池中复用已有的线程。在一个用户的会话存续期间，可能有多个线程处理过该用户的请求。这使得比较难以区分不同用户所对应的日志。当需要追踪某个用户在系统中的相关日志记录时，就会变得很麻烦。

一种解决的办法是采用自定义的日志格式，把用户的信息采用某种方式编码在日志记录中。这种方式的问题在于要求在每个使用日志记录器的类中，都可以访问到用户相关的信息。这样才可能在记录日志时使用。这样的条件通常是比较难以满足的。MDC 的作用是解决这个问题。

MDC 可以看成是一个与当前线程绑定的哈希表，可以往其中添加键值对。MDC 中包含的内容可以被同一线程中执行的代码所访问。当前线程的子线程会继承其父线程中的 MDC 的内容。当需要记录日志时，只需要从 MDC 中获取所需的信息即可。MDC 的内容则由程序在适当的时候保存进去。对于一个 Web 应用来说，通常是在请求被处理的最开始保存这些数据。
　　
至于相关原理及具体使用，大家自行谷歌下~

七、统一日志记录

介绍完相关知识后，我们开始来使用 AOP 实现统一的日志记录功能。

1、加入Aop依赖

 <dependencies><dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter</artifactId></dependency><dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-aop</artifactId></dependency><dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-web</artifactId></dependency><dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-test</artifactId><scope>test</scope></dependency><dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-autoconfigure</artifactId></dependency><!--引入Json序列化库--><dependency><groupId>com.alibaba</groupId><artifactId>fastjson</artifactId><version>1.2.47</version></dependency><!--引入效率插件--><dependency><groupId>org.projectlombok</groupId><artifactId>lombok</artifactId><version>1.18.2</version></dependency>

2、自定义拦截器 logback requestUUID


/*** 描述: 自定义拦截器 logback requestUUID** @author zuozewei* @create 2018-12-30 12:15**/@Slf4j
public class ControllerInterceptor extends HandlerInterceptorAdapter {//在请求处理之前回调方法@Overridepublic boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {String requestUUID = MDC.get("requestUUID");if (requestUUID == null || "".equals(requestUUID)) {String uuid = UUID.randomUUID().toString();uuid = uuid.replaceAll("-", "").toUpperCase();MDC.put("requestUUID", uuid);log.info("ControllerInterceptor preHandle 在请求处理之前生成 logback requestUUID:{}", uuid);}return true;// 只有返回true才会继续向下执行，返回false取消当前请求}//请求处理之后回调方法@Overridepublic void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {/* 线程结束后需要清除,否则当前线程会一直占用这个requestId值 */log.info("ControllerInterceptor postHandle 请求处理之后清除 logback MDC requestUUID");MDC.remove("requestUUID");}//整个请求处理完毕回调方法@Overridepublic void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {/*整个请求线程结束后需要清除,否则当前线程会一直占用这个requestId值 */log.info("ControllerInterceptor afterCompletion 整个请求处理完毕清除 logback MDC requestUUID");MDC.clear();}
}

对日志进行格式化,时候用到logback-spring.xml配置

    <!--对日志进行格式化--><property name="LOG_MSG" value="- | [%X{requestUUID}] | [%d{yyyyMMdd HH:mm:ss.SSS}] | [%level] | [${HOSTNAME}] | [%thread] | [%logger{36}] | --> %msg|%n "/>

3、拦截器配置

/*** 描述:拦截器配置** @author zuozewei* @create 2018-12-30 12:54**/
@Configuration
public class MyWebMvcConfigurer extends WebMvcConfigurerAdapter {@Overridepublic void addInterceptors(InterceptorRegistry registry) {/*** 多个拦截器组成一个拦截器链* addPathPatterns 用于添加拦截规则* excludePathPatterns 用于排除拦截*/registry.addInterceptor(new ControllerInterceptor()).addPathPatterns("/**");super.addInterceptors(registry);}
}

4、自定义日志注解


/*** 日志注解类* @author zuozewei**/
@Target({ElementType.TYPE, ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
public @interface Log {/*** 日志描述，这里使用了@AliasFor 别名。spring提供的* @return*/@AliasFor("desc")String value() default "";/*** 日志描述* @return*/@AliasFor("value")String desc() default "";/*** 是否忽略* @return*/boolean ignore() default false;
}

TIPS：熟悉Spring常用注解类的通信，对 @AliasFor 应该不陌生。它是Spring 提供的一个注解，主要是给注解的属性起名别的。让使用注解时，更加的容易理解（比如给 value 属性起别名）。一般上是配对别名。由于是 Spring 框架提供的，所以要使其生效，可以使用AnnotationUtils.synthesizeAnnotation或者AnnotationUtils.getAnnotation方法调用获取注解

5、日志切面


/*** 日志切面类* Created by zuozewei on 2018/12/12.*/
@Aspect  //申明一个切面
@Component
@Slf4j
public class LogAspect {private static final String dateFormat = "yyyy-MM-dd HH:mm:ss";private static final String STRING_START = "\n>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>\n";private static final String STRING_END   = "\n<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<\n";//设置切入点@Pointcut("within(@org.springframework.web.bind.annotation.RestController *)")public void serviceLog() {}/*** 切换方法，记录日志* @param joinPoint* @return* @throws Throwable*/@Around("serviceLog()")public Object around(ProceedingJoinPoint joinPoint) throws Throwable {MethodSignature signature = (MethodSignature) joinPoint.getSignature();Method method = signature.getMethod();Class<?> targetClass = method.getDeclaringClass();StringBuffer classAndMethod = new StringBuffer();Log classAnnotation = targetClass.getAnnotation(Log.class);Log methodAnnotation = method.getAnnotation(Log.class);if (classAnnotation != null) {if (classAnnotation.ignore()) {return joinPoint.proceed();}classAndMethod.append(classAnnotation.value()).append("-");}if (methodAnnotation != null) {if (methodAnnotation.ignore()) {return joinPoint.proceed();}classAndMethod.append(methodAnnotation.value());}String target = targetClass.getName() + "#" + method.getName();String params = null;params = JSONObject.toJSONStringWithDateFormat(joinPoint.getArgs(), dateFormat, SerializerFeature.WriteMapNullValue);log.info(STRING_START + "{} 开始调用--> {} 参数:{}", classAndMethod.toString(), target, params);long start = System.currentTimeMillis();Object result = joinPoint.proceed();long timeConsuming = System.currentTimeMillis() - start;log.info("\n{} 调用结束<-- {} 返回值:{} 耗时:{}ms" + STRING_END, classAndMethod.toString(), target, JSONObject.toJSONStringWithDateFormat(result, dateFormat, SerializerFeature.WriteMapNullValue), timeConsuming);return result;}

6、配置启动

启动类加入注解 @EnableAspectJAutoProxy，生效注解。另一说法，默认引入pom依赖就是默认开启的。无所谓，加了就是了，加上总之是个好习惯。

@SpringBootApplication
@EnableAspectJAutoProxy
@Slf4j
public class LogbackdemoApplication {public static void main(String[] args) {SpringApplication.run(LogbackdemoApplication.class, args);log.info("程序启动！");}
}

7、控制层

/*** aop统一异常示例* @author oKong**/
@RestController
@Slf4j
public class DemoController {/*** http://127.0.0.1:8888/index/?content="我是测试内容"** @param content* @return*/@Log("请求了aopDemo方法")@GetMapping(value = "aop")public String aopDemo(@RequestParam String content) {LocalDateTime localDateTime = LocalDateTime.now();log.trace("请求参数：content:{}", content);log.debug("请求参数：content:{}", content);log.info("请求参数：content:{}", content);log.warn("请求参数：content:{}", content);log.error("请求参数：content:{}", content);return localDateTime + ",content:" + content;}/*** 不拦截日志示例* @param content* @return*/@GetMapping(value = "/notaop")@Log(ignore=true)public String notAopDemo(String content) {LocalDateTime localDateTime = LocalDateTime.now();log.trace("请求参数：content:{}", content);log.debug("请求参数：content:{}", content);log.info("请求参数：content:{}", content);log.warn("请求参数：content:{}", content);log.error("请求参数：content:{}", content);return localDateTime + ",content:" + content;}
}

八、测试 logback

1、测试统一拦截日志

浏览器访问：http://127.0.0.1:8888/aop/?content=”我是测试内容”

日志前面的 8B7B6968FB9A45BD8A3681AF3B123212 就是通过logback 的 MDC 做到的

>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
请求了aopDemo方法 开始调用--> com.zuozewei.logbackdemo.controller.DemoController#aopDemo 参数:["”我是测试内容”"]|
- | [8B7B6968FB9A45BD8A3681AF3B123212] | [20181230 12:12:28.913] | [INFO] | [appletekimbp] | [http-nio-8888-exec-1] | [c.z.l.controller.DemoController] | --> 请求参数：content:”我是测试内容”|
- | [8B7B6968FB9A45BD8A3681AF3B123212] | [20181230 12:12:28.913] | [WARN] | [appletekimbp] | [http-nio-8888-exec-1] | [c.z.l.controller.DemoController] | --> 请求参数：content:”我是测试内容”|
- | [8B7B6968FB9A45BD8A3681AF3B123212] | [20181230 12:12:28.913] | [ERROR] | [appletekimbp] | [http-nio-8888-exec-1] | [c.z.l.controller.DemoController] | --> 请求参数：content:”我是测试内容”|
- | [8B7B6968FB9A45BD8A3681AF3B123212] | [20181230 12:12:28.914] | [INFO] | [appletekimbp] | [http-nio-8888-exec-1] | [c.z.logbackdemo.aspect.LogAspect] | --> 
请求了aopDemo方法 调用结束<-- com.zuozewei.logbackdemo.controller.DemoController#aopDemo 返回值:"2018-12-30T12:12:28.913,content:”我是测试内容”" 耗时:56ms
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

从上图可以看到，日志输出内容元素具体如下：

  • requestUUID：一次请求是唯一的
  • 时间日期：精确到毫秒
  • 日志级别：ERROR, WARN, INFO, DEBUG or TRACE
  • 主机名：
  • 进程ID：
  • 类路径：
  • 分隔符： --> 标识实际日志的开始
  • 日志内容：

日志切面的响应：

请求了aopDemo方法 开始调用--> com.zuozewei.logbackdemo.controller.DemoController#aopDemo 参数:["”我是测试内容”"]|
com.zuozewei.logbackdemo.controller.DemoController#aopDemo 返回值:"2018-12-30T12:12:28.913,content:”我是测试内容”" 耗时:56ms

2、测试忽略拦截日志

浏览器访问：http://127.0.0.1:8888/notaop/?content=”我是测试内容”

- | [E5FB9C1D66514C2783B8E4C8024562F4] | [20181230 12:13:57.749] | [INFO] | [appletekimbp] | [http-nio-8888-exec-5] | [c.z.l.aspect.ControllerInterceptor] | --> ControllerInterceptor preHandle 在请求处理之前生成 logback requestUUID:E5FB9C1D66514C2783B8E4C8024562F4|
- | [E5FB9C1D66514C2783B8E4C8024562F4] | [20181230 12:13:57.753] | [INFO] | [appletekimbp] | [http-nio-8888-exec-5] | [c.z.l.controller.DemoController] | --> 请求参数：content:”不记录日志“|
- | [E5FB9C1D66514C2783B8E4C8024562F4] | [20181230 12:13:57.753] | [WARN] | [appletekimbp] | [http-nio-8888-exec-5] | [c.z.l.controller.DemoController] | --> 请求参数：content:”不记录日志“|
- | [E5FB9C1D66514C2783B8E4C8024562F4] | [20181230 12:13:57.754] | [ERROR] | [appletekimbp] | [http-nio-8888-exec-5] | [c.z.l.controller.DemoController] | --> 请求参数：content:”不记录日志“|
- | [E5FB9C1D66514C2783B8E4C8024562F4] | [20181230 12:13:57.794] | [INFO] | [appletekimbp] | [http-nio-8888-exec-5] | [c.z.l.aspect.ControllerInterceptor] | --> ControllerInterceptor postHandle 请求处理之后清除 logback MDC requestUUID|

从上面看到日志切面被忽略。

九、工程目录

十、总结

本文主要是简单介绍了利用 AOP 实现统一的请求日志记录功能。本示例未演示日志入库功能，后续再实现。在实际测试开发过程中，一般上都是将日志保存进行异步化后进行入库处理的，这点需要注意，日志记录不能影响正常的方法请求，若是同步的，会本末倒置的。

项目源码地址：

更多推荐

走进Java接口测试之日志管理之AOP统一日志

本文发布于:2024-02-07 09:22:44，感谢您对本站的认可！
本文链接:https://www.elefans.com/category/jswz/34/1755835.html
版权声明:本站内容均来自互联网，仅供演示用，请勿用于商业和其他非法用途。如果侵犯了您的权益请与我们联系，我们将在24小时内删除。
本文标签：日志   接口   测试   Java   AOP

发布评论

评论列表 （有 0 条评论）

最近发表

草根站长

>www.elefans.com

编程频道|电子爱好者 - 技术资讯及电子产品介绍！

热门文章

标签列表