[아파치/톰캣] AH00287: server is within MinSpareThreads of MaxRequestWorkers, consider raising the MaxRequestWorkers setting 에러 해결

아직까지 너무나 어려운 미들웨어의 셋팅... 튜닝... 운영... 난 미들웨어 운영 담당자가 아닌데 왜...??!??!??

아직까지 본 에러 원인 분석이 진행되고 있다.

1. WAS의 Tomcat(이하 톰캣) 에서 파일 I/O 관련하여 처리가 되지 않고 있다.
2. WEB의 Apache(이하 아파치) 의 동시 접속자 처리가 되지 않고 있다.
3. 애초부터 WEB/WAS에서 받아줄 수 있는 수용량을 한참 넘어선 트래픽이 들어오고 있다.
4. 인프라(네트워크, 디스크, 로드밸런싱)에 문제가 있다.

위의 4가지를 원인으로 생각하고 하나씩 분석을 진행중이며,

4번의 경우 이슈 발생 당시의 모든 로그 및 모니터링 내용을 분석한 결과 문제가 없음으로 판단하고 지웠다.

사실 제일 의심이 가는 것은 톰캣이 API 통신 부분이 아닌 정적 컨텐츠 I/O 처리되는 부분에 무언가 병목 현상이 있을 것으로 예상하고 있는 점이다.

그러나 아파치 로그들을 분석하다 보니 아파치 MaxRequestWorkers 파라미터 설정도 변경이 필요해보였다.(톰캣 8버전 이후부터 MaxClients 가 MaxRequestWorkers로 변경되었다고 하며, MaxClients 로 설정해도 여전히 호환된다)

아래의 아파치의 error_log를 보면 다음과 같은 메시지가 뜬다.

[mpm_worker:error] [pid 11905:tid 139707719325504] AH00288: scoreboard is full, not at MaxRequestWorkers
[mpm_worker:error] [pid 11905:tid 139707719325504] AH00288: scoreboard is full, not at MaxRequestWorkers
[mpm_worker:error] [pid 11905:tid 139707719325504] AH00288: scoreboard is full, not at MaxRequestWorkers
[mpm_worker:error] [pid 11905:tid 139707719325504] AH00288: scoreboard is full, not at MaxRequestWorkers
[jk:error] [pid 30343:tid 139707417581312] mod_jk: jk_log_to_file [22 12 14 17: 59: 53]workers2 [url] 13.884628\n failed: Broken pipe
[jk:error] [pid 30494:tid 139707333654272] mod_jk: jk_log_to_file [22 12 14 17: 59: 53]workers2 [url] 3.929592\n failed: Broken pipe
[jk:error] [pid 30343:tid 139707409188608] mod_jk: jk_log_to_file [22 12 14 17: 59: 53]workers2 [url] 5.989197\n failed: Broken pipe
[jk:error] [pid 30343:tid 139707417581312] mod_jk: jk_log_to_file [22 12 14 17: 59: 53]workers2 [url] 0.078853\n failed: Broken pipe
[jk:error] [pid 30344:tid 139707442759424] mod_jk: jk_log_to_file [22 12 14 17: 59: 53][30344:139707442759424] [info] ajp_process_callback::jk_ajp_common.c (2073): (workers22) Writing to client aborted or
client network problems\n failed: Broken pipe
[jk:error] [pid 30344:tid 139707442759424] mod_jk: jk_log_to_file [22 12 14 17: 59: 53][30344:139707442759424] [info] ajp_service::jk_ajp_common.c (2774): (workers22) sending request to tomcat failed (unr
ecoverable), because of client write error (attempt=1)\n failed: Broken pipe
[jk:error] [pid 30344:tid 139707442759424] mod_jk: jk_log_to_file [22 12 14 17: 59: 53][30344:139707442759424] [info] service::jk_lb_worker.c (1600): service failed, worker workers22 is in local error sta
te\n failed: Broken pipe

동 시점의 아파치 mod_jk 로그를 보면 다음과 같은 메시지가 보인다.

