와스킹의 사건현장

현상
 외부 클라이언트에서 접속하지 못하는 현상 발생

원인
 1) wsadmin 의 st -p 로 html 프로세스 상태 확인
 html 프로세스의 status가 BRUN 상태로 남는 것을 확인

   -------------------------------------------------------------------------
   svr_name   svgname     spr_no(pid)  status    count    avg(rt)  clid svc 
   -------------------------------------------------------------------------

   html       htmlg        37(544822)   RDY     29235   0.0271( 0)   -1 -

   html       htmlg        38(630880)  BRUN     25869   0.0472(351) 5180 swf

   html       htmlg        39(606336)   RDY     29042   0.0290( 0)   -1 -

   html       htmlg        40(512038)   RDY     28183   0.0384( 0)   -1 -

   html       htmlg        41(503842)   RDY     27471   0.0445( 0)   -1 -

   html       htmlg        42(491548)   RDY     27667   0.0408( 0)   -1 -

 

 2) wsadmin 의 ci 로 클라이언트 상태 확인
 st -p 에서 보았던 BRUN상태의 clientID와 매칭 되는 부분과 접속이 BRUN상태라는 것을 확인할 수 있으며, 실질적으로 외부 사용자는 server쪽으로 요청을 했지만 계속 기다리는 상황인 것으로 추정.

------------------------------------------------------------------------
 no   status count idle    local_ipaddr:port    remote_ipaddr:port  spri
------------------------------------------------------------------------
 5178    RDY     2   33     172.17.1.72:80    221.166.124.147:3097    -1      

 5179    RDY     2   33     172.17.1.72:80    221.166.124.147:3099    -1      

 5180    RUN     4  190     172.17.1.72:80     218.150.29.223:1122    38      

 5181    RDY     2   30     172.17.1.72:80    221.166.124.147:3100    -1      

 5182    RDY     2   33     172.17.1.72:80    221.166.124.147:3098    -1      

 5183    RDY     2   33     172.17.1.72:80    221.166.124.147:3102    -1      

 

 3) network상태 확인
 netstat -an | grep [clientIP] 로 네트워크 상태 확인, sendQ의 byte size가 줄어들지 않고 계속 유지되고 있는 것 확인
 Client와 연결된 hth 프로세스가 더 이상 sendQ에 write를 못하고 대기하고 있는 상태로 추정

# netstat -na|grep 218.150.29.223

Active Internet connections (including servers)
Proto Recv-Q Send-Q  Local Address          Foreign Address        (state)

tcp4       0 119826  172.17.1.72.80         218.150.29.223.1122    ESTABLISHED

# netstat -na|grep 218.150.29.223

Active Internet connections (including servers)
Proto Recv-Q Send-Q  Local Address          Foreign Address        (state)

tcp4       0 119826  172.17.1.72.80         218.150.29.223.1122    ESTABLISHED

# netstat -na|grep 218.150.29.223

Active Internet connections (including servers)
Proto Recv-Q Send-Q  Local Address          Foreign Address        (state)

tcp4       0 119826  172.17.1.72.80         218.150.29.223.1122    ESTABLISHED

# netstat -na|grep 218.150.29.223

Active Internet connections (including servers)
Proto Recv-Q Send-Q  Local Address          Foreign Address        (state)

tcp4       0 119826  172.17.1.72.80         218.150.29.223.1122    FIN_WAIT_1

 

해결방안
 네트워크 상태 확인 필요, BRUN을 유발하는 거래 차단

개요
 JEUS 기동 시 TM로그 관련된 Exception메시지 기록

현상
 JEUS 기동 시 로그에서 아래와 같은 Exception 발생

Caused by: org.objectweb.howl.log.LogFileOverflowException: /shcsw/logs/jeus/TM/_`hostname`_"container_name"_LOCATION_0_10061_10_121_11_33_61/jeusres_1.log: high mark = 34bd000000; active mark for Logger = 33c2000037
        at org.objectweb.howl.log.LogFileManager.getLogFileForWrite(LogFileManager.java:389)
        at org.objectweb.howl.log.BlockLogBuffer.init(BlockLogBuffer.java:363)
        at org.objectweb.howl.log.LogBufferManager.getFillBuffer(LogBufferManager.java:591)
        at org.objectweb.howl.log.LogBufferManager.put(LogBufferManager.java:685)
        at org.objectweb.howl.log.Logger.put(Logger.java:207)
        at org.objectweb.howl.log.xa.XALogger.putCommit(XALogger.java:420)
        at jeus.transaction.logging.HowlLogManager.registerXaResourceFactory(HowlLogManager.java:282)
        ... 70 more

