今日はなにの日。

気になったこと勉強になったことのメモ。

トップ > MySQL > 今日は、MySQLのクエリプロファイリングについて調べてみたの日。

今日は、MySQLのクエリプロファイリングについて調べてみたの日。

MySQL データベース

目次

とある日

ずっと積んでいる実践ハイパフォーマンスMySQLを読んでいて、SHOW PROFILE ステートメントを使ったクエリプロファイリングの方法が記述されていて、そんなのがあるんだって思って調べてみたら今は非推奨らしくPerformance Schemaを使った方法があって気になったので使ってみた内容です。

注記

SHOW PROFILE および SHOW PROFILES ステートメントは非推奨になりました。将来の MySQL リリースで削除される予定です。 かわりに Performance Schema を使用します。セクション27.19.1「パフォーマンススキーマを使用したクエリープロファイリング」 を参照してください。

MySQL :: MySQL 8.0 リファレンスマニュアル :: 13.7.7.30 SHOW PROFILE ステートメント

実践ハイパフォーマンスMySQL 第3版

実践ハイパフォーマンスMySQL 第3版

Amazon

クエリをプロファイリングするとは？

色々と調べて考えましたがこれといった解答を提示することができないので情報となりそうなリンクとか記述を引用しておきます。

一応自分の見解としては、パフォーマンスボトルネックの調査とかをする際に使うイメージでした。

クエリが遅いときにチューニングをすると思うのですが、プロファイリングはクエリの外側の要因に対してのアプローチをする際に使用する感じだと思いました。

MySQLを運用していくうえで，スロークエリを見つけてしまった場合等に，そのクエリはどういった処理が遅いのだろうかと疑問に思ったことはあるのではないでしょうか。

第130回　クエリをプロファイリングしてみる：MySQL道普請便り｜gihyo.jp … 技術評論社

パフォーマンススキーマは、DBA が「大まかな推量」ではなく、実際に測定して、パフォーマンスのチューニングを行うのに役立つツールです。 このセクションでは、この目的でパフォーマンススキーマを使用するいくつかの方法について説明します。 ここでの説明は、セクション27.4.2「パフォーマンススキーマイベントフィルタリング」で説明しているイベントフィルタリングの使用に依存します。

MySQL :: MySQL 8.0 リファレンスマニュアル :: 27.19 問題を診断するためのパフォーマンススキーマの使用

パフォーマンススキーマを使用したクエリープロファイリング

次の例は、パフォーマンススキーマのステートメントイベントとステージイベントを使用して、SHOW PROFILES および SHOW PROFILE ステートメントによって提供されるプロファイリング情報と同等のデータを取得する方法を示しています。

プロファイリング手順

ざっくりと下記の手順でプロファイリングの下準備から収集確認まで行います。

  1. 履歴イベントの収集
  2. ステートメントおよびステージインストゥルメンテーションを有効
  3. コンシューマを有効
  4. 監視しているユーザー プロファイリングするステートメントを実行
  5. events_statements_history_long テーブル EVENT_ID を識別
  6. events_stages_history_long テーブル ステートメントステージイベントを取得

検証環境は下記です。

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

履歴イベントの収集

履歴イベントの収集を、クエリーを実行するユーザーに制限します。 デフォルトでは、setup_actors は、すべてのフォアグラウンドスレッドのモニタリングおよび履歴イベント収集を許可するように構成されています

setup_actors テーブルのデフォルト行を更新して、すべてのフォアグラウンドスレッドの履歴イベント収集および監視を無効にし、クエリーを実行するユーザーの監視および履歴イベント収集を有効にする新しい行を挿入します:

どのユーザのクエリも収集しているとサーバが重くなったりそれ自体がボトルネックになるため最小限にユーザのイベントだけに留めるために行う。

mysql>  SELECT * FROM performance_schema.setup_actors;
+------+------+------+---------+---------+
| HOST | USER | ROLE | ENABLED | HISTORY |
+------+------+------+---------+---------+
| %    | %    | %    | YES     | YES     |
+------+------+------+---------+---------+
1 row in set (0.01 sec)

mysql>  INSERT INTO performance_schema.setup_actors
    ->        (HOST,USER,ROLE,ENABLED,HISTORY)
    ->        VALUES('localhost','docker','%','YES','YES');
Query OK, 1 row affected (0.00 sec)

mysql>  SELECT * FROM performance_schema.setup_actors;
+-----------+--------+------+---------+---------+
| HOST      | USER   | ROLE | ENABLED | HISTORY |
+-----------+--------+------+---------+---------+
| %         | %      | %    | YES     | YES     |
| localhost | docker | %    | YES     | YES     |
+-----------+--------+------+---------+---------+
2 rows in set (0.00 sec)

