Tomcat > 성능 튜닝을 위한 사전 학습

행복한 코딩 생활을 방해하는, 잊을만하면 다시 찾아와 괴롭게 만드는 웹 서버 이슈 정말 싫다. 이제 공부 좀 해야겠다.

학습 대상

• Embedded Tomcat 9.0.70 (Spring Boot 2.7.7)

톰캣 9의 특징

• BIO(Java Blocking Connector)가 삭제되고 기본적으로 NIO(Java Nio Connector)가 사용됨
  • https://tomcat.apache.org/tomcat-8.0-doc/config/http.html#Connector_Comparison
  • https://tomcat.apache.org/tomcat-9.0-doc/config/http.html#Connector_Comparison
  • BIO와 NIO의 차이점은 추후에 알아보겠다.
  • NIO와 NIO2의 차이점은 추후에 알아보겠다.

준비

서버

서블릿 기반의 웹 API 서버 준비

• org.springframework.boot:spring-boot-starter-web 의존성 추가

클라이언트

• curl
  
  • RestTemplate, ab(Apache HTTP server benchmarking tool)는 예상한대로 동작하지 않음.
    • 서버에서 요청이 동시 처리되지 않고 순차 처리됨.

Q1. 해당 버전의 톰캣의 기본 커넥터가 NIO가 맞는가?

Root logger의 로깅 레벨을 debug로 변경하면

logging:
  level:
    root: debug

 

아래와 같은 로그를 통해 NIO 커넥터를 사용하고 있다는 것을 알 수 있다.

[ main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol port=8080)
[ main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol bindOnInit=false)
[ main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.NioEndpoint bindOnInit=false)
[ main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol maxPostSize=2097152)
[ main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.NioEndpoint maxPostSize=2097152)

 

좀 더 명확하게 확인해보자.

스프링 부트의 내장 톰캣은 TomcatServletWebServerFactory에 의해 설정되는데, 코드 상으로 기본 프로토콜이 다음과 같다.

 

Q2. 내장 톰캣의 기본 값이 외장 톰캣의 기본 값, 즉 레퍼런스 상의 설명과 동일한가?

