MySql CPU彪高到百分之1000的排查思路-LMLPHP
 
原文内容来自于LZ(楼主)的印象笔记,如出现排版异常或图片丢失等情况,可查看当前链接:https://app.yinxiang.com/fx/bf7839b3-5f7b-4212-9f7d-5f5577e952ea
 

MySql CPU彪高到百分之1000的排查思路

 
查看当前MySql的CPU已经在百分之 1019
MySql CPU彪高到百分之1000的排查思路-LMLPHP
 
下述为当前MySql的所以子线程的CPU使用状况,可以看到当前已经有11个线程的CPU都是在99%左右
MySql CPU彪高到百分之1000的排查思路-LMLPHP
 
进行问题的排查:
1、首先怀疑是否是存在较大的全盘扫描的SQL语句,导致MySql查询时间过长导致的CPU彪高现象
2、查询当前MySql的my.cnf配置,是否是MySql配置问题(由于我司运维同学有一个统一的MySql公共配置可用,所以并没有怀疑是MySql的配置不合理而导致的问题,最终确认,也的确不是MySql的配置问题,博客结尾会给出一份优化过的MySQL5.7.20的安装包,需要的朋友可自取)
3、验证当前服务器的IO,是否是过于频繁的读写引起的IO异常而导致的CPU彪高;
 
1、使用 show FULL PROCESSLIST 查询当前MySql的线程执行情况
 
MySql CPU彪高到百分之1000的排查思路-LMLPHP
由于之前出现过由于用户的使用过于频繁,而导致的表数据量过大引起的数据查询缓慢的问题,所以在此CPU彪高之前,已经频繁使用 show processlist 查看过执行时间过长的SQL,并且皆已经做了相对应的处理(相关的业务皆已经分表分层,以及都增加了相关的表索引),所以,我在人工观察 show processlist的过程当中,的确没有再出现过 Query过程中Time占用时间很长的情况;
 
并且查看了对应的 mysql-slow.log 日志(在最初部署Mysql的同时,MySql的配置中已经开启过了慢SQL记录的日志功能),查询了对应的慢SQL的记录日志后,的确是不存在在当前CPU彪高的时间点中存在慢SQL查询的情况;
 
所以,也就是说,当前已经不在存在由于表数据量较大导致的SQL查询慢的情况;那么此时则开始转向思考,难道是我的服务在使用MySql的过程中,读写频率太高了?而导致的MySql服务CPU异常?LZ(楼主)当前所负责开发的产品是一款坐席的实时通话的产品,相关的业务逻辑中的确是存在频繁的读写DB的;所以此时开始转向思考是否是读写频率太高而引起的CPU彪高的问题,于是开始了以下的排查;
 
2、查询CPU的IO读写速率
分别使用sar 命令获取 IO的读写速率监控:
1、sar -b 1 30
MySql CPU彪高到百分之1000的排查思路-LMLPHP
2、sar -u -o 1 30
 
MySql CPU彪高到百分之1000的排查思路-LMLPHP
通过使用,sar 命令查看了相关的IO信息后,发现并没有出现 IOWAIT过高的问题,并且也没看到每秒钟物理设备读写频率过高的问题,所以此处就很疑惑;并且由于此处使用sar是分析的系统级IO使用情况,所以也很 难避免是否存在MySql自身的机制,比如某些Sql的查询频繁被命中缓存,所以走缓存查询而并没有直接走IO读取的情况;由于上述使用TOP命令时,所对应的wa值也是很低的,那么到底是什么原因引起的MySQL的CPU彪高呢,而且还是如此高?
 
此时,在逐步的排查中,重点来了:
 
当首先出现了CPU彪高的时候,我们对于Mysql的第一印象就是某SQL执行较慢,导致的线程卡死最终引起的CPU彪高,我们会去排查慢SQL的执行日志,或者查看MySql的执行日志,是否有异常的情况出现;甚至还会怀疑是否是应用程序链接Mysql的线程池太多,没有及时回收线程链接,而导致不断创建线程链接最终导致的MySQL服务彪高(此时使用 top -Hp 查看了进程所创建的线程数量,也是正常数据);
 
但始终就一直没怀疑,是否是并发过高,而导致的MySQL CPU问题,其实LZ最初也怀疑过,难道是应用程序的并发过高而导致的吗?但简单想了一下,当前的应用程序并还没有到达完全的负载状态,理论上MySQL这样一个成熟的DB,不至于如此便随意彪高了,虽然是在简单的回想,但手上的动作还是敲起了熟悉的命令:show full processlist ,因为如果并发高的情况下,采取每1秒获取一次正在运行的线程数量的方式(采用SQL脚本for输出),可以判断出是否存在运行线程递增的情况。
 
MySql CPU彪高到百分之1000的排查思路-LMLPHP
 
此时则发现了一个新的问题,我每一次不管任何时候查询当前正在运行的线程,都会看到这样一个SQL在执行中过程中,尽管对应的Time查询时间很短,该线程的ID便直接结束了,但意外的是,每一次查看时,都能看到该SQL在运行中;换句话理解则是,该SQL查询结果是很快的,但是不管在任何一个时间查看线程时都能看到该SQL正在执行中,这只能说明一个问题,,那就是该SQL的查询频率极高!高到每毫秒不间断的都一直在重新查询该SQL;
 
