问题症状
HTTP 日志系统，老是出现日志信息覆盖的情况。比如同时调用 A 接口和 B 接口，B 接口请求响应信息变成了 A 接口请求响应相关信息。这个问题在并发量大的情况下越来越严重。
问题初步分析
显然并发量越来越大，问题越来越严重，是一个多线程问题。日志采集是通过 Spring 的 LogHttpInterceptor 来做的，分析一下代码。
public class LogHttpInterceptor extends HandlerInterceptorAdapter {
private Logger logger;
private PathMatcher pathMatcher;
private String[] excludePaths;
private LogMsg msg;
public LogHttpInterceptor(Logger logger) {
this.logger = logger;
}
public LogHttpInterceptor(Logger logger, String... excludePaths) {
this.logger = logger;
this.excludePaths = excludePaths;
if (!StringUtils.isEmpty(this.excludePaths)) {
pathMatcher = new AntPathMatcher();
}
}
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response,
Object handler) throws Exception {
if (isSkip(request)) {
return true;
}
msg = new LogMsg(logger.getModule());
msg.putRequest(request);
LogMsgThreadMapper.putLogMsg(LogMsg.REQUEST_TIME, "" + System.currentTimeMillis());
return true;
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response,
Object handler, Exception ex) throws Exception {
if (isSkip(request)) {
return;
}
LogMsgThreadMapper.putLogMsg(LogMsg.RESPONSE_TIME, "" + System.currentTimeMillis());
msg.putResponse(request, response);
if (ex != null) {
msg.append(ex.getMessage());
}
logger.log(msg);
}
private boolean isSkip(HttpServletRequest request) {
if (pathMatcher != null && excludePaths != null) {
for (String exclude : excludePaths) {
if (pathMatcher.match(exclude, request.getRequestURI())) {
return true;
}
}
}
return false;
}
}
其实我看了域变量 private LogMsg msg 我就感觉有问题了。在一个 Spring 框架中，像 HandlerInterceptorAdapter 一般都会生成单例 Bean。我仔细研读了注册 HandlerInterceptorAdapter Bean 代码，果然。
@Bean
public HandlerInterceptorAdapter aliLoggerInterceptor(@Autowired AliLogger aliLogger) {
LogHttpInterceptor interceptor = new LogHttpInterceptor(aliLogger, "/api/s/s");
return interceptor;
}
单例 Bean 在多线程环境下，写域变量是一件很危险的事情——每个线程都可以修改域变量的值。仔细看一下 LogMsg 使用，首先在 preHandle new 出一个实例，再在 afterCompletion 继续使用，在传入日志系统进行日志处理。
什么情况会出现该问题呢？具体分析一下。
- 第一种情况，请求 A preHandle、afterCompletion处理完，请求 B 继续处理 preHandle、afterCompletion，LogMsg 是新的，不是这种情况
- 第二种情况，请求 A preHandle 处理完、afterCompletion未处理完，请求 B 处理 preHandle，无论请求 B afterCompletion 是否处理完，请求 A 的 LogMsg 被修改
复现
复现该问题也简单，就不贴代码了。
- 在 Controller 中新建两个接口，一个叫 /fast，一个叫 /slow
- /slow 先休眠 10 s，/fast 立刻返回
- 先调用 /slow 接口，再调用 /fast 接口
问题必现了。
修复
很简单，不要在单例中共享对象。实现对象传递也要在 ThreadLocal 中。此问题只要把 LogMsg 放在 ThreadLocal 中操作即可，线程执行结束或者开始时，清理一下 ThreadLocal。
总结
- 单例模式不要在域中共享变量
- 线程共享变量最好在 ThreadLocal 中，以并发集合传递数据也是种不错的选择
- 对于多线程，要小心谨慎