원인
 LogFileOverflowException이 발생한 로그 파일은 JEUS transaction 로그입니다.
 transcation 로그란? 예상치 못한 문제 상황에 있어서 거래의 무결성을 보장하기 위해 거래정보를 저장하는 로그 입니다.
 LogFileOverflowException은 JEUS transaction 로그파일에 더 이상 용량이 없을 경우 발생합니다. (default로 4K block을 500개 사용하여 2M의 file을 2개 사용)
 일반적으로 대량의 거래가 발생 하였을 경우 해당 현상이 발생할 수 있으며, 거래에 영향을 주지는 않습니다.

해결방안
 1) 컨테이너 중지 후 transaction 로그 삭제 후 기동
  -> LogFileOverflowException 확률이 있음

 2) transaction 로그 파일 size 튜닝
  JEUSMain.xml의 command-option에 추가, 증가 시킨 후 모니터링이 필요.

   -Dhowl.log.MaximumFiles=5
   -Dhowl.log.MaximumBlocksPerFile=1000

 3) TM 로그 disable 방법
  JEUSMain.xml의 command-option에 추가, 증가 시킨 후 모니터링이 필요.

   -Djeus.tm.noLogging=true

서비스 거래 처리 시 확장명 처리 로직
 - 정의된 mime type을 명시하여 설정
  1)WEBTOB
   ${WEBTOB_HOME}/config/http.m의 EXT절에 정의

*EXT
html        MimeType = "text/html",  SvrType = HTML
gif         MimeType = "image/gif",  SvrType = HTML
jpg         MimeType = "image/jpeg", SvrType = HTML
js          MimeType = "application/x-javascript",  SvrType = HTML
css         MimeType = "text/css",  SvrType = HTML


  2)JEUS
   ${JEUS_HOME}/config/`hostname`/"servlet"/webcommon.xml에 정의

    <mime-mapping>
        <extension>jspf</extension>
        <mime-type>text/plain</mime-type>
    </mime-mapping>
    <mime-mapping>
        <extension>me</extension>
        <mime-type>application/x-troff-me</mime-type>
    </mime-mapping>

 

개요
 Java Minor Upgrade 후 JEUS 기동 실패

현상
 Java Minor Upgrade (1.6.0.20 -> 1.6.0.37) 후 JEUS 기동 실패

 1)JEUS Log
jeus.server.JeusServerException: failed to start the node security manager
        at jeus.server.JeusServer.start(JeusServer.java:317)
        at jeus.server.JeusServer.main(JeusServer.java:991)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at jeus.server.Bootstrapper.callMainMethod(Bootstrapper.java:718)
        at jeus.server.Bootstrapper.callMain(Bootstrapper.java:790)
        at jeus.server.Bootstrapper.main(Bootstrapper.java:784)
        at jeus.server.JeusBootstrapper.main(JeusBootstrapper.java:8)
Caused by: java.lang.ExceptionInInitializerError
        at javax.crypto.Cipher.getInstance(Cipher.java:429)
        at jeus.security.util.EncryptionUtil.decode(EncryptionUtil.java:458)
        at jeus.security.util.EncryptionUtil.decryptPassword(EncryptionUtil.java:642)
        at jeus.security.resource.Password.<init>(Password.java:72)
        at jeus.security.resource.DefaultPasswordFactory.getCredential(DefaultPasswordFactory.java:130)
        at jeus.security.impl.atnrep.XMLAccountConverter.fromXMLTree(XMLAccountConverter.java:128)
        at jeus.security.util.XMLConverter.unmarshal(XMLConverter.java:34)
        at jeus.security.util.XMLConverter.unmarshal(XMLConverter.java:51)
        at jeus.security.util.XMLConverter.unmarshal(XMLConverter.java:42)
        at jeus.security.impl.atnrep.XMLAccountPersistedDistributedMemoryAuthenticationRepositoryService.refreshRead(XMLAccountPersi
stedDistributedMemoryAuthenticationRepositoryService.java:97)
        at jeus.security.impl.atnrep.XMLAccountPersistedDistributedMemoryAuthenticationRepositoryService.doCreate(XMLAccountPersiste
dDistributedMemoryAuthenticationRepositoryService.java:36)
        at jeus.security.base.Service.create(Service.java:121)
        at jeus.security.base.Service.create(Service.java:107)
        at jeus.security.base.Domain.createAll(Domain.java:263)
        at jeus.security.impl.installer.JeusSecurityDomainInstaller.makeCustomDomains(JeusSecurityDomainInstaller.java:112)
        at jeus.security.impl.installer.JeusSecurityDomainInstaller.installMasterSecurityServer(JeusSecurityDomainInstaller.java:78)
        at jeus.security.impl.installer.JeusSecurityDomainInstaller.doInstallSecurity(JeusSecurityDomainInstaller.java:41)
        at jeus.security.spi.SecurityInstaller.installSecurity(SecurityInstaller.java:191)
        at jeus.server.JeusServer.start(JeusServer.java:311)
        ... 9 more
