如果是使用 nginx 对 spring boot 项目进行代理，想要记录 spring boot 处理每次请求花费的时间，可以参考 nginx记录请求时间，$request_time与$upstream_response_time ，使用 nginx 的 $upstream_response_time 变量，比较准确。

spring boot 本身也可以实现计算处理每次请求的执行时间，使用过滤器（Filter），或者拦截器（HandlerInterceptorAdapter）。

使用过滤器 Filter

• 定义一个过滤器

import org.apache.log4j.Logger;
import org.springframework.core.Ordered;
import org.springframework.core.annotation.Order;

import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import java.io.IOException;

@Order(Ordered.HIGHEST_PRECEDENCE)
public class RequestTimeFilter implements Filter {
    private static final Logger logger = Logger.getLogger(RequestTimeFilter.class);

    @Override
    public void init(FilterConfig filterConfig) throws ServletException {
        // empty
    }

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
            throws IOException, ServletException {
        long time = System.currentTimeMillis();
        try {
            chain.doFilter(request, response);
        } finally {
            time = System.currentTimeMillis() - time;
            String url = ((HttpServletRequest) request).getRequestURI();
            logger.info(url + " " + time + "ms");
        }
    }

    @Override
    public void destroy() {
        // empty
    }
}

• 注册Bean

@EnableCaching
@SpringBootApplication
public class App {

    public static void main(String[] args) {
        SpringApplication.run(App.class, args);
    }

    @Bean
    public Filter requestTimeFilter() {
        return new RequestTimeFilter();
    }
}

使用拦截器

• 定义 HandlerInterceptorAdapter

import org.apache.log4j.Logger;
import org.springframework.web.servlet.handler.HandlerInterceptorAdapter;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.UUID;

public class RequestTimeHandlerInterceptorAdapter extends HandlerInterceptorAdapter {
    private static Logger logger = Logger.getLogger(MyWebConfig.class);

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        String requestId = UUID.randomUUID().toString();
        long startTime = System.currentTimeMillis();
        request.setAttribute("startTime", startTime);
        request.setAttribute("requestId", requestId);
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        super.afterCompletion(request, response, handler, ex);
        long startTime = (Long) request.getAttribute("startTime");
        long endTime = System.currentTimeMillis();
        long executeTime = endTime - startTime;
        String log = String.format("requestId %s, Handle :%b , request take time: %d", request.getAttribute("requestId"), handler, executeTime);
        logger.info(log);
    }
}

• 注册 interceptor

@Configuration
@EnableWebMvc
public class MyWebConfig implements WebMvcConfigurer {
    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(new RequestTimeHandlerInterceptorAdapter()).addPathPatterns("/**");
    }
}