8. 慢SQL分析篇

慢查询日志

认识慢查询

mysql 的慢查询是 mysql 提供的一种日志记录，他用来记录 mysql 在执行时长超过设置的阀值的语句。而这个超时时长是可配置的，默认的超时时长是 10s，然后写到日志中。再结合 explain 进行分析 sql。

默认情况下，mysql 数据库没有开启慢查询日志，需要手动来设置这个参数。如果不是调优需要的话，一般不建议启动该参数，因为开启慢查询日志会或多或少带来一定的性能影响。

临时开启

show variables like '%slow_query_log%';

使用以上语句查询是否开启了慢查询，并且记录慢 sql 的日志位置。下图 slow_query_log：OFF 表示关闭。

使用这个语句开启慢查询日志（0关闭 1开启），只会对当前数据库生效。并且如果 mysql 重启后则会失效。

SET GLOBAL slow_query_log = 1;

再次查询发现已经开启了

永久开启

这种东西没必要一直开启，如果要永久生效需要修改配置文件 my.cnf 。在 my.cnf 文件增加或修改如下参数：

slow_query_log = 1
slow_query_log_file = /var/lib/mysql/[host_name]-slow.log

slow_query_log_file 指定慢查询日志文件存放路径。系统默认会给一个缺省的文件 host_name-slow.log

设置慢sql时长

mysql 默认的 SQL 执行超时时长为10s，通过如下命令修改：

-- 查询超时时长
show variables like '%long_query_time%';

-- 设置超时时长
set global long_query_time = 3;

设置完后重新使用客户端连接下 mysql。

查看mysql日志

– 模拟生成超时的日志

SELECT SLEEP(4);

找到慢sql日志文件

日志分析工具

如果在生产环境中，经常手工 查找、分析日志是个体力活，Mysql 提供了日志分析工具 mysqldumpslow。

分析参数：
s：表示按照何种方式排序
c：访问次数
l：锁定时间
r：返回记录
t：查询时间
al：平均锁定时间
ar：平均返回记录数
at：平均查询时间
t：返回前面多少条的数据
g：后面搭配一个正则匹配模式，大小写不敏感。
查询返回记录最多的10个SQL

常用的查询示例：

-- 返回记录集最多的10个sql
mysqldumpslow -s r -t 10 /var/lib/mysql/localhost-slow.log

-- 访问次数最多的 10  个sql
mysqldumpslow -s c -t 10 /var/lib/mysql/localhost-slow.log

-- 得到安装时间排序的前10条里面含有左连接的查询语句
mysqldumpslow -s t -t 10 -g "join" /var/lib/mysql/localhost-slow.log

-- 建议在使用这些命令时结合 | 和 more 使用，否则有可能出现屏幕一直刷贼多的情况
mysqldumpslow -s r -t 10 /var/lib/mysql/localhost-slow.log

show profile 分析 sql

增加测试数据，创建 2 张表，并模拟测试插入数据

CREATE TABLE dept
(
	id INT PRIMARY KEY AUTO_INCREMENT,
	deptno MEDIUMINT NOT NULL DEFAULT 0,
	dname VARCHAR(20) NOT NULL DEFAULT '',
	loc  VARCHAR(13) NOT NULL DEFAULT ''
);

CREATE TABLE emp
(
	id INT PRIMARY KEY AUTO_INCREMENT,
	empno  MEDIUMINT NOT NULL DEFAULT 0, -- 编号
	ename VARCHAR(20) NOT NULL DEFAULT '',	-- 名字	
	job  VARCHAR(9) NOT NULL DEFAULT '',	-- 工作
	mgr  MEDIUMINT NOT NULL DEFAULT 0, 	-- 上级编号
	hiredate DATE NOT NULL,			-- 日子时间
	sal DECIMAL(7, 2) NOT NULL,		-- 薪水
	comm DECIMAL(7, 2) NOT NULL,		-- 红利
	deptno MEDIUMINT NOT NULL DEFAULT 0	-- 部门编号
);


