Skip to content

Slow first request of Spring's WebClient caused by Netty Reactor Http Client #4208

@antonov-aa2702

Description

@antonov-aa2702

Hello team. I'm building an application that needs to call another microservice and I want to ensure the lowest possible latency.

On the first try I saw that the first call to the netty version was much slower than
simple ones based on a curl.
I added warmup functionality, but it didn't help much.
Is there anything else I can do to optimize first call performance?

Expected Behavior

The difference between the first and second request is not that big.

Actual Behavior

web client configuration

@Bean
WebClient webClient(Some properties properties) throws Exception {
    log.info("Initializing WebClient Bean");
    final var sslContext = getSslContext();
    HttpClient httpClient = HttpClient.create()
        .secure(sslContextSpec -> sslContextSpec.sslContext(sslContext));
    httpClient.warmup().block();
    ClientHttpConnector connector = new ReactorClientHttpConnector(httpClient);
    WebClient webClient = WebClient.builder()
        .baseUrl(properties.getUrl().getBase())
        .clientConnector(connector)
        .build();
    log.info("WebClient initialized");
    return webClient;
}

sending a request

    public byte[] decryptAndVerify(byte[] message, String user, String password) {
        log.trace("Calling Some service for decryption and verification. Message: {}", message);
        final var messageInBase64 = Base64.getEncoder().encodeToString(message);
        final var body = new SomeRequest().setPayload(messageInBase64);
        final var response = webClient.post()
                .uri(properties.getUrl().getDecryptAndVerify())
                .bodyValue(body)
                .headers(h -> h.setBasicAuth(user, password))
                .retrieve()
                .bodyToMono(SomeResponse.class)
                .doOnError(e -> {
                    log.error("Error calling Some service for decryption and verification: " + e.getMessage(), e);
                    throw new CryptoException(e.getMessage());
                })
                .block();
        final var decryptedMessageInBase64 = Objects.requireNonNull(response).getDecryptedMessage();
        final var decryptedMessage = Base64.getDecoder().decode(decryptedMessageInBase64);
        log.info("Successful Some service decryption and verification, url: {}",
                properties.getUrl().getBase() + properties.getUrl().getDecryptAndVerify());
        return decryptedMessage;
    }
}

warmup functionality

2026-05-06 06:04:27,550 INFO  com.example.demo :  Initializing WebClient Bean
2026-05-06 06:04:27,871 DEBUG reactor.netty.tcp.TcpResources :  [http] resources will use the default LoopResources: DefaultLoopResources {prefix=reactor-http, daemon=true, selectCount=40, workerCount=40}
2026-05-06 06:04:27,872 DEBUG reactor.netty.tcp.TcpResources :  [http] resources will use the default ConnectionProvider: reactor.netty.resources.DefaultPooledConnectionProvider@403adc49
2026-05-06 06:04:27,926 DEBUG reactor.netty.resources.DefaultLoopIOUring :  Default io_uring support : false
2026-05-06 06:04:28,430 DEBUG reactor.netty.resources.DefaultLoopEpoll :  Default Epoll support : true
2026-05-06 06:04:30,579 INFO com.example.demo :  WebClient initialized

first request 2.5-3.5 seconds on average

