2015년 1월 30일 금요일

[HTML][CSS] 이미지 누를 시 파란 선택화면(탭 하이라이트) 나오지 않는방법

Android 4.4 이상의 단말기의 OEM Browser 에서 이미지를 터치 했을 때 잠시 딜레이가 있으면 이미지가 선택이 되었다는 파란색 영역이 보이게 된다.
(iOS 에서는 언제부터 표시가 되는지 모름;;)

약 0.5~1초 정도 누르고 있으면 아래와 같이 선택된 영역이 선택된것 처럼 보이게 된다.

해결 방법은 다음과 같다.
(둘중에 편한 방법을 사용하면 된다.)

<html>
<head>
    <meta name="viewport" content="width=device-width,initial-scale=1.0,minimum-scale=1.0,maximum-scale=1.0">
    <style>
        a { -webkit-tap-highlight-color:transparent; }
    </style>
</head>
<body>
    <a href="#"
       style="-webkit-tap-highlight-color:transparent;">
        <div style="background-image: url('http://3.bp.blogspot.com/-O4Xi9hdrIcw/Ua6uy_seaoI/AAAAAAAAAGE/sCaP-SHLxw8/s1600/2.jpg'); width:150px; height:174px;"></div>
    </a>
</body>
</html>

[MAT][Android] 힙덤프(Heap Memory Dump) 에서 MAT(Eclipse Memory Analyzer)를 이용한 이미지(Bitmap) 추출

Android 에서 생성한 힙덤프(Heap Memory Dump) 를

MAT(Eclipse Memory Analyzer) 툴을 이용해서 이미지(Bitmap)를 추출하는 방법이 필요해서 알아봤다.

1. MAT 에서 Bitmap 객체를 찾는다.

2. mBuffer 의 값을 오른쪽 버튼 클릭 => Copy => Save Value To File

3. 확장자 .data 로 파일을 저장한다. (꼭 .data 로 할 필요는 없다.)

4. 김프를 실행한다.

Gimp: Download Link

5. 저장한 파일을 찾아서 연다.
- 이미지유형: RGB Alpha
- 너비, 높이: MAT 에 있던 속성을 입력한다.

참고: http://stackoverflow.com/questions/12709603/mat-eclipse-memory-analyzer-how-to-view-bitmaps-from-memory-dump

[Tomcat] Spring 으로 제작된 Web Application 구동 시 'DefaultListableBeanFactory - Pre-instantiating singletons' 로그에서 너무 오래 걸리는 경우

문제

로컬에 프로젝트 소스를 Tomcat 에 올려서 기동 시 시간이 너무 오래 걸린다.
(대략 15분 정도!? 서버에서의 기동시간은 빠르다)

아래는 Tomcat 기동시의 로그
(약 15분 정도의 간격이 있지만 해당 시점에는 CPU/Disk 의 사용량이 많지 않고 그냥 아무것도 하지 않는 느낌..)

[2015.01.28 14:04:54] *INFO * DispatcherServlet - FrameworkServlet 'dispatcher': initialization started

[2015.01.28 14:04:54] *INFO * XmlWebApplicationContext - Refreshing WebApplicationContext for namespace 'dispatcher-servlet': startup date [Wed Jan 28 14:04:54 KST 2015]; root of context hierarchy

[2015.01.28 14:04:54] *INFO * XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [config/spring/base-config.xml]

[2015.01.28 14:04:55] *INFO * XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [config/spring/mvc-config.xml]

[2015.01.28 14:04:56] *INFO * XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [config/spring/jdbc-config.xml]

[2015.01.28 14:04:56] *INFO * XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [config/spring/datasource-config.xml]

[2015.01.28 14:04:56] *INFO * XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [config/spring/message-config.xml]

[2015.01.28 14:04:56] *INFO * XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [config/spring/uri-config.xml]

[2015.01.28 14:04:56] *INFO * PropertyPlaceholderConfigurer - Loading properties file from class path resource [config/properties/jdbc-dev.properties]

