首页
站长论坛BBS
救助
投稿
discuz视频教程
discuz技术支持
版块
登录
快速注册

MySQL 之 慢查询slow log开启、查看和分析

冷蝶 2015-5-11 [MYSQL] 来自PC 复制链接
32744
discuz使用视频教程
31idc

马上注册,一起探讨正确快速的建站方法

您需要 登录 才可以下载或查看,没有帐号?快速注册

x
慢查询有什么用?   
      它能记录下所有执行超过long_query_time时间的SQL语句,帮你找到执行慢的SQL,方便我们对这些SQL进行优化。   

测试用 MySQL 版本。   
Server version: 5.6.10-log Source distribution   

未做任何慢日志设置时。   

  1. mysql> show variables like "%query%";   
  2. +------------------------------+--------------------------------------+
  3. | Variable_name                | Value                                |
  4. +------------------------------+--------------------------------------+
  5. | binlog_rows_query_log_events | OFF                                  |
  6. | ft_query_expansion_limit     | 20                                   |
  7. | have_query_cache             | YES                                  |
  8. | long_query_time              | 10.000000                            |
  9. | query_alloc_block_size       | 8192                                 |
  10. | query_cache_limit            | 1048576                              |
  11. | query_cache_min_res_unit     | 4096                                 |
  12. | query_cache_size             | 1048576                              |
  13. | query_cache_type             | OFF                                  |
  14. | query_cache_wlock_invalidate | OFF                                  |
  15. | query_prealloc_size          | 8192                                 |
  16. | slow_query_log               | OFF                                  |
  17. | slow_query_log_file          | /usr/local/mysql/data/Betty-slow.log |
  18. +------------------------------+--------------------------------------+
  19. 13 rows in set (0.01 sec)
  20. mysql>
复制代码


修改配置文件,开启 slow log 。  

  1. [root@Betty data]# vi /etc/my.cnf           
  2. # For advice on how to change settings please see
  3. # http://dev.mysql.com/doc/refman/5.6/en/server-configuration-defaults.html
  4. # *** DO NOT EDIT THIS FILE. It's a template which will be copied to the
  5. # *** default location during install, and will be replaced if you
  6. # *** upgrade to a newer version of MySQL.
  7. [mysqld]
  8. # Remove leading # and set to the amount of RAM for the most important data
  9. # cache in MySQL. Start at 70% of total RAM for dedicated server, else 10%.
  10. # innodb_buffer_pool_size = 128M

  11. # Remove leading # to turn on a very important data integrity option: logging
  12. # changes to the binary log between backups.
  13. log_bin=mysql-bin
  14. slow_query_log=on
  15. slow_query_log_file=mysql-slow
  16. long_query_time=2

  17. # These are commonly set, remove the # and set as required.
  18. # basedir = .....
  19. # datadir = .....
  20. # port = .....
  21. # server_id = .....
  22. # socket = .....

  23. # Remove leading # to set options mainly useful for reporting servers.
  24. # The server defaults are faster for transactions and fast SELECTs.
  25. # Adjust sizes as needed, experiment to find the optimal values.
  26. # join_buffer_size = 128M
  27. # sort_buffer_size = 2M
  28. # read_rnd_buffer_size = 2M

  29. sql_mode=NO_ENGINE_SUBSTITUTION,STRICT_TRANS_TABLES

  30. [mysql]
  31. socket = /tmp/mysql.sock
复制代码


重启 MySQL 。  
  1. [root@Betty data]# /etc/init.d/mysql restart
  2. Shutting down MySQL..                                      [  OK  ]
  3. Starting MySQL.                                            [  OK  ]
  4. [root@Betty data]#
复制代码


查看 slow log 。  
  1. [root@Betty data]# ll mysql-slow
  2. -rw-rw---- 1 mysql mysql 719 Sep  6 12:43 mysql-slow
复制代码


重新查看系统变量值。  
  1. mysql>
  2. mysql> show variables like "%query%";
  3. +------------------------------+------------+
  4. | Variable_name                | Value      |
  5. +------------------------------+------------+
  6. | binlog_rows_query_log_events | OFF        |
  7. | ft_query_expansion_limit     | 20         |
  8. | have_query_cache             | YES        |
  9. | long_query_time              | 2.000000   |
  10. | query_alloc_block_size       | 8192       |
  11. | query_cache_limit            | 1048576    |
  12. | query_cache_min_res_unit     | 4096       |
  13. | query_cache_size             | 1048576    |
  14. | query_cache_type             | OFF        |
  15. | query_cache_wlock_invalidate | OFF        |
  16. | query_prealloc_size          | 8192       |
  17. | slow_query_log               | ON         |
  18. | slow_query_log_file          | mysql-slow |
  19. +------------------------------+------------+
  20. 13 rows in set (0.00 sec)

  21. mysql>
