« 2023年7月 | トップページ | 2023年9月 »

2023年8月29日 (火)

帰ってきた! 標準はあるにはあるが癖の多いSQL #2 Actual Plan取得中のキャンセルでも癖が出る

前々回のエントリーで、MySQL 8.0.32のActual Plan取得中にキャンセルしてもキャンセルされるまでのActual Planを取得できることを確認した。

では、OracleやPostgreSQLではどうなのだろう?(Oracleは皆さんご存知だと思いますが、確認の意味も含めて)

Oracle Database 21c と PostgreSQL 13.6 (私の環境の都合上w)で確認しておこうと思います。

Actual Plan欲しいけど、本番環境でしか試せないとか、実行に数時間以上要するような状況と大人の事情で、泣く泣くキャンセルしなければいけない。
でも、途中まででもいいからActual Plan返してくれたら、原因特定できる。。。かもしれないし。。。と思いますよね。

MySQL 8.0.32では、キャンセルしても途中まで取得できました。
(SQLパースフェーズの場合を除く。これはOracleでも、PostgreSQLでも同じでしょう。だって、実行前の解析フェーズでキャンセルされたら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)

2023年8月 7日 (月)

帰ってきた! 標準はあるにはあるが癖の多いSQL #1 SQL de ROT13 やるにも癖が出るw

先日、Facebookの思い出なんぞを見返していたら、子供が小さい頃、ROT13で、謎の文字列を解かせる、コナンくん遊びをしてたことを思い出した。

ROT13

流石に小さい頃なので、難易度を下げるためROT13の文字対応表をヒントとして与えることにしようと思ったのですが、それだと逆に簡単になり過ぎると考え、文字列の順番を示す数字を、犯人からのメッセージとして、

謎の数字から犯人のメッセージを解け!。

みたいなことをやっていました。

意外と受けが良くて、複数の問題を解いて遊んで、問題を作る方が疲れるというわけわからん事態になってしまったことがありましたw

ということで、

 

本日の、帰ってきた! 標準はあるにはあるが癖の多いSQL は、 ROT13やるにも、Oracle/PostgreSQL/MySQLの癖が出ますよ!。というお話。

(実装は、SQL script file化してパラメータ渡し、渡せない癖のあるものは、代替方法にて渡すことにします。また、SQLだけで解決することにします)

前置きはこれぐらいにして、早速、間違いない、Oracleからw

 

ROT13 cipher実装するのにベタな感じで、PL/SQLになどに逃げる必要はないです。非常に強力な関数、 translate() 一発で解決できますよ。

SCOTT@freepdb1> select banner from v$version;

BANNER
--------------------------------------------------------------------------------
Oracle Database 23c Free, Release 23.0.0.0.0 - Developer-Release

経過: 00:00:00.02

 

 

 

文字列をrot13/derot13するSQL scriptファイルです。
Oracleの場合、単純です。translate()で対応する文字を返すようにするだけです。

SCOTT@freepdb1> !cat rot13.sql
SELECT
TRANSLATE
(
'&1'
,'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz'
,'NOPQRSTUVWXYZABCDEFGHIJKLMnopqrstuvwxyzabcdefghijklm'
)
;

UNDEFINE 1

 

 

SCOTT@freepdb1> !cat derot13.sql
SELECT
TRANSLATE
(
'&1'
,'NOPQRSTUVWXYZABCDEFGHIJKLMnopqrstuvwxyzabcdefghijklm'
,'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz')
;

UNDEFINE 1

 

 

 

では、実行! うまく行った!
簡単でしょ!この手のSQL文でのお遊びは。

SCOTT@freepdb1> @rot13 'Mac De Oracle'

