[CPU 과점유] HP-UX 편

본 포스팅은 SunOS, Solaris 서버의 CPU 과점유 현상 발생 시 대처 방안을 가이드합니다.

---

성능을 측정하는데는 여러가지 요소가 있습니다.

그중 중요한 CPU는 WEB/WAS 뿐만아니라 H/W, Network등의 병목을 유발하는 주요 성능 포인트 입니다.

그럼 CPU 성능 이슈가 발생했을 때 어떻게 처리해야 할 지 OS별로 알아보도록 하겠습니다.

 

이번에는 HP-UX 입니다.

HP-UX의 경우 LINUX와 마찬가지로 top 명령어를 통해 확인이 가능하나, glance을 통해 확인하는 방법을 가이드 하도록 하겠습니다.

1. glance

- glance 툴은 시스템에 대한 전반적인 상태 정보, 프로세스 정보, 네트웍, DISK, 메모리등 다양한 정보를 모니터링 할 수 있습니다.

glance는 text모드, gui모드, advisor 모드를 제공합니다.

# glance –j [갱신간격(초)]

Resources PID: 20649, testd         PPID: 20636 euid:   202 User: xxxxxxx
--------------------------------------------------------------------------------
CPU Usage (util):      3.1 Log Reads :      0 Wait Reason    :    SLEEP
User/Nice/RT CPU:      1.6 Log Writes:      1 Total RSS/VSS  : 59.9mb/ 94.1mb
System CPU      :      0.8 Phy Reads :      0 Traps / Vfaults:    324/    132
Interrupt CPU   :      0.0 Phy Writes:      2 Faults Mem/Disk:      0/      0
Cont Switch CPU :      0.6 FS Reads  :      0 Deactivations  :      0
Scheduler       :     HPUX FS Writes :      0 Forks & Vforks :      0
Priority        :      168 VM Reads  :      0 Signals Recd   :      0
Nice Value      :       20 VM Writes :      0 Mesg Sent/Recd :    281/    562
Dispatches      :     1120 Sys Reads :      0 Other Log Rd/Wt:    562/    281
Forced CSwitch  :      473 Sys Writes:      2 Other Phy Rd/Wt:      0/      0
VoluntaryCSwitch:      634 Raw Reads :      0 Proc Start Time
Running CPU     :        1 Raw Writes:      0    Thu Sep 20 09:41:25 2007
CPU Switches    :       34 Bytes Xfer:   16kb                :

상단에는 전체적인 시스템 사용률 정보(CPU, Memory, Disk, Network등)가 나옵니다.

아래에는 각 프로세스들에 대한 리스트와 간략한 CPU, Memory, Block 정보들이 나옵니다.

상세 모니터링을 하기 위해서는 다음과 같은 단축키를 제공합니다. (주요 옵션)

s Key : select a single process ([프로세스 id입력])

c Key : cpu info

m Key : memory info

d Key : disk info

F Key : process Open files

Y Key : Global System Call

L Key : process System Call

사용 법 예제 :

- s Key : select a single process ([프로세스 id입력]) -> G Key (thread info) -> I Key select single thread([thread id입력]) -> I Key (detail info)

- F Key : Open files for process (inode를 이용하여 file search) -> find –inum [inode num]

ex) c Key (cpu info)

Cum Resources PID: 20649, testd         PPID: 20636 euid:   202 User: xxxxxxx
--------------------------------------------------------------------------------
CPU Usage (util):      6.1 Log Reads : 332970 Wait Reason    :    SLEEP
User/Nice/RT CPU:      4.1 Log Writes:  74576 Total RSS/VSS  : 59.9mb/ 94.1mb
System CPU      :      1.1 Phy Reads : 279343 Traps / Vfaults:    103/    240
Interrupt CPU   :      0.3 Phy Writes: 143562 Faults Mem/Disk:     97/    273
Cont Switch CPU :      0.5 FS Reads  :      2 Deactivations  :      0
Scheduler       :     HPUX FS Writes :      0 Forks & Vforks :      0
Priority        :      168 VM Reads  :      3 Signals Recd   :      0
Nice Value      :       20 VM Writes :      0 Mesg Sent/Recd : 267979/ 522426
Dispatches      :  1230510 Sys Reads : 279336 Other Log Rd/Wt: 522332/ 267946
Forced CSwitch  :   248770 Sys Writes: 143562 Other Phy Rd/Wt:      0/      0
VoluntaryCSwitch:   920883 Raw Reads :      2 Proc Start Time
Running CPU     :        1 Raw Writes:      0    Thu Sep 20 09:41:25 2007
CPU Switches    :    51757 Bytes Xfer: 9.25gb                :

 

​- java 프로세스(pid 20649)에 대한 모니터링을 설명하겠습니다.

