MySQLクエリプロファイリングの使用方法

getdocs

2年前

序章

MySQLクエリプロファイリングは、データベース駆動型アプリケーションの全体的なパフォーマンスを分析しようとするときに便利な手法です。中規模から大規模のアプリケーションを開発する場合、大規模なコードベース全体に数百のクエリが分散される傾向があり、1秒あたりにデータベースに対して多数のクエリが実行される可能性があります。ある種のクエリプロファイリング手法がないと、ボトルネックの場所と原因を特定することが非常に困難になり、アプリケーションの速度が低下します。この記事では、MySQLサーバーに組み込まれているツールを使用したいくつかの便利なクエリプロファイリング手法について説明します。

MySQLの低速クエリログとは何ですか？

MySQLの低速クエリログは、MySQLが低速で潜在的に問題のあるクエリを送信するログです。このロギング機能はMySQLに付属していますが、デフォルトではオフになっています。ログに記録されるクエリは、アプリケーションのパフォーマンス要件に基づいたクエリプロファイリングを可能にするカスタマイズ可能なサーバー変数によって決定されます。通常、ログに記録されるクエリは、実行に指定された時間がかかるクエリ、またはインデックスに適切にヒットしないクエリです。

プロファイリング変数の設定

MySQLの低速クエリログを設定するための主要なサーバー変数は次のとおりです。

slow_query_log			G 
slow_query_log_file			G 
long_query_time			G / S
log_queries_not_using_indexes	G
min_examined_row_limit		G / S

注：（G）グローバル変数、（S）セッション変数

slow_query_log-低速クエリログのオンとオフを切り替えるブール値。

slow_query_log_file-クエリログファイルの絶対パス。ファイルのディレクトリはmysqldユーザーが所有し、読み取りと書き込みを行うための適切な権限を持っている必要があります。 mysqlデーモンは`mysql`として実行されている可能性がありますが、確認するには、Linuxターミナルで次を実行します。

 ps -ef | grep bin/mysqld | cut -d' ' -f1

出力には、現在のユーザーとmysqldユーザーが表示される可能性があります。ディレクトリパス/var/ log / mysqlの設定例：

cd /var/log
mkdir mysql
chmod 755 mysql
chown mysql:mysql mysql

long_query_time -クエリの長さをチェックするための時間（秒単位）。値が5の場合、実行に5秒以上かかるクエリはすべてログに記録されます。

log_queries_not_using_indexes-インデックスにヒットしていないクエリをログに記録するかどうかのブール値。クエリ分析を行うときは、インデックスにヒットしていないクエリをログに記録することが重要です。

min_examined_row_limit-検査する行数の下限を設定します。 1000の値は、1000行未満を分析するクエリを無視します。

MySQLサーバー変数は、MySQL confファイルで設定するか、MySQLGUIまたはMySQLコマンドラインを介して動的に設定できます。変数がconfファイルに設定されている場合、それらはサーバーの再起動時に保持されますが、サーバーを再起動してアクティブにする必要もあります。 MySQLconfファイルは通常`/etcまたは/usr`、通常は`/etc/my.cnf`または`/etc/mysql/my.cnf`にあります。 confファイルを見つけるには（検索をより多くのルートディレクトリに広げる必要があるかもしれません）：

find /etc -name my.cnf
find /usr -name my.cnf

confファイルが見つかったら、[mysqld]見出しの下に目的の値を追加するだけです。

[mysqld]
….
slow-query-log = 1
slow-query-log-file = /var/log/mysql/localhost-slow.log
long_query_time = 1
log-queries-not-using-indexes

繰り返しになりますが、変更はサーバーの再起動後まで有効にならないため、変更がすぐに必要な場合は、変数を動的に設定します。

mysql> SET GLOBAL slow_query_log = 'ON';
mysql> SET GLOBAL slow_query_log_file = '/var/log/mysql/localhost-slow.log';
mysql> SET GLOBAL log_queries_not_using_indexes = 'ON';
mysql> SET SESSION long_query_time = 1;
mysql> SET SESSION min_examined_row_limit = 100;

変数値を確認するには：

mysql> SHOW GLOBAL VARIABLES LIKE 'slow_query_log';
mysql> SHOW SESSION VARIABLES LIKE 'long_query_time';

MySQL変数を動的に設定することの1つの欠点は、サーバーの再起動時に変数が失われることです。永続化する必要のある重要な変数をMySQLconfファイルに追加することをお勧めします。

注：SETを介して変数を動的に設定し、それらをconfファイルに配置するための構文は少し異なります。 `slow_query_log`対。 `slow-query-log`。さまざまな構文については、MySQLの動的システム変数ページを参照してください。 Option-File Formatはconfファイルの形式であり、SystemVariableNameは変数を動的に設定するための変数名です。

クエリプロファイルデータの生成