[2015.01.28 14:04:57] *INFO * DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@1f5726ec: defining beans [package_name~~~~~~~~~~~~~~~~~~~~~~~]; root of factory hierarchy

[2015.01.28 14:19:23] *INFO * PropertiesFactoryBean - Loading properties file from class path resource [config/properties/legacy-real.properties]

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/bla] onto handler 'com.bla.bla.Controller'

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/bla.*] onto handler 'com.bla.bla.Controller'

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/bla/] onto handler 'com.bla.bla.Controller'

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/blaV2] onto handler 'com.bla.bla.Controller'

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/blaV2.*] onto handler 'com.bla.bla.Controller'

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/blaV2/] onto handler 'com.bla.bla.Controller'

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/blaV3] onto handler 'com.bla.bla.Controller'

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/blaV3.*] onto handler 'com.bla.bla.Controller'

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/blaV3/] onto handler 'com.bla.bla.Controller'

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/blaV4] onto handler 'com.bla.bla.Controller'

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/blaV4.*] onto handler 'com.bla.bla.Controller'

[2015.01.28 14:19:24] *INFO * DefaultAnnotationHandlerMapping - Mapped URL path [/rest/blaV4/] onto handler 'com.bla.bla.Controller'

원인

DB연결 작업 시 너무 오래 걸린다.
- 상용 및 스테이징 서버는 사양 및 네트워크가 좋아서 커넥션 개수를 300개로 설정해도 문제가 없다.
하지만 로컬 컴퓨터 및 개발용 DB서버는 사양도 낮고 멀리 떨어져 있다보니 초기 커넥션 개수를 높게 설정하면 커넥션을 맺는데 시간이 많이 소요된다.

방안

초기 커넥션 개수를 적절하게 낮게 설정한다.
(혼자 개발 및 테스트 용도이므로 많이 낮게 설정했다.)

기존

변경

2015년 1월 26일 월요일

[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 ???.???.???] 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: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 으로 늘려서 재기동 하겠다고 답변을 받음.

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

2015년 1월 6일 화요일

[JEUS][버그] UserAccessFormatter.java 에서 Lock 이 걸린경우

