Mysql slow query log


一、概念部分: 

   顧名思義,慢查詢日志中記錄的是執行時間較長的query,也就是我們常說的slow query,通過設--log-slow-queries[=file_name]來打開該功能並設置記錄位置和文件名,默認文件名為hostname-slow.log,默認目錄也是數據目錄。
    慢查詢日志采用的是簡單的文本格式,可以通過各種文本編輯器查看其中的內容。其中記錄了語句執行的時刻,執行所消耗的時間,執行用戶,連接主機等相關信息。MySQL還提供了專門用來分析滿查詢日志的工具程序mysqlslowdump,用來幫助數據庫管理人員解決可能存在的性能問題。

二、slow query log相關變量

  2.1、命令行參數:

    --log-slow-queries

    指定日志文件存放位置,可以為空,系統會給一個缺省的文件host_name-slow.log

  2.2、系統變量

    log_slow_queries

    指定日志文件存放位置,可以為空,系統會給一個缺省的文件host_name-slow.log

    slow_query_log

    slow quere log的開關,當值為1的時候說明開啟慢查詢。

    slow_query_log_file

    指定日志文件存放位置,可以為空,系統會給一個缺省的文件host_name-slow.log

    long_query_time

    記錄超過的時間,默認為10s

    log_queries_not_using_indexes

    log下來沒有使用索引的query,可以根據情況決定是否開啟

三、實驗部分:

----使用log_slow_queries參數打開慢查詢,由於該參數已經過時,因此在err日志中將出現提示信息
----修改my.cnf文件,添加log_slow_queries參數
[root@node4 ~]# vi /opt/mysql5.5/my.cnf
[root@node4 ~]# cat /opt/mysql5.5/my.cnf |grep '^log_slow'
log_slow_queries = /tmp/mysqlslow.log
----清空err日志內容:
[root@node4 ~]# cat /dev/null > /tmp/mysql3306.err 
[root@node4 ~]# service mysql start
Starting MySQL....                                         [  OK  ]
----查看err日志的信息
[root@node4 data]# tail -f /tmp/mysql3306.err 
130801 02:26:28 mysqld_safe Starting mysqld daemon with databases from /opt/mysql5.5/data
130801  2:26:28 [Warning] The syntax '--log-slow-queries' is deprecated and will be removed in a future release. Please use '--slow-query-log'/'--slow-query-log-file' instead.
130801  2:26:28 [Warning] You need to use --log-bin to make --binlog-format work.
130801  2:26:28 InnoDB: The InnoDB memory heap is disabled
130801  2:26:28 InnoDB: Mutexes and rw_locks use InnoDB's own implementation
130801  2:26:28 InnoDB: Compressed tables use zlib 1.2.3
130801  2:26:28 InnoDB: Initializing buffer pool, size = 128.0M
130801  2:26:28 InnoDB: Completed initialization of buffer pool
130801  2:26:28 InnoDB: highest supported file format is Barracuda.
130801  2:26:28  InnoDB: Waiting for the background threads to start
130801  2:26:30 InnoDB: 1.1.8 started; log sequence number 3069452
130801  2:26:30 [Note] Event Scheduler: Loaded 0 events
130801  2:26:30 [Note] /opt/mysql5.5/bin/mysqld: ready for connections.
Version: '5.5.22-log'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution

----使用slow_query_log和slow_query_log_file
[root@node4 ~]# vi /opt/mysql5.5/my.cnf
[root@node4 ~]# cat /opt/mysql5.5/my.cnf |grep '^slow_query'
slow_query_log = 1
slow_query_log_file = /tmp/mysqlslow.log1

[root@node4 ~]# service mysql start
Starting MySQL...                                          [  OK  ]
[root@node4 ~]# mysql
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.5.22-log Source distribution

Copyright (c) 2000, 2011, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> show variables like '%slow%';
+---------------------+---------------------+
| Variable_name       | Value               |
+---------------------+---------------------+
| log_slow_queries    | ON                  |
| slow_launch_time    | 10                   |
| slow_query_log      | ON                  |
| slow_query_log_file | /tmp/mysqlslow.log1 |
+---------------------+---------------------+
4 rows in set (0.00 sec)

----關於slow_launch_time參數,首先修改一下參數值
mysql> set global long_query_time=1;
Query OK, 0 rows affected (0.00 sec)
mysql> show variables like '%long_query%';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)

----進行一下相關操作,查看/tmp/mysqlslow.log1的內容 mysql> select database();
+------------+
| database() |
+------------+
| NULL       |
+------------+
1 row in set (0.00 sec)

mysql> use test;
Database changed
mysql> show tables;
Empty set (0.00 sec)

mysql> create table t as select * from information_schema.tables;
Query OK, 85 rows affected (0.38 sec)
Records: 85  Duplicates: 0  Warnings: 0

