基于SpringMVC拦截器的接口耗时监控方案

CIT
910 阅读5分钟

前言

在日常的项目开发过程中，后端开发人员应该主动去关心自己的接口性能。这种关心需要量化，而量化的直接方式就是对接口的响应时间进行监控，以了解系统性能，帮助判断性能瓶颈。本文基于已有的全链路日志系统进一步补充了接口耗时的方案。已有的全链路日志系统是围绕ELK+Jaeger构建起来的，在Spring Cloud微服务架构中，可以实现跨服务的请求日志追踪 ，帮助我们进行线上问题排查。

服务告警部分则是通过Frostmourne平台来实现了，该平台可以接入Elasticsearch，配置相关的项目监控与告警。当监控到接口超时以后，可以通过接口超时日志中的traceId，在Jaeger平台上查看整个请求链路的耗时分布，快速明确问题发生的位置，提升问题发现与响应的速度。

实现

基本介绍

统计接口的耗时情况属于一个可以复用的功能点，因此这里直接使用 SpringMVC的HandlerInterceptor拦截器来实现，后续抽取成一个公共组件，方便复用。

拦截器接口 HandlerInterceptor 提供了三个方法来实现对请求前、请求后，响应后进行自定义处理，并且拦截器的前置处理和后置处理是具体关联性的。

  • preHandle() ：在 Controller 方法执行之前执行。即在 HandlerMapping 确定适当的处理程序对象之后调用，但在HandlerAdapter 调用处理程序之前调用。
  • postHandle() ：在 Controller 方法执行之后执行。即在 HandlerAdapter 实际调用处理程序之后，但在DispatcherServlet 呈现视图之前调用。
  • afterCompletion() ：完成请求处理后（即渲染视图之后）的回调。 将在处理程序执行的任何结果上被调用，从而允许适当的资源清理。

实现思路

要统计接口处理请求的时长，可以在拦截器的 preHandle() 方法记录请求开始时间（startTime），在 afterCompletion() 方法中记录请求处理完后的结束时间（endTime），请求处理时间(响应时间) = 结束时间 - 开始时间。

实现过程

  1. 定义一个拦截器
import lombok.extern.slf4j.Slf4j;
import org.slf4j.MDC;
import org.springframework.core.NamedThreadLocal;
import org.springframework.lang.Nullable;
import org.springframework.web.bind.annotation.RequestMethod;
import org.springframework.web.servlet.HandlerInterceptor;
import org.springframework.web.servlet.ModelAndView;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

/**
 * 拦截器，统计接口耗时
 */
@Slf4j
public class TimeConsumingInterceptor implements HandlerInterceptor {
    public static final String APPLICATION_JSON = "application/json";
    private NamedThreadLocal<Long> threadLocal = new NamedThreadLocal<>("StopWatch_StartTime");

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        // 记录请求开始时间
        threadLocal.set(System.currentTimeMillis());
        return true;
    }

    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, @Nullable ModelAndView modelAndView) throws Exception {
        // no need to override
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, @Nullable Exception ex) throws Exception {
        // 请求结束时间
        Long endTime = System.currentTimeMillis();
        try {
            // 从HttpServletRequest获取开始时间
            Long startTime = threadLocal.get();
            String fullUrl = getFullUrl(request);
            String paremeter = getParemeter(request);
            Long cost = endTime - startTime;
            MDC.put("costTime", cost.toString());
            MDC.put("url", fullUrl);
            // 打印请求
            log.info("request parameter: {}", paremeter);
        } catch (Exception e) {
            log.error("fail to calculate time cost", e);
        } finally {
            threadLocal.remove();
            MDC.remove("costTime");
            MDC.remove("url");
        }
    }

    /**
     * 获取完整的URL路径
     *
     * @param request 请求对象
     * @return 完整的URL路径
     */
    private String getFullUrl(HttpServletRequest request) {
        StringBuilder sb = new StringBuilder();
        String method = request.getMethod();
        sb.append(method).append(" ").append(request.getRequestURL().toString());
        return sb.toString();
    }

    /**
     * 获取请求参数
     *
     * @param request 请求对象
     * @return 完整的URL路径
     */
    private String getParemeter(HttpServletRequest request) {
        try {
            if (RequestMethod.POST.name().equals(request.getMethod())
                    && APPLICATION_JSON.equals(request.getContentType())) {
                RequestWrapper requestWrapper = new RequestWrapper(request);
                return requestWrapper.getBodyString().replaceAll("\s+"", """); 
            }
        } catch (Exception e) {
            log.error("fail to get paramter", e);
        }
        return "";
    }
}
  1. 配置拦截器使其生效