2026-05-06 06:05:28,819 TRACE com.example.demo : Calling Some service for decryption and verification.
2026-05-06 06:05:29,242 DEBUG reactor.netty.resources.PooledConnectionProvider : trnId=B6126060527499010B10120011760501 Creating a new [http] client pool [PoolFactory{evictionInterval=PT0S, leasingStrategy=fifo, maxConnections=500, maxIdleTime=-1, maxLifeTime=-1, metricsEnabled=false, pendingAcquireMaxCount=1000, pendingAcquireTimeout=45000}] for [some.host.example/<unresolved>:8443]
2026-05-06 06:05:29,614 DEBUG reactor.netty.resources.PooledConnectionProvider :  [8ecf25df] Created a new pooled channel, now: 0 active connections, 0 inactive connections 0 pending acquire requests.
2026-05-06 06:05:29,684 DEBUG reactor.netty.tcp.SslProvider :  [8ecf25df] SSL enabled using engine SSLEngine[hostname=some.host.example, port=8443, Session(1778047529665|SSL_NULL_WITH_NULL_NULL)] and SNI some.host.example/<unresolved>:8443
2026-05-06 06:05:29,797 DEBUG reactor.netty.transport.TransportConfig :  [8ecf25df] Initialized pipeline DefaultChannelPipeline{(reactor.left.sslHandler = io.netty.handler.ssl.SslHandler), (reactor.left.sslReader = reactor.netty.tcp.SslProvider$SslReadHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2026-05-06 06:05:30,220 DEBUG reactor.netty.transport.TransportConnector :  [8ecf25df] Connecting to [some.host.example/20.20.20.20:20].
2026-05-06 06:05:30,246 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] Registering pool release on close event for channel
2026-05-06 06:05:30,249 DEBUG reactor.netty.resources.PooledConnectionProvider :  [8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] Channel connected, now: 1 active connections, 0 inactive connections 0 pending acquire requests.
2026-05-06 06:05:30,454 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(PooledConnection{channel=[id: 0x8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}, [connected])
2026-05-06 06:05:30,531 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [8ecf25df-1, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(GET{uri=/, connection=PooledConnection{channel=[id: 0x8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [configured])
2026-05-06 06:05:30,537 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [8ecf25df-1, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(POST{uri=/api/v2/some-url, connection=PooledConnection{channel=[id: 0x8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [request_prepared])
2026-05-06 06:05:30,745 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [8ecf25df-1, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(POST{uri=/api/v2/some-url, connection=PooledConnection{channel=[id: 0x8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [request_sent])
2026-05-06 06:05:30,944 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [8ecf25df-1, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(POST{uri=/api/v2/some-url, connection=PooledConnection{channel=[id: 0x8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [response_received])
2026-05-06 06:05:31,080 DEBUG reactor.netty.channel.FluxReceive :  [8ecf25df-1, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] [terminated=false, cancelled=false, pending=0, error=null]: subscribing inbound receiver
2026-05-06 06:05:31,111 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(POST{uri=/api/v2/some-url, connection=PooledConnection{channel=[id: 0x8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [response_completed])
2026-05-06 06:05:31,113 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(POST{uri=/api/v2/some-url, connection=PooledConnection{channel=[id: 0x8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [disconnecting])
2026-05-06 06:05:31,113 INFO  com.example.demo : trnId=B6126060527499010B10120011760501 Successful Some service decryption and verification, url: https://some.host.example:8443/api/v2/some-url
2026-05-06 06:05:31,113 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] Releasing channel
2026-05-06 06:05:31,130 DEBUG reactor.netty.resources.PooledConnectionProvider :  [8ecf25df, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] Channel cleaned, now: 0 active connections, 1 inactive connections 0 pending acquire requests.

second request 0.1-0.3 seconds on average

2026-05-06 06:09:09,157 TRACE com.example.demo : Calling Some service for decryption and verification.
2026-05-06 06:09:09,166 DEBUG reactor.netty.resources.PooledConnectionProvider :  [815e3e4e] Created a new pooled channel, now: 0 active connections, 0 inactive connections 0 pending acquire requests.
2026-05-06 06:09:09,167 DEBUG reactor.netty.tcp.SslProvider : [815e3e4e] SSL enabled using engine SSLEngine[hostname=some.host.example, port=8443, Session(1778047749167|SSL_NULL_WITH_NULL_NULL)] and SNI some.host.example/<unresolved>:8443
2026-05-06 06:09:09,169 DEBUG reactor.netty.transport.TransportConfig :  [815e3e4e] Initialized pipeline DefaultChannelPipeline{(reactor.left.sslHandler = io.netty.handler.ssl.SslHandler), (reactor.left.sslReader = reactor.netty.tcp.SslProvider$SslReadHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2026-05-06 06:09:09,190 DEBUG reactor.netty.transport.TransportConnector :  [815e3e4e] Connecting to [some.host.example/20.20.20.20:20].
2026-05-06 06:09:09,194 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] Registering pool release on close event for channel
2026-05-06 06:09:09,194 DEBUG reactor.netty.resources.PooledConnectionProvider :  [815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] Channel connected, now: 1 active connections, 0 inactive connections 0 pending acquire requests.
2026-05-06 06:09:09,233 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(PooledConnection{channel=[id: 0x815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}, [connected])
2026-05-06 06:09:09,234 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [815e3e4e-1, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(GET{uri=/, connection=PooledConnection{channel=[id: 0x815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [configured])
2026-05-06 06:09:09,235 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [815e3e4e-1, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(POST{uri=/api/v2/some-url, connection=PooledConnection{channel=[id: 0x815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [request_prepared])
2026-05-06 06:09:09,242 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [815e3e4e-1, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(POST{uri=/api/v2/some-url, connection=PooledConnection{channel=[id: 0x815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [request_sent])
2026-05-06 06:09:09,263 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [815e3e4e-1, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(POST{uri=/api/v2/some-url, connection=PooledConnection{channel=[id: 0x815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [response_received])
2026-05-06 06:09:09,266 DEBUG reactor.netty.channel.FluxReceive :  [815e3e4e-1, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] [terminated=false, cancelled=false, pending=0, error=null]: subscribing inbound receiver
2026-05-06 06:09:09,270 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(POST{uri=/api/v2/some-url, connection=PooledConnection{channel=[id: 0x815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [response_completed])
2026-05-06 06:09:09,271 INFO  com.example.demo : Successful Some service decryption and verification, url: https://some.host.example:8443/api/v2/some-url
2026-05-06 06:09:09,271 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] onStateChange(POST{uri=/api/v2/some-url, connection=PooledConnection{channel=[id: 0x815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20]}}, [disconnecting])
2026-05-06 06:09:09,271 DEBUG reactor.netty.resources.DefaultPooledConnectionProvider :  [815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] Releasing channel
2026-05-06 06:09:09,272 DEBUG reactor.netty.resources.PooledConnectionProvider :  [815e3e4e, L:/10.10.10.10:10 - R:some.host.example/20.20.20.20:20] Channel cleaned, now: 0 active connections, 1 inactive connections 0 pending acquire requests.

sending a request using CURL

curl -k -s -o /dev/null -w "namelookup:%{time_namelookup} connect:%{time_connect} appconnect:%{time_appconnect} starttransfer:%{time_starttransfer} total:%{time_total}\n" "https://some.host.example:443/someApi"

received response

namelookup:0.005330 connect:0.008379 appconnect:0.033125 starttransfer:0.065702 total:0.066037  

Steps to Reproduce

We cannot reproduce this in our test environment.

Your Environment

  • Reactor version(s) used: 1.2.12
  • Spring Boot: 3.5.8
  • JVM version (java -version): openjdk version "17.0.18" 2026-01-20 LTS
    OpenJDK Runtime Environment (build 17.0.18+10-LTS)
    OpenJDK 64-Bit Server VM (build 17.0.18+10-LTS, mixed mode)
  • OS and version (eg. uname -a): Linux pod-id 6.8.0-106-generic HttpServerOptions compression threshold is ignored, always compressing #106-Ubuntu SMP PREEMPT_DYNAMIC Fri Mar 6 07:58:08 UTC 2026 x86_64 GNU/Linux

Metadata

Metadata

Assignees

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions