mysql突然出现大量慢sql,随后redis访问超时
在亚马逊云买了多台的虚拟主机,一年多没有由于系统的原因出过故障。今天碰见了。
早上接到报警,从业务故障上来看,应该是数据库没有响应了。
SSH连数据库服务器,发现连不上。
重启数据库服务器,一直起不来。
最后用上周的数据库服务器的系统备份snapshot(我们的数据盘和系统盘是分开的)新建一个Volume,替换掉故障系统盘,重新启动服务器,才顺利进入系统。在用新的Volume挂靠服务器的时候,一定要记得,设备名称要和原来的系统Volume的名称一致,服务器才能顺利启动:
Root device /dev/sda1
MYSQL服务启动后,所有服务按照顺序重启一遍,业务恢复。
从业务日志上来看,在6月23日22:06分左右出现大量慢sql日志,非常简单的sql语句都会等待10秒以上,随后不久出现大量redis拒绝服务的错误日志。(Redis和数据库服务部署在同一台机器上),最终导致ssh都连接不上,系统处于宕机状态。
分析当时的CPU和磁盘IO都处于健康状态。
分析Linux系统/var/log/message的日志,发现在Jun 23 08:06:33开始就出现JAVA的OOM
Jun 23 08:06:33 App-01 kernel: java invoked oom-killer: gfp_mask=0x280da, order=0, oom_adj=0, oom_score_adj=0
Jun 23 08:06:33 App-01 kernel: java cpuset=/ mems_allowed=0
Jun 23 08:06:33 App-01 kernel: Pid: 30096, comm: java Not tainted 2.6.32-431.17.1.el6.x86_64 #1
然后出现出现各种系统错误日志。
分析/var/log/mysqld.log,发现在23点左右出现以下日志:
InnoDB: Warning: a long semaphore wait:
--Thread 140539730044672 has waited at btr0cur.cc line 257 for 1775.0 seconds the semaphore:
X-lock on RW-latch at 0x7fd1f7f589c0 '&block->lock'
number of readers 0, waiters flag 0, lock_word: 100000
Last time read locked in file btr0cur.cc line 257
Last time write locked in file /home/mysql/storage/innobase/btr/btr0cur.cc line 362
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
InnoDB: Pending preads 0, pwrites 0
=====================================
2015-06-23 23:02:52 7fd1eb5fe700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 1571 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 2215108 srv_active, 0 srv_shutdown, 164283 srv_idle
srv_master_thread log flush and writes: 2379391
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 815307
OS WAIT ARRAY INFO: signal count 905349
Mutex spin waits 13126865, rounds 31704200, OS waits 415905
RW-shared spins 503431, rounds 12970865, OS waits 375385
RW-excl spins 58495, rounds 950616, OS waits 5991
Spin rounds per wait: 2.42 mutex, 25.76 RW-shared, 16.25 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 226393815
Purge done for trx's n:o < 226393810 undo n:o < 0 state: running but idle
History list length 1365
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 226393813, not started
MySQL thread id 18660718, OS thread handle 0x7fd0ec968700, query id 195313941 ip-172-31-7-84.ap-southeast-1.compute.internal 172.31.7.84 admin cleaning up
---TRANSACTION 226393812, not started
MySQL thread id 18660719, OS thread handle 0x7fd1e4e59700, query id 195313940 ip-172-31-7-84.ap-southeast-1.compute.internal 172.31.7.84 admin cleaning up
---TRANSACTION 226393627, not started
MySQL thread id 18660553, OS thread handle 0x7fd1e63ad700, query id 195314129 ip-172-31-7-84.ap-southeast-1.compute.internal 172.31.7.84 admin cleaning up
---TRANSACTION 226393626, not started
MySQL thread id 18660552, OS thread handle 0x7fd1e5cd2700, query id 195314130 ip-172-31-7-84.ap-southeast-1.compute.internal 172.31.7.84 admin cleaning up
---TRANSACTION 226393625, not started
MySQL thread id 18660617, OS thread handle 0x7fd0ec189700, query id 195314208 ip-172-31-7-84.ap-southeast-1.compute.internal 172.31.7.84 admin cleaning up
---TRANSACTION 226393624, not started
MySQL thread id 18660618, OS thread handle 0x7fd0ec148700, query id 195314209 ip-172-31-7-84.ap-southeast-1.compute.internal 172.31.7.84 admin cleaning up
分析结论:
业务高峰期,JAVA/REDIS/MYSQL对服务器内存的需求都到达顶峰(目前JAVA进程的内存没有限制),在所有JAVA进程都没有FULLGC之前,可能会存在一个内存峰值,引发Linux系统开始*进程。
Linux*进程的过程中往往抓个最大的开始搞,mysql,redis就非常容易被搞掉。
因为这些服务还会自动重启,Linux杀着杀着就把自己给杀蒙了,就宕机了。
应对策略:
1.买两台内存更大的服务器作为资源服务器,MYSQL和REDIS从应用应用服务器迁移到资源服务器。
2.对MYSQL和Redis做高可用架构应对单机宕机的情形。
3.调整inux内核信号量默认设置,让MYSQL能撑的时间长一点。
参考文档:
http://www.cnblogs.com/GoodGoodWorkDayDayUp/p/3473348.html
http://blog.csdn.net/wulantian/article/details/37560849