Go to Qiita Advent Calendar 2024 Top
LoginSignup
6
4

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 5 years have passed since last update.

@ora_gonsuke777in日本オラクル株式会社

Oracle DatabaseでSQLの性能計測2(DBMS_XPLAN＆DBMS_SQLTUNE編)【Oracle Database or GoldenGate Advent Calendar 2018 Day 8】

Last updated at Posted at 2018-12-13

Oracle DatabaseでSQLの性能計測2(DBMS_XPLAN＆DBMS_SQLTUNE編)【Oracle Database or GoldenGate Advent Calendar 2018 Day 8】

このエントリは Oracle Database or GoldenGate Advent Calendar 2018 の Day 8 の記事となります。

Oracle Database or GoldenGate Advent Calendar 2018
https://adventar.org/calendars/3525

今日は Oracle Database の DBMS_XPLANパッケージ と DBMS_SQLTUNE で
SQLの実行時間を計測してみるやで彡(ﾟ)(ﾟ) Day 1 の続きになります。

Oracle DatabaseでSQLの性能計測1(SET AUTOTRACE TRACEONLY と SET TIMING ON編)
【Oracle Database or GoldenGate Advent Calendar 2018 Day 1】
https://gonsuke777.hatenablog.com/entry/2018/12/01/210651

1. DBMS_XPLANによるSQL実行時間の計測

1-1. DBMS_XPLAN とは？

Oracle Database の 標準パッケージ で、SQLの実行計画を出力する機能を持ちます。

Oracle Database PL/SQLパッケージおよびタイプ・リファレンス 18c
210 DBMS_XPLAN
https://docs.oracle.com/cd/E96517_01/arpls/DBMS_XPLAN.html#GUID-BAD480AA-351A-48FE-A8E7-F0D8EF643EBF

DBMS_XPLANパッケージには幾つかの機能が有りますが、今回は DISPLAY_CURSORファンクションの
ALLSTATS書式による実行時の統計出力でSQLの実行時間を計測しますやで彡(ﾟ)(ﾟ)

Oracle Database PL/SQLパッケージおよびタイプ・リファレンス 18c
210.4.4 DISPLAY_CURSORファンクション
https://docs.oracle.com/cd/E96517_01/arpls/DBMS_XPLAN.html#GUID-0EE333AF-E9AC-40A4-87D5-F6CF59D6C47B

1-2. ALLSTATS書式の前提条件

以下の「どちらか」の条件を満たして、SQLを実行する必要があります。

  • SQL に gather_plan_statisticsヒント を付与する。
  • STATISTICS_LEVELパラメータをALLにセットした状態でSQLを実行する。

更に以下の条件を満たす必要があります。

  • SQL の実行が終了していること(※Ctrl+Cによる強制終了でもOK)

1-3. DBMS_XPLAN.DISPLAY_CURSOR(ALLSTATS書式)の実行サンプル

下記が実行サンプルになります。STATISTICS_LEVELパラメータ を
セッション単位（ALTER SESSION ～）で ALL にセットしています。

-- パラメータをセット
ALTER SESSION SET STATISTICS_LEVEL = ALL;

-- サンプル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;

-- DBMS_XPLAN.DISPLAY_CURSORによる実行計画の出力
SET LINESIZE 300;
SET PAGESIZE 1000;
SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR('f9r2y6xdz6t84', NULL, 'ALL ALLSTATS LAST ADAPTIVE'));

実行結果は以下の通りです。

SQL> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR('f9r2y6xdz6t84', NULL, 'ALL ALLSTATS LAST ADAPTIVE'));

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  f9r2y6xdz6t84, child number 0
-------------------------------------
An uncaught error happened in prepare_sql_statement : ORA-01403: no data found

