前面在介绍aop的时候提到使用aop可以实现统一日志记录，这里就简单通过aop框架实现统一记录日志功能。
为了更加灵活处理，aop拦截时并不是对所有方法都记录日志，我的规划是添加指定标签的方法或类才记录日志，没有添加标签的方法就不记录日志，这样可以让代码更灵活。而且可以在标签中指定日志级别，日志包括方法进入时和退出时都要记录，并且记录方法执行时间，方便做一些统计分析。
按照上面的规划，首先要定义一个标签用于标记哪些方法或类要记录日志，并且标签可以指定日志级别：
import java.lang.annotation.*;
/**
* 写日志标签
* @Author xingo
* @Date 2023/12/13
*/
@Target({ ElementType.METHOD, ElementType.TYPE })
@Retention(RetentionPolicy.RUNTIME)
@Inherited
@Documented
public @interface LogWriter {
/**
* 写日志级别：debug、info、warn、error
* @return
*/
LogLevel level() default LogLevel.DEBUG;
}
接下来就是要写aop实现类了，首先还是要引入aop的依赖包：
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-aop</artifactId>
</dependency>
日志拦截类内容：
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.*;
import org.aspectj.lang.reflect.MethodSignature;
import org.example.pojo.ApiResult;
import org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint;
import org.springframework.boot.autoconfigure.condition.ConditionalOnWebApplication;
import org.springframework.stereotype.Component;
/**
* 日志记录切面类
*
* @author xingo
* @date 2023/12/13
*/
@Aspect
@Component
@ConditionalOnWebApplication
@Slf4j
public class LogAspect {
// 通过环绕通知方式处理
/**
* 定义切入点
*/
@Pointcut("execution(* org.example.controller.*.*(..))")
public void pointcut1() {
}
@Pointcut("execution(* org.example.service.*.*(..))")
public void pointcut2() {
}
/**
* 请求开始时间
*/
public static final ThreadLocal<Long> threadStartTime = new ThreadLocal<>();
/**
* 记录方法进入和退出次数
*/
public static final ThreadLocal<Integer> methodCount = new ThreadLocal<>();
/**
* 前置通知：执行目标方法之前运行
* @param jp
*/
@Before("pointcut1() || pointcut2()")
public void beforeMethod(JoinPoint jp) {
threadStartTime.set(System.currentTimeMillis());
if(methodCount.get() == null) {
methodCount.set(1);
} else {
methodCount.set(methodCount.get() + 1);
}
this.writeLogger(jp, "开始", null, null, null);
}
/**
* 返回通知：目标方法正常返回值后运行
* @param jp
*/
@AfterReturning(value = "pointcut1() || pointcut2()", returning = "result")
public void aftherReturn(JoinPoint jp, Object result) {
long diff = System.currentTimeMillis() - threadStartTime.get();
if(methodCount.get() == 1) {
methodCount.remove();
threadStartTime.remove();
} else {
methodCount.set(methodCount.get() - 1);
}
this.writeLogger(jp, "结束", diff, null, result);
}
/**
* 异常通知：目标方法出现异常后运行
* @param jp
*/
@AfterThrowing(value = "pointcut1() || pointcut2()", throwing = "e")
public void afterThrowing(JoinPoint jp, Exception e) {
long diff = System.currentTimeMillis() - threadStartTime.get();
if(methodCount.get() == 1) {
methodCount.remove();
threadStartTime.remove();
} else {
methodCount.set(methodCount.get() - 1);
}
this.writeLogger(jp, "异常", diff, e, null);
}
// /**
// * 后置通知：目标方法运行结束之后，不管有没有异常
// * @param jp
// */
// @After("execution(* org.example.controller.*.*(..))")
// public void afterMethod(JoinPoint jp) {
// long diff = System.currentTimeMillis() - threadStartTime.get();
// threadStartTime.remove();
// System.out.println("请求耗时 ====>>> " + diff);
// }
/**
* 记录日志方法
* @param jp 切入点
* @param step 步骤
* @param diff 时间差异
* @param e 异常
* @param result 结果
*/
private void writeLogger(JoinPoint jp, String step, Long diff, Exception e, Object result) {
// 判断方法或类上面是否有记录日志注解
MethodInvocationProceedingJoinPoint mjp = (MethodInvocationProceedingJoinPoint) jp;
MethodSignature signature = (MethodSignature) mjp.getSignature();
LogWriter logWriter = null;
if(signature.getMethod().isAnnotationPresent(LogWriter.class)) {
logWriter = signature.getMethod().getAnnotation(LogWriter.class);
} else {
Class<?> clazz = jp.getThis().getClass();
if(clazz.isAnnotationPresent(LogWriter.class)) {
logWriter = clazz.getAnnotation(LogWriter.class);
}
}
// 有注解就进行日志记录，记录日志时要区分日志级别
if(logWriter != null) {
if(e != null) {
log.error("{} 异常|参数{}", jp.getSignature().getName(), JacksonUtils.toJSONString(jp.getArgs()), e);
return;
}
String msg = "{} {}|参数 {}{}{}";
Object[] args = {
jp.getSignature().getName(),
step,
JacksonUtils.toJSONString(jp.getArgs()),
result == null ? "" : "|结果 " + JacksonUtils.toJSONString(result),
diff == null ? "" : ("|耗时 " + diff + "ms")
};
switch (logWriter.level()) {
case TRACE:
log.trace(msg, args);
break;
case DEBUG:
log.debug(msg, args);
break;
case INFO:
log.info(msg, args);
break;
case WARN:
log.warn(msg, args);
break;
case ERROR:
log.error(msg, args);
break;
}
}
}
}
定义了两个切入点，分别是在controller层和service层都要进行处理，前置通知主要是记录进入方法开始执行的时间，返回通知和异常通知是方法执行完后根据不同情况进行不同的调用。最主要的是写日志内容方法，它里面首先判断方法是否有注解，如果有优先使用方法上的注解；如果没有再判断类上面是否有注解。如果都没有注解，那么就不执行写日志。
下面是我的测试内容，分别用两个数相加和相除来测试。
controller中定义两个接口：
@Autowired
private DemoService demoService;
@LogWriter(level = LogLevel.INFO)
@GetMapping("/demo8")
public ApiResult demo8(Integer a, Double b) throws InterruptedException {
Map<String, Object> map = new HashMap<>();
map.put("method", "demo8");
map.put("sum", demoService.sum(a, b));
return ApiResult.success(map);
}
@LogWriter
@GetMapping("/demo9")
public ApiResult demo9(Integer a, Integer b) throws InterruptedException {
Map<String, Object> map = new HashMap<>();
map.put("method", "demo9");
map.put("sum", demoService.divide(a, b));
return ApiResult.success(map);
}
为了模拟多层方法的调用，在service层中执行具体的计算方法：
import org.example.handler.LogWriter;
import org.springframework.boot.logging.LogLevel;
import org.springframework.stereotype.Service;
import java.util.concurrent.TimeUnit;
/**
* @Author xingo
* @Date 2023/12/13
*/
@Service
public class DemoService {
@LogWriter(level = LogLevel.INFO)
public Double sum(Integer a, Double b) {
try {
TimeUnit.MILLISECONDS.sleep(200);
} catch (InterruptedException e) {
e.printStackTrace();
}
return a + b;
}
@LogWriter
public Integer divide(Integer a, Integer b) {
try {
TimeUnit.MILLISECONDS.sleep(200);
} catch (InterruptedException e) {
e.printStackTrace();
}
return a / b;
}
}
测试正常执行：
请求方法：http://localhost:8081/demo8?a=100&b=111
日志内容：
2023-12-13 10:43:07.527|http-nio-8081-exec-8|[INFO ]|org.example.handler.LogAspect.writeLogger|demo8 开始|参数 [100,111.0]
2023-12-13 10:43:07.528|http-nio-8081-exec-8|[ERROR]|org.example.handler.LogAspect.writeLogger|sum 开始|参数 [100,111.0]
2023-12-13 10:43:07.729|http-nio-8081-exec-8|[ERROR]|org.example.handler.LogAspect.writeLogger|sum 结束|参数 [100,111.0]|结果 211.0|耗时 201ms
2023-12-13 10:43:07.729|http-nio-8081-exec-8|[INFO ]|org.example.handler.LogAspect.writeLogger|demo8 结束|参数 [100,111.0]|结果 {"code":200,"data":{"method":"demo8","sum":211.0},"message":"success","time":"0","success":true}|耗时 201ms
请求方法：http://localhost:8081/demo9?a=100&b=100
日志内容：
2023-12-13 10:54:04.862|http-nio-8081-exec-1|[DEBUG]|org.example.handler.LogAspect.writeLogger|demo9 开始|参数 [100,100]
2023-12-13 10:54:04.871|http-nio-8081-exec-1|[DEBUG]|org.example.handler.LogAspect.writeLogger|divide 开始|参数 [100,100]
2023-12-13 10:54:05.075|http-nio-8081-exec-1|[DEBUG]|org.example.handler.LogAspect.writeLogger|divide 结束|参数 [100,100]|结果 1|耗时 204ms
2023-12-13 10:54:05.097|http-nio-8081-exec-1|[DEBUG]|org.example.handler.LogAspect.writeLogger|demo9 结束|参数 [100,100]|结果 {"code":200,"data":{"method":"demo9","sum":1},"message":"success","time":"0","success":true}|耗时 205ms
测试发生异常时：
请求方法：http://localhost:8081/demo9?a=100&b=0
日志内容：
2023-12-13 10:58:42.708|http-nio-8081-exec-1|[DEBUG]|org.example.handler.LogAspect.writeLogger|demo9 开始|参数 [100,0]
2023-12-13 10:58:42.716|http-nio-8081-exec-1|[DEBUG]|org.example.handler.LogAspect.writeLogger|divide 开始|参数 [100,0]
2023-12-13 10:58:42.923|http-nio-8081-exec-1|[ERROR]|org.example.handler.LogAspect.writeLogger|divide 异常|参数[100,0]
java.lang.ArithmeticException: / by zero
at org.example.service.DemoService.divide(DemoService.java:33)
at org.example.service.DemoService$$FastClassBySpringCGLIB$$66398aeb.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:793)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.aspectj.AspectJAfterThrowingAdvice.invoke(AspectJAfterThrowingAdvice.java:64)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.framework.adapter.AfterReturningAdviceInterceptor.invoke(AfterReturningAdviceInterceptor.java:57)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:58)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:708)
at org.example.service.DemoService$$EnhancerBySpringCGLIB$$3977f776.divide(<generated>)
at org.example.controller.DemoController.demo9(DemoController.java:114)
at org.example.controller.DemoController$$FastClassBySpringCGLIB$$e30db683.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:793)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.aspectj.AspectJAfterThrowingAdvice.invoke(AspectJAfterThrowingAdvice.java:64)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.framework.adapter.AfterReturningAdviceInterceptor.invoke(AfterReturningAdviceInterceptor.java:57)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:58)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89)
at org.example.handler.AopAspect.doAround(AopAspect.java:40)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:624)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:72)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:708)
at org.example.controller.DemoController$$EnhancerBySpringCGLIB$$b559dc28.demo9(<generated>)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150)
..........
2023-12-13 10:58:42.924|http-nio-8081-exec-1|[ERROR]|org.example.handler.LogAspect.writeLogger|demo9 异常|参数[100,0]
java.lang.ArithmeticException: / by zero
at org.example.service.DemoService.divide(DemoService.java:33)
at org.example.service.DemoService$$FastClassBySpringCGLIB$$66398aeb.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:793)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.aspectj.AspectJAfterThrowingAdvice.invoke(AspectJAfterThrowingAdvice.java:64)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.framework.adapter.AfterReturningAdviceInterceptor.invoke(AfterReturningAdviceInterceptor.java:57)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:58)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:708)
at org.example.service.DemoService$$EnhancerBySpringCGLIB$$3977f776.divide(<generated>)
at org.example.controller.DemoController.demo9(DemoController.java:114)
at org.example.controller.DemoController$$FastClassBySpringCGLIB$$e30db683.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
..........
通过在日志中记录发生异常的完整堆栈信息和方法入参，可以很方便的定位问题发生的原因。
上面这种通过aop记录日志的方式是通用的，只是在方法进入和返回时记录日志，如果要在方法内部代码执行时记录日志，还是要在代码中写入日志。这里也说明了aop是为了解决通用场景下的重复工作，特殊需求还是要单独处理。
虽然这种方式简化了重复代码的编写，但是却带来了额外的性能开销，所以在项目中要根据情况选择使用。
版权声明：本文内容由互联网用户自发贡献，该文观点仅代表作者本人。本站仅提供信息存储空间服务，不拥有所有权，不承担相关法律责任。如发现本站有涉嫌侵权/违法违规的内容， 请发送邮件至 举报，一经查实，本站将立刻删除。
文章由极客之音整理，本文链接：https://www.bmabk.com/index.php/post/181815.html
