SpringCloud升级之路2020.0.x版-42.SpringCloudGateway 现有的可供分析的请求日志以及缺陷

本系列代码地址://github.com/JoJoTec/spring-cloud-parent

网关由于是所有外部用户请求的入口,记录这些请求中我们需要的元素,对于线上监控以及业务问题定位,是非常重要的。并且,在这些元素中,链路信息也是非常重要的。通过链路信息,我们可以找到请求调用全链路相关的日志。并且,网关也是大部分请求链路起始的地方,记录请求中的元素的同时,也要带上链路信息。

我们需要在网关记录每个请求的:

  • HTTP 相关元素:
    • URL 相关信息
    • 请求信息,例如 HTTP HEADER,请求时间等等
    • 某些类型的请求体
    • 响应信息,例如响应码
    • 某些类型响应的响应体
  • 链路信息

现有的可供分析的日志以及缺陷

首先我们来看 Spring Cloud Gateway 中本身我们可以利用的日志。Spring Cloud Gateway 基于 Spring-WebFlux,Spring-WebFlux 基于 Project Reactor,我们没有在网关加入额外的 Web 容器依赖,所以 Web 容器用的是默认的基于 Project Reactor 的 reactor-netty 实现的 Web 容器。

netty 抓包日志

使用了 netty 我们可以联想到 netty 的抓包日志,Spring Cloud Gateway 封装了这个功能,并暴露了配置。Spring Cloud Gateway 是一个网关,他会作为 HTTP 服务器接受 HTTP 请求的同时,还在作为 HTTP 客户端将请求转发到下游的微服务。所以,这里有两种抓包日志,一种是作为 HTTP 服务器接收到的请求和响应,另一种是做为 HTTP 客户端发出的请求和响应。分别对应两个配置:

spring.cloud.gateway:
  httpserver:
    wiretap: true
  httpclient:
    wiretap: true

经常有读者私信我问如何看 spring cloud 有哪些配置,官方文档感觉不够清楚全面。我一般是看源码,但是鉴于很多人没有精力去研究源码,一种偷懒的方式是去看 jar 包里面的 spring-configuration-metadata.json。里面包含了比较全的配置,以及配置类(如果存在的话),这是很方便的。例如我们这里的两个配置,在这个 json 中对应:

{
  "name": "spring.cloud.gateway.httpclient.wiretap",
  "type": "java.lang.Boolean",
  "description": "Enables wiretap debugging for Netty HttpClient.",
  "sourceType": "org.springframework.cloud.gateway.config.HttpClientProperties",
  "defaultValue": false
},
{
  "name": "spring.cloud.gateway.httpserver.wiretap",
  "type": "java.lang.Boolean",
  "description": "Enables wiretap debugging for Netty HttpServer.",
  "defaultValue": "false"
},

可以看出,spring.cloud.gateway.httpclient.wiretap 对应配置类 org.springframework.cloud.gateway.config.HttpClientProperties(这个配置类里面的配置我们后面还会用到,到时候会详细分析其中的配置项),默认为 false。spring.cloud.gateway.httpserver.wiretap 没有配置类,他是被直接使用的,对应源码:

GatewayAutoConfiguration.java

@Bean
@ConditionalOnProperty(name = "spring.cloud.gateway.httpserver.wiretap")
public NettyWebServerFactoryCustomizer nettyServerWiretapCustomizer(Environment environment,
		ServerProperties serverProperties) {
	return new NettyWebServerFactoryCustomizer(environment, serverProperties) {
		@Override
		public void customize(NettyReactiveWebServerFactory factory) {
			factory.addServerCustomizers(httpServer -> httpServer.wiretap(true));
			super.customize(factory);
		}
	};
}

增加这两个配置为 true 之后,增加日志输出配置,我这里使用的是 log4j2(其实就是设置 reactor.netty.http.server.HttpServerreactor.netty.http.server.HttpClient 的日志级别为 DEBUG):

<AsyncLogger name="reactor.netty.http.server.HttpServer" level="debug" additivity="false" includeLocation="true">
    <appender-ref ref="console" />
</AsyncLogger>
<AsyncLogger name="reactor.netty.http.client.HttpClient" level="debug" additivity="false" includeLocation="true">
    <appender-ref ref="console" />
</AsyncLogger>

然后,再次请求我们前面实现的网关,可以看到类似于下面的日志:

