Autonomous Database で SQLトレース を採取してみる。(Oracle Cloud Infrastructure)
いつの間にか Autonomous Database で SQLトレース を採取できるようになったので、下記のマニュアルを見ながらやってみます。
彡(ﾟ)(ﾟ)
Autonomous DatabaseでのSQLトレースの実行
https://docs.oracle.com/cd/E83857_01/paas/autonomous-database/adbsa/application-tracing.html#GUID-25A5160B-C72A-4897-9CC9-0BE23EA7EC01
1. Object Storage Bucket作成/IAMユーザー作成/ポリシー付与/Auth Token生成/クレデンシャル登録
詳細は本記事では省略します。下記記事を参照して下さい。
Object Storage にアップロードしたファイルを Autonomous Database の DATA_PUMP_DIR にコピーする。(Oracle Cloud Infrastructure)
https://qiita.com/ora_gonsuke777/items/3e8b63b1d878c7fe343e
2. DATABASE PROPERTY の設定(DEFAULT_LOGGING_BUCKET, DEFAULT_CREDENTIAL)
上記 1. で作成した Object Storage Bucket や クレデンシャル を DATABASE PROPERTY として登録します。
SET DEFINE OFF; ALTER DATABASE PROPERTY SET DEFAULT_LOGGING_BUCKET = 'https://objectstorage.us-phoenix-1.oraclecloud.com/n/xxxxxxxxxxxxxx/b/ayu-bucket1/o/'; ALTER DATABASE PROPERTY SET DEFAULT_CREDENTIAL = 'ADMIN.DEF_CRED_NAME2';
3. SQLトレースの採取
まずは IDENTIFIER名 と MODULE名 をセットします。これらはオプションですが SQLトレース の ファイル名 を特定するのに便利です。
BEGIN DBMS_SESSION.SET_IDENTIFIER('ayu_sqlt'); END; / BEGIN DBMS_APPLICATION_INFO.SET_MODULE('test1', null); END; /
SQLトレースをセットします。
ALTER SESSION SET SQL_TRACE = TRUE;
トレースをセットした状態で、性能を測定したい SQL を実行します。
ダミーデータをセットアップして下記SQLを実行してみました。
SELECT /*+ MONITOR NO_VECTOR_TRANSFORM */ /* AYSHIBAT */ 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;
SQLトレースを解除します。
ALTER SESSION SET SQL_TRACE = FALSE;
4. Object Storage Bucket の SQLトレースの確認とダウンロード
Object Storage の Bucket に出力された SQLトレース を確認してダウンロードします。
5. SQLトレース の tkprof による整形と確認
Autonomous Database は OS にはログインできないため、
SQLトレースを整形する場合は別環境で実施する必要があります。
対応するバージョンの tkprofコマンドがセットアップされていれば環境は問わないのですが、
今回は下記の VirtualBox環境 で実施してみました。
OTN の VirtualBoxイメージ で Oracle DB 19c環境 を 楽々構築
https://qiita.com/ora_gonsuke777/items/b41f37637e59319796b4
採取した SQLトレース を VirtualBox の 仮想OS にアップロードして、tkprofコマンド で整形して確認します。
export ORACLE_HOME=/u01/app/oracle/product/version/db_1 export PATH=${PATH}:${ORACLE_HOME}/bin tkprof sqltrace_ayu_sqlt_test1_sqltrace_21569_30852.trc sqltrace_ayu_sqlt_test1_sqltrace_21569_30852.trc.txt view sqltrace_ayu_sqlt_test1_sqltrace_21569_30852.trc.txt
下記のように整形後のSQLトレースを確認できました。
： SELECT /*+ MONITOR NO_VECTOR_TRANSFORM */ /* AYSHIBAT */ 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 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 19 0.48 0.49 0 9177 0 261 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 21 0.48 0.49 0 9177 0 261 Misses in library cache during parse: 0 Optimizer mode: ALL_ROWS Parsing user id: 157 Number of plan statistics captured: 1 Rows (1st) Rows (avg) Rows (max) Row Source Operation ---------- ---------- ---------- --------------------------------------------------- 261 261 261 SORT GROUP BY (cr=9177 pr=0 pw=0 time=496578 us starts=1 cost=30 size=26 card=1) 26000 26000 26000 HASH JOIN (cr=9177 pr=0 pw=0 time=490431 us starts=1 cost=29 size=26 card=1) 2600000 2600000 2600000 JOIN FILTER CREATE :BF0000 (cr=9086 pr=0 pw=0 time=148913 us starts=1 cost=3 size=286 card=26) 2600000 2600000 2600000 TABLE ACCESS STORAGE FULL ORDER_TBL (cr=9086 pr=0 pw=0 time=69464 us starts=1 cost=3 size=286 card=26) 10 10 10 JOIN FILTER USE :BF0000 (cr=91 pr=0 pw=0 time=8325 us starts=1 cost=26 size=4500 card=300) 10 10 10 TABLE ACCESS STORAGE FULL ITEM_TBL (cr=91 pr=0 pw=0 time=7935 us starts=1 cost=26 size=4500 card=300)
一番時間が掛かっていそうなのは、下位Operattion との time値 のギャップが大きい HASH JOIN の部分ですかね～～。
彡(ﾟ)(ﾟ)
6. まとめ
Autonomous Database で SQLトレース を採取して、他環境で整形できるのを確認できました。
現時点(2022/2/28)で待機イベントやバインド変数が取得できないのが残念ですが、今後に期待や！彡(^)(^)
