译文-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
:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 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 |__mysqld03 :31 :07 PM 10014 - 32040 5 .00 1 .00 0 .00 6 .00 23 |__mysqld03 :31 :07 PM 10014 - 32042 6 .00 1 .00 0 .00 7 .00 8 |__mysqld03 :31 :07 PM 10014 - 32047 5 .00 1 .00 0 .00 6 .00 6 |__mysqld03 :31 :07 PM 10014 - 32048 5 .00 1 .00 0 .00 6 .00 15 |__mysqld03 :31 :07 PM 10014 - 32049 5 .00 1 .00 0 .00 6 .00 14 |__mysqld03 :31 :07 PM 10014 - 32052 5 .00 1 .00 0 .00 6 .00 14 |__mysqld03 :31 :07 PM 10014 - 32053 94 .00 0 .00 0 .00 94 .00 9 |__mysqld03 :31 :07 PM 10014 - 32055 4 .00 1 .00 0 .00 5 .00 10 |__mysqld03 :31 :07 PM 10014 - 4275 5 .00 1 .00 0 .00 6 .00 10 |__mysqld03 :31 :07 PM 10014 - 4276 5 .00 1 .00 0 .00 6 .00 7 |__mysqld03 :31 :07 PM 10014 - 4277 6 .00 1 .00 0 .00 7 .00 15 |__mysqld03 :31 :07 PM 10014 - 4278 5 .00 1 .00 0 .00 6 .00 18 |__mysqld03 :31 :07 PM 10014 - 4279 5 .00 1 .00 0 .00 6 .00 10 |__mysqld03 :31 :07 PM 10014 - 4280 5 .00 1 .00 0 .00 6 .00 12 |__mysqld03 :31 :07 PM 10014 - 4281 5 .00 1 .00 0 .00 6 .00 11 |__mysqld03 :31 :07 PM 10014 - 4282 4 .00 1 .00 0 .00 5 .00 2 |__mysqld03 :31 :07 PM 10014 - 35261 0 .00 0 .00 0 .00 0 .00 4 |__mysqld03 :31 :07 PM 10014 - 36153 0 .00 0 .00 0 .00 0 .00 5 |__mysqld
我们可以看到线程32053在很大程度上消耗了最多的CPU,并且我们确保验证了在pidstat的多个样本之间的消耗是否恒定。 利用这些信息,我们可以登录数据库,并使用以下查询来找出哪个MySQL Thread是罪魁祸首:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 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命令检查执行计划,以查看是否还有任何改进的余地。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 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!
1 2 3 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:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 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 |__mysqld03 :37 :54 PM 10014 - 32040 25 .00 5 .00 0 .00 30 .00 21 |__mysqld03 :37 :54 PM 10014 - 32042 25 .00 6 .00 0 .00 31 .00 20 |__mysqld03 :37 :54 PM 10014 - 32047 25 .00 4 .00 0 .00 29 .00 23 |__mysqld03 :37 :54 PM 10014 - 32048 25 .00 7 .00 0 .00 32 .00 22 |__mysqld03 :37 :54 PM 10014 - 32049 23 .00 6 .00 0 .00 29 .00 4 |__mysqld03 :37 :54 PM 10014 - 32052 23 .00 7 .00 0 .00 30 .00 14 |__mysqld03 :37 :54 PM 10014 - 32053 10 .00 2 .00 0 .00 12 .00 11 |__mysqld03 :37 :54 PM 10014 - 32055 24 .00 6 .00 0 .00 30 .00 1 |__mysqld03 :37 :54 PM 10014 - 4275 25 .00 6 .00 0 .00 31 .00 7 |__mysqld03 :37 :54 PM 10014 - 4276 25 .00 6 .00 0 .00 31 .00 1 |__mysqld03 :37 :54 PM 10014 - 4277 24 .00 5 .00 0 .00 29 .00 14 |__mysqld03 :37 :54 PM 10014 - 4278 24 .00 6 .00 0 .00 30 .00 9 |__mysqld03 :37 :54 PM 10014 - 4279 25 .00 5 .00 0 .00 30 .00 6 |__mysqld03 :37 :54 PM 10014 - 4280 26 .00 5 .00 0 .00 31 .00 14 |__mysqld03 :37 :54 PM 10014 - 4281 24 .00 6 .00 0 .00 30 .00 10 |__mysqld03 :37 :54 PM 10014 - 4282 25 .00 6 .00 0 .00 31 .00 10 |__mysqld03 :37 :54 PM 10014 - 35261 0 .00 0 .00 0 .00 0 .00 4 |__mysqld03 :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密集型查询。