ここでは実際に実行したSQLをトレースをすることにより実行計画を取得します。
次のように、トレースをONにして実行します。
var vcarrier number
var vleader number
exec :vcarrier := 2
exec :vleader := 2
alter session set timed_statistics=true;
alter session set events '10046 trace name context forever, level 12';
SELECT
*
FROM
(SELECT
rank() over (ORDER BY tt.regist_dt DESC) as rn,
tt.team_nm AS team_nm ,
tt.member_cnt AS member_cnt ,
tt.team_status_id AS team_status_id ,
tt.pr_comment AS pr_comment ,
tt.team_id AS team_id ,
tm.user_id AS user_id ,
tt.regist_dt AS regist_dt ,
wearing_avatar_kind,
avatar_id,
gender,
avatar_session
FROM
T01_Test2 tt ,
T01_TestMember2 tm ,
T01_UserMyTest2 my
WHERE
tt.carrier_id = :vcarrier AND
tm.user_id = my.user_id AND
tt.team_id = tm.team_id AND
tm.leader_flg = :vleader
ORDER BY
tt.regist_dt DESC
)
WHERE
rn BETWEEN 1 AND
30;
alter session set events '10046 trace name context off';
alter session set timed_statistics=false;
実行後、DBサーバにトレースファイルが出力されています。level 1 alter session set sql_trace=trueと同じ level 4 level 1にバインド変数情報 level 8 level 1に待機イベント情報 level 12 level 4 ＋ level 8
そのトレースファイルそのままだと読みづらいので、TKPROFというツールで整形します。
ただし、TKPROFはバインド情報を無視するので必要であればトレースファイルを直接確認します。$ ls -tlr /opt/app/oracle/admin/sss01dev/udump/ | tail -1 $ sudo scp /opt/app/oracle/admin/sss01dev/udump/sss01dev_ora_21243.trc snwdev1:/home/ito/tmp/ $ tkprof sss01dev_ora_21243.trc test.trc
整形したファイル例は次の通りです。$ grep -A4 "^ Bind" sss01dev_ora_21243.trc Bind#0 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1000000 frm=00 csi=00 siz=48 off=0 kxsbbbfp=2b818341b4c0 bln=22 avl=02 flg=05 value=2 Bind#1 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1000000 frm=00 csi=00 siz=0 off=24 kxsbbbfp=2b818341b4d8 bln=22 avl=02 flg=01 value=2
TKPROF: Release 10.2.0.4.0 - Production on 火 4月 5 11:25:10 2011
Copyright (c) 1982, 2007, Oracle. All rights reserved.
Trace file: sss01dev_ora_29755.trc
Sort options: default
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
SELECT
*
FROM
(SELECT
rank() over (ORDER BY tt.regist_dt DESC) as rn,
tt.team_nm AS team_nm ,
tt.member_cnt AS member_cnt ,
tt.team_status_id AS team_status_id ,
tt.pr_comment AS pr_comment ,
tt.team_id AS team_id ,
tm.user_id AS user_id ,
tt.regist_dt AS regist_dt ,
wearing_avatar_kind,
avatar_id,
gender,
avatar_session
FROM
T01_Team2 tt ,
T01_TeamMember2 tm ,
T01_UserMyRoom2 my
WHERE
tt.carrier_id = :vcarrier AND
tm.user_id = my.user_id AND
tt.team_id = tm.team_id AND
tm.leader_flg = :vleader
ORDER BY
tt.regist_dt DESC
)
WHERE
rn BETWEEN 1 AND
30
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 31 0.14 0.14 0 6097 0 30
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 33 0.14 0.14 0 6097 0 30
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 113
Rows Row Source Operation
------- ---------------------------------------------------
30 VIEW (cr=6097 pr=0 pw=0 time=140143 us)
1153 WINDOW SORT PUSHED RANK (cr=6097 pr=0 pw=0 time=141286 us)
1153 HASH JOIN (cr=6097 pr=0 pw=0 time=129360 us)
1164 TABLE ACCESS FULL T01_TEAM2 (cr=227 pr=0 pw=0 time=166 us)
1153 HASH JOIN (cr=5870 pr=0 pw=0 time=123033 us)
1153 TABLE ACCESS FULL T01_TEAMMEMBER2 (cr=253 pr=0 pw=0 time=4643 us)
86413 TABLE ACCESS FULL T01_USERMYROOM2 (cr=5617 pr=0 pw=0 time=86469 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 32 0.00 0.00
SQL*Net message from client 32 0.00 0.02
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 31 0.14 0.14 0 6097 0 30
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 33 0.14 0.14 0 6097 0 30
Misses in library cache during parse: 0
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 79 0.00 0.00
SQL*Net message from client 79 15.53 23.49
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
1 user SQL statements in session.
0 internal SQL statements in session.
1 SQL statements in session.
********************************************************************************
Trace file: sss01dev_ora_29755.trc
Trace file compatibility: 10.01.00
Sort options: default
1 session in tracefile.
1 user SQL statements in trace file.
0 internal SQL statements in trace file.
1 SQL statements in trace file.
1 unique SQL statements in trace file.
263 lines in trace file.
0 elapsed seconds in trace file.
0 件のコメント:
コメントを投稿