by-nc-sa     개발자, DBA가 함께 만들어가는 구루비 지식창고!

10046 Event




10046 Event ( Extended SQL Trace )이란..? SQL Tuning 의 핵심적인 도구 중 하나

  • 모든 SQL 문장의 Bind 변수 값을 추적할 수 있는 유일한 방법이다.( Level 4 )
  • 모든 SQL 문장의 대기 현상(Wait)을 추적할 수 있는 유일한 방법이다.( Level 8 )

V$SQL_BIND_CAPTURE View의 한계( 어느정도 추적 가능 )

  • 15분 간격으로 Capture를 수행한다. 주기는 _CURSOR_BIND_CAPTURE_INTERVAL Parameter 값에 의해 결정.( 기본 : 900초 ) 모든 추적은 불가능
  • 하나의 SQL Cursor에 대해 정해진 메모리 크기만큼만 Bind Capture 수행
    _CURSOR_BIND_CAPTURE_AREA_SIZE Parameter 값에 의해 결정.( 기본 : 2000(Byte) ) 누락 현상 발생
  • Oracle은 Select문장에 대해서만, 그리고 Bind 변수가 Where 절에서 사용되었을 경우에만 Bind Capture를 수행한다.
  • 최근에 Capture된 Bind 변수 값을 보여준다.

Monitoring View 종류

  • V4SESSION
  • V$SESSION_WAIT
  • V$SESSION_EVENT
  • V$SYSTEM_EVENT
  • V$ACTIVE_SESSION_HISTORY
  • DBA_HIST_ACTIVE_SESS_HISTORY
  • V$EVENT_HISTOGRAM
자동화 아이디어( 심풀하고 아름답나요?? )

@TRACE_ON 10046 8
ALTER SESSION SET EVENTS '&1 TRACE NAME CONTEXT FOREVER, LEVEL &2';

SELECT...

@TRACE_OFF
ALTER SESSION SET EVENTS '&1 TRACE NAME CONTEXT OFF';

@TRACE_FILE
------------------------------------------------------------------------------------
-- @NAME : TRACE_FILE
-- @AUTHOR : DION CHO
-- @DESCRIPTION : GET TRACE FILE NAME
------------------------------------------------------------------------------------
COLUMN TRACE_FILE_NAME NEW_VALUE TRACE_FILE
SELECT -- 아래 부분은 환경에 맞게 적절히 수정
      D.VALUE||'/'||P.VALUE||'_ora_'||S.SPID||'.trc' AS TRACE_FILE_NAME
 FROM (
       SELECT VALUE
        FROM V$PARAMETER
       WHERE NAME = 'instance_name' ) p
     ,(SELECT VALUE
        FROM V$PARAMETER
       WHERE NAME = 'user_dump_dest' ) d
     ,(SELECT SPID
        FROM V$PROCESS
       WHERE ADDR = (SELECT PADDR FROM V$SESSION WHERE SID = (SELECT SID FROM V$MYSTAT WHERE ROWNUM = 1) ))S
 ;
 
 PROMPT &TRACE_FILE
 
 @tkprof trc.out
 ho tkprof &trace_file &1
 
 ed trc.out
 |
준비
 SQL>  CREATE TABLE T_10046 AS
  2   SELECT CEIL( NUM / 100000) AS C1
  3     FROM (SELECT LEVEL NUM FROM DUAL CONNECT BY LEVEL <= 1000000);
  
 SQL> COMMIT;
 
 SQL> SELECT C1, COUNT(*)
  2    FROM T_10046
  3   GROUP BY C1
  4   ;

        C1   COUNT(*)
---------- ----------
         1     100000
         6     100000
         2     100000
         5     100000
         4     100000
         8     100000
         3     100000
         7     100000
         9     100000
        10     100000

10 개의 행이 선택되었습니다.


|
LEVLE. 1 - SQL의 RAW TRACLE 정보만 보여준다.
SQL> ALTER TABLE T_10046 PARALLEL 4;
SQL> ALTER SESSION SET EVENTS '10046 trace name context forever, level 1';

SQL> var b1 NUMBER;
SQL> exec :b1 := 1;

PL/SQL 처리가 정상적으로 완료되었습니다.

SQL>  SELECT COUNT(*)
  2     FROM T_10046
  3    WHERE C1 = :b1;

  COUNT(*)
----------
    100000
    
