锐客网

  1. 首页 > it技术 > >

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

本系列代码地址：https://github.com/JoJoTec/sp...
网关由于是所有外部用户请求的入口，记录这些请求中我们需要的元素，对于线上监控以及业务问题定位，是非常重要的。并且，在这些元素中，链路信息也是非常重要的。通过链路信息，我们可以找到请求调用全链路相关的日志。并且，网关也是大部分请求链路起始的地方，记录请求中的元素的同时，也要带上链路信息。
我们需要在网关记录每个请求的：
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.HttpServer 和 reactor.netty.http.server.HttpClient 的日志级别为 DEBUG）：






然后，再次请求我们前面实现的网关，可以看到类似于下面的日志：
2021-11-27 01:16:06,262 DEBUG [sports,,] [10632] reactor-http-nio-2:[id:1277d54e, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] READ: 466B
+-------------------------------------------------+ |0123456789abcdef |

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:[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:[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:[id:6666c1d1] REGISTERED
2021-11-27 01:16:06,437 DEBUG [sports,,] [10632] reactor-http-nio-6:[id:6666c1d1] CONNECT: httpbin.org/18.232.227.86:80
2021-11-27 01:16:06,656 DEBUG [sports,,] [10632] reactor-http-nio-6:[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:[id:6666c1d1-1, L:/172.168.160.198:52819 - R:httpbin.org/18.232.227.86:80] WRITE: 775B
+-------------------------------------------------+ |0123456789abcdef |

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:[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:[id:6666c1d1-1, L:/172.168.160.198:52819 - R:httpbin.org/18.232.227.86:80] READ: 1315B
+-------------------------------------------------+ |0123456789abcdef |

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 "http://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:[id:1277d54e-2, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] WRITE: 207B
+-------------------------------------------------+ |0123456789abcdef |

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:[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:[id:1277d54e-2, L:/127.0.0.1:8181 - R:/127.0.0.1:52797] WRITE: 1084B
+-------------------------------------------------+ |0123456789abcdef |

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:[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:[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:[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:[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，即这里的 6666c1d1 和 1277d54e (分别是作为 HttpServer 接受请求和作为 HttpClient 转发请求后台微服务)，这样其实就可以将 spring-cloud-sleuth 的链路信息与 netty 的链路信息结合在一起
这些日志很全面，但是有下面一些不好用的问题：
只能输出所有请求响应的包内容，并不能定制输出哪些内容。例如对于文件上传请求，我们其实并不想看他的请求体，但是这里无法定制化。
日志太多了，会影响我们的性能。
HttpWebHandlerAdapter 的 TRACE 日志
在系列前面文章的源码分析中，我们知道在入口的 HttpWebHandlerAdapter 中有请求与响应日志，可以通过下面的配置进行启用：



这样就能启用类似于下面的日志：
2021-11-27 01:25:28,472 TRACE [sports,,] [16188] reactor-http-nio-2:[8d5138d1-3] HTTP GET "/test-ss/anything", headers={masked}
2021-11-27 01:25:28,696 TRACE [sports,,] [16188] reactor-http-nio-2:[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:[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:[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> 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 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: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
【SpringCloud升级之路2020.0.x版-42.SpringCloudGateway 现有的可供分析的请求日志以及缺陷】微信搜索“我的编程喵”关注公众号，每日一刷，轻松提升技术，斩获各种offer：

    推荐阅读


    上一篇：Bugly不认真看文档，遇到的坑

    下一篇：php|php7安装swoole扩展