复制代码


查看新生成的 slow log 的内容。  
  1. [root@Betty data]# cat mysql-slow
  2. /usr/local/mysql/bin/mysqld, Version: 5.6.10-log (Source distribution). started with:
  3. Tcp port: 0  Unix socket: (null)
  4. Time                 Id Command    Argument
  5. [root@Betty data]#
复制代码


测试 slow log 。
  1. mysql>
  2. mysql> select 1;
  3. +---+
  4. | 1 |
  5. +---+
  6. | 1 |
  7. +---+
  8. 1 row in set (0.00 sec)

  9. mysql>
  10. mysql> select sleep(1);
  11. +----------+
  12. | sleep(1) |
  13. +----------+
  14. |        0 |
  15. +----------+
  16. 1 row in set (1.00 sec)

  17. mysql>
  18. mysql>
  19. mysql> select sleep(3);
  20. +----------+
  21. | sleep(3) |
  22. +----------+
  23. |        0 |
  24. +----------+
  25. 1 row in set (3.00 sec)

  26. mysql>
  27. mysql> select sleep(4);
  28. +----------+
  29. | sleep(4) |
  30. +----------+
  31. |        0 |
  32. +----------+
  33. 1 row in set (4.01 sec)

  34. mysql>
  35. mysql>
  36. mysql> select sleep(5);
  37. +----------+
  38. | sleep(5) |
  39. +----------+
  40. |        0 |
  41. +----------+
  42. 1 row in set (5.00 sec)

  43. mysql> select sleep(2);
  44. +----------+
  45. | sleep(2) |
  46. +----------+
  47. |        0 |
  48. +----------+
  49. 1 row in set (2.01 sec)

  50. mysql>
  51. mysql> select sleep(1);
  52. +----------+
  53. | sleep(1) |
  54. +----------+
  55. |        0 |
  56. +----------+
  57. 1 row in set (1.00 sec)

  58. mysql> select 2;      
  59. +---+
  60. | 2 |
  61. +---+
  62. | 2 |
  63. +---+
  64. 1 row in set (0.00 sec)

  65. mysql>
复制代码


查看此时 slow log 的内容。  

  1. [root@Betty data]# cat mysql-slow
  2. /usr/local/mysql/bin/mysqld, Version: 5.6.10-log (Source distribution). started with:
  3. Tcp port: 0  Unix socket: (null)
  4. Time                 Id Command    Argument
  5. # Time: 130906 12:52:51
  6. # User@Host: root[root] @ localhost []  Id:     1
  7. # Query_time: 3.002864  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
  8. SET timestamp=1378443171;
  9. select sleep(3);
  10. # Time: 130906 12:53:01
  11. # User@Host: root[root] @ localhost []  Id:     1
  12. # Query_time: 4.001943  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
  13. SET timestamp=1378443181;
  14. select sleep(4);
  15. # Time: 130906 12:53:09
  16. # User@Host: root[root] @ localhost []  Id:     1
  17. # Query_time: 5.002093  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
  18. SET timestamp=1378443189;
  19. select sleep(5);
  20. # Time: 130906 12:53:15
  21. # User@Host: root[root] @ localhost []  Id:     1
  22. # Query_time: 2.002984  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
  23. SET timestamp=1378443195;
  24. select sleep(2);
  25. [root@Betty data]#
复制代码

实验:  

a. 使用 mysql 自带慢查询日志分析工具 mysqldumpslow 。  
  1. [root@Betty data]# mysqldumpslow mysql-slow

  2. Reading mysql slow query log from mysql-slow
  3. Count: 4  Time=3.50s (14s)  Lock=0.00s (0s)  Rows=1.0 (4), root[root]@localhost
  4.   select sleep(N)

  5. [root@Betty data]#
复制代码


