-
Notifications
You must be signed in to change notification settings - Fork 673
Description
I was investigating the way how you can configure different timeouts for WebClient. I was pretty sure that setting response timeout like this:
var finalProperties = getFinalProperties(name, properties);
var connectionProvider = ConnectionProvider.builder(name)
.maxConnections(finalProperties.getMaxConnections())
.maxLifeTime(finalProperties.getMaxConnectionLifeTime())
.pendingAcquireMaxCount(-1) // no limit
.pendingAcquireTimeout(finalProperties.getAcquireTimeout())
.metrics(finalProperties.isMetrics())
.build();
var client = HttpClient.create(connectionProvider)
.compress(true)
.wiretap(true)
.option(ChannelOption.CONNECT_TIMEOUT_MILLIS, Long.valueOf(finalProperties.getConnectionTimeout().toMillis()).intValue())
.option(ChannelOption.SO_KEEPALIVE, true)
.responseTimeout(finalProperties.getResponseTimeout());
if (finalProperties.isInsecure()) {
client = client.secure(t -> t.sslContext(createInsecureSslContext()));
}
var connector = new ReactorClientHttpConnector(client);
var webClient = WebClient.builder()
.defaultHeader(HttpHeaders.CONTENT_TYPE, MediaType.APPLICATION_JSON_VALUE)
.clientConnector(connector)
.filter(new LogbookExchangeFilterFunction(logbook));
if (finalProperties.isMetrics()) {
webClient.observationRegistry(observationRegistry);
}
I would have total time which takes from getting first bytes from server until the last one so total time of getting response back. I prepared some integration test for that using toxiproxy and wiremock:
final ToxiproxyClient toxiproxyClient = new ToxiproxyClient(TOXI_PROXY.getHost(), TOXI_PROXY.getControlPort()); final Proxy proxy = toxiproxyClient.createProxy("wiremock", "0.0.0.0:8666", "wiremock:" + "8080"); proxy.toxics() .slicer("slicer", ToxicDirection.DOWNSTREAM, 1, Duration.ofMillis(100).toMillis() * 1000);
In my test I call endpoint on Wiremock via Toxiproxy. Toxproxy is configured to reply with new bytes every 100ms. My configured timeout is 17sec. Here are wiretap logs:
2025-07-18 11:22:49.345 [main] TRACE [] o.s.w.r.f.client.ExchangeFunctions - [37e64e37] HTTP GET http://localhost:64175/albums/1/photos, headers={masked} 2025-07-18 11:22:49.650 [reactor-http-nio-2] DEBUG [] r.netty.http.client.HttpClient - [d16433fd] REGISTERED 2025-07-18 11:22:49.665 [reactor-http-nio-2] DEBUG [] r.netty.http.client.HttpClient - [d16433fd] CONNECT: localhost/127.0.0.1:64175 2025-07-18 11:22:49.667 [reactor-http-nio-2] DEBUG [] r.netty.http.client.HttpClient - [d16433fd, L:/127.0.0.1:64179 - R:localhost/127.0.0.1:64175] ACTIVE 2025-07-18 11:22:49.672 [reactor-http-nio-2] DEBUG [] r.n.http.client.HttpClientConnect - [d16433fd-1, L:/127.0.0.1:64179 - R:localhost/127.0.0.1:64175] Handler is being applied: {uri=http://localhost:64175/albums/1/photos, method=GET} 2025-07-18 11:22:49.675 [reactor-http-nio-2] DEBUG [] r.n.http.client.HttpClientOperations - [d16433fd-1, L:/127.0.0.1:64179 - R:localhost/127.0.0.1:64175] No sendHeaders() called before complete, sending zero-length header 2025-07-18 11:22:49.680 [reactor-http-nio-2] DEBUG [] r.netty.http.client.HttpClient - [d16433fd-1, L:/127.0.0.1:64179 - R:localhost/127.0.0.1:64175] WRITE: 156B +-------------------------------------------------+ | 0 1 2 3 4 5 6 7 8 9 a b c d e f | +--------+-------------------------------------------------+----------------+ |00000000| 47 45 54 20 2f 61 6c 62 75 6d 73 2f 31 2f 70 68 |GET /albums/1/ph| |00000010| 6f 74 6f 73 20 48 54 54 50 2f 31 2e 31 0d 0a 61 |otos HTTP/1.1..a| |00000020| 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 3a 20 |ccept-encoding: | |00000030| 67 7a 69 70 0d 0a 75 73 65 72 2d 61 67 65 6e 74 |gzip..user-agent| |00000040| 3a 20 52 65 61 63 74 6f 72 4e 65 74 74 79 2f 31 |: ReactorNetty/1| |00000050| 2e 32 2e 35 0d 0a 68 6f 73 74 3a 20 6c 6f 63 61 |.2.5..host: loca| |00000060| 6c 68 6f 73 74 3a 36 34 31 37 35 0d 0a 61 63 63 |lhost:64175..acc| |00000070| 65 70 74 3a 20 2a 2f 2a 0d 0a 43 6f 6e 74 65 6e |ept: */*..Conten| |00000080| 74 2d 54 79 70 65 3a 20 61 70 70 6c 69 63 61 74 |t-Type: applicat| |00000090| 69 6f 6e 2f 6a 73 6f 6e 0d 0a 0d 0a |ion/json.... | +--------+-------------------------------------------------+----------------+ 2025-07-18 11:22:49.681 [reactor-http-nio-2] DEBUG [] r.netty.http.client.HttpClient - [d16433fd-1, L:/127.0.0.1:64179 - R:localhost/127.0.0.1:64175] FLUSH 2025-07-18 11:23:05.749 [reactor-http-nio-2] DEBUG [] r.n.http.client.HttpClientOperations - [d16433fd-1, L:/127.0.0.1:64179 - R:localhost/127.0.0.1:64175] Received response (auto-read:false) : RESPONSE(decodeResult: success, version: HTTP/1.1) 2025-07-18 11:23:25.349 [reactor-http-nio-2] DEBUG [] r.n.http.client.HttpClientOperations - [d16433fd-1, L:/127.0.0.1:64179 - R:localhost/127.0.0.1:64175] Received last HTTP packet
What I've observed is:
- The read timeout isn't firing, even though it should trigger after 17 seconds.
- The read timeout is firing when timeout is set to less than 16 seconds.
- The read timeout is currently being measured from when the request is flushed until the log line 'Received response (auto-read:false)' appears. However, it should be measured until the 'Received last HTTP packet' log entry.
- There is no option to configure real readtimeout which refers to the maximum duration allowed between each network-level read operation.
- ReadTimeoutHandler does not allow to set values less than seconds
I am using reactor-netty-http:1.2.5