Oracle DatabaseでSQLの性能計測1(SET AUTOTRACE TRACEONLY と SET TIMING ON編)【Oracle Database or GoldenGate Advent Calendar 2018 Day 1】
このエントリは Oracle Database or GoldenGate Advent Calendar 2018 の Day 1 の記事となります。
Oracle Database or GoldenGate Advent Calendar 2018
https://adventar.org/calendars/3525
1日目はSQL*Plusの SET AUTOTRACE TRACEONLY と SET TIMING ON で、SQLの実行時間を計測してみるやで。
彡(ﾟ)(ﾟ)
1. AUTOTRACE とは？
Oracle Databaseユーティリティ の SQL*Plus(sqlplus)の機能で、
SQLの実行計画や実行統計の取得できます。
SQL*Plus ユーザーズ・ガイドおよびリファレンス 18c
12.41.6 SET AUTOT[RACE] {ON | OFF | TRACE[ONLY]} [EXP[LAIN]] [STAT[ISTICS]]
https://docs.oracle.com/cd/E96517_01/sqpug/SET-system-variable-summary.html#GUID-0791433C-CA4A-4C79-BFF6-B7976E1534BA
8.1 文のトレースについて
https://docs.oracle.com/cd/E96517_01/sqpug/tuning-SQL-Plus.html#GUID-1425180A-9917-429E-B908-B217C0CAC3DD
2. SET TIMING とは？
Oracle Databaseユーティリティ の SQL*Plus(sqlplus)の機能で、
SQL や PL/SQL を実行した際の経過時間を表示できます。
SQL*Plus ユーザーズ・ガイドおよびリファレンス 18c
12.41.64 SET TIMI[NG] {ON | OFF}
https://docs.oracle.com/cd/E96517_01/sqpug/SET-system-variable-summary.html#GUID-35276053-FA28-4CA3-94A8-8806682C9EA5
3. 実行サンプル
下記に実行サンプルを提示してみますやで彡(ﾟ)(ﾟ)
CONNECT AYSHIBAT/xxxxxxxx@yyyyyyyy SET TIMING ON; -- TIMING を有効化しています。 SET AUTOTRACE TRACEONLY; -- AUTOTRACE を有効化しています。 -- サンプルSQL SELECT /*+ MONITOR */ B.ITEM_NAME , TRUNC(A.ORDER_DATE, 'DD') AS ORDER_DAILY , COUNT(*) FROM ORDER_TBL A , ITEM_TBL B WHERE A.ITEM_NO = B.ITEM_NO -- AND B.ITEM_NO BETWEEN 1 AND 100 AND TO_CHAR(B.REGIST_DATE, 'YYYYMMDD') = '20120801' GROUP BY B.ITEM_NAME, TRUNC(A.ORDER_DATE, 'DD') ORDER BY 1; Connected. 261 rows selected. Elapsed: 00:00:05.22 ★SET TIMING ON によって出力されたSQLの経過時間です。 Execution Plan ---------------------------------------------------------- Plan hash value: 44130803 --------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | --------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 8 | 208 | 30 (7)| 00:00:01 | | 1 | SORT GROUP BY | | 8 | 208 | 30 (7)| 00:00:01 | |* 2 | HASH JOIN | | 26 | 676 | 29 (4)| 00:00:01 | | 3 | TABLE ACCESS FULL| ORDER_TBL | 26 | 286 | 3 (0)| 00:00:01 | |* 4 | TABLE ACCESS FULL| ITEM_TBL | 300 | 4500 | 26 (4)| 00:00:01 | --------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 2 - access("A"."ITEM_NO"="B"."ITEM_NO") 4 - filter(TO_CHAR(INTERNAL_FUNCTION("B"."REGIST_DATE"),'YYYYMMDD')='2 0120801') Statistics ★SET AUTOTRACE TRACEONLY によって出力されたSQLの実効統計 ---------------------------------------------------------- 97 recursive calls 0 db block gets 9012 consistent gets 15579 physical reads 0 redo size 7401 bytes sent via SQL*Net to client 795 bytes received via SQL*Net from client 19 SQL*Net roundtrips to/from client 11 sorts (memory) 0 sorts (disk) 261 rows processed
4. 出力された統計の見方
SET TIMING ON の方はシンプル、経過時間そのものを確認します。
： Elapsed: 00:00:05.22 ←コレを確認する。 ：
SET AUTOTRACE TRACEONLY では様々な統計が出力されますが、
SQL性能観点だと「consistent gets」「physical reads」辺りをよく見ますかね彡(ﾟ)(ﾟ)
： Statistics ---------------------------------------------------------- 97 recursive calls 0 db block gets 9012 consistent gets ★SQLの読込ブロック数 ←これはよく見る 15579 physical reads ★SQLのDisk IOブロック数 ←これはよく見る 0 redo size 7401 bytes sent via SQL*Net to client 795 bytes received via SQL*Net from client 19 SQL*Net roundtrips to/from client 11 sorts (memory) 0 sorts (disk) 261 rows processed ：
8.1.3 統計
https://docs.oracle.com/cd/E96517_01/sqpug/tuning-SQL-Plus.html#GUID-32806E04-0E05-4579-B2DB-E2C757CEA448
統計は、文を実行したときにサーバーによって記録され、文の実行に必要とされた
システム・リソースを示します。結果には、次の統計が含まれます。
recursive calls
db block gets
：
SQLチューニング観点で言えば、SET TIMING ON で確認できる「Elapsed」や
AUTOTRACEの「consistent gets」「physical reads」を血眼になって減らすんやね彡(ﾟ)(ﾟ)
5. AUTOTRACE TRACEONLY の注意点
まずひとつ目、AUTOTRACE TRACEONLY はその字面に反して
SQLのトランザクションが実行されてしまいます。下記記事参照彡(ﾟ)(ﾟ)
sqlplus の SET AUTOTRACE TRACEONLY は トレースオンリーじゃなくてトランザクションが実行されてしまう。
https://gonsuke777.hatenablog.com/entry/20160120/1453266062
ふたつ目は、AUTOTRACE TRACEONLY で出てくる実行計画と
(共有プール上に格納された)実際の実行計画は異なるケースが有ります。下記記事参照
EXPLAIN PLAN FOR …(※AUTOTRACE TRACEONLY含む)で出てくる実行計画 と
SQL実行時の実行計画が異なるケースを作ってみる。
https://gonsuke777.hatenablog.com/entry/20150723/1437662167
これは下記マニュアルにも制限事項として記載が有ります。
6.2.5 EXPLAIN PLANの制限事項
https://docs.oracle.com/cd/E96517_01/tgsql/generating-and-displaying-execution-plans.html#GUID-E2463C7B-F71A-4F06-85D3-1AF3D4D71CE8
Oracle Databaseでは、日付バインド変数の暗黙的な型変換を実行する文でのEXPLAIN PLANをサポートしません。
一般にバインド変数では、EXPLAIN PLANが実際の実行計画を表していない場合があります。
過去あるいは後日記載する DBMS_XPLAN.DISPLAY_CURSOR や DBMS_SQLTUNE も併用や！彡(ﾟ)(ﾟ)
6. まとめ
上記のような制限事項が有るとはいえ、特に AUTOTRACE TRACEONLY は便利です。
sqlplus だけで操作が完結するんで、SQLチューニングの最盛期で
超高速PDCAを廻してるタイミングでは重宝しますやね彡(^)(^)
