V$SESSION 뷰의 WAIT_TIME_MICRO 및 TIME_SINCE_LAST_WAIT_MICRO 칼럼에 대한 명확한 이해

1. SECONDS_IN_WAIT 및 WAIT_TIME 칼럼의 문제점


11g 부터 제공되는 WAIT_TIME_MICROTIME_SINCE_LAST_WAIT_MICRO 칼럼은 기존에 제공되던 SECONDS_IN_WAIT 및 WAIT_TIME 칼럼의 한계를 뛰어넘는 매우 유용한 데이터를 제공합니다. 기존에 제공되는 SECONDS_IN_WAIT 및 WAIT_TIME 칼럼의 한계점은 다음과 같습니다.

  • 세션 상태가 WAITING인 경우, SECONDS_IN_WAIT 칼럼은 대기이벤트가 지속된 시간을 제공합니다. 하지만 enqueue를 제외한 일반적인 대기이벤트 (예를 들어 db file sequential read) 들의 1회 대기 시간은 대략 수 밀리세컨 ~ 수십 밀리세컨 정도이므로 초 단위로 제공되는 SECONDS_IN_WAIT 칼럼에서는 대부분 0으로 표시됩니다.
  • 세션 상태가 WAITING이 아닌 경우 (ON CPU 상태인 경우), CPU를 사용한 시간을 확인할 수 가 없습니다.
  • 세션 상태가 WAITING이 아닌 경우 (ON CPU 상태인 경우), 이전 대기가 지속된 시간을 확인할 수 없습니다. 단순히 이전 대기가 1/100초 이내였는지 정도의 여부만을 확인할 수 있을 뿐입니다.
이러한 구조적인 한계점으로 인해 11g 부터는 SECONDS_IN_WAIT 및 WAIT_TIME 칼럼 대신에 WAIT_TIME_MICRO 및 TIME_SINCE_LAST_WAIT_MICRO 칼럼을 사용하는 것을 권고하고 있습니다.



2. WAIT_TIME_MICRO 및 TIME_SINCE_LAST_WAIT_MICRO 칼럼의 이해


세션 상태가 WAITING (V$SESSION.WAIT_TIME=0)인 경우에, WAIT_TIME_MICRO 칼럼은 ‘대기 지속 시간’을 의미합니다. 이때 TIME_SINCE_LAST_WAIT_MICRO 칼럼 값은 0입니다.

세션 상태가 ON_CPU (V$SESSION.WAIT_TIME0)인 경우에, WAIT_TIME_MICRO 칼럼은 ‘마지막 (바로 직전) 대기 지속 시간’을 의미하고, TIME_SINCE_LAST_WAIT_MICRO 칼럼은 ‘마지막 대기 이후부터 지금까지의 경과 시간’을 의미합니다. 다시 말해 CPU 사용 지속 시간을 의미합니다. (그림-1 참조)

그림-1. WAIT_TIME_MICRO 및 TIME_SINCE_LAST_WAIT_MICRO 개념도

%ec%84%b1%eb%8a%a56-1

3. WAIT_TIME_MICRO 및 TIME_SINCE_LAST_WAIT_MICRO 칼럼을 이용한 세션 액티비티 모니터링 방안


세션이 현재 ON_CPU 상태인 경우에, “수식-1″을 이용해서 대기시간과 CPU 사용시간의 비율을 계산할 수 있습니다.

수식-1. SESS_ACTIVITY(%) 수식

 SESS_ACTIVITY(%) = (TIME_SINCE_LAST_WAIT_MICRO /
(WAIT_TIME_MICRO + TIME_SINCE_LAST_WAIT_MICRO)) * 100

SESS_ACTIVITY(%)가 높을수록 세션 활동이 원활히 진행된다는 것을 의미합니다. 다시 말해 대기 시간 대비 CPU 사용 시간의 비율이 높다는 것을 의미합니다. 그럼 실제 부하를 유발시켜 해당 칼럼을 이용한 모니터링의 효율성을 확인해보도록 하겠습니다.

4. db file sequential read 대기이벤트 모니터링 예제


-- 비효율적인 인덱스 스캔을 수행하는 SQL 수행 

SCOTT@OOW1:1> declare
v1 number;
begin
 for i in 1..100000 loop
    execute immediate 'alter system flush buffer_cache';
    select /*+ index(a) */ count(*)  into v1 from big_t a where c1 > ' ';
 end loop;
end;
/

SYS@OOW1:1>@mon_1_sess 183
                                                                                               TIME_SINCE
       WAIT                                                               SESS      WAIT_TIME   LAST_WAIT
   SID STATUS   STATUS         SEQ# EVENT                          ACTIVITY(%)    (millisecs) (millisecs)
------ -------- -------- ---------- ------------------------------ ----------- -------------- -----------
   183 WAITING  ACTIVE        51201 db file sequential read                             3.500         .00
SCOTT@OOW1:1> /

                                                                                               TIME_SINCE
       WAIT                                                               SESS      WAIT_TIME   LAST_WAIT
   SID STATUS   STATUS         SEQ# EVENT                          ACTIVITY(%)    (millisecs) (millisecs)
------ -------- -------- ---------- ------------------------------ ----------- -------------- -----------
   183 WAITING  ACTIVE        51350 db file sequential read                             4.730         .00
SCOTT@OOW1:1> /

                                                                                               TIME_SINCE
       WAIT                                                               SESS      WAIT_TIME   LAST_WAIT
   SID STATUS   STATUS         SEQ# EVENT                          ACTIVITY(%)    (millisecs) (millisecs)
------ -------- -------- ---------- ------------------------------ ----------- -------------- -----------
   183 ON_CPU   ACTIVE        51519 db file sequential read               63.5          2.120        3.68

.. 이하 생략

분석결과
싱글 블록 IO에 대한 대기 시간은 대부분 5 밀리세컨 이내이므로 디스크 IO 속도는 양호합니다. 그리고 ON_CPU 상태인 경우를 보면 대기 시간 대비 CPU 사용 시간 비율이 높은 것을 알 수 있습니다.

모니터링 스크립트

set feedback off
set verify   off
set pages 1000

col sid           for 99999
col wait_status   for a8 heading 'WAIT|STATUS'
col event         for a30
col sess_activity for 999.9 heading 'SESS|ACTIVITY(%)'
col wait_time     for 9,999,999.999 heading 'WAIT_TIME|(millisecs)'
col time_since_last_wait for 999.99 heading 'TIME_SINCE|LAST_WAIT|(millisecs)'

define __SID=&1

SELECT
     a.sid ,
     decode(a.wait_time,0,'WAITING','ON_CPU') wait_status ,
     a.status,
     a.seq#,
     a.event ,
     case
       when a.wait_time=0 then null
       else ((a.time_since_last_wait_micro)/(a.time_since_last_wait_micro+a.wait_time_micro))*100
     end sess_activity,
     round(a.wait_time_micro/1000,2) wait_time,
     round(a.time_since_last_wait_micro/1000,2) time_since_last_wait
FROM  v$session a
WHERE a.sid in (&__SID);
Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s