b. 使用 hackmysql.com 推出的一款日志分析工具 mysqlsla 。  
  1. [root@Betty data]# mysqlsla -lt slow mysql-slow
  2. Report for slow logs: mysql-slow
  3. 4 queries total, 1 unique
  4. Sorted by 't_sum'
  5. Grand Totals: Time 14 s, Lock 0 s, Rows sent 4, Rows Examined 0

  6. ______________________________________________________________________ 001 ___
  7. Count         : 4  (100.00%)
  8. Time          : 14.009884 s total, 3.502471 s avg, 2.002984 s to 5.002093 s max  (100.00%)
  9. Lock Time (s) : 0 total, 0 avg, 0 to 0 max  (0.00%)
  10. Rows sent     : 1 avg, 1 to 1 max  (100.00%)
  11. Rows examined : 0 avg, 0 to 0 max  (0.00%)
  12. Database      :
  13. Users         :
  14.         root@localhost  : 100.00% (4) of query, 100.00% (4) of all users

  15. Query abstract:
  16. SET timestamp=N; SELECT sleep(N);

  17. Query sample:
  18. SET timestamp=1378443171;
  19. select sleep(3);
  20. [root@Betty data]#
复制代码

c. 使用德国人写的 mysql_explain_slow_log 。(不知道为什么未统计出信息)  
  1. [root@Betty WGET_DIR]# ./mysql_explain_slow_log --user=root --password= --socket=/tmp/mysql.sock < /usr/local/mysql/data/mysql-slow     

  2. mysql_explain_slow_log
  3. ======================

  4. Index usage ------------------------------------

  5. Queries causing table scans -------------------

  6. Sum: 0 table scans

  7. Summary ---------------------------------------

  8. Select:         0 queries
  9. Update:         0 queries
  10. Load:   0 queries

  11. Logfile:        26 lines
  12. Started:        Fri Sep  6 15:59:13 2013
  13. Finished:       Fri Sep  6 15:59:13 2013
  14. [root@Betty WGET_DIR]#
复制代码

d.    google code 上的一个分析工具 mysql_filter_slow_log (最后更新日期为2007年),提供了 python 和 php 两种可执行的脚本。   

  1. [root@Betty WGET_DIR]# python mysql_filter_slow_log.py /usr/local/mysql/data/mysql-slow --no-duplicates --sort-execution-count --top=10
  2. # Execution count: 1 time on 2013-09-06 16:07:23.
  3. # Column       : avg | max | sum
  4. # Query time   :   5 |   5 |   5
  5. # Lock time    :   0 |   0 |   0
  6. # Rows examined:   0 |   0 |   0
  7. # Rows sent    :   1 |   1 |   1
  8. # User@Host: root[root] @ localhost []  Id:     1

  9. SET timestamp=1378454843;select sleep(5);

  10. # Execution count: 1 time on 2013-09-06 16:07:15.
  11. # Column       : avg | max | sum
  12. # Query time   :   4 |   4 |   4
  13. # Lock time    :   0 |   0 |   0
  14. # Rows examined:   0 |   0 |   0
  15. # Rows sent    :   1 |   1 |   1
  16. # User@Host: root[root] @ localhost []  Id:     1

  17. SET timestamp=1378454835;select sleep(4);

  18. # Execution count: 1 time on 2013-09-06 16:07:01.
  19. # Column       : avg | max | sum
  20. # Query time   :   3 |   3 |   3
  21. # Lock time    :   0 |   0 |   0
  22. # Rows examined:   0 |   0 |   0
  23. # Rows sent    :   1 |   1 |   1
  24. # User@Host: root[root] @ localhost []  Id:     1

  25. SET timestamp=1378454821;select sleep(3);

  26. # Execution count: 1 time on 2013-09-06 16:07:28.
  27. # Column       : avg | max | sum
  28. # Query time   :   2 |   2 |   2
  29. # Lock time    :   0 |   0 |   0
  30. # Rows examined:   0 |   0 |   0
  31. # Rows sent    :   1 |   1 |   1
  32. # User@Host: root[root] @ localhost []  Id:     1

  33. SET timestamp=1378454848;select sleep(2);

  34. [root@Betty WGET_DIR]#
复制代码