- 각 Thread에 대한 정보를 확인 하기 위해 “G” 키를 입력합니다.

9923517   89.7/  92.4   50348    0.0/   0.0     na/    na      HPUX  241    PRI
9923518    0.0/   0.0     0.0    0.0/   0.0     na/    na      HPUX  137  SLEEP
9923519   0.1/   0.1   50080    0.0/   0.0     na/    na      HPUX  241    PRI
9930561    0.1/   0.2     135    0.0/   0.0     na/    na      HPUX  168  SLEEP
9948906    1.5/   1.6     849    0.0/   0.0     na/    na      HPUX  168  SLEEP
9948907    0.9/   0.9     492    0.0/   0.0     na/    na      HPUX  168  SLEEP
9948933   0.1/   0.2   48963    0.0/   0.0     na/    na      HPUX  241    PRI

- glance를 통해 해당 프로세스의 특정 thread 1개의 Thread가 90%CPU 사용

​

2. Thread Dump 생성

먼저 Sun HotSpot 계열 Thread Dump에 대해 간단히 살펴 보고 넘어가도록 하겠습니다.

Thread Dump 생성

- Java process에 signal을 전달하여 생성합니다. (SIGQUIT)
- Java process를 만든 벤더들이 내부적으로 SIGQUIT에 대한 signal을 catch하여 그 시점의 stack trace를 출력하는 것입니다.
- Unix 계열 (Sun, HP-UX, AIX, Linux 등)
# kill -3 [프로세스 ID]

생성 위치
- Sun 계열 (Sun, HP-UX, Linux 등)의 경우는 Thread dump를 수행하면 STOUT으로 출력됩니다. STOUT은 표준 출력을 말합니다. 표준 출력이란 프로세스가 기본적으로 생성되는 입출력 (FD) 중의 하나입니다. (0:STDIN, 1:STDOUT, 2:STDERR)
WAS의 경우 로그파일에 출력되게 됩니다.

# 참조 Thread 상태 정보
[Sun jdk 1.5]

- allocated : Thread가 생성되기 위해 메모리 할당 된 상태
- initialized : Thread가 초기화 된 상태
- runnable : Thread가 java virtual machine 내에서 수행 중인 상태
- waiting for monitor entry : Thread가 Monitor lock을 획득하기 위해 대기중인 상태
 Monitor lock이란 Multi thread 환경에서 thread를 동시 접근하는 것을 막아 database 부하를 줄이거나 thread 병합을 막는 역할을 합니다. 해당 lock은 synchronized 된 object에만 적용 됩니다. 정리하자면, synchronized 된 object를 현재 사용 중인지 아닌지 검사하는 것이 Monitor lock입니다.
- waiting on condition : Thread가 조건 변수(Condition Variable)에 의해 대기 중인 상태
- in object wait() : Thread가 Object.wait()으로 인해 대기 중인 상태
- sleeping : Thread가 I/O등에 의해 대기 중인 SLEEP 상태가 된 경우

[Sun jdk 1.6]

- NEW : Thread가 생성되기 위해 메모리에 할당 된 상태
- RUNNABLE : Thread가 java virtual machine 내에서 수행 중인 상태
- BLOCKED : Thread가 Monitor lock을 획득하기 위해 대기중인 상태
- WAITING : Thread가 특정 작업을 위해 다른 Thread를 무기한 대기하는 상태
- TIMED_WAITING : Thread가 특정 작업을 위해 정해진 시가만큼 다른 Thread를 대기하는 상태
- TERMINATED : Thread가 exited 된 상태

위 내용을 기반으로 Thread Dump를 생성합니다.

HP-UX의 경우 WAS Server Log 동일 경로의 jvm.log에 생성됩니다.

$JEUS_LOG_HOME/server1/jvm.log

 

3. Thread Dump 분석

Thread Dump를 편집기로 오픈 한 후 glance로 확인한 TID와 매칭되는 lwp_id를 찾습니다.

CPU 90%를 잡아 먹는 녀석을 드디어 찾았습니다.

"http1-6" daemon prio=10 tid=0x018bd800 nid=83 lwp_id=9923517 runnable [0x244c0000]
   java.lang.Thread.State: RUNNABLE
        at jeus_jspwork._700_while_5fjsp._jspService(_700_while_5fjsp.java:68)
        at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
        at jeus.servlet.jsp.JspServletWrapper.executeServlet(JspServletWrapper.java:66)
        at jeus.servlet.servlets.JspServlet.executeServlet(JspServlet.java:134)
        at jeus.servlet.servlets.JspServlet.execute(JspServlet.java:74)
        at jeus.servlet.engine.RequestProcessor.run(RequestProcessor.java:211)
        at jeus.util.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:1211)
        at jeus.util.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:1261)
        at jeus.servlet.engine.WebThreadPoolExecutor$WebRequestWorker.run(WebThreadPoolExecutor.java:340)
        at java.lang.Thread.run(Thread.java:744)

