TRACE 10046

특징과 용도

  • 모든 SQL{}{*}문장의{*}* * Bind{}{*}변수* 값을 추적할 있는 유일한 방법이다{}*.(level4)*
  • 모든 SQL{}{*}문장의* 대기현상{}*(Wait){}를* 추적할 있는 유일한 방법이다{}*.(level8)*

LEVEL1


/******************* test script start **********************/

WOONG@ORCL>var ag_bind varchar2(5);
WOONG@ORCL>exec :ag_bind := 'Many2';

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

경   과: 00:00:00.22
WOONG@ORCL>@trace_on 10046 1
구   1: alter session set events '&1 trace name context forever, level &2'
신   1: alter session set events '10046 trace name context forever, level 1'

세션이 변경되었습니다.

경   과: 00:00:00.00
WOONG@ORCL>select /*+ gather_plan_statistics qb_name(main_query)*/
  2         a.col1, a.col2
  3    from t_plan a
  4   where (a.col1, a.col2) in (select /*+ parallel(b,8) qb_name(sub_query) */
  5                                     b.col1, b.col2
  6                                from t_plan2 b
  7                               where col1 = :ag_bind
  8                                 and col2 <= 100);

선택된 레코드가 없습니다.

경   과: 00:00:02.52
WOONG@ORCL>@trace_off 10046
구   1: alter session set events '&1 trace name context off'
신   1: alter session set events '10046 trace name context off'

세션이 변경되었습니다.

경   과: 00:00:00.00
WOONG@ORCL>@trace_file

TRACE_FILE_NAME
----------------------------------------------
D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\UDUMP\orcl_ora_5324.trc

경   과: 00:00:00.23
D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\UDUMP\orcl_ora_5324.trc
WOONG@ORCL>@tkprof D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\UDUMP\orcl_ora_5324.trc D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\UDUMP\orcl_ora_5324.txt

/******************* script end **********************/

LEVEL 1 - SQL의 Raw Trace 정보만 보여준다.


select /*+ gather_plan_statistics qb_name(main_query)*/
       a.col1, a.col2
  from t_plan a
 where (a.col1, a.col2) in (select /*+ parallel(b,8) qb_name(sub_query) */
                                   b.col1, b.col2
                              from t_plan2 b
                             where col1 = :ag_bind
                               and col2 <= 100)

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.33          0          3          0           0
Fetch        1      0.00       2.11          0         29          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       2.45          0         32          0           0

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: 61

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  PX COORDINATOR  (cr=32 pr=0 pw=0 time=2423240 us)
      0   PX SEND QC (RANDOM) :TQ10002 (cr=0 pr=0 pw=0 time=0 us)
      0    HASH JOIN SEMI BUFFERED (cr=0 pr=0 pw=0 time=0 us)
      0     BUFFER SORT (cr=0 pr=0 pw=0 time=0 us)
      0      PX RECEIVE  (cr=0 pr=0 pw=0 time=0 us)
      0       PX SEND HASH :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
      0        TABLE ACCESS BY INDEX ROWID T_PLAN (cr=29 pr=0 pw=0 time=193 us)
      0         INDEX RANGE SCAN T_PLAN_IDX (cr=29 pr=0 pw=0 time=117 us)(object id 55297)
      0     PX RECEIVE  (cr=0 pr=0 pw=0 time=0 us)
      0      PX SEND HASH :TQ10001 (cr=0 pr=0 pw=0 time=0 us)
      0       PX BLOCK ITERATOR PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us)
      0        TABLE ACCESS FULL T_PLAN2 PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us)


********************************************************************************
Trace file: D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\UDUMP\orcl_ora_5324.trc
Trace file compatibility: 10.01.00
Sort options: default

       1  session in tracefile.
       2  user  SQL statements in trace file.
       2  internal SQL statements in trace file.
       4  SQL statements in trace file.
       4  unique SQL statements in trace file.
      73  lines in trace file.
      12  elapsed seconds in trace file.

LEVEL4

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


/************************ *****************************/
=====================
PARSING IN CURSOR #2 len=362 dep=0 uid=61 oct=3 lid=61 tim=27304013069 hv=1246081662 ad='30491808'
select /*+ gather_plan_statistics qb_name(main_query)*/
       a.col1, a.col2
  from t_plan a
 where (a.col1, a.col2) in (select /*+ parallel(b,8) qb_name(sub_query) */
                                   b.col1, b.col2
                              from t_plan2 b
                             where col1 = :ag_bind
                               and col2 <= 100)
END OF STMT
PARSE #2:c=0,e=495,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=27304013059
=====================
BINDS #2:
kkscoacd
 Bind#0
  oacdty=01 mxl=32(05) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1000000 frm=01 csi=846 siz=32 off=0
  kxsbbbfp=08817950  bln=32  avl=05  flg=05
  value="Many2"
EXEC #2:c=15600,e=180452,p=0,cr=4,cu=3,mis=1,r=0,dep=0,og=4,tim=27304197986
FETCH #2:c=0,e=2106012,p=0,cr=29,cu=0,mis=0,r=0,dep=0,og=4,tim=27306304196
STAT #2 id=1 cnt=0 pid=0 pos=1 obj=0 op='PX COORDINATOR  (cr=32 pr=0 pw=0 time=2273926 us)'
STAT #2 id=2 cnt=0 pid=1 pos=1 obj=0 op='PX SEND QC (RANDOM) :TQ10002 (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=3 cnt=0 pid=2 pos=1 obj=0 op='HASH JOIN SEMI BUFFERED (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=4 cnt=0 pid=3 pos=1 obj=0 op='BUFFER SORT (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=5 cnt=0 pid=4 pos=1 obj=0 op='PX RECEIVE  (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=6 cnt=0 pid=5 pos=1 obj=0 op='PX SEND HASH :TQ10000 (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=7 cnt=0 pid=6 pos=1 obj=55296 op='TABLE ACCESS BY INDEX ROWID T_PLAN (cr=29 pr=0 pw=0 time=135 us)'
STAT #2 id=8 cnt=0 pid=7 pos=1 obj=55297 op='INDEX RANGE SCAN T_PLAN_IDX (cr=29 pr=0 pw=0 time=119 us)'
STAT #2 id=9 cnt=0 pid=3 pos=2 obj=0 op='PX RECEIVE  (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=10 cnt=0 pid=9 pos=1 obj=0 op='PX SEND HASH :TQ10001 (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=11 cnt=0 pid=10 pos=1 obj=0 op='PX BLOCK ITERATOR PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=12 cnt=0 pid=11 pos=1 obj=55330 op='TABLE ACCESS FULL T_PLAN2 PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us)'

LEVEL8

LEVEL 8 - SQL의 Raw Trace와 Wait Event를 함께 보여준다.


select /*+ gather_plan_statistics qb_name(main_query)*/
       a.col1, a.col2
  from t_plan a
 where (a.col1, a.col2) in (select /*+ parallel(b,8) qb_name(sub_query) */
                                   b.col1, b.col2
                              from t_plan2 b
                             where col1 = :ag_bind
                               and col2 <= 100)

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.03       0.14          0          4          3           0
Fetch        8      0.01       2.14          0         46          0         100
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       10      0.04       2.29          0         50          3         100

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: 61

Rows     Row Source Operation
-------  ---------------------------------------------------
    100  PX COORDINATOR  (cr=49 pr=0 pw=0 time=2181083 us)
      0   PX SEND QC (RANDOM) :TQ10002 (cr=0 pr=0 pw=0 time=0 us)
      0    HASH JOIN SEMI BUFFERED (cr=0 pr=0 pw=0 time=0 us)
      0     BUFFER SORT (cr=0 pr=0 pw=0 time=0 us)
      0      PX RECEIVE  (cr=0 pr=0 pw=0 time=0 us)
      0       PX SEND HASH :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
    100        TABLE ACCESS FULL T_PLAN (cr=46 pr=0 pw=0 time=2038 us)
      0     PX RECEIVE  (cr=0 pr=0 pw=0 time=0 us)
      0      PX SEND HASH :TQ10001 (cr=0 pr=0 pw=0 time=0 us)
      0       PX BLOCK ITERATOR PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us)
      0        TABLE ACCESS FULL T_PLAN2 PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  PX Deq: Join ACK                                9        0.00          0.00
  PX Deq: Parse Reply                             8        0.04          0.05
  SQL*Net message to client                       8        0.00          0.00
  PX Deq: Execute Reply                          38        0.00          0.01
  PX qref latch                                 181        0.00          0.00
  PX Deq Credit: send blkd                        8        1.99          1.99
  PX Deq: Table Q Normal                          1        0.00          0.00
  SQL*Net message from client                     8        7.75          7.96
  PX Deq: Signal ACK                             18        0.09          0.12
  enq: PS - contention                            1        0.00          0.00
********************************************************************************

LEVEL12

LEVEL 12 - SQL의 Raw Trace + Bind 상수값 + Wait Event를 함께 보여준다(Bind변수값을 확인하기 위해서는 직접 TRC파일을 검색하여야 한다.)
TKPROF의 결과값은 LEVEL 8 과 같다.

문서에 대하여