e. 使用 percona-toolkit 中的 pt-query-digest (在《高性能MySQL》中多次提出,值得使用的工具)。   

  1. [root@Betty data]# pt-query-digest --user=root  mysql-slow            


  2. # 120ms user time, 10ms system time, 20.21M rss, 68.70M vsz
  3. # Current date: Mon Sep  9 13:21:38 2013
  4. # Hostname: Betty
  5. # Files: mysql-slow
  6. # Overall: 4 total, 1 unique, 0.15 QPS, 0.52x concurrency ________________
  7. # Time range: 2013-09-06 16:07:01 to 16:07:28
  8. # Attribute          total     min     max     avg     95%  stddev  median
  9. # ============     ======= ======= ======= ======= ======= ======= =======
  10. # Exec time            14s      2s      5s      4s      5s      1s      4s
  11. # Lock time              0       0       0       0       0       0       0
  12. # Rows sent              4       1       1       1       1       0       1
  13. # Rows examine           0       0       0       0       0       0       0
  14. # Query size            60      15      15      15      15       0      15

  15. # Profile
  16. # Rank Query ID           Response time  Calls R/Call V/M   Item
  17. # ==== ================== ============== ===== ====== ===== ======
  18. #    1 0xF9A57DD5A41825CA 14.0097 100.0%     4 3.5024  0.36 SELECT

  19. # Query 1: 0.15 QPS, 0.52x concurrency, ID 0xF9A57DD5A41825CA at byte 548
  20. # This item is included in the report because it matches --limit.
  21. # Scores: V/M = 0.36
  22. # Time range: 2013-09-06 16:07:01 to 16:07:28
  23. # Attribute    pct   total     min     max     avg     95%  stddev  median
  24. # ============ === ======= ======= ======= ======= ======= ======= =======
  25. # Count        100       4
  26. # Exec time    100     14s      2s      5s      4s      5s      1s      4s
  27. # Lock time      0       0       0       0       0       0       0       0
  28. # Rows sent    100       4       1       1       1       1       0       1
  29. # Rows examine   0       0       0       0       0       0       0       0
  30. # Query size   100      60      15      15      15      15       0      15
  31. # String:
  32. # Hosts        localhost
  33. # Users        root
  34. # Query_time distribution
  35. #   1us
  36. #  10us
  37. # 100us
  38. #   1ms
  39. #  10ms
  40. # 100ms
  41. #    1s  ################################################################
  42. #  10s+
  43. # EXPLAIN /*!50100 PARTITIONS*/
  44. select sleep(5)\G
  45. [root@Betty data]#
复制代码

慢查询配置项   
  1. # I.e. you could add the following lines under the [mysqld] section of your my.ini or my.cnf configuration file:

  2. # Log all queries taking more than 3 seconds
  3. long_query_time=3  # minimum: 1, default: 10

  4. # MySQL >= 5.1.21 (or patched): 3 seconds = 3000000 microseconds
  5. # long_query_time=3.000000  # minimum: 0.000001 (1 microsecond)

  6. # Activate the Slow Query Log
  7. slow_query_log  # >= 5.1.29
  8. # log-slow-queries  # deprecated since 5.1.29

  9. # Write to a custom file name (>= 5.1.29)
  10. # slow_query_log_file=file_name  # default: /data_dir/host_name-slow.log

  11. # Log all queries without indexes
  12. # log-queries-not-using-indexes


  13. # Log only queries which examine at least N rows (>= 5.1.21)
  14. # min_examined_row_limit=1000  # default: 0

  15. # Log slow OPTIMIZE TABLE, ANALYZE TABLE, and ALTER TABLE statements
  16. # log-slow-admin-statements

  17. # Log slow queries executed by replication slaves (>= 5.1.21)
  18. # log-slow-slave-statements

  19. # MySQL 5.1.6 through 5.1.20 had a default value of log-output=TABLE, so you should force
  20. # Attention: logging to TABLE only includes whole seconds information
  21. log-output=FILE

  22. ## Admin query for online activation is possible since MySQL 5.1 (without server restart)
  23. ## SET @@global.slow_query_log=1
  24. ## SET @@global.long_query_time=1

  25. ## Show current variables related to the Slow Query Log
  26. ## SHOW GLOBAL VARIABLES WHERE Variable_name REGEXP 'admin|min_examined|log_output|log_queries|log_slave|long|slow_quer'
复制代码



上一篇:关于Jquery中 “$(document).ready(function(){ })”函数的使用
下一篇:优化中需要保持平衡性
Reus 发表于 2015-5-14 12:34:08 来自PC
看到这帖子真是高兴!
lelegoer 发表于 2015-5-18 22:37:41 来自PC
真是难得给力的帖子啊。终于知道了。
miyukong.com yihaojiayuan,.com howdian.com
362938688 发表于 2015-5-19 12:23:21 来自PC
我看不代码的
www.yandaoqingxi.cn|www.jjpd888.com|www.jjjnews.top|www.bjxdc2001.com|www.gchb001.com|www.seoh.cn网站推广
您需要登录后才可以回帖 登录 | 快速注册

本版积分规则

快速回复 返回顶部 返回列表