​어디서 많이 본 형태네요.

LINUX 편과 동일하게 아래와 같이 분석을 진행합니다.

 

4. 조치

WAS 엔지니어의 입장에서는 JSP 파일(상단의 Stack 정보를 통해 Compiled 된 jsp 파일을 찾을수 있음 - sleep.jsp)과 Compile java source를 전달하면 완료되지만, 직접 분석을 진행해 보도록 하겠습니다.

JSP 파일과 JAVA 파일을 열어보면 다음과 같습니다.

[sleep.jsp]

<%@ page contentType="text/html; charset=euc-kr" %>
<%
        int i=0;
        int sum=0;
        while (i<=0) {
                        sum=sum+i;
                        i=i++;
        }
%>

이거만 봐도... 문제가 있죠?? while문이 무한루프가 돌게 작성이 되어 있네요..

다만 단순한 소스가 아니고 Thread Dump 스택의 경우 아래와 같이 Compiled java source 기준으로 line(68)이 표시 되기 때문에 실제로는 java Source를 확인해야 합니다.

&quot;http1-13 [server1-487]&quot; daemon prio=10 tid=0x00007fb42400d000 nid=0x1e4f runnable [0x00007fb4687bc000]
   java.lang.Thread.State: RUNNABLE
        at jeus_jspwork._700_sleep_5fjsp._jspService(_700_sleep_5fjsp.java:68)
        at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
        at jeus.servlet.jsp.JspServletWrapper.executeServlet(JspServletWrapper.java:66)
        at jeus.servlet.engine.ServletWrapper.execute(ServletWrapper.java:149)
        at jeus.servlet.jsp.JspServletWrapper.execute(JspServletWrapper.java:40)
        at jeus.servlet.engine.RequestProcessor.run(RequestProcessor.java:211)
        at jeus.util.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:1211)
        at jeus.util.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:1261)
        at jeus.servlet.engine.WebThreadPoolExecutor$WebRequestWorker.run(WebThreadPoolExecutor.java:340)
        at java.lang.Thread.run(Thread.java:722)

 

[_700_sleep_5fjsp.java] 

     51     try {
     52       response.setContentType("text/html; charset=euc-kr");
     53       pageContext = _jspxFactory.getPageContext(this, request, response,
     54                         null, true, 8192, true);
     55       _jspx_page_context = pageContext;
     56       application = pageContext.getServletContext();
     57       config = pageContext.getServletConfig();
     58       session = pageContext.getSession();
     59       out = pageContext.getOut();
     60       _jspx_out = out;
     61
     62       out.write('\n');
     63
     64         int i=0;
     65         int sum=0;
     66         while (i<=0) {
     67                         sum=sum+i;
     68                         i=i++;
     69         }
     70
     71       out.write('\n');
     72     } catch (java.lang.Throwable t) {
     73       if (!(t instanceof javax.servlet.jsp.SkipPageException)){
     74         out = _jspx_out;
     75         if (out != null && out.getBufferSize() != 0)
     76           try {
     77             if (response.isCommitted()) {
     78               out.flush();
     79             } else {
     80               out.clearBuffer();
     81             }
     82           } catch (java.io.IOException e) {}
     83         if (_jspx_page_context != null) _jspx_page_context.handlePageException(t);
     84         else throw new ServletException(t);
     85       }
     86     } finally {
     87       _jspxFactory.releasePageContext(_jspx_page_context);
     88     }
     89   }

68 라인에 가봤더니 동일한 위치에서 걸려 있네요.. 해당 부분의 수정이 필요하다는 것을 판단하고 개발자에게 전달하면 1Cycle 완료!

자 다음에는 마지막 AIX 편으로 찾아 오겠습니다.

감사합니다.

# 댓글과 추천은 글쓴이에게 힘이됩니다!

 

 

- 요약

1. 먼저 JVM이 Hotspot mode로 작동하고 있어야 한다. (classic 모드가 아니어야 한다.) 옵션을 주지 않았으면 Hotspot 모드가 default이다.

2. glance를 실행해서 ‘G’를 누르고 WAS의 PID를 입력한다.
각 Thread의 CPU 사용률이 실시간으로 모니터링이 되는데.

여기서 CPU 사용률이 높은 Thread의 TID를 구한다.

3. kill -3 을 이용해서 Thread dump를 추출해서. 2에서 구한 TID와 Thread Dump상의 lwp_id가 일치하는 Thread를 찾으면 된다.