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兩種模式，具體可以參考：https://github.com/spring-projects/spring-boot/issues/12953#issuecomment-383830749
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().