TRANSLATE('MA
-------------
Znp Qr Benpyr

経過: 00:00:00.00

 

 

SCOTT@freepdb1> @derot13 'Znp Qr Benpyr'

TRANSLATE('ZN
-------------
Mac De Oracle

経過: 00:00:00.01

 

つづいで、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 行)

 

実行! 

[postgres@localhost ~]$ psql -d perftestdb -U discus -p 5432 -W -h localhost -f /var/lib/pgsql/pg_rot13.sql -v str="'Mac De Oracle'"

translate
---------------
Znp Qr Benpyr
(1 行)

 

 

[postgres@localhost ~]$ psql -d perftestdb -U discus -p 5432 -W -h localhost -f /var/lib/pgsql/pg_derot13.sql -v str="'Znp Qr Benpyr'"

translate
---------------
Mac De Oracle
(1 行)

 

PostgreSQLの場合、translate()関数が実装されており、Oracleと同じように利用できました。SQL scriptファイル実行時のパラメータの渡し方に癖がある感じですかね。(なかなか、慣れないです。これ)

[postgres@localhost ~]$ cat pg_rot13.sql
SELECT
TRANSLATE
(
:str
,'NOPQRSTUVWXYZABCDEFGHIJKLMnopqrstuvwxyzabcdefghijklm'
,'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz')
;

 

[postgres@localhost ~]$ cat pg_derot13.sql
SELECT
TRANSLATE
(
':str'
,'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz'
,'NOPQRSTUVWXYZABCDEFGHIJKLMnopqrstuvwxyzabcdefghijklm')
;

 

さて、最後は、MySQL 8.0.xを利用します。理由は使える構文が多くなったためですが。おそらくそれ以前のMySQLだと実装はかなり辛い。

mysql> select version();
+-----------+
| version() |
+-----------+
| 8.0.32 |
+-----------+
1 row in set (0.00 sec)

 

理由は、見ての通り、再帰問合せを利用する必要があるためです。これ使えないとかなりキツイ。w
ついでに、translate()関数も存在しないため、バリバリ既存の関数を使ってシンプルに書いても多分これぐらいw

他に、もっといいやり方あるよーって方、ブログ書いて公開してほしいっす!
ちなみに、ググったら、こんなのをGitHubで見つけました。同じ方法じゃなくてよかったという感じではあります :) 俺オリジナルだ:)

こちらの方は、function化したようですね
https://github.com/samuelfaj/MySQL-rot13/blob/master/MySQL_rot13.sql

 

では、私が作ったSQL scriptファイルでパラメータをSETコマンドで渡す方法。苦心の跡が見えるかと思います。(これは無理だ、function化して逃げるかー。と一瞬過りましたが、閃いた方法がよかったという感じ)

mysql> \! cat mysql_rot13.sql
WITH RECURSIVE rot13(v)
AS
(
SELECT 1
UNION ALL
SELECT v + 1
FROM
rot13
WHERE v + 1 <= CHAR_LENGTH(@str)
)
SELECT
GROUP_CONCAT(
CASE
WHEN
INSTR(
CAST('ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz' AS BINARY)
, SUBSTR(@str, v, 1)
) = 0
THEN
SUBSTR(@str, v, 1)
ELSE
SUBSTR(
'NOPQRSTUVWXYZABCDEFGHIJKLMnopqrstuvwxyzabcdefghijklm'
, INSTR(
CAST('ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyza' AS BINARY)
, SUBSTR(@str, v, 1)
)
, 1
)
END
SEPARATOR ''
) AS rot13
FROM rot13
;

 

mysql> \! cat mysql_derot13.sql
WITH RECURSIVE derot13(v)
AS
(
SELECT 1
UNION ALL
SELECT v + 1
FROM
derot13
WHERE v + 1 <= CHAR_LENGTH(@str)
)
SELECT
GROUP_CONCAT(
CASE
WHEN
INSTR(
CAST('NOPQRSTUVWXYZABCDEFGHIJKLMnopqrstuvwxyzabcdefghijklm' AS BINARY)
, SUBSTR(@str, v, 1)
) = 0
THEN
SUBSTR(@str, v, 1)
ELSE
SUBSTR(
'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz'
, INSTR(
CAST('NOPQRSTUVWXYZABCDEFGHIJKLMnopqrstuvwxyzabcdefghijklm' AS BINARY)
, SUBSTR(@str, v, 1)
)
, 1
)
END
SEPARATOR ''
) AS derot13
FROM derot13
;

 

では実行。

mysql> set @str='Mac De Oracle';
Query OK, 0 rows affected (0.01 sec)

mysql> \. mysql_rot13.sql
+---------------+
| rot13 |
+---------------+
| Znp Qr Benpyr |
+---------------+
1 row in set (0.00 sec)

 

mysql> set @str='Znp Qr Benpyr';
Query OK, 0 rows affected (0.00 sec)

mysql> \. mysql_derot13.sql
+---------------+
| derot13 |
+---------------+
| Mac De Oracle |
+---------------+
1 row in set (0.00 sec)

 

 


 

ということで、いろいろな、癖という鞭に打たれても、ニッコリ笑える。変態になれると良いですね :)

まだまだまだ、クソ暑い、東京からお送りしました。 ではまた。

 



標準はあるにはあるが癖の多い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

 

| | | コメント (0)

2023年8月 4日 (金)

MySQL 8.0.32 / explain analyze 実行途中でキャンセルできるみたいだけど、キャンセルしたら、Actual Plan、途中まで出るの?

本年度一発目のw Databaseネタは、なんと、MySQLネタからのスタートですw