환경 및 구성
OS: Redhat Enterprise
WEB: WebtoB 4.1 SP 7 Fix #1
WAS: JEUS 6.0 (Fix#8) - 6.0.0.8-b288
DBMS: Oracle
Application: JAVA(Spring+iBatis etc)

증상
WAS의 응답이 점점 느려지다가 현재는 대부분의 요청을 처리할 수 없게 됨.
(페이지가 뜨지 않음)

증상확인

1. 시스템 리소스 확인 (CPU, Memory, I/O)

[was:WAS1:/proc/4473] sar 1 100
Linux 2.6.18-371.9.1.el5 (WAS1) 2015 01 05

CPU %user %nice %system %iowait %steal %idle
all 7.46 0.00 2.49 0.00 0.00 90.05
all 7.00 0.00 2.50 0.00 0.00 90.50
all 5.00 0.00 2.50 0.00 0.00 92.50
all 19.90 0.00 3.48 0.00 0.00 76.62
all 3.50 0.00 1.50 0.50 0.00 94.50
all 17.91 0.00 3.98 0.00 0.00 78.11
all 7.50 0.00 4.50 0.00 0.00 88.00
all 5.47 0.00 1.99 0.00 0.00 92.54
all 5.56 0.00 1.01 0.00 0.00 93.43
all 8.96 0.00 2.49 0.00 0.00 88.56

[was:WAS1:/proc/4473]
[was:WAS1:/proc/4473]
[was:WAS1:/proc/4473] vmstat 1 100
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 400792 38380 48812 1092324 0 0 233 107 1 2 7 2 91 0 0
3 0 400792 38388 48828 1092272 0 0 0 36 2280 5615 6 2 93 0 0
1 0 400792 38388 48836 1092264 0 0 0 892 2736 5943 9 3 87 0 0
2 0 400792 38256 48836 1092364 0 0 0 16 2588 6655 9 4 88 0 0
0 0 400792 38132 48844 1092356 0 0 0 36 2150 5528 9 4 87 0 0
0 0 400792 38008 48844 1092432 0 0 0 0 2362 5862 8 2 90 0 0
4 0 400792 38008 48860 1092564 0 0 0 24 2314 5621 8 2 91 0 0
0 0 400792 37884 48868 1092580 0 0 0 372 2218 5256 10 3 88 0 0
0 0 400792 37760 48876 1092720 0 0 0 52 2451 5485 9 1 89 0 0
0 0 400792 37644 48884 1092808 0 0 0 20 2653 6248 14 4 82 0 0
4 0 400792 37644 48884 1092808 0 0 0 0 2223 5717 5 2 93 0 0
0 0 400792 37644 48884 1092936 0 0 0 0 2842 5894 12 3 85 0 0
0 0 400792 37520 48892 1092928 0 0 0 520 2571 5719 7 3 91 0 0
5 0 400792 37388 48908 1093092 0 0 0 120 3174 6210 15 5 80 0 0
3 0 400792 37388 48956 1093192 0 0 0 112 3969 7281 21 8 71 0 0
0 0 400792 37388 48964 1093292 0 0 0 36 3044 5766 18 2 80 0 0
0 0 400792 37388 48964 1093292 0 0 0 0 2503 6158 9 4 88 0 0
3 0 400792 37496 48972 1093484 0 0 0 548 3908 6011 25 4 72 0 0
0 0 400792 37744 48988 1093468 0 0 0 112 1642 4813 4 1 95 0 0
1 0 400792 37744 48996 1093548 0 0 0 20 1908 5366 8 4 88 0 0
3 0 400792 37620 48996 1093548 0 0 0 0 1733 4794 6 1 94 0 0
3 0 400792 37512 49004 1093628 0 0 0 92 2866 5876 15 5 81 0 0

[was:WAS1:/proc/4473]

2. Thread Dump 생성 및 확인
- 'kill -3 pid' 명령어가 권한문제로 수행되지 않아서 'jstack pid' 방법으로 덤프를 생성

WAS1_ThreadDump_20150105.log (덤프파일 다운로드)
(위험하다고 판단되는 정보를 제거를 했으나 분석하는데에는 문제 없음)

덤프 생성시간
01) 15:40:44
02) 15:40:47
03) 15:40:50
04) 15:40:54
05) 15:40:57
06) 15:41:00
07) 15:41:03
08) 15:41:06
09) 15:41:09
10) 15:41:11

"webtob2_WAS1-hth2(???.???.???.???:19902)-w10 [WAS1-99]" prio=10 tid=0x0000000058db7000 nid=0x11f6 waiting for monitor entry [0x00002ad90430b000]
java.lang.Thread.State: BLOCKED (on object monitor)
at jeus.util.logging.UserAccessFormatter.format(UserAccessFormatter.java:544)
- waiting to lock <0x00000000c00bae08> (a jeus.util.logging.UserAccessFormatter)
at jeus.util.logging.StreamHandler.writeRecord(StreamHandler.java:150)
at jeus.util.logging.StreamHandler.publish(StreamHandler.java:144)
at java.util.logging.Logger.log(Logger.java:478)
at jeus.util.logging.AccessLogger.log(AccessLogger.java:34)
at jeus.servlet.engine.WebtobRequestProcessor.run(WebtobRequestProcessor.java:367)

"webtob2_WAS1-hth2(???.???.???.???:19902)-w09 [WAS1-98]" prio=10 tid=0x0000000059532800 nid=0x11f5 waiting for monitor entry [0x00002ad90420a000]
java.lang.Thread.State: BLOCKED (on object monitor)
at jeus.util.logging.UserAccessFormatter.format(UserAccessFormatter.java:544)
- waiting to lock <0x00000000c00bae08> (a jeus.util.logging.UserAccessFormatter)
at jeus.util.logging.StreamHandler.writeRecord(StreamHandler.java:150)
at jeus.util.logging.StreamHandler.publish(StreamHandler.java:144)
at java.util.logging.Logger.log(Logger.java:478)
at jeus.util.logging.AccessLogger.log(AccessLogger.java:34)
at jeus.servlet.engine.WebtobRequestProcessor.run(WebtobRequestProcessor.java:367)