docker-composeで構築していてdockerユーザが存在するので今回はdockerの起こすイベントを収集する設定にしています。

MySQL :: MySQL 8.0 リファレンスマニュアル :: 27.12.2.1 setup_actors テーブル

setup_actors テーブルには、新しいフォアグラウンドサーバースレッド (クライアント接続に関連付けられたスレッド) の監視および履歴イベントロギングを有効にするかどうかを決定する情報が含まれます。

単純に誰に対する監視を有効を行うテーブルです。

ステートメントおよびステージインストゥルメンテーションを有効

setup_instruments テーブルを更新して、ステートメントおよびステージインストゥルメンテーションが有効になっていることを確認します。 一部のインストゥルメントは、デフォルトですでに有効になっている場合があります。

ステートメントおよびステージインストゥルメンテーション デフォルト設定確認

一部デフォルトですでに有効になっている場合があるらしいので見てみます。

アップデートするSQLのwhere句を反転しているだけです。

mysql> select count(*) from performance_schema.setup_instruments WHERE NAME LIKE '%statement/%' and enabled != 'YES' and timed != 'YES' ;
+----------+
| count(*) |
+----------+
|        0 |
+----------+
1 row in set (0.00 sec)

mysql> select count(*) from performance_schema.setup_instruments WHERE NAME LIKE '%stage/%' and enabled != 'YES' and timed != 'YES' ;
+----------+
| count(*) |
+----------+
|      115 |
+----------+
1 row in set (0.00 sec)

performance_schema.setup_instruments を更新する

mysql>  UPDATE performance_schema.setup_instruments
    ->        SET ENABLED = 'YES', TIMED = 'YES'
    ->        WHERE NAME LIKE '%statement/%';
Query OK, 0 rows affected (0.00 sec)
Rows matched: 213  Changed: 0  Warnings: 0

mysql> UPDATE performance_schema.setup_instruments
    ->        SET ENABLED = 'YES', TIMED = 'YES'
    ->        WHERE NAME LIKE '%stage/%';
Query OK, 115 rows affected (0.01 sec)
Rows matched: 131  Changed: 115  Warnings: 0

MySQL :: MySQL 8.0 リファレンスマニュアル :: 27.12.2.3 setup_instruments テーブル

setup_instruments テーブルは、イベントを収集できるインストゥルメントされたオブジェクトのクラスを一覧表示します。

コンシューマを有効

events_statements_* および events_stages_* コンシューマが有効になっていることを確認します。 一部のコンシューマは、デフォルトですでに有効になっている場合があります。

events_statements*およびevents_stages* デフォルト設定確認

こちらも気になるので調べてみます。

Updateを行う必要はなさそうですが一応実行します。

mysql> select count(*) from performance_schema.setup_instruments WHERE NAME LIKE '%events_statements_%' and enabled != 'YES';
+----------+
| count(*) |
+----------+
|        0 |
+----------+
1 row in set (0.00 sec)

mysql> select count(*) from performance_schema.setup_instruments WHERE NAME LIKE '%events_stages_/%' and enabled != 'YES';
+----------+
| count(*) |
+----------+
|        0 |
+----------+
1 row in set (0.00 sec)

performance_schema.setup_consumersを更新する

mysql> UPDATE performance_schema.setup_consumers
    ->        SET ENABLED = 'YES'
    ->        WHERE NAME LIKE '%events_statements_%';
Query OK, 1 row affected (0.00 sec)
Rows matched: 3  Changed: 1  Warnings: 0

mysql> UPDATE performance_schema.setup_consumers
    ->        SET ENABLED = 'YES'
    ->        WHERE NAME LIKE '%events_stages_%';
Query OK, 3 rows affected (0.00 sec)
Rows matched: 3  Changed: 3  Warnings: 0

監視しているユーザー プロファイリングするステートメントを実行

  1. 監視しているユーザーアカウントで、プロファイリングするステートメントを実行します。 例:

    mysql> SELECT * FROM employees.employees WHERE emp_no = 10001;
+--------+------------+------------+-----------+--------+------------+
| emp_no | birth_date | first_name | last_name | gender | hire_date |
+--------+------------+------------+-----------+--------+------------+
|  10001 | 1953-09-02 | Georgi     | Facello   | M      | 1986-06-26 |
+--------+------------+------------+-----------+--------+------------+

これは適当なテーブルに対して行っているので以前使用しているMySQL公式サンプルworld_xデータベースを使って行います。

world_xデータベースの構築は割愛します。

ユーザ切り替え

root@be8f4f678878:/# mysql -udocker -pdocker
mysql: [Warning] Using a password on the command line interface can be insecure.
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 16
Server version: 8.0.27 MySQL Community Server - GPL