SQL> COLUMN TRACE_FILE_NAME NEW_VALUE TRACE_FILE
SQL> SELECT -- 아래 부분은 환경에 맞게 적절히 수정
  2        D.VALUE||'/'||P.VALUE||'_ora_'||S.SPID||'.trc' AS TRACE_FILE_NAME
  3   FROM (
  4         SELECT VALUE
  5          FROM V$PARAMETER
  6         WHERE NAME = 'instance_name' ) p
  7       ,(SELECT VALUE
  8          FROM V$PARAMETER
  9         WHERE NAME = 'user_dump_dest' ) d
 10       ,(SELECT SPID
 11          FROM V$PROCESS
 12         WHERE ADDR = (SELECT PADDR FROM V$SESSION WHERE SID = (SELECT SID FROM V$MYSTAT WHERE ROWNUM = 1) ))S
 13   ;

TRACE_FILE_NAME
--------------------------------------------------------------------------------------------------------------------
/usr/local/oracle/admin/luxtv/udump/luxtv_ora_5592.trc

SQL>
SQL>  PROMPT &TRACE_FILE;
/usr/local/oracle/admin/luxtv/udump/luxtv_ora_5592.trc
SQL>
SQL>
SQL> ho tkprof /usr/local/oracle/admin/luxtv/udump/luxtv_ora_5592.trc trc_01.out;

SELECT COUNT(*)
  FROM T_10046
 WHERE C1 = :b1

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.17          0          4          0           0
Fetch        2      0.00       0.01          0          0          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.19          0          4          0           1

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 79

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT AGGREGATE (cr=3 pr=0 pw=0 time=189632 us)
      4   PX COORDINATOR  (cr=3 pr=0 pw=0 time=189430 us)
      0    PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
      0     SORT AGGREGATE (cr=0 pr=0 pw=0 time=0 us)
      0      PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)
      0       TABLE ACCESS FULL T_10046 (cr=0 pr=0 pw=0 time=0 us)


|
LEVEL 4 - SQL의 Raw Trace와 Bind 변수의 상수값을 함께 보여준다.(Bind변수값을 확인하기 위해서는 직접 TRC파일을 검색하여야 한다.)

ALTER SESSION SET EVENTS '10046 trace name context forever, level 4';

 PARSING IN CURSOR #3 len=449 dep=0 uid=79 oct=3 lid=79 tim=1269978134951853 hv=4020523396 ad='966cc680'
SELECT -- 아래 부분은 환경에 맞게 적절히 수정
      D.VALUE||'/'||P.VALUE||'_ora_'||S.SPID||'.trc' AS TRACE_FILE_NAME
 FROM (
       SELECT VALUE
        FROM V$PARAMETER
       WHERE NAME = 'instance_name' ) p
     ,(SELECT VALUE
        FROM V$PARAMETER
       WHERE NAME = 'user_dump_dest' ) d
     ,(SELECT SPID
        FROM V$PROCESS
       WHERE ADDR = (SELECT PADDR FROM V$SESSION WHERE SID = (SELECT SID FROM V$MYSTAT WHERE ROWNUM = 1) ))S

END OF STMT
PARSE #3:c=0,e=31,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1269978134951849
BINDS #3:
EXEC #3:c=0,e=46,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1269978134951990
FETCH #3:c=4999,e=4849,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=1269978134956866
FETCH #3:c=1000,e=440,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1269978134957493
STAT #3 id=1 cnt=1 pid=0 pos=1 obj=0 op='HASH JOIN  (cr=0 pr=0 pw=0 time=4850 us)'
STAT #3 id=2 cnt=1 pid=1 pos=1 obj=0 op='MERGE JOIN CARTESIAN (cr=0 pr=0 pw=0 time=4073 us)'
STAT #3 id=3 cnt=1 pid=2 pos=1 obj=0 op='HASH JOIN  (cr=0 pr=0 pw=0 time=3665 us)'
STAT #3 id=4 cnt=1385 pid=3 pos=1 obj=0 op='MERGE JOIN CARTESIAN (cr=0 pr=0 pw=0 time=2909 us)'
STAT #3 id=5 cnt=1 pid=4 pos=1 obj=0 op='FIXED TABLE FULL X$KSPPI (cr=0 pr=0 pw=0 time=538 us)'
STAT #3 id=6 cnt=1385 pid=4 pos=2 obj=0 op='BUFFER SORT (cr=0 pr=0 pw=0 time=1212 us)'
STAT #3 id=7 cnt=1385 pid=6 pos=1 obj=0 op='FIXED TABLE FULL X$KSPPCV (cr=0 pr=0 pw=0 time=1388 us)'
STAT #3 id=8 cnt=1 pid=3 pos=2 obj=0 op='FIXED TABLE FULL X$KSPPI (cr=0 pr=0 pw=0 time=330 us)'
STAT #3 id=9 cnt=1 pid=2 pos=2 obj=0 op='BUFFER SORT (cr=0 pr=0 pw=0 time=403 us)'
STAT #3 id=10 cnt=1 pid=9 pos=1 obj=0 op='FIXED TABLE FULL X$KSUPR (cr=0 pr=0 pw=0 time=370 us)'
STAT #3 id=11 cnt=1 pid=10 pos=1 obj=0 op='NESTED LOOPS  (cr=0 pr=0 pw=0 time=239 us)'
STAT #3 id=12 cnt=1 pid=11 pos=1 obj=0 op='FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=232 us)'
STAT #3 id=13 cnt=1 pid=12 pos=1 obj=0 op='COUNT STOPKEY (cr=0 pr=0 pw=0 time=10 us)'
STAT #3 id=14 cnt=1 pid=13 pos=1 obj=0 op='FIXED TABLE FULL X$KSUMYSTA (cr=0 pr=0 pw=0 time=9 us)'
STAT #3 id=15 cnt=1 pid=14 pos=1 obj=0 op='FIXED TABLE FULL X$KSUSGIF (cr=0 pr=0 pw=0 time=3 us)'
STAT #3 id=16 cnt=1 pid=11 pos=2 obj=0 op='FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=3 us)'
STAT #3 id=17 cnt=1385 pid=1 pos=2 obj=0 op='FIXED TABLE FULL X$KSPPCV (cr=0 pr=0 pw=0 time=3 us)'
        