Plan hash value: 44130803

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation           | Name      | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem | Used-Mem | Used-Tmp|
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT    |           |      1 |        |       |    30 (100)|          |    261 |00:00:07.37 |    9068 |   4366 |   6795 |       |     |          |         |
|   1 |  SORT GROUP BY      |           |      1 |      8 |   208 |    30   (7)| 00:00:01 |    261 |00:00:07.37 |    9068 |   4366 |   6795 | 20480 | 20480 |18432  (0)|       |
|*  2 |   HASH JOIN         |           |      1 |     26 |   676 |    29   (4)| 00:00:01 |  26000 |00:00:07.20 |    9068 |   4366 |   6795 |   142M|  9292K| 17M (1)|   58368 |
|   3 |    TABLE ACCESS FULL| ORDER_TBL |      1 |     26 |   286 |     3   (0)| 00:00:01 |   2600K|00:00:00.60 |    8836 |      0 |      0 |       |     |          |         |
|*  4 |    TABLE ACCESS FULL| ITEM_TBL  |      1 |    300 |  4500 |    26   (4)| 00:00:01 |     10 |00:00:00.06 |      91 |      0 |      0 |       |     |          |         |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------

   1 - SEL$1
   3 - SEL$1 / A@SEL$1
   4 - SEL$1 / B@SEL$1

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("A"."ITEM_NO"="B"."ITEM_NO")
   4 - filter(TO_CHAR(INTERNAL_FUNCTION("B"."REGIST_DATE"),'YYYYMMDD')='20120801')

Column Projection Information (identified by operation id):
-----------------------------------------------------------

   1 - (#keys=2) "B"."ITEM_NAME"[VARCHAR2,100], TRUNC(INTERNAL_FUNCTION("A"."ORDER_DATE"),'fmdd')[8], COUNT(*)[22]
   2 - (#keys=1) "A"."ORDER_DATE"[DATE,7], "B"."ITEM_NAME"[VARCHAR2,100]
   3 - (rowset=256) "A"."ITEM_NO"[NUMBER,22], "A"."ORDER_DATE"[DATE,7]
   4 - (rowset=256) "B"."ITEM_NO"[NUMBER,22], "B"."ITEM_NAME"[VARCHAR2,100]

1-4. 出力された統計の統計の見方(DBMS_XPLAN.DISPLAY_CURSORのALLSTATS書式)

まず A-Time を確認します。ここで実行計画の各ステップで
実際に掛かった実行時間を確認できます。今回の例では全体で7.37秒、
HASH JOINまでのステップで7.2秒ほど掛かっているのが確認できます。

：
Plan hash value: 44130803

-----------------------------------------…--------------…-
| Id  | Operation           | Name      |…|   A-Time   |…|
-----------------------------------------…--------------…-
|   0 | SELECT STATEMENT    |           |…|00:00:07.37 |…| ★全体で7.37秒程度時間が掛かっている。
|   1 |  SORT GROUP BY      |           |…|00:00:07.37 |…|
|*  2 |   HASH JOIN         |           |…|00:00:07.20 |…| ★HASH JOIN までのステップで7.2秒ほど掛かっている。
|   3 |    TABLE ACCESS FULL| ORDER_TBL |…|00:00:00.60 |…|
|*  4 |    TABLE ACCESS FULL| ITEM_TBL  |…|00:00:00.06 |…|
-----------------------------------------…--------------…-
：

次に E-Rows と A-Rows を確認します。E-Rows はオプティマイザの予測行数、
A-Rows は実測値として処理行数が確認できます。今回の例では STEP 3 の
ORDER_TBL表 の予測と実測が大きく乖離していることが確認できます。

Plan hash value: 44130803

-----------------------------------------…----------…----------…-
| Id  | Operation           | Name      |…| E-Rows |…| A-Rows |…|
-----------------------------------------…----------…----------…-
|   0 | SELECT STATEMENT    |           |…|        |…|    261 |…|
|   1 |  SORT GROUP BY      |           |…|      8 |…|    261 |…|
|*  2 |   HASH JOIN         |           |…|     26 |…|  26000 |…|
|   3 |    TABLE ACCESS FULL| ORDER_TBL |…|     26 |…|   2600K|…| ★E-Rows(予測行数) と A-Rows(実測行数) が乖離している。
|*  4 |    TABLE ACCESS FULL| ITEM_TBL  |…|    300 |…|     10 |…|
-----------------------------------------…----------…----------…-

2. DBMS_SQLTUNEによるSQL実行時間の計測

2-1. DBMS_SQLTUNE とは？

Oracle Database の パッケージ で、SQLチューニング関連の機能を持ちます。
Enterprise Edition の Tuning Packオプション の機能となります。

Oracle Database PL/SQLパッケージおよびタイプ・リファレンス 18c
160 DBMS_SQLTUNE
https://docs.oracle.com/cd/E96517_01/arpls/DBMS_SQLTUNE.html#GUID-821462BF-1695-41CF-AFF7-FD23E9999C6A

Oracle Database ライセンス情報ユーザー・マニュアル 18c
1.6 機能、オプションおよびManagement Packの使用状況の確認
https://docs.oracle.com/cd/E96517_01/dblic/Licensing-Information.html#GUID-C3042D9A-5596-41A3-A08A-4581FED7634F
：
Oracle Tuning Pack
：
Oracle Tuning Packの機能は、データベース・サーバーAPIおよびコマンドライン・インタフェースでもアクセスできます。
：
・DBMS_SQLTUNE (注意事項を参照)

DBMS_SQLTUNEパッケージには幾つかの機能が有りますが、今回は REPORT_SQL_MONITORファンクションで
SQL監視(SQLモニタリング)のレポートを出力してみますやで彡(ﾟ)(ﾟ)

Oracle Database PL/SQLパッケージおよびタイプ・リファレンス 18c
160.5.27 REPORT_SQL_MONITORファンクション
https://docs.oracle.com/cd/E96517_01/arpls/DBMS_SQLTUNE.html#GUID-CFA1F851-1FC1-44D6-BB5C-76C3ADE1A483

2-2. DBMS_SQLTUNE.REPORT_SQL_MONITORファンクションの前提条件

以下の「どれか」の条件が満たされると、SQLの監視情報が自動でモニタリングされて、
REPORT_SQL_MONITORファンクションで確認可能となります。

  • SQL の実行時間が5秒以上
  • SQL がパラレル・クエリとして実行
  • SQL に MONITORヒント が付与

SQLが完了する必要は無く、実行中でも確認できます。

※(2018/12/16追記) SQLの実行計画のステップ数が300を超える場合は、
上記の条件を満たしていてもSQL監視の対象になりません。
隠しパラメータ"_sqlmon_max_planlines"を300よりも多くセットする必要があります。

-- データベース全体でセットする場合
ALTER SYSTEM SET "_sqlmon_max_planlines"=1000 SCOPE=BOTH SID='*';

-- セッション単位でセットする場合
ALTER SESSION SET "_sqlmon_max_planlines"=1000;

上記パラメータの詳細は下記ドキュメントをご参照下さい(｀･ω･)ゞ ※要My Oracle Supportアカウント

How to Monitor SQL Statements with Large Plans Using Real-Time SQL Monitoring? (ドキュメントID 1613163.1)
https://support.oracle.com/epmos/faces/DocumentDisplay?id=1613163.1

2-3. DBMS_SQLTUNE.REPORT_SQL_MONITORの実行サンプル

下記が実行サンプルになります。MONITORヒントを付与してSQLを実行しています。

ALTER SESSION SET STATISTICS_LEVEL = ALL;

-- サンプル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;

-- DBMS_SQLTUNE.REPORT_SQL_MONITORによるレポート出力
SET LONG 1000000
SET LONGC 1000000
SET LINESIZE 300;
SET PAGESIZE 1000;
VAR c_rep CLOB;
EXEC :c_rep := DBMS_SQLTUNE.REPORT_SQL_MONITOR(sql_id => 'f9r2y6xdz6t84', TYPE => 'TEXT');
PRINT c_rep;

実行結果は以下の通りです。

SQL> EXEC :c_rep := DBMS_SQLTUNE.REPORT_SQL_MONITOR(sql_id => 'f9r2y6xdz6t84', TYPE => 'TEXT');

PL/SQL procedure successfully completed.

SQL> PRINT c_rep;

C_REP
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL Monitoring Report

SQL Text
------------------------------
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

Global Information
------------------------------
 Status              :  DONE (ALL ROWS)
 Instance ID         :  1
 Session             :  AYSHIBAT (88:40832)
 SQL ID              :  f9r2y6xdz6t84
 SQL Execution ID    :  16777216
 Execution Started   :  12/08/2018 04:07:45
 First Refresh Time  :  12/08/2018 04:07:45
 Last Refresh Time   :  12/08/2018 04:07:53
 Duration            :  8s
 Module/Action       :  SQL*Plus/-
 Service             :  orcl
 Program             :  sqlplus@localhost.localdomain (TNS V1-V3)
 Fetch Calls         :  19

Global Stats
===========================================================================================
| Elapsed |   Cpu   |    IO    |  Other   | Fetch | Buffer | Read | Read  | Write | Write |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Calls |  Gets  | Reqs | Bytes | Reqs  | Bytes |
===========================================================================================
|    7.37 |    1.31 |     5.56 |     0.51 |    19 |   9068 |  292 |  34MB |   453 |  53MB |
===========================================================================================

SQL Plan Monitoring Details (Plan Hash Value=44130803)
==========================================================================================================================================================================================
| Id |       Operation       |   Name    |  Rows   | Cost |   Time    | Start  | Execs |   Rows   | Read | Read  | Write | Write |  Mem  | Temp  | Activity |    Activity Detail       |
|    |                       |           | (Estim) |      | Active(s) | Active |       | (Actual) | Reqs | Bytes | Reqs  | Bytes | (Max) | (Max) |   (%)    |      (# samples)         |
==========================================================================================================================================================================================
|  0 | SELECT STATEMENT      |           |         |      |         1 |     +8 |     1 |      261 |      |       |       |       |     . |     . |    12.50 | local write wait (1)     |
|  1 |   SORT GROUP BY       |           |       8 |   30 |         1 |     +8 |     1 |      261 |      |       |       |       | 18432 |     . |        |                            |
|  2 |    HASH JOIN          |           |      26 |   29 |         7 |     +2 |     1 |    26000 |  291 |  34MB |   453 |  53MB |  18MB |  57MB |    75.00 | direct path write temp (6) |
|  3 |     TABLE ACCESS FULL | ORDER_TBL |      26 |    3 |         5 |     +2 |     1 |       3M |      |       |       |       |     . |     . |        |                            |
|  4 |     TABLE ACCESS FULL | ITEM_TBL  |     300 |   26 |         1 |     +8 |     1 |       10 |      |       |       |       |     . |     . |        |                            |
==========================================================================================================================================================================================

2-4. 出力された統計の統計の見方(DBMS_SQLTUNE.REPORT_SQL_MONITORによるレポート出力)

まず Global Information の Duration を確認します。SQL全体の実行時間を確認できます。

Global Information
------------------------------
：
 Duration            :  8s
：

今回のSQLでは該当しませんが、Global Stats の Elapsed Time(s) は
パラレル・クエリの子プロセス(スレーブ)のSQL実行時間も積算されるため、
その点を考慮して確認する必要があります。

：
Global Stats
===========================================================================================
| Elapsed |   Cpu   |    IO    |  Other   | Fetch | Buffer | Read | Read  | Write | Write |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Calls |  Gets  | Reqs | Bytes | Reqs  | Bytes |
===========================================================================================
|    7.37 |    1.31 |     5.56 |     0.51 |    19 |   9068 |  292 |  34MB |   453 |  53MB |
===========================================================================================
^^^^^^^^^^^子プロセス(スレーブ)のSQL実行時間も含んだ積算値
：

次に Activity(%) と Activity Detail(# samples) を確認します。
実行計画のどこで時間が掛かっているか、どんな待機イベントで時間が掛かっているかを
直感的に把握できるため、非常に有用な情報となります。

SQL Plan Monitoring Details (Plan Hash Value=44130803)
==========================================…=========================================
| Id |       Operation       |   Name    |…| Activity |    Activity Detail       |
|    |                       |           |…|   (%)    |      (# samples)         |
==========================================…=========================================
|  0 | SELECT STATEMENT      |           |…|    12.50 | local write wait (1)     |
|  1 |   SORT GROUP BY       |           |…|        |                            |
|  2 |    HASH JOIN          |           |…|    75.00 | direct path write temp (6) | ★direct path write temp で全体の75%を占める。
|  3 |     TABLE ACCESS FULL | ORDER_TBL |…|        |                            |
|  4 |     TABLE ACCESS FULL | ITEM_TBL  |…|        |                            |
==========================================…=========================================

あとはDBMS_XPLANと同様にRows(Estim)の予測値とRows(Actual)の実測値を確認します。

SQL Plan Monitoring Details (Plan Hash Value=44130803)
====================================================…============…=
| Id |       Operation       |   Name    |  Rows   |…|   Rows   |…|
|    |                       |           | (Estim) |…| (Actual) |…|
====================================================…============…=
|  0 | SELECT STATEMENT      |           |         |…|      261 |…|
|  1 |   SORT GROUP BY       |           |       8 |…|      261 |…|
|  2 |    HASH JOIN          |           |      26 |…|    26000 |…|
|  3 |     TABLE ACCESS FULL | ORDER_TBL |      26 |…|       3M |…| ★ 26件(予測)と3M件(実測)で大きく乖離
|  4 |     TABLE ACCESS FULL | ITEM_TBL  |     300 |…|       10 |…|
====================================================…============…=

3. 今回のケースでのSQL性能改善(チューニング)

このエントリは SQL性能計測 をメインとしているため
チューニングの詳細は割愛しますが、今回のケースでは

  • ORDER_TBL表の E-Rows(予測値) と A-Rows(実測値)が乖離している。
  • HASH JOINのステップで時間が掛かっている。

事が、DBMS_XPLAN と DBMS_SQLTUNE の性能計測により確認できます。
このようなケースでは以下のようなチューニングを試すのがセオリーとなります。

  • オプティマイザ統計の採取
  • ヒストグラム、拡張統計(複数列統計, 式統計)の取得
  • SQLチューニング・アドバイザの実行 と SQLプロファイルの適用(※)
    ※SQLプロファイルが提案された場合

どのチューニングも E-Rows(予測値) と A-Rows(実測値) の
乖離を埋めて、良い実行計画が生成される事を期待する手法となります。

4. まとめ

DBMS_XPLAN.DISPLAY_CURSOR と DBMS_SQLTUNE.REPORT_SQL_MONITOR による性能計測は、
SQLのボトルネック特定に非常に有効な手段となります。皆活用するんやで彡(^)(^)

もっと詳しく説明した資料も有るので、皆読んでクレメンス(ステマ

Oracle DBA & Developer Day 2013
https://www.oracle.com/technetwork/jp/ondemand/ddd-2013-2051348-ja.html

【A-1】オラクル・コンサルが語る！ SQLチューニングに必要な考え方と最新テクニック
http://www.oracle.com/webfolder/technetwork/jp/ondemand/ddd2013/A-1.pdf

Alt text

6
4
3

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
Sign upLogin
6
4

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?