mysql:慢查询日志slow_query_log
1、慢查询日志：当查询超过一定的时间没有返回结果的时候，才会记录到慢查询日志中。默认不开启。采样的时候手工开启。可以帮助DBA找出执行慢的SQL语句
2、常用的参数详解：
注意：修改以下参数，需要重新启动数据库服务才会生效。 slow_query_log=off|on --是否开启慢查询日志 slow_query_log_file=filename --指定保存路径及文件名，默认为数据文件目录，hostname-slow.log long_query_time=2 --指定多少秒返回查询的结果为慢查询
long-queries-not-using-indexes --记录所有没有使用到索引的查询语句
min_examined_row_limit=1000 --记录那些由于查找了多余1000次而引发的慢查询
long-slow-admin-statements --记录那些慢的optimize table，analyze table和alter table语句
log-slow-Slave-statements --记录由Slave所产生的慢查询
3、不重启修改慢查询配置：
set @@global.slow_query_log=1 set @@global.slow_query_time=3 其他参数可通过以下命令查阅： show variables '%slow%';
mysql> show variables like '%slow%'; +---------------------------+-----------------------------------+ | Variable_name | Value | +---------------------------+-----------------------------------+ | log_slow_admin_statements | OFF | | log_slow_slave_statements | OFF | | slow_launch_time | 2 | | slow_query_log | OFF | | slow_query_log_file | /var/lib/mysql/localhost-slow.log | +---------------------------+-----------------------------------+ mysql> show variables like '%long%'; +--------------------------------------------------------+-----------+ | Variable_name | Value | +--------------------------------------------------------+-----------+ | long_query_time | 10.000000 | | performance_schema_events_stages_history_long_size | 10000 | | performance_schema_events_statements_history_long_size | 10000 | | performance_schema_events_waits_history_long_size | 10000 | +--------------------------------------------------------+-----------+ 4 rows in set (0.03 sec) mysql> show variables like '%min%'; +---------------------------+-------+ | Variable_name | Value | +---------------------------+-------+ | ft_min_word_len | 4 | | innodb_ft_min_token_size | 3 | | log_slow_admin_statements | OFF | | min_examined_row_limit | 0 | | query_cache_min_res_unit | 4096 | +---------------------------+-------+ 5 rows in set (0.00 sec)
EG:开启慢查询日志：示例
mysql> set global slow_query_log=1; Query OK, 0 rows affected (0.08 sec) mysql> set global long_query_time=2; Query OK, 0 rows affected (0.00 s mysql> set long_query_time=2; Query OK, 0 rows affected (0.05 sec) [root@localhost mysql]# ls auto.cnf ib_logfile0 king localhost.log mysql mysql_bin.000002 mysql_bin.000004 mysql_bin.index performance_schema utf8 ibdata1 ib_logfile1 localhost.localdomain.pid localhost-slow.log mysql_bin.000001 mysql_bin.000003 mysql_bin.000005 mysql.sock test world mysql> select sleep(3); +----------+ | sleep(3) | +----------+ | 0 | +----------+ 1 row in set (3.00 sec) mysql> select sleep(4); +----------+ | sleep(4) | +----------+ | 0 | +----------+ 1 row in set (4.01 sec) [root@localhost mysql]# tail -f localhost-slow.log /usr/local/mysql/bin/mysqld, Version: 5.6.23-log (MySQL Community Server (GPL)). started with: Tcp port: 3306 Unix socket: /var/lib/mysql/mysql.sock Time Id Command Argument # Time: 160328 11:31:47 # User@Host: root[root] @ localhost [] Id: 4 # Query_time: 3.000955 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 use king; SET timestamp=1459135907; select sleep(3); # Time: 160328 11:31:57 # User@Host: root[root] @ localhost [] Id: 4 # Query_time: 4.001169 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 SET timestamp=1459135917; select sleep(4);
4、常用慢查询分析工具：
mysqldumpslow（结果简陋不方便阅读分析）
mysqlsla
percona-toolkit中的pt-query-digest
[root@localhost mysql]# mysqldumpslow localhost-slow.log Reading mysql slow query log from localhost-slow.log Count: 2 Time=3.50s (7s) Lock=0.00s (0s) Rows=1.0 (2), root[root]@localhost select sleep(N)
[root@localhost log]# chmod +x mysqlsla-2.03 [root@localhost log]# ll 总用量 1824 -rwxr-xr-x. 1 root root 105463 11月 11 2008 mysqlsla-2.03 -rw-r--r--. 1 root root 1760229 4月 18 2014 percona-toolkit-2.2.7-1.noarch.rpm [root@localhost log]# ./mysqlsla-2.03 /var/lib/mysql/localhost-slow.log Auto-detected logs as slow logs Report for slow logs: /var/lib/mysql/localhost-slow.log 2 queries total, 1 unique Sorted by 't_sum' Grand Totals: Time 7 s, Lock 0 s, Rows sent 2, Rows Examined 0 ______________________________________________________________________ 001 ___ Count : 2 (100.00%) Time : 7.002124 s total, 3.501062 s avg, 3.000955 s to 4.001169 s max (100.00%) Lock Time (s) : 0 total, 0 avg, 0 to 0 max (0.00%) Rows sent : 1 avg, 1 to 1 max (100.00%) Rows examined : 0 avg, 0 to 0 max (0.00%) Database : king Users : root@localhost : 100.00% (2) of query, 100.00% (2) of all users Query abstract: SET timestamp=N; SELECT sleep(N); Query sample: SET timestamp=1459135907; select sleep(3);
[root@localhost log]# rpm -ivh percona-toolkit-2.2.7-1.noarch.rpm --nodeps Preparing... ########################################### [100%] 1:percona-toolkit ########################################### [100%] [root@localhost log]# pt-query-digest /var/lib/mysql/localhost-slow.log # A software update is available: # * The current version for Percona::Toolkit is 2.2.14. # 820ms user time, 390ms system time, 21.98M rss, 177.44M vsz # Current date: Mon Mar 28 11:50:37 2016 # Hostname: localhost.localdomain # Files: /var/lib/mysql/localhost-slow.log # Overall: 2 total, 1 unique, 0.20 QPS, 0.70x concurrency ________________ # Time range: 2016-03-28 11:31:47 to 11:31:57 # Attribute total min max avg 95% stddev median # ============ ======= ======= ======= ======= ======= ======= ======= # Exec time 7s 3s 4s 4s 4s 707ms 4s # Lock time 0 0 0 0 0 0 0 # Rows sent 2 1 1 1 1 0 1 # Rows examine 0 0 0 0 0 0 0 # Query size 30 15 15 15 15 0 15 # Profile # Rank Query ID Response time Calls R/Call V/M Item # ==== ================== ============= ===== ====== ===== ====== # 1 0xF9A57DD5A41825CA 7.0021 100.0% 2 3.5011 0.14 SELECT # Query 1: 0.20 QPS, 0.70x concurrency, ID 0xF9A57DD5A41825CA at byte 397 # This item is included in the report because it matches --limit. # Scores: V/M = 0.14 # Time range: 2016-03-28 11:31:47 to 11:31:57 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 100 2 # Exec time 100 7s 3s 4s 4s 4s 707ms 4s # Lock time 0 0 0 0 0 0 0 0 # Rows sent 100 2 1 1 1 1 0 1 # Rows examine 0 0 0 0 0 0 0 0 # Query size 100 30 15 15 15 15 0 15 # String: # Databases king # Hosts localhost # Users root # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s ################################################################ # 10s+ # EXPLAIN /*!50100 PARTITIONS*/ select sleep(4)\G
