Java Servlet API是否提供响应发送完成事件？排查Spring MVC请求延迟

针对你基于Spring Rest MVC的场景，要追踪控制器执行完成到请求销毁之间的延迟，可通过以下方案实现：

1. 自定义响应包装器+过滤器追踪响应完成时间 #

通过包装HttpServletResponse监听输出流关闭事件（这是响应发送完成的标志），再结合ServletRequestListener记录请求销毁时间，两者对比即可定位延迟环节。

实现步骤： #

• 自定义ServletResponseWrapper，重写输出流相关方法，在流关闭时记录响应完成时间并绑定到请求属性：

public class TimingResponseWrapper extends HttpServletResponseWrapper {
    private long responseFinishTime;
    private ServletOutputStream wrappedStream;

    public TimingResponseWrapper(HttpServletResponse response) {
        super(response);
    }

    @Override
    public ServletOutputStream getOutputStream() throws IOException {
        if (wrappedStream == null) {
            wrappedStream = new TimingOutputStream(getResponse().getOutputStream());
        }
        return wrappedStream;
    }

    @Override
    public PrintWriter getWriter() throws IOException {
        return new PrintWriter(new OutputStreamWriter(getOutputStream(), getCharacterEncoding()));
    }

    private class TimingOutputStream extends ServletOutputStream {
        private final ServletOutputStream delegate;

        public TimingOutputStream(ServletOutputStream delegate) {
            this.delegate = delegate;
        }

        @Override
        public void write(int b) throws IOException {
            delegate.write(b);
        }

        @Override
        public void close() throws IOException {
            super.close();
            responseFinishTime = System.currentTimeMillis();
            getRequest().setAttribute("response_finish_time", responseFinishTime);
        }

        @Override
        public boolean isReady() {
            return delegate.isReady();
        }

        @Override
        public void setWriteListener(WriteListener writeListener) {
            delegate.setWriteListener(writeListener);
        }
    }

    public long getResponseFinishTime() {
        return responseFinishTime;
    }
}

• 编写Filter应用该包装器，同时记录控制器执行完成的时间（同步请求下，chain.doFilter执行完毕即代表控制器处理完成）：

@WebFilter(urlPatterns = "/*")
public class TimingFilter implements Filter {
    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        long controllerFinishTime = 0;
        TimingResponseWrapper wrappedResponse = new TimingResponseWrapper((HttpServletResponse) response);
        try {
            chain.doFilter(request, wrappedResponse);
            // 同步请求下，此处控制器已执行完成，记录时间
            controllerFinishTime = System.currentTimeMillis();
            request.setAttribute("controller_finish_time", controllerFinishTime);
        } finally {
            // 打印控制器到响应完成的耗时
            long responseFinish = wrappedResponse.getResponseFinishTime();
            if (responseFinish > 0 && controllerFinishTime > 0) {
                System.out.printf("控制器到响应完成耗时: %dms%n", responseFinish - controllerFinishTime);
            }
        }
    }
}

2. 结合ServletRequestListener记录请求销毁时间 #

在ServletRequestListener中，获取之前绑定到请求的响应完成时间，计算与请求销毁时间的差值：

@WebListener
public class RequestTimingListener implements ServletRequestListener {
    @Override
    public void requestInitialized(ServletRequestEvent sre) {
        sre.getServletRequest().setAttribute("request_start_time", System.currentTimeMillis());
    }

    @Override
    public void requestDestroyed(ServletRequestEvent sre) {
        ServletRequest request = sre.getServletRequest();
        long requestDestroyTime = System.currentTimeMillis();
        Long responseFinishTime = (Long) request.getAttribute("response_finish_time");
        Long controllerFinishTime = (Long) request.getAttribute("controller_finish_time");

        if (responseFinishTime != null) {
            System.out.printf("响应完成到请求销毁耗时: %dms%n", requestDestroyTime - responseFinishTime);
        }
        if (controllerFinishTime != null && responseFinishTime != null) {
            System.out.printf("控制器到响应完成耗时: %dms%n", responseFinishTime - controllerFinishTime);
        }
    }
}

3. 异步请求场景的额外处理 #

如果接口使用了Spring MVC异步特性（如Callable、DeferredResult），需额外监听异步请求的完成事件：

• 实现AsyncHandlerInterceptor，在异步请求启动时添加AsyncListener：

public class AsyncTimingInterceptor implements AsyncHandlerInterceptor {
    @Override
    public void afterConcurrentHandlingStarted(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        AsyncContext asyncContext = request.startAsync();
        asyncContext.addListener(new AsyncListener() {
            @Override
            public void onComplete(AsyncEvent event) throws IOException {
                long asyncFinishTime = System.currentTimeMillis();
                event.getAsyncContext().getRequest().setAttribute("response_finish_time", asyncFinishTime);
            }

            @Override
            public void onTimeout(AsyncEvent event) throws IOException {}

            @Override
            public void onError(AsyncEvent event) throws IOException {}

            @Override
            public void onStartAsync(AsyncEvent event) throws IOException {}
        });
    }
}

• 在Spring配置中注册该拦截器：

@Configuration
public class WebConfig implements WebMvcConfigurer {
    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(new AsyncTimingInterceptor());
    }
}

通过以上方案，你可以清晰区分控制器执行完成、响应发送完成、请求销毁三个时间点，精准定位延迟出现的具体环节。

内容的提问来源于stack exchange，提问作者Cristina_eGold