查了下151的workflowMessageListenerContainer日志，并没有什么异常…

至此，通过查看web相关请求的响应时间，排除了web相关请求，通过两台机器对比线程，排除了非web相关请求。这样问题就死在这里了…

小光抬眼看了下时间，已经到了晚上，思路也渐渐的不清晰了，暂时休息，明天继续。

5. 第二天，根据不在场证明确定嫌疑人

第二天，小光早早的起了床，并立了一个Flag，今天肯定能查到原因。因为昨晚他突然想到，当一个请求很耗时，甚至都不返回成为死循环时，可能连日志都没有。

同时，WebFilter的日志打印，是在finally中，当请求无法返回时，当然不会打印日志，昨天确实是忽略了这个问题，走了个大的弯路。

public void doFilter(ServletRequest request, ServletResponse response,
					 FilterChain arg2) throws IOException, ServletException {
    long startTime = System.currentTimeMillis();
    StringBuffer url = new StringBuffer();
    try {
        url = url.append(((HttpServletRequest)request).getRequestURL().toString());
        arg2.doFilter(request, response);
    } catch (Throwable e){
        request.setAttribute("errmsg", e.getClass()+"-"+e.getMessage());
        RequestDispatcher rd = request.getRequestDispatcher("/resources/error.jsp");
        try {  
            rd.forward(request, response);  
            return;  
        }catch(Exception ex){}  
    } finally{
        if (!url.toString().contains("resources")) {
            logger.info(String.format("time %s,%s", url, System.currentTimeMillis() - startTime));
        }
    }
}

可以看到，只有finally中打印了日志，请求之前并没有打印日志。

那么是否有before和after都打印了日志，只要分析一下有before但是没有after的请求，那么就可以定位到问题点了！

想到这里，小光立马兴奋了一起，打开代码，找寻其他切入点，果然找到了一个WebInterceptor：

public class RequestLoggerHandler extends HandlerInterceptorAdapter {
    private static Logger logger = LogManager.getLogger(RequestLoggerHandler.class);
    private ThreadLocal<Long> startTime = new ThreadLocal();

    public RequestLoggerHandler() {
    }

    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        this.startTime.set(System.currentTimeMillis());
        User user = SessionUserUtil.getCurrentSessionUser();
        logger.info("[http]preHandle url: {}, user:{}, inParams: {}", new Object[]{request.getRequestURL(), user, this.toJSONString(request.getParameterMap())});
        return true;
    }

    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {
        logger.info("[http]postHandle url: {}, cause [{}] ms", new Object[]{request.getRequestURL(), System.currentTimeMillis() - ((Long)this.startTime.get()).longValue()});
        ThreadTokenHelper.clear();
    }

    private String toJSONString(Object object) {
        try {
            return JSON.toJSONString(object);
        } catch (Exception var3) {
            logger.warn("request请求参数序列化{}异常......");
            var3.printStackTrace();
            return null;
        }
    }
}

这里的before和after都打印了日志，且日志可以通过上面的n2即日志id来关联，没有日志id的时候可以使用请求地址来做对比。

结构化该请求相关的日志

cat all_is_well.log | grep '20180110-08:2[2-4].*com.xxx.commons.log.RequestLoggerHandler.*'
导出日志。

SELECT count(1),n2 FROM requestlog GROUP BY n2
查询数据，找出其中为奇数的请求。

最终竟然真的找到了一个，而且有且只有一个

查看时间点，也确实与案发时间对的上。为增加确定性，搜索该时间点之后线程catalina-exec-19的相关日志，发现在该时间点之后，就没有与此线程相关的日志了。由此，根据各线程的不在场证明可以基本确定嫌疑人为线程catalina-exec-19。