MySQL慢查詢日志(二)

慢查詢日志用來優化Query語句，以下是有關的幾個參數，5.5版本以後可以到微秒（μs）新版本中還有long_query_io(讀取次數) log_queries_not_using_indexes(沒有使用索引的SQL) log_throttle_not_using_indexes(控制每分鐘不實用索引SQL記錄的次數)

mysql> show variables like '%slow%';

| slow_query_log            | ON    #最好在配置檔案不要開啟 用的時候再打開開關

| slow_query_log_file       | /opt/mysql/data/hack-slow.log | #指定慢查詢日志檔案

+---------------------------+-------------------------------+

mysql> show variables like '%long%';

| long_query_time          | 0.050000 | #這裡看到時間為秒

mysql> 通過tail（沒有規律）或者mysqldumslow檢視慢查詢日志（常用）

[root@hack data]# mysqldumpslow --help 常用的解釋一下

Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]

  -s ORDER  （可以根據查詢時間、行數、鎖定時間，總數及他們的平均值）   

what to sort by (al, at, ar, c, l, r, t), 'at' is default 

                al: average lock time

                ar: average rows sent

                at: average query time

                 c: count

                 l: lock time

                 r: rows sent

                 t: query time  

  -r （倒序）          reverse the sort order (largest last instead of first)

  -t NUM  （指定傳回的條數）     just show the top n queries

  -g PATTERN（用來過濾）   grep: only consider stmts that include this string

  eg：查詢最慢執行時間最慢的10條？？？？？？？？

針對mysqldumpslow的輸出做個說明

[root@hack data]# mysqldumpslow hack-slow.log 這個是我的輸出

Reading mysql slow query log from hack-slow.log

Count: 5  Time=0.01s (0s)  Lock=0.00s (0s)  Rows=128.8 (644), root[root]@localhost

  select * from ssq where s2 =N limit N

[root@hack data]# 

下面進行說明：

Count 是我執行了五次這樣的query，

 select * from ssq where s2 =2 limit 123

 select * from ssq where s2 =4 limit 123

 認為是這種類型：select * from ssq where s2 =N limit N是以認為是一樣的

Time 執行這類query的時候的平均時間（0）s Lock Rows 同樣如此

[root@hack data]# mysqldumpslow -s r -t 10 hack-slow.log

#我是按傳回的行數進行的排序可以看到是用的Rows括号的值，如果用外面的就用參數ar

Count: 1  Time=25.94s (25s)  Lock=0.00s (0s)  Rows=47823.0 (47823), root[root]@localhost

  select * from t

Count: 1  Time=0.03s (0s)  Lock=0.00s (0s)  Rows=1225.0 (1225), root[root]@localhost

  select * from dlt

Count: 5  Time=0.01s (0s)  Lock=0.00s (0s)  Rows=128.8 (644), root[root]@localhost

Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=234.0 (234), root[root]@localhost

  select * from dlt  limit N

Count: 1  Time=0.01s (0s)  Lock=0.00s (0s)  Rows=146.0 (146), root[root]@localhost

[root@hack data]# mysqldumpslow -s at -t 10 hack-slow.log

#用at排序

Reading mysql slow query log from hack-slow.log 

Count: 1  Time=25.94s (25s)  Lock=0.00s (0s)  Rows=47823.0 (47823), root[root]@localhost

Count: 1  Time=0.03s (0s)  Lock=0.00s (0s)  Rows=1225.0 (1225), root[root]@localhost

[root@hack data]# tail -f hack-slow.log 

Tcp port: 3306  Unix socket: /usr/local/mysql/mysql.sock

Time                 Id Command    Argument

/usr/local/mysql/bin/mysqld, Version: 5.6.14-log (Source distribution). started with:

# Time: 150417  1:23:49

# User@Host: root[root] @ localhost []  Id:     1

# Query_time: 0.118892  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0

SET timestamp=1429205029;

select version();

# Time: 150417  1:24:20

# Query_time: 0.426234  Lock_time: 0.139966 Rows_sent: 5  Rows_examined: 5

SET timestamp=1429205060;

show variables like '%slow%';

^C

另外從5.1版本之後，開始慢查詢日志可以記錄到資料庫中，在mysql中存在一個slow_log的表

mysql> show create table mysql.slow_log \G

*************************** 1. row ***************************

       Table: slow_log

Create Table: CREATE TABLE `slow_log` (

  `start_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,

  `user_host` mediumtext NOT NULL,

  `query_time` time NOT NULL,

  `lock_time` time NOT NULL,

  `rows_sent` int(11) NOT NULL,

  `rows_examined` int(11) NOT NULL,

  `db` varchar(512) NOT NULL,

  `last_insert_id` int(11) NOT NULL,

  `insert_id` int(11) NOT NULL,

  `server_id` int(10) unsigned NOT NULL,

  `sql_text` mediumtext NOT NULL,

  `thread_id` bigint(21) unsigned NOT NULL

) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log'

1 row in set (0.07 sec)

mysql> 可以看到該表的引擎為CSV 

mysql> show variables like '%log_output%';

+---------------+-------+

| Variable_name | Value |

| log_output    | FILE  |

1 row in set (0.03 sec)

mysql> set global log_output='FILE,TABLE';更改日志輸出到檔案和表中

Query OK, 0 rows affected (0.07 sec)

mysql> show variables like '%log_output%';

+---------------+------------+

| Variable_name | Value      |

| log_output    | FILE,TABLE |

1 row in set (0.09 sec)

mysql> select sleep(10);

+-----------+

| sleep(10) |

|         0 |

1 row in set (10.09 sec)

mysql> select * from mysql.slow_log \G 我從打開table到查詢有兩條語句達到慢查詢設定的時間

    start_time: 2015-04-17 01:33:50

     user_host: root[root] @ localhost []

    query_time: 00:00:00

     lock_time: 00:00:00

     rows_sent: 0

 rows_examined: 0

            db: 

last_insert_id: 0

     insert_id: 0

     server_id: 13

      sql_text: set global log_output='FILE,TABLE'

     thread_id: 1

*************************** 2. row ***************************

    start_time: 2015-04-17 01:34:17

    query_time: 00:00:10

     rows_sent: 1

      sql_text: select sleep(10)

2 rows in set (0.01 sec)

mysql> 修改slow_log的存儲引擎為myisam

mysql> alter table mysql.slow_log engine=myisam;

ERROR 1580 (HY000): You cannot 'ALTER' a log table if logging is enabled

mysql> set global slow_query_log=off;

Query OK, 0 rows affected (0.00 sec)

Query OK, 3 rows affected (0.15 sec)

Records: 3  Duplicates: 0  Warnings: 0

mysql> 

本文轉自 aklaus 51CTO部落格，原文連結:http://blog.51cto.com/aklaus/1633633