/**
	会报 This function has none of DETERMINISTIC, NO SQL, or READS SQL DATA in its declaration and binary logging is enabled (you *might* want to use the less safe log_bin_trust_function_creators variable)
	需要开启 bin-log ，执行以下：
		show variables like 'log_bin_trust_function_creators';	-- 查询是否开启了
		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 'qwertyuiopasdfghjklzxcvbnm';
	DECLARE return_str VARCHAR(100) DEFAULT '';
	DECLARE i INT DEFAULT 0;
	
	WHILE i < n DO
		SET return_str = CONCAT( return_str, SUBSTRING( return_str, FLOOR( 1 + RAND() * 52 ), 1 ) );
		SET i = i + 1;
	END WHILE;
	
	RETURN return_str;
END $$


-- 生成随机数
DELIMITER $$
CREATE FUNCTION rand_num() RETURNS INT(5)
BEGIN 
	DECLARE i INT DEFAULT 0;
		SET i = FLOOR( 100 + RAND() * 10 );
	RETURN i;
END$$

-- drop function rand_num;  	-- 删除方法


-- 批量创建数据存储过程
-- 提前将自动提交关闭
SET autocommit = 0;

DELIMITER $$
CREATE PROCEDURE insert_emp( IN START INT(10), IN max_num INT(10) )
BEGIN 
	DECLARE i INT DEFAULT 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 $$



DELIMITER $$
CREATE PROCEDURE insert_dept( IN START INT(10), IN max_num INT(10) )
BEGIN 
	DECLARE i INT DEFAULT 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 $$


-- dept 表添加10条数据
CALL insert_dept( 100, 10 );

-- emp 添加 50w数据
CALL insert_emp( 100001, 500000 );

show profile 是 mysql 提供的可以用来分析当前会话 中 sql 语句执行的资源消耗情况的工具。可以用于 sql 调优时候的测量标准。默认情况下处于关闭状态。并保存最近 15 出的允许结果。开启之后会在后台记录你的 SQL，到分析时候，直接记录里清单中获取sql。

打开 profile

-- 查看是否开启了，默认是关闭
SHOW VARIABLES LIKE 'profiling';

-- 开启（客户端连接工具需要重启）
set global profiling = 1;

测试查询sql

-- id%10 没有特别意义就是让索引失效
SELECT * FROM emp GROUP BY id%10 LIMIT 150000;	-- 0.482s

分析sql执行过程

show profiles;

可以发现有刚才那条sql，
Query_id：查询id，可以使用这个id查看更详细的执行信息。
Duration：执行时长
Query：执行时间

查看某个 Query_id 对应更详细点的信息

-- 执行计划
EXPLAIN SELECT * FROM emp GROUP BY id%10 LIMIT 150000;
-- profile 详细执行信息，最后跟的是对应 Query_id 
SHOW PROFILE cpu, block io FOR QUERY 5;

下图有sql 的执行时候每一步的信息

通过执行计划发现，出现了临时表与外部排序。然后再通过 profile 观察发现，首先通过 Creating tmp table 创建了一个临时表，然后开始执行 Sending data 将数据搬到了临时表，发现贼耗时，然后再排个序，最后将临时表删掉。
可以发现 profile 配个执行计划用着非常好用。

profile 每个参数含义
红色标注的重点关注
①ALL：显示所有的开销信息。
②BLOCK IO：显示块IO开销。
③CONTEXT SWITCHES：上下文切换开销。
④CPU：显示CPU开销信息。
⑤IPC：显示发送和接收开销信息。
⑥MEMORY：显示内存开销信息。
⑦PAGE FAULTS：显示页面错误开销信息。
⑧SOURCE：显示和Source_function，Source_file，Source_line相关的开销信息。
⑨SWAPS：显示交换次数开销信息。

如果在执行的详细信息出现以下信息（上面示例就出现了 Creating tmp table 发现就贼慢了），就需要优化你的SQL了：
①converting HEAP to MyISAM：查询结果太大，内存不够，数据往磁盘上搬了。
②Creating tmp table：创建临时表。先拷贝数据到临时表，用完后再删除临时表。
③Copying to tmp table on disk：把内存中临时表复制到磁盘上，危险！！！
④locked：锁了

开启全局查询日志

全局查询日志用于保存所有的 SQL 执行记录，该功能主要用于测试环境，在生产环境中永远不要开启该功能。

配置启动
在 my.cnf 中修改

# 开启
general_log=1
# 记录日志文件的路径
general_log_file=/path/logfile
# 输出格式
log_output=FILE

编码启动(推荐)

#开启
set global general_log=1;
set global log_output='TABLE';

#此后，所编写的sql语句，将会记录到mysql库里的general_log表，可以用下面的命令查看
select * from mysql.general_log;

此后，你编写的 SQL 语句，将会记录到 MySQL 安装时候就有的一个 mysql 库里的 general_log 表，可使用下面的命令查看

select * from mysql.general_log;

另外附上 performance schema 性能分析：https://www.cnblogs.com/zhoujinyi/p/5236705.html