1.7 10053 Event Trace
2011.09.06 20:43
10053 Event Trace
과거: Access Path와 조인순서, 조인방법이 잘못되는 경우 그 이유를 알기 위해
현재: Query Transformation의 동작 추적에 이용
장점: Logical Optimization 입장에서 볼 때 가장 상세한 레벨의 동작방식을 설명
단점: Trace의 내용이 너무 길어 분석이 어렵다는 점
발생 방법
ALTER SESSION SET optimizer_mode = first_rows_1 --
ALTER SESSION SET EVENTS ‘10053 trace name context forever, level 1’; -- Trace 생성 시작
ALTER SESSION SET EVENTS ‘10053 trace name context off’; -- Trace 생성 끄기
설정할 수 있는 레벨 값은 1, 4, 8, 12 이며 레벨1은 일반적인 SQL 트레이스와 같고,
4나 12로 설정했을 때는 바인드 변수에 대한 정보를 확인할 수 있다.
8이나 12로 설정하면, SQL 수행 도중 대기 이벤트가 발생할 때마다 로그처럼 기록
LEVEL - 1: 기본 정보
LEVEL - 4: 기본 정보 + Binding 정보
LEVEL – 8: 기본 정보 + Waiting 정보
LEVEL – 12: 기본 정보 + Binding 정보 + Waiting 정보
First_rows_1로 한 이유는 아래 설명될 Trace에서 어떻게 출력되는지 알아보기 위해서
-- 실제 수행한 쿼리
|
Select /*+ QB_NAME(main) */ user_id, name, home_tel, mobile_tel From tb_user u WHERE EXISTS (SELECT /*+ QB_NAME(sub) */ NULL FROM tb_user_point p WHERE u.user_id = p.user_id AND p.event_point= :v_event_point) order by u.user_id desc; |
이후에 쿼리를 실행하면 user_dump_dest 파라미터에 지정된 서버 디렉토리 밑에 트레이스 파일(.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) ; |
TKProf 유틸리티 사용 à 트레이스 파일을 보기 쉽게 포맷팅 해준다.
tkprof [파일명.trc] [아웃풋.prf] sys=no
발생순서
1) DBMS, OS, 하드웨어, SQL을 실행한 Client의 정보 출력
|
Dump file c:\oracle\product\10.2.0\admin\orcl\udump\orcl_ora_5376.trc Tue Sep 06 11:52:14 2011 ORACLE V10.2.0.1.0 - Production vsnsta=0 vsnsql=14 vsnxtr=3 Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Production With the Partitioning, OLAP and Data Mining options Windows XP Version V5.1 Service Pack 3 CPU : 2 - type 586, 2 Physical Cores Process Affinity : 0x00000000 Memory (Avail/Total): Ph:818M/1976M, Ph+PgF:1898M/3867M, VA:1304M/2047M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 5376, image: ORACLE.EXE (SHAD) *** 2011-09-06 11:52:14.468 *** ACTION NAME:() 2011-09-06 11:52:14.421 *** MODULE NAME:(TOAD 9.6.0.27) 2011-09-06 11:52:14.421 *** SERVICE NAME:(SYS$USERS) 2011-09-06 11:52:14.421 *** SESSION ID:(146.4) 2011-09-06 11:52:14.421 |
2) 쿼리블럭 정보와 수행된 SQL을 Parser로부터 받아서 출력
|
**************** QUERY BLOCK TEXT **************** Select /*+ QB_NAME(main) */ user_id, name, home_tel, mobile_tel, email From tb_user u WHERE EXISTS (SELECT /*+ QB_NAME(sub) */ NULL FROM tb_user_point p WHERE u.user_id = p.user_id AND p.event_point= :v_event_point) |
3) 10053 Event에서 사용될 용어 출력
|
Legend The following abbreviations are used by optimizer trace. CBQT - cost-based query transformation JPPD - join predicate push-down FPD - filter push-down PM - predicate move-around CVM - complex view merging SPJ - select-project-join SJC - set join conversion |
4) Optimizer에 관련된 성능 파라미터 출력, Bug Fix Control 정보 출력
파라미터는 Default 출력, 수정된 파라미터는 따로 출력
SQL에서 Opt_param힌트를 사용하여 파라미터 수정한 경우도 따로 출력
|
PARAMETERS WITH ALTERED VALUES --변경된 파라미터 출력 PARAMETERS WITH DEFAULT VALUES --Default 파라미터 출력 optimizer_mode_hinted = false optimizer_features_hinted = 0.0.0 parallel_execution_enabled = true PARAMETERS IN OPT_PARAM HINT --Opt_param 힌트를 사용한 경우 출력 |
5) Heuristic Query Transformation(HQT) 과정이 출력
|
|
6) Bind Peeking이 수행
|
******************************************* Peeked values of the binds in SQL statement ******************************************* |
7) Cost Based Query Transformation 과정이 출력
HQT나 CBQT로 인해 신규로 생성된 쿼리블럭 정보가 출력
|
********************* QUERY BLOCK SIGNATURE ********************* qb name was generated signature (optimizer): qb_name=SEL$526A7031 nbfros=2 flg=0 fro(0): flg=0 objn=53374 hint_alias="U"@"MAIN" fro(1): flg=0 objn=53378 hint_alias="P"@"SUB" |
8) 시스템 통계정보와 테이블과 인덱스의 통계정보를 출력
|
***************************** SYSTEM STATISTICS INFORMATION ***************************** Using NOWORKLOAD Stats CPUSPEED: 485 millions instruction/sec IOTFRSPEED: 4096 bytes per millisecond (default is 4096) IOSEEKTIM: 10 milliseconds (default is 10) *************************************** BASE STATISTICAL INFORMATION *********************** Table Stats:: Table: TB_USER Alias: U #Rows: 282 #Blks: 13 AvgRowLen: 158.00 Column (#1): USER_ID(VARCHAR2) AvgLen: 9.00 NDV: 282 Nulls: 0 Density: 0.0035461 Index Stats:: Index: SYS_C006146 Col#: 1 LVLS: 0 #LB: 1 #DK: 282 LB/K: 1.00 DB/K: 1.00 CLUF: 243.00 Index: XAK1TB_USER Col#: 4 LVLS: 1 #LB: 2 #DK: 282 LB/K: 1.00 DB/K: 1.00 CLUF: 238.00 Index: XIE1TB_USER Col#: 2 LVLS: 0 #LB: 1 #DK: 278 LB/K: 1.00 DB/K: 1.00 CLUF: 249.00 |
9) 테이블 단위로 최적의 Access Path와 cost 출력
|
*************************************** 1-ROW TABLES: IND$[I]#0 *************************************** SINGLE TABLE ACCESS PATH Column (#1): OBJ#(NUMBER) AvgLen: 5.00 NDV: 2567 Nulls: 0 Density: 3.8956e-004 Min: 3 Max: 53809 Column (#13): TYPE#(NUMBER) AvgLen: 3.00 NDV: 6 Nulls: 0 Density: 1.9478e-004 Min: 1 Max: 9 Histogram: Freq #Bkts: 6 UncompBkts: 2567 EndPtVals: 6 Table: IND$ Alias: I Card: Original: 2567 Rounded: 1 Computed: 0.78 Non Adjusted: 0.78 Access Path: TableScan Cost: 196.27 Resp: 196.27 Degree: 0 Cost_io: 195.00 Cost_cpu: 7410721 Resp_io: 195.00 Resp_cpu: 7410721 Access Path: index (UniqueScan) Index: I_IND1 resc_io: 2.00 resc_cpu: 22085 ix_sel: 3.8956e-004 ix_sel_with_filters: 3.8956e-004 Cost: 2.00 Resp: 2.00 Degree: 1 Access Path: index (AllEqUnique) Index: I_IND1 resc_io: 2.00 resc_cpu: 22085 ix_sel: 3.8956e-004 ix_sel_with_filters: 3.8956e-004 Cost: 2.00 Resp: 2.00 Degree: 1 One row Card: 1.00 Best:: AccessPath: IndexUnique Index: I_IND1 Cost: 2.00 Degree: 1 Resp: 2.00 Card: 1.00 Bytes: 0 *************************************** OPTIMIZER STATISTICS AND COMPUTATIONS *************************************** |
10) 최적의 조인방법과 순서를 정한다.
|
*************************************** OPTIMIZER STATISTICS AND COMPUTATIONS *************************************** GENERAL PLANS *************************************** Considering cardinality-based initial join order. *********************** Join order[1]: X$KSPPI[X]#0 X$KSPPCV[Y]#1 *************** Now joining: X$KSPPCV[Y]#1 *************** |
11) SQL dump와 Explain Plan Dump를 수행하여 SQL과 실행계획을 출력한다.
|
============ Plan Table ============ -------------------------------------+-----------------------------------+ | Id | Operation | Name | Rows | Bytes | Cost | Time | -------------------------------------+-----------------------------------+ | 0 | SELECT STATEMENT | | | | 1 | | | 1 | HASH JOIN | | 1 | 358 | 1 | 00:00:01 | | 2 | FIXED TABLE FULL | X$KSPPI | 1 | 68 | 0 | | | 3 | FIXED TABLE FULL | X$KSPPCV| 100 | 28K | 0 | | -------------------------------------+-----------------------------------+ |
12) Optimizer state dump와 Hint dump를 수행하여 SQL이 수행되었던 당시의 옵티마이져 관련 파라미터 정보, Bug Fix Control, 최종 적용된 힌트정보 등을 출력한다.
|
|
