콜트리분석

• 특정 프로세스가 현재 어떤 콜 트리 구조를 가지고 있는지 분석하는 기법
• 프로세스가 특정 함수를 호출하면서 행(Hang)상태에 빠지거나 CPU와 같은 자원을 과다하게 사용하는 현상을 분석할 때 유용.

콜 트리 분석 기초

콜 트리 얻는 법

oradebug short_stack

SQL >
  l  oradebug setmypid
명령문을 처리했습니다.

SQL >
  l  oradebug short_stack
ksedsts()+585<-ksdxfstk()+44<-ksdxen_int()+6463<-ksdxen()+17<-opiodr()+1662<-ttcpip()+1325<-opitsk()+2040<-opiino()+1258<-opiodr()+1662<-opidrv()+864<-sou2o()+98<-opimai_real()+158<-opimai()+191<-OracleThreadStart()+724<-000000007682652D<-0000000076D0C521

• 왼쪽에 있을수록 가장 현재 실행 중인 함수
• 오른쪽에 있을수록 현재 함수를 실행하기 위해 이전 단계에서 실행된 함수에 해당

콜 스택 덤프(Call Stack Dump)

SQL >
  l  oradebug dump callstack 1
명령문을 처리했습니다.

----- Call Stack Trace -----
calling              call     entry                argument values in hex
location             type     point                (? means dubious value)
-------------------- -------- -------------------- ----------------------------
ksedst1()+129        CALL???  skdstdst()           00C465990 00C2F7FE0 300000048
                                                   0FFFFFFFD
ksedst_tracecb()+69  CALL???  ksedst1()            000000000 01CF59CC1
                                                   243AAE1482B7 01CF5DB58
ksdxfdmp()+1909      CALL???  ksedst_tracecb()     01CF5A020 000000000 000000000
                                                   000000000
ksdxen_int()+6463    CALL???  ksdxfdmp()           01CF5C160 000000010 000000003
                                                   01CF5AFE0
ksdxen()+17          CALL???  ksdxen_int()         7FF00000056 000000011
                                                   01CF5E100 000000001
opiodr()+1662        CALL???  ksdxen()             000000001 243A0000001C
                                                   01CF5E100 01CF5B350
ttcpip()+1325        CALL???  opiodr()             000000056 000000011 01CF5E100
              ...
OracleThreadStart()  CALL???  opimai()             000000000 006DF0B34 0000000E8
+724                                               000000878
000000007682652D     CALL???  OracleThreadStart()  00DA9FF18 000000000 000000000
                                                   000000000
0000000076D0C521     CALL???  0000000076826520     000000000 000000000 000000000
                                                   000000000
----- End of Call Stack Trace -----

• 콜 스택의 위에 있을수록 현재 실행 중인 함수에 가까운 단계

함수명의 의미

• 함수명 앞의 세자리에서 네자리 정도는 Prefix로 각 함수가 사용되는 코드 영역을 가르킨다. (kks로 시작하는 함수는 Kernel Kompile Shared SQL 영역에 해당하는 함수)
• p.420 ~ 439 참고

OS의 명령어를 이용한 콜분석

• Strace, truss, tusc 와 같은 명령어들은 특정 프로세스가 호출하는 시스템 콜(System Call)을 추적하는데 사용합니다.
• 서버 프로세스의 비정상적인 I/O 문제나 행(Hang) 문제를 분석하기 위한 용도로 종종 사용됩니다.
• 일부 OS가 제공하는 pstack과 같은 명령은 오라클의 콜 스택 덤프와 거의 동일한 기능을 제공합니다.
• 오라클 서버에서의 접속이 불가능할 정도의 상황이라면 이러한 명령을 사용해서 동일한 분석을 수행할 수 있습니다.

strace

Linux 계열의 OS에서 사용

strace -ttT -o strace.txt -p 32319

strace -c -ttT -o strace.txt -p 32319


17:30:42.799348 read(16, 0x133ba626, 2064) = ? ERESTARTSYS (To be restarted) <2.806911>
17:30:45.615125 --- SIGALRM (Alarm clock) @ 0 (0) ---
17:30:45.615308 rt_sigprocmask(SIG_BLOCK, [], NULL, 8) = 0 <0.000031>
17:30:45.615465 gettimeofday({1335515445, 615508}, NULL) = 0 <0.000022>
17:30:45.615578 gettimeofday({1335515445, 615620}, NULL) = 0 <0.000024>
17:30:45.615688 gettimeofday({1335515445, 615717}, NULL) = 0 <0.000020>
17:30:45.615782 rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 8) = 0 <0.000021>
17:30:45.615883 gettimeofday({1335515445, 615911}, NULL) = 0 <0.000020>
17:30:45.615994 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0 <0.000026>
17:30:45.616109 rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 8) = 0 <0.000020>
17:30:45.616198 gettimeofday({1335515445, 616225}, NULL) = 0 <0.000020>
17:30:45.616291 rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 8) = 0 <0.000019>
17:30:45.616376 gettimeofday({1335515445, 616403}, NULL) = 0 <0.000019>
17:30:45.616464 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0 <0.000021>
17:30:45.616561 rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 8) = 0 <0.000024>
17:30:45.616664 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0 <0.000022>
17:30:45.616765 rt_sigprocmask(SIG_UNBLOCK, [], NULL, 8) = 0 <0.000028>
17:30:45.616859 rt_sigreturn(0x1)       = 0 <0.000023>
17:30:45.616958 read(16,  <unfinished ...>

Truss

AIX 계열의 OS에서 사용

truss -adD -o <output_file> -p <pid>

truss -c -adD -o <output_file> -p <pid>

Tusc

HP-UX 계열의 OS에서 사용

tusc -aT -o <output_file> <pid>

tusc -c -aT -o <output_file> <pid>

pstack

• Process Stack Trace를 보여주는 OS 명령어
• 오라클이 제공하는 콜 스택 명령과 거의 동일

pstack 32319

#0  0x000000355980d590 in __read_nocancel () from /lib64/libpthread.so.0
#1  0x000000000497201e in snttread ()
#2  0x000000000496f059 in nttrd ()
#3  0x000000000485ddca in nsprecv ()
#4  0x0000000004861a0f in nsrdr ()
#5  0x000000000483b750 in nsdo ()
#6  0x000000000483b032 in nsbrecv ()
#7  0x0000000004878e7e in nioqrc ()
#8  0x000000000130dc7f in opikndf2 ()
#9  0x000000000130b807 in opitsk ()
#10 0x000000000130e9e4 in opiino ()
#11 0x00000000013103f4 in opiodr ()
#12 0x0000000001301e13 in opidrv ()
#13 0x0000000001e8ca2a in sou2o ()
#14 0x00000000006e901b in opimai_real ()
#15 0x00000000006e8f6c in main ()