MySQL——慢查询日志分析
MySQL的慢查询日志是MySQL提供的一种日志记录，它用来记录在MySQL中响应时间超过阀值的语句，具体指运行时间超过long_query_time值的SQL，则会被记录到慢查询日志中。long_query_time的默认值为10。
通过慢查询日志，可以查找出哪些查询语句的执行效率低，以便进行优化。
如果不是调优需要的话，一般不建议启动该参数，因为开启慢查询日志会或多或少带来一定的性能影响。
long_query_time的默认值为10
mysql> SHOW VARIABLES LIKE 'long_query_time';
+
| Variable_name | Value |
+
| long_query_time | 10.000000 |
+
1 row in set (0.00 sec)
1、启动和设置慢查询日志
查看是否开启慢查询日志功能
- slow_query_log：慢查询开启状态
- slow_query_log_file：慢查询日志存放的位置（一般设置为 MySQL 的数据存放目录）
mysql> SHOW VARIABLES LIKE 'slow_query%';
+
| Variable_name | Value |
+
| slow_query_log | OFF |
| slow_query_log_file | /data/mysql/CHENG-slow.log |
+
2 rows in set (0.00 sec)
开启慢查询日志功能
方式一：配置文件开启(永久有效)
将 log_slow_queries 选项和 long_query_time 选项加入到配置文件的 [mysqld] 组中。格式如下：
[mysqld]
show_query_log=on/off # 开启或关闭
log-slow-queries=dir/filename
long_query_time=n
log_output=file
其中：
- dir 参数指定慢查询日志的存储路径，如果不指定存储路径，慢查询日志将默认存储到 MySQL 数据库的数据文件夹下。
- filename 参数指定日志的文件名，生成日志文件的完整名称为 filename-slow.log。 如果不指定文件名，默认文件名为 hostname-slow.log，hostname 是 MySQL 服务器的主机名。
- “n”参数是设定的时间值，该值的单位是秒。如果不设置 long_query_time 选项，默认时间为 10 秒。
方式二：命令开启慢查询日志
SET GLOBAL slow_query_log=on/off;
SET GLOBAL long_query_time=1;
SET long_query_time=1;
2、数据准备
1、建表
create table student(
id int(11) not null auto_increment,
stuno int not null ,
name varchar(20) default null,
age int(3) default null,
classID int(11) default null,
primary key (id)
)engine=innodb auto_increment=1 default charset=utf8;
2、创建函数：
开启创建函数：
set global log_bin_trust_function_creators = 1;
函数一：随机生成字符串函数
delimiter
create function rand_string(n int)
returns varchar(255)
begin
declare chars_str varchar(100) default
'abcdefghijklmnopqrstuvwsyzABCDEFGJHIKLMNOPQRSTUVWSYZ';
declare return_str varchar(255) default '';
declare i int default 0;
while i < n do
set return_str = concat(return_str,substring(chars_str,floor(1+rand()*52),1));
set i = i + 1;
end while ;
return return_str;
end
delimiter ;
函数二：随机数生成函数
delimiter
create function rand_num(from_num int , to_num int) returns int(11)
begin
declare i int default 0;
set i = floor(from_num+rand()*(to_num - from_num + 1));
return i;
end
delimiter ;
3、创建存储过程
delimiter
create procedure insert_stu1(start int,max_num int)
begin
declare i int default 0;
set autocommit = 0;
repeat
set i = i + 1;
insert into student(stuno, name,age,classID) VALUES
((start+1),rand_string(6),rand_num(10,100),rand_num(10,1000));
until i = max_num
end repeat ;
commit;
end
delimiter ;
4、调用存储过程
call insert_stu1(100001,4000000);
5、查看数据添加结果
mysql> select count(*) from student;
+
| count(*) |
+
| 4000000 |
+
1 row in set (1.40 sec)
6、查看记录到慢查询日志中的sql数量
mysql> show status like 'slow_queries';
+
| Variable_name | Value |
+
| Slow_queries | 1 |
+
1 row in set (0.01 sec)
3、慢查询日志分析工具：mysqldumpslow
mysqldumpslow 是MySQL提供的日志分析工具，用于帮我们分析日志，查找、分析SQL。
查看mysqldumpslow的用法
[root@CHENG bin]
Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]
Parse and summarize the MySQL slow query log. Options are
-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
- -s 是order的顺序
- al 平均锁定时间
- ar 平均返回记录时间
- at 平均查询时间（默认）
- c 计数
- 锁定时间
- r 返回记录
- t 查询时间
- -t 是top n的意思，即为返回前面多少条的数据
- -g 后边可以写一个正则匹配模式，大小写不敏感的
解决 bash: mysqldumpslow: command not found
这个错误是因为 mysqldumpslow不在/usr/bin下面，我们需要找到 mysqldumpslow （一般是在mysql的安装目录下）安装目录，然后做一个软链接到/usr/bin下。我的mysqldumpslow路径为 /usr/local/mysql/bin
ln -s /usr/local/mysql/bin/mysqldumpslow /usr/bin
mysqldumpslow 的使用
[root@CHENG mysql]
Reading mysql slow query log from /data/mysql/CHENG-slow.log
Count: 1 Time=356.29s (356s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@[58.242.191.115]
/* ApplicationName=DataGrip 2021.1 */ call insert_stu1(100001,4000000)
Count: 1 Time=1.39s (1s) Lock=0.00s (0s) Rows=1.0 (1), root[root]@localhost
select count(*) from student
Died at /usr/bin/mysqldumpslow line 167, <> chunk 2.
4、删除慢查询日志
慢查询日志的删除方法与通用日志的删除方法是一样的。可以使用 mysqladmin 命令来删除。也可以使用手工方式（rm -rf）来删除。mysqladmin 命令的语法如下：mysqladmin 命令会重新生成查询日志文件
mysqladmin -uroot -p flush-logs slow
执行该命令后，命令行会提示输入密码。输入正确密码后，将执行删除操作。新的慢查询日志会直接覆盖旧的查询日志，不需要再手动删除。
数据库管理员也可以手工删除慢查询日志，删除之后需要重新启动 MySQL 服务。
注意：通用查询日志和慢查询日志都是使用这个命令，使用时一定要注意，一旦执行这个命令，通用查询日志和慢查询日志都只存在新的日志文件中。如果需要备份旧的慢查询日志文件，必须先将旧的日志改名，然后重启 MySQL 服务或执行 mysqladmin 命令。
5、show profile
Show Profile是MysQL提供的可以用来分析当前会话中sQL都做了什么、执行的资源消耗情况的工具，可用于sqt调优的测量。默认情况下处于关闭状态，并保存最近15次的运行结果。|
查看show profile是否开启
mysql> show variables like 'profiling';
+
| Variable_name | Value |
+
| profiling | OFF |
+
1 row in set (0.00 sec)
开启 show profile
mysql> set profiling = 'ON';
Query OK, 0 rows affected, 1 warning (0.00 sec)
mysql> show variables like 'profiling';
+
| Variable_name | Value |
+
| profiling | ON |
+
1 row in set (0.02 sec)
查看当前会话都有哪些 profiles
mysql> show profiles;
+
| Query_ID | Duration | Query |
+
| 1 | 0.02887100 | show variables like 'profiling' |
| 2 | 0.00010500 | select * from student where stuno = 1234567 |
| 3 | 0.00062425 | show databases |
| 4 | 0.00016825 | SELECT DATABASE() |
| 5 | 0.00034500 | show databases |
| 6 | 0.01144500 | show tables |
| 7 | 2.41117450 | select * from student where stuno = 1234567 |
| 8 | 1.27697000 | select * from student where stuno = 1231234 |
| 9 | 1.33853225 | select * from student where stuno = 3453451 |
| 10 | 0.00023825 | show create table student |
| 11 | 0.00043500 | select * from student where id = 1231231 |
| 12 | 1.23249650 | select * from student where classID = 1231231 |
| 13 | 1.29235175 | select * from student where classID = 1000000 |
| 14 | 1.45108200 | select * from student where name = 'jnoefp' |
+
14 rows in set, 1 warning (0.00 sec)
查看最近的一次查询的开销
mysql> show profile;
+
| Status | Duration |
+
| starting | 0.000093 |
| checking permissions | 0.000009 |
| Opening tables | 0.000022 |
| init | 0.000033 |
| System lock | 0.000011 |
| optimizing | 0.000020 |
| statistics | 0.000022 |
| preparing | 0.000016 |
| executing | 0.000004 |
| Sending data | 1.437393 |
| end | 0.000027 |
| query end | 0.000013 |
| closing tables | 0.000013 |
| freeing items | 0.000679 |
| cleaning up | 0.012730 |
+
15 rows in set, 1 warning (0.00 sec)
查看指定查询的开销
查询Query_ID为3的开销：
mysql> show profile for query 3;
+
| Status | Duration |
+
| starting | 0.000114 |
| checking permissions | 0.000011 |
| Opening tables | 0.000050 |
| init | 0.000014 |
| System lock | 0.000008 |
| optimizing | 0.000007 |
| statistics | 0.000015 |
| preparing | 0.000016 |
| executing | 0.000314 |
| Sending data | 0.000019 |
| end | 0.000005 |
| query end | 0.000008 |
| closing tables | 0.000004 |
| removing tmp table | 0.000007 |
| closing tables | 0.000005 |
| freeing items | 0.000015 |
| cleaning up | 0.000015 |
+
17 rows in set, 1 warning (0.00 sec)
show profile的常用查询参数
- ALL:显示所有的开销信息。
- BLOCK IO:显示块IO开销。
- CONTEXT SWITCHES: 上下文切换开销。
- CPU:显示CPU开销信息。
- IPC:显示发送和接收开销信息。
- MEMORY:显示内存开销信息。
- PAGE FAULTS:显示页面错误开销信息。
- SOURCE:显示和Source_function，Source_file，Source_line相关的开销信息。
- SWAPS:显示交换次数开销信息。
|