MySQL中查询日志与慢查询日志的基本学习教程_MySQL

WBOY
Lepaskan: 2016-05-27 13:46:15
asal
1202 orang telah melayarinya

一、查询日志

  查询日志记录MySQL中所有的query,通过"--log[=file_name]"来打开该功能。由于记录了所有的query,包括所有的select,体积比较大,开启后对性能也有比较大的影响,所以请大家慎用该功能。一般只用于跟踪某些特殊的sql性能问题才会短暂打开该功能。默认的查询日志文件名为:hostname.log. 
----默认情况下查看是否启用查询日志:

[root@node4 mysql5.5]# service mysql start
Salin selepas log masuk
Salin selepas log masuk

Starting MySQL....                     [ OK ]
Salin selepas log masuk
Salin selepas log masuk

[root@node4 mysql5.5]# mysql
Salin selepas log masuk
Salin selepas log masuk

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.

Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

mysql> show variables like '%log';
Salin selepas log masuk

+--------------------------------+-------+
| Variable_name         | Value |
+--------------------------------+-------+
| back_log            | 50  |
| general_log          | OFF  |
| innodb_locks_unsafe_for_binlog | OFF  |
| log              | OFF  |
| relay_log           |    |
| slow_query_log         | OFF  |
| sync_binlog          | 0   |
| sync_relay_log         | 0   |
+--------------------------------+-------+
8 rows in set (0.00 sec)
Salin selepas log masuk

----备注:log和general_log这两个参数是兼容的。而默认的情况下查询日志是不开启的<br />----使用下面的命令是开启查询日志<br />mysql> set global log=1;

Salin selepas log masuk

Query OK, 0 rows affected, 1 warning (0.03 sec)

Salin selepas log masuk

mysql> show variables like '%log';

Salin selepas log masuk
Salin selepas log masuk

+--------------------------------+-------+
| Variable_name         | Value |
+--------------------------------+-------+
| back_log            | 50  |
| general_log          | ON  |
| innodb_locks_unsafe_for_binlog | OFF  |
| log              | ON  |
| relay_log           |    |
| slow_query_log         | OFF  |
| sync_binlog          | 0   |
| sync_relay_log         | 0   |
+--------------------------------+-------+
8 rows in set (0.00 sec) 
----其中log参数是过时的,在启动选项中使用log参数的话,会在err日志中显示出来。
----修改my.cnf文件,添加log的参数设置
Salin selepas log masuk

[root@node4 mysql5.5]# vi my.cnf
[root@node4 mysql5.5]# cat ./my.cnf |grep '^log='
log=/tmp/mysqlgen.log
----清空err日志
[root@node4 mysql5.5]# cat /dev/null > /tmp/mysql3306.err 
[root@node4 mysql5.5]# ll /tmp/mysql3306.err 
-rw-rw---- 1 mysql root 0 Jul 31 07:50 /tmp/mysql3306.err
[root@node4 mysql5.5]# service mysql start
Salin selepas log masuk

Starting MySQL...                     [ OK ]
----启动数据库后查看err日志的内容
Salin selepas log masuk

[root@node4 mysql5.5]# cat /tmp/mysql3306.err 
Salin selepas log masuk

130731 07:51:32 mysqld_safe Starting mysqld daemon with databases from /opt/mysql5.5/data
130731 7:51:32 [Warning] The syntax '--log' is deprecated and will be removed in a future release. Please use '--general-log'/'--general-log-file' instead.
130731 7:51:33 InnoDB: The InnoDB memory heap is disabled
130731 7:51:33 InnoDB: Mutexes and rw_locks use InnoDB's own implementation
130731 7:51:33 InnoDB: Compressed tables use zlib 1.2.3
130731 7:51:33 InnoDB: Initializing buffer pool, size = 128.0M
130731 7:51:33 InnoDB: Completed initialization of buffer pool
130731 7:51:33 InnoDB: highest supported file format is Barracuda.
130731 7:51:33 InnoDB: Waiting for the background threads to start
130731 7:51:34 InnoDB: 1.1.8 started; log sequence number 1625855
130731 7:51:34 [Note] Event Scheduler: Loaded 0 events
130731 7:51:34 [Note] /opt/mysql5.5/bin/mysqld: ready for connections.
Version: '5.5.22-log' socket: '/tmp/mysql.sock' port: 3306 Source distribution
----使用最新的参数
----general_log和general_log_file。
Salin selepas log masuk