import lombok.extern.slf4j.Slf4j;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;
​
@Slf4j
@Configuration
public class WebMvcConfig implements WebMvcConfigurer {
​
    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(new TimeConsumingInterceptor())
                // 需拦截的URI配置
                .addPathPatterns("/**")
                // 不需拦截的URI配置
                .excludePathPatterns("/swagger/**", "/static/**", "/resource/**");
        log.info("***************** ADD TIME CONSUMING INTERCEPTOR  ******************");
    }
}
  1. 添加logback配置，在开发和测试环境由于流量小，可以通过TCP监听的方式直接将接口的耗时日志传输至logstash，生产环境最好还是通过filebeat监听日志文件的方式去实现。
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <contextName>log</contextName>
​
    <property name="logback.logDir" value="${LOG_PATH}"/>
    <springProperty name="logback.appName" scope="context" source="spring.application.name"/>
    <springProperty name="logback.elastic" scope="context" source="logback.elastic"/>
    <springProperty name="env" scope="context" source="spring.profiles.active"/>
    <springProperty name="serverIP" scope="context" source="spring.cloud.client.ip-address" defaultValue="0.0.0.0"/>
    <property name="commonLayoutPattern"
              value="[${serverIP}] %d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}} [%mdc{trace_id:-N/A}] ${LOG_LEVEL_PATTERN:-%p} ${PID:- } --- [%t] %logger{39}.%method[%line] : %m%n"/>
​
    <appender name="consoleLog" class="ch.qos.logback.core.ConsoleAppender">
        <!--展示格式 layout -->
        <layout class="ch.qos.logback.classic.PatternLayout">
            <pattern>${commonLayoutPattern}</pattern>
        </layout>
    </appender>
​
    <appender name="logStash" class="net.logstash.logback.appender.LogstashTcpSocketAppender">
        <!--可以访问的logstash日志收集端口-->
        <destination>192.168.xxx.xxx:4560</destination>
        <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
            <providers>
                <timestamp>
                    <timeZone>Asia/Shanghai</timeZone>
                </timestamp>
                <pattern>
                    <pattern>
                        {
                        "appName": "${logback.appName}-${env}",
                        "serverIP": "${serverIP}",
                        "traceId": "%mdc{trace_id:-N/A}",
                        "costTime": "%mdc{costTime:-0}",
                        "url": "%mdc{url:-N/A}",
                        "message": "%message",
                        "exception": "%ex{15}"
                        }
                    </pattern>
                </pattern>
            </providers>
        </encoder>
    </appender>
​
    <springProfile name="dev,pre">
        <logger name="com.xxx.xxx.log.autoconfigure.TimeConsumingInterceptor" additivity="false">
            <appender-ref ref="logStash"/>
            <appender-ref ref="consoleLog"/>
            <appender-ref ref="fileRequestLog"/>
        </logger>
    </springProfile>
​
    <springProfile name="prod">
        <logger name="com.xxx.xxx.log.autoconfigure.TimeConsumingInterceptor" additivity="false">
            <appender-ref ref="fileRequestLog"/>
        </logger>
    </springProfile>
​
    <appender name="asyncRequestLog" class="ch.qos.logback.classic.AsyncAppender">
        <discardingThreshold>0</discardingThreshold>
        <queueSize>1024</queueSize>
        <appender-ref ref="fileRequestLog"/>
    </appender>
</configuration>
  1. 配置开发、测试环境的logstash传输耗时日志