2021-11-27 01:16:06,262 DEBUG [sports,,] [10632] [reactor-http-nio-2][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:1277d54e, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] READ: 466B
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 47 45 54 20 2f 74 65 73 74 2d 73 73 2f 61 6e 79 |GET /test-ss/any|
|00000010| 74 68 69 6e 67 20 48 54 54 50 2f 31 2e 31 0d 0a |thing HTTP/1.1..|
|00000020| 48 6f 73 74 3a 20 31 32 37 2e 30 2e 30 2e 31 3a |Host: 127.0.0.1:|
|00000030| 38 31 38 31 0d 0a 43 6f 6e 6e 65 63 74 69 6f 6e |8181..Connection|
|00000040| 3a 20 6b 65 65 70 2d 61 6c 69 76 65 0d 0a 43 61 |: keep-alive..Ca|
|00000050| 63 68 65 2d 43 6f 6e 74 72 6f 6c 3a 20 6d 61 78 |che-Control: max|
|00000060| 2d 61 67 65 3d 30 0d 0a 55 70 67 72 61 64 65 2d |-age=0..Upgrade-|
|00000070| 49 6e 73 65 63 75 72 65 2d 52 65 71 75 65 73 74 |Insecure-Request|
|00000080| 73 3a 20 31 0d 0a 55 73 65 72 2d 41 67 65 6e 74 |s: 1..User-Agent|
|00000090| 3a 20 4d 6f 7a 69 6c 6c 61 2f 35 2e 30 20 28 57 |: Mozilla/5.0 (W|
|000000a0| 69 6e 64 6f 77 73 20 4e 54 20 31 30 2e 30 3b 20 |indows NT 10.0; |
|000000b0| 57 4f 57 36 34 29 20 41 70 70 6c 65 57 65 62 4b |WOW64) AppleWebK|
|000000c0| 69 74 2f 35 33 37 2e 33 36 20 28 4b 48 54 4d 4c |it/537.36 (KHTML|
|000000d0| 2c 20 6c 69 6b 65 20 47 65 63 6b 6f 29 20 43 68 |, like Gecko) Ch|
|000000e0| 72 6f 6d 65 2f 37 30 2e 30 2e 33 35 33 38 2e 32 |rome/70.0.3538.2|
|000000f0| 35 20 53 61 66 61 72 69 2f 35 33 37 2e 33 36 20 |5 Safari/537.36 |
|00000100| 43 6f 72 65 2f 31 2e 37 30 2e 33 38 37 39 2e 34 |Core/1.70.3879.4|
|00000110| 30 30 20 51 51 42 72 6f 77 73 65 72 2f 31 30 2e |00 QQBrowser/10.|
|00000120| 38 2e 34 35 35 32 2e 34 30 30 0d 0a 41 63 63 65 |8.4552.400..Acce|
|00000130| 70 74 3a 20 74 65 78 74 2f 68 74 6d 6c 2c 61 70 |pt: text/html,ap|
|00000140| 70 6c 69 63 61 74 69 6f 6e 2f 78 68 74 6d 6c 2b |plication/xhtml+|
|00000150| 78 6d 6c 2c 61 70 70 6c 69 63 61 74 69 6f 6e 2f |xml,application/|
|00000160| 78 6d 6c 3b 71 3d 30 2e 39 2c 69 6d 61 67 65 2f |xml;q=0.9,image/|
|00000170| 77 65 62 70 2c 69 6d 61 67 65 2f 61 70 6e 67 2c |webp,image/apng,|
|00000180| 2a 2f 2a 3b 71 3d 30 2e 38 0d 0a 41 63 63 65 70 |*/*;q=0.8..Accep|
|00000190| 74 2d 45 6e 63 6f 64 69 6e 67 3a 20 67 7a 69 70 |t-Encoding: gzip|
|000001a0| 2c 20 64 65 66 6c 61 74 65 2c 20 62 72 0d 0a 41 |, deflate, br..A|
|000001b0| 63 63 65 70 74 2d 4c 61 6e 67 75 61 67 65 3a 20 |ccept-Language: |
|000001c0| 7a 68 2d 43 4e 2c 7a 68 3b 71 3d 30 2e 39 0d 0a |zh-CN,zh;q=0.9..|
|000001d0| 0d 0a                                           |..              |
+--------+-------------------------------------------------+----------------+
2021-11-27 01:16:06,262 DEBUG [sports,,] [10632] [reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:249]:[id:1277d54e-2, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] Handler is being applied: org.springframework.http.server.reactive.ReactorHttpHandlerAdapter@317ee5cc
2021-11-27 01:16:06,378 DEBUG [sports,,] [10632] [reactor-http-nio-2][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:1277d54e-2, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] READ COMPLETE
2021-11-27 01:16:06,381 DEBUG [sports,,] [10632] [reactor-http-nio-6][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:6666c1d1] REGISTERED
2021-11-27 01:16:06,437 DEBUG [sports,,] [10632] [reactor-http-nio-6][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:6666c1d1] CONNECT: httpbin.org/18.232.227.86:80
2021-11-27 01:16:06,656 DEBUG [sports,,] [10632] [reactor-http-nio-6][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:6666c1d1, L:/172.168.160.198:52819 - R:httpbin.org/18.232.227.86:80] ACTIVE
2021-11-27 01:16:06,672 DEBUG [sports,,] [10632] [reactor-http-nio-6][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:6666c1d1-1, L:/172.168.160.198:52819 - R:httpbin.org/18.232.227.86:80] WRITE: 775B
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 47 45 54 20 2f 61 6e 79 74 68 69 6e 67 20 48 54 |GET /anything HT|
|00000010| 54 50 2f 31 2e 31 0d 0a 43 61 63 68 65 2d 43 6f |TP/1.1..Cache-Co|
|00000020| 6e 74 72 6f 6c 3a 20 6d 61 78 2d 61 67 65 3d 30 |ntrol: max-age=0|
|00000030| 0d 0a 55 70 67 72 61 64 65 2d 49 6e 73 65 63 75 |..Upgrade-Insecu|
|00000040| 72 65 2d 52 65 71 75 65 73 74 73 3a 20 31 0d 0a |re-Requests: 1..|
|00000050| 55 73 65 72 2d 41 67 65 6e 74 3a 20 4d 6f 7a 69 |User-Agent: Mozi|
|00000060| 6c 6c 61 2f 35 2e 30 20 28 57 69 6e 64 6f 77 73 |lla/5.0 (Windows|
|00000070| 20 4e 54 20 31 30 2e 30 3b 20 57 4f 57 36 34 29 | NT 10.0; WOW64)|
|00000080| 20 41 70 70 6c 65 57 65 62 4b 69 74 2f 35 33 37 | AppleWebKit/537|
|00000090| 2e 33 36 20 28 4b 48 54 4d 4c 2c 20 6c 69 6b 65 |.36 (KHTML, like|
|000000a0| 20 47 65 63 6b 6f 29 20 43 68 72 6f 6d 65 2f 37 | Gecko) Chrome/7|
|000000b0| 30 2e 30 2e 33 35 33 38 2e 32 35 20 53 61 66 61 |0.0.3538.25 Safa|
|000000c0| 72 69 2f 35 33 37 2e 33 36 20 43 6f 72 65 2f 31 |ri/537.36 Core/1|
|000000d0| 2e 37 30 2e 33 38 37 39 2e 34 30 30 20 51 51 42 |.70.3879.400 QQB|
|000000e0| 72 6f 77 73 65 72 2f 31 30 2e 38 2e 34 35 35 32 |rowser/10.8.4552|
|000000f0| 2e 34 30 30 0d 0a 41 63 63 65 70 74 3a 20 74 65 |.400..Accept: te|
|00000100| 78 74 2f 68 74 6d 6c 2c 61 70 70 6c 69 63 61 74 |xt/html,applicat|
|00000110| 69 6f 6e 2f 78 68 74 6d 6c 2b 78 6d 6c 2c 61 70 |ion/xhtml+xml,ap|
|00000120| 70 6c 69 63 61 74 69 6f 6e 2f 78 6d 6c 3b 71 3d |plication/xml;q=|
|00000130| 30 2e 39 2c 69 6d 61 67 65 2f 77 65 62 70 2c 69 |0.9,image/webp,i|
|00000140| 6d 61 67 65 2f 61 70 6e 67 2c 2a 2f 2a 3b 71 3d |mage/apng,*/*;q=|
|00000150| 30 2e 38 0d 0a 41 63 63 65 70 74 2d 45 6e 63 6f |0.8..Accept-Enco|
|00000160| 64 69 6e 67 3a 20 67 7a 69 70 2c 20 64 65 66 6c |ding: gzip, defl|
|00000170| 61 74 65 2c 20 62 72 0d 0a 41 63 63 65 70 74 2d |ate, br..Accept-|
|00000180| 4c 61 6e 67 75 61 67 65 3a 20 7a 68 2d 43 4e 2c |Language: zh-CN,|
|00000190| 7a 68 3b 71 3d 30 2e 39 0d 0a 46 6f 72 77 61 72 |zh;q=0.9..Forwar|
|000001a0| 64 65 64 3a 20 70 72 6f 74 6f 3d 68 74 74 70 3b |ded: proto=http;|
|000001b0| 68 6f 73 74 3d 22 31 32 37 2e 30 2e 30 2e 31 3a |host="127.0.0.1:|
|000001c0| 38 31 38 31 22 3b 66 6f 72 3d 22 31 32 37 2e 30 |8181";for="127.0|
|000001d0| 2e 30 2e 31 3a 35 32 37 39 37 22 0d 0a 58 2d 46 |.0.1:52797"..X-F|
|000001e0| 6f 72 77 61 72 64 65 64 2d 46 6f 72 3a 20 31 32 |orwarded-For: 12|
|000001f0| 37 2e 30 2e 30 2e 31 0d 0a 58 2d 46 6f 72 77 61 |7.0.0.1..X-Forwa|
|00000200| 72 64 65 64 2d 50 72 6f 74 6f 3a 20 68 74 74 70 |rded-Proto: http|
|00000210| 0d 0a 58 2d 46 6f 72 77 61 72 64 65 64 2d 50 72 |..X-Forwarded-Pr|
|00000220| 65 66 69 78 3a 20 2f 74 65 73 74 2d 73 73 0d 0a |efix: /test-ss..|
|00000230| 58 2d 46 6f 72 77 61 72 64 65 64 2d 50 6f 72 74 |X-Forwarded-Port|
|00000240| 3a 20 38 31 38 31 0d 0a 58 2d 46 6f 72 77 61 72 |: 8181..X-Forwar|
|00000250| 64 65 64 2d 48 6f 73 74 3a 20 31 32 37 2e 30 2e |ded-Host: 127.0.|
|00000260| 30 2e 31 3a 38 31 38 31 0d 0a 68 6f 73 74 3a 20 |0.1:8181..host: |
|00000270| 68 74 74 70 62 69 6e 2e 6f 72 67 0d 0a 58 2d 42 |httpbin.org..X-B|
|00000280| 33 2d 54 72 61 63 65 49 64 3a 20 65 66 39 36 35 |3-TraceId: ef965|
|00000290| 33 61 30 30 30 33 65 64 36 38 65 0d 0a 58 2d 42 |3a0003ed68e..X-B|
|000002a0| 33 2d 53 70 61 6e 49 64 3a 20 38 32 62 36 61 30 |3-SpanId: 82b6a0|
|000002b0| 32 30 32 64 63 31 35 36 36 62 0d 0a 58 2d 42 33 |202dc1566b..X-B3|
|000002c0| 2d 50 61 72 65 6e 74 53 70 61 6e 49 64 3a 20 65 |-ParentSpanId: e|
|000002d0| 66 39 36 35 33 61 30 30 30 33 65 64 36 38 65 0d |f9653a0003ed68e.|
|000002e0| 0a 58 2d 42 33 2d 53 61 6d 70 6c 65 64 3a 20 30 |.X-B3-Sampled: 0|
|000002f0| 0d 0a 63 6f 6e 74 65 6e 74 2d 6c 65 6e 67 74 68 |..content-length|
|00000300| 3a 20 30 0d 0a 0d 0a                            |: 0....         |
+--------+-------------------------------------------------+----------------+
2021-11-27 01:16:06,672 DEBUG [sports,,] [10632] [reactor-http-nio-6][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:6666c1d1-1, L:/172.168.160.198:52819 - R:httpbin.org/18.232.227.86:80] FLUSH
2021-11-27 01:16:06,890 DEBUG [sports,,] [10632] [reactor-http-nio-6][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:6666c1d1-1, L:/172.168.160.198:52819 - R:httpbin.org/18.232.227.86:80] READ: 1315B
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 48 54 54 50 2f 31 2e 31 20 32 30 30 20 4f 4b 0d |HTTP/1.1 200 OK.|
|00000010| 0a 44 61 74 65 3a 20 53 61 74 2c 20 32 37 20 4e |.Date: Sat, 27 N|
|00000020| 6f 76 20 32 30 32 31 20 30 31 3a 31 36 3a 30 34 |ov 2021 01:16:04|
|00000030| 20 47 4d 54 0d 0a 43 6f 6e 74 65 6e 74 2d 54 79 | GMT..Content-Ty|
|00000040| 70 65 3a 20 61 70 70 6c 69 63 61 74 69 6f 6e 2f |pe: application/|
|00000050| 6a 73 6f 6e 0d 0a 43 6f 6e 74 65 6e 74 2d 4c 65 |json..Content-Le|
|00000060| 6e 67 74 68 3a 20 31 30 38 34 0d 0a 43 6f 6e 6e |ngth: 1084..Conn|
|00000070| 65 63 74 69 6f 6e 3a 20 6b 65 65 70 2d 61 6c 69 |ection: keep-ali|
|00000080| 76 65 0d 0a 53 65 72 76 65 72 3a 20 67 75 6e 69 |ve..Server: guni|
|00000090| 63 6f 72 6e 2f 31 39 2e 39 2e 30 0d 0a 41 63 63 |corn/19.9.0..Acc|
|000000a0| 65 73 73 2d 43 6f 6e 74 72 6f 6c 2d 41 6c 6c 6f |ess-Control-Allo|
|000000b0| 77 2d 4f 72 69 67 69 6e 3a 20 2a 0d 0a 41 63 63 |w-Origin: *..Acc|
|000000c0| 65 73 73 2d 43 6f 6e 74 72 6f 6c 2d 41 6c 6c 6f |ess-Control-Allo|
|000000d0| 77 2d 43 72 65 64 65 6e 74 69 61 6c 73 3a 20 74 |w-Credentials: t|
|000000e0| 72 75 65 0d 0a 0d 0a 7b 0a 20 20 22 61 72 67 73 |rue....{.  "args|
|000000f0| 22 3a 20 7b 7d 2c 20 0a 20 20 22 64 61 74 61 22 |": {}, .  "data"|
|00000100| 3a 20 22 22 2c 20 0a 20 20 22 66 69 6c 65 73 22 |: "", .  "files"|
|00000110| 3a 20 7b 7d 2c 20 0a 20 20 22 66 6f 72 6d 22 3a |: {}, .  "form":|
|00000120| 20 7b 7d 2c 20 0a 20 20 22 68 65 61 64 65 72 73 | {}, .  "headers|
|00000130| 22 3a 20 7b 0a 20 20 20 20 22 41 63 63 65 70 74 |": {.    "Accept|
|00000140| 22 3a 20 22 74 65 78 74 2f 68 74 6d 6c 2c 61 70 |": "text/html,ap|
|00000150| 70 6c 69 63 61 74 69 6f 6e 2f 78 68 74 6d 6c 2b |plication/xhtml+|
|00000160| 78 6d 6c 2c 61 70 70 6c 69 63 61 74 69 6f 6e 2f |xml,application/|
|00000170| 78 6d 6c 3b 71 3d 30 2e 39 2c 69 6d 61 67 65 2f |xml;q=0.9,image/|
|00000180| 77 65 62 70 2c 69 6d 61 67 65 2f 61 70 6e 67 2c |webp,image/apng,|
|00000190| 2a 2f 2a 3b 71 3d 30 2e 38 22 2c 20 0a 20 20 20 |*/*;q=0.8", .   |
|000001a0| 20 22 41 63 63 65 70 74 2d 45 6e 63 6f 64 69 6e | "Accept-Encodin|
|000001b0| 67 22 3a 20 22 67 7a 69 70 2c 20 64 65 66 6c 61 |g": "gzip, defla|
|000001c0| 74 65 2c 20 62 72 22 2c 20 0a 20 20 20 20 22 41 |te, br", .    "A|
|000001d0| 63 63 65 70 74 2d 4c 61 6e 67 75 61 67 65 22 3a |ccept-Language":|
|000001e0| 20 22 7a 68 2d 43 4e 2c 7a 68 3b 71 3d 30 2e 39 | "zh-CN,zh;q=0.9|
|000001f0| 22 2c 20 0a 20 20 20 20 22 43 61 63 68 65 2d 43 |", .    "Cache-C|
|00000200| 6f 6e 74 72 6f 6c 22 3a 20 22 6d 61 78 2d 61 67 |ontrol": "max-ag|
|00000210| 65 3d 30 22 2c 20 0a 20 20 20 20 22 43 6f 6e 74 |e=0", .    "Cont|
|00000220| 65 6e 74 2d 4c 65 6e 67 74 68 22 3a 20 22 30 22 |ent-Length": "0"|
|00000230| 2c 20 0a 20 20 20 20 22 46 6f 72 77 61 72 64 65 |, .    "Forwarde|
|00000240| 64 22 3a 20 22 70 72 6f 74 6f 3d 68 74 74 70 3b |d": "proto=http;|
|00000250| 68 6f 73 74 3d 5c 22 31 32 37 2e 30 2e 30 2e 31 |host=\"127.0.0.1|
|00000260| 3a 38 31 38 31 5c 22 3b 66 6f 72 3d 5c 22 31 32 |:8181\";for=\"12|
|00000270| 37 2e 30 2e 30 2e 31 3a 35 32 37 39 37 5c 22 22 |7.0.0.1:52797\""|
|00000280| 2c 20 0a 20 20 20 20 22 48 6f 73 74 22 3a 20 22 |, .    "Host": "|
|00000290| 68 74 74 70 62 69 6e 2e 6f 72 67 22 2c 20 0a 20 |httpbin.org", . |
|000002a0| 20 20 20 22 55 70 67 72 61 64 65 2d 49 6e 73 65 |   "Upgrade-Inse|
|000002b0| 63 75 72 65 2d 52 65 71 75 65 73 74 73 22 3a 20 |cure-Requests": |
|000002c0| 22 31 22 2c 20 0a 20 20 20 20 22 55 73 65 72 2d |"1", .    "User-|
|000002d0| 41 67 65 6e 74 22 3a 20 22 4d 6f 7a 69 6c 6c 61 |Agent": "Mozilla|
|000002e0| 2f 35 2e 30 20 28 57 69 6e 64 6f 77 73 20 4e 54 |/5.0 (Windows NT|
|000002f0| 20 31 30 2e 30 3b 20 57 4f 57 36 34 29 20 41 70 | 10.0; WOW64) Ap|
|00000300| 70 6c 65 57 65 62 4b 69 74 2f 35 33 37 2e 33 36 |pleWebKit/537.36|
|00000310| 20 28 4b 48 54 4d 4c 2c 20 6c 69 6b 65 20 47 65 | (KHTML, like Ge|
|00000320| 63 6b 6f 29 20 43 68 72 6f 6d 65 2f 37 30 2e 30 |cko) Chrome/70.0|
|00000330| 2e 33 35 33 38 2e 32 35 20 53 61 66 61 72 69 2f |.3538.25 Safari/|
|00000340| 35 33 37 2e 33 36 20 43 6f 72 65 2f 31 2e 37 30 |537.36 Core/1.70|
|00000350| 2e 33 38 37 39 2e 34 30 30 20 51 51 42 72 6f 77 |.3879.400 QQBrow|
|00000360| 73 65 72 2f 31 30 2e 38 2e 34 35 35 32 2e 34 30 |ser/10.8.4552.40|
|00000370| 30 22 2c 20 0a 20 20 20 20 22 58 2d 41 6d 7a 6e |0", .    "X-Amzn|
|00000380| 2d 54 72 61 63 65 2d 49 64 22 3a 20 22 52 6f 6f |-Trace-Id": "Roo|
|00000390| 74 3d 31 2d 36 31 61 31 38 36 64 34 2d 34 31 38 |t=1-61a186d4-418|
|000003a0| 32 30 65 31 66 36 33 39 30 32 64 34 64 33 63 63 |20e1f63902d4d3cc|
|000003b0| 64 38 62 39 64 22 2c 20 0a 20 20 20 20 22 58 2d |d8b9d", .    "X-|
|000003c0| 42 33 2d 50 61 72 65 6e 74 73 70 61 6e 69 64 22 |B3-Parentspanid"|
|000003d0| 3a 20 22 65 66 39 36 35 33 61 30 30 30 33 65 64 |: "ef9653a0003ed|
|000003e0| 36 38 65 22 2c 20 0a 20 20 20 20 22 58 2d 42 33 |68e", .    "X-B3|
|000003f0| 2d 53 61 6d 70 6c 65 64 22 3a 20 22 30 22 2c 20 |-Sampled": "0", |
|00000400| 0a 20 20 20 20 22 58 2d 42 33 2d 53 70 61 6e 69 |.    "X-B3-Spani|
|00000410| 64 22 3a 20 22 38 32 62 36 61 30 32 30 32 64 63 |d": "82b6a0202dc|
|00000420| 31 35 36 36 62 22 2c 20 0a 20 20 20 20 22 58 2d |1566b", .    "X-|
|00000430| 42 33 2d 54 72 61 63 65 69 64 22 3a 20 22 65 66 |B3-Traceid": "ef|
|00000440| 39 36 35 33 61 30 30 30 33 65 64 36 38 65 22 2c |9653a0003ed68e",|
|00000450| 20 0a 20 20 20 20 22 58 2d 46 6f 72 77 61 72 64 | .    "X-Forward|
|00000460| 65 64 2d 48 6f 73 74 22 3a 20 22 31 32 37 2e 30 |ed-Host": "127.0|
|00000470| 2e 30 2e 31 3a 38 31 38 31 22 2c 20 0a 20 20 20 |.0.1:8181", .   |
|00000480| 20 22 58 2d 46 6f 72 77 61 72 64 65 64 2d 50 72 | "X-Forwarded-Pr|
|00000490| 65 66 69 78 22 3a 20 22 2f 74 65 73 74 2d 73 73 |efix": "/test-ss|
|000004a0| 22 0a 20 20 7d 2c 20 0a 20 20 22 6a 73 6f 6e 22 |".  }, .  "json"|
|000004b0| 3a 20 6e 75 6c 6c 2c 20 0a 20 20 22 6d 65 74 68 |: null, .  "meth|
|000004c0| 6f 64 22 3a 20 22 47 45 54 22 2c 20 0a 20 20 22 |od": "GET", .  "|
|000004d0| 6f 72 69 67 69 6e 22 3a 20 22 31 32 37 2e 30 2e |origin": "127.0.|
|000004e0| 30 2e 31 2c 20 35 39 2e 31 35 32 2e 32 35 34 2e |0.1, 59.152.254.|
|000004f0| 32 33 38 22 2c 20 0a 20 20 22 75 72 6c 22 3a 20 |238", .  "url": |
|00000500| 22 68 74 74 70 3a 2f 2f 31 32 37 2e 30 2e 30 2e |"//127.0.0.|
|00000510| 31 3a 38 31 38 31 2f 61 6e 79 74 68 69 6e 67 22 |1:8181/anything"|
|00000520| 0a 7d 0a                                        |.}.             |
+--------+-------------------------------------------------+----------------+
2021-11-27 01:16:06,904 DEBUG [sports,,] [10632] [reactor-http-nio-2][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:1277d54e-2, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] WRITE: 207B
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 48 54 54 50 2f 31 2e 31 20 32 30 30 20 4f 4b 0d |HTTP/1.1 200 OK.|
|00000010| 0a 44 61 74 65 3a 20 53 61 74 2c 20 32 37 20 4e |.Date: Sat, 27 N|
|00000020| 6f 76 20 32 30 32 31 20 30 31 3a 31 36 3a 30 34 |ov 2021 01:16:04|
|00000030| 20 47 4d 54 0d 0a 43 6f 6e 74 65 6e 74 2d 54 79 | GMT..Content-Ty|
|00000040| 70 65 3a 20 61 70 70 6c 69 63 61 74 69 6f 6e 2f |pe: application/|
|00000050| 6a 73 6f 6e 0d 0a 53 65 72 76 65 72 3a 20 67 75 |json..Server: gu|
|00000060| 6e 69 63 6f 72 6e 2f 31 39 2e 39 2e 30 0d 0a 41 |nicorn/19.9.0..A|
|00000070| 63 63 65 73 73 2d 43 6f 6e 74 72 6f 6c 2d 41 6c |ccess-Control-Al|
|00000080| 6c 6f 77 2d 4f 72 69 67 69 6e 3a 20 2a 0d 0a 41 |low-Origin: *..A|
|00000090| 63 63 65 73 73 2d 43 6f 6e 74 72 6f 6c 2d 41 6c |ccess-Control-Al|
|000000a0| 6c 6f 77 2d 43 72 65 64 65 6e 74 69 61 6c 73 3a |low-Credentials:|
|000000b0| 20 74 72 75 65 0d 0a 63 6f 6e 74 65 6e 74 2d 6c | true..content-l|
|000000c0| 65 6e 67 74 68 3a 20 31 30 38 34 0d 0a 0d 0a    |ength: 1084.... |
+--------+-------------------------------------------------+----------------+
2021-11-27 01:16:06,904 DEBUG [sports,,] [10632] [reactor-http-nio-2][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:1277d54e-2, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] FLUSH
2021-11-27 01:16:06,909 DEBUG [sports,,] [10632] [reactor-http-nio-2][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:1277d54e-2, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] WRITE: 1084B
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 7b 0a 20 20 22 61 72 67 73 22 3a 20 7b 7d 2c 20 |{.  "args": {}, |
|00000010| 0a 20 20 22 64 61 74 61 22 3a 20 22 22 2c 20 0a |.  "data": "", .|
|00000020| 20 20 22 66 69 6c 65 73 22 3a 20 7b 7d 2c 20 0a |  "files": {}, .|
|00000030| 20 20 22 66 6f 72 6d 22 3a 20 7b 7d 2c 20 0a 20 |  "form": {}, . |
|00000040| 20 22 68 65 61 64 65 72 73 22 3a 20 7b 0a 20 20 | "headers": {.  |
|00000050| 20 20 22 41 63 63 65 70 74 22 3a 20 22 74 65 78 |  "Accept": "tex|
|00000060| 74 2f 68 74 6d 6c 2c 61 70 70 6c 69 63 61 74 69 |t/html,applicati|
|00000070| 6f 6e 2f 78 68 74 6d 6c 2b 78 6d 6c 2c 61 70 70 |on/xhtml+xml,app|
|00000080| 6c 69 63 61 74 69 6f 6e 2f 78 6d 6c 3b 71 3d 30 |lication/xml;q=0|
|00000090| 2e 39 2c 69 6d 61 67 65 2f 77 65 62 70 2c 69 6d |.9,image/webp,im|
|000000a0| 61 67 65 2f 61 70 6e 67 2c 2a 2f 2a 3b 71 3d 30 |age/apng,*/*;q=0|
|000000b0| 2e 38 22 2c 20 0a 20 20 20 20 22 41 63 63 65 70 |.8", .    "Accep|
|000000c0| 74 2d 45 6e 63 6f 64 69 6e 67 22 3a 20 22 67 7a |t-Encoding": "gz|
|000000d0| 69 70 2c 20 64 65 66 6c 61 74 65 2c 20 62 72 22 |ip, deflate, br"|
|000000e0| 2c 20 0a 20 20 20 20 22 41 63 63 65 70 74 2d 4c |, .    "Accept-L|
|000000f0| 61 6e 67 75 61 67 65 22 3a 20 22 7a 68 2d 43 4e |anguage": "zh-CN|
|00000100| 2c 7a 68 3b 71 3d 30 2e 39 22 2c 20 0a 20 20 20 |,zh;q=0.9", .   |
|00000110| 20 22 43 61 63 68 65 2d 43 6f 6e 74 72 6f 6c 22 | "Cache-Control"|
|00000120| 3a 20 22 6d 61 78 2d 61 67 65 3d 30 22 2c 20 0a |: "max-age=0", .|
|00000130| 20 20 20 20 22 43 6f 6e 74 65 6e 74 2d 4c 65 6e |    "Content-Len|
|00000140| 67 74 68 22 3a 20 22 30 22 2c 20 0a 20 20 20 20 |gth": "0", .    |
|00000150| 22 46 6f 72 77 61 72 64 65 64 22 3a 20 22 70 72 |"Forwarded": "pr|
|00000160| 6f 74 6f 3d 68 74 74 70 3b 68 6f 73 74 3d 5c 22 |oto=http;host=\"|
|00000170| 31 32 37 2e 30 2e 30 2e 31 3a 38 31 38 31 5c 22 |127.0.0.1:8181\"|
|00000180| 3b 66 6f 72 3d 5c 22 31 32 37 2e 30 2e 30 2e 31 |;for=\"127.0.0.1|
|00000190| 3a 35 32 37 39 37 5c 22 22 2c 20 0a 20 20 20 20 |:52797\"", .    |
|000001a0| 22 48 6f 73 74 22 3a 20 22 68 74 74 70 62 69 6e |"Host": "httpbin|
|000001b0| 2e 6f 72 67 22 2c 20 0a 20 20 20 20 22 55 70 67 |.org", .    "Upg|
|000001c0| 72 61 64 65 2d 49 6e 73 65 63 75 72 65 2d 52 65 |rade-Insecure-Re|
|000001d0| 71 75 65 73 74 73 22 3a 20 22 31 22 2c 20 0a 20 |quests": "1", . |
|000001e0| 20 20 20 22 55 73 65 72 2d 41 67 65 6e 74 22 3a |   "User-Agent":|
|000001f0| 20 22 4d 6f 7a 69 6c 6c 61 2f 35 2e 30 20 28 57 | "Mozilla/5.0 (W|
|00000200| 69 6e 64 6f 77 73 20 4e 54 20 31 30 2e 30 3b 20 |indows NT 10.0; |
|00000210| 57 4f 57 36 34 29 20 41 70 70 6c 65 57 65 62 4b |WOW64) AppleWebK|
|00000220| 69 74 2f 35 33 37 2e 33 36 20 28 4b 48 54 4d 4c |it/537.36 (KHTML|
|00000230| 2c 20 6c 69 6b 65 20 47 65 63 6b 6f 29 20 43 68 |, like Gecko) Ch|
|00000240| 72 6f 6d 65 2f 37 30 2e 30 2e 33 35 33 38 2e 32 |rome/70.0.3538.2|
|00000250| 35 20 53 61 66 61 72 69 2f 35 33 37 2e 33 36 20 |5 Safari/537.36 |
|00000260| 43 6f 72 65 2f 31 2e 37 30 2e 33 38 37 39 2e 34 |Core/1.70.3879.4|
|00000270| 30 30 20 51 51 42 72 6f 77 73 65 72 2f 31 30 2e |00 QQBrowser/10.|
|00000280| 38 2e 34 35 35 32 2e 34 30 30 22 2c 20 0a 20 20 |8.4552.400", .  |
|00000290| 20 20 22 58 2d 41 6d 7a 6e 2d 54 72 61 63 65 2d |  "X-Amzn-Trace-|
|000002a0| 49 64 22 3a 20 22 52 6f 6f 74 3d 31 2d 36 31 61 |Id": "Root=1-61a|
|000002b0| 31 38 36 64 34 2d 34 31 38 32 30 65 31 66 36 33 |186d4-41820e1f63|
|000002c0| 39 30 32 64 34 64 33 63 63 64 38 62 39 64 22 2c |902d4d3ccd8b9d",|
|000002d0| 20 0a 20 20 20 20 22 58 2d 42 33 2d 50 61 72 65 | .    "X-B3-Pare|
|000002e0| 6e 74 73 70 61 6e 69 64 22 3a 20 22 65 66 39 36 |ntspanid": "ef96|
|000002f0| 35 33 61 30 30 30 33 65 64 36 38 65 22 2c 20 0a |53a0003ed68e", .|
|00000300| 20 20 20 20 22 58 2d 42 33 2d 53 61 6d 70 6c 65 |    "X-B3-Sample|
|00000310| 64 22 3a 20 22 30 22 2c 20 0a 20 20 20 20 22 58 |d": "0", .    "X|
|00000320| 2d 42 33 2d 53 70 61 6e 69 64 22 3a 20 22 38 32 |-B3-Spanid": "82|
|00000330| 62 36 61 30 32 30 32 64 63 31 35 36 36 62 22 2c |b6a0202dc1566b",|
|00000340| 20 0a 20 20 20 20 22 58 2d 42 33 2d 54 72 61 63 | .    "X-B3-Trac|
|00000350| 65 69 64 22 3a 20 22 65 66 39 36 35 33 61 30 30 |eid": "ef9653a00|
|00000360| 30 33 65 64 36 38 65 22 2c 20 0a 20 20 20 20 22 |03ed68e", .    "|
|00000370| 58 2d 46 6f 72 77 61 72 64 65 64 2d 48 6f 73 74 |X-Forwarded-Host|
|00000380| 22 3a 20 22 31 32 37 2e 30 2e 30 2e 31 3a 38 31 |": "127.0.0.1:81|
|00000390| 38 31 22 2c 20 0a 20 20 20 20 22 58 2d 46 6f 72 |81", .    "X-For|
|000003a0| 77 61 72 64 65 64 2d 50 72 65 66 69 78 22 3a 20 |warded-Prefix": |
|000003b0| 22 2f 74 65 73 74 2d 73 73 22 0a 20 20 7d 2c 20 |"/test-ss".  }, |
|000003c0| 0a 20 20 22 6a 73 6f 6e 22 3a 20 6e 75 6c 6c 2c |.  "json": null,|
|000003d0| 20 0a 20 20 22 6d 65 74 68 6f 64 22 3a 20 22 47 | .  "method": "G|
|000003e0| 45 54 22 2c 20 0a 20 20 22 6f 72 69 67 69 6e 22 |ET", .  "origin"|
|000003f0| 3a 20 22 31 32 37 2e 30 2e 30 2e 31 2c 20 35 39 |: "127.0.0.1, 59|
|00000400| 2e 31 35 32 2e 32 35 34 2e 32 33 38 22 2c 20 0a |.152.254.238", .|
|00000410| 20 20 22 75 72 6c 22 3a 20 22 68 74 74 70 3a 2f |  "url": "http:/|
|00000420| 2f 31 32 37 2e 30 2e 30 2e 31 3a 38 31 38 31 2f |/127.0.0.1:8181/|
|00000430| 61 6e 79 74 68 69 6e 67 22 0a 7d 0a             |anything".}.    |
+--------+-------------------------------------------------+----------------+
2021-11-27 01:16:06,909 DEBUG [sports,,] [10632] [reactor-http-nio-6][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:6666c1d1, L:/172.168.160.198:52819 - R:httpbin.org/18.232.227.86:80] READ COMPLETE
2021-11-27 01:16:06,910 DEBUG [sports,,] [10632] [reactor-http-nio-2][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:1277d54e-2, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] FLUSH
2021-11-27 01:16:06,910 DEBUG [sports,,] [10632] [reactor-http-nio-2][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:1277d54e-2, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] WRITE: 0B
2021-11-27 01:16:06,910 DEBUG [sports,,] [10632] [reactor-http-nio-2][io.netty.util.internal.logging.AbstractInternalLogger:145]:[id:1277d54e-2, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] FLUSH


可以从日志中看出下面比较重要的信息:

  • 从抓包日志从可以得出 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,即这里的 6666c1d11277d54e (分别是作为 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 的大小:

CodecProperties.java

@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 包含的元素有:

AccessLogArgProvider.java

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 中,并且通过 AccessLogArgProviderrequestHeader 将这些 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

微信搜索“我的编程喵”关注公众号,每日一刷,轻松提升技术,斩获各种offer