MySQL道普請便り
第130回 クエリをプロファイリングしてみる
MySQLを運用していくうえで,
MySQLには,
今回は,
SHOW PROFILE構文
SHOW PROFILE構文は,SET profiling = 1
でプロファイルを有効にする必要があります。有効かどうか確認するにはSELECT @@profiling
,SHOW VARIABLES
で確認することができます。
mysql> SHOW VARIABLES like 'profil'; +------------------------+-------+ | Variable_name | Value | +------------------------+-------+ | profiling | ON | | profiling_history_size | 15 | +------------------------+-------+ 2 rows in set (0.00 sec)
profiling_
は,SHOW PROFILES
を実行するとQuery_
mysql> show profiles; +----------+------------+----------------------------------+ | Query_ID | Duration | Query | +----------+------------+----------------------------------+ | 1 | 0.00019425 | select @@version_comment limit 1 | | 2 | 0.00015375 | SELECT DATABASE() | | 3 | 0.00015900 | SET profiling = 1 | | 4 | 0.00005975 | show warnings | | 5 | 0.00537800 | SELECT count(1) FROM t1 | +----------+------------+----------------------------------+ 5 rows in set, 1 warning (0.00 sec)
SHOW PROFILE FOR QUERY <Query_
を実行すると,FOR QUERY
を使わずに実行した場合は,
mysql> SHOW PROFILE; +--------------------------------+----------+ | Status | Duration | +--------------------------------+----------+ | starting | 0.000163 | | Executing hook on transaction | 0.000011 | | starting | 0.000023 | | checking permissions | 0.000011 | | Opening tables | 0.000169 | | init | 0.000010 | | System lock | 0.000016 | | optimizing | 0.000005 | | optimizing | 0.000004 | | statistics | 0.000059 | | preparing | 0.000044 | | Creating tmp table | 0.000051 | (以下省略)
デフォルトではStatusとDurationが表示されますが,
option | 説明 |
---|---|
ALL | 全情報を表示 |
BLOCK IO | BLOCK I/ |
CONTEXT SWITCHES | コンテキストスイッチの回数 |
CPU | CPU時間 |
IPC | メッセージの送受信 |
PAGE FAULTS | ページフォルト回数 |
SOURCE | ソースコードのファイル名と関数名, |
SWAPS | スワップの回数 |
mysql> SHOW PROFILE SOURCE; +--------------------------------+----------+---------------------------+----------------------+-------------+ | Status | Duration | Source_function | Source_file | Source_line | +--------------------------------+----------+---------------------------+----------------------+-------------+ | starting | 0.000092 | NULL | NULL | NULL | | Executing hook on transaction | 0.000008 | launch_hook_trans_begin | rpl_handler.cc | 1122 | | starting | 0.000015 | launch_hook_trans_begin | rpl_handler.cc | 1124 | | checking permissions | 0.000008 | check_access | sql_authorization.cc | 2207 | | Opening tables | 0.000083 | open_tables | sql_base.cc | 5605 | | init | 0.000009 | execute | sql_select.cc | 684 | | System lock | 0.000011 | mysql_lock_tables | lock.cc | 329 | | optimizing | 0.000008 | optimize | sql_optimizer.cc | 282 | | optimizing | 0.000007 | optimize | sql_optimizer.cc | 282 | | statistics | 0.000024 | optimize | sql_optimizer.cc | 504 | | preparing | 0.000017 | optimize | sql_optimizer.cc | 588 | | Creating tmp table | 0.000054 | create_intermediate_table | sql_executor.cc | 198 | (以下省略)
同様の情報はInformation Schemaのprofiling
テーブルからも取得することが可能です。通常SHOW PROFILE構文ではorder byを使った並び替えはできませんが,profiling
テーブルを参照すると良いかと思います。
ここでSHOW PROFILEを利用する際にはいくつか注意が必要です。公式ドキュメントにもある通り,
Warning (Code 1287): 'SHOW PROFILE' is deprecated and will be removed in a future release. Please use Performance Schema instead
Performance Schemaを利用した計測
続いて,
ただし,
Performance Schemaを利用して計測するには,
mysql> UPDATE performance_schema.setup_instruments SET ENABLED = 'YES', TIMED = 'YES' WHERE NAME LIKE '%statement/%'; mysql> UPDATE performance_schema.setup_instruments SET ENABLED = 'YES', TIMED = 'YES' WHERE NAME LIKE '%stage/%'; mysql> UPDATE performance_schema.setup_consumers SET ENABLED = 'YES' WHERE NAME LIKE '%events_statements_%'; mysql> UPDATE performance_schema.setup_consumers SET ENABLED = 'YES' WHERE NAME LIKE '%events_stages_%';
このクエリを実行すると,events_
テーブルにevent_
event_events_
テーブルのnesting_
公式ドキュメントにも説明がある通り,
mysql> SELECT event_name, source, truncate(timer_wait/1000000000000, 6) as duration FROM performance_schema.events_stages_history_long where NESTING_EVENT_ID = 74; +------------------------------------------------+----------------------------------+----------+ | event_name | source | duration | +------------------------------------------------+----------------------------------+----------+ | stage/sql/starting | init_net_server_extension.cc:101 | 0.000257 | | stage/sql/Executing hook on transaction begin. | rpl_handler.cc:1122 | 0.000011 | | stage/sql/starting | rpl_handler.cc:1124 | 0.000030 | | stage/sql/checking permissions | sql_authorization.cc:2207 | 0.000011 | | stage/sql/Opening tables | sql_base.cc:5605 | 0.000246 | | stage/sql/init | sql_select.cc:684 | 0.000025 | | stage/sql/System lock | lock.cc:329 | 0.000026 | | stage/sql/optimizing | sql_optimizer.cc:282 | 0.000009 | | stage/sql/optimizing | sql_optimizer.cc:282 | 0.000004 | | stage/sql/statistics | sql_optimizer.cc:504 | 0.000061 | | stage/sql/preparing | sql_optimizer.cc:588 | 0.000022 | | stage/sql/Creating tmp table | sql_executor.cc:198 | 0.000061 | (以下省略)
まとめ
今回は,
バックナンバー
MySQL道普請便り
- 第141回 LIMIT句の利用について
- 第140回 オンラインスキーママイグレーションツール gh-ostを使ってみよう[その3]
- 第139回 オンラインスキーママイグレーションツール gh-ostを使ってみよう[その2]
- 第138回 オンラインスキーママイグレーションツール gh-ostを使ってみよう[その1]
- 第137回 MySQLTunerを使ってチューニングの足がかりを見つけてみる
- 第136回 CHECK制約を利用してみよう
- 第135回 MySQL 8.0で追加されたoptimizer_switchのフラグについて
- 第134回 DDLと暗黙的なコミットについて
- 第133回 Partial Revokesによる権限の一部剥奪について
- 第132回 Internal Temporary Table(内部テンポラリテーブル)について[その2]
関連記事
- 第46回 MySQL Cluster 8.0.16 DMRリリースと開発者来日セミナー開催,PostgreSQLエンタープライズ・コンソーシアムが検証成果を公開
- 第45回 OSSコンソーシアム 第3回データベース比較セミナー開催,MySQL 8.0.16でのCHECK制約追加,PostgreSQL関連ニュース
- 第42回 MySQL 8.0.14リリース,PostgreSQL商用ツールのPostgreSQL 11対応
- 第40回 「MySQL Innovation Day 2018 秋」「PostgreSQL Conference Japan 2018」開催
- 第38回 LOCONDO.jpやLINEでのMySQL最新導入事例,PostgreSQL 11ベータ4リリース,Cassandra(イベント情報のみ)