[root@node4 mysql5.5]# service mysql stop
Salin selepas log masuk

Shutting down MySQL.                    [ OK ]
Salin selepas log masuk

[root@node4 mysql5.5]# vi my.cnf
[root@node4 mysql5.5]# cat ./my.cnf |grep '^general'
Salin selepas log masuk

general_log = 1 
general_log_file = /tmp/mysqlgen.log
Salin selepas log masuk

[root@node4 mysql5.5]# service mysql start
Salin selepas log masuk
Salin selepas log masuk

Starting MySQL...                     [ OK ]
Salin selepas log masuk
Salin selepas log masuk

[root@node4 mysql5.5]# mysql
Salin selepas log masuk
Salin selepas log masuk

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.

Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

mysql> show variables like '%log';

Salin selepas log masuk
Salin selepas log masuk

+--------------------------------+-------+
| Variable_name         | Value |
+--------------------------------+-------+
| back_log            | 50  |
| general_log          | ON  |
| innodb_locks_unsafe_for_binlog | OFF  |
| log              | ON  |
| relay_log           |    |
| slow_query_log         | OFF  |
| sync_binlog          | 0   |
| sync_relay_log         | 0   |
+--------------------------------+-------+
8 rows in set (0.04 sec)
Salin selepas log masuk

mysql> show variables like '%file';
Salin selepas log masuk

+---------------------+-----------------------------------+
| Variable_name    | Value               |
+---------------------+-----------------------------------+
| ft_stopword_file  | (built-in)            |
| general_log_file  | /tmp/mysqlgen.log         |
| init_file      |                  |
| local_infile    | ON                |
| pid_file      | /tmp/mysql3306.pid        |
| relay_log_info_file | relay-log.info          |
| slow_query_log_file | /opt/mysql5.5/data/node4-slow.log |
+---------------------+-----------------------------------+
7 rows in set (0.00 sec)
----在上面的操作中可以看到已经启用查询日志,并且文件目录是/tmp/mysqlgen.log。
----查询日志记录了哪些东西?
Salin selepas log masuk

进行下面的查询

mysql> show databases;
Salin selepas log masuk

+--------------------+
| Database      |
+--------------------+
| information_schema |
| mysql       |
| performance_schema |
| test        |
| test2       |
+--------------------+
5 rows in set (0.08 sec)

Salin selepas log masuk

mysql> use test;
Salin selepas log masuk
Salin selepas log masuk

Database changed
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

mysql> show tables;
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

Empty set (0.00 sec)

Salin selepas log masuk
Salin selepas log masuk

mysql> use test2;
Salin selepas log masuk

Database changed
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

mysql> show tables;
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

+-----------------+
| Tables_in_test2 |
+-----------------+
| course     |
| jack      |
| sc       |
| student     |
| t        |
| teacher     |
+-----------------+
6 rows in set (0.07 sec)

Salin selepas log masuk

mysql> drop table t;
Salin selepas log masuk

Query OK, 0 rows affected (0.13 sec)

Salin selepas log masuk

mysql> select * from sc;
Salin selepas log masuk

Empty set (0.04 sec)

----可以看到上面的操作都记录在了mysqlgen.log里面。

Salin selepas log masuk

[root@node4 ~]# tail -f /tmp/mysqlgen.log
Salin selepas log masuk

/opt/mysql5.5/bin/mysqld, Version: 5.5.22-log (Source distribution). started with:
Tcp port: 3306 Unix socket: /tmp/mysql.sock
Time         Id Command  Argument
130731 7:55:41    1 Query  show databases
130731 7:55:56    1 Query  SELECT DATABASE()
      1 Init DB  test
