SQL 트레이스

(1) 자기 세센에 트레이스 걸기

  • 현재 자신이 접속해 있는 세션에만 트레이스 설정

SQL> alter session set sql_trace = true;
SQL> SELECT * FROM emp WHERE empno = 7788;
SQL> SELECT * FROM dual;
SQL> alter session set sql_trace = false;

user_dump_dest에 지정된 디렉토리 밑에 트레이스(.trc) 파일이 생성됨

  • 트레이스 파일찾는 스크립트 실행(trc 파일의 이름이 출력된다)

SELECT r.value || '/' || LOWER(t.instance_name) || '_ora_'
    || ltrim(to_char(p.spid)) || '.trc' trace_file
  FROM v$process p, v$session s, v$parameter r, v$instance t
 WHERE p.addr = s.paddr
   AND r.name = 'user_dump_dest'
   AND s.sid = (SELECT sid FROM v$mystat WHERE rownum = 1)
;

TRACE_FILE
-----------------------------------------------------------
c:\app\manon94\diag\rdbms\orcl\orcl\trace/orcl_ora_2444.trc


TIP!

더 쉽게 자기 세션 트레이스 파일 찾기


SQL> alter session set tracefile_identifier ='oraking'
orcl_ora_2444_oraking.trc


  • tkprof 사용하여 프로파일 파일 생성(report.prf를 생성)

$ tkprof orcl_ora_4000.trc report.prf sys=no;  //sys=no옵션: sql파싱과정에서 내부적으로 수행되는 sql문장 제외함

$vi report.prf
================================================================================
Call     Count CPU Time Elapsed Time       Disk      Query    Current       Rows
------- ------ -------- ------------ ---------- ---------- ---------- ----------
Parse        1    0.000        0.002          0          0          0          0
Execute      1    0.000        0.000          0          0          0          0
Fetch        1    0.000        0.028          3          4          0          0
------- ------ -------- ------------ ---------- ---------- ---------- ----------
Total        3    0.000        0.031          3          4          0          0

