1 打开及设置MySQL的慢查询日志
慢查询日志是MySQL中常用的性能诊断工具，通过慢查询日志把执行时间超过一定时间限制（默认10秒）的sql语句记录下来，通过收集一个时间段内（数据库出现性能问题）性能运行欠佳的sql语句，进行统一的分析和诊断，是DBA解决MySQL数据库常用的方法之一。
慢查询日志默认是关闭的。
mysql> show variables like'%slow_query%';+---------------------------+---------------------------------------------+| Variable_name | Value |+---------------------------+---------------------------------------------+|| slow_query_log | OFF || slow_query_log_file |/mysqldata/iZ2ze0t8khaprrpfvmevjiZ-slow.log|+---------------------------+---------------------------------------------+5 rows inset(0.01 sec)
要想打开慢查询日志，可以编辑MySQL数据库配置文件，在[mysqld]部分 加入slow_query_log=on，重启数据库。如果不想重启数据库，可以登录数据库直接设置slow_query_log全局变量。
mysql>set global slow_query_log=on; Query OK,0 rows affected (0.14 sec)
这样设置对于设置后新建的连接有效，对于当前已连接会话是无效的，退出当前会话后重新登录数据库
mysql> show global variables like'%slow_query%';+---------------------------+---------------------------------------------+| Variable_name | Value || slow_query_log |ON|| slow_query_log_file |/mysqldata/iZ2ze0t8khaprrpfvmevjiZ-slow.log|+---------------------------+---------------------------------------------+
慢查询日志已经打开，捕获的慢查询日志存储在文件 /mysqldata/iZ2ze0t8khaprrpfvmevjiZ-slow.log中，这个文件是数据库的默认设置，/mysqldataMySQL的数据目录，iZ2ze0t8khaprrpfvmevjiZ是数据库服务器的主机名。
慢查询日志有2个常用的选项需要调整，一个是long_query_time，设置多长时间之上的查询需要捕获，另一个是log_queries_not_using_indexes，这个选项默认是off，如果设置为on，会捕获所有没有使用索引的sql语句。这一点对于DBA来说很有用，众所周知的是MySQL只支持嵌套连接，而索引对于嵌套连接有十分重要，如果能一次性获取数据库中所有没有使用索引的sql给DBA提供了很大的方便。
mysql>set global log_queries_not_using_indexes=on; Query OK,0 rows affected (0.00 sec)mysql>set long_query_time=0.1; Query OK,0 rows affected (0.00 sec)
2 用sysbench（docker）方式创建测试数据
使用docker运行sysbench的原因一个是安装配置十分简单，不用在操作系统安装sysbench以及依赖包，只要拉取镜像，运行容器即可，另一个是这样使用对现有的操作系统环境几乎没什么影响，要删除也十分方便，只要把容器删除即可。
2.1 安装docker
docker的安装十分简单，这里只列出步骤
[root]# yum install -y yum-utils [root]# yum-config-manager --add-repo http://mirrors.aliyun.com/docker-ce/linux/centos/docker-ce.repo Adding repo from: http://mirrors.aliyun.com/docker-ce/linux/centos/docker-ce.repo [root]# yum makecache fast && yum -y install docker-ce[root@ ~]# systemctl start docker[root@ ~]# systemctl status docker ● docker.service - Docker Application Container Engine Loaded: loaded (/usr/lib/systemd/system/docker.service; disabled; vendor preset: disabled) Active: active (running) since Mon 2022-08-1509:51:47 CST; 8s ago
2.2 拉取sysbench映像
搜索sysbench映像
[root@ ~]# docker search sysbench NAME DESCRIPTION STARS OFFICIAL AUTOMATED severalnines/sysbench Sysbench 1.0 18 [OK]
拉取搜到的第一个映像
[root@ ~]# docker pull severalnines/sysbench Using default tag: latest latest: Pulling from severalnines/sysbench e79bb959ec00: Pull complete 6f6da6c9c901: Pull complete 206bc115af8c: Pull complete ba6ac542f035: Pull complete 1f1dcb85e92e: Pull complete Digest: sha256:64cd003bfa21eaab22f985e7b95f90d21a970229f5f628718657dd1bae669abd Status: Downloaded newer image for severalnines/sysbench:latest docker.io/severalnines/sysbench:latest
映像拉取成功，查看以下本地映像
[root@ ~]# docker images REPOSITORY TAG IMAGE ID CREATED SIZE severalnines/sysbench latest 0e71335a2211 3 years ago 429MB
2.3 创建sysbench数据库及账号
本地已经有sysbench映像了，在MySQL中创建一个sysbench数据库及用来连接这个数据库的账号和密码
mysql>create database sysbenchdb; Query OK,1 row affected (0.00 sec)mysql> grant all privileges on sysbenchdb.* to u_sysbench@'%' identified by'123456'; Query OK,0 rows affected,1 warning (0.00 sec)mysql> flush privileges; Query OK,0 rows affected (0.00 sec)
创建账号密码后不要忘了刷新权限，否则会登录不到数据库。
2.4 创建测试数据
使用下面命令创建测试数据。
[root@ ~]# docker run --rm=true --name=sb-prepare 0e71335a2211 sysbench --test=/usr/share/sysbench/oltp_read_only.lua --mysql-host=172.20.11.244 --mysql-port=3306 --mysql-db=sysbenchdb --mysql-user="u_sysbench" --mysql-password='123456' --tables=4 --table_size=10000000 --threads=2 --time=300 --report-interval=3 --db-driver=mysql --db-ps-mode=disable --skip-trx=on --mysql-ignore-errors=6002,6004,4012,2013,4016,1062 prepare
这个命令很长，看起来稍稍有点复杂，这了略微解释以下，除了第一行之外，这个命令就是sysbench在操作系统下直接安装时创建测试数据的命令。第一行是用docker来运行sysbench，--name设置容器的名称，--rm=true是在创建测试数据完成后删除容器，这是个一次性的任务，完成了之后容器的使命也就结束了，留着也没啥用。0e71335a2211是我们拉取的sysbench映像的id，这个也可以用名称，后面跟的就是这个容器启动后要运行的命令。
--test是要运行的sysbench的脚本，后面几个是连接到数据库的信息，因为是sysbench是运行在docker中，这里不能用本地地址（127.0.0.1或者localhost）作为主机名，后面是表数量、线程数、表大小，时间，报道间隔，数据库驱动器、事务选项、要忽略的错误等，最后的prepare是sysbench要运行的命令。这里因为是测试慢查询，表设得大一点。这个命令的输出是这样的。
WARNING: the --test option is deprecated. You can pass a script name or path on the command line without any options. sysbench 1.0.17 (using bundled LuaJIT 2.1.0-beta2) Initializing worker threads... Creating table 'sbtest2'... Creating table 'sbtest1'... Inserting 10000000 records into 'sbtest1' Inserting 10000000 records into 'sbtest2' Creating a secondary index on 'sbtest1'... Creating a secondary index on 'sbtest2'... Creating table 'sbtest3'... Inserting 10000000 records into 'sbtest3' Creating table 'sbtest4'... Inserting 10000000 records into 'sbtest4' Creating a secondary index on 'sbtest3'... Creating a secondary index on 'sbtest4'...
不但创建了表，也创建了索引。
2.5 运行sysbench测试
[root@ ~]# docker run --name=sb-run 0e71335a2211 sysbench --test=/usr/share/sysbench/oltp_read_only.lua --mysql-host=172.20.11.244 --mysql-port=3306 --mysql-db=sysbenchdb --mysql-user="u_sysbench" --mysql-password=123456 --tables=4 --table_size=10000000 --threads=4 --time=300 --report-interval=10 --db-driver=mysql --db-ps-mode=disable --skip-trx=on --mysql-ignore-errors=6002,6004,4012,2013,4016,1062 run
这个命令和创建测试数据的命令大部分是相同的，第一行没有了--rm=true，这个测试以后可能会还要做，所以运行完之后保留这个容器。sysbench
运行的命令是run，不是prepare。这个命令的输出如下：
SQL statistics: queries performed: read: 1477406write: 0 other: 0 total: 1477406 transactions: 105529 (351.72 per sec.) queries: 1477406 (4924.08 per sec.) ignored errors: 0 (0.00 per sec.) reconnects: 0 (0.00 per sec.) General statistics: total time: 300.0350s total number of events: 105529 Latency (ms): min: 2.22 avg: 11.37 max: 349.88 95th percentile: 15.00 sum: 1199812.63 Threads fairness: events (avg/stddev): 26382.2500/23.23 execution time (avg/stddev): 299.9532/0.01
3 MySQL慢查询日志分析
3.1 使用文本工具
慢查询日志是文本文件，可以直接使用linux文本命令来查看
[root@ mysqldata]# cat iZ2ze0t8khaprrpfvmevjiZ-slow.log /usr/local/mysql/bin/mysqld, Version: 5.7.34 (MySQL Community Server (GPL)). started with: Tcp port: 3306 Unix socket: /tmp/mysql.sock Time Id Command Argument /usr/local/mysql/bin/mysqld, Version: 5.7.34 (MySQL Community Server (GPL)). started with: Tcp port: 3306 Unix socket: /tmp/mysql.sock Time Id Command Argument # Time: 2022-08-15T02:46:17.506869Z# User@Host: root[root] @ localhost [] Id: 34# Query_time: 22.707483 Lock_time: 0.000098 Rows_sent: 400000 Rows_examined: 800000 use sysbenchdb; SET timestamp=1660531577; select * from sbtest1 union select * from sbtest2 union select * from sbtest3 union select * from sbtest4; # Time: 2022-08-15T02:52:41.908776Z# User@Host: root[root] @ localhost [] Id: 37# Query_time: 24.590315 Lock_time: 0.000109 Rows_sent: 1 Rows_examined: 1200000 SET timestamp=1660531961; select count(*) from (select * from sbtest1 union select * from sbtest2 union select * from sbtest3 union select * from sbtest4) a;
慢查询日志中显示了每一个捕获的sql语句的时间，连接信息，查询时间、锁时间，发送的行数，扫描行数等，可以看，但是不太直观。
3.2 使用mysqldumpslow
mysqldumpslow是MySQL官方提供的慢查询日志查看工具，随着MySQL数据库一起安装，这个工具对慢查询日志做了一定的格式化，查看起来要方面一些。
[root@ mysqldata]# mysqldumpslow -v iZ2ze0t8khaprrpfvmevjiZ-slow.log Reading mysql slow query log from iZ2ze0t8khaprrpfvmevjiZ-slow.log Count: 1Time=24.59s (24s) Lock=0.00s (0s) Rows=1.0 (1), root[root]@localhost select count(*) from (select * from sbtest1 union select * from sbtest2 union select * from sbtest3 union select * from sbtest4) a Count: 1Time=22.71s (22s) Lock=0.00s (0s) Rows=400000.0 (400000), root[root]@localhost select * from sbtest1 union select * from sbtest2 union select * from sbtest3 union select * from sbtest4 Count: 1Time=0.41s (0s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@localhost select pad from sbtest1 where c ="S"
显示的信息看起来更直观了一些，对每个sql的执行次数，查询时间，查询行数做了汇总。
4 使用percona的pt-query-digest分析慢查询日志
4.1 pt-query-digest的安装
使用pt-query-digest，需要安装percona-toolkit，这个工具有几个依赖包需要安装，这里列出安装命令，不做解释。
[root@ mysqldata]# yum -y install perl-IO-Socket-SSL[root@ mysqldata]# yum -y install perl[root@ mysqldata]# yum -y install perl-DBD-MySQL [root@ mysqldata]# yum install perl-Digest-MD5 -y
对于percona-toolkit，最简单的安装方式是yum源安装，首先下载percona-toolkit的官方yum源
[root@ mysqldata]# wget percona.com/get/percona-toolkit.rpm percona-toolkit.rpm [ <=> ] 51.08K 203KB/s in0.3s 2022-08-1511:20:59 (203 KB/s) - ‘percona-toolkit.rpm’ saved [52310]
下载的yum源是一个rpm包，安装一下
[root@~]# yum install https://repo.percona.com/yum/percona-release-latest.noarch.rpm
yum源安装完成之后，就可以安装percona-toolkit工具了
[root@ ~]# yum install percona-toolkitPercona Original release/x86_64 YUM repository 1.9 MB/s | 8.7 MB 00:04 Percona Original release/noarch YUM repository 2.8 kB/s | 3.6 kB 00:01 Percona Release release/noarch YUM repository 1.4 kB/s | 1.8 kB 00:01 Dependencies resolved. ======================================================================================================================== Package Architecture Version Repository Size ========================================================================================================================Installing: percona-toolkit x86_64 3.4.0-3.el8 percona-release-x86_64 20 M Installing dependencies: perl-TermReadKey x86_64 2.37-7.el8 AppStream 40 k perl-Time-HiRes x86_64 4:1.9758-2.el8 AppStream 61 k Installed: percona-toolkit-3.4.0-3.el8.x86_64 perl-TermReadKey-2.37-7.el8.x86_64 perl-Time-HiRes-4:1.9758-2.el8.x86_64 Complete!
4.2 分析慢查询日志
pt-query-digest的使用非常简单，只有一个必须的参数，就是要分析的慢查询日志文件名。
这个命令的输出可以分为三个部分，第一部分是对整个慢查询日志作为分析，所有慢查询语句的执行时间，慢查询语句执行的最短时间，最长时间，平均时间，时间的中位值，标准差等，看了这个，对这个时间段的sql语句总体的运行情况就有了基本的了解。
[root@ mysqldata]# pt-query-digest iZ2ze0t8khaprrpfvmevjiZ-slow.log# 180ms user time, 30ms system time, 34.11M rss, 99.52M vsz# Current date: Mon Aug 15 14:54:31 2022# Hostname: iZ2ze0t8khaprrpfvmevjiZ# Files: iZ2ze0t8khaprrpfvmevjiZ-slow.log# Overall: 5 total, 5 unique, 0.02 QPS, 0.59x concurrency ________________# Time range: 2022-08-15T06:50:43 to 2022-08-15T06:54:04# Attribute total min max avg 95% stddev median# ============ ======= ======= ======= ======= ======= ======= =======# Exec time 119s 104ms 91s 24s 88s 34s 189ms# Lock time 50ms 24us 42ms 10ms 42ms 16ms 44us# Rows sent 201 0 100 40.20 97.36 47.53 0.99# Rows examine 20.40M 100 10.86M 4.08M 10.76M 4.94M 299.03# Query size 316 43 78 63.20 76.28 12.04 62.76
第二部分列出排在前列的慢查询语句，这里列出的语句应该是关注的重点。
# Profile# Rank Query ID Response time Calls R/Call V/M# ==== =================================== ============= ===== ======= ===# 1 0xEE987693396E1A09E0A9089F9AFA861A 91.0625 76.5% 1 91.0625 0.00 SELECT UNION sbtest?# 2 0xB3461D1C50B98133F6292480060B3436 27.6287 23.2% 1 27.6287 0.00 SELECT sbtest?# MISC 0xMISC 0.4052 0.3% 3 0.1351 0.0 <3 ITEMS>
第三部分是每条慢查询语句具体的信息
# Query 1: 0 QPS, 0x concurrency, ID 0xEE987693396E1A09E0A9089F9AFA861A at byte 1056# This item is included in the report because it matches --limit.# Scores: V/M = 0.00# Time range: all events occurred at 2022-08-15T06:54:04# Attribute pct total min max avg 95% stddev median# ============ === ======= ======= ======= ======= ======= ======= =======# Count 20 1# Exec time 76 91s 91s 91s 91s 91s 0 91s# Lock time 16 8ms 8ms 8ms 8ms 8ms 0 8ms# Rows sent 0 0 0 0 0 0 0 0# Rows examine 53 10.86M 10.86M 10.86M 10.86M 10.86M 0 10.86M# Query size 23 74 74 74 74 74 0 74# String:# Hosts localhost# Users root# Query_time distribution# 1us# 10us# 100us# 1ms# 10ms# 100ms# 1s# 10s+ ################################################################# Tables# SHOW TABLE STATUS LIKE 'sbtest1'\G# SHOW CREATE TABLE `sbtest1`\G# SHOW TABLE STATUS LIKE 'sbtest2'\G# SHOW CREATE TABLE `sbtest2`\G# EXPLAIN /*!50100 PARTITIONS*/ select count(*) from (select * from sbtest1 union select * from sbtest2) a\G # Query 2: 0 QPS, 0x concurrency, ID 0xB3461D1C50B98133F6292480060B3436 at byte 816# This item is included in the report because it matches --limit.# Scores: V/M = 0.00# Time range: all events occurred at 2022-08-15T06:50:56# Attribute pct total min max avg 95% stddev median# ============ === ======= ======= ======= ======= ======= ======= =======# Count 20 1# Exec time 23 28s 28s 28s 28s 28s 0 28s# Lock time 82 42ms 42ms 42ms 42ms 42ms 0 42ms# Rows sent 0 0 0 0 0 0 0 0# Rows examine 46 9.54M 9.54M 9.54M 9.54M 9.54M 0 9.54M# Query size 13 43 43 43 43 43 0 43# String:# Hosts localhost# Users root# Query_time distribution# 1us# 10us# 100us# 1ms# 10ms# 100ms# 1s# 10s+ ################################################################# Tables# SHOW TABLE STATUS LIKE 'sbtest1'\G# SHOW CREATE TABLE `sbtest1`\G# EXPLAIN /*!50100 PARTITIONS*/ select pad from sbtest1 where c ='changan'\G
从上面的输出来看，对每一条语句都进行了分析，一眼就可以看到各个指标的最大值、最小值，平均值，均值、查询事件分布等，给性能诊断提供了丰富的信息。