MySQL 8.0.18以降、Actualプランが取得できるようになってた。
また、MySQL 8.0.20 以降、KILL QUERY または CTRL-C を使用してこのステートメントを終了できるとある。
ただ、マニュアルに記載されているのはここまでで、キャンセルできることは記載されているが、キャンセルした場合のActual Planはどこまで出力されるのだろう? or 全く出力されない?

OracleのリアルタイムSQL監視だとキャンセルすると不完全ではあるけども、なんとなーく判断できる程度の情報は途中まで取得できるが、
GATHER_PLAN_STATISTICSヒントなどを使ったActualプランは最後まで実行しないとアcつあlはしゅとくできない。どちらのタイプに似ているのでしょうね?

長時間(数日とかw)かかってしまうようになったSQLのActualプラン取得するの意外と難しいケースも場合によってはあったりするわけで。。。そんなとき、Actualみたいけど、キャンセルしたらどうなるのだろうと。。
途中まででも取得できるのか、それとも、Nothingなのか。。。

MySQLのActualプランの取得はどうなんだろう。。。ということで、試してみた。

EXPLAIN ANALYZE による情報の取得
https://dev.mysql.com/doc/refman/8.0/ja/explain.html#explain-analyze





結論から書くと、
MySQL 8.0.32での検証だが、

explain analyzeで取得できるActual Planは、対応しているSQL文の実行中にCTRL-Cでキャンセルしても、その時点までの、Actual Planを表示してくれる!!!!!!

ただし、パース時間が異常に長めのSQL文(結合数めちゃ多いとか)だと、実行以前に、パース時間が長いため、パースフェーズでキャンセルしてしまうの何も表示されない。。と(最初はこちらを引いてしまったので、常に表示されないものかと思い込んでしまった)
他の方法で実行をキャンセルした場合も同じだろう。とは思う。

いや、他にも出力されないケースがあるとか、その検証方法だから出力されているだけどか、MySQLのexplain analyzeのディープなツッコミがありましたら、よろしくお願いします。:)

MySQLの8.0台ってマイナー番号変わっても機能追加されたり変化しているので、一応。 MySQL 8.0.32 上では。ということにしておく。




以下、検証の記録的なもの。

確認に使用した MySQLのバージョン

[master@localhost ~]$ mysql -u scott -p
Enter password:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 8
Server version: 8.0.32 Source distribution

Copyright (c) 2000, 2023, Oracle and/or its affiliates.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> select version();
+-----------+
| version() |
+-----------+
| 8.0.32 |
+-----------+
1 row in set (0.00 sec)

事前に準備したクエリ向け表と索引など

Database changed
mysql> use perftestdb
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql>
mysql> desc master;
+--------+-------------+------+-----+---------+-------+
| Field | Type | Null | Key | Default | Extra |
+--------+-------------+------+-----+---------+-------+
| id | int | NO | PRI | NULL | |
| dummya | varchar(10) | YES | | NULL | |
+--------+-------------+------+-----+---------+-------+
2 rows in set (0.01 sec)

mysql> desc detail;
+--------+-------------+------+-----+---------+-------+
| Field | Type | Null | Key | Default | Extra |
+--------+-------------+------+-----+---------+-------+
| id | int | NO | PRI | NULL | |
| subid | int | NO | PRI | NULL | |
| dummya | varchar(10) | YES | | NULL | |
+--------+-------------+------+-----+---------+-------+
3 rows in set (0.00 sec)

mysql> show indexes from master;
+--------+------------+----------+--------------+-------------+------------+
| Table | Non_unique | Key_name | Seq_in_index | Column_name | Index_type |
+--------+------------+----------+--------------+-------------+------------+
| master | 0 | PRIMARY | 1 | id | BTREE |
+--------+------------+----------+--------------+-------------+------------+
1 row in set (0.02 sec)

mysql> show indexes from detail;
+--------+------------+----------+--------------+-------------+------------+
| Table | Non_unique | Key_name | Seq_in_index | Column_name | Index_type |
+--------+------------+----------+--------------+-------------+------------+
| detail | 0 | PRIMARY | 1 | id | BTREE |
| detail | 0 | PRIMARY | 2 | subid | BTREE |
+--------+------------+----------+--------------+-------------+------------+
2 rows in set (0.02 sec)

mysql> select * from master;
+----+--------+
| id | dummya |
+----+--------+
| 1 | 1 |
| 2 | 2 |
| 3 | 3 |
| 4 | 4 |
| 5 | 5 |
| 6 | 6 |
| 7 | 7 |
| 8 | 8 |
| 9 | 9 |
| 10 | 10 |
+----+--------+
10 rows in set (0.01 sec)

