SpringBoot記錄HTTP請求日誌

王翱_奧利奧發表於2018-08-29
Spring BootHTTP

SpringBoot記錄HTTP請求日誌

1、需求解讀

需求：

框架需要記錄每一個HTTP請求的資訊，包括請求路徑、請求引數、響應狀態、返回引數、請求耗時等資訊。

需求解讀：

Springboot框架提供了多種方式來攔截HTTP請求和響應，只要能夠獲取到對應的request和response，就可以通過相應的API來獲取所需要的資訊。

需要注意的是，請求引數可以分為兩部分，一部分是GET請求時，請求引數通過URL拼接的方式傳到後端，還有一部分是通過POST請求提交Json格式的引數，這種引數會放在request body中傳到後端，通過request.getParameterMap是無法獲取到的。

2、Spring Boot Actuator

2.1、介紹和使用

Spring Boot Actuator 的關鍵特性是在應用程式裡提供眾多 Web 介面，通過它們瞭解應用程式執行時的內部狀況，且能監控和度量Spring Boot 應用程式。

要使用Spring Boot Actuator，首先需要引入依賴包

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-actuator</artifactId>
</dependency>
複製程式碼

其次需要開啟埠訪問許可權

management.endpoints.web.exposure.include=httptrace
複製程式碼

Spring Boot 應用啟動時可以看到控制檯的資訊如下，代表開啟了該埠的訪問

image-20180829094800774

瀏覽器訪問/acutator/httptrace就能看到HTTP的請求情況

image-20180829100827244

2.2、預設的HttpTraceRepository

Spring Boot Actuator 預設會把最近100次的HTTP請求記錄到記憶體中，對應的實現類是InMemoryHttpTraceRepository

public class InMemoryHttpTraceRepository implements HttpTraceRepository {

	private int capacity = 100;

	private boolean reverse = true;

	private final List<HttpTrace> traces = new LinkedList<>();

	/**
	 * Flag to say that the repository lists traces in reverse order.
	 * @param reverse flag value (default true)
	 */
	public void setReverse(boolean reverse) {
		synchronized (this.traces) {
			this.reverse = reverse;
		}
	}

	/**
	 * Set the capacity of the in-memory repository.
	 * @param capacity the capacity
	 */
	public void setCapacity(int capacity) {
		synchronized (this.traces) {
			this.capacity = capacity;
		}
	}

	@Override
	public List<HttpTrace> findAll() {
		synchronized (this.traces) {
			return Collections.unmodifiableList(new ArrayList<>(this.traces));
		}
	}

	@Override
	public void add(HttpTrace trace) {
		synchronized (this.traces) {
			while (this.traces.size() >= this.capacity) {
				this.traces.remove(this.reverse ? this.capacity - 1 : 0);
			}
			if (this.reverse) {
				this.traces.add(0, trace);
			}
			else {
				this.traces.add(trace);
			}
		}
	}

}
複製程式碼

這裡add方法使用了synchronized，預設只儲存最近到100條，如果併發量大的話，效能會有所影響

2.3、自定義HttpTraceRepository

我們可以自己實現HttpTraceRepository這個介面，重寫add方法並記錄trace日誌

@Slf4j
public class RemoteHttpTraceRepository implements HttpTraceRepository {

    @Override
    public List<HttpTrace> findAll() {
        return Collections.emptyList();
    }

    @Override
    public void add(HttpTrace trace) {
        String path = trace.getRequest().getUri().getPath();
        String queryPara = trace.getRequest().getUri().getQuery();
        String queryParaRaw = trace.getRequest().getUri().getRawQuery();
        String method = trace.getRequest().getMethod();
        long timeTaken = trace.getTimeTaken();
        String time = trace.getTimestamp().toString();
        log.info("path: {}, queryPara: {}, queryParaRaw: {}, timeTaken: {}, time: {}, method: {}", path, queryPara, queryParaRaw,
                timeTaken, time, method);
    }
}
複製程式碼

將該實現類註冊到Spring的容器中

@Configuration
@ConditionalOnWebApplication
@ConditionalOnProperty(prefix = "management.trace.http", name = "enabled", matchIfMissing = true)
@EnableConfigurationProperties(HttpTraceProperties.class)
@AutoConfigureBefore(HttpTraceAutoConfiguration.class)
public class TraceConfig {

    @Bean
    @ConditionalOnMissingBean(HttpTraceRepository.class)
    public RemoteHttpTraceRepository traceRepository() {
        return new RemoteHttpTraceRepository();
    }
}
複製程式碼

2.4、缺點

目前這種實現可以記錄到請求路徑、請求耗時、響應狀態、請求Header、響應Header等資訊，**沒有辦法記錄請求引數和響應引數。**有人在github上提了個issue，作者回復說這樣的設計是為了相容Spring MVC和WebFlux兩種模式，具體可以參考：github.com/spring-proj…

3、Spring Boot Filter

3.1、HttpTraceFilter

既然httptrace無法滿足現有的需求，我們可以順著InMemoryHttpTraceRepository這個預設實現往上找，看看誰呼叫了這個實現類。結果可以發現是被HttpTraceFilter這個攔截器（servlet模式下）進行了呼叫。

public class HttpTraceFilter extends OncePerRequestFilter implements Ordered {

	// Not LOWEST_PRECEDENCE, but near the end, so it has a good chance of catching all
	// enriched headers, but users can add stuff after this if they want to
	private int order = Ordered.LOWEST_PRECEDENCE - 10;

	private final HttpTraceRepository repository;

	private final HttpExchangeTracer tracer;

	/**
	 * Create a new {@link HttpTraceFilter} instance.
	 * @param repository the trace repository
	 * @param tracer used to trace exchanges
	 */
	public HttpTraceFilter(HttpTraceRepository repository, HttpExchangeTracer tracer) {
		this.repository = repository;
		this.tracer = tracer;
	}

	@Override
	public int getOrder() {
		return this.order;
	}

	public void setOrder(int order) {
		this.order = order;
	}

	@Override
	protected void doFilterInternal(HttpServletRequest request,
			HttpServletResponse response, FilterChain filterChain)
			throws ServletException, IOException {
		if (!isRequestValid(request)) {
			filterChain.doFilter(request, response);
			return;
		}
		TraceableHttpServletRequest traceableRequest = new TraceableHttpServletRequest(
				request);
		HttpTrace trace = this.tracer.receivedRequest(traceableRequest);
		int status = HttpStatus.INTERNAL_SERVER_ERROR.value();
		try {
			filterChain.doFilter(request, response);
			status = response.getStatus();
		}
		finally {
			TraceableHttpServletResponse traceableResponse = new TraceableHttpServletResponse(
					(status != response.getStatus())
							? new CustomStatusResponseWrapper(response, status)
							: response);
			this.tracer.sendingResponse(trace, traceableResponse,
					request::getUserPrincipal, () -> getSessionId(request));
			this.repository.add(trace);
		}
	}
    ...省略部分程式碼
}
複製程式碼

tracer中會記錄HTTP的請求耗時

3.2、自定義HttpTraceFilter獲取請求引數

在HttpTraceFilter繼承了OncePerRequestFilter，我們可以仿照這個過濾器，定義自己的過濾器去繼承OncePerRequestFilter，在doFilterInternal這個方法中獲取到HttpServletRequest，HttpServletResponse，這樣就可以獲取到對應的請求引數和返回引數了。

GET請求時的引數可以通過以下方式進行獲取：

String parameterMap = request.getParameterMap()
複製程式碼

POST請求會將引數放入request body中，用以下方式進行獲取：

String requestBody = IOUtils.toString(request.getInputStream(), Charsets.UTF_8);
複製程式碼

很不幸，程式碼執行會丟擲異常

image-20180829111619987

原因是：body裡字元的傳輸是通過HttpServletRequest中的位元組流getInputStream()獲得的；而這個位元組流在讀取了一次之後就不復存在了。

解決方法：利用ContentCachingRequestWrapper對HttpServletRequest的請求包一層，該類會將inputstream中的copy一份到自己的位元組陣列中，這樣就不會報錯了。讀取完body後，需要呼叫

wrappedResponse.copyBodyToResponse();
複製程式碼

將請求還原。

3.3、完整的自定義HttpTraceFilter

@Slf4j
public class HttpTraceLogFilter extends OncePerRequestFilter implements Ordered {

    private static final String NEED_TRACE_PATH_PREFIX = "/api";
    private static final String IGNORE_CONTENT_TYPE = "multipart/form-data";

    private final MeterRegistry registry;

    public HttpTraceLogFilter(MeterRegistry registry) {
        this.registry = registry;
    }


    @Override
    public int getOrder() {
        return Ordered.LOWEST_PRECEDENCE - 10;
    }

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
            throws ServletException, IOException {
        if (!isRequestValid(request)) {
            filterChain.doFilter(request, response);
            return;
        }
        if (!(request instanceof ContentCachingRequestWrapper)) {
            request = new ContentCachingRequestWrapper(request);
        }
        if (!(response instanceof ContentCachingResponseWrapper)) {
            response = new ContentCachingResponseWrapper(response);
        }
        int status = HttpStatus.INTERNAL_SERVER_ERROR.value();
        long startTime = System.currentTimeMillis();
        try {
            filterChain.doFilter(request, response);
            status = response.getStatus();
        } finally {
            String path = request.getRequestURI();
            if (path.startsWith(NEED_TRACE_PATH_PREFIX) && !Objects.equals(IGNORE_CONTENT_TYPE, request.getContentType())) {

                String requestBody = IOUtils.toString(request.getInputStream(), Charsets.UTF_8);
                log.info(requestBody);
                //1. 記錄日誌
                HttpTraceLog traceLog = new HttpTraceLog();
                traceLog.setPath(path);
                traceLog.setMethod(request.getMethod());
                long latency = System.currentTimeMillis() - startTime;
                traceLog.setTimeTaken(latency);
                traceLog.setTime(LocalDateTime.now().toString());
                traceLog.setParameterMap(JsonMapper.INSTANCE.toJson(request.getParameterMap()));
                traceLog.setStatus(status);
                traceLog.setRequestBody(getRequestBody(request));
                traceLog.setResponseBody(getResponseBody(response));
                log.info("Http trace log: {}", JsonMapper.INSTANCE.toJson(traceLog));
            }
            updateResponse(response);
        }
    }

    private boolean isRequestValid(HttpServletRequest request) {
        try {
            new URI(request.getRequestURL().toString());
            return true;
        } catch (URISyntaxException ex) {
            return false;
        }
    }

    private String getRequestBody(HttpServletRequest request) {
        String requestBody = "";
        ContentCachingRequestWrapper wrapper = WebUtils.getNativeRequest(request, ContentCachingRequestWrapper.class);
        if (wrapper != null) {
            try {
                requestBody = IOUtils.toString(wrapper.getContentAsByteArray(), wrapper.getCharacterEncoding());
            } catch (IOException e) {
                // NOOP
            }
        }
        return requestBody;
    }

    private String getResponseBody(HttpServletResponse response) {
        String responseBody = "";
        ContentCachingResponseWrapper wrapper = WebUtils.getNativeResponse(response, ContentCachingResponseWrapper.class);
        if (wrapper != null) {
            try {
                responseBody = IOUtils.toString(wrapper.getContentAsByteArray(), wrapper.getCharacterEncoding());
            } catch (IOException e) {
                // NOOP
            }
        }
        return responseBody;
    }

    private void updateResponse(HttpServletResponse response) throws IOException {
        ContentCachingResponseWrapper responseWrapper = WebUtils.getNativeResponse(response, ContentCachingResponseWrapper.class);
        Objects.requireNonNull(responseWrapper).copyBodyToResponse();
    }


    @Data
    private static class HttpTraceLog {

        private String path;
        private String parameterMap;
        private String method;
        private Long timeTaken;
        private String time;
        private Integer status;
        private String requestBody;
        private String responseBody;
    }


}
複製程式碼
​@Configuration
@ConditionalOnWebApplication
public class HttpTraceConfiguration {

    @ConditionalOnWebApplication(type = Type.SERVLET)
    static class ServletTraceFilterConfiguration {

        @Bean
        public HttpTraceLogFilter httpTraceLogFilter(MeterRegistry registry) {
            return new HttpTraceLogFilter(registry);
        }

    }

}
複製程式碼

4、Spring AOP

使用Spring AOP的方式需要自定義註解，並且每個controller的方法上都需要加上這個註解才能進行攔截，對業務程式碼對編寫有強制性的要求，所以沒有采用這種方式。

相關文章