Caused by: java.lang.SecurityException: Cannot set up certs for trusted CAs
        at javax.crypto.JceSecurity.<clinit>(JceSecurity.java:267)
        ... 28 more
Caused by: java.lang.SecurityException: Jurisdiction policy files are not signed by trusted signers!
        at javax.crypto.JceSecurity.loadPolicies(JceSecurity.java:593)
        at javax.crypto.JceSecurity.setupJurisdictionPolicies(JceSecurity.java:524)
        at javax.crypto.JceSecurity.access$700(JceSecurity.java:37)
        at javax.crypto.JceSecurity$1.run(JceSecurity.java:258)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.crypto.JceSecurity.<clinit>(JceSecurity.java:234)
        ... 28 more

원인
 256bit 이상 암호화를 해야하는 경우 JAVA의 local_policy.jar와 US_export_policy.jar를 버전에 맞게 패치해 주어야 한다.
 Minor Upgreade 한 1.6.0.37에는 /opt/java6/jre/lib/security/policy의 limited 디렉토리와 unlimited 디렉토리에 각각 존재하지만,
 1.6.0.20에는 /opt/java6/jre/lib/security에 존재하였다.
 따라서 Upgrade 이 후 /opt/java6/jre/lib/security에 있는 local_policy.jar와 US_export_policy.jar를 참조하게 되면서 발생한 문제로 보인다.
 JEUS의 경우 기동시 JEUS Manager 를 올리기 위하여 ${JEUS_HOME}/config/`hostname`/security/SYSTEM_DOMAIN/account.xml 파일의 계정정보를 참조하게 되는데
 해당 파일에 AES로 암호화된 패스워드가 들어 있기 때문이다.

해결방안
 local_policy.jar와 US_export_policy.jar를 /opt/java6/jre/lib/security로 복사

 - 취약점 내용
    * TLS 프로토콜 취약점을 이용하여 Diffie-Hellman 키를 의도적으로 수출용 512bit 로 downgrade 하여 암호통신을 복보화하는 Logjam 취약점

 - 조치방안
    * Diffie-Hellman의 키 길이를 2048bit 설정

1. 다음의 명령어로 2048 bit 키파일 생성
 wbssl dhparam -out dhparams.pem 2048

2. 아래와 같이 WEBTOB설정에 추가
 *SSL
  DHParameter="/webtob6/cert/dhparams.pem"

개요
 Network의 문제로 기인한 Web 서비스 지연 및 불가 상황

현상
 Web 화면 호출이 전혀 되지 않고, 단순 image파일 개별 호출도 되지 않는 현상 발생.
 WebtoB/JEUS 재 기동 후에는 서비스 정상 작동함.

원인
 1) wsadmin을 통한 확인(wsadmin : st -s, si)
    html서비스의 평균 처리시간이 오래 걸렸으며(60초이상), Queueing 또한 발생.
    이 상황으로 인해 단순한 image파일도 호출되지 않았음.
 

 2) WebtoB의 error log 확인 결과
    [27/Mar/2018:08:43:45 +0900] [error] [client -] TIMEOUT is expired while svc is running
   [27/Mar/2018:08:43:49 +0900] [error] [client -] TIMEOUT is expired while svc is running
   위 로그에서 확인되는 사항은 사용자의 요청이 WebtoB의 TIMEOUT(300초)시간을 지났다는 로그임.
   WebtoB의 TIMEOUT은 Client와 WebtoB사이의 데이터 전송 중 TIMOUT시간 (300초) 이상 어떠한 패킷(데이터)도 Client와 WebtoB사이에 전송되지 않았을 경우 적용되는 값임.
    Network Bottleneck이나 기타 요인으로 인해 패킷 전송지연이 발생되었을 것으로 판단됨.

