基于SpringMVC攔截器實現(xiàn)接口耗時監(jiān)控功能

更新時間：2024年02月03日 08:48:02 作者：CIT

本文呢主要介紹了基于SpringMVC攔截器實現(xiàn)的接口耗時監(jiān)控功能,統(tǒng)計接口的耗時情況屬于一個可以復用的功能點,因此這里直接使用 SpringMVC的HandlerInterceptor攔截器來實現(xiàn),需要的朋友可以參考下

前言

在日常的項目開發(fā)過程中，后端開發(fā)人員應該主動去關心自己的接口性能。這種關心需要量化，而量化的直接方式就是對接口的響應時間進行監(jiān)控，以了解系統(tǒng)性能，幫助判斷性能瓶頸。本文基于已有的全鏈路日志系統(tǒng)進一步補充了接口耗時的方案。已有的全鏈路日志系統(tǒng)是圍繞ELK+Jaeger構建起來的，在Spring Cloud微服務架構中，可以實現(xiàn)跨服務的請求日志追蹤，幫助我們進行線上問題排查。

服務告警部分則是通過Frostmourne平臺來實現(xiàn)了，該平臺可以接入Elasticsearch，配置相關的項目監(jiān)控與告警。當監(jiān)控到接口超時以后，可以通過接口超時日志中的traceId，在Jaeger平臺上查看整個請求鏈路的耗時分布，快速明確問題發(fā)生的位置，提升問題發(fā)現(xiàn)與響應的速度。

實現(xiàn)

基本介紹

統(tǒng)計接口的耗時情況屬于一個可以復用的功能點，因此這里直接使用 SpringMVC的HandlerInterceptor攔截器來實現(xiàn)，后續(xù)抽取成一個公共組件，方便復用。

攔截器接口 HandlerInterceptor 提供了三個方法來實現(xiàn)對請求前、請求后，響應后進行自定義處理，并且攔截器的前置處理和后置處理是具體關聯(lián)性的。

preHandle() ：在 Controller 方法執(zhí)行之前執(zhí)行。即在 HandlerMapping 確定適當?shù)奶幚沓绦驅(qū)ο笾笳{(diào)用，但在HandlerAdapter 調(diào)用處理程序之前調(diào)用。
postHandle() ：在 Controller 方法執(zhí)行之后執(zhí)行。即在 HandlerAdapter 實際調(diào)用處理程序之后，但在DispatcherServlet 呈現(xiàn)視圖之前調(diào)用。
afterCompletion() ：完成請求處理后（即渲染視圖之后）的回調(diào)。將在處理程序執(zhí)行的任何結果上被調(diào)用，從而允許適當?shù)馁Y源清理。

實現(xiàn)思路

要統(tǒng)計接口處理請求的時長，可以在攔截器的 preHandle() 方法記錄請求開始時間（startTime），在 afterCompletion() 方法中記錄請求處理完后的結束時間（endTime），請求處理時間(響應時間) = 結束時間 - 開始時間。

實現(xiàn)過程

定義一個攔截器

import cn.hutool.core.text.CharSequenceUtil;
import cn.hutool.extra.servlet.ServletUtil;
import lombok.extern.slf4j.Slf4j;
import org.slf4j.MDC;
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;
import java.util.Iterator;
import java.util.Map;
import java.util.Set;
?
/**
 * 攔截器，統(tǒng)計接口耗時
 */
@Slf4j
public class TimeConsumingInterceptor implements HandlerInterceptor {
?
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        // 記錄請求開始時間
        request.setAttribute("_startTime", 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 = (long) request.getAttribute("_startTime");
            String clientIP = ServletUtil.getClientIP(request, "");
            String fullUrl = getFullUrl(request);
            Long cost = endTime - startTime;
            MDC.put("cost_time", cost.toString());
            MDC.put("request_url", fullUrl);
            MDC.put("client_ip", clientIP);
            // 打印接口信息及耗時
            log.info("client IP {}, url {}, cost {}ms", clientIP, fullUrl, cost);
        } catch (Exception e) {
            log.error("fail to calculate time cost", e);
        } finally {
            MDC.remove("cost_time");
            MDC.remove("request_url");
            MDC.remove("client_ip");
        }
    }
?
    /**
     * 獲取完整的URL路徑
     *
     * @param request 請求對象{@link HttpServletRequest}
     * @return 完整的URL路徑
     */
    private String getFullUrl(HttpServletRequest request) {
        //記錄請求參數(shù)
        StringBuilder sb = new StringBuilder();
        String method = request.getMethod();
        sb.append(method).append(" ");
        sb.append(request.getRequestURL().toString());
        if (RequestMethod.POST.name().equals(method)) {
            //獲取參數(shù)
            Map<String, String[]> pm = request.getParameterMap();
            Set<Map.Entry<String, String[]>> es = pm.entrySet();
            Iterator<Map.Entry<String, String[]>> iterator = es.iterator();
            appendPathVariable(iterator, sb);
        }
        return sb.toString();
    }
?
    private void appendPathVariable(Iterator<Map.Entry<String, String[]>> iterator, StringBuilder sb) {
        int pointer = 0;
        while (iterator.hasNext()) {
            if (pointer == 0) {
                sb.append("?");
            } else {
                sb.append("&");
            }
            Map.Entry<String, String[]> next = iterator.next();
            String key = next.getKey();
            String[] value = next.getValue();
            for (int i = 0; i < value.length; i++) {
                if (i != 0) {
                    sb.append("&");
                }
                if (value[i].length() <= 20) {
                    sb.append(key).append("=").append(value[i]);
                } else {
                    sb.append(key).append("=").append(CharSequenceUtil.subPre(value[i], 20)).append("…");
                }
            }
            pointer++;
        }
    }
}

配置攔截器使其生效

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  ******************");
    }
}

添加logback配置，在開發(fā)和測試環(huán)境由于流量小，可以通過TCP監(jiān)聽的方式直接將接口的耗時日志傳輸至logstash，生產(chǎn)環(huán)境最好還是通過filebeat監(jiān)聽日志文件的方式去實現(xiàn)。

<?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}",
                        "requestUrl":"%mdc{request_url:-N/A}",
                        "clientIP":"%mdc{client_ip:-N/A}",
                        "costTime": "%mdc{cost_time:-N/A}"
                        }
                    </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>

配置開發(fā)、測試環(huán)境的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}"
    }
}