Yakstは、海外の役立つブログ記事などを人力で翻訳して公開するプロジェクトです。
6年弱前投稿

MySQLのストアドプロシージャ、ファンクション、トリガーのパフォーマンスが悪いのはなぜか

MySQLのストアドプロシージャ、ファンクション、トリガーの性能が良くない理由について解説した記事。 実際のテストケースを交えながら、性能が落ちてしまうケースについて考察しています。

原文
Why MySQL Stored Procedures, Functions and Triggers Are Bad For Performance - Percona Database Performance Blog (English)
原文公開日
2018-07-12
翻訳依頼者
D98ee74ffe0fafbdc83b23907dda3665
翻訳者
C17de91fbad737faaa06173533ed323d kakuka4430
翻訳レビュアー
D98ee74ffe0fafbdc83b23907dda3665 doublemarket
原著者への翻訳報告
2102日前 原文へのコメントで報告済み 編集


アプリケーション開発者は、MySQLのストアドプロシージャ、ファンクション、トリガーをよく作成します。しかしながら、私が知る限り、MySQLのストアドルーチンを使うとデータベースの性能に問題が起きてしまうケースがいくつかあります。ただ、これまでお客様の環境で見てきたことであり、私自身完全に理解はしていないので、データベースの性能に及ぼす影響を測定するための簡単なテストを用意しました。この結果にあなたは驚くかもしれません。

ストアドルーチンが最適なパフォーマンスを発揮しない理由:ショートバージョン

最近、私はトリガーやストアドルーチンの性能を分析する顧客と一緒に働きました。そこで私が学んだのは、"死んだ" コード(ブランチ内に存在するが決して実行されないコード)が ファンクション・プロシージャ・トリガー のレスポンスタイムを大幅に遅延させていていることでした。私たちは、必要としないコードを掃除するために注意する必要があります。

MySQLストアドファンクションを分析する

以下の4つの簡単なストアドファンクションを比較してみましょう(in MySQL5.7)

ファンクション1:

CREATE DEFINER=`root`@`localhost` FUNCTION `func1`() RETURNS int(11)
BEGIN
    declare r int default 0;
RETURN r;
END

変数を定義し、それを返す簡単なファンクションです。これはダミーファンクションです。

ファンクション2:

CREATE DEFINER=`root`@`localhost` FUNCTION `func2`() RETURNS int(11)
BEGIN
    declare r int default 0;
    IF 1=2
    THEN
        select levenshtein_limit_n('test finc', 'test func', 1000) into r;
    END IF;
RETURN r;
END

レーベンシュタイン距離を計算する levenshtein_limit_n 関数を呼び出す関数です。しかし、「IF 1=2」という条件は決して真にならないため、このコードが実行されることはありません。そのため、このファンクションは上のファンクション1と同義です。

ファンクション3:

CREATE DEFINER=`root`@`localhost` FUNCTION `func3`() RETURNS int(11)
BEGIN
    declare r int default 0;
    IF 1=2 THEN
        select levenshtein_limit_n('test finc', 'test func', 1) into r;
    END IF;
    IF 2=3 THEN
        select levenshtein_limit_n('test finc', 'test func', 10) into r;
    END IF;
    IF 3=4 THEN
        select levenshtein_limit_n('test finc', 'test func', 100) into r;
    END IF;
    IF 4=5 THEN
        select levenshtein_limit_n('test finc', 'test func', 1000) into r;
    END IF;
RETURN r;
END

この関数には4つのIF条件が含まれていますが、どれも真になることはありません。つまり4つの "死んだ" コードが存在しています。ファンクション3の実行結果は、ファンクション1 および 2 と同じになります。

ファンクション4:

CREATE DEFINER=`root`@`localhost` FUNCTION `func3_nope`() RETURNS int(11)
BEGIN
    declare r int default 0;
    IF 1=2 THEN
        select does_not_exit('test finc', 'test func', 1) into r;
    END IF;
    IF 2=3 THEN
        select does_not_exit('test finc', 'test func', 10) into r;
    END IF;
    IF 3=4 THEN
        select does_not_exit('test finc', 'test func', 100) into r;
    END IF;
    IF 4=5 THEN
        select does_not_exit('test finc', 'test func', 1000) into r;
    END IF;
RETURN r;
END

ファンクション3とほぼ同じ内容ですが、実行しようとしている関数は存在しないものです。そのため、select does_not_exit関数は決して実行されません。

以上、全ての関数は必ず 0 を返します。これらファンクションの性能は同じ、もしくはかなり近いものになることが予想されます。しかし、驚くべきことにそうはなりません!私は同じファンクションを100万回実行する "benchmark" 関数を使用して性能を計測しました。以下がその結果です:

+-----------------------------+
| benchmark(1000000, func1()) |
+-----------------------------+
|                           0 |
+-----------------------------+
1 row in set (1.75 sec)
+-----------------------------+
| benchmark(1000000, func2()) |
+-----------------------------+
|                           0 |
+-----------------------------+
1 row in set (2.45 sec)
+-----------------------------+
| benchmark(1000000, func3()) |
+-----------------------------+
|                           0 |
+-----------------------------+
1 row in set (3.85 sec)
+----------------------------------+
| benchmark(1000000, func3_nope()) |
+----------------------------------+
|                                0 |
+----------------------------------+
1 row in set (3.85 sec)

御覧の通り、func3(決して実行されない4つのデッドコードが含まれている点以外、func1と同じ)が func1 よりも3倍近く遅いことが分かります。func3_nope()は func3() と実行時間が同じになっています。

ファンクションによる全てのシステムコールを可視化する

ファクションのコール処理内部で何が起きているのかを解明するため、performance_schema および sys schema を使って、ps_trace_thread() プロシージャによるトレースを取得しました。

1. MySQLコネクションの thread_id を取得します

mysql> select THREAD_ID from performance_schema.threads where processlist_id = connection_id();
+-----------+
| THREAD_ID |
+-----------+
|        49 |
+-----------+
1 row in set (0.00 sec)

2. 別のコネクションから thread_id=49 に対して ps_trace_thread を実行

mysql> CALL sys.ps_trace_thread(49, concat('/var/lib/mysql-files/stack-func1-run1.dot'), 10, 0, TRUE, TRUE, TRUE);
+--------------------+
| summary            |
+--------------------+
| Disabled 0 threads |
+--------------------+
1 row in set (0.00 sec)
+---------------------------------------------+
| Info                                        |
+---------------------------------------------+
| Data collection starting for THREAD_ID = 49 |
+---------------------------------------------+
1 row in set (0.00 sec)

3. ここで元のコネクション(thread_id = 49)に切り替え、func1()を実行

mysql> select func1();
+---------+
| func1() |
+---------+
|       0 |
+---------+
1 row in set (0.00 sec)

4. sys.ps_trace_thread が情報を集め(私が select func1() を実行した10秒間)、収集が完了したら dot ファイルを作成します

+-----------------------------------------------------------------------+
| Info                                                                  |
+-----------------------------------------------------------------------+
| Stack trace written to /var/lib/mysql-files/stack-func3nope-new12.dot |
+-----------------------------------------------------------------------+
1 row in set (9.21 sec)
+-------------------------------------------------------------------------------+
| Convert to PDF                                                                |
+-------------------------------------------------------------------------------+
| dot -Tpdf -o /tmp/stack_49.pdf /var/lib/mysql-files/stack-func3nope-new12.dot |
+-------------------------------------------------------------------------------+
1 row in set (9.21 sec)
+-------------------------------------------------------------------------------+
| Convert to PNG                                                                |
+-------------------------------------------------------------------------------+
| dot -Tpng -o /tmp/stack_49.png /var/lib/mysql-files/stack-func3nope-new12.dot |
+-------------------------------------------------------------------------------+
1 row in set (9.21 sec)
Query OK, 0 rows affected (9.45 sec)

上記の手順を全ファンクションに対して繰り返し行い、各コマンドのチャート図を作成しました。結果は以下の通りです:

Func1()

Galera

Func2()

func2.png

Func3()

func3.png

見て分かる通り、全ての if チェックの後に opening tables statementが続くsp/jump_if_notコールが存在しています(これはかなり興味深いです)。つまり、"IF"条件のパースが違いを生んでいるのです。

MySQL8.0の場合、 MySQL source code documentation for stored routinesを読めば、それがどのように実装されているか分かります。いわく:

Flow Analysis Optimizations
After code is generated, the low level sp_instr instructions are optimized. The optimization focuses on two areas:

フロー解析が生成された後、低いレベルのsp_instrが最適化されます。この最適化は2つの項目に注力しています:

Dead code removal,
Jump shortcut resolution.
These two optimizations are performed together, as they both are a problem involving flow analysis in the graph that represents the generated code.

デッドコードの除去、ショートカットの解決
これら2つの最適化は、両方とも生成されたコードを表すグラフ内のフロー解析に関するものであるため、同時に行われます。

The code that implements these optimizations is sp_head::optimize().

これらの最適化を実装するコードは sp_head :: optimize() です。

しかしながら、これだけではなぜ“opening tables”が実行されているのか説明にはなっていません。この点はバグとして報告しました。

遅いファンクションが実際に違いを生む時

さて、もし100万件のストアドファンクションを実行でもしない限り、その違いに気づかないこともあるでしょう。しかしながら、どこで違いが発生するかというと…それはトリガーの内部です。あるテーブルにあるトリガーを設定していると仮定しましょう。それはテーブルに更新がかかるごとに別のカラムを更新します。例えば以下のようになります: "form"というテーブルがあり、作成日時のカラムを更新する必要がある場合

mysql> update form set form_created_date = NOW() where form_id > 5000;
Query OK, 65536 rows affected (0.31 sec)
Rows matched: 65536  Changed: 65536  Warnings: 0

この処理は速くて良いです。ここで、先ほどの func1() をコールするトリガーを作成します。

CREATE DEFINER=`root`@`localhost` TRIGGER `test`.`form_AFTER_UPDATE`
AFTER UPDATE ON `form`
FOR EACH ROW
BEGIN
    declare r int default 0;
    select func1() into r;
END

更新を繰り返してみましょう。トリガの中では実質的に何の処理も行われておらず、更新クエリの結果に変化はないという点に注意してください。

mysql> update form set form_created_date = NOW() where form_id > 5000;
Query OK, 65536 rows affected (0.90 sec)
Rows matched: 65536  Changed: 65536  Warnings: 0

ダミーとなるトリガーを追加しただけで2倍のオーバーヘッドが発生してしまいました。次にファンクションすら実行しないトリガーで試してみると、こちらも遅くなりました。

CREATE DEFINER=`root`@`localhost` TRIGGER `test`.`form_AFTER_UPDATE`
AFTER UPDATE ON `form`
FOR EACH ROW
BEGIN
    declare r int default 0;
END

mysql> update form set form_created_date = NOW() where form_id > 5000;
Query OK, 65536 rows affected (0.52 sec)
Rows matched: 65536  Changed: 65536  Warnings: 0

次に func3 を使ってみましょう("死んだ"コードを含んでいる以外 func1 と同等)。

CREATE DEFINER=`root`@`localhost` TRIGGER `test`.`form_AFTER_UPDATE`
AFTER UPDATE ON `form`
FOR EACH ROW
BEGIN
    declare r int default 0;
    select func3() into r;
END

mysql> update form set form_created_date = NOW() where form_id > 5000;
Query OK, 65536 rows affected (1.06 sec)
Rows matched: 65536  Changed: 65536  Warnings: 0

しかし、ファンクションをコールするのではなく、トリガ内で func3 のコードを実行すると、更新性能が上がります。

CREATE DEFINER=`root`@`localhost` TRIGGER `test`.`form_AFTER_UPDATE`
AFTER UPDATE ON `form`
FOR EACH ROW
BEGIN
    declare r int default 0;
    IF 1=2 THEN
        select levenshtein_limit_n('test finc', 'test func', 1) into r;
    END IF;
    IF 2=3 THEN
        select levenshtein_limit_n('test finc', 'test func', 10) into r;
    END IF;
    IF 3=4 THEN
        select levenshtein_limit_n('test finc', 'test func', 100) into r;
    END IF;
    IF 4=5 THEN
        select levenshtein_limit_n('test finc', 'test func', 1000) into r;
    END IF;
END

mysql> update form set form_created_date = NOW() where form_id > 5000;
Query OK, 65536 rows affected (0.66 sec)
Rows matched: 65536  Changed: 65536  Warnings: 0

メモリの割り当て

潜在的にコードが実行されることが決してない場合でも、MySQLは実行されるたびにストアドルーチンまたはトリガのコードを解析しなければならず、そのためメモリリークを引き起こす可能性があります。このことは、このバグレポートでも説明されています。

まとめ

ストアドルーチンおよびトリガイベントは、実行された時にパースされます。決して実行されない"死んだ"コードだとしても、バルク処理の性能に著しい影響を与えてしまうことがあります(e.g. トリガー内で実行した時)。また、“flag”を設定する(e.g if @trigger_disable = 0 then ...)ことでトリガーを無効にしたとしても、バルク処理性能への影響が残ることもあります。

次の記事
さようならPython、こんにちはGo
前の記事
MySQLがメモリー不足の時に何をするか : トラブルシューティングガイド

Feed small 記事フィード

新着記事Twitterアカウント