mysql> select * from detail;
+----+-------+--------+
| id | subid | dummya |
+----+-------+--------+
| 1 | 1 | 11 |
| 1 | 2 | 12 |
| 2 | 1 | 21 |
| 2 | 2 | 22 |
| 3 | 1 | 31 |
...略...
| 7 | 1 | 71 |
| 7 | 2 | 72 |
| 8 | 1 | 81 |
| 8 | 2 | 82 |
| 9 | 1 | 91 |
| 9 | 2 | 92 |
| 10 | 1 | 101 |
| 10 | 2 | 102 |
+----+-------+--------+
20 rows in set (0.01 sec)

検証用に作ったSQL。どのぐらいのElapsed Timeかanaluyzeをつけて実行して、キャンセルしやすい程度のElapsed Timeか確認しておきます。

mysql> explain analyze
-> select *
-> from
-> master inner join detail
-> on master.id = detail.id
-> inner join detail t2
-> on
-> t2.id = detail.id
-> inner join detail t3
-> on
-> t3.id = t2.id
-> inner join detail t4
-> on
-> t4.id = t3.id
-> inner join detail t5
-> on
-> t5.id = t4.id
-> inner join detail t6
-> on
-> t6.id = t5.id
-> inner join detail t7
-> on
-> t7.id = t6.id
-> inner join detail t8
-> on
-> t8.id = t7.id
-> inner join detail t9
-> on
-> t9.id = t8.id
-> inner join detail t10
-> on
-> t10.id = t9.id
-> ;
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| EXPLAIN |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| -> Nested loop inner join (cost=5729.85 rows=8192) (actual time=0.115..37.938 rows=10240 loops=1)
-> Nested loop inner join (cost=2862.65 rows=4096) (actual time=0.108..18.747 rows=5120 loops=1)
-> Nested loop inner join (cost=1429.05 rows=2048) (actual time=0.102..9.267 rows=2560 loops=1)
-> Nested loop inner join (cost=712.25 rows=1024) (actual time=0.097..4.689 rows=1280 loops=1)
-> Nested loop inner join (cost=353.85 rows=512) (actual time=0.091..2.336 rows=640 loops=1)
-> Nested loop inner join (cost=174.65 rows=256) (actual time=0.086..1.203 rows=320 loops=1)
-> Nested loop inner join (cost=85.05 rows=128) (actual time=0.080..0.630 rows=160 loops=1)
-> Nested loop inner join (cost=40.25 rows=64) (actual time=0.075..0.337 rows=80 loops=1)
-> Nested loop inner join (cost=17.85 rows=32) (actual time=0.069..0.189 rows=40 loops=1)
-> Nested loop inner join (cost=6.65 rows=16) (actual time=0.063..0.110 rows=20 loops=1)
-> Table scan on master (cost=1.05 rows=8) (actual time=0.041..0.047 rows=10 loops=1)
-> Index lookup on detail using PRIMARY (id=`master`.id) (cost=0.53 rows=2) (actual time=0.005..0.006 rows=2 loops=10)
-> Index lookup on t2 using PRIMARY (id=`master`.id) (cost=0.51 rows=2) (actual time=0.003..0.004 rows=2 loops=20)
-> Index lookup on t3 using PRIMARY (id=`master`.id) (cost=0.51 rows=2) (actual time=0.002..0.003 rows=2 loops=40)
-> Index lookup on t4 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.002..0.003 rows=2 loops=80)
-> Index lookup on t5 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.002..0.003 rows=2 loops=160)
-> Index lookup on t6 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.002..0.003 rows=2 loops=320)
-> Index lookup on t7 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.002..0.003 rows=2 loops=640)
-> Index lookup on t8 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.002..0.003 rows=2 loops=1280)
-> Index lookup on t9 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.002..0.003 rows=2 loops=2560)
-> Index lookup on t10 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.002..0.003 rows=2 loops=5120)
|
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (21.18 sec)


では、explain analyseを途中でキャンセルしてみます。elapsed timeが21秒ほどなので、20秒後にキャンセルしてみます。

mysql> explain analyze
select *
from
master inner join detail
on master.id = detail.id
inner join detail t2
on t2.id = master.id
inner join detail t3
on t3.id = master.id
inner join detail t4
on t4.id = master.id
inner join detail t5
on t5.id = master.id
inner join detail t6
on t6.id = master.id
inner join detail t7
on t7.id = master.id
inner join detail t8
on t8.id = master.id
inner join detail t9
on t9.id = master.id
inner join detail t10
on t10.id = master.id
;
^C^C -- query aborted
ERROR 1317 (70100): Query execution was interrupted
mysql>


! やはり、実行途中のキャンセルだとActual Planは何も出力されないみたい。。。。

??ん? いや、なんか違うな。これw!