130731 7:55:59    1 Query  show tables
130731 7:56:19    1 Query  SELECT DATABASE()
      1 Init DB  test2
130731 7:56:23    1 Query  show tables
130731 7:56:27    1 Query  drop table t
130731 7:56:39    1 Query  select * from sc

Salin selepas log masuk

二、慢查询日志
顾名思义,慢查询日志中记录的是执行时间较长的query,也就是我们常说的slow query,通过设--log-slow-queries[=file_name]来打开该功能并设置记录位置和文件名,默认文件名为hostname-slow.log,默认目录也是数据目录。
慢查询日志采用的是简单的文本格式,可以通过各种文本编辑器查看其中的内容。其中记录了语句执行的时刻,执行所消耗的时间,执行用户,连接主机等相关信息。MySQL还提供了专门用来分析满查询日志的工具程序mysqlslowdump,用来帮助数据库管理人员解决可能存在的性能问题。

----使用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
Salin selepas log masuk

Starting MySQL....                     [ OK ]
Salin selepas log masuk
Salin selepas log masuk

----查看err日志的信息


[root@node4 data]# tail -f /tmp/mysql3306.err 

Salin selepas log masuk

02:26:28 mysqld_safe Starting mysqld daemon with databases from /opt/mysql5.5/data
 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.
 2:26:28 [Warning] You need to use --log-bin to make --binlog-format work.
 2:26:28 InnoDB: The InnoDB memory heap is disabled
 2:26:28 InnoDB: Mutexes and rw_locks use InnoDB's own implementation
 2:26:28 InnoDB: Compressed tables use zlib 1.2.3
 2:26:28 InnoDB: Initializing buffer pool, size = 128.0M
 2:26:28 InnoDB: Completed initialization of buffer pool
 2:26:28 InnoDB: highest supported file format is Barracuda.
 2:26:28 InnoDB: Waiting for the background threads to start
 2:26:30 InnoDB: 1.1.8 started; log sequence number 3069452
 2:26:30 [Note] Event Scheduler: Loaded 0 events
 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

Salin selepas log masuk

----使用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'
Salin selepas log masuk

slow_query_log = 1
slow_query_log_file = /tmp/mysqlslow.log1

Salin selepas log masuk

[root@node4 ~]# service mysql start
Salin selepas log masuk

Starting MySQL...                     [ OK ]
Salin selepas log masuk
Salin selepas log masuk

[root@node4 ~]# mysql
Salin selepas log masuk

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.

Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

mysql> show variables like '%slow%';

Salin selepas log masuk

+---------------------+---------------------+
| Variable_name    | Value        |
+---------------------+---------------------+
| log_slow_queries  | ON         |
| slow_launch_time  | 10          |
| slow_query_log   | ON         |
| slow_query_log_file | /tmp/mysqlslow.log1 |
+---------------------+---------------------+
rows in set (0.00 sec)

Salin selepas log masuk

----关于slow_launch_time参数,首先修改一下参数值
mysql> set global long_query_time=1;
Salin selepas log masuk

Query OK, 0 rows affected (0.00 sec)
Salin selepas log masuk

mysql> show variables like '%long_query%';
Salin selepas log masuk

+-----------------+----------+
| Variable_name  | Value  |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
row in set (0.00 sec)

Salin selepas log masuk

----进行一下相关操作,查看/tmp/mysqlslow.log1的内容

mysql> select database();
Salin selepas log masuk

+------------+
| database() |
+------------+
| NULL    |
+------------+
row in set (0.00 sec)

Salin selepas log masuk

mysql> use test;
Salin selepas log masuk
Salin selepas log masuk

Database changed
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

mysql> show tables;
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

Empty set (0.00 sec)

Salin selepas log masuk
Salin selepas log masuk

mysql> create table t as select * from information_schema.tables;
Salin selepas log masuk

