使用Spring WebClient实现可读的HTTP请求调试日志记录

12
我正在使用Spring响应式WebClient发送请求到一个HTTP服务器。为了查看正在发送的基础请求和响应,我启用了reactor.ipc.netty包的调试日志记录。
出站请求的标头可以正常查看。
虽然我通过http发送和接收纯文本,但是日志以以下格式(十六进制?)包含请求和响应。
我不确定如何以易于理解的方式查看已记录的数据。最好记录请求和响应以便更容易理解。
这里是已记录数据的片段。
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 47 45 54 20 2f 53 65 61 72 63 68 5f 47 43 2e 61 |GET /Search_GC.a|
|00000010| 73 70 78 20 48 54 54 50 2f 31 2e 31 0d 0a 75 73 |spx HTTP/1.1..us|
|00000020| 65 72 2d 61 67 65 6e 74 3a 20 52 65 61 63 74 6f |er-agent: Reacto|
|00000030| 72 4e 65 74 74 79 2f 30 2e 37 2e 32 2e 52 45 4c |rNetty/0.7.2.REL|
|00000040| 45 41 53 45 0d 0a 68 6f 73 74 3a 20 63 65 6f 6b |EASE..host: ceok|
|00000050| 61 72 6e 61 74 61 6b 61 2e 6b 61 72 2e 6e 69 63 |arnataka.kar.nic|
|00000060| 2e 69 6e 0d 0a 61 63 63 65 70 74 3a 20 2a 2f 2a |.in..accept: */*|
|00000070| 0d 0a 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e |..accept-encodin|
|00000080| 67 3a 20 67 7a 69 70 0d 0a 63 6f 6e 74 65 6e 74 |g: gzip..content|
|00000090| 2d 6c 65 6e 67 74 68 3a 20 30 0d 0a 0d 0a       |-length: 0....  |
+--------+-------------------------------------------------+----------------+

发现一个无人回答的问题,这可能是由于同一库引起的:读取包含PooledUnsafeDirectByteBuf的HttpContent内容 在此提出一个问题:点此 似乎有一种非正统观点认为,对于响应式客户端来说,不需要调试。然而,我们使用诸如rest clientpostmancurlhttpie等工具发送请求和查看响应,这个观点完全没有意义。

你可以在中间放置像MembraneSoa这样的代理。 - Marged
不确定通过特殊代理调试应用程序请求会有多大用处。 - Ashok Koyi
可能是如何在Spring WebFlux中记录请求和响应体的重复问题。 - Abhijit Sarkar
1
你找到了好的解决方案吗? - membersound
@membersound 是的,我找到了一个好的解决方案,请看我的回答。 - Honza Zidek
1
@AbhijitSarkar,我不同意你的观点,你所引用的问题是关于拦截请求/响应和/或实现任何用户定义日志记录的一般机制,而这个问题是关于如何配置内置低级日志记录机制的格式。 - Honza Zidek
3个回答

5

我升级到io.projectreactor.netty:reactor-netty-http:1.0.5后,他们改变了reactor.netty.http.client.HttpClient类,在以下代码中,可以编译并且运行得到预期的结果。(我不确定哪个是最小版本,我是从较旧的版本进行升级的,但我猜测它是1.0.0。这里是一个传递依赖项,我将spring-boot-starter-webflux2.3.4.RELEASE升级到2.4.4。)

关键部分是调用wiretap()

wiretap("reactor.netty.http.client.HttpClient", LogLevel.DEBUG, AdvancedByteBufFormat.TEXTUAL, StandardCharsets.UTF_8)

它还记录请求和响应的头部和主体。

整个上下文如下:

package com.example;

import io.netty.handler.logging.LogLevel;
import lombok.AllArgsConstructor;
import lombok.Builder;
import lombok.Data;
import lombok.NoArgsConstructor;
import lombok.extern.slf4j.Slf4j;
import org.junit.jupiter.api.Test;
import org.springframework.http.HttpMethod;
import org.springframework.http.MediaType;
import org.springframework.http.client.reactive.ReactorClientHttpConnector;
import org.springframework.web.reactive.function.BodyInserters;
import org.springframework.web.reactive.function.client.WebClient;
import reactor.core.publisher.Mono;
import reactor.netty.http.client.HttpClient;
import reactor.netty.transport.logging.AdvancedByteBufFormat;

import java.nio.charset.StandardCharsets;

@Slf4j
class RestClientTest {
    private WebClient createWebClient() {
        final HttpClient httpClient = HttpClient.create()
                .wiretap(HttpClient.class.getCanonicalName(), LogLevel.DEBUG, AdvancedByteBufFormat.TEXTUAL, StandardCharsets.UTF_8);
        return WebClient.builder()
                .clientConnector(new ReactorClientHttpConnector(httpClient))
                .build();
    }

    @Data
    @Builder
    @NoArgsConstructor
    @AllArgsConstructor
    private static class User {
        int id;
        int userId;
        String title;
        String body;
    }

    @Test
    void createUsersReactive() {
        final WebClient webClient = createWebClient();
        final String url = "http://jsonplaceholder.typicode.com/posts";
        final Mono<User> userMono = webClient.method(HttpMethod.POST)
                .uri(url)
                .contentType(MediaType.APPLICATION_JSON_UTF8)
                .header("X-My-Header", "MyValue1", "MyValue2")
                .body(BodyInserters.fromValue(User.builder().userId(1).title("foo").body("bar").build()))
                .retrieve()
                .bodyToMono(User.class);
        final User user = userMono.block();
        log.info("Created user: " + user);
    }
}

而且日志输出是符合您要求的易于阅读的格式:

... reactor.netty.http.client.HttpClient     : [id:e7d7ed93] REGISTERED
... reactor.netty.http.client.HttpClient     : [id:e7d7ed93] CONNECT: jsonplaceholder.typicode.com/<unresolved>:80
... reactor.netty.http.client.HttpClient     : [id:e7d7ed93] ACTIVE
... r.netty.http.client.HttpClientConnect    : [id:e7d7ed93-1] Handler is being applied: {uri=http://jsonplaceholder.typicode.com/posts, method=POST}
... reactor.netty.http.client.HttpClient     : [id:e7d7ed93-1] WRITE: 217B POST /posts HTTP/1.1
user-agent: ReactorNetty/1.0.5
host: jsonplaceholder.typicode.com
accept: */*
Content-Type: application/json;charset=UTF-8
X-My-Header: MyValue1
X-My-Header: MyValue2
content-length: 46


