[WebtoB] Access Log 에서 'max q for svr' 메시지가 나오는 경우

날짜:



환경 및 구성
- WebtoB + JEUS




증상 확인
WebtoB 의 Access Error Log 에서 'max q for svr (SERVICE) reached: error sent' 메시지가 발생됨.



[20/Jan/2015:00:00:04 +0900] [error] [client ???.???.???] max q for svr (SERVICE) reached: error sent
[20/Jan/2015:00:00:04 +0900] [error] [client ???.???.???] max q for svr (SERVICE) reached: error sent
[20/Jan/2015:00:00:04 +0900] [error] [client ???.???.???] max q for svr (SERVICE) reached: error sent
[20/Jan/2015:00:00:04 +0900] [error] [client ???.???.???] max q for svr (SERVICE) reached: error sent
[20/Jan/2015:00:00:04 +0900] [error] [client ???.???.???] JSV(QED): premature client close. POST /blablabla.do HTTP/1.1
[20/Jan/2015:00:00:04 +0900] [error] [client ???.???.???] JSV: premature client close. POST /blablabla.do HTTP/1.1
[20/Jan/2015:00:00:04 +0900] [error] [client ???.???.???] JSV(QED): premature client close. POST /blablabla.do HTTP/1.1
[20/Jan/2015:00:00:05 +0900] [error] [client ???.???.???] max q for svr (SERVICE) reached: error sent
[20/Jan/2015:00:00:05 +0900] [error] [client ???.???.???] max q for svr (SERVICE) reached: error sent
[20/Jan/2015:00:00:05 +0900] [error] [client ???.???.???] max q for svr (SERVICE) reached: error sent
[20/Jan/2015:00:00:07 +0900] [error] [client ???.???.???] max q for svr (SERVICE) reached: error sent

[20/Jan/2015:00:00:07 +0900] [error] [client ???.???.???] max q for svr (SERVICE) reached: error sent




일반 Access Log 는 다음과 같다.


???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 399ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 489ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 1s 578ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 130ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 479ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 1s 623ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 48ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 43ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 1s 733ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 44ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 54ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 72ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 114ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 58ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 195ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 190ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 1s 629ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 511ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 107ms
???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 163ms

???.???.???.??? -- [2015.01.20 00:00:01] "POST /blablabla.do HTTP/1.1" "-" "-" 200 0s 44ms







원인분석 및 조치방법


max q for svr (svr_name) reached: error sent
„  - 설명 : 서버프로세스(svr_name)의 큐에 있는 클라이언트의
요청이 한계를 초과했다.
„  - 조치 : 사용자 Request 가 폭주하여 서버프로세스 큐의 크기를
초과하였기 때문이다. WebtoB 환경설정에서 SERVER 절의
MaxQCount 값을 늘려주거나 Application 의 수행 속도를
튜닝해야 한다.


문서 (WebtoB_4.1_Error_Message_Reference.pdf)
Tmax링크, 다운로드링크




1. 페이지의 응답속도가 너무 느리다.
  - 대부분 응답속도가 100ms 가 넘으며 뜨문뜨문 1000ms 가 넘어가는 응답이 있음.
    한정된 Thread 로 응답을 해야 하다보니 응답이 너무 느려서 모든 Thread 를 사용하고도 wait queue 에 Request 가 계속 쌓이다보니 임계치를 초과하여 'max q for svr' 로그가 발생되었다.
  - 응답속도를 높이기 위해 어플리케이션 튜닝이 불가피하다.

2. 처리가능한 Thread 의 개수가 너무 적다.
  - service2 가 service1 보다 월등히 사용량과 요청량이 많음에도 Thread 개수가 더 적게 잡혀있다.
    가능하다면 Thread 개수를 적정량의 처리가능 수치로 변경이 필요하다.

{WebtoB_home}/config/http.m 설정 중 일부

##############################################################
*SERVER
##############################################################
HT_NODE           SVGNAME = htmlg_node,         MinProc = 15,  MaxProc = 15,  ASQCOUNT =  5, MAXQCOUNT = 50, SvrChkTime = 30

HT_SERVICE1         SVGNAME = htmlg_service1,       MinProc = 30,  MaxProc = 30,  ASQCOUNT =  5, MAXQCOUNT = 150, SvrChkTime = 30
HT_SERVICE1_ssl     SVGNAME = htmlg_service1_ssl,   MinProc = 30,  MaxProc = 30,  ASQCOUNT =  5, MAXQCOUNT = 50, SvrChkTime = 30

HT_SERVICE2        SVGNAME = htmlg_service2,      MinProc = 30,  MaxProc = 30,  ASQCOUNT =  5, MAXQCOUNT = 50, SvrChkTime = 30
HT_SERVICE2_ssl    SVGNAME = htmlg_service2_ssl,  MinProc = 30,  MaxProc = 30,  ASQCOUNT =  5, MAXQCOUNT = 50, SvrChkTime = 30

SERVICE1            SVGNAME = jsvg_service1,        MinProc = 180,  MaxProc = 180,  ASQCOUNT =  5, MAXQCOUNT = 50, SvrChkTime = 30  #, SessionIdCookieKey = "JSESSIONSERVICE1"
SERVICE1_ssl        SVGNAME = jsvg_service1_ssl,    MinProc = 60,  MaxProc = 60,  ASQCOUNT =  5, MAXQCOUNT = 50, SvrChkTime = 30  #, SessionIdCookieKey = "JSESSIONSERVICE1"

SERVICE2           SVGNAME = jsvg_service2,       MinProc = 120,  MaxProc = 120,  ASQCOUNT =  5, MAXQCOUNT = 50, SvrChkTime = 30  #, SessionIdCookieKey = "JSESSIONSERVICE2"

SERVICE2_ssl       SVGNAME = jsvg_service2_ssl,   MinProc = 60,  MaxProc = 60,  ASQCOUNT =  5, MAXQCOUNT = 50, SvrChkTime = 30  #, SessionIdCookieKey = "JSESSIONSERVICE2"





=================================
2015.06.03 내용추가

오전에 정상적인 응답대신 HTTP Error - Service unavailable 이라는 문구가 나타나며 서비스가 정상적으로 되지 않았다.

서버 담당자에게 요청하니 WebtoB 에서 사용가능한 임계점을 넘어가서 문제가 발생되었다고 보고를 받았고 Thread 개수를 30 => 60 으로 늘려서 재기동 하겠다고 답변을 받음.

아무래도 서버관리자가 아니다보니 확신이 없어서 제대로 이슈제기를 하지 못했었고 결국 사고가 터지고 말았다.
현재는 정상적으로 서비스되고 있음.


댓글

댓글 쓰기