SQL文の実行時間はたいしたことない。人間がこの時間内にピンポイントでキャンセルするには短すぎるよね。
SQL文の実行時間は、約38ミリ秒!!! こっちだw 最終に表示されている21秒には、SQLのパース時間も含まれているはず。。。。見逃した。俺としたことが。。。

| -> Nested loop inner join  (cost=5729.85 rows=8192) (actual time=0.115..37.938 rows=10240 loops=1)

キャンセルしたのは、SQL実行後、おおよそ、20秒後。SQLのActualタイムを見ると38ミリ秒なので、ギリギリ、パース時間中に被ってそう。

1 row in set (21.00 sec)

だとしたら、まず、そこから確認。パースにどの程度要しているか、explainだけにすれば、良さそうだよね。Oracle Databaseでもそうだし。(PostgreSQLはパース時間も表示してくれたりするけども。あれ意外に便利なんだよ)

mysql> explain format=tree    -> select *
-> from
-> master inner join detail
-> on master.id = detail.id
-> inner join detail t2
-> on
-> t2.id = detail.id
-> inner join detail t3
-> on
-> t3.id = t2.id
-> inner join detail t4
-> on
-> t4.id = t3.id
-> inner join detail t5
-> on
-> t5.id = t4.id
-> inner join detail t6
-> on
-> t6.id = t5.id
-> inner join detail t7
-> on
-> t7.id = t6.id
-> inner join detail t8
-> on
-> t8.id = t7.id
-> inner join detail t9
-> on
-> t9.id = t8.id
-> inner join detail t10
-> on
-> t10.id = t9.id
-> ;
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| EXPLAIN |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| -> Nested loop inner join (cost=5729.85 rows=8192)
-> Nested loop inner join (cost=2862.65 rows=4096)
-> Nested loop inner join (cost=1429.05 rows=2048)
-> Nested loop inner join (cost=712.25 rows=1024)
-> Nested loop inner join (cost=353.85 rows=512)
-> Nested loop inner join (cost=174.65 rows=256)
-> Nested loop inner join (cost=85.05 rows=128)
-> Nested loop inner join (cost=40.25 rows=64)
-> Nested loop inner join (cost=17.85 rows=32)
-> Nested loop inner join (cost=6.65 rows=16)
-> Table scan on master (cost=1.05 rows=8)
-> Index lookup on detail using PRIMARY (id=`master`.id) (cost=0.53 rows=2)
-> Index lookup on t2 using PRIMARY (id=`master`.id) (cost=0.51 rows=2)
-> Index lookup on t3 using PRIMARY (id=`master`.id) (cost=0.51 rows=2)
-> Index lookup on t4 using PRIMARY (id=`master`.id) (cost=0.50 rows=2)
-> Index lookup on t5 using PRIMARY (id=`master`.id) (cost=0.50 rows=2)
-> Index lookup on t6 using PRIMARY (id=`master`.id) (cost=0.50 rows=2)
-> Index lookup on t7 using PRIMARY (id=`master`.id) (cost=0.50 rows=2)
-> Index lookup on t8 using PRIMARY (id=`master`.id) (cost=0.50 rows=2)
-> Index lookup on t9 using PRIMARY (id=`master`.id) (cost=0.50 rows=2)
-> Index lookup on t10 using PRIMARY (id=`master`.id) (cost=0.50 rows=2)
|
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (21.84 sec)


お! 予想通り、explainでパースだけさせたら、explain analyze(SQL文の実行を含む)とほぼ同じ 21秒台。想定は正しそう。

だとすると、今回確認したいことを実現するには、..... SQLの実行時間をもっと長くして、人がw キャンセルしやすい程度に実行時間を間延びさせておく必要がある。。
とはいえ、大量のデータを用意する時間もVMのストレージもないと。。。

さて、どうするか。。。。

***** ここで、 一休さん、考え中。。。 木魚の音。ポク、ポク、ポク。。。。w *****


***** ここで、 一休さん、閃いた。。。 鐘の音、チーーーーーん *****
 
sleep()関数を使って、眠らせると時間稼ぎできるのでは?  やってみよう!
おおおおお、いい感じだ。

mysql> explain analyze
-> select *, sleep(0.01)
-> from
-> master inner join detail
-> on master.id = detail.id
-> inner join detail t2
-> on
-> t2.id = detail.id
-> inner join detail t3
-> on
-> t3.id = t2.id
-> inner join detail t4
-> on
-> t4.id = t3.id
-> inner join detail t5
-> on
-> t5.id = t4.id
-> inner join detail t6
-> on
-> t6.id = t5.id
-> inner join detail t7
-> on
-> t7.id = t6.id
-> inner join detail t8
-> on
-> t8.id = t7.id
-> inner join detail t9
-> on
-> t9.id = t8.id
-> inner join detail t10
-> on
-> t10.id = t9.id
-> ;
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| EXPLAIN |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| -> Nested loop inner join (cost=5729.85 rows=8192) (actual time=0.170..232.399 rows=10240 loops=1)
-> Nested loop inner join (cost=2862.65 rows=4096) (actual time=0.164..75.457 rows=5120 loops=1)
-> Nested loop inner join (cost=1429.05 rows=2048) (actual time=0.159..37.659 rows=2560 loops=1)
-> Nested loop inner join (cost=712.25 rows=1024) (actual time=0.154..17.709 rows=1280 loops=1)
-> Nested loop inner join (cost=353.85 rows=512) (actual time=0.149..9.612 rows=640 loops=1)
-> Nested loop inner join (cost=174.65 rows=256) (actual time=0.143..4.658 rows=320 loops=1)
-> Nested loop inner join (cost=85.05 rows=128) (actual time=0.138..2.285 rows=160 loops=1)
-> Nested loop inner join (cost=40.25 rows=64) (actual time=0.132..1.174 rows=80 loops=1)
-> Nested loop inner join (cost=17.85 rows=32) (actual time=0.126..0.625 rows=40 loops=1)
-> Nested loop inner join (cost=6.65 rows=16) (actual time=0.120..0.347 rows=20 loops=1)
-> Table scan on master (cost=1.05 rows=8) (actual time=0.097..0.122 rows=10 loops=1)
-> Index lookup on detail using PRIMARY (id=`master`.id) (cost=0.53 rows=2) (actual time=0.017..0.021 rows=2 loops=10)
-> Index lookup on t2 using PRIMARY (id=`master`.id) (cost=0.51 rows=2) (actual time=0.010..0.013 rows=2 loops=20)
-> Index lookup on t3 using PRIMARY (id=`master`.id) (cost=0.51 rows=2) (actual time=0.010..0.013 rows=2 loops=40)
-> Index lookup on t4 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.010..0.013 rows=2 loops=80)
-> Index lookup on t5 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.010..0.014 rows=2 loops=160)
-> Index lookup on t6 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.011..0.015 rows=2 loops=320)
-> Index lookup on t7 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.009..0.012 rows=2 loops=640)
-> Index lookup on t8 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.011..0.015 rows=2 loops=1280)
-> Index lookup on t9 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.010..0.014 rows=2 loops=2560)
-> Index lookup on t10 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.010..0.028 rows=2 loops=5120)
|
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (2 min 47.64 sec)


Elapsed Timeがパース時間より長くなったので、できそう。 60秒後にキャンセルすれば余裕はありそう。

1 row in set (2 min 47.64 sec)

explain analyzeを実行して、60秒後にキャンセルした!

mysql> explain analyze
-> select *, sleep(0.01)
-> from
-> master inner join detail
-> on master.id = detail.id
-> inner join detail t2
-> on
-> t2.id = detail.id
-> inner join detail t3
-> on
-> t3.id = t2.id
-> inner join detail t4
-> on
-> t4.id = t3.id
-> inner join detail t5
-> on
-> t5.id = t4.id
-> inner join detail t6
-> on
-> t6.id = t5.id
-> inner join detail t7
-> on
-> t7.id = t6.id
-> inner join detail t8
-> on
-> t8.id = t7.id
-> inner join detail t9
-> on
-> t9.id = t8.id
-> inner join detail t10
-> on
-> t10.id = t9.id
-> ;

^C^C -- query aborted

+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| EXPLAIN |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| -> Nested loop inner join (cost=5729.85 rows=8192) (actual time=0.113..92.382 rows=2639 loops=1)
-> Nested loop inner join (cost=2862.65 rows=4096) (actual time=0.106..29.480 rows=1320 loops=1)
-> Nested loop inner join (cost=1429.05 rows=2048) (actual time=0.101..14.323 rows=660 loops=1)
-> Nested loop inner join (cost=712.25 rows=1024) (actual time=0.096..7.161 rows=330 loops=1)
-> Nested loop inner join (cost=353.85 rows=512) (actual time=0.090..3.507 rows=165 loops=1)
-> Nested loop inner join (cost=174.65 rows=256) (actual time=0.085..1.624 rows=83 loops=1)
-> Nested loop inner join (cost=85.05 rows=128) (actual time=0.079..0.867 rows=42 loops=1)
-> Nested loop inner join (cost=40.25 rows=64) (actual time=0.073..0.352 rows=21 loops=1)
-> Nested loop inner join (cost=17.85 rows=32) (actual time=0.068..0.210 rows=11 loops=1)
-> Nested loop inner join (cost=6.65 rows=16) (actual time=0.062..0.122 rows=6 loops=1)
-> Table scan on master (cost=1.05 rows=8) (actual time=0.040..0.044 rows=3 loops=1)
-> Index lookup on detail using PRIMARY (id=`master`.id) (cost=0.53 rows=2) (actual time=0.021..0.024 rows=2 loops=3)
-> Index lookup on t2 using PRIMARY (id=`master`.id) (cost=0.51 rows=2) (actual time=0.011..0.014 rows=2 loops=6)
-> Index lookup on t3 using PRIMARY (id=`master`.id) (cost=0.51 rows=2) (actual time=0.009..0.012 rows=2 loops=11)
-> Index lookup on t4 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.020..0.024 rows=2 loops=21)
-> Index lookup on t5 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.014..0.017 rows=2 loops=42)
-> Index lookup on t6 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.015..0.022 rows=2 loops=83)
-> Index lookup on t7 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.014..0.021 rows=2 loops=165)
-> Index lookup on t8 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.016..0.021 rows=2 loops=330)
-> Index lookup on t9 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.015..0.022 rows=2 loops=660)
-> Index lookup on t10 using PRIMARY (id=`master`.id) (cost=0.50 rows=2) (actual time=0.015..0.044 rows=2 loops=1320)
|
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set, 1 warning (1 min 3.57 sec)


SQLのActualタイムは、92ミリ秒、処理した行数が、2629行。

| -> Nested loop inner join  (cost=5729.85 rows=8192) (actual time=0.113..92.382 rows=2639 loops=1)

以下を見ると、loopsが、1320回となっている。

    -> Index lookup on t10 using PRIMARY (id=`master`.id)  (cost=0.50 rows=2) (actual time=0.015..0.044 rows=2 loops=1320)

やった〜〜〜。 MySQLの explain analyzeは、"SQLの実行途中"(パース時間が長い割に、実行時間が短い場合は、実行中にキャンセルするのが難しいので表示されないケースはあるので注意)でキャンセルしても、途中までのActual Planを返してくれる!


念の為、sleep()関数を使ったトリッキーな再現方法ではなく、実際にSQLの実行中にキャンセルする方法を思いついたので、さらに、試してみる!


お分かりだろうか。 みなさん大好き(?)、 再起問い合わせ再帰問合せでシーケンス番号を生成するクエリーだ。100000000ぐらい生成すれば、いい感じの実行時間になるだろうと、思われるので、まず、このSQLのパース時間だけ確認。


mysql> SET SESSION cte_max_recursion_depth = 100000000;
Query OK, 0 rows affected (0.00 sec)

パース時間はほぼかかってないですね。先ほどの例は、結合する表が多いので、パース時間は長くなる傾向があるので、シンプルなSQLだけど、実行時間は、なげ〜〜〜〜ぞ〜というのにしてみた。

mysql> explain format=tree
-> 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;
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| EXPLAIN |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| -> Table scan on gen_nums (cost=3.87..5.56 rows=3)
-> Materialize recursive CTE gen_nums (cost=3.03..3.03 rows=3)
-> Rows fetched before execution (cost=0.00..0.00 rows=1)
-> Repeat until convergence
-> Filter: ((gen_nums.v + 1) <= 100000000) (cost=2.73 rows=2)
-> Scan new records on gen_nums (cost=2.73 rows=2)
|
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)


explain analyzeの実時間を確認

mysql> explain analyze
-> 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;
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| EXPLAIN |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| -> Table scan on gen_nums (cost=3.87..5.56 rows=3) (actual time=139082.095..178091.268 rows=100000000 loops=1)
-> Materialize recursive CTE gen_nums (cost=3.03..3.03 rows=3) (actual time=139081.959..139081.959 rows=100000000 loops=1)
-> Rows fetched before execution (cost=0.00..0.00 rows=1) (actual time=0.000..0.000 rows=1 loops=1)
-> Repeat until convergence
-> Filter: ((gen_nums.v + 1) <= 100000000) (cost=2.73 rows=2) (actual time=0.003..29453.367 rows=50000000 loops=2)
-> Scan new records on gen_nums (cost=2.73 rows=2) (actual time=0.002..21852.139 rows=50000000 loops=2)
|
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (3 min 8.46 sec)

Actual timeは、178秒なので、60秒後にキャンセルすればよさそうですね。

| -> Table scan on gen_nums  (cost=3.87..5.56 rows=3) (actual time=139082.095..178091.268 rows=100000000 loops=1)

では、キャンセルでどうなるか検証!!

mysql> explain analyze
-> 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^C -- query aborted
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| EXPLAIN |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| -> Table scan on gen_nums (cost=3.87..5.56 rows=3) (never executed)
-> Materialize recursive CTE gen_nums (cost=3.03..3.03 rows=3) (never executed)
-> Rows fetched before execution (cost=0.00..0.00 rows=1) (actual time=0.000..0.000 rows=1 loops=1)
-> Repeat until convergence
-> Filter: ((gen_nums.v + 1) <= 100000000) (cost=2.73 rows=2) (actual time=0.004..27789.355 rows=47924088 loops=1)
-> Scan new records on gen_nums (cost=2.73 rows=2) (actual time=0.002..20555.788 rows=47924088 loops=1)
|
+------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set, 1 warning (1 min 3.94 sec)


60行でキャンセルしたので、ほぼ同じ。

1 row in set, 1 warning (1 min 3.94 sec

以下の行ソースを見ると、Actual timeが21秒ほど、rowsも47924088行。


-> Scan new records on gen_nums (cost=2.73 rows=2) (actual time=0.002..20555.788 rows=47924088 loops=1)

興味深い部分は、以下の2行の行ソース。never execute と表示されている。

| -> Table scan on gen_nums  (cost=3.87..5.56 rows=3) (never executed)
-> Materialize recursive CTE gen_nums (cost=3.03..3.03 rows=3) (never executed)
¥


これを見る限り、MySQLのexplain analyzeは、SQL文の実行フェース中にキャンセルすると、その時点までの Actual Planを出力してくれる。これ、結構嬉しいよね。長時間実行で、仕方なくキャンセルするにしても途中の状態。運が良ければ、詰まっている部分が見えるかもしれないわけで。。。


いや、他にも出力されないケースがあるとか、その検証方法だから出力されているだけどか、MySQLのexplain analyzeのディープなツッコミがありましたら、よろしくお願いします。:) (大事なので、2度書いておくw)


以上、explain analyze のブラックボックステスト。 実行途中でキャンセルできるみたいだけど、キャンセルしたら、Actual Plan、途中まで出るの? の巻。終わり。


似てるようで、似てない。それぞれのRDBMSの世界w。 ではまた。

 

参考)
EXPLAIN ANALYZE による情報の取得
https://dev.mysql.com/doc/refman/8.0/ja/explain.html#explain-analyze


| | | コメント (0)

2023年8月 3日 (木)

DTM/GarageBand 7月のTop5 / N + 1 Loops

さて、恒例の? My DTM/GarageBand - N + 1 Loops、7月のTop5

(下位の方は色々動いてるんだけど、それらが上位に上がってこないと、変化しにくいw 6位以降はかなり入れ替わってきたけど)


1. Rain Loops / N + 1 Loops - 1,093回
2. Memories Loops / N + 1 Loops - 713回
3. Loops in Clouds / N + 1 Loops - 673回
4. Waterfall Loops - Dance Edition / N + 1 Loops - 524回
5. Number Of Loops - Club Edition / N + 1 Loops - 475回


Rain Loops / N + 1 Loops


Memories Loops / N + 1 Loops


Loops in Clouds / N + 1 Loops


Waterfall Loops - Dance Edition / N + 1 Loops


Number Of Loops - Club Edition / N + 1 Loops



6位以下は、Playlistで。


鎌倉にいい感じの古民家コワーキングスペースを見つけて、行ってきたんだけど、たまたま、終日私だけで、貸切みたいで最高だった:)

では、また

| | | コメント (0)

DTM/GarageBand : 7月にリリースした曲

ということで、最近のルーティーンw

DTM/GarageBand : 7月にリリースした N + 1 Loops の曲

Warm Breeze Loops / N + 1 Loops - 2023/07/02

クリアなブラスのLoopをちょっとラスティーな感じできないのかなぁ。とおもってて、以前試したディストーションをかけてみたら、それなりの感じに:)


High Way Loops / N + 1 Loops - 2023/07/07

前曲同様、サックスにディストーション効かせた実験。クリアな音のブラス系ループが多いので、ディストーション効かせると渋さがでてきてよさげな感じできることは理解したw


他力本願 Loops / N + 1 Loops - 2023/07/22

Spotify聴いてたら、お経みたいなのに音を被せている面白い曲があって、それ聴いたとたん、作られねば!
と、フリーのお経音源を探して作ってみた曲w
DTMって、この手の遊びが面白い。


あと、お遊びといえば、Beat Saberやってる動画をまんまアップすると色々面倒くさいので、DTMで作った曲に置き換えてみた。
このBeat Saberの曲特に何もかんがて無いくて、Beat Saber向けの音置き換えぐらいの気持ちしかないので、特にN + 1 Loopsにはしてないのだけども、一応

元は、Beat Saber - Week End Die for You remix / Export modeとExpert+ modeのなのですが、音だけDTMで作った曲に変えて動画に合わせています:)

muggy 過ぎるよな最近の日本
では、また。

| | | コメント (0)