MySQLの低速クエリログ構成の概要が説明されたので、プロファイリング用のクエリデータを生成します。この例は、事前に低速ログ構成が設定されていない実行中のMySQLインスタンスで作成されました。この例のクエリは、MySQLGUIまたはMySQLコマンドプロンプトを介して実行できます。遅いクエリログを監視するときは、サーバーに対して2つの接続ウィンドウを開いておくと便利です。1つはMySQLステートメントを書き込むための接続で、もう1つはクエリログを監視するための接続です。

MySQLコンソールタブで、SUPERADMIN権限を持つユーザーでMySQLサーバーにログインします。まず、テストデータベースとテーブルを作成し、ダミーデータを追加して、低速のクエリログをオンにします。この例は、開発環境で実行する必要があります。理想的には、MySQLを使用する他のアプリケーションを使用せずに、監視中のクエリログが乱雑にならないようにします。

$> mysql -u  -p

mysql> CREATE DATABASE profile_sampling;
mysql> USE profile_sampling;
mysql> CREATE TABLE users ( id TINYINT PRIMARY KEY AUTO_INCREMENT, name VARCHAR(255) );
mysql> INSERT INTO users (name) VALUES ('Walter'),('Skyler'),('Jesse'),('Hank'),('Walter Jr.'),('Marie'),('Saul'),('Gustavo'),('Hector'),('Mike');

mysql> SET GLOBAL slow_query_log = 1;
mysql> SET GLOBAL slow_query_log_file = '/var/log/mysql/localhost-slow.log';
mysql> SET GLOBAL log_queries_not_using_indexes = 1;
mysql> SET long_query_time = 10;
mysql> SET min_examined_row_limit = 0;

これで、少量のテストデータを含むテストデータベースとテーブルができました。低速クエリログはオンになりましたが、クエリ時間は意図的に高く設定され、最小行検査フラグはオフのままになりました。ログを表示するためのコンソールタブ：

cd /var/log/mysql
ls -l

クエリが実行されていないため、フォルダに遅いクエリログはまだありません。ある場合は、過去に低速クエリログがオンになって構成されていることを意味します。これにより、この例の結果の一部が歪む可能性があります。 [MySQL]タブに戻り、次のSQLを実行します。

mysql> USE profile_sampling;
mysql> SELECT * FROM users WHERE id = 1;

実行されたクエリは、テーブルの主キーインデックスを使用した単純な選択でした。このクエリは高速でインデックスを使用していたため、このクエリの低速クエリログにはエントリがありません。クエリログディレクトリを振り返り、ログが作成されていないことを確認します。ここで、MySQLウィンドウに戻って実行します。

mysql> SELECT * FROM users WHERE name = 'Jesse';

このクエリは、インデックス付けされていない列–nameで実行されました。この時点で、次の情報を含むクエリがログに記録されます（完全に同じではない場合があります）。

/var/log/mysql/localhost-slow.log

# Time: 140322 13:54:58
# User@Host: root[root] @ localhost []
# Query_time: 0.000303  Lock_time: 0.000090 Rows_sent: 1  Rows_examined: 10
use profile_sampling;
SET timestamp=1395521698;
SELECT * FROM users WHERE name = 'Jesse';

クエリは正常にログに記録されました。もう1つの例。調べた行の最小制限を引き上げて、同様のクエリを実行します。

mysql> SET min_examined_row_limit = 100;
mysql> SELECT * FROM users WHERE name = 'Walter';

最小100行が分析されなかったため、データはログに追加されません。

注：ログにデータが入力されていない場合、確認できることがいくつかあります。まず、ログが作成されているディレクトリの権限。所有者/グループはmysqldユーザー（たとえば上記を参照）と同じである必要があり、正しい権限を持っている必要があります。確かにchmod755です。第二に、例を妨害している既存の遅いクエリ変数構成があった可能性があります。 confファイルから低速のクエリ変数を削除してサーバーを再起動することでデフォルトをリセットするか、グローバル変数を動的にデフォルト値に戻します。変更が動的に行われる場合は、ログアウトしてMySQLに再度ログインし、グローバル更新が有効になるようにします。

クエリプロファイル情報の分析

上記の例のクエリプロファイルデータを見てください。

# Time: 140322 13:54:58
# User@Host: root[root] @ localhost []
# Query_time: 0.000303  Lock_time: 0.000090 Rows_sent: 1  Rows_examined: 10
use profile_sampling;
SET timestamp=1395521698;
SELECT * FROM users WHERE name = 'Jesse';

エントリは次のように表示されます。

クエリが実行された時刻
誰がそれを実行したか
クエリにかかった時間
ロックの長さ
返された行数
調べた行数

サーバー変数で指定されたパフォーマンス要件に違反するクエリはログに記録されるため、これは便利です。これにより、開発者または管理者は、クエリが実行されていないときにMySQLにアラートを送信させることができます。また、クエリプロファイリングデータは、一定期間にわたってプロファイリングされる場合に役立ちます。これは、どのような状況がアプリケーションのパフォーマンスの低下に寄与しているかを判断するのに役立ちます。

mysqldumpslowの使用