"webtob2_WAS1-hth2(???.???.???.???:19902)-w08 [WAS1-97]" prio=10 tid=0x0000000059530800 nid=0x11f4 waiting for monitor entry [0x00002ad904109000]
java.lang.Thread.State: BLOCKED (on object monitor)
at jeus.util.logging.UserAccessFormatter.format(UserAccessFormatter.java:544)
- waiting to lock <0x00000000c00bae08> (a jeus.util.logging.UserAccessFormatter)
at jeus.util.logging.StreamHandler.writeRecord(StreamHandler.java:150)
at jeus.util.logging.StreamHandler.publish(StreamHandler.java:144)
at java.util.logging.Logger.log(Logger.java:478)
at jeus.util.logging.AccessLogger.log(AccessLogger.java:34)
at jeus.servlet.engine.WebtobRequestProcessor.run(WebtobRequestProcessor.java:367)

"webtob2_WAS1-hth2(???.???.???.???:19902)-w07 [WAS1-96]" prio=10 tid=0x00000000591ea000 nid=0x11f3 runnable [0x00002ad904008000]
java.lang.Thread.State: RUNNABLE
at java.net.Inet4AddressImpl.getHostByAddr(Native Method)
at java.net.InetAddress$1.getHostByAddr(InetAddress.java:853)
at java.net.InetAddress.getHostFromNameService(InetAddress.java:533)
at java.net.InetAddress.getHostName(InetAddress.java:476)
at java.net.InetAddress.getHostName(InetAddress.java:448)
at jeus.servlet.engine.HttpServletRequestImpl.getRemoteHost(HttpServletRequestImpl.java:916)
at jeus.util.logging.UserAccessFormatter.format(UserAccessFormatter.java:586)
- locked <0x00000000c00bae08> (a jeus.util.logging.UserAccessFormatter)
at jeus.util.logging.StreamHandler.writeRecord(StreamHandler.java:150)
at jeus.util.logging.StreamHandler.publish(StreamHandler.java:144)
at java.util.logging.Logger.log(Logger.java:478)
at jeus.util.logging.AccessLogger.log(AccessLogger.java:34)
at jeus.servlet.engine.WebtobRequestProcessor.run(WebtobRequestProcessor.java:367)

"webtob2_WAS1-hth2(???.???.???.???:19902)-w06 [WAS1-95]" prio=10 tid=0x0000000058502000 nid=0x11f2 waiting for monitor entry [0x00002ad903f07000]
java.lang.Thread.State: BLOCKED (on object monitor)
at jeus.util.logging.UserAccessFormatter.format(UserAccessFormatter.java:544)
- waiting to lock <0x00000000c00bae08> (a jeus.util.logging.UserAccessFormatter)
at jeus.util.logging.StreamHandler.writeRecord(StreamHandler.java:150)
at jeus.util.logging.StreamHandler.publish(StreamHandler.java:144)
at java.util.logging.Logger.log(Logger.java:478)
at jeus.util.logging.AccessLogger.log(AccessLogger.java:34)
at jeus.servlet.engine.WebtobRequestProcessor.run(WebtobRequestProcessor.java:367)

3. 시스템계정 환경설정 및 해당 컨테이너 정보 확인

[was:WAS1:/home/was] ulinmimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 46648
max locked memory (kbytes, -l) 32
max memory size (kbytes, -m) unlimited
open files (-n) 1024
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 10240
cpu time (seconds, -t) unlimited
max user processes (-u) 46648
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited
[was:WAS1:/home/was]

[was:WAS1:/proc/4473/fd] ls -l | wc -l

413

증상분석

1. 시스템리소스
- 별다른 문제가 보이지 않는다.

