慢查询日志
MySQL的慢查询日志是MySQL提供的一种日志记录，它用来记录在MySQL中响应时间超过阀值的语句，具体指运行时间超过long_query_time值的SQL，则会被记录到慢查询日志中。
慢查询sql具体指运行时间超过long_query_time（阀值）值的SQL，则会被记录到慢查询日志中。long_query_time的默认值为10，意思是运行10秒以上的语句。
由他来查看哪些SQL超出了我们的最大忍耐时间值，比如一条sql执行超过5秒钟，我们就算慢SQL，希望能收集超过5秒的sql，结合之前explain进行全面分析。
如何操作
默认情况下，MySQL数据库没有开启慢查询日速，需要我们手动来设置这个参数。
当然，如果不是调优需要的话，一般不建议启动该参数，因为开启慢查询日志会或多或少带来一定的性能影响。慢查询日志支持将日志记录写入文件。
查看是否开启及如何开启
查看是否开启
SHOW VARIABLES LIKE '%slow_query_log%';
AI 代码解读
开启慢查询日志，如果MySQL重启后则会失效。
set global slow_query_log=1;
AI 代码解读
注意：慢查询日志影响效率，因此不建议一直开启。
永久开启慢查询日志
修改my.cnf文件，[mysqld]下增加修改
slow_query_log =1 slow_query_log_file=/var/lib/mysqatguigu-slow.logAI 代码解读
慢查询日志位置
show variables like '%slow_query_log_file%';
AI 代码解读
设置慢sql记录的阀值
SHOW VARIABLES LIKE 'long_query_time%';
AI 代码解读
set global long_query_time=3;
AI 代码解读
注意：需要重新开一个bash/cmd，不然阀值还是10
**案例：
模仿慢sql，让慢查询日志记录**
select sleep(5);
AI 代码解读
show variables like '%slow_query_log_file%';
AI 代码解读
查看慢查询日志文件
可以看到test数据库中，哪一时间，出现了慢sql
查询当前系统中有多少条慢查询记录
mysql> show global status like 'Slow_queries';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries | 1 |
+---------------+-------+
1 row in set (0.00 sec)
AI 代码解读
慢查询日志分析工具mysqldumpslow
在生产环境中，可以使用MySQL提供的日志分析工具mysqldumpslow。
查看mysqldumpslow的帮助信息，mysqldumpslow --help。
s：是表示按照何种方式排序
c：访问次数
l：锁定时间
r：返回记录
t：查询时间
al：平均锁定时间
ar：平均返回记录数
at：平均查询时间
t：即为返回前面多少条的数据
g：后边搭配一个正则匹配模式，大小写不敏感的
常用mysqldumpslow命令
linux中慢查询日志文件 /var/lib/mysql/xiaoxuya-slow.log
- 得到返回记录集最多的10个SQL
mysqldumpslow -s r -t 10 /var/lib/mysql/xiaoxuya-slow.log
- 得到访问次数最多的10个SQL
mysqldumpslow -s c -t 10 /var/lib/mysql/xiaoxuya-slow.log
- 得到按照时间排序的前10条里面含有左连接的查询语句
mysqldumpslow -s t -t 10 -g "left join" /var/lib/mysql/xiaoxuya-slow.log
- 另外建议在使用这些命令时结合│和more 使用，否则有可能出现爆屏情况
mysqldumpslow -s r-t 10 /ar/lib/mysql/xiaoxuya-slow.log | more
注意：提取到慢sql之后，可以使用explain/show profile 对sql进行分析优化
show profile进行sql分析
准备50万数据
1、创建对应库和表
create database bigData;
use bigData;
CREATE TABLE dept(
id INT UNSIGNED PRIMARY KEY AUTO_INCREMENT,
deptno MEDIUMINT UNSIGNED NOT NULL DEFAULT 0,
dname VARCHAR(20)NOT NULL DEFAULT "",
loc VARCHAR(13) NOT NULL DEFAULT ""
)ENGINE=INNODB DEFAULT CHARSET=utf8;
CREATE TABLE emp(
id int unsigned primary key auto_increment,
empno mediumint unsigned not null default 0,
ename varchar(20) not null default "",
job varchar(9) not null default "",
mgr mediumint unsigned not null default 0,
hiredate date not null,
sal decimal(7,2) not null,
comm decimal(7,2) not null,
deptno mediumint unsigned not null default 0
)ENGINE=INNODB DEFAULT CHARSET=utf8;
AI 代码解读
2、设置参数log_bin_trust_function_creators
show variables like 'log_bin_trust_function_creators';
set global log_bin_trust_function_creators=1;
AI 代码解读
由于开启过慢查询日志，因为我们开启了bin-log，我们就必须为我们的function指定一个参数。不然会报This function has none of DETERMINISTIC
3、创建函数 和 存储过程
3.1、随机字符串函数
delimiter $$
create function rand_string(n int) returns varchar(255)
begin
declare chars_str varchar(100) default 'abcdefghijklmnopqrstuvwxyz';
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 $$
AI 代码解读
delimiter $$ 意为设置界限符，以 $ $结束的意思
3.2 随机产生部门编号函数
delimiter $$
create function rand_num() returns int(5)
begin
declare i int default 0;
set i=floor(100+rand()*10);
return i;
end $$
AI 代码解读
函数记得要先执行，因为存储过程需要使用
3.3、创建往emp表中插入数据的存储过程
delimiter $$
create procedure insert_emp(in start int(10),in max_num int(10))
begin
declare i int default 0;
set autocommit = 0;
repeat
set i = i+1;
insert into emp(empno,ename,job,mgr,hiredate,sal,comm,deptno) values((start+i),rand_string(6),'salesman',0001,curdate(),2000,400,rand_num());
until i=max_num
end repeat;
commit;
end $$
AI 代码解读
3.4、创建往dept表中插入数据的存储过程
delimiter $$
create procedure insert_dept(in start int(10),in max_num int(10))
begin
declare i int default 0;
set autocommit = 0;
repeat
set i = i+1;
insert into dept(deptno,dname,loc) values((start+i),rand_string(10),rand_string(8));
until i=max_num
end repeat;
commit;
end $$
AI 代码解读
4、插入数据，调用存储过程
往部门表插入10条数据
mysql> CALL insert_dept(100, 10);
AI 代码解读
往员工表插入50万条数据
mysql> CALL insert_emp(100001, 500000);
AI 代码解读
注意：不要使用可视化软件插入数据，慢！
6、结果
show profile 分析步骤
1、查看当前mysql版本是否支持profile分析，
mysql> show variables like 'profiling';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling | OFF |
+---------------+-------+
1 row in set, 1 warning (0.00 sec)
AI 代码解读
2、开启profiling
mysql> set profiling = 1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
mysql> show variables like 'profiling';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling | ON |
+---------------+-------+
1 row in set, 1 warning (0.00 sec)
AI 代码解读
3、执行sql
select count(e.deptno) number , e.deptno from emp e
left join dept d
on e.deptno = d.deptno
group by e.deptno
order by e.deptno;
AI 代码解读
结果：
mysql> select count(e.deptno) number , e.deptno from emp e left join dept d on e.deptno = d.deptno group by e.deptno order by e.deptno;
+--------+--------+
| number | deptno |
+--------+--------+
| 50113 | 100 |
| 50433 | 101 |
| 50018 | 102 |
| 49803 | 103 |
| 49803 | 104 |
| 50106 | 105 |
| 49949 | 106 |
| 49855 | 107 |
| 50005 | 108 |
| 49915 | 109 |
+--------+--------+
10 rows in set (0.47 sec)
AI 代码解读
explain结果分析
mysql> explain select count(e.deptno) number , e.deptno from emp e left join dept d on e.deptno = d.deptno group by e.deptno order by e.deptno;
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------------+
| 1 | SIMPLE | e | NULL | ALL | NULL | NULL | NULL | NULL | 498620 | 100.00 | Using temporary; Using filesort |
| 1 | SIMPLE | d | NULL | ALL | NULL | NULL | NULL | NULL | 10 | 100.00 | Using where; Using join buffer (Block Nested Loop) |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------------+
2 rows in set, 1 warning (0.00 sec)
AI 代码解读
产生了临时表，文件内排序
4、 show profiles获取sql列表
mysql> show profiles;
+----------+------------+-------------------------------------------------------------------------------------------------------------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+-------------------------------------------------------------------------------------------------------------------------------------------+
| 8 | 0.00013875 | set long_query_time = 2 |
| 9 | 0.00244625 | show variables like 'long_query_time' |
| 10 | 0.00184675 | show variables like 'profiling' |
| 11 | 0.00035400 | explain select * from emp group by id%10 limit 150000 |
| 12 | 0.00042575 | explain select id from emp group by id%10 limit 150000 |
| 13 | 0.00050400 | select * from emp limit 10 |
| 14 | 0.16561600 | select deptno from emp group by deptno |
| 15 | 0.00079050 | explain select deptno from emp group by deptno |
| 16 | 0.31239600 | select count(deptno) number , deptno from emp group by deptno |
| 17 | 0.00035800 | explain select count(deptno) number , deptno from emp group by deptno |
| 18 | 0.00059450 | select * from emp limit 10 |
| 19 | 0.00127075 | select * from dept limit 10 |
| 20 | 0.00418550 | select * from emp e left join dept d on e.deptno = d.deptno limit 20 |
| 21 | 0.47500125 | select count(e.deptno) number , e.deptno from emp e left join dept d on e.deptno = d.deptno group by e.deptno order by e.deptno |
| 22 | 0.00038550 | explain select count(e.deptno) number , e.deptno from emp e left join dept d on e.deptno = d.deptno group by e.deptno order by e.deptno |
+----------+------------+-------------------------------------------------------------------------------------------------------------------------------------------+
15 rows in set, 1 warning (0.00 sec)
AI 代码解读
5、诊断SQL，show profile cpu,block io for query sqlQuery_ID;
我们选取执行时间最长的sql，查看其执行步骤
mysql> show profile cpu,block io for query 21;
+--------------------------------+----------+----------+------------+--------------+---------------+
| Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+--------------------------------+----------+----------+------------+--------------+---------------+
| starting | 0.000078 | 0.000000 | 0.000000 | NULL | NULL |
| Executing hook on transaction | 0.000003 | 0.000000 | 0.000000 | NULL | NULL |
| starting | 0.000004 | 0.000000 | 0.000000 | NULL | NULL |
| checking permissions | 0.000002 | 0.000000 | 0.000000 | NULL | NULL |
| checking permissions | 0.000003 | 0.000000 | 0.000000 | NULL | NULL |
| Opening tables | 0.000037 | 0.000000 | 0.000000 | NULL | NULL |
| init | 0.000004 | 0.000000 | 0.000000 | NULL | NULL |
| System lock | 0.000007 | 0.000000 | 0.000000 | NULL | NULL |
| optimizing | 0.000008 | 0.000000 | 0.000000 | NULL | NULL |
| statistics | 0.000017 | 0.000000 | 0.000000 | NULL | NULL |
| preparing | 0.000028 | 0.000000 | 0.000000 | NULL | NULL |
| Creating tmp table | 0.000058 | 0.000000 | 0.000000 | NULL | NULL |
| Sorting result | 0.000012 | 0.000000 | 0.000000 | NULL | NULL |
| executing | 0.000002 | 0.000000 | 0.000000 | NULL | NULL |
| Sending data | 0.474489 | 0.484375 | 0.000000 | NULL | NULL |
| Creating sort index | 0.000108 | 0.000000 | 0.000000 | NULL | NULL |
| end | 0.000004 | 0.000000 | 0.000000 | NULL | NULL |
| query end | 0.000003 | 0.000000 | 0.000000 | NULL | NULL |
| waiting for handler commit | 0.000013 | 0.000000 | 0.000000 | NULL | NULL |
| removing tmp table | 0.000008 | 0.000000 | 0.000000 | NULL | NULL |
| waiting for handler commit | 0.000003 | 0.000000 | 0.000000 | NULL | NULL |
| closing tables | 0.000008 | 0.000000 | 0.000000 | NULL | NULL |
| freeing items | 0.000087 | 0.000000 | 0.000000 | NULL | NULL |
| cleaning up | 0.000019 | 0.000000 | 0.000000 | NULL | NULL |
+--------------------------------+----------+----------+------------+--------------+---------------+
24 rows in set, 1 warning (0.00 sec)
AI 代码解读
可以看到，创建临时表（create tmp table ），发送数据（send data），创建排序索引，以及释放空间，最耗时，特别是数据量特别大的情况下
这也是为什么，我们要创建索引，一旦为group by ， order by 对应列 创建索引，可以免去创建临时表，和文件内排序（filesort）
我们在来看一个例子：
mysql> select e.deptno from emp e group by e.deptno order by e.deptno ;
+--------+
| deptno |
+--------+
| 100 |
| 101 |
| 102 |
| 103 |
| 104 |
| 105 |
| 106 |
| 107 |
| 108 |
| 109 |
+--------+
10 rows in set (0.16 sec)
AI 代码解读
mysql> explain select e.deptno from emp e group by e.deptno order by e.deptno ;
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+---------------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+---------------------------------+
| 1 | SIMPLE | e | NULL | ALL | NULL | NULL | NULL | NULL | 498620 | 100.00 | Using temporary; Using filesort |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+---------------------------------+
1 row in set, 1 warning (0.00 sec)
AI 代码解读
产生了filesort，temporary
sql诊断分析
mysql> show profile cpu , block io for query 41;
+--------------------------------+----------+----------+------------+--------------+---------------+
| Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+--------------------------------+----------+----------+------------+--------------+---------------+
| starting | 0.000055 | 0.000000 | 0.000000 | NULL | NULL |
| Executing hook on transaction | 0.000003 | 0.000000 | 0.000000 | NULL | NULL |
| starting | 0.000005 | 0.000000 | 0.000000 | NULL | NULL |
| checking permissions | 0.000003 | 0.000000 | 0.000000 | NULL | NULL |
| Opening tables | 0.000042 | 0.000000 | 0.000000 | NULL | NULL |
| init | 0.000004 | 0.000000 | 0.000000 | NULL | NULL |
| System lock | 0.000006 | 0.000000 | 0.000000 | NULL | NULL |
| optimizing | 0.000038 | 0.000000 | 0.000000 | NULL | NULL |
| statistics | 0.000013 | 0.000000 | 0.000000 | NULL | NULL |
| preparing | 0.000008 | 0.000000 | 0.000000 | NULL | NULL |
| Creating tmp table | 0.000056 | 0.000000 | 0.000000 | NULL | NULL |
| Sorting result | 0.000007 | 0.000000 | 0.000000 | NULL | NULL |
| executing | 0.000001 | 0.000000 | 0.000000 | NULL | NULL |
| Sending data | 0.000005 | 0.000000 | 0.000000 | NULL | NULL |
| Creating sort index | 0.158347 | 0.156250 | 0.000000 | NULL | NULL |
| end | 0.000009 | 0.000000 | 0.000000 | NULL | NULL |
| query end | 0.000003 | 0.000000 | 0.000000 | NULL | NULL |
| waiting for handler commit | 0.000009 | 0.000000 | 0.000000 | NULL | NULL |
| removing tmp table | 0.000008 | 0.000000 | 0.000000 | NULL | NULL |
| waiting for handler commit | 0.000002 | 0.000000 | 0.000000 | NULL | NULL |
| closing tables | 0.000007 | 0.000000 | 0.000000 | NULL | NULL |
| freeing items | 0.000067 | 0.000000 | 0.000000 | NULL | NULL |
| cleaning up | 0.000037 | 0.000000 | 0.000000 | NULL | NULL |
+--------------------------------+----------+----------+------------+--------------+---------------+
23 rows in set, 1 warning (0.00 sec)
AI 代码解读
sql优化
mysql> create index idx_emp_deptno on emp(deptno);
Query OK, 0 rows affected (3.17 sec)
Records: 0 Duplicates: 0 Warnings: 0
AI 代码解读
explain分析优化后的sql
mysql> explain select e.deptno from emp e group by e.deptno order by e.deptno ;
+----+-------------+-------+------------+-------+----------------+----------------+---------+------+------+----------+--------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+-------+----------------+----------------+---------+------+------+----------+--------------------------+
| 1 | SIMPLE | e | NULL | range | idx_emp_deptno | idx_emp_deptno | 3 | NULL | 10 | 100.00 | Using index for group-by |
+----+-------------+-------+------------+-------+----------------+----------------+---------+------+------+----------+--------------------------+
1 row in set, 1 warning (0.00 sec)
AI 代码解读
show profile分析优化后的sql
可以看到产生临时表，和filesort没有了，取而代之的index，执行时间也变快了。
show profile参数备注
ALL：显示所有的开销信息。
BLOCK IO：显示块lO相关开销。
CONTEXT SWITCHES ：上下文切换相关开销。
CPU：显示CPU相关开销信息。
IPC：显示发送和接收相关开销信息。
MEMORY：显示内存相关开销信息。
PAGE FAULTS：显示页面错误相关开销信息。
SOURCE：显示和Source_function，Source_file，Source_line相关的开销信息。
SWAPS：显示交换次数相关开销的信息。
日常开发需要注意的结论
- converting HEAP to MyISAM 查询结果太大，内存都不够用了往磁盘上搬了。
- Creating tmp table 创建临时表，拷贝数据到临时表，用完再删除
- Copying to tmp table on disk 把内存中临时表复制到磁盘，危险!
locked
