1.前言
在后端业务中,对每次请求的入参、被请求类、方法,以及出参、执行耗时等信息进行日志打印,是很有必要的,有了这些信息,当某个接口出现问题时,可以帮助我们快速完成问题的追踪。那么,Spring Boot 中要如何实现呢? 相对于这种与主流程有一定的功能解耦的相对独立小功能可以使用springboot的切面来在关键地方织入我们的程序。
2.什么是自定义注解 (Custom Annotations)?
Java 注解是从 Java 5 开始引入的,它为我们提供了一种元编程的方法,允许我们在不改变代码逻辑的情况下为代码添加元数据。这些元数据可以在编译时或运行时通过反射被访问。
自定义注解就是用户定义的,用于为代码提供元数据的注解。例如,本小节中自定义的 @ApiOperationLog 注解,它用来表示一个方法在执行时需要被记录日志。
3.什么是 AOP (面向切面编程)?
AOP(Aspect-Oriented Programming,面向切面编程)是一个编程范式,它提供了一种能力,让开发者能够模块化跨多个对象的横切关注点(例如日志、事务管理、安全等)。
主要概念包括:
- 切点 (Pointcuts): 定义在哪里应用切面(即在哪里插入横切关注点的代码)。
- 通知 (Advices): 定义在特定切点上要执行的代码。常见的通知类型有:前置通知、后置通知、环绕通知等。
- 切面 (Aspects): 切面将切点和通知结合起来,定义了在何处和何时应用特定的逻辑。
例如,使用AOP,我们可以为所有使用 @ApiOperationLog 注解的方法自动添加日志逻辑,而不需要在每个方法中手动添加。
4.开始动手
4.1 添加依赖
添加 jackson 工具,它用于将出入参转为 json 字符串:
<!-- 版本号统一管理 -->
<properties>
...省略
<jackson.version>2.15.2</jackson.version>
</properties>
<dependencies>
...省略
<!-- AOP 切面 -->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-aop</artifactId>
</dependency>
<!-- Jackson -->
<dependency>
<groupId>com.fasterxml.jackson.core</groupId>
<artifactId>jackson-databind</artifactId>
<version>${jackson.version}</version>
</dependency>
</dependencies>
4.2 自定义注解
新建一个名为 aspect 的包,用于放置切面相关的功能类接着,在其中创建一个名为 ApiOperationLog 的自定义注解:
package com.wind.weblog.common.aspect;
import java.lang.annotation.*;
@Retention(RetentionPolicy.RUNTIME)
@Target({ElementType.METHOD})
@Documented
public @interface ApiOperationLog {
/**
* 日志方法描述
*
* @return
*/
String description() default "";
}
元注解说明:
- @interface用来声明这是一个注解,接口是interface来声明
- @Retention(RetentionPolicy.RUNTIME): 这个元注解用于指定注解的保留策略,即注解在何时生效。RetentionPolicy.RUNTIME 表示该注解将在运行时保留,这意味着它可以通过反射在运行时被访问和解析。
- @Target({ElementType.METHOD}): 这个元注解用于指定注解的目标元素,即可以在哪些地方使用这个注解。ElementType.METHOD 表示该注解只能用于方法上。这意味着您只能在方法上使用这个特定的注解。
- @Documented: 这个元注解用于指定被注解的元素是否会出现在生成的Java文档中。如果一个注解使用了 @Documented,那么在生成文档时,被注解的元素及其注解信息会被包含在文档中。这可以帮助文档生成工具(如 JavaDoc)在生成文档时展示关于注解的信息。
4.3 日志切面
aspectj 注解说明
在配置 AOP 切面之前,我们需要了解下 aspectj 相关注解的作用:
- @Aspect:声明该类为一个切面类;
- @Pointcut:定义一个切点,后面跟随一个表达式,表达式可以定义为切某个注解,也可以切某个 package 下的方法;
切点定义好后,就是围绕这个切点做文章了:
- @Before: 在切点之前,织入相关代码;
- @After: 在切点之后,织入相关代码;
- @AfterReturning: 在切点返回内容后,织入相关代码,一般用于对返回值做些加工处理的场景;
- @AfterThrowing: 用来处理当织入的代码抛出异常后的逻辑处理;
- @Around: 环绕,可以在切入点前后织入代码,并且可以自由的控制何时执行切点;
创建 JSON 转换方法
在定义日志切面之前,我们先来创建一个 JSON 转换方法,这在日志切面中打印出入参为 JSON 字符串会用到。
private String toJson(JoinPoint joinPoint) throws JsonProcessingException {
ObjectMapper mapper = new ObjectMapper();
return mapper.writeValueAsString(joinPoint.getArgs());
}
完整的切面类:
package com.wind.weblog.common.aspect;
import com.fasterxml.jackson.core.JsonProcessingException;
import com.fasterxml.jackson.databind.ObjectMapper;
import com.wind.weblog.common.domain.dos.VisitorRecordDO;
import com.wind.weblog.common.domain.mapper.VisitorMapper;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.*;
import org.springframework.beans.factory.annotation.Value;
import org.springframework.scheduling.annotation.EnableScheduling;
import org.springframework.scheduling.annotation.Scheduled;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import javax.annotation.Resource;
import javax.servlet.http.HttpServletRequest;
import java.lang.reflect.Method;
import java.util.Date;
import java.util.concurrent.ConcurrentHashMap;
import static com.wind.weblog.common.utils.AgentRegionUtils.getIpAddress;
import static com.wind.weblog.common.utils.AgentRegionUtils.getIpRegion;
@Aspect
@Component
@Slf4j
@EnableScheduling
public class ApiOperationLogAspect {
/**
* 换行符
*/
private static final String LINE_SEPARATOR = System.lineSeparator();
/**
* 使用线程安全的hashmap作为每天访客ip记录
*/
private static final ConcurrentHashMap<String, String> AGENT_IP = new ConcurrentHashMap<>(8);
/**
* 定时更新访问ip记录 每天零点零一秒
*/
private static final String TASK_SCHEDULE = "1 0 0 * * ?" ;
/**
* todo ip2region.xdb库对应的文件路径,需在配置文件中写入
*/
@Value("${xdb.profile}")
private String xdbPath;
@Resource
private VisitorMapper visitorMapper;
/** 以所有添加 @WebLog 注解为切点 */
@Pointcut("@annotation(com.wind.weblog.common.aspect.ApiOperationLog)")
public void apiOperationLog() {
}
/**
* 在切点之前织入
* @param joinPoint
* @throws Throwable
*/
@Before("apiOperationLog()")
public void doBefore(JoinPoint joinPoint) throws Throwable {
// 开始打印请求日志
ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
HttpServletRequest request = attributes.getRequest();
// 获取日志注解的描述信息
String methodDescription = getAspectLogDescription(joinPoint);
// 打印请求相关参数
log.info("========== 请求开始: [{}], 入参: {} =================================== ", methodDescription, toJson(joinPoint));
log.warn("请求的类: {}, 方法: {}", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName());
// 根据request 获取ip地址并查询归属地
String ipAddress = getIpAddress(request);
if (!AGENT_IP.containsKey(ipAddress)) {
VisitorRecordDO visitorRecordDO = new VisitorRecordDO();
String region = getIpRegion(ipAddress, xdbPath);
// 将新的访客IP和归属地信息放入map
AGENT_IP.put(ipAddress, region);
Date date = new Date();
visitorRecordDO.setVisitor("agent");
visitorRecordDO.setIpAddress(ipAddress);
visitorRecordDO.setIpRegion(region);
visitorRecordDO.setVisitTime(date);
// todo 是否邮箱通知,默认为0不通知
visitorRecordDO.setIsNotify(0);
visitorMapper.insert(visitorRecordDO);
log.info("ipAddress: {}, Region: {}", ipAddress, region);
}
}
/**
* 每天零点零一秒执行,删除hashmap中的输出,更新当天访问ip记录
*/
@Scheduled(cron = TASK_SCHEDULE)
private void scheduledClearTask() {
AGENT_IP.clear();
}
/**
* 在切点之后织入
* @throws Throwable
*/
@After("apiOperationLog()")
public void doAfter() throws Throwable {
// nothing
}
/**
* 环绕
* @param proceedingJoinPoint
* @return
* @throws Throwable
*/
@Around("apiOperationLog()")
public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
long startTime = System.currentTimeMillis();
Object result = proceedingJoinPoint.proceed();
// 耗时
long timeConsuming = System.currentTimeMillis() - startTime;
String methodDescription = getAspectLogDescription(proceedingJoinPoint);
log.info("========== 请求结束: [{}], 耗时: {}ms, 出参: {} =================================== {}", methodDescription, timeConsuming, new ObjectMapper().writeValueAsString(result), LINE_SEPARATOR);
return result;
}
/**
* 获取切面注解的描述
*
* @param joinPoint 切点
* @return 方法描述
* @throws Exception
*/
public String getAspectLogDescription(JoinPoint joinPoint)
throws Exception {
String targetName = joinPoint.getTarget().getClass().getName();
String methodName = joinPoint.getSignature().getName();
Object[] arguments = joinPoint.getArgs();
Class targetClass = Class.forName(targetName);
Method[] methods = targetClass.getMethods();
StringBuilder description = new StringBuilder("");
for (Method method : methods) {
if (method.getName().equals(methodName)) {
Class[] clazzs = method.getParameterTypes();
if (clazzs.length == arguments.length) {
description.append(method.getAnnotation(ApiOperationLog.class).description());
break;
}
}
}
return description.toString();
}
/**
* 转 json
* @param joinPoint
* @return
*/
private String toJson(JoinPoint joinPoint) throws JsonProcessingException {
ObjectMapper mapper = new ObjectMapper();
return mapper.writeValueAsString(joinPoint.getArgs());
}
}
添加包扫描
在启动类 WeblogWebApplication 中,手动添加包扫描 @ComponentScan , 指定扫描 com.wind.weblog 包下面的所有类:
5. 测试一下
运行后的执行效果