可以从日志中看出下面比较重要的信息:
- 从抓包日志从可以得出 HTTP 请求与响应包中的所有内容。
- 这里的日志,由于没被 spring-cloud-sleuth 包装,所以日志本身的占位符没有相关链路信息
- 但是从包中,可以看到 spring-cloud-sleuth 的链路信息,这里是:
"X-B3-Parentspanid": "ef9653a0003ed68e", "X-B3-Sampled": "0", "X-B3-Spanid": "82b6a0202dc1566b", "X-B3-Traceid": "ef9653a0003ed68e",
- netty 本身有 traceId,即这里的
6666c1d1
和1277d54e
(分别是作为 HttpServer 接受请求和作为 HttpClient 转发请求后台微服务),这样其实就可以将 spring-cloud-sleuth 的链路信息与 netty 的链路信息结合在一起
这些日志很全面,但是有下面一些不好用的问题:
- 只能输出所有请求响应的包内容,并不能定制输出哪些内容。例如对于文件上传请求,我们其实并不想看他的请求体,但是这里无法定制化。
- 日志太多了,会影响我们的性能。
HttpWebHandlerAdapter 的 TRACE 日志
在系列前面文章的源码分析中,我们知道在入口的 HttpWebHandlerAdapter 中有请求与响应日志,可以通过下面的配置进行启用:
<AsyncLogger name="org.springframework.web.server.adapter.HttpWebHandlerAdapter" level="trace" additivity="false" includeLocation="true"> <appender-ref ref="console" /> </AsyncLogger>
这样就能启用类似于下面的日志:
2021-11-27 01:25:28,472 TRACE [sports,,] [16188] [reactor-http-nio-2][org.springframework.core.log.LogFormatUtils:88]:[8d5138d1-3] HTTP GET "/test-ss/anything", headers={masked} 2021-11-27 01:25:28,696 TRACE [sports,,] [16188] [reactor-http-nio-2][org.springframework.core.log.LogFormatUtils:88]:[8d5138d1-3] Completed 200 OK, headers={masked}
如何让 headers 不要被掩码,可以通过下面的配置实现:
spring.codec: log-request-details: true
这个配置对应的配置类是:CodecProperties
,通过源码我们也可以发现,我们还可以在这里限制 body 的大小:
@ConfigurationProperties(prefix = "spring.codec") public class CodecProperties { private boolean logRequestDetails; private DataSize maxInMemorySize; }
加上配置后,日志如下:
2021-11-27 01:32:50,501 TRACE [sports,,] [17668] [reactor-http-nio-2][org.springframework.core.log.LogFormatUtils:88]:[ecf9f55a-1] HTTP GET "/test-ss/anything", headers=[Host:"127.0.0.1:8181", Connection:"keep-alive", Cache-Control:"max-age=0", Upgrade-Insecure-Requests:"1", User-Agent:"Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.25 Safari/537.36 Core/1.70.3879.400 QQBrowser/10.8.4552.400", Accept:"text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8", Accept-Encoding:"gzip, deflate, br", Accept-Language:"zh-CN,zh;q=0.9"] 2021-11-27 01:32:51,212 TRACE [sports,,] [17668] [reactor-http-nio-2][org.springframework.core.log.LogFormatUtils:88]:[ecf9f55a-1] Completed 200 OK, headers=[Date:"Sat, 27 Nov 2021 01:32:48 GMT", Content-Type:"application/json", Server:"gunicorn/19.9.0", Access-Control-Allow-Origin:"*", Access-Control-Allow-Credentials:"true", content-length:"1084"]
但是这个日志内容太少,只包含请求和响应头,并且没有 spring-cloud-sleuth 相关的链路信息。
AccessLog
Spring Cloud Gateway 使用基于 reactor-netty 的 http 服务器,在 spring-boot 的封装中,可以通过添加 NettyServerCustomizer
Bean 来实现添加自定义 AccessLog。AccessLog 包含的元素有:
public interface AccessLogArgProvider { @Nullable @Deprecated String zonedDateTime(); @Nullable ZonedDateTime accessDateTime(); @Nullable SocketAddress remoteAddress(); @Nullable CharSequence method(); @Nullable CharSequence uri(); @Nullable String protocol(); @Nullable String user(); @Nullable CharSequence status(); long contentLength(); long duration(); @Nullable CharSequence requestHeader(CharSequence name); @Nullable CharSequence responseHeader(CharSequence name); @Nullable Map<CharSequence, Set<Cookie>> cookies(); }
可以看出里面没有 spring cloud sleuth 相关的链路信息,但是我们可以通过实现 Global Filter 将链路信息加入 Response 的 Header 中,并且通过 AccessLogArgProvider
的 requestHeader
将这些 Header 输出到 accesslog:
package com.github.jojotech.spring.cloud.apigateway.filter; import java.util.List; import lombok.extern.log4j.Log4j2; import reactor.core.publisher.Mono; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.cloud.gateway.filter.GatewayFilterChain; import org.springframework.cloud.gateway.filter.GlobalFilter; import org.springframework.cloud.sleuth.Span; import org.springframework.cloud.sleuth.TraceContext; import org.springframework.cloud.sleuth.Tracer; import org.springframework.core.Ordered; import org.springframework.http.HttpHeaders; import org.springframework.http.server.reactive.ServerHttpResponse; import org.springframework.stereotype.Component; import org.springframework.web.server.ServerWebExchange; @Log4j2 @Component public class CommonTraceFilter implements GlobalFilter, Ordered { public static final String TRACE_ID = "traceId"; public static final String SPAN_ID = "spanId"; @Autowired private Tracer tracer; @Override public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) { Span span = tracer.currentSpan(); if (span == null) { span = tracer.nextSpan(); } TraceContext context = span.context(); ServerHttpResponse response = exchange.getResponse(); HttpHeaders headers = response.getHeaders(); headers.put(TRACE_ID, List.of(context.traceId())); headers.put(SPAN_ID, List.of(context.spanId())); return chain.filter(exchange); } @Override public int getOrder() { //需要在所有的 Filter 之前,拿到 trace 信息 return Ordered.HIGHEST_PRECEDENCE; } }
然后,通过实现 NettyServerCustomizer
注册一个 Bean 来配置 Access Log。
package com.github.jojotech.spring.cloud.apigateway.filter; import java.net.InetSocketAddress; import java.net.SocketAddress; import reactor.netty.http.server.HttpServer; import reactor.netty.http.server.logging.AccessLog; import reactor.netty.http.server.logging.AccessLogFactory; import reactor.util.annotation.Nullable; import org.springframework.boot.web.embedded.netty.NettyServerCustomizer; import org.springframework.stereotype.Component; @Component public class AccessLogNettyServerCustomizer implements NettyServerCustomizer { static final String DEFAULT_LOG_FORMAT = "{},{} -> {} - {} [{}] \"{} {} {}\" {} {} {} ms"; static final String MISSING = "-"; @Override public HttpServer apply(HttpServer httpServer) { httpServer = httpServer.accessLog(true, AccessLogFactory.createFilter( accessLogArgProvider -> { //所有的都打印 return true; }, accessLogArgProvider -> { return AccessLog.create(DEFAULT_LOG_FORMAT, accessLogArgProvider .responseHeader(CommonTraceFilter.TRACE_ID) == null ? MISSING : accessLogArgProvider .responseHeader(CommonTraceFilter.TRACE_ID), accessLogArgProvider .responseHeader(CommonTraceFilter.SPAN_ID) == null ? MISSING : accessLogArgProvider .responseHeader(CommonTraceFilter.SPAN_ID), applyAddress(accessLogArgProvider .remoteAddress()), accessLogArgProvider.user(), accessLogArgProvider.zonedDateTime(), accessLogArgProvider.method(), accessLogArgProvider .uri(), accessLogArgProvider.protocol(), accessLogArgProvider.status(), accessLogArgProvider.contentLength() > -1 ? accessLogArgProvider .contentLength() : MISSING, accessLogArgProvider.duration()); }) ); return httpServer; } static String applyAddress(@Nullable SocketAddress socketAddress) { if (socketAddress instanceof InetSocketAddress) { InetSocketAddress inetSocketAddress = (InetSocketAddress) socketAddress; return inetSocketAddress.getHostString() + ":" + inetSocketAddress.getPort(); } else { return MISSING; } } }
这样,我们就可以得到像下面的 access log:
2021-11-27 03:56:10,948 INFO [sports,,] [8536] [reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:269]:baa69b779a8497eb,baa69b779a8497eb -> 127.0.0.1:64196 - - [2021-11-27T03:56:10.720844200Z[Etc/GMT]] "GET /test-ss/anything HTTP/1.1" 200 1084 228 ms
accesslog 的也不能输出 body,所以我们还是需要定制自己的日志 Filter。
我们在下一节,会开始实现我们自己定制的日志 Filter