해결방안
 본 상황은 큰 파일을 동시에 많은 사용자가 다운 받음으로 인해 발생된 서비스 지연에 해당한다.
 즉 시스템적인 오류가 아닌 업무적인 특성으로 인해 과부하가 발생한 것으로, Network 전송속도를 개선하는 것이 근본적인 해결방법임.

 

개요
 jvm compiler에 의해 Hotspot Code를 compile 하던 중 문제가 생겨 Signal을 받고 비정상종료 발생

현상
 서비스 운영 중 지속적인 java 프로세스의 비정상 종료 발생

원인
 JVM bug로 인해 Hostpot Compile 수행 중 Java 프로세스가 Crash 발생
  ※ Hotspot Compile 이란 ?
    10,000 회 이상 반복되는 byte code를 machine code로 바꾸어 속도를 빠르게 하려는 목적으로 JVM이 자동으로 Compile 수행

 CORE 파일 분석 결과 Hostpot Compile 시 문제를 발생 시키는 특정 method를 도출하였음.

해결방안
 Hotspot Compile 시 문제되는 대상 method 제외
  1) JVM 옵션 내 -XX:CompileCommandFile  추가 
     -XX:CompileCommandFile=$JEUS_HOME/config/`hostname`/nohotspot.conf
  2) nohotspot.conf  파일에는 컴파일 제외할 메소드 입력
      exclude abc/oeq/pss/cmd/GetInfoC command 

개요
 WebtoB Vhost에 URLREWRITE 설정 후 503에러 발생
 Rewrite 설정시 하위 Extension 붙은 거래에 대하여 처리 불가문제 발생


현상
 rewrite 할 도메인에 대하여 rewrite로 전달 해주는 VHOST를 추가하고, 해당 VHOST를 SVGROUP에 포함시키지 않은 환경 설정으로 인해 하위 URI(Extension) 붙은 거래가 node로 빠져서 처리 불가.
 ※ 단. 하위 URI없는 순수 URL은 리라이팅 정상 처리
ex) http://www.abc.com => https://www.abc.com (o)
    http://www.abc.com/test.jsp => http://www.abc.com/test.jsp (x)

원인
 1) 환경파일 분석

  80포트를 사용하는 vh_def_abc 를 추가하고 해당 vhost로 유입 시 443포트로 URLREWRITE 적용

*VHOST
vh_def_abc                DOCROOT="해당 DOCROOT",
                          PORT=80,
                          HOSTNAME="서비스IP",
                          HostAlias="www.abc.com",
                          URLRewrite=Y,
                          URLRewriteConfig="config/rewrite_abc.cfg"
        
vh_abc                   DOCROOT="해당 DOCROOT",
                          PORT=443,
                          HOSTNAME="서비스IP",
                          HostAlias="www.abc.com",

*SVRGROUP
 htmlg          SVRTYPE=HTML

jsvg_abc     SVRTYPE=JSV, VHOSTNAME="vh_abc"
 
*SERVER
html   SVGNAME=htmlg, MinProc=300, MaxProc=600, Schedule=FA
abc    SVGNAME=jsvg_abc, MinProc=60, MaxProc=600, SvrChkTime=300, Schedule=FA
  
 2) vhost와 JEUS와의 연관 관계

  위 반영된 설정 대로 trace확인 결과 유입된 URI를 분석 후 Vhost와 맵핑되어 있는 JSV Server절을 찾으나, Vhost(vh_def_abc) 맵핑되어 있는 SVRGROUP을 찾을 수 없어 에러를 도출 합니다.

아래는 재현 시  HTH Trace 입니다.

[2018/02/02:15:37:51] HTH-1020 T http_parse.c:362 0: reqline(21)="GET /get.jsp HTTP/1.1"
[2018/02/02:15:37:51] HTH-1020 T http_parse.c:500 0: uripath after unescape[8]="/get.jsp"
[2018/02/02:15:37:51] HTH-1020 T http_io.c:198 0: cli_rdata_getline(45)="Accept: text/html, application/xhtml+xml, */*"
[2018/02/02:15:37:51] HTH-1020 T http_parse.c:819 0: parse_mime_hdr: key(6)="Accept", val(37)="text/html, application/xhtml+xml, */*"
--------------------------------------------------------(중략)--------------------------------------------------------
[2018/02/02:15:37:51] HTH-1020 T http_util.c:2202 make_errmsg("Request (%s) arrived at vhost (%s) is routed to server (%s). But, the server's vhost is different. svc=%s. Check WebtoB configuration.", ...): "Request (GET /get.jsp HTTP/1.1) arrived at vhost (vh_def_abc) is routed to server (abc). But, the server's vhost is different. svc=abc. Check WebtoB configuration."
[2018/02/02:15:37:51] HTH-1020 T http_msg.c:2038 0: send_http_error: svrtype=16, errmsg=Request (GET /get.jsp HTTP/1.1) arrived at vhost (vh_def_abc) is routed to server (abc). But, the server's vhost is different. svc=abc. Check WebtoB configuration.

 ==> Vhost와 연관된 server절을 찾을 수 없어 errmsg를 생성