mysql> insert into t select * from t;
Query OK, 85 rows affected (0.05 sec)
Records: 85  Duplicates: 0  Warnings: 0

mysql> insert into t select * from t;
Query OK, 170 rows affected (0.03 sec)
Records: 170  Duplicates: 0  Warnings: 0

mysql> insert into t select * from t;
Query OK, 340 rows affected (0.05 sec)
Records: 340  Duplicates: 0  Warnings: 0

mysql> insert into t select * from t;
Query OK, 680 rows affected (0.08 sec)
Records: 680  Duplicates: 0  Warnings: 0

mysql> insert into t select * from t;
Query OK, 1360 rows affected (0.29 sec)
Records: 1360  Duplicates: 0  Warnings: 0

mysql> insert into t select * from t;
Query OK, 2720 rows affected (1.49 sec)
Records: 2720  Duplicates: 0  Warnings: 0

----在這里已經超過1s了,查看/tmp/mysqlslow.log1
[root@node4 data]# tail -f /tmp/mysqlslow.log1
# Time: 130801  2:36:25
# User@Host: root[root] @ localhost []
# Query_time: 2.274219  Lock_time: 0.000322 Rows_sent: 0  Rows_examined: 5440
use test;
SET timestamp=1375295785;
insert into t select * from t;

----log_queries_not_using_indexes參數實驗
mysql> show variables like '%indexes%';
+-------------------------------+-------+
| Variable_name                 | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | OFF   |
+-------------------------------+-------+
1 row in set (0.00 sec)

mysql> set log_queries_not_using_indexes = 1;
ERROR 1229 (HY000): Variable 'log_queries_not_using_indexes' is a GLOBAL variable and should be set with SET GLOBAL
mysql> set global log_queries_not_using_indexes = 1;
Query OK, 0 rows affected (0.01 sec)

mysql> show variables like '%indexes%';
+-------------------------------+-------+
| Variable_name                 | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | ON    |
+-------------------------------+-------+
1 row in set (0.00 sec)

mysql> desc t;
+-----------------+---------------------+------+-----+---------+-------+
| Field           | Type                | Null | Key | Default | Extra |
+-----------------+---------------------+------+-----+---------+-------+
| TABLE_CATALOG   | varchar(512)        | NO   |     |         |       |
| TABLE_SCHEMA    | varchar(64)         | NO   |     |         |       |
| TABLE_NAME      | varchar(64)         | NO   |     |         |       |
| TABLE_TYPE      | varchar(64)         | NO   |     |         |       |
| ENGINE          | varchar(64)         | YES  |     | NULL    |       |
| VERSION         | bigint(21) unsigned | YES  |     | NULL    |       |
| ROW_FORMAT      | varchar(10)         | YES  |     | NULL    |       |
| TABLE_ROWS      | bigint(21) unsigned | YES  |     | NULL    |       |
| AVG_ROW_LENGTH  | bigint(21) unsigned | YES  |     | NULL    |       |
| DATA_LENGTH     | bigint(21) unsigned | YES  |     | NULL    |       |
| MAX_DATA_LENGTH | bigint(21) unsigned | YES  |     | NULL    |       |
| INDEX_LENGTH    | bigint(21) unsigned | YES  |     | NULL    |       |
| DATA_FREE       | bigint(21) unsigned | YES  |     | NULL    |       |
| AUTO_INCREMENT  | bigint(21) unsigned | YES  |     | NULL    |       |
| CREATE_TIME     | datetime            | YES  |     | NULL    |       |
| UPDATE_TIME     | datetime            | YES  |     | NULL    |       |
| CHECK_TIME      | datetime            | YES  |     | NULL    |       |
| TABLE_COLLATION | varchar(32)         | YES  |     | NULL    |       |
| CHECKSUM        | bigint(21) unsigned | YES  |     | NULL    |       |
| CREATE_OPTIONS  | varchar(255)        | YES  |     | NULL    |       |
| TABLE_COMMENT   | varchar(2048)       | NO   |     |         |       |
+-----------------+---------------------+------+-----+---------+-------+
21 rows in set (0.05 sec)
----下面的命令是查看索引的 mysql> show index from t;
Empty set (0.01 sec)

mysql> select * from t where engine='xxx';
Empty set (0.18 sec)

# Time: 130801  2:43:43
# User@Host: root[root] @ localhost []
# Query_time: 0.185773  Lock_time: 0.148868 Rows_sent: 0  Rows_examined: 5440
SET timestamp=1375296223;
select * from t where engine='xxx';

四、Mysqldumpslow

    如果日志內容很多,用眼睛一條一條看會累死,mysql自帶了分析的工具,使用方法如下:

[root@node4 data]# mysqldumpslow --help
Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]

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 (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
  -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

 


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM