五一当天，公司下午2点，数据库的机器突然访问不了。应用不能访问了。客户无法使用！客服同志打电话通知，我当时在外面陪女儿玩，周边没有电脑。为了应付紧急状况，马上重启了机器。重启后可以使用了。具体什么原因导致这一的现象还要仔细分析。
第一步，找出宕机半个小时之内的CPU，内存，网络等检测数据！检测结果是这样的：
从上面四个图可以看出，内存和网络正常，只有CPU从13：50开始一直使用过高，突然增长到90%！
由此分析出
原因一，Query查询响应过慢，也就是个别查询占用时间太长。
原因二，磁盘出问题
或许还有其他原因，目前还没经验分析出来
第二步，我接到电话后赶紧在附近找了一个商务中心，借了一台电脑，登陆到了首都在线的云端，查看mysql数据库机器的日志，昨天13：50左右出现了这样一段日志：
InnoDB: Warning: a long semaphore wait: --Thread 140157120059136 has waited at lock0lock.cc line 6837 for 289.00 seconds the semaphore: Mutex at 0x7f79ec457078 created file lock0lock.cc line 611, lock var 1 waiters flag 1 InnoDB: Warning: a long semaphore wait: --Thread 140157120661248 has waited at trx0trx.cc line 1195 for 290.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 InnoDB: Warning: a long semaphore wait: --Thread 140161374390016 has waited at trx0sys.ic line 431 for 290.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 InnoDB: Warning: a long semaphore wait: --Thread 140161383220992 has waited at trx0trx.cc line 193 for 272.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 InnoDB: Warning: a long semaphore wait: --Thread 140161379407616 has waited at trx0trx.cc line 863 for 271.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 InnoDB: Warning: a long semaphore wait: --Thread 140157120259840 has waited at trx0trx.cc line 2013 for 270.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 InnoDB: Warning: a long semaphore wait: --Thread 140161431643904 has waited at lock0lock.cc line 6837 for 270.00 seconds the semaphore: Mutex at 0x7f79ec457078 created file lock0lock.cc line 611, lock var 1 waiters flag 1 InnoDB: Warning: a long semaphore wait: --Thread 140161432647424 has waited at trx0trx.cc line 863 for 262.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info: InnoDB: Pending preads 0, pwrites 1 ===================================== 2016-05-01 13:51:01 7f79e4b4b700 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 68 seconds ----------------- BACKGROUND THREAD ----------------- srv_master_thread loops: 11249 srv_active, 0 srv_shutdown, 208673 srv_idle srv_master_thread log flush and writes: 219885 ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 37569 --Thread 140161388840704 has waited at trx0rec.cc line 1295 for 0.00 seconds the semaphore: X-lock (wait_ex) on RW-latch at 0x7f7a246dadc0 created in file buf0buf.cc line 1069 a writer (thread id 140161388840704) has reserved it in mode wait exclusive number of readers 1, waiters flag 0, lock_word: ffffffffffffffff Last time read locked in file buf0flu.cc line 1056 Last time write locked in file /usr/local/src/mysql-5.6.27/storage/innobase/trx/trx0rec.cc line 1295 wait has ended --Thread 140161446295296 has waited at lock0lock.cc line 6837 for 36.00 seconds the semaphore: Mutex at 0x7f79ec457078 created file lock0lock.cc line 611, lock var 1 waiters flag 1 --Thread 140157129492224 has waited at trx0trx.cc line 193 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140157119256320 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140157121464064 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161369372416 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161394259712 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140157125478144 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161371780864 has waited at trx0trx.cc line 1195 for 36.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161521604352 has waited at lock0wait.cc line 510 for 52.00 seconds the semaphore: Mutex at 0x7f79ec4570c8 created file lock0lock.cc line 614, lock var 1 waiters flag 1 --Thread 140157123069696 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140157119055616 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161397470976 has waited at lock0lock.cc line 5946 for 36.00 seconds the semaphore: Mutex at 0x7f79ec457078 created file lock0lock.cc line 611, lock var 1 waiters flag 1 --Thread 140157121865472 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161375393536 has waited at trx0trx.cc line 863 for 43.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161380009728 has waited at lock0lock.cc line 6837 for 36.00 seconds the semaphore: Mutex at 0x7f79ec457078 created file lock0lock.cc line 611, lock var 1 waiters flag 1 --Thread 140161435457280 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140157119457024 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161370375936 has waited at trx0trx.cc line 193 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140157121664768 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161430038272 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161449305856 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161394861824 has waited at trx0trx.cc line 1195 for 37.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 InnoDB: ###### Diagnostic info printed to the standard error stream --Thread 140157126481664 has waited at lock0lock.cc line 6837 for 37.00 seconds the semaphore: Mutex at 0x7f79ec457078 created file lock0lock.cc line 611, lock var 1 waiters flag 1 --Thread 140157119657728 has waited at trx0sys.ic line 431 for 37.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140157118453504 has waited at trx0trx.cc line 863 for 37.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140157118854912 has waited at lock0lock.cc line 6837 for 37.00 seconds the semaphore: Mutex at 0x7f79ec457078 created file lock0lock.cc line 611, lock var 1 waiters flag 1 --Thread 140161388439296 has waited at trx0trx.cc line 2013 for 37.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161445693184 has waited at lock0lock.cc line 4416 for 37.00 seconds the semaphore: Mutex at 0x7f79ec457078 created file lock0lock.cc line 611, lock var 1 waiters flag 1 --Thread 140161441879808 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140157122066176 has waited at trx0trx.cc line 863 for 53.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161431643904 has waited at trx0trx.cc line 1195 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161426425600 has waited at lock0lock.cc line 6837 for 37.00 seconds the semaphore: Mutex at 0x7f79ec457078 created file lock0lock.cc line 611, lock var 1 waiters flag 1 --Thread 140161432848128 has waited at trx0trx.cc line 1195 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161379206912 has waited at trx0trx.cc line 1195 for 37.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161496426240 has waited at read0read.cc line 414 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161383220992 has waited at trx0rec.cc line 1457 for 49.00 seconds the semaphore: S-lock on RW-latch at 0xd1d3278 created in file trx0purge.cc line 128 a writer (thread id 140161496426240) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file trx0rec.cc line 1457 Last time write locked in file /usr/local/src/mysql-5.6.27/storage/innobase/trx/trx0purge.cc line 1197 --Thread 140161374390016 has waited at lock0wait.cc line 95 for 36.00 seconds the semaphore: Mutex at 0x7f79ec457078 created file lock0lock.cc line 611, lock var 1 waiters flag 1 --Thread 140161381816064 has waited at lock0lock.cc line 6837 for 36.00 seconds the semaphore: Mutex at 0x7f79ec457078 created file lock0lock.cc line 611, lock var 1 waiters flag 1 --Thread 140161441478400 has waited at trx0rec.cc line 1457 for 56.00 seconds the semaphore: S-lock on RW-latch at 0xd1d3278 created in file trx0purge.cc line 128 a writer (thread id 140161496426240) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file trx0rec.cc line 1457 Last time write locked in file /usr/local/src/mysql-5.6.27/storage/innobase/trx/trx0purge.cc line 1197 --Thread 140161432647424 has waited at trx0trx.cc line 863 for 56.00 seconds the semaphore: Mutex at 0xd1c60f8 created file trx0sys.cc line 597, lock var 0 waiters flag 0 --Thread 140161529997056 has waited at log0log.cc line 2159 for 49.00 seconds the semaphore: S-lock on RW-latch at 0xd1be058 created in file log0log.cc line 907 number of readers 0, waiters flag 0, lock_word: 100000 Last time read locked in file log0log.cc line 2159 Last time write locked in file /usr/local/src/mysql-5.6.27/storage/innobase/log/log0log.cc line 1944 OS WAIT ARRAY INFO: signal count 78027 Mutex spin waits 203541, rounds 135641, OS waits 1189 RW-shared spins 64274, rounds 1104435, OS waits 34133 RW-excl spins 38583, rounds 268488, OS waits 2065 Spin rounds per wait: 0.67 mutex, 17.18 RW-shared, 6.96 RW-excl FAIL TO OBTAIN LOCK MUTEX, SKIP LOCK INFO PRINTING -------- FILE I/O -------- I/O thread 0 state: waiting for i/o request (insert buffer thread) I/O thread 1 state: waiting for i/o request (log thread) I/O thread 2 state: waiting for i/o request (read thread) I/O thread 3 state: waiting for i/o request (read thread) I/O thread 4 state: waiting for i/o request (read thread) I/O thread 5 state: waiting for i/o request (read thread) I/O thread 6 state: complete io for buf page (write thread) ev set I/O thread 7 state: waiting for i/o request (write thread) I/O thread 8 state: waiting for i/o request (write thread) I/O thread 9 state: waiting for i/o request (write thread) Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] , ibuf aio reads: 0, log i/o‘s: 0, sync i/o‘s: 0 Pending flushes (fsync) log: 0; buffer pool: 1 116146 OS file reads, 287569 OS file writes, 176487 OS fsyncs 0.00 reads/s, 0 avg bytes/read, 0.30 writes/s, 0.17 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf: size 1, free list len 14, seg size 16, 20355 merges merged operations: insert 23246, delete mark 0, delete 0 discarded operations: insert 0, delete mark 0, delete 0 Hash table size 12749851, node heap has 3154 buffer(s) 527.29 hash searches/s, 35.50 non-hash searches/s --- LOG --- Log sequence number 12608071674 Log flushed up to 12608071674 Pages flushed up to 12608062434 Last checkpoint at 12608062035 0 pending log writes, 0 pending chkp writes 38319 log i/o‘s done, 0.03 log i/o‘s/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 6593445888; in additional pool allocated 0 Dictionary memory allocated 2835498 Buffer pool size 393212 Free buffers 262259 Database pages 127799 Old database pages 47258 Modified db pages 15 Pending reads 0 Pending writes: LRU 0, flush list 3, single page 0 Pages made young 36, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 124071, created 3728, written 229860 0.00 reads/s, 0.00 creates/s, 0.27 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 127799, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---------------------- INDIVIDUAL BUFFER POOL INFO ---------------------- ---BUFFER POOL 0 Buffer pool size 49152 Free buffers 32497 Database pages 16268 Old database pages 6020 Modified db pages 4 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 4, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 15847, created 421, written 37802 0.00 reads/s, 0.00 creates/s, 0.00 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 16268, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 1 Buffer pool size 49151 Free buffers 32784 Database pages 15965 Old database pages 5913 Modified db pages 2 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 5, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 15489, created 476, written 26109 0.00 reads/s, 0.00 creates/s, 0.00 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 15965, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 2 Buffer pool size 49152 Free buffers 33272 Database pages 15486 Old database pages 5736 Modified db pages 1 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 2, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 15161, created 325, written 23667 0.00 reads/s, 0.00 creates/s, 0.00 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 15486, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 3 Buffer pool size 49151 Free buffers 32607 Database pages 16140 Old database pages 5975 Modified db pages 2 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 3, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 15684, created 456, written 31295 0.00 reads/s, 0.00 creates/s, 0.00 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 16140, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 4 Buffer pool size 49152 Free buffers 32504 Database pages 16250 Old database pages 6002 Modified db pages 1 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 8, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 15740, created 510, written 32564 0.00 reads/s, 0.00 creates/s, 0.05 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 16250, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 5 Buffer pool size 49151 Free buffers 32925 Database pages 15839 Old database pages 5847 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 5, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 15239, created 600, written 27844 0.00 reads/s, 0.00 creates/s, 0.10 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 15839, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 6 Buffer pool size 49152 Free buffers 33046 Database pages 15718 Old database pages 5790 Modified db pages 2 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 5, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 15179, created 539, written 24954 0.00 reads/s, 0.00 creates/s, 0.08 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 15718, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 7 Buffer pool size 49151 Free buffers 32624 Database pages 16133 Old database pages 5975 Modified db pages 3 Pending reads 0 Pending writes: LRU 0, flush list 3, single page 0 Pages made young 4, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 15732, created 401, written 25625 0.00 reads/s, 0.00 creates/s, 0.05 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 16133, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] -------------- ROW OPERATIONS -------------- 0 queries inside InnoDB, 0 queries in queue 61 read views open inside InnoDB Main thread process no. 17977, id 140161529997056, state: making checkpoint Number of rows inserted 147712, updated 47959, deleted 89012, read 2163996308 0.03 inserts/s, 0.00 updates/s, 0.00 deletes/s, 2529.48 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================
从上面日志能分析，原来linux内核信号量默认设置太小，并发高的时候，造成大量等待，
默认
# cat /proc/sys/kernel/sem
250 32000 32 128
信号量：
# ipcs -ls
—— Semaphore Limits ——–
max number of arrays = 128
max semaphores per array = 250
max semaphores system wide = 32000
max ops per semop call = 100
SEMMSL
SEMMNI
含义：linux系统信号量set最大个数
设置：最少128
SEMMNS
含义：linux系统中信号量最大个数
设置：至少32000；SEMMSL * SEMMNI
SEMOPM
含义：semop系统调用允许的信号量最大个数
设置：至少100；或者等于SEMMSL
查看信号量设置：cat /proc/sys/kernel/sem
order：SEMMSL, SEMMNS, SEMOPM, SEMMNI
# cat /proc/sys/kernel/sem
250 32000 100 128
修改：
sysctl -w kernel.sem="250 32000 100 128"
echo "kernel.sem=250 32000 100 128">> /etc/sysctl.conf
这样问题就能够得到解决了！
本文出自 “轻餐邦-带鱼” 博客，请务必保留此出处http://daiyiyi.blog.51cto.com/2358701/1769476
ubuntu mysql5.6 数据库占用CPU过高导致机器卡死
原文地址：http://daiyiyi.blog.51cto.com/2358701/1769476