... reactor.netty.http.client.HttpClient     : [id:e7d7ed93-1] WRITE: 46B {"id":0,"userId":1,"title":"foo","body":"bar"}
... reactor.netty.http.client.HttpClient     : [id:e7d7ed93-1] FLUSH
... reactor.netty.http.client.HttpClient     : [id:e7d7ed93-1] READ: 1347B HTTP/1.1 201 Created
Date: Tue, 13 Apr 2021 12:49:33 GMT
Content-Type: application/json; charset=utf-8
Content-Length: 65
X-Powered-By: Express
X-Ratelimit-Limit: 1000
X-Ratelimit-Remaining: 999
X-Ratelimit-Reset: 1618318233
Vary: Origin, X-HTTP-Method-Override, Accept-Encoding
Access-Control-Allow-Credentials: true
Cache-Control: no-cache
Pragma: no-cache
Expires: -1
Access-Control-Expose-Headers: Location
Location: http://jsonplaceholder.typicode.com/posts/101
X-Content-Type-Options: nosniff
Etag: W/"41-0LtsWqhuQ7Zsjlj0tYnOrT/Vw5o"
Via: 1.1 vegur
CF-Cache-Status: DYNAMIC
cf-request-id: 096ce0bd560000736722853000000001
Report-To: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report?s=laAKjgGcoi8SLu%2F6VX5pQIAksdmj9xi31elC5Ld97eljznKIpYjdkQsittoMJp3lJoQIwOACmj89bKSa%2Ff15gRHRmyasV2Xcl%2FmVjJBJm7ytbWocp39UBd90JwVM"}],"max_age":604800,"group":"cf-nel"}
NEL: {"max_age":604800,"report_to":"cf-nel"}
Server: cloudflare
CF-RAY: 63f4d0a88ed07367-CPH
alt-svc: h3-27=":443"; ma=86400, h3-28=":443"; ma=86400, h3-29=":443"; ma=86400
Proxy-Connection: Keep-Alive
Connection: Keep-Alive
Set-Cookie: __cfduid=d11c86fbd953f7cf768cf7db0c346f22b1618318173; expires=Thu, 13-May-21 12:49:33 GMT; path=/; domain=.typicode.com; HttpOnly; SameSite=Lax

