@yarel: Pomysł z podziałem na krótkie i długie zapytania jest jak najbardziej ciekawy i zaraz to sobie przemyślę a tym czasem podrzucę mój pomysł który zaimplementowałem. Znalazłem taki artykuł:
https://nickebbitt.github.io/blog/2017/03/22/async-web-service-using-completable-future
Muszę to testować na jakichś mniejszych obciążeniach które sam jestem wstanie wygenerować więc ustawiłem sobie pulę wątków dla Tomcata w Spring boot na 2 wątki.
Kopiuj
server:
port: 9095
tomcat:
max-threads: 2
Zaimplementowałem najpierw zwykły kontroler. Kontroler dostaje jakieś ID i zwraca customera z bazy ale żeby móc testować to podczas walidacji wątek jest usypiany na 1 sekundę a podczas pobierania z bazy danych na 3 sekundy. Cała operacja więc od przyjęcia ID do zwrócenia customera trwa 4 sekundy. Jeśli przyjdą 2 requesty to mając pulę 2 wątków obsłużone zostaną oba jednocześnie w ciągu 4 sekund. Jeśli trafią się 4 zapytania to pierwsze 2 będą zwrócone po 4 sekundach a 2 następne będą czekały w kolejce (najpierw czekają na zakończenie poprzednich 4 sekundy + 4 sekundy podczas wykonywania operacji = łącznie 8s). Itd itd.
Kopiuj
@GetMapping("/customer2/{id}")
ResponseEntity<Customer> getById2(@PathVariable long id) throws InterruptedException {
logger.info("Request received");
dataValidation();
Customer customer = fetchFromDbSync(id);
logger.info("Servlet thread released");
return ResponseEntity.ok(customer);
}
private void dataValidation() throws InterruptedException {
logger.info("Start data validation");
//some important operation
TimeUnit.SECONDS.sleep(1);
logger.info("Completed data validation");
}
private Customer fetchFromDbSync(long id) throws InterruptedException {
logger.info("Start processing request");
//imitation of long db operation
TimeUnit.SECONDS.sleep(3);
Customer customer = repository.findById(id);
logger.info("Completed processing request");
return customer;
}
Zrobiłem test Apache Bench:
Kopiuj
ab -n 10 -c 10 http://localhost:9095/customer2/2
10 zapytań na 10 wątkach więc 8 będzie wrzuconych do kolejki.
Wynik jest taki:
Pierwszy request jest najkrótszy - 4 sekundy a każdy kolejny trwa dłużej ponieważ wszystko jest synchroniczne.
Natomiast jak zmodyfikowałem metodę kontrolera:
Kopiuj
@GetMapping("/async/customer2/{id}")
CompletableFuture<ResponseEntity<Customer>> asyncGetById2(@PathVariable long id) throws InterruptedException {
logger.info("Request received");
dataValidation();
CompletableFuture<Customer> completableFuture =
CompletableFuture.supplyAsync(() -> fetchFromDbSync(id));
logger.info("Servlet thread released");
return completableFuture
.thenApplyAsync(ResponseEntity::ok);
}
To wynik jest znacznie lepszy:
Najkrótszy request zajął 5 sekund (pewnie dlatego że jak metoda fetchFromDbSync zakończyła działanie to wynik nie mógł być zwrócony ponieważ wszystkie wątki były zajęte) ale za to łączny czas wykonania wszystkich requestów spadł do 8 sekund (poprzednio było 20 s) a średni czas wyniósł 6 sekund na request (wcześniej było 12s).
Jak się przejrzy logi:
2018-11-13 14:08:16.674 INFO 22188 --- [nio-9095-exec-1] c.t.customer.AsyncCustomerController : Request received
2018-11-13 14:08:16.674 INFO 22188 --- [nio-9095-exec-1] c.t.customer.AsyncCustomerController : Start data validation
2018-11-13 14:08:16.674 INFO 22188 --- [nio-9095-exec-2] c.t.customer.AsyncCustomerController : Request received
2018-11-13 14:08:16.674 INFO 22188 --- [nio-9095-exec-2] c.t.customer.AsyncCustomerController : Start data validation
2018-11-13 14:08:17.675 INFO 22188 --- [nio-9095-exec-2] c.t.customer.AsyncCustomerController : Completed data validation
2018-11-13 14:08:17.675 INFO 22188 --- [nio-9095-exec-1] c.t.customer.AsyncCustomerController : Completed data validation
2018-11-13 14:08:17.675 INFO 22188 --- [nio-9095-exec-2] c.t.customer.AsyncCustomerController : Servlet thread released
2018-11-13 14:08:17.675 INFO 22188 --- [nPool-worker-13] c.t.customer.AsyncCustomerController : Start processing request
2018-11-13 14:08:17.675 INFO 22188 --- [nio-9095-exec-1] c.t.customer.AsyncCustomerController : Servlet thread released
2018-11-13 14:08:17.675 INFO 22188 --- [onPool-worker-8] c.t.customer.AsyncCustomerController : Start processing request
2018-11-13 14:08:17.677 INFO 22188 --- [nio-9095-exec-2] c.t.customer.AsyncCustomerController : Request received
2018-11-13 14:08:17.677 INFO 22188 --- [nio-9095-exec-1] c.t.customer.AsyncCustomerController : Request received
2018-11-13 14:08:17.677 INFO 22188 --- [nio-9095-exec-2] c.t.customer.AsyncCustomerController : Start data validation
2018-11-13 14:08:17.677 INFO 22188 --- [nio-9095-exec-1] c.t.customer.AsyncCustomerController : Start data validation
...
To wygląda na to że wszystkie operacje wykonywane są na wątku 1 i 2 a zapytanie do bazy danych jest asynchroniczne i wątek nie czeka na odpowiedź z bazy tylko zaczyna obsługiwać kolejne zapytanie (Request received).
Nie wiem czy mój tok rozumowania jest poprawny ale wydaje mi się że działa tak jak bym chciał. Pytanie tylko czy w takim podejściu przy dużej liczbie zapytań ta asynchroniczność nie wyjdzie bokiem i wszystko się nie rozjedzie?