Misses in library cache during parse: 1
Optimizer goal: ALL_ROWS
Parsing user: APPS (ID=44)

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  STATEMENT
      0   TABLE ACCESS BY INDEX ROWID EMP (cr=4 pr=3 pw=0 time=28400 us)
      1    INDEX UNIQUE SCAN EMP_U1 (cr=3 pr=2 pw=0 time=22438 us)(Object ID 6485271


Call통계 컬럼 의미

항목설명
call커서 상태에 따라 Parse, Execute, Fetch 세 개의 Call로 나누어 각각에 대한 통계정보를 보여줌

\- Parse : 커서를 파싱하고 실행계획을 생성하는 데 대한 통계

\- Execute : 커서의 실행 단계에 대한 통계

\- Fetch : 레코드를 실제로 Fetch하는 데 대한 통계
countParse, Execute, Fetch 각 단계가 수행된 횟수
cpu현재 커서가 각 단계에서 사용한 cpu time
elapsed현재 커서가 각 단계를 수행하는 데 소요된 시간
disk디스크로부터 읽은 블록 수
queryConsistent 모드에서 읽은 버퍼 블록 수
currentCurrent모드에서 읽은 버퍼 블록수
rows각 단계에서 읽거나 갱신한 처리건수

Auto Trace의 실행통계 항목과 비교

실행 통계Call
db block getscurrent
consistent getsquery
physical readsdisk
SQL*Net roundtrips to/from clientfetch count
rows processedfetch rows
  1. 참고

Rows     Row Source Operation
-------  ---------------------------------------------------
    728    HASH JOIN OUTER (cr=32575 r=0 w=0 time=663883 us)  //us = microsecond

Rows각 수행 단계에서 출력된 로우 수
crConsistent 모드 블록 읽기
r(pr)디스크 블록 읽기
w(pw)디스크 블록 쓰기
time소요시간

중요!

부도는 자식 노드 값을 누적한 값을 갖는다

  • 10046 이벤트 트레이스를 추가하는 방법 - 아래 명령어를 실행한 다음 위 (1),(2),(3) 과정 반복

alter session set events '10046 trace name context forever, level 8';

레벨 값은 1,4,8,12로 설정 할 수 있음
레벨4 이상으로 설정할 경우 파일의 크기가 급격하게 커질 수 있으므로 주의해야함

레벨설명
레벨1기본 정보
레벨4기본 정보 + Binding 정보
레벨8기본 정보 + Waiting 정보
레벨12기본 정보 + Binding 정보 + Waiting 정보

주의

레벨이 4이상인 경우, 트레이스 파일이 급격히 커지므로, 모니터링 후 적정 시점에서 정지시켜야 함

Elapsed time = CPU time + Waint time
= Response 시점 - Call 시점

select문 수행 = 최소 3번의 Call 발생
Parse call + Execute call + Fetch call

다량의 데이터 전송 시, Fetch call = 전송 레코드 건수 / ArraySize 만큼 발생

DML문 수행 = 2번의 Call 발생
Parse call + Execute call


set timing on
set arraysize 100
alter session set evetns '10046 trace name context forever, level 8';
select * from big_table where id <= 1000;
............
1000개 행이 선택되었습니다.

경      과 : 00:00:08:71

질의문 실행 흐름

(2) 다른 세센에 트레이스 걸기

  • 9i

exec dbms_system.set_ev(145, 3, 10046, 12, '');  //시리얼 번호가 3인 145번 세션에서 레벨 12로 10046 이벤트 트레이스
exec dbms_system.set_ev(145, 3, 10046, 0, '');   //해제

  • 10i

begin
    dbms_monitor.session_trace_enable(  //시작
    session_id=>145, 
    serial_num=>3, 
    waits=>TRUE, 
    binds=>TRUE);
end;


begin
    dbms_monitor.session_trace_disable(
    session_id=>145, 
    serial_num=>3);
end;

  • oradebug 명령어


oradebug setospid 3796    //트레이스 설정
oradebug unlimit /* 트레이스 파일의 크기를 없앰 */
oradebug event 10046 trace name context forever, level 8

oradebug tracefile_name /* 트레이스 파일 이름 확인 */

oradebug event 10046 trace name context off /* 트레이스 해제 */
oradebug close_trace 

(3) Service, Modele, Action 단위로 트레이스 걸기

1. Service 이름에 트레이스 걸기

세션 이름이 eCRM인 세션에 모두 트레이스 걸기


begin
  dbms_monitor.serv_mod_act_trace_enable(
  service_name=>'eCRM', 
  module_name=>dbms_monitor.all_modules,
  action_name=>dbms_monitor.all_actions,
  waits=>true, 
  binds=>true);
end;

트레이스 설정 확인


select 
     primary_id service_name
   , qualifier_id1 module
   , qualifier_id2 action
   , waits
   , binds
from dba_enabled_traces;

트레이스 해제


begin
  dbms_monitor.serv_mod_act_trace_disable(
  service_name=>'eCRM',
  module_name=>dbms_monitor.all_modules,
  action_name=>dbms_monitor.all_actions);
end;

2. 특정 module 트레이스 걸기

module 이름/ action 이름 변경


begin
  dbms_application_info.set_module(
  module_name=>'emp manager',
  action_name=>'select emp');
end;

특정 module에 트레이스 걸기


begin
   dbms_monitor.serv_mod_act_trace_enable(
   service_name=>'eCRM', 
   module_name=>'emp manager',
   action_name=>dbms_monitor.all_actions,
   waits=>true, 
   binds=>true);
end;

트레이스 설정 확인


select 
     primary_id service_name
   , qualifier_id1 module
   , qualifier_id2 action
   , waits
   , binds
from dba_enabled_traces;

트레이스 해제


begin
   dbms_monitor.serv_mod_act_trace_disable(
   service_name=>'eCRM', 
   module_name=>'emp manager',
   action_name=>dbms_monitor.all_actions);
end;

특정값으로 설정된 세션에만 트레이스 걸기


exec dbms_session.set_identifier('oraking');  //설정
----------------------------------------------------
begin
   dbms_monitor.client_id_trace_enable(
   client_id=>'oraking',
   waits=>false, 
   binds=>false);
end;