{
  "id": 101,
  "userId": 1,
  "title": "foo",
  "body": "bar"
}
... r.n.http.client.HttpClientOperations     : [id:e7d7ed93-1] Received response (auto-read:false) : [Date=Tue, 13 Apr 2021 12:49:33 GMT, Content-Type=application/json; charset=utf-8, X-Powered-By=Express, X-Ratelimit-Limit=1000, X-Ratelimit-Remaining=999, X-Ratelimit-Reset=1618318233, Vary=Origin, X-HTTP-Method-Override, Accept-Encoding, Access-Control-Allow-Credentials=true, Cache-Control=no-cache, Pragma=no-cache, Expires=-1, Access-Control-Expose-Headers=Location, Location=http://jsonplaceholder.typicode.com/posts/101, X-Content-Type-Options=nosniff, Etag=W/"41-0LtsWqhuQ7Zsjlj0tYnOrT/Vw5o", Via=1.1 vegur, CF-Cache-Status=DYNAMIC, cf-request-id=096ce0bd560000736722853000000001, Report-To={"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report?s=laAKjgGcoi8SLu%2F6VX5pQIAksdmj9xi31elC5Ld97eljznKIpYjdkQsittoMJp3lJoQIwOACmj89bKSa%2Ff15gRHRmyasV2Xcl%2FmVjJBJm7ytbWocp39UBd90JwVM"}],"max_age":604800,"group":"cf-nel"}, NEL={"max_age":604800,"report_to":"cf-nel"}, Server=cloudflare, CF-RAY=63f4d0a88ed07367-CPH, alt-svc=h3-27=":443"; ma=86400, h3-28=":443"; ma=86400, h3-29=":443"; ma=86400, Proxy-Connection=Keep-Alive, Connection=Keep-Alive, Set-Cookie=__cfduid=d11c86fbd953f7cf768cf7db0c346f22b1618318173; expires=Thu, 13-May-21 12:49:33 GMT; path=/; domain=.typicode.com; HttpOnly; SameSite=Lax, content-length=65]
... r.n.http.client.HttpClientOperations     : [id:e7d7ed93-1] Received last HTTP packet
... reactor.netty.http.client.HttpClient     : [id:e7d7ed93] READ COMPLETE
... com.example.RestClientTest              : Created user: RestClientIT.User(id=101, userId=1, title=foo, body=bar)

有没有办法访问Wiretap写入控制台的数据?我需要将响应保存到我的数据库中。 - Maxi

0

如果您使用DataBuffer作为读取器,可以使用doOnNext()来完成:

public Mono<ServerResponse> selectByPost(ServerRequest request) {
  Flux<DataBuffer> requestBodyFlux = request.bodyToFlux(DataBuffer.class)
    .doOnNext(dataBuffer -> {
      if (debug ) {
        log.debug(new String(dataBuffer.asByteBuffer().array()));
      }
      Scannable.from(dataBuffer).tags().forEach(System.out::println);
    });
}

这可能不是最好的方法,当然,如果Netty提供了不同的记录有效负载的方式,那将是一个很好的功能。十六进制具有其优点,具体取决于您需要调试的内容。


现在Netty提供了一种更优雅的方式,详见我的回答。 - Honza Zidek

-4

看起来响应服务器正在返回gzipped内容,所以你无法读取它是有道理的。

如果您真的想在原始HTTP级别拦截,请确保您的请求标头不指定可以接受GZipped内容(accept-encoding:gzip)。

另一种选择可能是在另一层记录请求,当它已经从原始数据流中解压缩,但尚未被您的应用程序代码处理 - 不确定这在反应式Web客户端中如何工作 ;)


1
不,即使我的请求正文是纯文本也是那种格式。 - Ashok Koyi
您提供的正文可能是纯文本,但Spring客户端会在将其放入线路之前应用一些魔法来最小化开销/带宽。不确定是否可以禁用GZipping。 - Frederik Heremans
1
这里我们在客户端使用Spring。客户端是否可以在不知道服务器能力的情况下以gzip格式发送数据?或者客户端是否允许以gzip格式发送请求?我认为gzip不是问题所在。我的假设是他们将其打印成一些十六进制格式,以涵盖二进制和文本请求体用例。 - Ashok Koyi
这不是压缩的 - 这只是以ASCII和十六进制格式显示的请求... - Brian Clozel

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接