mysql one thread cpu 100%

标签：kth   统一   cli   5.5   cal   sch   com   cache   性能优化   

昨天晚上，运维过来说有台生产服务器的mysql cpu一直100%，新的客户端登录不了，但是已经在运行的应用都正常可用。

登录服务器后，top -H看了下，其中一个线程的cpu 一直100%，其他的几乎都空闲。

MySQL thread id 14560536, OS thread handle 0x7f1255ef1700, query id 31889137761 10.26.124.8 osm cleaning up

top - 18:56:26 up 62 days, 3:55, 3 users, load average: 1.08, 1.13, 1.18
Tasks: 1503 total, 2 running, 1501 sleeping, 0 stopped, 0 zombie
Cpu(s): 12.9%us, 0.2%sy, 0.0%ni, 86.9%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 16333644k total, 15440672k used, 892972k free, 45652k buffers
Swap: 4153340k total, 0k used, 4153340k free, 1050524k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
15669 mysql 20 0 8338m 5.9g 5808 R 100.0 38.1 162:29.18 mysqld
29679 rabbitmq 20 0 4315m 154m 1780 S 1.3 1.0 1162:54 beam.smp
3887 root 20 0 16092 2360 940 R 0.7 0.0 0:00.27 top
426 root 20 0 68020 6136 4244 S 0.3 0.0 0:03.34 AliYunDun
427 root 20 0 68020 6136 4244 S 0.3 0.0 0:02.62 AliYunDun
430 root 20 0 68020 6136 4244 S 0.3 0.0 0:08.37 AliYunDun
432 root 20 0 68020 6136 4244 S 0.3 0.0 0:05.34 AliYunDun
1247 root 20 0 245m 49m 1604 S 0.3 0.3 28:40.31 AliHids
1249 root 20 0 245m 49m 1604 S 0.3 0.3 10:17.96 AliHids
3653 root 20 0 113m 1572 932 S 0.3 0.0 0:00.11 wrapper
12293 root 20 0 9722m 1.3g 5940 S 0.3 8.6 20:10.09 java
16457 root 20 0 8710m 166m 5772 S 0.3 1.0 1:52.67 java
16914 root 20 0 9864m 168m 5808 S 0.3 1.1 19:30.97 java
29680 rabbitmq 20 0 4315m 154m 1780 S 0.3 1.0 578:21.03 beam.smp
1 root 20 0 19356 800 500 S 0.0 0.0 0:02.80 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.03 kthreadd
3 root RT 0 0 0 0 S 0.0 0.0 0:15.65 migration/0
4 root 20 0 0 0 0 S 0.0 0.0 0:32.07 ksoftirqd/0
5 root RT 0 0 0 0 S 0.0 0.0 0:00.00 stopper/0
6 root RT 0 0 0 0 S 0.0 0.0 0:05.98 watchdog/0

这个问题已经发生过接近10来次了，只不过之前除了一两次是其他的生产系统外，大部分发生在开发环境，一直也没找到原因，一旦kill这个线程，就导致mysql实例被kill并自动重启了。

因为之前发生过，没解决，所以刚好那台服务器的Innodb_monitor开着，但是根据时间往后退算到差不多出问题的那一刻，只看到有一个事务从出问题开始一直持续运行了差不多20多分钟，如下：

FILE I/O
--
MySQL thread id 14560536, OS thread handle 0x7f122db3c700, query id 31889113153 10.26.124.8 osm cleaning up
---TRANSACTION 604639618, ACTIVE 1248 sec
MySQL thread id 14561064, OS thread handle 0x7f122db3c700, query id 31887588399 125.118.111.42 osm cleaning up
--------
FILE I/O
--
MySQL thread id 14560536, OS thread handle 0x7f122db3c700, query id 31889113154 10.26.124.8 osm cleaning up
---TRANSACTION 604639618, ACTIVE 1268 sec
MySQL thread id 14561064, OS thread handle 0x7f122db3c700, query id 31887588399 125.118.111.42 osm cleaning up
--------
FILE I/O
--
MySQL thread id 14560536, OS thread handle 0x7f122db3c700, query id 31889113373 10.26.124.8 osm cleaning up
---TRANSACTION 604639618, ACTIVE 1288 sec
MySQL thread id 14561064, OS thread handle 0x7f122db3c700, query id 31887588399 125.118.111.42 osm cleaning up

因为所有的系统配置参数、mysql都是统一的，OS版本、内核版本都是一致的，所以应该不是版本和某个参数导致的问题。

跟相关运维确认的时候，只说用gui连接过，但是没有做运行慢的操作比如直接通过navicat进行导出等操作。所以这个问题比较像之前遇到的内存问题，光靠模拟它好像永远不出来，但某个时间就出来了。

strace和ltrace也没看出什么问题，那会儿实在比较郁闷。。。折腾到后来，mysqld不知怎么被不小心的killed了。

早上回来，继续研究，搜了bing半天，最后在mysql buglist发现就是5.5.23之前有个performance_schema的bug，跟我们的现象极为相似，如下：

http://bugs.mysql.com/bug.php?id=64491

http://lists.mysql.com/commits/143350?f=plain

one thread call sched_yield(), but other threads are‘t ready run. so cause cpu 100%.

 但根据开发者所说这个问题在5.5.23以及5.6.6就已经修复，我们使用的是percona server 5.6.31，理论上应该不会出现这个bug的。

因为现在没有当时的现场了，只能等下次出现gdb上去看下，那个出问题的线程在执行什么操作了，还是非c++出身gdb不熟导致的，哎。。。这个负责性能优化的gdb/wireshark真得熟悉的滚瓜烂熟，不然有些诡异的现象光通过服务器本身提供的API和CLI和一些高级工具真不能定位到原因啊。。

mysql one thread cpu 100%

标签：kth   统一   cli   5.5   cal   sch   com   cache   性能优化   

原文地址：http://www.cnblogs.com/zhjh256/p/6185633.html