[2018/02/02:15:37:51] HTH-1020 T main_hth.c:878 0: msg to tproc: msgtype=142, svcname=, len=222
[2018/02/02:15:37:51] HTH-1020 T http_io.c:2680 free--3() hp=6000000003210c70
[2018/02/02:15:37:51] HTH-1020 T http_error.c:358 _make_http_error_msg: requested_url=/get.jsp
[2018/02/02:15:37:51] HTH-1020 T http_util.c:1814 _wb_make_content_type(0000000000000000"(null)", 6000000000008ec0"text/html", 0, -1, -1):
[2018/02/02:15:37:51] HTH-1020 T http_util.c:1839 _wb_make_content_type--1: default_charset = "Off"
[2018/02/02:15:37:51] HTH-1020 T http_etc.c:2922 headers_response. svri=1, vhosti=0, hpp=9ffffffffffff050(6000000003217910)
[2018/02/02:15:37:51] HTH-1020 T http_etc.c:2974 headers_response. hpp=9ffffffffffff050(6000000003217910)
[2018/02/02:15:37:51] HTH-1020 T main_hth.c:1876 0: reply_to_client--1: fd=12, status=1, whp=6000000003217910, flags=0x20
[2018/02/02:15:37:51] HTH-1020 T main_hth.c:1908 0: msg to client: ind=0, msgtype=2301, svci=0, len=342, clen=192
[2018/02/02:15:37:51] HTH-1020 T http_io.c:1744 0: write_to_cli_async(60000000005e4060): whp=6000000003217910, 0(342)/342
[2018/02/02:15:37:51] HTH-1020 T http_io.c:1786 0: write_to_cli_async--1: write(12, 6000000003217970, 342)=342: errno=0
[2018/02/02:15:37:51] HTH-1020 T http_io.c:2783 0: accesslog_and_init_status: clii=0, rhp=0000000000000000, saved_rhp=60000000032a00c0, msgtype=2301, svrtype=16
[2018/02/02:15:37:51] HTH-1020 T http_log.c:897 process_log: logind=1, len=76, data="16.16.16.8 - - [02/Feb/2018:15:37:51 +0900] "GET /get.jsp HTTP/1.1" 503 192

 ==> 에러 메세지 발생 후 503에러 도출

 3) 결론
  WEBTOB에서 Rewritng Rule을 적용하기 이전에 vhost -> svrgroup -> sever 의 관계를 먼저 파악한 뒤 Rewritng Rule이 적용됨.

해결방안
 Rewritng Rule을 쓰기 위해서는 Vhost와 SERVER과의 구조(vhost -> svrgroup -> sever)가 필수적으로 구성이 되어야 함.

 문제의 환경파일을 아래와 같이 구성하여 Vhost와 SERVER과의 구조를 필수적으로 구성하여야 함.

*VHOST
vh_def_abc                DOCROOT="해당 DOCROOT",
                          PORT=80,
                          HOSTNAME="서비스IP",
                          HostAlias="www.abc.com",
                          URLRewrite=Y,
                          URLRewriteConfig="config/rewrite_abc.cfg"
        
vh_abc                   DOCROOT="해당 DOCROOT",
                          PORT=443,
                          HOSTNAME="서비스IP",
                          HostAlias="www.abc.com"

*SVRGROUP
htmlg          SVRTYPE=HTML
jsvg_abc       SVRTYPE=JSV, VHOSTNAME="vh_abc, vh_def_abc"
 
*SERVER
html   SVGNAME=htmlg, MinProc=300, MaxProc=600, Schedule=FA
abc    SVGNAME=jsvg_card, MinProc=60, MaxProc=600, SvrChkTime=300, Schedule=FA