Copyright (c) 2000, 2021, 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> use world_x
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

SELECT文発行

mysql> SELECT * FROM city where city.ID = 1001;
+------+-------+-------------+------------+------------------------+
| ID   | Name  | CountryCode | District   | Info                   |
+------+-------+-------------+------------+------------------------+
| 1001 | Depok | IDN         | Yogyakarta | {"Population": 106800} |
+------+-------+-------------+------------+------------------------+
1 row in set (0.01 sec)

events_statements_history_long テーブル EVENT_ID を識別

events_statements_history_long テーブルをクエリーして、ステートメントの EVENT_ID を識別します。 このステップは、Query_ID を識別するための SHOW PROFILES の実行に似ています。 次のクエリーでは、SHOW PROFILES のような出力が生成されます:

発行されたイベントの履歴から対象とするクエリを探します。

mysql> SELECT EVENT_ID, TRUNCATE(TIMER_WAIT/1000000000000,6) as Duration, SQL_TEXT        FROM performance_schema.events_statements_history_long WHERE SQL_TEXT like '%1001%' limit 1 \G;
*************************** 1. row ***************************
EVENT_ID: 93
Duration: 0.0010
SQL_TEXT: SELECT * FROM city where city.ID = 1001
1 row in set (0.00 sec)

このEVENT_ID: 93を使ってプロファイリングの内容を確認します。

MySQL :: MySQL 8.0 リファレンスマニュアル :: 27.12.6.3 events_statements_history_long テーブル

events_statements_history_long テーブルには、すべてのスレッドでグローバルに終了した N の最新のステートメントイベントが含まれます。 ステートメントイベントは終了するまでテーブルに追加されません。 テーブルがいっぱいになると、どちらのスレッドがどちらの行を生成したかに関係なく、新しい行が追加されたときにもっとも古い行が破棄されます。

events_stages_history_long テーブル ステートメントステージイベントを取得

events_stages_history_long テーブルをクエリーして、ステートメントステージイベントを取得します。 ステージは、イベントネストを使用してステートメントにリンクされます。 各ステージイベントレコードには、親ステートメントの EVENT_ID を含む NESTING_EVENT_ID カラムがあります。

mysql> SELECT event_name AS Stage, TRUNCATE(TIMER_WAIT/1000000000000,6) AS Duration        FROM performance_schema.events_stages_history_long WHERE NESTING_EVENT_ID=93\G;
*************************** 1. row ***************************
   Stage: stage/sql/starting
Duration: 0.0000
*************************** 2. row ***************************
   Stage: stage/sql/Executing hook on transaction begin.
Duration: 0.0000
*************************** 3. row ***************************
   Stage: stage/sql/starting
Duration: 0.0000
*************************** 4. row ***************************
   Stage: stage/sql/checking permissions
Duration: 0.0000
*************************** 5. row ***************************
   Stage: stage/sql/Opening tables
Duration: 0.0000
*************************** 6. row ***************************
   Stage: stage/sql/init
Duration: 0.0000
*************************** 7. row ***************************
   Stage: stage/sql/System lock
Duration: 0.0000
*************************** 8. row ***************************
   Stage: stage/sql/optimizing
Duration: 0.0000
*************************** 9. row ***************************
   Stage: stage/sql/statistics
Duration: 0.0008
*************************** 10. row ***************************
   Stage: stage/sql/preparing
Duration: 0.0000
*************************** 11. row ***************************
   Stage: stage/sql/executing
Duration: 0.0000
*************************** 12. row ***************************
   Stage: stage/sql/end
Duration: 0.0000
*************************** 13. row ***************************
   Stage: stage/sql/query end
Duration: 0.0000
*************************** 14. row ***************************
   Stage: stage/sql/waiting for handler commit
Duration: 0.0000
*************************** 15. row ***************************
   Stage: stage/sql/closing tables
Duration: 0.0000
*************************** 16. row ***************************
   Stage: stage/sql/freeing items
Duration: 0.0000
*************************** 17. row ***************************
   Stage: stage/sql/cleaning up
Duration: 0.0000
17 rows in set (0.00 sec)

クエリを発行してからの一覧が取得できます。

これによってどこにどのぐらい時間がかかっているかが把握できます。

今回の場合だとときに問題のあるクエリではないためほとんど時間がかかってないです。

ちなみに、実践ハイパフォーマンスでも記述がありましたが、このプロファイリングだけではクエリ内部のことはあまり教えてくれません。

なのでSHOW STATUSとかも使って調べる必要があるそうです。

〆

今年中に実践ハイパフォーマンスを読み終わりたい。

内容としてはかなり深くまで解説しているので読んでいて面白いしためになりますね。

ただ、かなり量があるので苦戦してます。