alter session set events '10046 trace name context off';
                                                                                                
|
LEVEL 8 -SQL의 Raw Trace와 Wait Event를 함께 보여준다.
SELECT -- 아래 부분은 환경에 맞게 적절히 수정
      D.VALUE||'/'||P.VALUE||'_ora_'||S.SPID||'.trc' AS TRACE_FILE_NAME
 FROM (
       SELECT VALUE
        FROM V$PARAMETER
       WHERE NAME = 'instance_name' ) p
     ,(SELECT VALUE
        FROM V$PARAMETER
       WHERE NAME = 'user_dump_dest' ) d
     ,(SELECT SPID
        FROM V$PROCESS
       WHERE ADDR = (SELECT PADDR FROM V$SESSION WHERE SID = (SELECT SID FROM V$MYSTAT WHERE ROWNUM = 1) ))S

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.03       0.03          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0          0          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.04       0.04          0          0          0           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 79

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  HASH JOIN  (cr=0 pr=0 pw=0 time=7351 us)
      1   MERGE JOIN CARTESIAN (cr=0 pr=0 pw=0 time=5887 us)
      1    HASH JOIN  (cr=0 pr=0 pw=0 time=5014 us)
   1385     MERGE JOIN CARTESIAN (cr=0 pr=0 pw=0 time=3036 us)
      1      FIXED TABLE FULL X$KSPPI (cr=0 pr=0 pw=0 time=819 us)
   1385      BUFFER SORT (cr=0 pr=0 pw=0 time=1325 us)
   1385       FIXED TABLE FULL X$KSPPCV (cr=0 pr=0 pw=0 time=1389 us)
      1     FIXED TABLE FULL X$KSPPI (cr=0 pr=0 pw=0 time=331 us)
      1    BUFFER SORT (cr=0 pr=0 pw=0 time=862 us)
      1     FIXED TABLE FULL X$KSUPR (cr=0 pr=0 pw=0 time=825 us)
      1      NESTED LOOPS  (cr=0 pr=0 pw=0 time=685 us)
      1       FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=679 us)
      1        COUNT STOPKEY (cr=0 pr=0 pw=0 time=14 us)
      1         FIXED TABLE FULL X$KSUMYSTA (cr=0 pr=0 pw=0 time=10 us)
      1          FIXED TABLE FULL X$KSUSGIF (cr=0 pr=0 pw=0 time=4 us)
      1       FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=3 us)
   1385   FIXED TABLE FULL X$KSPPCV (cr=0 pr=0 pw=0 time=5 us)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       2        0.00          0.00
  SQL*Net message from client                     2        0.00          0.00
|
LEVEL 12 -SQL의 Raw Trace + Bind 상수값 + Wait Event를 함께 보여준다(Bind변수값을 확인하기 위해서는 직접 TRC파일을 검색하여야 한다.)
TKPROF의 결과값은 LEVEL 8 과 같다.

문서정보

Enter labels to add to this page:
Please wait 
Looking for a label? Just start typing.