Query OK, 85 rows affected (0.38 sec)
Records: 85 Duplicates: 0 Warnings: 0

Salin selepas log masuk

mysql> insert into t select * from t;
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

Query OK, 85 rows affected (0.05 sec)
Records: 85 Duplicates: 0 Warnings: 0

Salin selepas log masuk

mysql> insert into t select * from t;
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

Query OK, 170 rows affected (0.03 sec)
Records: 170 Duplicates: 0 Warnings: 0

Salin selepas log masuk

mysql> insert into t select * from t;
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

Query OK, 340 rows affected (0.05 sec)
Records: 340 Duplicates: 0 Warnings: 0

Salin selepas log masuk

mysql> insert into t select * from t;
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

Query OK, 680 rows affected (0.08 sec)
Records: 680 Duplicates: 0 Warnings: 0

Salin selepas log masuk

mysql> insert into t select * from t;
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

Query OK, 1360 rows affected (0.29 sec)
Records: 1360 Duplicates: 0 Warnings: 0

Salin selepas log masuk

mysql> insert into t select * from t;
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk
Salin selepas log masuk

Query OK, 2720 rows affected (1.49 sec)
Records: 2720 Duplicates: 0 Warnings: 0

----在这里已经超过1s了,查看/tmp/mysqlslow.log1

Salin selepas log masuk

[root@node4 data]# tail -f /tmp/mysqlslow.log1
Salin selepas log masuk

# 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参数实验

Salin selepas log masuk

mysql> show variables like '%indexes%';
Salin selepas log masuk
Salin selepas log masuk

+-------------------------------+-------+
| Variable_name         | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | OFF  |
+-------------------------------+-------+
row in set (0.00 sec)

Salin selepas log masuk

mysql> set log_queries_not_using_indexes = 1;
Salin selepas log masuk

ERROR 1229 (HY000): Variable 'log_queries_not_using_indexes' is a GLOBAL variable and should be set with SET GLOBAL
Salin selepas log masuk

mysql> set global log_queries_not_using_indexes = 1;
Salin selepas log masuk

Query OK, 0 rows affected (0.01 sec)

Salin selepas log masuk

mysql> show variables like '%indexes%';
Salin selepas log masuk
Salin selepas log masuk

+-------------------------------+-------+
| Variable_name         | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | ON  |
+-------------------------------+-------+
row in set (0.00 sec)

Salin selepas log masuk

mysql> desc t;
Salin selepas log masuk

+-----------------+---------------------+------+-----+---------+-------+
| 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  |   |     |    |
+-----------------+---------------------+------+-----+---------+-------+
rows in set (0.05 sec)
Salin selepas log masuk

----下面的命令是查看索引的
mysql> show index from t;
Salin selepas log masuk

Empty set (0.01 sec)

Salin selepas log masuk

mysql> select * from t where engine='xxx';
Salin selepas log masuk

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';

Salin selepas log masuk

PS:slow query log相关变量

命令行参数:

--log-slow-queries

指定日志文件存放位置,可以为空,系统会给一个缺省的文件host_name-slow.log

系统变量

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,可以根据情况决定是否开启

三、Mysqldumpslow

如果日志内容很多,用眼睛一条一条看会累死,mysql自带了分析的工具,使用方法如下:

[root@node4 data]# mysqldumpslow --help
Salin selepas log masuk

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
Salin selepas log masuk

Label berkaitan:
sumber:php.cn
Kenyataan Laman Web ini
Kandungan artikel ini disumbangkan secara sukarela oleh netizen, dan hak cipta adalah milik pengarang asal. Laman web ini tidak memikul tanggungjawab undang-undang yang sepadan. Jika anda menemui sebarang kandungan yang disyaki plagiarisme atau pelanggaran, sila hubungi admin@php.cn
Tutorial Popular
Lagi>
Muat turun terkini
Lagi>
kesan web
Kod sumber laman web
Bahan laman web
Templat hujung hadapan