帰ってきた！ 標準はあるにはあるが癖の多いSQL #2 Actual Plan取得中のキャンセルでも癖が出る Tweet
前々回のエントリーで、MySQL 8.0.32のActual Plan取得中にキャンセルしてもキャンセルされるまでのActual Planを取得できることを確認した。
では、OracleやPostgreSQLではどうなのだろう？（Oracleは皆さんご存知だと思いますが、確認の意味も含めて）
Oracle Database 21c と PostgreSQL 13.6 (私の環境の都合上w）で確認しておこうと思います。
Actual Plan欲しいけど、本番環境でしか試せないとか、実行に数時間以上要するような状況と大人の事情で、泣く泣くキャンセルしなければいけない。
でも、途中まででもいいからActual Plan返してくれたら、原因特定できる。。。かもしれないし。。。と思いますよね。
では、Oracle Database 21cから見てみましょう！
(ご存知の方も多いと思いますので最初に答えを言っちゃうと、Oracleの場合、Actual Plan取得でも、SQLモニターの場合でもキャンセルしても途中までの結果を見ることができます！)
再帰問合せを利用した連番生成を行う方法で試してみます。
SYS@ORCLCDB> select banner_full from v$version;
BANNER_FULL
------------------------------------------------------------------------------------------
Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production Version 21.3.0.0.0
gather_plan_statisticsヒントを利用した、Actual Plan取得（キャンセルせず最後まで実行した例です）
SCOTT@freepdb1> @actual
1 WITH gen_nums(v)
2 AS
3 (
4 SELECT /*+ gather_plan_statistics */ 1
5 FROM
6 dual
7 UNION ALL
8 SELECT v + 1
9 FROM
10 gen_nums
11 WHERE v + 1 <= 10000000
12 )
13* SELECT v from gen_nums
SCOTT@freepdb1> @actual_plan 6n3sc0n82t9dq
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID 6n3sc0n82t9dq, child number 0
-------------------------------------
WITH gen_nums(v) AS ( SELECT /*+ gather_plan_statistics */ 1 FROM
dual UNION ALL SELECT v + 1 FROM gen_nums WHERE v + 1 <=
10000000 ) SELECT v from gen_nums
Plan hash value: 1492144221
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers | Writes | OMem | 1Mem | Used-Mem |
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 4 (100)| | 10M|00:07:57.97 | 105M| 28831 | | | |
| 1 | VIEW | | 1 | 2 | 26 | 4 (0)| 00:00:01 | 10M|00:07:57.97 | 105M| 28831 | | | |
| 2 | UNION ALL (RECURSIVE WITH) BREADTH FIRST| | 1 | | | | | 10M|00:07:53.30 | 105M| 28831 | 2048 | 2048 | 97M (0)|
| 3 | FAST DUAL | | 1 | 1 | | 2 (0)| 00:00:01 | 1 |00:00:00.01 | 0 | 0 | | | |
| 4 | RECURSIVE WITH PUMP | | 10M| | | | | 9999K|00:00:16.81 | 0 | 0 | | | |
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
同SQLを途中でキャンセルした例です。
A-Rows/A-Timeが途中まで実行されたことを示しています。
SCOTT@freepdb1> @actual
1 WITH gen_nums(v)
2 AS
3 (
4 SELECT /*+ gather_plan_statistics */ 1
5 FROM
6 dual
7 UNION ALL
8 SELECT v + 1
9 FROM
10 gen_nums
11 WHERE v + 1 <= 10000000
12 )
13* SELECT v from gen_nums
^CSCOTT@freepdb1>
SCOTT@freepdb1> @actual_plan 6n3sc0n82t9dq
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID 6n3sc0n82t9dq, child number 0
-------------------------------------
WITH gen_nums(v) AS ( SELECT /*+ gather_plan_statistics */ 1 FROM
dual UNION ALL SELECT v + 1 FROM gen_nums WHERE v + 1 <=
10000000 ) SELECT v from gen_nums
Plan hash value: 1492144221
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers | Writes | OMem | 1Mem | Used-Mem |
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 4 (100)| | 7479K|00:06:29.48 | 76M| 21535 | | | |
| 1 | VIEW | | 1 | 2 | 26 | 4 (0)| 00:00:01 | 7479K|00:06:29.48 | 76M| 21535 | | | |
| 2 | UNION ALL (RECURSIVE WITH) BREADTH FIRST| | 1 | | | | | 7479K|00:06:25.85 | 76M| 21535 | 2048 | 2048 | 2048 (0)|
| 3 | FAST DUAL | | 1 | 1 | | 2 (0)| 00:00:01 | 1 |00:00:00.01 | 0 | 0 | | | |
| 4 | RECURSIVE WITH PUMP | | 7479K| | | | | 7479K|00:00:12.40 | 0 | 0 | | | |
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
次に、SQL監視の例を見てみます。まず、キャンセルせず、最後まで実行した場合の例
Global Information
------------------------------
Status : DONE (ALL ROWS)
Instance ID : 1
Session : SCOTT (379:17125)
SQL ID : 8m5nwydj0rk2t
...中略...
Global Stats
============================================================================
| Elapsed | Cpu | IO | Other | Fetch | Buffer | Write | Write |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Calls | Gets | Reqs | Bytes |
============================================================================
| 294 | 195 | 3.56 | 95 | 100K | 105M | 1126 | 225MB |
============================================================================
SQL Plan Monitoring Details (Plan Hash Value=1492144221)
============================================================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Write | Write | Mem | Temp | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes | (Max) | (Max) | (%) | (# samples) |
============================================================================================================================================================================================
| 0 | SELECT STATEMENT | | | | 411 | +0 | 1 | 10M | | | . | . | | |
| 1 | VIEW | | 2 | 4 | 411 | +0 | 1 | 10M | | | . | . | | |
| 2 | UNION ALL (RECURSIVE WITH) BREADTH FIRST | | | | 411 | +0 | 1 | 10M | 1126 | 225MB | 98MB | 226MB | 95.44 | Cpu (248) |
| | | | | | | | | | | | | | | direct path write temp (3) |
| 3 | FAST DUAL | | 1 | 2 | 1 | +0 | 1 | 1 | | | . | . | | |
| 4 | RECURSIVE WITH PUMP | | | | 411 | +0 | 10M | 10M | | | . | . | 1.90 | Cpu (5) |
============================================================================================================================================================================================
次に途中でキャンセルした場合の例。 410sec要していたので、10sec後ぐらいにキャンセルしました。どちらの方法でもキャンセルした場合でも途中までのActual Planを取得できました。MySQLは、Actual Plan取得時のキャンセルの挙動をOracle Database側にあわせたのでしょうかね？
SQLモニターの場合、Global informationのStatusにも着目してください。全行取得できたのか、途中で止められたのか、エラーで途中終了したのかなどの情報も確認できます。
1 WITH gen_nums(v)
2 AS
3 (
4 SELECT /*+ MONITOR */ 1
5 FROM
6 dual
7 UNION ALL
8 SELECT v + 1
9 FROM
10 gen_nums
11 WHERE v + 1 <= 10000000
12 )
13* SELECT v from gen_nums
^CSCOTT@orclpdb1>
Global Information
------------------------------
Status : DONE (FIRST N ROWS)
Instance ID : 1
Session : SCOTT (379:17125)
SQL ID : 8m5nwydj0rk2t
...中略...
Global Stats
=================================================
| Elapsed | Cpu | Other | Fetch | Buffer |
| Time(s) | Time(s) | Waits(s) | Calls | Gets |
=================================================
| 10 | 5.49 | 4.45 | 7216 | 2M |
=================================================
SQL Plan Monitoring Details (Plan Hash Value=1492144221)
=========================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Mem | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | (Max) | (%) | (# samples) |
=========================================================================================================================================================
| 0 | SELECT STATEMENT | | | | 19 | +0 | 1 | 722K | . | | |
| 1 | VIEW | | 2 | 4 | 19 | +0 | 1 | 722K | . | | |
| 2 | UNION ALL (RECURSIVE WITH) BREADTH FIRST | | | | 19 | +0 | 1 | 722K | 34MB | 83.33 | Cpu (5) |
| 3 | FAST DUAL | | 1 | 2 | 1 | +0 | 1 | 1 | . | | |
| 4 | RECURSIVE WITH PUMP | | | | 19 | +0 | 722K | 722K | . | | |
=========================================================================================================================================================
次にPostgreSQL
perftestdb=> select version();
version
--------------------------------------------------------------------------------------------------------
PostgreSQL 13.6 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 8.5.0 20210514 (Red Hat 8.5.0-4), 64-bit
(1 行)
キャンセルせず、最後まで実行した例
perftestdb=> explain (analyze, buffers, verbose)
perftestdb-> WITH RECURSIVE gen_nums(v)
perftestdb-> AS
perftestdb-> (
perftestdb(> SELECT 1
perftestdb(> UNION ALL
perftestdb(> SELECT v + 1
perftestdb(> FROM
perftestdb(> gen_nums
perftestdb(> WHERE v + 1 <= 100000000
perftestdb(> )
perftestdb-> SELECT v from gen_nums;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------
CTE Scan on gen_nums (cost=3.21..3.83 rows=31 width=4) (actual time=0.007..98357.448 rows=100000000 loops=1)
Output: gen_nums.v
Buffers: temp written=170898
CTE gen_nums
-> Recursive Union (cost=0.00..3.21 rows=31 width=4) (actual time=0.005..67023.784 rows=100000000 loops=1)
-> Result (cost=0.00..0.01 rows=1 width=4) (actual time=0.002..0.002 rows=1 loops=1)
Output: 1
-> WorkTable Scan on gen_nums gen_nums_1 (cost=0.00..0.26 rows=3 width=4) (actual time=0.000..0.000 rows=1 loops=100000000)
Output: (gen_nums_1.v + 1)
Filter: ((gen_nums_1.v + 1) <= 100000000)
Rows Removed by Filter: 0
Planning Time: 0.090 ms
Execution Time: 103968.625 ms
(13 行)
キャンセルした例。
Planning Time: 0.090 ms なので、パースフェーズ中にキャンセルする方が難しいですね。103秒ほど要するので、60秒ぐらいでキャンセルしましたが、PostgreSQLの場合は、Actual Plan取得中のキャンセルでは何も出力されません。
XにPostしたところ、篠田さんから、本体側で対応しないと返せなようだ、とコメントをもらいコードを見始めたり() 機能として、あったら便利かもしれないですね。PostgreSQLでも。キャンセルしたところまでのActual Planを返してくれたら問題解決の糸口になることもあるだろうし。
perftestdb=> explain (analyze, buffers, verbose)
WITH RECURSIVE gen_nums(v)
AS
(
SELECT 1
UNION ALL
SELECT v + 1
FROM
gen_nums
WHERE v + 1 <= 100000000
)
SELECT v from gen_nums;
^Cキャンセル要求を送信しました
ERROR: canceling statement due to user request
perftestdb=>
温泉三昧と、いつも満席で諦めてた蕎麦屋のいくつかは食べ歩けた遅いお盆休みも終わり。もう9月が目の前ですね。
では、また。
・標準はあるにはあるが癖の多いSQL 全部俺 #1 Pagination
・標準はあるにはあるが癖の多いSQL 全部俺 #2 関数名は同じでも引数が逆の罠！
・標準はあるにはあるが癖の多いSQL 全部俺 #3 データ型確認したい時あるんです
・標準はあるにはあるが癖の多いSQL 全部俺 #4 リテラル値での除算の内部精度も違うのよ!
・標準はあるにはあるが癖の多いSQL 全部俺 #5 和暦変換機能ある方が少数派
・標準はあるにはあるが癖の多いSQL 全部俺 #6 時間厳守！
・標準はあるにはあるが癖の多いSQL 全部俺 #7 期間リテラル！
・標準はあるにはあるが癖の多いSQL 全部俺 #8 翌月末日って何日？
・標準はあるにはあるが癖の多いSQL 全部俺 #9 部分文字列の扱いでも癖が出る＞＜
・標準はあるにはあるが癖の多いSQL 全部俺 #10 文字列連結の罠（有名なやつ）
・標準はあるにはあるが癖の多いSQL 全部俺 #11 デュエル、じゃなくて、デュアル
・標準はあるにはあるが癖の多いSQL 全部俺 #12 文字[列]探すにも癖がある
・標準はあるにはあるが癖の多いSQL 全部俺 #13 あると便利ですが意外となかったり
・標準はあるにはあるが癖の多いSQL 全部俺 #14 連番の集合を返すにも癖がある
・標準はあるにはあるが癖の多いSQL 全部俺 #15 SQL command line client
・標準はあるにはあるが癖の多いSQL 全部俺 #16 SQLのレントゲンを撮る方法
・標準はあるにはあるが癖の多いSQL 全部俺 #17 その空白は許されないのか？
・標準はあるにはあるが癖の多いSQL 全部俺 #18 (+)の外部結合は方言
・標準はあるにはあるが癖の多いSQL 全部俺 #19 帰ってきた、部分文字列の扱いでも癖w
・標準はあるにはあるが癖の多いSQL 全部俺 #20 結果セットを単一列に連結するにも癖がある
・標準はあるにはあるが癖の多いSQL 全部俺 #21 演算結果にも癖がある
・標準はあるにはあるが癖の多いSQL 全部俺 #22 集合演算にも癖がある
・標準はあるにはあるが癖の多いSQL 全部俺 #23 複数行INSERTにも癖がある
・標準はあるにはあるが癖の多いSQL 全部俺 #24 乱数作るにも癖がある
・標準はあるにはあるが癖の多いSQL 全部俺 #25 SQL de Fractalsにも癖がある:)
・標準はあるにはあるが癖の多いSQL 全部俺 おまけ SQL de 湯婆婆やるにも癖がでるw
・帰ってきた！ 標準はあるにはあるが癖の多いSQL #1 SQL de ROT13 やるにも癖が出るw
| 固定リンク | 0
コメント