数据库调优的目标就是响应速度更快,吞吐量更大
。利用宏观的监控工具和微观的日志分析可以帮助我们找到调优的思路和方式。
整个流程分为了观察(Show Status)
和行动(Action)
两个部分,S观察会使用相应的分析工具
,字母A代表的部分是行动,对应分析可以采取的行动。
周期性波动
,即是否由一些周期性节点
造成的(如双十一、促销活动),然后通过增加缓存或者更改缓存失效策略解决long_query_time
并开启慢查询
,记录慢查询到码查询日志
中,然后在日志中找到慢查询的sql语句,使用慢查询监控工具如EXPLAIN
查看慢查询的执行计划进行分析、或者Show Profiling
查看每个步骤的执行时间成本,来判断是由于SQL执行时间较长还是SQL的等待时间比较长导致的延迟卡顿。小结:
查询语句语法如下:
SHOW [GLOBAL | SESSION] STATUS LIKE '参数';
Connections:连接MySQL服务器的次数
Uptime:MySQL服务器上线运行的时间
slow_queries:慢查询的个数
innodb_rows_%:增删改的行的个数
mysql> show status like 'innodb_rows_%';
+----------------------+---------+
| Variable_name | Value |
+----------------------+---------+
| Innodb_rows_deleted | 0 |
| Innodb_rows_inserted | 1395950 |
| Innodb_rows_read | 8045388 |
| Innodb_rows_updated | 0 |
+----------------------+---------+
4 rows in set (0.00 sec)
com_%:增删改查的次数
一条查询SQL在执行前需要确定执行计划,如果存在多条执行计划,MySQL会从多条执行计划中选出一条执行成本最小的最为最终的执行计划
。
可以通过last_query_cost
来查看刚刚执行的最后一条SQL的查询成本,这个变量也是查询效率的一个指标,它的值的含义是该SQL语句查询需要读取的页的数量。
举个栗子,以student_info为例:
mysql> select * from student_info where id = 1065943;
+---------+------------+--------+-----------+----------+---------------------+
| id | student_id | name | course_id | class_id | create_time |
+---------+------------+--------+-----------+----------+---------------------+
| 1065943 | 23672 | VnzJZS | 10089 | 10111 | 2023-04-06 00:16:23 |
+---------+------------+--------+-----------+----------+---------------------+
1 row in set (0.00 sec)
mysql> show status like 'last_query_cost';
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| Last_query_cost | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)
可以看到该条查询sql需要进行读取一个页的查询成本消耗。
mysql> select * from student_info where id between 1055968 and 1065943;
...
9976 rows in set (0.00 sec)
mysql> show status like 'last_query_cost';
+-----------------+-------------+
| Variable_name | Value |
+-----------------+-------------+
| Last_query_cost | 3912.489842 |
+-----------------+-------------+
1 row in set (0.00 sec)
mysql> select * from student_info where id > 1055968
...
944032 rows in set (0.49 sec)
mysql> show status like 'last_query_cost';
+-----------------+--------------+
| Variable_name | Value |
+-----------------+--------------+
| Last_query_cost | 99910.581873 |
+-----------------+--------------+
1 row in set (0.00 sec)
可以看到两个查询在数据页上有25
倍多的差距,但是在查询时间上并没有太大的差别(0.49 0.00),这是因为是采取的顺序读取
的方式将数据页一次性加载到了缓冲池
中,然后进行查找,虽然页数量增加了很多,但是由于缓冲池的机制,并没有增加很多的查询时间。
SQL查询是一个动态的过程,从页的加载的角度看,有以下两点结论:
因此,我们首先要考虑数据存放的位置,如果是经常使用的数据就要放到缓冲池中,其次应尽量一次性批量读取数据,这样单个页的读取效率页得到了提升。
MySQL的慢查询日志记录的是超过慢查询时间阈值long_query_time
的sql语句,long_query_time
的默认时长为10s,因此超过10s的sql就会被认为是慢查询记录到慢查询日志中。
默认情况下mysql数据库没有开启慢查询,需要手动进行开启,但是如果不是调优使用一般不建议开启该参数,因为开启慢查询日志会带来一些性能影响。慢查询日志会将日志记录写到文件中。
mysql> show variables like 'slow_query_log';
+----------------+-------+
| Variable_name | Value |
+----------------+-------+
| slow_query_log | OFF |
+----------------+-------+
1 row in set (0.01 sec)
mysql> set slow_query_log = on
-> ;
ERROR 1229 (HY000): Variable 'slow_query_log' is a GLOBAL variable and should be set with SET GLOBAL
mysql> set global slow_query_log = on;
Query OK, 0 rows affected (0.01 sec)
slow_query_log是全局变量,因此设置的时候需要添加global
mysql> show variables like '%slow_query_log%';
+---------------------+-----------------------------------+
| Variable_name | Value |
+---------------------+-----------------------------------+
| slow_query_log | ON |
| slow_query_log_file | /var/lib/mysql/hadoop102-slow.log |
+---------------------+-----------------------------------+
2 rows in set (0.00 sec)
mysql> show variables like 'long_query_time';
+-----------------+-----------+
| Variable_name | Value |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)
mysql> set global long_query_time=1;
Query OK, 0 rows affected (0.00 sec)
mysql> show variables like 'long_query_time';
+-----------------+-----------+
| Variable_name | Value |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)
mysql> set long_query_time=1;
Query OK, 0 rows affected (0.01 sec)
由于long_query_time即是global也是session变量,因此只设置global的话只会对新会话生效,而当前会话还是10s,因此还需要设置一下会话变量
补充:
上面的配置在mysql服务器重启后就会失效,想要进行永久性的设置,需要在mysql配置文件my.cnf中设置参数slow_query_log
、slow_query_log_file
、long_query_time
。
如不指定目录,则会将慢查询日志存储到数据库数据目录下,不指定文件名则默认使用hostname-slow.log
Show global status like 'slow_queries';
举个栗子,首先创建一个表:
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
创建随机生成数字和字符串的函数,和上一章相同
创建存储过程
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;
执行存储过程
CALL insert_stu1(100001, 4000000);
这时候执行两条sql语句:
mysql> select * from student where name = 'Jhon';
Empty set (1.32 sec)
mysql> select * from student where stuno = 34521;
Empty set (1.47 sec)
与此同时监视的slow_log_file 输出了:
[root@hadoop102 mysql]# tail -f hadoop102-slow.log
/usr/sbin/mysqld, Version: 8.0.31 (MySQL Community Server - GPL). started with:
Tcp port: 3306 Unix socket: /var/lib/mysql/mysql.sock
Time Id Command Argument
# Time: 2023-04-07T08:17:42.255709Z
# User@Host: root[root] @ [192.168.60.1] Id: 128
# Query_time: 1743.052707 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0
use atguigudb1;
SET timestamp=1680855460;
CALL insert_stu1(100001, 4000000);
# Time: 2023-04-07T08:21:18.455242Z
# User@Host: root[root] @ localhost [] Id: 123
# Query_time: 1.328363 Lock_time: 0.000006 Rows_sent: 0 Rows_examined: 4000000
SET timestamp=1680855677;
select * from student where name = 'Jhon';
# Time: 2023-04-07T08:21:45.554053Z
# User@Host: root[root] @ localhost [] Id: 123
# Query_time: 1.466888 Lock_time: 0.000002 Rows_sent: 0 Rows_examined: 4000000
SET timestamp=1680855704;
select * from student where stuno = 34521;
slow_queries显示数量为2
mysql> show status like 'slow_queries';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries | 2 |
+---------------+-------+
1 row in set (0.03 sec)
[root@hadoop102 ~]# mysqldumpslow -help
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
-a:不使用n、s等字母缩写sql语句中的变量
-s:排序
-t:只显示最前面的
[root@hadoop102 ~]# mysqldumpslow -a -s t -t 5 /var/lib/mysql/hadoop102-slow.log
Reading mysql slow query log from /var/lib/mysql/hadoop102-slow.log
Count: 1 Time=1743.05s (1743s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@[192.168.60.1]
CALL insert_stu1(100001, 4000000)
Count: 1 Time=1.47s (1s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@localhost
select * from student where stuno = 34521
Count: 1 Time=1.33s (1s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@localhost
select * from student where name = 'Jhon'
Died at /usr/bin/mysqldumpslow line 162, <> chunk 3.
修改my.cnf文件,设置slow_query_log为off或者注释掉
[mysqld]
slow_query_log = off
再次重启服务即可
mysql> show variables like '%slow%';
+-----------------------------+-----------------------------------+
| Variable_name | Value |
+-----------------------------+-----------------------------------+
| log_slow_admin_statements | OFF |
| log_slow_extra | OFF |
| log_slow_replica_statements | OFF |
| log_slow_slave_statements | OFF |
| slow_launch_time | 2 |
| slow_query_log | OFF |
| slow_query_log_file | /var/lib/mysql/hadoop102-slow.log |
+-----------------------------+-----------------------------------+
7 rows in set (0.03 sec)
mysql> show variables like 'long_query_time';
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)
① 停止慢查询日志功能
SET GLOBAL slow_query_log = off;
② 重启mysql服务
mysql> show variables like '%slow%';
+-----------------------------+-----------------------------------+
| Variable_name | Value |
+-----------------------------+-----------------------------------+
| log_slow_admin_statements | OFF |
| log_slow_extra | OFF |
| log_slow_replica_statements | OFF |
| log_slow_slave_statements | OFF |
| slow_launch_time | 2 |
| slow_query_log | OFF |
| slow_query_log_file | /var/lib/mysql/hadoop102-slow.log |
+-----------------------------+-----------------------------------+
7 rows in set (0.03 sec)
mysql> show variables like 'long_query_time';
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)
rm手动删除mysql数据目录下的慢查询日志即可。
[root@hadoop102 mysql]# rm hadoop102-slow.log
rm:是否删除普通文件 "hadoop102-slow.log"?y
可以通过mysqladmin -uroot -p flush-logs
命令重置慢查询日志
[root@hadoop102 mysql]# mysqladmin -uroot -p flush-logs slow
Enter password:
慢查询日志都是通过这个命令来删除重建的,一旦执行这个命令,慢查询日志都只保存在新的日志文件中,如果需要旧的就必须实现备份
show profile 可以分析当前会话中SQL做了什么、执行的资源消耗情况的工具,可用于sql调优的测量。默认情况下处于关闭状态
,并保存最近15次
的运行结果。
mysql> show variables like 'profiling';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling | OFF |
+---------------+-------+
1 row in set (0.00 sec)
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.00 sec)
mysql> select * from student where stuno = 34521;
Empty set (1.52 sec)
mysql> select * from student where name = 'Jhon';
Empty set (1.08 sec)
mysql> show profiles;
+----------+------------+-------------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+-------------------------------------------+
| 1 | 0.00140400 | show variables like 'profiling' |
| 2 | 1.52199250 | select * from student where stuno = 34521 |
| 3 | 1.08189700 | select * from student where name = 'Jhon' |
+----------+------------+-------------------------------------------+
3 rows in set, 1 warning (0.00 sec)
会保存15次查询,Duration为时间
show_profile会显示最近的一次详细信息:
mysql> show profile;
+--------------------------------+----------+
| Status | Duration |
+--------------------------------+----------+
| starting | 0.000148 |
| Executing hook on transaction | 0.000028 |
| starting | 0.000010 |
| checking permissions | 0.000006 |
| Opening tables | 0.000056 |
| init | 0.000007 |
| System lock | 0.000008 |
| optimizing | 0.000009 |
| statistics | 0.000047 |
| preparing | 0.000042 |
| executing | 1.081442 |
| end | 0.000019 |
| query end | 0.000005 |
| waiting for handler commit | 0.000011 |
| closing tables | 0.000011 |
| freeing items | 0.000036 |
| cleaning up | 0.000014 |
+--------------------------------+----------+
17 rows in set, 1 warning (0.00 sec)
mysql> show profile for query 2;
+--------------------------------+----------+
| Status | Duration |
+--------------------------------+----------+
| starting | 0.000186 |
| Executing hook on transaction | 0.000024 |
| starting | 0.000026 |
| checking permissions | 0.000008 |
| Opening tables | 0.000128 |
| init | 0.000023 |
| System lock | 0.000010 |
| optimizing | 0.000065 |
| statistics | 0.000064 |
| preparing | 0.000022 |
| executing | 1.521179 |
| end | 0.000025 |
| query end | 0.000005 |
| waiting for handler commit | 0.000046 |
| closing tables | 0.000049 |
| freeing items | 0.000044 |
| cleaning up | 0.000090 |
+--------------------------------+----------+
17 rows in set, 1 warning (0.00 sec)
并且也可以查看cpu和堵塞io情况
mysql> show profile cpu, block io for query 2;
+--------------------------------+----------+----------+------------+--------------+---------------+
| Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+--------------------------------+----------+----------+------------+--------------+---------------+
| starting | 0.000186 | 0.000072 | 0.000111 | 0 | 0 |
| Executing hook on transaction | 0.000024 | 0.000008 | 0.000013 | 0 | 0 |
| starting | 0.000026 | 0.000011 | 0.000016 | 0 | 0 |
| checking permissions | 0.000008 | 0.000002 | 0.000004 | 0 | 0 |
| Opening tables | 0.000128 | 0.000051 | 0.000078 | 0 | 0 |
| init | 0.000023 | 0.000009 | 0.000014 | 0 | 0 |
| System lock | 0.000010 | 0.000003 | 0.000005 | 0 | 0 |
| optimizing | 0.000065 | 0.000026 | 0.000041 | 0 | 0 |
| statistics | 0.000064 | 0.000025 | 0.000039 | 0 | 0 |
| preparing | 0.000022 | 0.000009 | 0.000012 | 0 | 0 |
| executing | 1.521179 | 1.407445 | 0.269692 | 4096 | 0 |
| end | 0.000025 | 0.000015 | 0.000000 | 0 | 0 |
| query end | 0.000005 | 0.000005 | 0.000000 | 0 | 0 |
| waiting for handler commit | 0.000046 | 0.000048 | 0.000000 | 0 | 0 |
| closing tables | 0.000049 | 0.000048 | 0.000000 | 0 | 0 |
| freeing items | 0.000044 | 0.000044 | 0.000000 | 0 | 0 |
| cleaning up | 0.000090 | 0.000091 | 0.000000 | 0 | 0 |
+--------------------------------+----------+----------+------------+--------------+---------------+
17 rows in set, 1 warning (0.00 sec)
可以看出上面两条sql的主要执行时间都在executing执行上,只需要添加索引即可大幅度缩减执行时间
手机扫一扫
移动阅读更方便
你可能感兴趣的文章