MySQL 故障诊断:MySQL 占用 CPU 过高问题定位及优化

作者阿里云代理 文章分类 分类:新闻快递 阅读次数 已被围观 1188

CPU 占用过高常见现象

在使用 MySQL 的过程中会遇到各种瓶颈问题,常见的是 IO 瓶颈,但是有时候会出现服务器 CPU 使用率超过 100%,应用页面访问慢,登录服务器负载很高。而导致这个问题竟然是 MySQL 进程,按理说如果 MySQL 运行稳定,服务器的 CPU 资源并不会跑满,如果出现这个问题,初步可以断定,是 MySQL 实例中出现了问题 SQL。

CPU 占用过高常见原因:

  • 服务器硬件问题

  • 内存溢出

  • 业务高并发

如果是业务高并发引起,可以理解为一种业务繁忙的状态,有可能业务猛增,有可能是定期或者临时的并发窗口:

  • 数据库对象设计不合理

  • 触发器导致

  • 表索引设计不合理

  • 数据库锁导致,如行锁冲突、行锁等待、锁超时、死锁等

  • 系统架构没有缓存中间件

  • 读写分离配置不合理

  • OLTP 系统承载了 OLAP 的业务需求

  • 未合理升级改造为集群环境

  • 未配置异构数据分析系统

  • MySQL 系统参数设置不合理

  • 问题 SQL 导致

SQL 问题导致 CPU 使用率过高是最常见的现象,比如 group by、order by、join 等,这些很大程度影响 SQL 执行效率,从而占用大量的系统资源。

说了这么多常见原因,其实总结一句话来说就是现有系统的现有配置下的现有环境提供不了所需要的数据查询、分析、执行能力,针对这个问题,首先我们要发现问题的所在,就是说我们要准确的定位问题,然后针对问题进行优化,再考虑其他升级改造的事情。

定位分析问题 SQL

光说不练假把式,接下来我们比划比划。

首先,搭建一套模拟环境,这里我让我的得力助手 DBdeployer 来帮我搭建一套模拟环境。

DBdeployer 是用 Go 语言实现的一款非常强大与高效的部署数据库环境的开源工具,我们完全可以用它来部署开发、测试环境。

使用 DBdeployer 来部署一个单点 5.7.27 版本的 MySQL,并配置一个模拟 CPU 占比高的测试环境。

复制
[root@localhost ~]# dbdeployer deploy single 5.7.27Database installed in /dbdata/sandboxes/msb_5_7_27
run 'dbdeployer usage single' for basic instructions'.. sandbox server started1.2.3.4.

创建测试表:

复制
[root@localhost ~]# cd /dbdata/sandboxes/msb_5_7_27/[root@localhost msb_5_7_27]# ./use 
mysql [localhost:5727] {msandbox} ((none)) > use test
Database changed
mysql [localhost:5727] {msandbox} (test) > create table t_cpu(id int primary key auto_increment);        Query OK, 0 rows affected (0.39 sec)1.2.3.4.5.6.

插入大量模拟测试数据:

复制
mysql [localhost:5727] {msandbox} (test) > insert into t_cpu values(),(),(),(),();Query OK, 5 rows affected (0.06 sec)Records: 5  Duplicates: 0  Warnings: 0mysql [localhost:5727] {msandbox} (test) > insert into t_cpu select id+(select count(*) from t_cpu) from t_cpu;Query OK, 5 rows affected (0.05 sec)Records: 5  Duplicates: 0  Warnings: 0......
......

mysql [localhost:5727] {msandbox} (test) > insert into t_cpu select id+(select count(*) from t_cpu) from t_cpu;Query OK, 5242880 rows affected (1 min 8.84 sec)Records: 5242880  Duplicates: 0  Warnings: 0mysql [localhost:5727] {msandbox} (test) > select count(*) from t_cpu;                                         +----------+| count(*) |+----------+| 10485760 |+----------+1 row in set (2.22 sec)1.2.3.4.5.6.7.8.9.10.11.12.13.14.15.16.17.18.19.20.21.

至此我们已经造了 10485760 条数据。

有 1000W+ 的数据量了,我们模拟一个业务场景,让 CPU 嗨(high)起来。

执行一个慢查询:

复制
mysql [localhost:5727] {msandbox} (test) > select * from t_cpu order by rand() limit 1;1.

另外开一个会话,top 看看进程:

复制
top - 15:21:20 up 33 days, 23:10,  3 users,  load average: 0.38, 0.19, 0.21Tasks: 202 total,   2 running, 200 sleeping,   0 stopped,   0 zombie%Cpu(s): 23.3 us,  3.6 sy,  0.0 ni, 73.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  8173716 total,  2867684 free,  1059276 used,  4246756 buff/cache
KiB Swap:  2097148 total,  2097140 free,        8 used.  6761912 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                              
32232 root      20   0 1443252 356688  11748 S 107.0  4.4   2:03.82 mysqld                                                                               
  296 root      20   0   67044  15588   1440 S   0.7  0.2 325:32.46 plymouthd                                                                            
  600 root      20   0  162032   2360   1580 R   0.3  0.0   0:04.21 top                                                                                  
 1901 gnome-i+  20   0  714116  22436   9168 S   0.3  0.3  98:46.20 gsd-color                                                                            
    1 root      20   0  191264   4192   2632 S   0.0  0.1  18:39.97 systemd                                                                              
    2 root      20   0       0      0      0 S   0.0  0.0   0:01.28 kthreadd                                                                             
    4 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kworker/0:0H                                                                         
    6 root      20   0       0      0      0 S   0.0  0.0   0:00.95 ksoftirqd/0                                                                          
    7 root      rt   0       0      0      0 S   0.0  0.0   0:02.08 migration/0                                                                          
    8 root      20   0       0      0      0 S   0.0  0.0   0:00.00 rcu_bh    1.2.3.4.5.6.7.8.9.10.11.12.13.14.15.16.17.

通过 top 我们发现有一个 32232 的进程使得 CPU 使用率已经超过了 100%。

接下来我们具体分析分析,究竟是什么导致 CPU 使用率达到 100%以上的。

检查内存使用情况

复制
[root@localhost ~]# free -m
              total        used        free      shared  buff/cache   available
Mem:           7982        1033        2801          40        4147        6604Swap:          2047           0        20471.2.3.4.

内存使用率还可以,应该不是内存影响导致的问题。

检查服务器线程

方法一:

复制
top -H -p <mysqld 进程 id>1.

先通过 top 找出占用 CPU 使用率 100% 的 MySQL 进程 32232,在具体查看该进程下的线程情况。

复制
[root@localhost ~]# top -H -p 32232top - 15:30:32 up 33 days, 23:20,  3 users,  load average: 0.18, 0.15, 0.18Threads:  28 total,   1 running,  27 sleeping,   0 stopped,   0 zombie%Cpu(s): 24.4 us,  3.2 sy,  0.0 ni, 72.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  8173716 total,  2867420 free,  1059520 used,  4246776 buff/cache
KiB Swap:  2097148 total,  2097140 free,        8 used.  6761668 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                                                                               
32272 root      20   0 1443252 356688  11748 R 99.7  4.4   2:25.74 mysqld                                                                                
32244 root       0 -20 1443252 356688  11748 S  3.7  4.4   0:08.68 mysqld                                                                                
32236 root      20   0 1443252 356688  11748 S  1.7  4.4   0:01.45 mysqld                                                                                
32237 root      20   0 1443252 356688  11748 S  1.7  4.4   0:01.43 mysqld                                                                                
32238 root      20   0 1443252 356688  11748 S  1.3  4.4   0:01.43 mysqld                                                                                
32239 root      20   0 1443252 356688  11748 S  1.3  4.4   0:01.42 mysqld                                                                                
32241 root      20   0 1443252 356688  11748 S  0.3  4.4   0:00.75 mysqld                                                                                
32250 root      20   0 1443252 356688  11748 S  0.3  4.4   0:00.98 mysqld                                                                                
32232 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.31 mysqld                                                                                
32233 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.00 mysqld                                                                                
32234 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.23 mysqld                                                                                
32235 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.31 mysqld                                                                                
32240 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.74 mysqld                                                                                
32242 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.72 mysqld                                                                                
32243 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.69 mysqld                                                                                
32247 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.16 mysqld                                                                                
32248 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.23 mysqld                                                                                
32249 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.02 mysqld                                                                                
32251 root      20   0 1443252 356688  11748 S  0.0  4.4   0:08.04 mysqld                                                                                
32252 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.00 mysqld                                                                                
32253 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.00 mysqld                                                                                
32254 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.00 mysqld                                                                                
32255 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.00 mysqld                                                                                
32256 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.18 mysqld                                                                                
32257 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.03 mysqld                                                                                
32258 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.00 mysqld                                                                                
32259 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.00 mysqld                                                                                
32260 root      20   0 1443252 356688  11748 S  0.0  4.4   0:00.00 mysqld      1.2.3.4.5.6.7.8.9.10.11.12.13.14.15.16.17.18.19.20.21.22.23.24.25.26.27.28.29.30.31.32.33.34.35.36.

结果可以明显的看到 32272 这个线程的 CPU 使用率异常。

方法二:

复制
pidstat -t -p <mysqld 进程 id> 1 51.

先通过 top 找出占用 CPU 使用率 100% 的 MySQL 进程 32232,使用 pidstat 工具在具体查看该进程下的线程情况。

复制
pidstat -t -p 32232 1 5Average:      UID      TGID       TID    %usr %system  %guest    %CPU   CPU  Command
Average:        0     32232         -   85.00   12.60    0.00   97.60     -  mysqld
Average:        0         -     32232    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32233    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32234    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32235    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32236    1.00    0.40    0.00    1.40     -  |__mysqld
Average:        0         -     32237    0.80    0.40    0.00    1.20     -  |__mysqld
Average:        0         -     32238    0.80    0.40    0.00    1.20     -  |__mysqld
Average:        0         -     32239    1.00    0.20    0.00    1.20     -  |__mysqld
Average:        0         -     32240    0.20    0.00    0.00    0.20     -  |__mysqld
Average:        0         -     32241    0.00    0.20    0.00    0.20     -  |__mysqld
Average:        0         -     32242    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32243    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32244    1.20    1.80    0.00    3.00     -  |__mysqld
Average:        0         -     32247    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32248    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32249    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32250    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32251    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32252    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32253    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32254    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32255    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32256    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32257    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32258    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32259    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32260    0.00    0.00    0.00    0.00     -  |__mysqld
Average:        0         -     32272   80.00    9.80    0.00   89.80     -  |__mysqld1.2.3.4.5.6.7.8.9.10.11.12.13.14.15.16.17.18.19.20.21.22.23.24.25.26.27.28.29.30.31.32.

结果可以明显的看到 32272 这个线程的 CPU 使用率异常。

查看 MySQL 进程

在 MySQL 中看看当前连接是否有什么异常。

方法一:

复制
mysql [localhost:5727] {msandbox} ((none)) > show full processlist;+----+----------+-----------+------+---------+------+---------------------+---------------------------------------------+| Id | User     | Host      | db   | Command | Time | State               | Info                                        |+----+----------+-----------+------+---------+------+---------------------+---------------------------------------------+|  3 | msandbox | localhost | test | Query   |    7 | Creating sort index | select * from t_cpu order by rand() limit 1 ||  4 | msandbox | localhost | NULL | Query   |    0 | starting            | show full processlist                       |+----+----------+-----------+------+---------+------+---------------------+---------------------------------------------+2 rows in set (0.00 sec)1.2.3.4.5.6.7.8.

方法二:

复制
mysql [localhost:5727] {msandbox} ((none)) > select * from information_schema.processlist;+----+----------+-----------+------+---------+------+--------------+----------------------------------------------+| ID | USER     | HOST      | DB   | COMMAND | TIME | STATE        | INFO                                         |+----+----------+-----------+------+---------+------+--------------+----------------------------------------------+|  5 | msandbox | localhost | test | Query   |    2 | Sending data | select * from t_cpu order by rand() limit 1  ||  6 | msandbox | localhost | NULL | Query   |    0 | executing    | select * from information_schema.processlist ||  4 | msandbox | localhost | NULL | Sleep   | 1401 |              | NULL                                         ||  3 | msandbox | localhost | test | Sleep   | 1405 |              | NULL                                         |+----+----------+-----------+------+---------+------+--------------+----------------------------------------------+4 rows in set (0.00 sec)1.2.3.4.5.6.7.8.9.10.

参数说明:

  • id:标识位,MySQL 进程 ID,使用 kill id,可以杀掉某一个进程

  • user:当前连接的用户

  • host:当前连接的主机

  • db:连接的数据库

  • command:执行的数据库操作类型

  • sleep:休眠状态

  • Query:查询状态

  • connect:连接状态

  • time:已经执行的时间,单位秒

  • info:已经执行的 SQL

  • state:SQL 执行的状态,结果是 SQL 语句整个执行状态中的一个,其中包含很多状态,我们整理如下表:

MySQL 5.7 官方参考MySQL 8.0 官方参考:

状态

含义

After create

当线程使用函数创建表(包括内部临时表)最后阶段会出现这个状态,即使由于某些错误未能创建成功,也会标识该状态

altering table

服务端正在执行 ALTER TABLE

Analyzing

线程正在计算 MyISAM 引擎表键值分布(例如 ANALYZE TABLE)

checking permissions

线程正在检查服务端是否有执行语句所需要的的权限

Checking table

线程正在执行表的检查工作

cleaning up

线程已经处理了一个命令,并准备释放内存并重置某些状态

Closing tables

线程正在将表中修改的数据刷新到磁盘,同时正在关闭已经用完的表。是一个能很快完成的动作,如果持续完不成,需要确认磁盘空间是否用满或者磁盘使用的负载很高

converting HEAP to ondisk

线程正在将内部临时表从 MEMORY 表转换为磁盘表

copy to tmp table

线程正在执行一个 ALTER TABLE 语句。在创建一个新表,然后将老表记录复制到新表之前将是此状态

Copying to group table

如果语句具有不同的条件 ORDER BY 和 GROUP BY 标准,则按组对行进行排序并将其复制到临时表

Copying to tmp table

服务端正在复制到内存中的临时表

Copying to tmp table on disk

服务端正在复制到磁盘上的临时表,临时结果集变的太大(参考 8.4.4 节,MySQL 内部临时表的使用),线程正在将临时表从内存更改为基于磁盘的格式来节省内存

Creating index

线程正在执行 MyISAM 表的 ALTER TABLE ... ENABLE KEYS

Creating sort index

线程正在处理 SELECT 使用内部临时表

creating table

线程正在创建表,包括创建临时表

Creating tmp table

线程正在内存中或者磁盘上创建临时表,如果临时表在内存中创建之后转换到磁盘,状态为 Copying to tmp table on disk

committing alter table to storage engine

服务端完成 ALTER TABLE 并提交结果

deleting from main table

服务端正在执行多表删除的第一部分,仅删除第一个表,保存列和偏移量用于删除其他表

deleting from reference tables

服务端正在执行多表删除的第二部分,在其他表中删除匹配的行

discard_or_import_tablespace

线程正在执行 ALTER TABLE ... DISCARD TABLESPACE or ALTER TABLE ... IMPORT TABLESPACE 语句

end

结束状态,结束之前需要清理 ALTER TABLE, CREATE VIEW, DELETE, INSERT, SELECT, or UPDATE

executing

线程正在执行语句

Execution of init_command

线程正在执行变量 init_command system 中的语句

freeing items

线程执行了一条命令,在此期间完成了一些项目的资源释放,涉及如查询缓存,这个状态之后通常为 cleaning up

FULLTEXT initialization

服务端正在准备执行 natural-language 的全文检索

init

该状态在 ALTER TABLE, DELETE, INSERT, SELECT, or UPDATE 初始化之前,服务端在该状态下会刷新二进制日志和 InnoDB 日志,清理查询缓存

Killed

有发送了一个 KILL 线程的请求,下次终止前会检查 kill 标志位。MySQL 会在每次主循环中检查 kill 标志位,有时该线程并不能立马杀掉会保留短暂时间,如果该线程被其他线程锁定,那么 kill 会在锁释放后生效

logging slow query

线程正在往慢日志中写入语句

login

连接线程的初始状态,直到客户端成功完成验证

manage keys

服务端开启或者关闭表的索引

Opening tables

线程正在打开表,这应该是一个很快的过程,除非有些事情组织了打开表。例如 ALTER TABLE or a LOCK TABLE 会在结束前阻止打开表操作。再就是有必要检查 table_open_cache 参数的值设置是否足够大。

optimizing

服务端正在对查询进行初始化优化

preparing

查询优化状态

Purging old relay logs

线程正在删除不需要的中继日志

query end

处理完查询,在 freeing items 之前的状态

Receiving from client

服务端正在读取客户端的包,该状态在 5.7.8 叫 Reading from net

Removing duplicates

查询正在使用 SELECT DISTINCT,这个过程 MySQL 在早期阶段无法完成,因此需要一个额外的阶段在把结果返回给客户端前需要删除重复行

removing tmp table

线程在执行完 SELECT 后删除中间临时表,如果没有使用临时表,无该状态

rename

重命名表

rename result table

线程正在执行 ALTER TABLE 语句,创建一个新表,重命名新表替换老表

Reopen tables

线程给表加锁,但是发现在获取表后发现表结构发生了变化。当释放锁,关闭表之后尝试重新打开表

Repair by sorting

使用排序创建索引修复代码

preparing for alter table

服务端正准备就地执行 ALTER TABLE

Repair done

线程已完成对 MyISAM 表的多线程修复

Repair with keycache

创建索引缓存修复代码,比 Repair by sorting 慢的多

Rolling back

线程在回滚事务

Saving state

对于 MyISAM 表的修复和分析操作,线程将新表保存到.MYI 文件头,状态包含行数,AUTO_INCREMENT 计数器,键值分布之类的信息

Searching rows for update

线程正在执行第一阶段查询未更新的数据,如果更新了索引所在行就会执行有该状态

Sending data

线程正在读取和处理 SELECT 的行记录,发送给客户端,由于在这个状态下的操作会执行大量的磁盘访问(读),因此它通常是查询生命周期最长的状态。

Sending to client

服务端正在给客户端发送包,在 5.7.8 该状态叫 Writing to net

setup

线程开始执行 ALTER TABLE 操作

Sorting for group

线程正在做排序来满足 GROUP BY

Sorting for order

线程正在做排序来满足 ORDER BY

Sorting index

线程正在做索引页优化来使得 MyISAM 表优化操作期间有更高效的访问

Sorting result

对于一个 SELECT 语句,类似不使用临时表的 Creating sort index

starting

语句执行的第一个状态

statistics

服务端正在计算统计信息对一个查询创建执行计划,如果持续很长时间,服务端可能正在执行其他的操作

System lock

线程调用了 mysqllocktables(),并且一直未更新状态,这个状态非常常见,可能有很多原因造成。

update

线程正准备执行更新操作

Updating

线程正在检索要更新的行并且更新行

updating main table

服务端正在执行多表更新的第一部分,仅更新第一个表,保存列和偏移量用于更新其他表

updating reference tables

服务端正在执行多表更新的第二部分,在其他表中更新匹配的行

User lock

线程正在使用 GET_LOCK()请求或等待一个意向锁,对于 SHOW PROFILE 这个状态意味着线程请求锁(但是不等锁)

User sleep

线程正在调用 SLEEP()

Waiting for commit lock

FLUSH TABLES WITH READ LOCK 正在等待一个提交锁

