As far as I know, if the number of simultaneous connections reached at the maxConnections
setting, the rest of connections are accepted based on the acceptCount
setting but not processed until worker thread is available, as mentioned in docs.
So I did some experiments and the results were not what I expected.
I wrote sever side code as follow (Spring Boot 2.7.3)
@RestController
@Slf4j
public class ResponseController {
static final AtomicLong atomic = new AtomicLong(0L);
@GetMapping("/test")
public String response() throws InterruptedException {
Thread.sleep(1000);
long count = atomic.incrementAndGet();
log.info("request processed = {}", count);
return "Hello " + count;
}
}
application.yml
server:
tomcat:
max-connections: 5
accept-count: 5
threads:
max: 1
And client side code,
import java.io.IOException;
import java.net.URI;
import java.net.http.HttpClient;
import java.net.http.HttpRequest;
import java.net.http.HttpResponse.BodyHandlers;
import java.time.Duration;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Client {
static Logger log = LoggerFactory.getLogger(Client.class);
private static final HttpClient httpClient = HttpClient.newBuilder()
.version(HttpClient.Version.HTTP_1_1)
.connectTimeout(Duration.ofSeconds(20))
.build();
public static void main(String[] args) throws InterruptedException {
int NUMBER_OF_THREAD = 10;
Thread[] threads = new Thread[NUMBER_OF_THREAD];
for (int i = 0; i < NUMBER_OF_THREAD; i++) {
threads[i] = new Thread(() -> {
String result = send();
log.info("received = {}", result);
});
}
for (Thread thread : threads) {
thread.start();
Thread.sleep(50);
}
}
private static String send() {
HttpRequest request = HttpRequest.newBuilder()
.uri(URI.create("http://localhost:8080/test"))
.timeout(Duration.ofSeconds(20))
.build();
try {
log.info("send!");
return httpClient.send(request, BodyHandlers.ofString()).body();
} catch (IOException | InterruptedException e) {
log.info(e.getMessage());
throw new RuntimeException(e);
}
}
}
I expected all requests succeed, but it doesn't.
server side log
2022-09-09 01:06:05.070 INFO 14732 --- [nio-8080-exec-1] c.e.c.controller.ResponseController : request processed = 1
2022-09-09 01:06:06.125 INFO 14732 --- [nio-8080-exec-1] c.e.c.controller.ResponseController : request processed = 2
2022-09-09 01:06:07.140 INFO 14732 --- [nio-8080-exec-1] c.e.c.controller.ResponseController : request processed = 3
2022-09-09 01:06:08.154 INFO 14732 --- [nio-8080-exec-1] c.e.c.controller.ResponseController : request processed = 4
2022-09-09 01:06:09.165 INFO 14732 --- [nio-8080-exec-1] c.e.c.controller.ResponseController : request processed = 5 // 20 seceonds of idle after fifth request processed.
2022-09-09 01:06:25.496 INFO 14732 --- [nio-8080-exec-1] c.e.c.controller.ResponseController : request processed = 6
2022-09-09 01:06:26.499 INFO 14732 --- [nio-8080-exec-1] c.e.c.controller.ResponseController : request processed = 7
2022-09-09 01:06:27.508 INFO 14732 --- [nio-8080-exec-1] c.e.c.controller.ResponseController : request processed = 8
2022-09-09 01:06:28.516 INFO 14732 --- [nio-8080-exec-1] c.e.c.controller.ResponseController : request processed = 9
2022-09-09 01:06:29.523 INFO 14732 --- [nio-8080-exec-1] c.e.c.controller.ResponseController : request processed = 10
client side log
01:06:03.596 [Thread-0] INFO com.example.concurrent.client.Client - send!
01:06:03.641 [Thread-1] INFO com.example.concurrent.client.Client - send!
01:06:03.695 [Thread-2] INFO com.example.concurrent.client.Client - send!
01:06:03.750 [Thread-3] INFO com.example.concurrent.client.Client - send!
01:06:03.805 [Thread-4] INFO com.example.concurrent.client.Client - send!
01:06:03.862 [Thread-5] INFO com.example.concurrent.client.Client - send!
01:06:03.920 [Thread-6] INFO com.example.concurrent.client.Client - send!
01:06:03.973 [Thread-7] INFO com.example.concurrent.client.Client - send!
01:06:04.025 [Thread-8] INFO com.example.concurrent.client.Client - send!
01:06:04.080 [Thread-9] INFO com.example.concurrent.client.Client - send!
01:06:05.172 [Thread-4] INFO com.example.concurrent.client.Client - received = Hello 1
01:06:06.136 [Thread-3] INFO com.example.concurrent.client.Client - received = Hello 2
01:06:07.151 [Thread-0] INFO com.example.concurrent.client.Client - received = Hello 3
01:06:08.161 [Thread-1] INFO com.example.concurrent.client.Client - received = Hello 4
01:06:09.175 [Thread-2] INFO com.example.concurrent.client.Client - received = Hello 5
01:06:23.884 [Thread-5] INFO com.example.concurrent.client.Client - request timed out
Exception in thread "Thread-5" java.lang.RuntimeException: java.net.http.HttpTimeoutException: request timed out
at com.example.concurrent.client.Client.send(Client.java:49)
at com.example.concurrent.client.Client.lambda$main$0(Client.java:27)
at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.net.http.HttpTimeoutException: request timed out
at java.net.http/jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:559)
at java.net.http/jdk.internal.net.http.HttpClientFacade.send(HttpClientFacade.java:119)
at com.example.concurrent.client.Client.send(Client.java:46)
... 2 more
Caused by: java.net.http.HttpTimeoutException: request timed out
...
I can't understand why the timeout occurred on 5 requests, when the number of connections reached at maxConnection
(5), the rest of them must be queued.
According to the logs, all requests were processed fine. However, java.net.http.HttpTimeoutException occurred in client side, even though the set timeout (20 seconds) was not reached.
Why does it happened?