より現実的な例では、データベース駆動型アプリケーションでプロファイリングが有効になり、プロファイリングの対象となる適度なデータストリームが提供されます。ログは継続的に書き込まれ、おそらく誰もが見ているよりも頻繁に書き込まれます。ログのサイズが大きくなると、すべてのデータを解析することが難しくなり、問題のあるクエリがログで簡単に失われます。 MySQLは、遅いクエリログを分解することでこの問題を回避するのに役立つ別のツールmysqldumpslowを提供しています。バイナリはMySQL（Linux上）にバンドルされているため、それを使用するには、コマンドを実行してログパスを渡すだけです。

mysqldumpslow -t 5 -s at /var/log/mysql/localhost-slow.log

コマンドで使用して出力をカスタマイズするのに役立つさまざまなパラメーターがあります。上記の例では、平均クエリ時間でソートされた上位5つのクエリが表示されます。結果の行は、クエリごとにグループ化されるだけでなく、より読みやすくなります（この出力は、高い値を示す例とは異なります）。

Count: 2  Time=68.34s (136s)  Lock=0.00s (0s)  Rows=39892974.5 (79785949), root[root]@localhost
  SELECT PL.pl_title, P.page_title
  FROM page P
  INNER JOIN pagelinks PL
  ON PL.pl_namespace = P.page_namespace
  WHERE P.page_namespace = N
…

表示されているデータ：

カウント-クエリがログに記録された回数
時間-（）の平均時間と合計時間の両方
ロック-テーブルのロック時間
行-返された行の数

このコマンドは数値と文字列を抽象化するため、WHERE句が異なる同じクエリは同じクエリとしてカウントされます（page_namespace = Nに注意してください）。 mysqldumpslowのようなツールを使用すると、遅いクエリログを常に監視する必要がなくなり、代わりに定期的または自動化されたチェックが可能になります。 mysqldumpslowコマンドのパラメーターにより、ログ内のさまざまなクエリにドリルダウンするのに役立つ複雑な式のマッチングが可能になります。

さまざまなデータビューを提供するサードパーティのログ分析ツールも利用できます。人気のあるツールはpt-query-digestです。

クエリの内訳

知っておくべき最後のプロファイリングツールは、クエリの複雑な内訳を可能にするツールです。このツールの良い使用例は、遅いクエリログから問題のあるクエリを取得し、それをMySQLで直接実行することです。最初にプロファイリングをオンにする必要があり、次にクエリが実行されます。

mysql> SET SESSION profiling = 1;
mysql> USE profile_sampling;
mysql> SELECT * FROM users WHERE name = 'Jesse';
mysql> SHOW PROFILES;

プロファイリングをオンにすると、SHOWPROFILESにQuery_IDをSQLステートメントにリンクするテーブルが表示されます。実行されたクエリに対応するQuery_IDを見つけて、次のクエリを実行します（＃をQuery_IDに置き換えます）。

mysql> SELECT * FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID=#;

サンプル出力：

シーケンス	州	間隔
1	起動	0.000046
2	権限の確認	0.000005
3	テーブルを開く	0.000036
…	…	…

STATEはクエリを実行するプロセスの「ステップ」であり、DURATIONはそのステップが完了するまでにかかった時間（秒単位）です。これはあまり便利なツールではありませんが、興味深いものであり、クエリ実行のどの部分が最も遅延を引き起こしているのかを判断するのに役立ちます。

さまざまな列の詳細な概要については、 http://dev.mysql.com/doc/refman/5.5/en/profiling-table.html

さまざまな「ステップ」の詳細な概要については、 http://dev.mysql.com/doc/refman/5.5/en/general-thread-states.html

注：このツールは、特定のクエリを分析するためではなく、実稼働環境で使用しないでください。

クエリログのパフォーマンスが遅い

対処すべき最後の質問は、遅いクエリログがパフォーマンスにどのように影響するかです。一般に、本番環境で低速のクエリログを実行するのは安全です。 CPUもI/O負荷も問題にはなりません¹ ²。ただし、ログファイルサイズがファイルシステムに対して大きくなりすぎないように、ログサイズを監視するための戦略が必要です。また、実稼働環境で低速クエリログを実行する場合の経験則として、long_query_timeを1秒以上のままにしておくことをお勧めします。

重要：プロファイリングツールSET profiling = 1を使用したり、すべてのクエリをログに記録したりすることはお勧めできません。実稼働環境での高ワークロード環境でのgeneral_log変数。

結論

遅いクエリログは、問題のあるクエリを特定し、全体的なクエリパフォーマンスをプロファイリングするのに非常に役立ちます。遅いクエリログを使用してクエリプロファイリングを行うと、開発者はアプリケーションのMySQLクエリがどのように実行されているかを深く理解できます。 mysqldumpslowなどのツールを使用すると、低速のクエリログの監視と評価が管理しやすくなり、開発プロセスに簡単に組み込むことができます。問題のあるクエリが特定されたので、次のステップは、最大のパフォーマンスが得られるようにクエリを調整することです。

投稿者： Jesse Cascio