input {
  tcp {
    host => "192.168.xxx.xxx"
    port => 4560
    codec => json_lines
  }
}
​
​
filter {
  mutate {
    convert => {
      "costTime" => "integer"
    }
  }
}
​
output {
  elasticsearch {
    hosts => ["http://192.168.xxx.xxx:9200"]
    index => "request-%{[appName]}-%{+YYYY.MM.dd}"
    }
}
  1. 查看耗时结果

企业微信截图_20240206132452.png

  1. 配置耗时监控与结果验证

image-20240202104718793.png

image-20240202104839798.png

补充

在调试过程中发现无法获取接口的请求参数，原因在于请求流只能操作一次，会导致后续无法再获取流了。解决的方案是通过过滤器获取参数然后传到后面程序中。

  1. 定义过滤器
import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Component;

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


@Slf4j
@Component
@WebFilter(urlPatterns = "/*", filterName = "channelFilter")
public class ChannelFilter implements Filter {

    @Override
    public void init(FilterConfig filterConfig) {
        // no need to override
    }

    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
        log.debug("================进入过滤器==================");
        HttpServletRequest httpServletRequest = (HttpServletRequest) servletRequest;
        RequestWrapper requestWrapper = new RequestWrapper(httpServletRequest);
        filterChain.doFilter(requestWrapper, servletResponse);
    }

    @Override
    public void destroy() {
        // no need to override
    }
}
  1. 添加请求参数处理逻辑
import lombok.extern.slf4j.Slf4j;

import javax.servlet.ReadListener;
import javax.servlet.ServletInputStream;
import javax.servlet.ServletRequest;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletRequestWrapper;
import java.io.*;
import java.nio.charset.StandardCharsets;


@Slf4j
public class RequestWrapper extends HttpServletRequestWrapper {
    private final byte[] body;

    public RequestWrapper(HttpServletRequest request) {
        super(request);
        String sessionStream = getBodyString(request);
        body = sessionStream.getBytes(StandardCharsets.UTF_8);
    }

    public String getBodyString() {
        return new String(body, StandardCharsets.UTF_8);
    }

    public String getBodyString(final ServletRequest request) {
        StringBuilder sb = new StringBuilder();
        BufferedReader reader = null;
        try (InputStream inputStream = cloneInputStream(request.getInputStream())) {
            reader = new BufferedReader(new InputStreamReader(inputStream, StandardCharsets.UTF_8));
            String line = "";
            while ((line = reader.readLine()) != null) {
                sb.append(line);
            }
        } catch (IOException e) {
            log.error("fail to get request body", e);
        } finally {
            if (reader != null) {
                try {
                    reader.close();
                } catch (IOException e) {
                    log.error("fail to close stream reader", e);
                }
            }
        }
        log.debug("获取body请求参数:" + sb);
        return sb.toString();
    }

    public InputStream cloneInputStream(ServletInputStream inputStream) {
        ByteArrayOutputStream byteArrayOutputStream = new ByteArrayOutputStream();
        byte[] buffer = new byte[1024];
        int len;
        try {
            while ((len = inputStream.read(buffer)) > -1) {
                byteArrayOutputStream.write(buffer, 0, len);
            }
            byteArrayOutputStream.flush();
        } catch (IOException e) {
            log.error("fail to clone input stream", e);
        }
        return new ByteArrayInputStream(byteArrayOutputStream.toByteArray());
    }

    @Override
    public BufferedReader getReader() {
        return new BufferedReader(new InputStreamReader(getInputStream()));
    }

    @Override
    public ServletInputStream getInputStream() {

        final ByteArrayInputStream bais = new ByteArrayInputStream(body);
        return new ServletInputStream() {

            @Override
            public int read() {
                return bais.read();
            }

            @Override
            public boolean isFinished() {
                return false;
            }

            @Override
            public boolean isReady() {
                return false;
            }

            @Override
            public void setReadListener(ReadListener readListener) {
                // no need to override
            }
        };
    }
}

参考

www.elastic.co/guide/en/lo…

github.com/AutohomeCor…

blog.csdn.net/ffyyhh99551…

blog.csdn.net/u013845177/…

blog.csdn.net/QIU17616165…

segmentfault.com/a/119000004…

avatar
文章
阅读
粉丝