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