スロー クエリ ログの内容は、long_query_time 秒より実行に時間がかかる
SQL ステートメントすべてが入ります。最初のテーブル ロックを取得するまでの時間は、
実行時間としてはカウントしていません。すべてのステートメントを実行し、
すべてのロックをリリースした後に、mysqld で、ステートメントをスロー クエリ ログ
として書き込むため、ログ順は実行順とは異なることがあります。最低限値は 1 で、
long_query_time のデフォルト値 (最大値) は 10です。

MySQL 5.1.6 以降、スロー クエリ ログを有効化するには、
mysqld を –log-slow-queries[=file_name]
オプションで起動します。必要に応じて、–log-output オプションを使用して、
ログの出力先を指定します。
MySQL 5.1.6 より前は、スロー クエリ ログの出力先はファイルです。
スロー クエリ ログ ファイルを有効化するには、–log-slow-queries[=file_name]
オプションを使用します。

スロー クエリ ログには、実行に時間がかかるクエリが入るため、最適化の対象になります。
しかし、時間がかかるスロー クエリ ログの検査は手間がかかります。
ここで、mysqldumpslowコマンドを使用してスロー クエリ ログを処理することで、
そのクエリをログに概括表示します。mysqldumpslow –help を使用して、
このコマンドに関するサポートを探してください。

MySQL 5.1 では、インデックスを使用しないクエリは、–log-queries-not-using-indexes
オプションで指定すると、スロー クエリ ログで記録するようになります。
MySQL 5.1 では、スロー クエリ ログに対して、–log-slow-admin-statements というサーバ
オプションで、OPTIMIZE TABLE、ANALYZE TABLE、ALTER TABLE など、時間がかかる管理ステートメントのロギング要求を有効化します。

クエリ キャッシュで扱うクエリは、スロー クエリ ログには付加しません。
テーブルのレコードがない、または 1 つだけであるときは、インデックスで管理する必要がないため、
これもスロー クエリ ログには入りません。

SlowログをCATコマンドで確認した場合

[root@colinux data]# cat mysql-slow.log
/usr/local/mysql/bin/mysqld, Version: 5.1.30-log (MySQL Community Server (GPL)).
 started with:
Tcp port: 3306  Unix socket: /tmp/mysql.sock
Time                 Id Command    Argument
[root@colinux data]# 

mysqldumpslowでSlowログを確認した場合

[root@colinux data]# mysqldumpslow  mysql-slow.log

Reading mysql slow query log from mysql-slow.log
Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), 0users@0hosts

[root@colinux data]#

MySQL Server 5.0 管理監視ガイド

4.11.5. スロー クエリ ログ

mysqldumpslow

[root@colinux data]# mysqldumpslow --help
Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]
<code>
Parse and summarize the MySQL slow query log. Options are

  --verbose    verbose
  --debug      debug
  --help       write this text to standard output

  -v           verbose
  -d           debug
  -s ORDER     what to sort by (t, at, l, al, r, ar etc), 'at' is default
  -r           reverse the sort order (largest last instead of first)
  -t NUM       just show the top n queries
  -a           don't abstract all numbers to N and strings to 'S'
  -n NUM       abstract numbers with at least n digits within names
  -g PATTERN   grep: only consider stmts that include this string
  -h HOSTNAME  hostname of db server for *-slow.log filename (can be wildcard),
               default is '*', i.e. match all
  -i NAME      name of server instance (if using mysql.server startup script)
  -l           don't subtract lock time from total time
</code>
[root@colinux data]# 

mysqldumpslowは、スロークエリーログ内における、条件値が異なるだけの
SQL文をまとめて、各SQL文をまとめて、各SQL文の平均実行時間の長い順番に
並び替えて表示してくれる。

mysql_slow

その他以下のように一定時間より長いQueryのみをフィルター抽出出来る。
mysql_slow_log_filter.pl

===========================================================
"tail -f mysql-slow.log | mysql_slow_log_filter -T 0.5 -R 1000"
===========================================================
Filtering Slow Query Log – Especially after the changes to log all
queries slow query log may be growing too rapidly to follow,
so we implemented slow query log filter (based on parse_mysql_slow_log by Nathanial Hendler)
which allows you to filter out only queries which took more than certain amount
of time or examined more than certain amount of rows. This is great as allows
multiple passes across same slow query log first to fix worse queries and then
come to find more optimization candidates.
So “tail -f mysql-slow.log | mysql_slow_log_filter -T 0.5 -R 1000” will look at queries
as they come and will print out queries taking more than 0.5 seconds to execute or
having more than 1000 rows examined.
===========================================================


[root@HOME001 data]# ./slolog.pl -T 0.05 < home001-mysql-slow.log Starting... # Query_time: 0.461031 Lock_time: 0.000137 Rows_sent: 0 Rows_examined: 39 SET timestamp=1359610099; update test.TABLE001 set comment = 'test percona-toolkit-2.1.8'; # Time: 130131 14:28:25 # User@Host: root[root] @ localhost [] # Query_time: 0.433720 Lock_time: 0.000131 Rows_sent: 0 Rows_examined: 1 SET timestamp=1359610148; delete from test.TABLE001 where id = 39; # Time: 130131 14:29:12 # User@Host: root[root] @ localhost [] [root@HOME001 data]# [/SQL]

Comments are closed.

Post Navigation