2. ThreadDump
1) 대부분의 Thread 에서 AccessLog 클래스의 Lock 때문에 BLOCKED 상태가 되었다.
2) LOCK 을 걸고 수행하는 Thread 는 JEUS 에서 Log를 수행중 getHostName 메소드를 수행을 했다.
3) 덤프 파일의 15:40:57, 15:41:00 시간의 덤프 두개를 확인해보면 동일한 Thread(tid=0x0000000057f9d800) 에서 Reverse DNS query 수행중인 것을 확인 할 수 있다.(우연히 동일한 Thread 에 DNS 질의를 했다면 그나마 다행이겠지만 DNS의 응답이 늦어 처리가 되지 않은 상황이라면 직접적인 위험요소가 된다.)

3. Openfiles 설정 및 컨테이너의 파일 열려진 개수
1) 쉘 및 프로세스당 open 가능한 file 개수가 1024 로 낮게 잡혀있다.
2) JEUS 컨테이너가 열고 있는 파일 개수는 413개 정도로 보여진다.
(413개의 수치는 WAS에서 사용하는 Lib jar파일, Log파일, Socket파일(Request) 등등이 포함된 수치다.)
- ulimit 의 openfiles 설정이 1024 라는 수치로 낮게 잡혀있지만 현재 발생한 증상에 직접적인 관계는 없어 보인다.

원인

1. AccessLog 설정부분

  1) AccessLog 를 남기는 여부!?
- 보통 AccessLog 는 웹서버(apache, webtob) 쪽에만 설정을 하는게 일반적인데 JEUS 에 AccessLog 가 남기게 설정이 되어있다.

  2) format의 잘못된 설정
- JEUS 설정을 확인해보니 AccessLog 의 format 이 다음과 같이 설정되어 있었다.
  [%{yyyy.MM.dd HH:mm:ss}t] %a “%m %U%q” %u %h %s %S %b %D

- %h 라는 설정은 Remote host name 을 저장하는 옵션인데 Reverse DNS query 가 필요한 부분이다.
모든 Request 에 대해서 DNS에 조회를 해야 하며 DNS조회 하는 시점에서는 나머지 Thread 가 BLOCKED 되어버려 퍼포먼스에 문제가 발생을 하게된다.

2. JEUS 의 로직문제

  1) JEUS 버그이슈!?
- AccessLog 의 %h 옵션이 무슨 문제가 있겠는가?? 쓰라고 만들어 놓은 옵션인데..
원인을 찾다가 답답한 나머지 JEUS의 코어 파일인 jeus.jar 파일을 디컴파일하여 분석했다.
  UserAccessFormatter Class의 format Method 를 확인해보니 Method 에 static 키워드가 걸려있었다.
그러니 모든 Thread 에서 Lock 이 걸리는게 당연한 문제..
해당 Method 에서 static 이 사용된 이유는 로그파일에 기록을 하는 로직이 들어있어서 사용을 한 듯 하지만 DNS질의가 필요하다면 해당 부분은 static 밖으로 빼야 하는게 맞다.
만일 DNS설정이 잘못되어 있거나 응답이 10초가 걸려버리면 바로 WAS hang 문제가 발생이 될 수 있는 상황..;;

* JEUS_6_Web_Container.pdf
다운로드 (링크1, 링크2)

조치방법

1. AccessLog 설정

1) AccessLog 를 웹서버(apache, webtob)쪽에만 설정을 하고 JEUS는 설정을 삭제한다.

2) format 옵션에서 %h 옵션을 제거한다.

2. JEUS 의 핫픽스 및 버그이슈 확인

- 위의 상황이라면 분명 제우스의 버그라고 봐도 될 듯 하다.
아마 핫픽스나 버그이슈가 있어서 버전을 올리던지 하는 이슈가 있지 않을까 싶다.

조치 후

중간중간 페이지가 안뜨거나 하는 부분이 확실히 개선이 되었다.
아마 WAS 서버에 설정된 DNS서버의 응답이 최근에 느려져서 최근에 이런 증상이 발생하지 않았나 싶다.

이후 상황

JEUS 컨테이너 소프트웨어를 제작한 TmaxSoft 측에서 자사의 버그를 인정했으며, 추후 해당 이슈에 대한 퍼포먼스 이슈를 수정한 패치를 진행했었다.

피드 구독하기: 글 ( Atom )

Programming Log

Translate