在使用springboot的时候,输出日志都是通过配置logback.xml配置文件进行输出的,之后在文件输出。
最近有一个新的需求:想对于日志进行定式化,通过自定义日志,把单个接口的日志信息存到数据库中,信息包括接口的请求地址,参数,返回信息,还有运行时候的日志信息,过程如下:
1、新建一个类,继承UnsynchronizedAppenderBase,并重新append()方法
当在代码里面指定日志打印的时候都会经过这个方法
/**
* @author YeChuanMing
* @date 2022/2/23
*/
@Component
public class CustomAppender extends UnsynchronizedAppenderBase<ILoggingEvent> {
private final StringBuffer stringBuffer = new StringBuffer();
@Override
protected void append(ILoggingEvent iLoggingEvent) {
HttpServletRequest req = ((ServletRequestAttributes) Objects
.requireNonNull(RequestContextHolder.getRequestAttributes())).getRequest();
if (req.getRequestURI() != null) {
stringBuffer.append(iLoggingEvent.getMessage());
if ("接口执行完毕".equals(iLoggingEvent.getMessage())) {
String uuid = UuidUtil.randomUUID();
req.setAttribute("requestId", uuid);
RedisUtil redisUtil = getRedisUtil();
redisUtil.set(uuid, stringBuffer.toString());
}
}
}
}
2、在logback配置文件指定这个类
<appender name="myLog" class="com.ycm.CustomAppender">
<root level="info">
<appender-ref ref="myLog"/>
</root>
3、代码中使用的方法
- 通过RequestContextHolder.getRequestAttributes()获取当前接口的请求信息
- 给这个http请求对象放置一个UUID用于在AOP的执行方法找到当前的这条日志信息
- 通过redis将数据进行缓存,之后在AOP的方法里面读取这条日志信息
4、遇到的问题
在代码中使用@Autowide对Redis的工具类进行注入,但是在运行的时候显示null,但是此时RedisUtil已经在容器中了。问题排查后可能是这个类做了继承,这个类的执行先于Spring容器的扫描。
最后采用的方法是通过Spring的上下文去获取RedisUtil。
/**
* @author YeChuanMing
* @date 2022/2/24
*/
@Component
public class SpringContextUtil implements ApplicationContextAware {
private static ApplicationContext applicationContext; // Spring应用上下文环境
@Override
public void setApplicationContext(ApplicationContext applicationContext) throws BeansException {
SpringContextUtil.applicationContext = applicationContext;
}
public static ApplicationContext getApplicationContext() {
return applicationContext;
}
@SuppressWarnings("unchecked")
public static <T> T getBean(String name) throws BeansException {
return (T) applicationContext.getBean(name);
}
public static <T> T getBean(Class<T> clazz) throws BeansException {
return applicationContext.getBean(clazz);
}
}
两天后重新更新
前面说的这个实现的功能在单线程的情况下是没有问题的
但是在多线程的情况下就会出现问题了
原因如下:
假设有2个线程A和B,A线程需要运行5秒,B线程需要运行1秒
A线程首先进入,此时这个Http对象为A的,日志打印也是使用A的Http请求对象
但是A线程运行的期间,B过来了,那么B还是会使用A的Http对象进行UUID的存储
导致日志输出的时候2个线程都是输出B的日志
代码改进:
- 创建一个不重复的key,这里用一个不重复的随机数来替代
- 在每一次请求的时候,将这个随机数放到Http对象当中,用来标识Http对象,这个实现可以放在AOP的before方法中
- 在日志打印的append()方法中做这样一个操作:每次获取打印日志以后,先拿到Http对象中的随机数,用这个随机数去Redis里面判断,如果存在这个key就把日志追加到这个key的value上面;如果不存在这个key就创建一个以随机数为key,这条日志信息为value的数据放到redis中。
- 在AOP的around方法中,通过随机数取到这个打印日志。