LoginSignup
5
3

More than 5 years have passed since last update.

Oracle DatabaseでSQLの性能計測1(SET AUTOTRACE TRACEONLY と SET TIMING ON編)【Oracle Database or GoldenGate Advent Calendar 2018 Day 1】

Posted at

このエントリは 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 ★SQLDisk 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を廻してるタイミングでは重宝しますやね彡(^)(^)

5
3
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
5
3