메뉴 건너뛰기

bysql.net

1.7 10053 Event Trace

2011.09.07 05:43

고구마 조회 수:4665

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, 최종 적용된 힌트정보 등을 출력한다.