9-1. MySQL 性能分析工具的使用——last_query_cost,慢查询日志
文章目录
1. 数据库服务器的优化步骤
当我们遇到数据库调优问题的时候,该如何思考呢?这里把思考的流程整理成下面这张图。
整个流程划分成了 观察(Show status)
和 行动(Action)
两个部分。字母 S 的部分代表观察(会使 用相应的分析工具),字母 A 代表的部分是行动(对应分析可以采取的行动)。
2. 查看系统性能参数
在MySQL中,可以使用 SHOW STATUS
语句查询一些MySQL数据库服务器的性能参数 、 执行频率
。 SHOW STATUS语句语法如下:
sql>mysql">SHOW [GLOBAL|SESSION] STATUS LIKE '参数';
一些常用的性能参数如下:
- Connections:连接MySQL服务器的次数。
- Uptime:MySQL服务器的上 线时间。
- Slow_queries:慢查询的次数。
- Innodb_rows_read:Select查询返回的行数
- Innodb_rows_inserted:执行INSERT操作插入的行数
- Innodb_rows_updated:执行UPDATE操作更新的 行数
- Innodb_rows_deleted:执行DELETE操作删除的行数
- Com_select:查询操作的次数。
- Com_insert:插入操作的次数。对于批量插入的 INSERT 操作,只累加一次。
- Com_update:更新操作 的次数。
- Com_delete:删除操作的次数。
举例:
sql>mysql">sql>mysql> show status like 'connections';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Connections | 21 |
+---------------+-------+
1 row in set (0.00 sec)
举例:
sql>mysql">sql>mysql> show status like 'uptime';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Uptime | 28235 |
+---------------+-------+
1 row in set (0.00 sec)
sql>mysql">sql>mysql> show status like 'slow_queries';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries | 0 |
+---------------+-------+
1 row in set (0.00 sec)
sql>mysql">sql>mysql> show status like 'innodb_row_%';
+-------------------------------+---------+
| Variable_name | Value |
+-------------------------------+---------+
| Innodb_row_lock_current_waits | 0 |
| Innodb_row_lock_time | 0 |
| Innodb_row_lock_time_avg | 0 |
| Innodb_row_lock_time_max | 0 |
| Innodb_row_lock_waits | 0 |
| Innodb_rows_deleted | 0 |
| Innodb_rows_inserted | 1000901 |
| Innodb_rows_read | 8001090 |
| Innodb_rows_updated | 0 |
+-------------------------------+---------+
9 rows in set (0.00 sec)
3. 统计SQL的查询成本:last_query_cost
我们依然使用第8章的 student_info 表为例:
sql>mysql">CREATE TABLE `student_info` (
`id` INT(11) NOT NULL AUTO_INCREMENT,
`student_id` INT NOT NULL ,
`name` VARCHAR(20) DEFAULT NULL,
`course_id` INT NOT NULL ,
`class_id` INT(11) DEFAULT NULL,
`create_time` DATETIME DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, PRIMARY KEY (`id`)
) ENGINE=INNODB AUTO_INCREMENT=1 DEFAULT CHARSET=utf8;
如果我们想要查询 id=900001 的记录,然后看下查询成本,我们可以直接在聚簇索引上进行查找:
sql>mysql">sql>mysql> SELECT student_id, class_id, NAME, create_time FROM student_info WHERE id = 900001;
+------------+----------+--------+---------------------+
| student_id | class_id | NAME | create_time |
+------------+----------+--------+---------------------+
| 46284 | 10136 | gUfQOy | 2025-02-13 12:48:08 |
+------------+----------+--------+---------------------+
1 row in set (0.00 sec)
然后再看下查询优化器的成本,实际上我们只需要检索一个页即可:
sql>mysql">sql>mysql> SHOW STATUS LIKE 'last_query_cost';
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| Last_query_cost | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)
如果我们想要查询 id 在 900001 到 9000100 之间的学生记录呢?
sql>mysql">sql>mysql> SELECT student_id, class_id, NAME, create_time FROM student_info WHERE id BETWEEN 900001 AND 900100;
运行结果(100 条记录,运行时间为 0.046s ):
然后再看下查询优化器的成本,这时我们大概需要进行 20 个页的查询。
sql>mysql">sql>mysql> SHOW STATUS LIKE 'last_query_cost';
+-----------------+-----------+
| Variable_name | Value |
+-----------------+-----------+
| Last_query_cost | 20.290412 |
+-----------------+-----------+
1 row in set (0.00 sec)
你能看到页的数量是刚才的 20 倍,但是查询的效率并没有明显的变化,实际上这两个 SQL 查询的时间页基本上一样,就是因为采用了顺序读取
的方式将页面一次性加载到缓冲池中,然后再进行查找。虽然 数量(last_query_cost)
增加了不少 ,但是通过缓冲池的机制,并 没有增加多少查询时间
。
使用场景: 它对于比较开销是非常有用的,特别是我们有好几种查询方式可选的时候。
4. 定位执行慢的 SQL:慢查询日志
4.1 开启慢查询日志参数
- 开启slow_query_log
sql>mysql">set global slow_query_log='ON';
sql>mysql">sql>mysql> show variables like '%slow_query_log%';
你能看到这时慢查询分析已经开启,同时文件保存在 /var/lib/sql>mysql/RainbowSea-slow.log
文件 中。
- 修改long_query_time阈值
接下来我们来看下慢查询的时间阈值设置,使用如下命令:
sql>mysql">sql>mysql> show variables like '%long_query_time%';
这里如果我们想把时间缩短,比如设置为 1 秒,可以这样设置:
sql>mysql">#测试发现:设置global的方式对当前session的long_query_time失效。对新连接的客户端有效。所以可以一并 执行下述语句
sql>mysql > set global long_query_time = 1;
sql>mysql> show global variables like '%long_query_time%';
sql>mysql> set long_query_time=1;
sql>mysql> show variables like '%long_query_time%';
4.2 查看慢查询数目
查询当前系统中有多少条慢查询记录
sql>mysql">sql>mysql> SHOW GLOBAL STATUS LIKE '%Slow_queries%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries | 0 |
+---------------+-------+
1 row in set (0.00 sec)
4.3 案例演示
步骤1. 建表
sql>mysql">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:设置参数 log_bin_trust_function_creators
创建函数,假如报错:
This function has none of DETERMINISTIC......
命令开启:允许创建函数设置:
sql>mysql">set global log_bin_trust_function_creators=1; # 不加global只是当前窗口有效。
第2步:创建模拟数据必需的存储函数
说明: 创建函数,假如报错:
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, 我们就必须为我们的
function
指定一个参数。主从复制,主机会将写操作记录在bin-log日志中。从机读取bin-log日志,执行语句来同步数据。如果使 用函数来操作数据,会导致从机和主键操作时间不一致。所以,默认情况下,sql>mysql不开启创建函数设 置。
sql>mysql">SHOW VARIABLES LIKE 'log_bin_trust_function_creators';
- 命令开启:允许创建函数设置:
sql>mysql">set global log_bin_trust_function_creators=1; # 不加global只是当前窗口有效。
sql>mysql">
#函数1:创建随机产生字符串函数
DELIMITER //
CREATE FUNCTION rand_string(n INT)
RETURNS VARCHAR(255) #该函数会返回一个字符串
BEGIN
DECLARE chars_str VARCHAR(100) DEFAULT
'abcdefghijklmnopqrstuvwxyzABCDEFJHIJKLMNOPQRSTUVWXYZ';
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 ;
sql>mysql">#函数2:创建随机数函数
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步:创建插入模拟数据的存储过程
sql>mysql"># 存储过程1:创建插入课程表存储过程
DELIMITER //
CREATE PROCEDURE insert_course( max_num INT )
BEGIN
DECLARE i INT DEFAULT 0;
SET autocommit = 0; #设置手动提交事务
REPEAT #循环
SET i = i + 1; #赋值
INSERT INTO course (course_id, course_name ) VALUES (rand_num(10000,10100),rand_string(6));
UNTIL i = max_num
END REPEAT;
COMMIT; #提交事务
END //
DELIMITER;
sql>mysql"># 存储过程2:创建插入学生信息表存储过程
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+i),rand_string(6),rand_num(10,100),rand_num(10,1000));
UNTIL i = max_num
END REPEAT;
COMMIT; # 提交事务
END //
DELIMITER ;
第4步:调用存储过程
sql>mysql">#调用刚刚写好的函数, 4000000条记录,从100001号开始
CALL insert_stu1(100001,4000000);
第5步:查看是否含有这么多数据,数据是否插入成功
sql>mysql">SELECT COUNT(*) FROM student;
4.4 测试及分析
1. 测试
sql>mysql">sql>mysql> SELECT * FROM student WHERE stuno = 3455655;
+---------+---------+--------+------+---------+
| id | stuno | name | age | classId |
+---------+---------+--------+------+---------+
| 3523633 | 3455655 | oQmLUr | 19 | 39 |
+---------+---------+--------+------+---------+
1 row in set (2.09 sec)
sql>mysql> SELECT * FROM student WHERE name = 'oQmLUr';
+---------+---------+--------+------+---------+
| id | stuno | name | age | classId |
+---------+---------+--------+------+---------+ |
1154002 | 1243200 | OQMlUR | 266 | 28 |
| 1405708 | 1437740 | OQMlUR | 245 | 439 |
| 1748070 | 1680092 | OQMlUR | 240 | 414 |
| 2119892 | 2051914 | oQmLUr | 17 | 32 |
| 2893154 | 2825176 | OQMlUR | 245 | 435 |
| 3523633 | 3455655 | oQmLUr | 19 | 39 |
+---------+---------+--------+------+---------+
6 rows in set (2.39 sec)
从上面的结果可以看出来,查询学生编号为“3455655”的学生信息花费时间为2.09秒。查询学生姓名为 “oQmLUr”的学生信息花费时间为2.39秒。已经达到了秒的数量级,说明目前查询效率是比较低的,下面 的小节我们分析一下原因。
2.分析
sql>mysql">show status like 'slow_queries';
补充说明:
除了上述变量,控制慢查询日志的还有一个变量:min_examined_row_limit。这个变量的意思是,查询
扫描过的最少记录数
。这个变量和查询执行时间,共同组成了判别一个查询是否是慢查询的条件。如果查询扫描过的记录数大于等于这个变量值,并且查询执行时间超过long_query_time
的值,那么,这个查询就被记录到慢查询日志中;反之,则不被记录到慢查询中。sql>mysql">sql>mysql> show variables like 'min%'; +------------------------+-------+ | Variable_name | Value | +------------------------+-------+ | min_examined_row_limit | 0 | +------------------------+-------+ 1 row in set (0.01 sec)
这个值,默认是
0
,与long_query_time = 10
合在一起,表示只要查询的执行时间超过10 秒钟,哪怕一个记录也没有扫描过,都要被记录到慢查询日志
中。你也可以根据需要,通过修改my.ini
文件,来修改查询时长,或者通过 set 指令,用 SQL 语句修改“min_examined_row_limit
” 的值。
sql>mysqldumpslow_538">4.5 慢查询日志分析工具:sql>mysqldumpslow
在生产环境中,如果要手工分析日志,查找、分析SQL,显然是个体力活,MySQL提供了日志分析工具 sql>mysqldumpslow
。
[root@RainbowSea ~]# sql>mysqldumpslow --help;
-a:
不将数字抽象成N,字符串抽象成S-s:
是表示按照何种方式排序:
c:
访问次数l:
锁定时间r:
返回记录t:
查询时间al:
平均锁定时间ar:
平均返回记录数at:
平均查询时间 (默认方式)ac:
平均查询次数t:
即为返回前面多少条的数据;-g:
后边搭配一个正则匹配模式,大小写不敏感的;
举例:我们想要按照查询时间排序,查看前五条 SQL 语句,这样写即可:
sql>mysqldumpslow -s t -t 5 /var/lib/sql>mysql/RainbowSea-slow.log
其中的路径位置是通过如下:show variables like '%slow_query_log%';
这条命令查询到的
sql>mysql">sql>mysql> show variables like '%slow_query_log%';
+---------------------+------------------------------------+
| Variable_name | Value |
+---------------------+------------------------------------+
| slow_query_log | ON |
| slow_query_log_file | /var/lib/sql>mysql/RainbowSea-slow.log |
+---------------------+------------------------------------+
2 rows in set (0.01 sec)
[root@RainbowSea ~]# sql>mysqldumpslow -s t -t 5 /var/lib/sql>mysql/RainbowSea-slow.log
Reading sql>mysql slow query log from /var/lib/sql>mysql/RainbowSea-slow.log
Count: 1 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), 0users@0hosts
工作常用参考:
#得到返回记录集最多的10个SQL sql>mysqldumpslow -s r -t 10 /var/lib/sql>mysql/RainbowSea-slow.log #得到访问次数最多的10个SQL sql>mysqldumpslow -s c -t 10 /var/lib/sql>mysql/RainbowSea-slow.log #得到按照时间排序的前10条里面含有左连接的查询语句 sql>mysqldumpslow -s t -t 10 -g "left join" /var/lib/sql>mysql/RainbowSea-slow.log #另外建议在使用这些命令时结合 | 和more 使用 ,否则有可能出现爆屏情况 sql>mysqldumpslow -s r -t 10 /var/lib/sql>mysql/RainbowSea-slow.log | more
4.6 关闭慢查询日志
MySQL服务器停止慢查询日志功能有两种方法:
[sql>mysqld]
slow_query_log=OFF
或者,把slow_query_log一项注释掉 或 删除
[sql>mysqld]
#slow_query_log =OFF
重启MySQL服务,执行如下语句查询慢日志功能。
sql>mysql">SHOW VARIABLES LIKE '%slow%'; #查询慢查询日志所在目录
SHOW VARIABLES LIKE '%long_query_time%'; #查询超时时长
- 方式2:临时性方式
使用SET语句来设置。 (1)停止MySQL慢查询日志功能,具体SQL语句如下。
sql>mysql">SET GLOBAL slow_query_log=off;
(2)重启MySQL服务,使用SHOW语句查询慢查询日志功能信息,具体SQL语句如下
SHOW VARIABLES LIKE '%slow%';
#以及
SHOW VARIABLES LIKE '%long_query_time%';
4.7 删除慢查询日志
进入到我们的日志文件的目录当中,找到对于的日志文件,然后,直接删除就可以了。
通过如下指令:找到日志文件的所在位置
sql>mysql">sql>mysql> show variables like '%slow_query_log%';
+---------------------+------------------------------------+
| Variable_name | Value |
+---------------------+------------------------------------+
| slow_query_log | ON |
| slow_query_log_file | /var/lib/sql>mysql/RainbowSea-slow.log |
+---------------------+------------------------------------+
2 rows in set (0.01 sec)
从执行结果可以看出,慢查询日志的目录默认为 MySQL
的数据目录,在该目录下手动删除慢查询日志文件
即可。使用命令sql>mysqladmin flush-logs
来重新生成查询日志文件,具体命令如下,执行完毕会在数据目录下重新生成慢查询日志文件。
sql>mysql">sql>mysqladmin -uroot -p flush-logs slow
提示:
慢查询日志都是使用
sql>mysqladmin flush-logs
命令来删除重建的。使用时一定要主键,一旦执行了这个命令,慢查询日志都只存在新的日志文件中,如果需要旧的查询日志,就必须事先备份。
5. 查看 SQL 执行成本:SHOW PROFILE
sql>mysql">sql>mysql > show variables like 'profiling';
通过设置 profiling='ON’
来开启 show profile:
sql>mysql">sql>mysql > set profiling = 'ON';
然后执行相关的查询语句。接着看下当前会话都有哪些 profiles,使用下面这条命令:
sql>mysql">sql>mysql > show profiles;
你能看到当前会话一共有 2 个查询。如果我们想要查看最近一次查询的开销,可以使用:
sql>mysql">sql>mysql > show profile;
sql>mysql">sql>mysql> show profile cpu,block io for query 2;
show profile的常用查询参数:
ALL:
显示所有的开销信息。BLOCK IO:
显示块IO开销。CONTEXT SWITCHES:
上下文切换开 销。CPU:
显示CPU开销信息。IPC:
显示发送和接收开销信息。MEMORY:
显示内存开销信息。PAGE FAULTS:
显示页面错误开销信息。SOURCE:
显示和Source_function,Source_file,Source_line相关的开销信息。SWAPS:
显示交换次数开销信息。
6. 最后:
“在这个最后的篇章中,我要表达我对每一位读者的感激之情。你们的关注和回复是我创作的动力源泉,我从你们身上吸取了无尽的灵感与勇气。我会将你们的鼓励留在心底,继续在其他的领域奋斗。感谢你们,我们总会在某个时刻再次相遇。”