A Simple Approach to Troubleshooting High CPU in MySQL
我们的一位客户最近问,是否有可能从MySQL方面识别导致系统CPU使用率高的查询。 PostgreSQL和Oracle DBA长期以来一直使用简单的OS工具查找罪魁祸首,但是它对MySQL无效,因为历史上我们一直缺乏将OS线程与内部线程进行匹配的工具 - 直到最近。
Percona添加了支持,可从针对MySQL 5.6.27的Percona Server开始,通过information_schema.processlist表的TID列将进程列表ID映射到OS线程ID。 在5.7发行版中,MySQL扩展了PERFORMANCE_SCHEMA.THREADS表并添加了一个名为THREAD_OS_ID的新列,从而实现了自己的实现,Percona Server for MySQL代替了自己的列,因为它通常尽可能地靠近上游。
对于在其他内核正常运行时查询使一个特定CPU过载的情况,以下方法很有用。 对于一般的CPU使用问题,可以使用不同的方法,例如另一篇博客文章Reducing High CPU on MySQL: A Case Study的方法.
我们如何使用这个新列来找出哪个会话使用了数据库中最多的CPU资源?
让我们举个例子:
要解决CPU问题,我们可以使用几种工具,例如top或pidstat(需要sysstat程序包)。 在下面的示例中,我们将使用pidstat。 该工具有一个选项(-t),可将其视图从进程(默认值)更改为线程,在其中显示给定进程内的关联线程。 我们可以使用它来找出哪个线程在服务器中消耗了最多的CPU。 将-p参数与mysql进程ID一起添加,以便该工具仅显示MySQL线程,从而使我们更容易进行故障排除。 最后一个参数(1)是每秒显示一个样本:
命令为pidstat -t -p <mysqld_pid> 1
:
shell> pidstat -t -p 31258 1
03:31:06 PM UID TGID TID %usr %system %guest %CPU CPU Command
[...]
03:31:07 PM 10014 - 32039 5.00 1.00 0.00 6.00 22 |__mysqld
03:31:07 PM 10014 - 32040 5.00 1.00 0.00 6.00 23 |__mysqld
03:31:07 PM 10014 - 32042 6.00 1.00 0.00 7.00 8 |__mysqld
03:31:07 PM 10014 - 32047 5.00 1.00 0.00 6.00 6 |__mysqld
03:31:07 PM 10014 - 32048 5.00 1.00 0.00 6.00 15 |__mysqld
03:31:07 PM 10014 - 32049 5.00 1.00 0.00 6.00 14 |__mysqld
03:31:07 PM 10014 - 32052 5.00 1.00 0.00 6.00 14 |__mysqld
03:31:07 PM 10014 - 32053 94.00 0.00 0.00 94.00 9 |__mysqld
03:31:07 PM 10014 - 32055 4.00 1.00 0.00 5.00 10 |__mysqld
03:31:07 PM 10014 - 4275 5.00 1.00 0.00 6.00 10 |__mysqld
03:31:07 PM 10014 - 4276 5.00 1.00 0.00 6.00 7 |__mysqld
03:31:07 PM 10014 - 4277 6.00 1.00 0.00 7.00 15 |__mysqld
03:31:07 PM 10014 - 4278 5.00 1.00 0.00 6.00 18 |__mysqld
03:31:07 PM 10014 - 4279 5.00 1.00 0.00 6.00 10 |__mysqld
03:31:07 PM 10014 - 4280 5.00 1.00 0.00 6.00 12 |__mysqld
03:31:07 PM 10014 - 4281 5.00 1.00 0.00 6.00 11 |__mysqld
03:31:07 PM 10014 - 4282 4.00 1.00 0.00 5.00 2 |__mysqld
03:31:07 PM 10014 - 35261 0.00 0.00 0.00 0.00 4 |__mysqld
03:31:07 PM 10014 - 36153 0.00 0.00 0.00 0.00 5 |__mysqld
我们可以看到线程32053在很大程度上消耗了最多的CPU,并且我们确保验证了在pidstat的多个样本之间的消耗是否恒定。 利用这些信息,我们可以登录数据库,并使用以下查询来找出哪个MySQL Thread是罪魁祸首:
mysql > select * from performance_schema.threads where THREAD_OS_ID = 32053 \G
*************************** 1. row ***************************
THREAD_ID: 686
NAME: thread/sql/one_connection
TYPE: FOREGROUND
PROCESSLIST_ID: 590
PROCESSLIST_USER: msandbox
PROCESSLIST_HOST: localhost
PROCESSLIST_DB: NULL
PROCESSLIST_COMMAND: Query
PROCESSLIST_TIME: 0
PROCESSLIST_STATE: Sending data
PROCESSLIST_INFO: select * from test.joinit where b = 'a a eveniet ut.'
PARENT_THREAD_ID: NULL
ROLE: NULL
INSTRUMENTED: YES
HISTORY: YES
CONNECTION_TYPE: SSL/TLS
THREAD_OS_ID: 32053
1 row in set (0.00 sec)
好了! 现在我们知道,CPU高消耗来自joinit表中的查询,该查询由数据库测试中来自本地主机的用户msandbox执行。 使用此信息,我们可以对查询进行故障排除,并使用EXPLAIN命令检查执行计划,以查看是否还有任何改进的余地。
mysql > explain select * from test.joinit where b = 'a a eveniet ut.' \G
*************************** 1. row ***************************
id: 1
select_type: SIMPLE
table: joinit
partitions: NULL
type: ALL
possible_keys: NULL
key: NULL
key_len: NULL
ref: NULL
rows: 7170836
filtered: 10.00
Extra: Using where
1 row in set, 1 warning (0.00 sec)
In this case, it was a simple index that was missing!
mysql > alter table test.joinit add index (b) ;
Query OK, 0 rows affected (15.18 sec)
Records: 0 Duplicates: 0 Warnings: 0
After we create the index, we are no longer seeing CPU spikes:
shell> pidstat -t -p 31258 1
03:37:53 PM UID TGID TID %usr %system %guest %CPU CPU Command
[...]
03:37:54 PM 10014 - 32039 25.00 6.00 0.00 31.00 0 |__mysqld
03:37:54 PM 10014 - 32040 25.00 5.00 0.00 30.00 21 |__mysqld
03:37:54 PM 10014 - 32042 25.00 6.00 0.00 31.00 20 |__mysqld
03:37:54 PM 10014 - 32047 25.00 4.00 0.00 29.00 23 |__mysqld
03:37:54 PM 10014 - 32048 25.00 7.00 0.00 32.00 22 |__mysqld
03:37:54 PM 10014 - 32049 23.00 6.00 0.00 29.00 4 |__mysqld
03:37:54 PM 10014 - 32052 23.00 7.00 0.00 30.00 14 |__mysqld
03:37:54 PM 10014 - 32053 10.00 2.00 0.00 12.00 11 |__mysqld
03:37:54 PM 10014 - 32055 24.00 6.00 0.00 30.00 1 |__mysqld
03:37:54 PM 10014 - 4275 25.00 6.00 0.00 31.00 7 |__mysqld
03:37:54 PM 10014 - 4276 25.00 6.00 0.00 31.00 1 |__mysqld
03:37:54 PM 10014 - 4277 24.00 5.00 0.00 29.00 14 |__mysqld
03:37:54 PM 10014 - 4278 24.00 6.00 0.00 30.00 9 |__mysqld
03:37:54 PM 10014 - 4279 25.00 5.00 0.00 30.00 6 |__mysqld
03:37:54 PM 10014 - 4280 26.00 5.00 0.00 31.00 14 |__mysqld
03:37:54 PM 10014 - 4281 24.00 6.00 0.00 30.00 10 |__mysqld
03:37:54 PM 10014 - 4282 25.00 6.00 0.00 31.00 10 |__mysqld
03:37:54 PM 10014 - 35261 0.00 0.00 0.00 0.00 4 |__mysqld
03:37:54 PM 10014 - 36153 0.00 0.00 0.00 0.00 5 |__mysqld
为什么不使用这种方法来解决IO和内存问题?
从OS端测量线程IO的问题在于,大多数MySQL IO操作是由后台线程完成的,例如读取,写入和页面清理程序线程。 要测量线程IO,您可以使用带有-d(IO而不是CPU)选项的pidstat或带有-H(每个线程)的iostat之类的工具。 如果您有一个非常消耗IO的线程,您也许可以看到它,但是要警告,由于后台线程操作,结果可能会产生误导。
内存消耗是要从OS端衡量的一个更加棘手的资源,因为所有内存都是在MySQL进程下分配的,并且由于是MySQL管理其内存访问,因此对于OS来说哪个线程消耗最多的内存是透明的。 为此,我们可以使用从5.7开始使用perfomance_schema memory instrumentation available starting in 5.7.
结论
有很多方法可以解决CPU使用率过高的问题,但是从5.7版开始,我们在Oracle和PostgreSQL数据库上提供了一种简单且广泛使用的方法,该方法可以适应MySQL。 通过从OS线程消耗跟踪到数据库端,我们可以快速检测到影响系统性能的CPU密集型查询。