1. HOME
  2. [종료]대용량 데이터베이스 스터디
  3. 2011년 상반기 대용량데이터베이스 스터디
  4. 10046 Event

10046 Event (by ljh1148) [2011.03.18]

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
자동화 아이디어( 심풀하고 아름답나요?? )
{CODE}

@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

{CODE}
준비
{CODE}
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 개의 행이 선택되었습니다.

{CODE}LEVLE. 1 - SQL의 RAW TRACLE 정보만 보여준다.
{CODE}
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)

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

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';

{CODE}LEVEL 8 -SQL의 Raw Trace와 Wait Event를 함께 보여준다.
{CODE}
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

{CODE}
LEVEL 12 -SQL의 Raw Trace + Bind 상수값 + Wait Event를 함께 보여준다(Bind변수값을 확인하기 위해서는 직접 TRC파일을 검색하여야 한다.)
TKPROF의 결과값은 LEVEL 8 과 같다.
  1. HOME
  2. [종료]대용량 데이터베이스 스터디
  3. 2011년 상반기 대용량데이터베이스 스터디
  4. 10046 Event