Waiting for global read lock

FLUSH TABLES WITH READ LOCK 正在等待全局读锁或者设置系统全局变量 read_only

Waiting for tables

线程得到一个表结构变化的通知,需要重新打开表获取新的表结构,该线程需要等待其他线程关闭该表。这个通知发生在另外的线程执行了 FLUSH TABLES,ALTER TABLE,RENAME TABLE,REPAIR TABLE,ANALYZE TABLE or OPTIMIZE TABLE

Waiting for table flush

线程正在执行 FLUSH TABLES,正在等待其他线程关闭他们的表,或者是线程得到一个表结构变化的通知,需要重新打开表获取新的表结构,该线程需要等待其他线程关闭该表。这个通知发生在另外的线程执行了 FLUSH TABLES,ALTER TABLE,RENAME TABLE,REPAIR TABLE,ANALYZE TABLE or OPTIMIZE TABLE

Waiting for lock_type lock

服务端正在等待 THR_LOCK 锁,或者是元数据锁定子系统的锁,其中 lock_type 是锁的类型,等待 THR_LOCK 锁(Waiting for table level lock),等待元数据锁(Waiting for event metadata lock、Waiting for global read lock、Waiting for schema metadata lock、Waiting for stored function metadata lock、Waiting for stored procedure metadata lock、Waiting for table metadata lock、Waiting for trigger metadata lock)

Waiting on cond

线程正在等待条件变为 true 的状态,没有具体可用的状态信息

Writing to net

服务端正在网络中写包,在 5.7.8 中该状态叫 Sending to client


通过结果我们可以大致看看如下的情况:

  • 是否有大量的未执行查询语句

  • 是否有正在执行的 DML 语句

  • 是否有执行了很长时间的 DDL 语句

  • 是否有锁等情况

我们模拟的这个环境,show 的结果只有两条,结果非常明显,但是真正的生产环境不止这两条结果,通过这个查询结果,可以大致分析一下,并不能准确定位,准确的定位问题,需要进行后续的操作。

根据问题线程 id 定位 MySQL 中的 SQL:

复制
mysql [localhost:5727] {msandbox} ((none)) > select a.user,a.host,a.db,b.thread_os_id,b.thread_id,a.id processlist_id,a.command,a.time,a.state,a.info from information_schema.processlist a,performance_schema.threads b where a.id = b.processlist_id and b.thread_os_id=32272;+----------+-----------+------+--------------+-----------+----------------+---------+------+--------------+---------------------------------------------+| user     | host      | db   | thread_os_id | thread_id | processlist_id | command | time | state        | info                                        |+----------+-----------+------+--------------+-----------+----------------+---------+------+--------------+---------------------------------------------+| msandbox | localhost | test |        32272 |        32 |              7 | Query   |    2 | Sending data | select * from t_cpu order by rand() limit 1 |+----------+-----------+------+--------------+-----------+----------------+---------+------+--------------+---------------------------------------------+1 row in set (0.00 sec)1.2.3.4.5.6.7.
  • thread_os_id=32272,代表的是操作系统级别的线程 id

  • thread_id=32,代表的是 MySQL 内部级别的线程 id

  • processlist_id=7,代表的是会话发起者的进程 id,可 kill 的 id

根据问题线程 id 查看其他监控指标:

复制
mysql [localhost:5727] {msandbox} (performance_schema) > select * from performance_schema.events_statements_current where thread_id in (select thread_id from performance_schema.threads where thread_os_id = 32272)\G;*************************** 1. row ***************************
              THREAD_ID: 32
               EVENT_ID: 11
           END_EVENT_ID: 11
             EVENT_NAME: statement/sql/select
                 SOURCE: 
            TIMER_START: 93213362472684000
              TIMER_END: 93221551162460000
             TIMER_WAIT: 8188689776000
              LOCK_TIME: 993000000
               SQL_TEXT: select * from t_cpu order by rand() limit 1
                 DIGEST: 83dacab9df764f11291d0001e420012e
            DIGEST_TEXT: SELECT * FROM `t_cpu` ORDER BY `rand` ( ) LIMIT ? 
         CURRENT_SCHEMA: test
            OBJECT_TYPE: NULL
          OBJECT_SCHEMA: NULL
            OBJECT_NAME: NULL
  OBJECT_INSTANCE_BEGIN: NULL
            MYSQL_ERRNO: 0
      RETURNED_SQLSTATE: NULL
           MESSAGE_TEXT: NULL
                 ERRORS: 0
               WARNINGS: 0
          ROWS_AFFECTED: 0
              ROWS_SENT: 1
          ROWS_EXAMINED: 20971521CREATED_TMP_DISK_TABLES: 1
     CREATED_TMP_TABLES: 1
       SELECT_FULL_JOIN: 0
 SELECT_FULL_RANGE_JOIN: 0
           SELECT_RANGE: 0
     SELECT_RANGE_CHECK: 0
            SELECT_SCAN: 1
      SORT_MERGE_PASSES: 0
             SORT_RANGE: 0
              SORT_ROWS: 1
              SORT_SCAN: 1
          NO_INDEX_USED: 0
     NO_GOOD_INDEX_USED: 0
       NESTING_EVENT_ID: NULL
     NESTING_EVENT_TYPE: NULL
    NESTING_EVENT_LEVEL: 01 row in set (0.00 sec)ERROR: No query specified1.2.3.4.5.6.7.8.9.10.11.12.13.14.15.16.17.18.19.20.21.22.23.24.25.26.27.28.29.30.31.32.33.34.35.36.37.38.39.40.41.42.43.44.45.46.47.

通过这个结果我们可以查看具体的 SQL,看到有使用临时表、使用了排序等信息。

复制
CREATED_TMP_DISK_TABLES: 1  CREATED_TMP_TABLES: 1  SORT_ROWS: 1  SORT_SCAN: 1  1.2.3.4.

其他排查手段之慢查询日志

查询慢日志情况:

复制
mysql [localhost:5727] {msandbox} ((none)) > show variables like 'slow_query_log%';+---------------------+------------------------------------------------------+| Variable_name       | Value                                                |+---------------------+------------------------------------------------------+| slow_query_log      | ON                                                   || slow_query_log_file | /dbdata/sandboxes/msb_5_7_27/data/localhost-slow.log |+---------------------+------------------------------------------------------+2 rows in set (0.01 sec)1.2.3.4.5.6.7.8.

在慢日志中查看慢 SQL:

复制
cat /dbdata/sandboxes/msb_5_7_27/data/localhost-slow.log# Time: 2021-08-17T09:11:06.768816Z
# User@Host: msandbox[msandbox] @ localhost []  Id:     5# Query_time: 7.984593  Lock_time: 0.000184 Rows_sent: 1  Rows_examined: 20971521SET timestamp=1629191466;select * from t_cpu order by rand() limit 1;1.2.3.4.5.6.7.

可以很清楚的查到慢 SQL:

复制
select * from t_cpu order by rand() limit 11.

执行了有 7.984593 秒,返回结果为 1 行。

其他排查手段之排查日志

开启排查日志功能:

复制
更改排查日志为 TABLE 方式,默认为 FILE 方式
mysql [localhost:5727] {msandbox} ((none)) > set global log_output='TABLE';Query OK, 0 rows affected (0.00 sec)mysql [localhost:5727] {msandbox} ((none)) > set global general_log=ON;Query OK, 0 rows affected (0.00 sec)1.2.3.4.5.6.

执行慢查询:

复制
select * from t_cpu order by rand() limit 11.

查询排查日志内容:

复制
mysql [localhost:5727] {msandbox} ((none)) > SELECT * from mysql.general_log ORDER BY event_time DESC;+----------------------------+-----------------------------------+-----------+-----------+--------------+----------------------------------------------------------+| event_time                 | user_host                         | thread_id | server_id | command_type | argument                                                 |+----------------------------+-----------------------------------+-----------+-----------+--------------+----------------------------------------------------------+| 2021-08-17 17:19:19.863849 | msandbox[msandbox] @ localhost [] |         2 |         0 | Query        | SELECT * from mysql.general_log ORDER BY event_time DESC || 2021-08-17 17:18:45.017615 | msandbox[msandbox] @ localhost [] |         5 |         0 | Query        | select * from t_cpu order by rand() limit 1              |+----------------------------+-----------------------------------+-----------+-----------+--------------+----------------------------------------------------------+2 rows in set (0.00 sec)1.2.3.4.5.6.7.8.

结果显示了刚才的慢 SQL,还有我们查询排查日志结果的 SQL,其实慢日志会记录所有的 SQL,我们只能通过这个日志内容查看一些不太正常的 SQL,比如大量相同的 SQL;定期出现的 SQL;分析一个特定的事务等,排查日志模式非常影响 MySQL 性能,慎用。

关闭排查日志模式:

复制
mysql [localhost:5727] {msandbox} ((none)) > set global general_log=OFF;Query OK, 0 rows affected (0.05 sec)mysql [localhost:5727] {msandbox} ((none)) > truncate table mysql.general_log;Query OK, 0 rows affected (0.05 sec)1.2.3.4.5.

到目前为止,介绍了几种常用的 MySQL 占用 CPU 过高的定位方法,你是否掌握了。找到问题了,接下来,我们就需要看看如何优化这个问题了。

优化一下也不难

前面介绍了几种常用的排查 MySQL 占用 CPU 过高问题排查的方法,那么当我们遇到问题了,如何解决,如何优化呢?

首先,最暴力的方法,如果我们确定这个 SQL 可以被干掉,我们直接 kill id 即可。id 为 process 的 id。

其次,具体问题具体分析,如何排查问题是如何发生的,根据不同的问题作出相应的解决方法。

1. 优化 SQL,从逻辑上优化 SQL,降低 SQL 复杂度,降低 MySQL 执行成本。

2. 对 where、join、max()、min()、order by、group by 等子句用到的字段,创建相应的索引。

3. 二级索引的正确使用。

4. 参数优化:

  • 增加 tmp_table_size 大小

  • 增加 max_heap_table_size 大小

  • 调整 key_buffer_size、table_cache、innodb_buffer_pool_size、innodb_log_file_size 参数大小

其他常用优化方法

1. 检查 MySQL 连接数当前使用是否超过限制

如果超出限制,而且之前的连接没有得到释放,那新的连接肯定会连接不到,造成连接延迟,影响效率。

2. MySQL 的 timeout 参数设置问题

这里介绍两个参数:

  • wait_timeout:MySQL 在关闭一个非交互的连接之前所要等待的秒数,其取值范围在 windows 系统中为 1-2147483,linux 系统中为 1-31536000,默认值 28800。

  • interactive_time:MySQL 在关闭一个交互的连接之前所要等待的秒数(如 mysql gui tool 中的连接),其取值范围随 wait_timeout 变动,默认值 28800。

交互连接即在 mysql_real_connect() 函数中使用了 CLIENT_INTERACTIVE 选项。简单说,就是通过 MySQL 客户端连接数据库是交互式连接,通过 jdbc 连接数据库是非交互式连接。在 MySQL 默认设置下,当一个连接的空闲时间超过 8 小时后,当业务出现了高峰期,肯定会造成有太多的 TCP 连接没关闭,数据库连接数肯定会不够用。从而会产生 CPU 占用过高,服务器告警等问题。因 EPG 的一个访问一次对数据库操作量不大,查询完数据就完成 ok 了,wait_timeout 设置在 120s 内就可以了。

在 MySQL 的官网了解到修改以上两个参数必须修改 interactive_timeout。如果修改 interactive_timeout,则 wait_timeout 也发生变化,如果只修改 wait_timeout,不生效。

3. 老生常谈,规范的 SQL 也是非常必要的

c


本公司销售:阿里云新/老客户,只要购买阿里云,即可享受折上折优惠!>

我有话说: