reactor / reactor-netty

TCP/HTTP/UDP/QUIC client/server with Reactor over Netty
https://projectreactor.io
Apache License 2.0
2.58k stars 645 forks source link

reactor.netty.http.client.HttpClient as @Bean always emit cancel signal despite success request #2182

Closed patpatpat123 closed 2 years ago

patpatpat123 commented 2 years ago

Hello Reactor Netty Team,

I wanted to start an issue observed using the reactor.netty.http.client.HttpClient

Background, the project is a Java 11 + Spring Boot 2.6.7 + Jubilee 2021.0.1, very recent as of this writing.

The issue is that reactor.netty.http.client.HttpClient as @Bean will always send a cancel signal, while using it without @Bean will not (expected)

Here is the minimal sample reproducible code. I tried my best to water it down to only two classes and one pom.

Instead of attaching a zip / linking a repo, here they are, it is really just couple of files, again, 100% reproducible.

But if you really need a repo, please let me know (but it is really just those files)

the pom

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.6.7</version>
        <relativePath/>
    </parent>

    <groupId>io.github.hakky54</groupId>
    <artifactId>java-tutorials</artifactId>
    <version>1.0.0-SNAPSHOT</version>
    <packaging>pom</packaging>

    <licenses>
        <license>
            <name>Apache License, Version 2.0</name>
            <url>http://www.apache.org/licenses/LICENSE-2.0.txt</url>
            <distribution>repo</distribution>
        </license>
    </licenses>

    <properties>
        <version.java>11</version.java>
    </properties>

    <dependencyManagement>
        <dependencies>
            <dependency>
                <groupId>org.springframework.cloud</groupId>
                <artifactId>spring-cloud-dependencies</artifactId>
                <version>2021.0.1</version>
                <type>pom</type>
                <scope>import</scope>
            </dependency>
        </dependencies>
    </dependencyManagement>

    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-webflux</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-security</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-starter-sleuth</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-sleuth-zipkin</artifactId>
        </dependency>
        <dependency>
            <groupId>io.projectreactor.netty</groupId>
            <artifactId>reactor-netty-http-brave</artifactId>
        </dependency>
        <dependency>
            <groupId>io.micrometer</groupId>
            <artifactId>micrometer-registry-prometheus</artifactId>
        </dependency>
        <dependency>
            <groupId>io.github.resilience4j</groupId>
            <artifactId>resilience4j-micrometer</artifactId>
        </dependency>
    </dependencies>

    <build>
        <plugins>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-compiler-plugin</artifactId>
                <version>3.10.1</version>
                <configuration>
                    <source>11</source>
                    <target>11</target>
                </configuration>
            </plugin>
        </plugins>
    </build>

</project>

The controller file

package com.why.cancelled;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.http.MediaType;
import org.springframework.stereotype.Controller;
import org.springframework.web.bind.annotation.PostMapping;
import org.springframework.web.bind.annotation.ResponseBody;
import org.springframework.web.reactive.function.client.WebClient;
import reactor.core.publisher.Mono;

@Controller
public class CancelledController {

    private static final Logger LOGGER = LogManager.getLogger(CancelledController.class.getName());
    private final    WebClient webClient;

    @Autowired
    public CancelledController(final WebClient webClient) {
        this.webClient = webClient;
    }

    @ResponseBody
    @PostMapping(path = "/whycancelled", consumes = MediaType.APPLICATION_JSON_VALUE, produces = MediaType.APPLICATION_JSON_VALUE)
    public Mono<String> whycancelled() {
        LOGGER.info("why cancelled when using the bean?");
        return webClient.post().uri("https://httpbin.org/post").retrieve().bodyToMono(String.class);
    }

}

The file where the issue happens

package com.why.cancelled;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.cloud.client.discovery.EnableDiscoveryClient;
import org.springframework.context.annotation.Bean;
import org.springframework.http.HttpHeaders;
import org.springframework.http.MediaType;
import org.springframework.http.client.reactive.ReactorClientHttpConnector;
import org.springframework.security.config.web.server.ServerHttpSecurity;
import org.springframework.security.web.server.SecurityWebFilterChain;
import org.springframework.web.reactive.function.client.WebClient;
import reactor.netty.http.HttpProtocol;
import reactor.netty.http.client.HttpClient;

import java.util.Map;
import java.util.function.Function;

@EnableDiscoveryClient
@SpringBootApplication
public class CancelledApplication {

    /**
     * The issue is happening here. Please run a query with the first line comment, and then another test with the second line comment.
     */
    @Bean
    public WebClient getWebClient(HttpClient httpClient) {
        return WebClient.create().mutate().defaultHeader(HttpHeaders.CONTENT_TYPE, MediaType.APPLICATION_JSON_VALUE, HttpHeaders.ACCEPT, MediaType.APPLICATION_JSON_VALUE).clientConnector(new ReactorClientHttpConnector(httpClient)).build();
//        return WebClient.create().mutate().defaultHeader(HttpHeaders.CONTENT_TYPE, MediaType.APPLICATION_JSON_VALUE, HttpHeaders.ACCEPT, MediaType.APPLICATION_JSON_VALUE).clientConnector(new ReactorClientHttpConnector(HttpClient.create().wiretap(false).metrics(true, Function.identity()).protocol(HttpProtocol.HTTP11))).build();
    }

    @Bean
    public HttpClient getHttpClient() {
        return HttpClient.create().wiretap(false).metrics(true, Function.identity()).protocol(HttpProtocol.HTTP11);
    }

    @Bean
    public SecurityWebFilterChain insecureWebFilterChain(ServerHttpSecurity http) {
        return http.csrf().disable().build();
    }

    public static void main(String[] args) {
        SpringApplication app = new SpringApplication(CancelledApplication.class);
        app.setDefaultProperties(Map.of("server.port", "8765", "spring.application.name", "cancelledapplication", "spring.sleuth.sampler.probability", "1.0", "spring.sleuth.sampler.rate", "10000", "spring.zipkin.base-url", "http://localhost:9411", "spring.zipkin.enabled", "true", "spring.zipkin.sender.type", "web"));
        app.run(args);
    }

}

Structure (screenshot)

Screen Shot 2022-04-27 at 9 54 43 PM

Run command: A curl equivalent is ok

POST http://localhost:8765/whycancelled
Content-Type: application/json

{
    "foo": "bar"
}

Case 1: the issue: (please run with )

 @Bean
    public WebClient getWebClient(HttpClient httpClient) {
        return WebClient.create().mutate().defaultHeader(HttpHeaders.CONTENT_TYPE, MediaType.APPLICATION_JSON_VALUE, HttpHeaders.ACCEPT, MediaType.APPLICATION_JSON_VALUE).clientConnector(new ReactorClientHttpConnector(httpClient)).build();
//        return WebClient.create().mutate().defaultHeader(HttpHeaders.CONTENT_TYPE, MediaType.APPLICATION_JSON_VALUE, HttpHeaders.ACCEPT, MediaType.APPLICATION_JSON_VALUE).clientConnector(new ReactorClientHttpConnector(HttpClient.create().wiretap(false).metrics(true, Function.identity()).protocol(HttpProtocol.HTTP11))).build();
    }

Case 2: the good (it is really strange, jut one single line change, reproducible 100%, please run with)

  @Bean
    public WebClient getWebClient(HttpClient httpClient) {
//        return WebClient.create().mutate().defaultHeader(HttpHeaders.CONTENT_TYPE, MediaType.APPLICATION_JSON_VALUE, HttpHeaders.ACCEPT, MediaType.APPLICATION_JSON_VALUE).clientConnector(new ReactorClientHttpConnector(httpClient)).build();
        return WebClient.create().mutate().defaultHeader(HttpHeaders.CONTENT_TYPE, MediaType.APPLICATION_JSON_VALUE, HttpHeaders.ACCEPT, MediaType.APPLICATION_JSON_VALUE).clientConnector(new ReactorClientHttpConnector(HttpClient.create().wiretap(false).metrics(true, Function.identity()).protocol(HttpProtocol.HTTP11))).build();
    }

The result of a cancelled versus not cancelled can further be hard proven when using Zipkin, which will visually show the usage of @Bean will have this cancel signal.

Screen Shot 2022-05-10 at 3 45 14 PM Screen Shot 2022-05-10 at 3 44 55 PM

I believe there is an issue there, where reactor.netty.http.client.HttpClient as @Bean should maybe not send the cancel signal.

Thank you

violetagg commented 2 years ago

@patpatpat123 @Bean is not provided by Reactor Netty. Please explain why you think this is a Reactor Netty issue.

patpatpat123 commented 2 years ago

Hello @violetagg,

Thank you for looking into this. I did think about it before posting.

So I tried using @Bean on other http clients, and none of them are emitting this cancel signal.

This cancel signal is further shown in Zipkin, and can be intercepted by https://github.com/spring-cloud/spring-cloud-sleuth/blob/3.1.x/spring-cloud-sleuth-instrumentation/src/main/java/org/springframework/cloud/sleuth/instrument/web/client/TraceExchangeFilterFunction.java#L293-L312)

Finally, please correct me if I am wrong here, I think it is the reactor.netty.http.client.HttpClient which emits the cancel even upon success.

violetagg commented 2 years ago

@patpatpat123 When you declare HttpClient as a Bean, spring-cloud-sleuth applies some instrumentation (see the stack below), when you do NOT declare HttpClient as a Bean there is no more instrumentation on the level of HttpClient. I cannot comment why at some point while Reactor Netty is delivering the result, a cancel signal is emitted, and whether it is related to the classes below: org.springframework.cloud.sleuth.instrument.web.client.HttpClientBeanPostProcessor org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber

Screenshot 2022-05-10 at 22 01 03

I'm closing the issue, if the problem appears in Reactor Netty we can reopen it.

patpatpat123 commented 2 years ago

Thank you @violetagg for looking into this.

I really though this was related to the Reactor HttpClient itself. Now very clear. Thank you again.