workers2 [url] 0.009194
workers2 [url] 0.007713
[info] ajp_process_callback::jk_ajp_common.c (2073): (workers22) Writing to client aborted or client network problems
[info] ajp_service::jk_ajp_common.c (2774): (workers22) sending request to tomcat failed (unrecoverable), because of client write error (attempt=1)
[info] service::jk_lb_worker.c (1600): service failed, worker workers22 is in local error state
[info] service::jk_lb_worker.c (1619): unrecoverable error 200, request failed. Client failed in the middle of request, we can't recover to another instance.
[info] jk_handler::mod_jk.c (2984): Aborting connection for worker=workers2

 

그래서 아파치의 httpd.conf 파일을 수정을 먼저 해보았다.

<IfModule worker.c>
	StartServers        16 
	ServerLimit         32
	MaxRequestWorkers 2048
	MinSpareThreads    512
	MaxSpareThreads   1024
	ThreadsPerChild     64
	MaxRequestsPerChild  0
</IfModule>

그리고 아파치 종료 후 재시작 하여 모니터링 진행을 해보니, 위 아차피 error_log 에서 나왔던 "AH00288: scoreboard is full, not at MaxRequestWorkers" 메시지가 사라졌다. 그러나 여전히 Aborting connection 등의 오류는 지속적으로 나오는 것으로 보아, 톰캣의 파라미터도 설정을 해보는 것이 좋겠다는 판단이 들었다.

그래서 톰캣의 server.xml 에 파라미터를 추가하였다.

<Connector address="0.0.0.0" port="9010" protocol="AJP/1.3"
           server="Server"
           acceptCount="1000"
           minSpareThreads="100"
           maxThreads="2048"
           maxConnections="20000"
           tcpNoDelay="true"
           redirectPort="9444"
           URIEncoding="UTF-8"
           secretRequired="false" />

위 파라미터는 Connector 에 추가해야 하는 부분이다.

그리고 톰캣 중지 후 재기동을 하고 모니터링을 진행해보았다.

아파치, 톰캣의 파라미터 설정 전보다 확실히 "Aborting connection" 로그 메시지는 줄어들었으나 여전히 만족할만한 성능이 나오지는 않았다. 그래서 CentOS의 커널 파라미터도 조정을 해보기로 했다.

fs.file-max = 512000
net.core.rmem_default = 253952
net.core.wmem_default = 253952
net.core.rmem_max = 16777216
net.core.wmem_max = 16777216
net.ipv4.tcp_rmem = 4096 87380 16777216
net.ipv4.tcp_wmem = 4096 65536 16777216
net.ipv4.tcp_mem = 50576   64768   98152
net.ipv4.tcp_syncookies = 1
net.ipv4.tcp_window_scaling = 1
net.core.netdev_max_backlog = 30000
ipv4.tcp_timestamps = 1
net.ipv4.tcp_tw_reuse = 1

WEB/WAS 서버의 커널에 /etc/sysctl.conf 에 위 파라미터들을 반영 후 아파치, 톰캣 중지 후 OS 재부팅 후 아파치 톰캣 재기동 후 모니터링을 시작하였다.

조금이나마 더 "Aborting connection" 로그 메시지가 줄어들긴 했으나, 여전히 만족할 만한 성능이 나오지 않고 있다.

WEB/WAS의 스펙이 높은데(8Core, 24GB, 이중화, L4구성), 스펙 대비 동시 접속 사용자 수 처리가 생각보단 적은 것 같다.
이렇게 까지 튜닝 후에 20TPS 정도까지는 무리가 없는 상태이다.

그러나 동시 접속자가 많을때는 시간당 15~20만 접속을 하는 상황인데, 이 중에는 API 통신 뿐만 아니라, 약 1~10MB 사이의 정적 컨텐츠도 클라이언트로 내려주는 작업이 일어난다. 실제로 정적 컨텐츠 다운로드는 시간당 2~3만건 정도로 추산되고 있다.

음.. 아무래도 와스를 Scale Out을 하거나, 정적 컨텐츠 배포만을 위한 별도의 서버를 구성하거나, 아예 CDN을 구성해야 하나 라는 생각이 든다.

다만, 현재 할당 되어있는 리소스 조차 다 사용하고 있지 못하는 것을 보면 어딘가 병목이 있어서 제 성능이 안나오는 것 같은 느낌인데 어디를 더 튜닝해야 할지 모르겠는 상태이다. 계속 찾아보며 본 글을 업데이트 할 예정이다.