레퍼런스(https://tomcat.apache.org/tomcat-9.0-doc/config/http.html)와 org.springframework.boot.autoconfigure.web.ServerProperties 파일의 기본 값을 비교해보면 동일함을 확인할 수 있다.

(IntelliJ IDEA로 application.yml을 열어 Control + Space를 눌러서 나오는 화면을 봐도 됨)

 

그런데 스프링 프라퍼티 중 server.tomcat.connection-timeout은 기본값 설정이 되어 있지 않다. 레퍼런스에서는 "한 커넥션을 받아들인 후 요청 URI 라인이 나타날 때까지 커넥터가 기다릴 시간"이라고 적혀있다. 그리고 60000(60초)이 기본값이다. 하지만 표준 server.xml에 기설정되어 있는 값은 20000(20초)이다.

Q3. 톰캣은 쓰레드 풀을 사용하여 요청을 처리한다. ThreadPoolExecutor라는 이름의 클래스가 2개 검색되는데, 어느 것이 사용되는 걸까?

• java.util.concurrent.ThreadPoolExecutor
• org.apache.tomcat.util.threads.ThreadPoolExecutor

애플리케이션을 실행하면 둘 다 사용된다. 하지만 디버깅해보면 내장 톰캣 실행을 위해 사용되는 것은 org.apache.tomcat.util.threads.ThreadPoolExecutor이다.

 

NioEndPoint 클래스의 createExecutor 메서드에서 ThreadPoolExecutor가 생성되는데, 특이사항은 keepAliveTime은 60초로 하드코딩된다는 것이다.

스프링 프라퍼티의 기본값

server:
  tomcat:
    max-connections: 8192
    accept-count: 100
    connection-timeout: 20s # 60s
    threads:
      max: 200
      min-spare: 10

 

참고로 server.xml에 설정한 것과 다르게 connection-timeout은 Duration 타입이므로 20000 대신에 20s로 설정할 수 있다. (훌륭해!)

각 프라퍼티에 대응하는 ThreadPoolExecutor의 속성

• corePoolSize: server.tomcat.threads.min-spare
• maximumPoolSize: server.tomcat.threads.max
• keepAliveTime: 60초 (하드코딩. 수정 불가)
  • when the number of threads is greater than the core, this is the maximum time that excess idle threads will wait for new tasks before terminating.

테스트 1. maxConnections 1, maxThreads 1, Concurrent request 2

3초의 작업을 수행하는 API 애플리케이션이 있다고 가정하자. (해당 API의 로직은 3초간 Sleep을 주어 조건을 시뮬레이션한다.)

그리고 해당 서버의 설정을 조금씩 변경하면서 동작 방식을 확인해볼 것이다.

서버 설정

server:
  tomcat:
    max-connections: 1
    connection-timeout: 20s
    threads:
      max: 1

이제 서버는 1개의 커넥션만 처리할 수 있고, 1개의 쓰레드만 사용할 수 있다.

클라이언트의 요청

클라이언트는 동시에 2개의 요청을 API 서버로 보낸다. (터미널을 2개 열어 동시에 실행)

curl localhost:8080/request

 

서버 로그

2023-11-29 07:53:49,855 [nio-8080-exec-1] 요청 시작
2023-11-29 07:53:52,875 [nio-8080-exec-1] 요청 끝. 응답시간: 3.00512875초
2023-11-29 07:53:53,068 [nio-8080-exec-1] 요청 시작
2023-11-29 07:53:56,073 [nio-8080-exec-1] 요청 끝. 응답시간: 3.004014375초

요청을 처리하는 데 3초가 걸렸고 두 요청 간 약 3초의 간격이 있다.

예상 가능한 결과다.

테스트 2. maxConnections 2, maxThreads 1, Concurrent request 2

server:
  tomcat:
    max-connections: 2
    connection-timeout: 20s
    threads:
      max: 1

 

2023-11-29 07:55:23,892 [nio-8080-exec-1] 요청 시작
2023-11-29 07:55:26,908 [nio-8080-exec-1] 요청 끝. 응답시간: 3.002739959초
2023-11-29 07:55:27,086 [nio-8080-exec-1] 요청 시작
2023-11-29 07:55:30,091 [nio-8080-exec-1] 요청 끝. 응답시간: 3.005106042초

테스트 1과 동일하다. 이는 커넥션은 2개여서 2개의 요청을 동시에 수락할 수 있지만, 일할 쓰레드가 1개이기 때문이다.

테스트 3. maxConnections 2, maxThreads 2, Concurrent request 2

server:
  tomcat:
    max-connections: 2
    connection-timeout: 20s
    threads:
      max: 2

 

2023-11-29 07:56:52,507 [nio-8080-exec-1] 요청 시작
2023-11-29 07:56:52,507 [nio-8080-exec-2] 요청 시작
2023-11-29 07:56:55,522 [nio-8080-exec-2] 요청 끝. 응답시간: 3.007253708초
2023-11-29 07:56:55,523 [nio-8080-exec-1] 요청 끝. 응답시간: 3.007200375초

일할 쓰레드가 2개가 되어 요청 1, 2가 동시에 처리되는 것을 확인할 수 있다.

테스트 4. maxConnections 2, maxThreads 2, Concurrent request 3

server:
  tomcat:
    max-connections: 2
    connection-timeout: 20s
    threads:
      max: 2

 

2023-11-29 08:00:15,325 [nio-8080-exec-1] 요청 시작
2023-11-29 08:00:15,325 [nio-8080-exec-2] 요청 시작
2023-11-29 08:00:18,331 [nio-8080-exec-1] 요청 끝. 응답시간: 3.005042834초
2023-11-29 08:00:18,332 [nio-8080-exec-2] 요청 끝. 응답시간: 3.005476833초
2023-11-29 08:00:18,359 [nio-8080-exec-2] 요청 시작
2023-11-29 08:00:21,365 [nio-8080-exec-2] 요청 끝. 응답시간: 3.005047709초

1, 2번째 요청은 동시, 3 번째 요청은 잠시 대기했다 처리되는 것을 확인할 수 있다.

Q4. acceptCount가 1일 때 동시 요청이 들어오면 어떻게 될까?

acceptCount에 대한 레퍼런스의 설명은 다음과 같다.

The maximum length of the operating system provided queue for incoming connection requests when maxConnections has been reached. The operating system may ignore this setting and use a different size for the queue. When this queue is full, the operating system may actively refuse additional connections or those connections may time out. The default value is 100.

 

모든 커넥션이 사용되면 들어오는 커넥션 요청에 대해서 OS가 제공하는 큐에 담아두었다가 순차적으로 처리하는 것으로 보인다. 지금까지는 별도 설정을 안 했기에 100개까지 사용되고 있었을 것이다.

테스트 5. maxConnections 2, maxThreads 2, acceptCount 1, Concurrent request 3

원래 값을 0으로 주고 테스트를 하려고 했는데, AbstractEndpoint의 코드를 보면

public void setAcceptCount(int acceptCount) {
    if (acceptCount > 0) {
        this.acceptCount = acceptCount;
    }
}

위와 같이 0보다 큰 값만 받아들이고 있어서 최소 1은 설정해야 한다.

 

그 뿐만 아니라 TomcatWebServerFactoryCustomizer 클래스의 customize 메서드의 로직을 보면 

...
propertyMapper.from(threadProperties::getMax)
              .when(this::isPositive)
              .to((maxThreads) -> customizeMaxThreads(factory, threadProperties.getMax()));
propertyMapper.from(threadProperties::getMinSpare)
              .when(this::isPositive)
              .to((minSpareThreads) -> customizeMinThreads(factory, minSpareThreads));
...
propertyMapper.from(tomcatProperties::getMaxConnections)
              .when(this::isPositive)
              .to((maxConnections) -> customizeMaxConnections(factory, maxConnections));
propertyMapper.from(tomcatProperties::getAcceptCount)
              .when(this::isPositive)
              .to((acceptCount) -> customizeAcceptCount(factory, acceptCount));
...

maxConnections, acceptCount, maxThreads, minSpareThreads 모두 양수로 설정해야만 적용되도록 되어 있음을 알 수 있다.

 

server:
  tomcat:
    max-connections: 2
    accept-count: 1
    connection-timeout: 20s
    threads:
      max: 2

 

2023-11-29 08:15:38,091 [nio-8080-exec-1] 요청 시작
2023-11-29 08:15:41,105 [nio-8080-exec-1] 요청 끝. 응답시간: 3.005080167초

 

3개의 동시 요청 중 하나의 요청만 들어왔다.

$ curl localhost:8080/request
curl: (56) Recv failure: Connection reset by peer
또는
curl: (55) Send failure: Broken pipe

나머지 2개를 요청한 클라이언트는 위와 같은 응답을 받았다.

 

그런데 테스트 할 때마다 다르게 동작했다.

• 기대한대로 동작하지 않음
  • 1개 성공, 2개 실패
  • 2개 성공, 1개 실패
• 기대한대로 동작
  • 2개 성공, 1개 대기했다 처리 성공

Connection reset by peer

여기서는 서버에서 소켓을 닫아 연결이 강제로 종료되었음을 의미하는 것 같다.

그런데 커넥션 2개가 요청 2개를 처리하고 남은 요청에 대해서는 큐에 담겨졌다가 처리가 될 것으로 생각했는데, 에러가 발생하는 것은 이해가 안 가는 부분이다.

Broken pipe

클라이언트가 연결을 강제로 종료하거나, 서버에서 응답을 보내기 전에 연결을 닫았을 때 발생한다고 한다.

 

혹시나 curl이 기본적으로 타임아웃을 사용하는지 확인해봤는데, 기본적으로 그렇지 않다고 한다.

https://everything.curl.dev/usingcurl/timeouts

 

여기서는 잘 모르겠지만 서버에서 뭔가 메시지를 받고 클라이언트가 서버의 처리를 기다리지 않고 연결을 닫은 모양이다.

혹시 curl의 문제는 아닐까?

이대로 끝낼 순 없지. 부하 도구인 Apache JMeter를 사용해서 동일 테스트를 해보았다. 위와 동일한 현상이 발생했을 때의 결과는 아래와 같다.

 

성공 x 1

Thread Name:Thread Group 1-2
Sample Start:2023-12-01 09:47:54 KST
Load time:3039
Connect Time:2
Latency:3038
Size in bytes:183
Sent bytes:123
Headers size in bytes:162
Body size in bytes:21
Sample Count:1
Error Count:0
Data type ("text"|"bin"|""):text
Response code:200
Response message:


HTTPSampleResult fields:
ContentType: application/json
DataEncoding: null

 

실패 x 2

Thread Name:Thread Group 1-2
Sample Start:2023-12-01 09:56:09 KST
Load time:1004
Connect Time:2
Latency:0
Size in bytes:2455
Sent bytes:0
Headers size in bytes:0
Body size in bytes:2455
Sample Count:1
Error Count:1
Data type ("text"|"bin"|""):text
Response code:Non HTTP response code: java.net.SocketException
Response message:Non HTTP response message: Broken pipe


HTTPSampleResult fields:
ContentType: 
DataEncoding: null

 

JMeter를 사용해도 동일했다.

결론

커넥션 2개가 요청 2개를 처리하고 남은 요청 1개가 큐에 담겨졌다 처리될 것으로 기대를 했으나, 때에 따라서 기대한대로 동작하지 않았다. 이유를 모르겠다.

테스트 6. maxConnections 2, maxThreads 2, acceptCount 100, Concurrent request 3

acceptCount가 원하는대로 딱 맞게 동작하지 않아서, 기본값을 쓰도록 하고 다시 테스트해보았다.

server:
  tomcat:
    max-connections: 2
    accept-count: 100
    connection-timeout: 20s
    threads:
      max: 2

 

2023-11-29 10:11:44,573 [nio-8080-exec-1] 요청 시작
2023-11-29 10:11:44,568 [nio-8080-exec-2] 요청 시작
2023-11-29 10:11:47,574 [nio-8080-exec-1] 요청 끝. 응답시간: 3.000210625초
2023-11-29 10:11:47,577 [nio-8080-exec-2] 요청 끝. 응답시간: 3.002382041초
2023-11-29 10:11:47,603 [nio-8080-exec-1] 요청 시작
2023-11-29 10:11:50,609 [nio-8080-exec-1] 요청 끝. 응답시간: 3.005041833초

 

몇 번을 테스트를 해도 테스트 5에서의 문제가 발생하지 않고, 예상한대로 동작하였다.

 

acceptCount는 기본값을 사용하거나 트래픽에 기반해 넉넉히 값을 주는 것이 좋을지도 모르겠다. 조대협님의 블로그를 보면 10 내외 정도로 짧게 주는 것이 좋다고 한다.

테스트 7. maxConnections 2, maxThreads 2, acceptCount 3, Concurrent request 3

문득 레퍼런스의 설명을 믿지 않고 acceptCount를 동시 요청 수와 동일하게 설정하면 어떻게 될지 궁금해졌다. 요청을 허용하는 총량이 maxConnections + acceptCount가 아니라 acceptCount라면? 이라는 가설이다.

server:
  tomcat:
    max-connections: 2
    accept-count: 3
    connection-timeout: 20s
    threads:
      max: 2

동시 요청이 3이기 때문에 acceptCount를 3으로 설정했다.

2023-11-30 15:14:20,314 [  http-nio-8080-exec-1] 요청 시작
2023-11-30 15:14:20,324 [  http-nio-8080-exec-2] 요청 시작
2023-11-30 15:14:23,318 [  http-nio-8080-exec-1] 요청 끝. 응답시간: 3.003672541초
2023-11-30 15:14:23,332 [  http-nio-8080-exec-2] 요청 끝. 응답시간: 3.007974417초
2023-11-30 15:14:23,348 [  http-nio-8080-exec-1] 요청 시작
2023-11-30 15:14:26,354 [  http-nio-8080-exec-1] 요청 끝. 응답시간: 3.005045167초

몇 번을 테스트해도 앞선 두 요청은 성공하고 나머지 한 요청은 대기했다 성공하였다.

 

클라이언트의 요청이 실패하지 않도록 하는 데는 acceptCount의 값이 중요하다는 것이 확인되었다.

테스트 8. maxConnections 1, maxThreads 2, acceptCount 3, Concurrent request 3

여기서 maxConnections를 1로 바꾼다면 어떻게 될까?

server:
  tomcat:
    max-connections: 1
    accept-count: 3
    connection-timeout: 20s
    threads:
      max: 2

2023-11-30 15:18:28,074 [  http-nio-8080-exec-1] 요청 시작
2023-11-30 15:18:31,079 [  http-nio-8080-exec-1] 요청 끝. 응답시간: 3.004166916초
2023-11-30 15:18:31,101 [  http-nio-8080-exec-1] 요청 시작
2023-11-30 15:18:34,107 [  http-nio-8080-exec-1] 요청 끝. 응답시간: 3.005057583초
2023-11-30 15:18:34,126 [  http-nio-8080-exec-2] 요청 시작
2023-11-30 15:18:37,130 [  http-nio-8080-exec-2] 요청 끝. 응답시간: 3.003104125초

 

요청 1건씩 순차적으로 대기하면서 처리되고 클라이언트의 요청은 실패하지 않았다.

테스트 코드

https://github.com/venzersiz/learn-tomcat-9-performance/blob/main/src/main/java/learn/tomcat9/performance/controller/TestController.java

참고

• Spring Property
  • https://docs.spring.io/spring-boot/docs/2.7.7/reference/html/application-properties.html#appendix.application-properties.server
• Apache Tomcat
  • https://tomcat.apache.org/tomcat-9.0-doc/config/http.html
  • BIO, NIO Connector Architecture in Tomcat
  • [톰캣] 아파치톰캣 알아보기(2) - Connector 속성
  • 스프링부트는 어떻게 다중 유저 요청을 처리할까? (Tomcat9.0 Thread Pool)
• Apache Tomcat Tuning
  
  • Apache Tomcat Tuning (아파치 톰캣 튜닝 가이드) by 조대협
  • 톰캣 튜닝 맛보기 - maxConnections, acceptCount, maxThreads
• Timeout
  • Timeout을 정리하려고 해봤다
  • 웹 서비스 동작구조와 소켓 통신
• Thread Pool
  • [10분 테코톡] 조조그린의 Thread Pool
  •