所以这只能是代码BUG问题,最终根据该线程所一直在执行的SQL反向推到应用程序中以后发现,。。。。的确是存在一个定时器的业务BUG,由于定时器是每秒钟都会被执行,且当前定时器设置的是并行模式(即当前定时器线程无论是否执行完成,只要1秒以后,都会紧接着开启新的线程执行该定时器代码块,所以,这就导致了一旦线程执行了1分钟,甚至更久,那么将会导致后续的所有线程都会执行1分钟的时间,并且还在源源不断的创建新的线程,且由于线程代码快中,对该SQL查询代码还是循环的在查询........(后续这块代码被重构了),所以这将导致不断的for循环查询,再加上不断的新的创建的创建查询,引起了CPU的循环彪高的情况。。。。。)
 
 
所以如果有遇到相同CPU彪高的情况,但是一直在生产环境没法定位到具体SQL的情况下,此时记得也一定要关注下SQL的执行频率问题,因为最初的确没有想到执行频率可以高到这种程度,一个如此高的执行频率竟然可以让MySQL彪高到如此大的CPU;
 
 
此处做下简单汇总:
MySQL的服务器本质上是一个很稳定的软件了,正常情况下只要是给与正确的服务器配置(my.cnf),很难再出现因为连接数过多,或者线程所占用内存较大,导致的内存或者CPU问题,因为在对应的mysql的配置中,可以设置对应的线程链接数,以及线程所占用的内存大小,包括缓冲区的内存大小等配置,只要给与合理的配置,这些问题所导致的服务异常都很难看到,也正是因为如此,所以MySQL这样的服务对外所提供的排查手段也是极为有限的,类似排查MySQL的运行日志,以及查看慢SQL的日志,和查看线程的执行状况等,只有寥寥几个是MySQL所提供的排查工具;
所以如果出现了MySql的服务异常:
1、排查MySql运行日志,是否有错误提示
2、排查是否是全表查询慢SQL导致的服务异常
3、排查MySQL内部线程的执行情况
4、排查SQL线程的执行频率
 
MySQL本质上还是一个DB服务,提供数据的存储和检索,一般情况下更大的问题还是来自于不合理的表的使用,以及不合理的全表检索,和不合理的索引等使用上而导致的服务异常的情况偏多,而对于上述LZ做碰到的频繁的线程查询而导致的CPU彪高,应该也是很难遇到的。。。当然,,如果遇到类似的问题,一定也要记得关注下执行频率而会导致的问题。
 
此处推荐一份已经被验证过的常用的MySQL服务器配置方式,以及已经被优化过的mysqlDB.5.7.20的安装包:
提取码:a47j
[client]
port = 3306
default-character-set=utf8
#character_set_server=utf8
 
 
[mysqld]
port = 3306
character_set_server=utf8
basedir = /opt/mysqlDB/mysql
datadir = /opt/mysqlDB/dbData
server-id = 1 #表示是本机的序号为1,一般来讲就是master的意思
skip-name-resolve
#skip-networking
back_log = 600
max_connections = 1000
open_files_limit = 65535
table_open_cache = 128
max_allowed_packet = 4M
binlog_cache_size = 1M
max_heap_table_size = 8M
tmp_table_size = 16M
read_buffer_size = 2M
read_rnd_buffer_size = 8M
sort_buffer_size = 8M
join_buffer_size = 8M
thread_cache_size = 16
query_cache_size = 8M
query_cache_limit = 2M
key_buffer_size = 4M
log_bin = /opt/mysqlDB/logs/binLog/mysql-bin
binlog_format = mixed
expire_logs_days = 7 #超过7天的binlog删除
log_error = /opt/mysqlDB/logs/errorLog/mysql-error.log #错误日志路径
slow_query_log = 1
long_query_time = 10 #慢查询时间 超过1秒则为慢查询
slow_query_log_file = /opt/mysqlDB/logs/slowLog/mysql-slow.log
performance_schema = 0
explicit_defaults_for_timestamp
lower_case_table_names = 1 #不区分大小写
skip-external-locking #MySQL选项以避免外部锁定。该选项默认开启
default-storage-engine = InnoDB #默认存储引擎
 
 
innodb_file_per_table = 1
innodb_open_files = 500
innodb_buffer_pool_size = 5G
innodb_write_io_threads = 4
innodb_read_io_threads = 4
innodb_thread_concurrency = 0
innodb_purge_threads = 1
innodb_flush_log_at_trx_commit = 2
innodb_log_buffer_size = 2M
innodb_log_file_size = 32M
innodb_log_files_in_group = 3
innodb_max_dirty_pages_pct = 90
innodb_lock_wait_timeout = 120
 
 
bulk_insert_buffer_size = 8M
myisam_sort_buffer_size = 8M
myisam_max_sort_file_size = 10G
myisam_repair_threads = 1
interactive_timeout = 28800
wait_timeout = 28800
 
 
sql_mode=NO_ENGINE_SUBSTITUTION,STRICT_TRANS_TABLES
[mysqldump]
quick
max_allowed_packet = 16M #服务器发送和接受的最大包长度
[myisamchk]
key_buffer_size = 8M
sort_buffer_size = 8M
read_buffer = 4M
write_buffer = 4M
 
 
 
 
相关链接参考推荐:
1、使用sar 命令进行IO以及CPU读写速率的排查,相关 sar 命令参数使用详解可参考如下链接:
2、索引的创建及优化方式: 
3、show processlist 字段解释
 
 
 
 
 
12-11 12:40