環境
SQLトレースの取得
Oracle Database PL/SQLパッケージおよびタイプ・リファレンス11g リリース2(11.2) DBMS_MONITOR
DBMS_MONITORパッケージを利用する。幾つかプロシージャがあるのだけど、DATABASE_TRACE_ENABLEプロシージャとSESSION_TRACE_ENABLEプロシージャが主に使うものだと思われる。この2つの違いはSQLトレースを取得対象とする範囲の違いで、前者はDB全体もしくはインスタンス単位、後者はセッション単位となっている。また、取得を停止するDISABLEプロシージャもそれぞれに対応する形で用意されている。
セッション単位
Oracle Database PL/SQLパッケージおよびタイプ・リファレンス11g リリース2(11.2) DBMS_MONITOR.SESSION_TRACE_ENABLEプロシージャ
詳細は上記のリファレンスを参照。使い方はこんな感じ。
--現在のセッションでトレースを開始する。 EXECUTE SYS.DBMS_MONITOR.SESSION_TRACE_ENABLE(); --セッションIDを指定してトレースを開始する。 EXECUTE SYS.DBMS_MONITOR.SESSION_TRACE_ENABLE(12); --セッションIDとシリアルIDを指定してトレースを開始する。 EXECUTE SYS.DBMS_MONITOR.SESSION_TRACE_ENABLE(12, 133); --バインド情報をトレースに含める。 EXECUTE SYS.DBMS_MONITOR.SESSION_TRACE_ENABLE(binds=>TRUE); --待機情報をトレースに含める。 EXECUTE SYS.DBMS_MONITOR.SESSION_TRACE_ENABLE(waits=>TRUE); --バインド情報と待機情報をトレースに含める。下記2つは同じ意味。 EXECUTE SYS.DBMS_MONITOR.SESSION_TRACE_ENABLE(binds=>TRUE, waits=>TRUE); EXECUTE SYS.DBMS_MONITOR.SESSION_TRACE_ENABLE(NULL, NULL, TRUE, TRUE); --現在のセッションのトレースを停止する。 EXECUTE SYS.DBMS_MONITOR.SESSION_TRACE_DISABLE();
現行セッションでの取得はともかく。トレースを取得したいセッションの外からセッションIDを指定できるのは場合によっては便利そう。
DB全体もしくはインスタンス単位
Oracle Database PL/SQLパッケージおよびタイプ・リファレンス11g リリース2(11.2) DBMS_MONITOR.DATABASE_TRACE_ENABLEプロシージャ
詳細は上記のリファレンスを参照。使い方は……まぁセッションの時とほとんど変わらないので例は省略。
ALTER SESSION SET SQL_TRACEとかALTER SESSION SET TIMED_STATISTICSとか
DBMS_MONITORパッケージは10g(未確認)くらいから導入されたらしく、それ以前のバージョンには存在しない。なので「SQLトレース」でぐぐったり参考文献見たりすると取得方法は下記のような感じで書かれている。
ALTER SESSION SET TIMED_STATISTICS = TRUE; ALTER SESSION SET SQL_TRACE = TRUE; --待機イベントの取得 ALTER SESSION SET EVENTS '10046 trace name context forever, level 8';
別にコレでも出来ないことはないっぽいのだけど、待機の取得が謎めいた10046とかでマジで謎。なので明示的にパラメータで設定できるDBMS_MONITORを使った方が良いような気がする。
ファイルの吐き出し場所の確認
初期化パラメータuser_dump_destで指定されたディレクトリにトレースファイルが出力される。
SELECT NAME, VALUE FROM v$parameter WHERE NAME = 'user_dump_dest';
ウチの11g XE環境では下記のディレクトリに出力されることになる。
NAME | VALUE |
---|---|
user_dump_dest | /u01/app/oracle/diag/rdbms/xe/XE/trace |
トレースファイルの確認
とりあえず下記のような手順でSQLトレースを取得した、として以降は話を進める。
EXECUTE SYS.DBMS_MONITOR.SESSION_TRACE_ENABLE(BINDS=>TRUE, WAITS=>TRUE); SELECT COUNT(*) FROM million_rows_table; SELECT * FROM million_rows_table WHERE column_pk_int < :ID; EXECUTE SYS.DBMS_MONITOR.SESSION_TRACE_DISABLE();
TKPROFによる整形
出力されたトレースファイル(*.trc)はそのままでは人間が読むには厳しいものがある。よって、TKPROFユーティリティによって整形を行う。コマンドラインの引数とかは下記のような感じらしい。
TKPROFはコマンド・ラインで“tkprof トレース・ファイル名 出力ファイル名 [SORT=パラメータ][PRINT=数値][EXPLAIN=ユーザー名/パスワード]”といった形式で実行します。
トラブル110番 - OracleのSQLトレースの取り方が分からない:ITpro
実行はこんな感じ。処理結果は3294.txtに出力される。
$ tkprof XE_ora_3294.trc EXPLAIN=kagamihoge/xxxx output = 3294.txt TKPROF: Release 11.2.0.2.0 - Development on 木 1月 23 17:56:39 2014 Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.
出力結果の一部抜粋はこんな感じ。長ったらしいけど上から順に、実行したSQL・実行したSQLの統計情報いろいろ・実行計画・待機情報、となっている。
******************************************************************************** SQL ID: bfhu193kfrz51 Plan Hash: 1047193584 SELECT * FROM million_rows_table WHERE column_pk_int < :ID 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 40 0.00 0.00 9 93 0 1999 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 42 0.00 0.00 9 93 0 1999 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: 48 (KAGAMIHOGE) Number of plan statistics captured: 1 Rows (1st) Rows (avg) Rows (max) Row Source Operation ---------- ---------- ---------- --------------------------------------------------- 1999 1999 1999 TABLE ACCESS BY INDEX ROWID MILLION_ROWS_TABLE (cr=93 pr=9 pw=0 time=10067 us cost=15 size=51974 card=1999) 1999 1999 1999 INDEX RANGE SCAN MILLION_ROWS_TABLE_PK (cr=45 pr=0 pw=0 time=3800 us cost=6 size=0 card=1999)(object id 21359) Rows Execution Plan ------- --------------------------------------------------- 0 SELECT STATEMENT MODE: ALL_ROWS 1999 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF 'MILLION_ROWS_TABLE' (TABLE) 1999 INDEX MODE: ANALYZED (RANGE SCAN) OF 'MILLION_ROWS_TABLE_PK' (INDEX (UNIQUE)) Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 40 0.00 0.00 db file sequential read 9 0.00 0.00 SQL*Net message from client 40 2.33 2.41 ********************************************************************************
SQL Developerによる表示
TKPROFで整形しない方法としてSQL Developerがある。ナマのtrcファイルをそのままSQL Developerにドラッグ&ドロップするか、ファイル -> 開く、をするだけ。イメージ的には下記のような感じ。
ソートがカンタンに出来るし、統計と待機をセットで流し見していけるので、SQLの件数が多い場合にはこっちのほうが便利かもしれない。
しかし、日本語がビミョーなのが気になるんだよなぁ……昇順の逆が説明になってるのかなり謎。ソートはディスクなのに、一覧では物理になってたりも謎めいている。
SQLトレースとTKPROF整形後のファイル
https://github.com/kagamihoge/oraclestudy/tree/master/sqltrace/introduction