MySQL服务器昨天在这里坠毁,我不知道为什么(最恼人的崩溃)。 错误日志充满了信号量等待,但我不知道如何解释它的大部分( <path> = /export/home/pb2/build/sb_0-3159149-1301580870.56/mysql-5.5.11/storage/innobase/ ,取而代之以保持某种简洁)。 在这些错误期间,负载,CPU和内存消耗可以忽略/正常:
InnoDB: Warning: a long semaphore wait: --Thread 140054029002496 has waited at <path>/btr/btr0sea.c line 631 for 241.00 seconds the semaphore: X-lock (wait_ex) on RW-latch at 0x78733f8 created in file <path>/btr/btr0sea.c line 182 a writer (thread id 140054029002496) has reserved it in mode wait exclusive number of readers 1, waiters flag 1, lock_word: ffffffffffffffff Last time read locked in file <path>/btr/btr0sea.c line 879 Last time write locked in file <path>/btr/btr0cur.c line 1896 InnoDB: Warning: a long semaphore wait: --Thread 140054051079936 has waited at <path>/btr/btr0cur.c line 1896 for 241.00 seconds the semaphore: X-lock on RW-latch at 0x78733f8 created in file <path>/btr/btr0sea.c line 182 a writer (thread id 140054029002496) has reserved it in mode wait exclusive number of readers 1, waiters flag 1, lock_word: ffffffffffffffff Last time read locked in file <path>/btr/btr0sea.c line 879 Last time write locked in file <path>/btr/btr0cur.c line 1896 InnoDB: Warning: a long semaphore wait: --Thread 140054255666944 has waited at <path>/row/row0sel.c line 3606 for 241.00 seconds the semaphore: S-lock on RW-latch at 0x78733f8 created in file <path>/btr/btr0sea.c line 182 a writer (thread id 140054029002496) has reserved it in mode wait exclusive number of readers 1, waiters flag 1, lock_word: ffffffffffffffff Last time read locked in file <path>/btr/btr0sea.c line 879 Last time write locked in file <path>/btr/btr0cur.c line 1896 InnoDB: Warning: a long semaphore wait: --Thread 140054294693632 has waited at <path>/row/row0sel.c line 2902 for 241.00 seconds the semaphore: S-lock on RW-latch at 0x7f60fa5b7f40 created in file <path>/buf/buf0buf.c line 898 a writer (thread id 140054051079936) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file <path>/row/row0sel.c line 2902 Last time write locked in file <path>/row/row0upd.c line 2131 InnoDB: Warning: a long semaphore wait: --Thread 140054005319424 has waited at <path>/btr/btr0sea.c line 1054 for 241.00 seconds the semaphore: S-lock on RW-latch at 0x78733f8 created in file <path>/btr/btr0sea.c line 182 a writer (thread id 140054029002496) has reserved it in mode wait exclusive number of readers 1, waiters flag 1, lock_word: ffffffffffffffff Last time read locked in file <path>/btr/btr0sea.c line 879 Last time write locked in file <path>/btr/btr0cur.c line 1896 InnoDB: Warning: a long semaphore wait: --Thread 140054272325376 has waited at <path>/trx/trx0trx.c line 208 for 241.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1
最后3行重复了一堆,之后,我得到了InnoDB监视器输出:
===================================== 110523 19:19:05 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 45 seconds ----------------- BACKGROUND THREAD ----------------- srv_master_thread loops: 1661111 1_second, 1661102 sleeps, 166100 10_second, 429 background, 413 flush srv_master_thread log flush and writes: 1662059 ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 3952510, signal count 31019262 --Thread 140054029002496 has waited at <path>/btr/btr0sea.c line 631 for 243.00 seconds the semaphore: X-lock (wait_ex) on RW-latch at 0x78733f8 created in file <path>/btr/btr0sea.c line 182 a writer (thread id 140054029002496) has reserved it in mode wait exclusive number of readers 1, waiters flag 1, lock_word: ffffffffffffffff Last time read locked in file <path>/btr/btr0sea.c line 879 Last time write locked in file <path>/btr/btr0cur.c line 1896 --Thread 140054051079936 has waited at <path>/btr/btr0cur.c line 1896 for 243.00 seconds the semaphore: X-lock on RW-latch at 0x78733f8 created in file <path>/btr/btr0sea.c line 182 a writer (thread id 140054029002496) has reserved it in mode wait exclusive number of readers 1, waiters flag 1, lock_word: ffffffffffffffff Last time read locked in file <path>/btr/btr0sea.c line 879 Last time write locked in file <path>/btr/btr0cur.c line 1896 --Thread 140054255666944 has waited at <path>/row/row0sel.c line 3606 for 243.00 seconds the semaphore: S-lock on RW-latch at 0x78733f8 created in file <path>/btr/btr0sea.c line 182 a writer (thread id 140054029002496) has reserved it in mode wait exclusive number of readers 1, waiters flag 1, lock_word: ffffffffffffffff Last time read locked in file <path>/btr/btr0sea.c line 879 Last time write locked in file <path>/btr/btr0cur.c line 1896 --Thread 140054294693632 has waited at <path>/row/row0sel.c line 2902 for 243.00 seconds the semaphore: S-lock on RW-latch at 0x7f60fa5b7f40 created in file <path>/buf/buf0buf.c line 898 a writer (thread id 140054051079936) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file <path>/row/row0sel.c line 2902 Last time write locked in file <path>/row/row0upd.c line 2131 --Thread 140054005319424 has waited at <path>/btr/btr0sea.c line 1054 for 243.00 seconds the semaphore: S-lock on RW-latch at 0x78733f8 created in file <path>/btr/btr0sea.c line 182 a writer (thread id 140054029002496) has reserved it in mode wait exclusive number of readers 1, waiters flag 1, lock_word: ffffffffffffffff Last time read locked in file <path>/btr/btr0sea.c line 879 Last time write locked in file <path>/btr/btr0cur.c line 1896 --Thread 140054272325376 has waited at <path>/trx/trx0trx.c line 208 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054306334464 has waited at <path>/trx/trx0trx.c line 353 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054310147840 has waited at <path>/trx/trx0trx.c line 1983 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054295697152 has waited at <path>/trx/trx0trx.c line 700 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054344120064 has waited at <path>/row/row0mysql.c line 2233 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054259681024 has waited at <path>/row/row0sel.c line 4708 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054009534208 has waited at <path>/trx/trx0trx.c line 208 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054008129280 has waited at <path>/trx/trx0trx.c line 700 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054303323904 has waited at <path>/trx/trx0trx.c line 208 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054308140800 has waited at <path>/trx/trx0trx.c line 700 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054293088000 has waited at <path>/trx/trx0trx.c line 700 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140053984847616 has waited at <path>/trx/trx0trx.c line 208 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054302119680 has waited at <path>/trx/trx0trx.c line 700 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054307337984 has waited at <path>/trx/trx0trx.c line 208 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054270318336 has waited at <path>/trx/trx0trx.c line 208 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140053899802368 has waited at <path>/trx/trx0trx.c line 208 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054307538688 has waited at <path>/trx/trx0trx.c line 208 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140060523423488 has waited at <path>/trx/trx0trx.c line 208 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140053988259584 has waited at <path>/trx/trx0trx.c line 208 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054050076416 has waited at <path>/trx/trx0trx.c line 208 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140053885150976 has waited at <path>/trx/trx0trx.c line 700 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054007727872 has waited at <path>/trx/trx0trx.c line 700 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054051280640 has waited at <path>/trx/trx0trx.c line 700 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140053661017856 has waited at <path>/trx/trx0trx.c line 700 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054306735872 has waited at <path>/trx/trx0trx.c line 700 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054020171520 has waited at <path>/trx/trx0trx.c line 700 for 243.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140053914253056 has waited at <path>/trx/trx0trx.c line 700 for 242.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054335727360 has waited at <path>/srv/srv0srv.c line 2293 for 242.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140053635929856 has waited at <path>/trx/trx0trx.c line 700 for 242.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140053900805888 has waited at <path>/trx/trx0trx.c line 700 for 242.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140053987858176 has waited at <path>/trx/trx0trx.c line 208 for 242.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054299109120 has waited at <path>/trx/trx0trx.c line 700 for 241.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054259881728 has waited at <path>/trx/trx0trx.c line 700 for 241.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054042851072 has waited at <path>/trx/trx0trx.c line 700 for 240.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140053897594624 has waited at <path>/trx/trx0trx.c line 700 for 240.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140054269314816 has waited at <path>/trx/trx0trx.c line 700 for 228.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 --Thread 140053912647424 has waited at <path>/trx/trx0trx.c line 208 for 78.00 seconds the semaphore: Mutex at 0x1276a68 created file <path>/srv/srv0srv.c line 1038, lock var 1 waiters flag 1 Mutex spin waits 117851637, rounds 89989545, OS waits 249362 RW-shared spins 11452811, rounds 158361139, OS waits 2122101 RW-excl spins 5229822, rounds 128114865, OS waits 1176460 Spin rounds per wait: 0.76 mutex, 13.83 RW-shared, 24.50 RW-excl FAIL TO OBTAIN KERNEL MUTEX, SKIP LOCK INFO PRINTING -------- FILE I/O -------- I/O thread 0 state: waiting for completed aio requests (insert buffer thread) I/O thread 1 state: waiting for completed aio requests (log thread) I/O thread 2 state: waiting for completed aio requests (read thread) I/O thread 3 state: waiting for completed aio requests (read thread) I/O thread 4 state: waiting for completed aio requests (read thread) I/O thread 5 state: waiting for completed aio requests (read thread) I/O thread 6 state: waiting for completed aio requests (write thread) I/O thread 7 state: waiting for completed aio requests (write thread) I/O thread 8 state: waiting for completed aio requests (write thread) I/O thread 9 state: waiting for completed aio requests (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: 0 9947500 OS file reads, 105696752 OS file writes, 98371237 OS fsyncs 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf: size 68, free list len 3667, seg size 3736, 997096 merges merged operations: insert 1421280, delete mark 897892, delete 86296 discarded operations: insert 0, delete mark 0, delete 0 Hash table size 6375023, node heap has 13494 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 113572832858 Log flushed up to 113572832858 Last checkpoint at 113568853883 0 pending log writes, 0 pending chkp writes 95703706 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 3296722944; in additional pool allocated 0 Dictionary memory allocated 515016 Buffer pool size 196607 Free buffers 0 Database pages 183112 Old database pages 67574 Modified db pages 1548 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 30254129, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 9947464, created 56336, written 8910159 0.00 reads/s, 0.00 creates/s, 0.00 writes/s No buffer pool page gets since the last printout Pages read ahead 0.00/s, evicted without access 0.00/s LRU len: 183112, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] -------------- ROW OPERATIONS -------------- 26 queries inside InnoDB, 0 queries in queue 3 read views open inside InnoDB Main thread process no. 11983, id 140054344120064, state: doing background drop tables Number of rows inserted 2622442, updated 21677630, deleted 504511, read 297438002948 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================
经过几次(当然信号量等待秒数增加到700),MySQL进程变得无法访问(可能是由于达到的最大客户端数量),唯一能find的方法就是发送kill -9到mysqld进程。
现在,我该如何解释这个InnoDB监视器输出? 它只是一个很长的/慢的查询崩溃了很多(并没有被写入到慢日志由于杀)? 其他来源的问题,我应该看看?
sudo ipcs -s -c -p -t # will tell what semaphores are running sudo ipcs -l # will tell limits are into the system do you have the slow query log on - if not try to have it on into my.cnf [mysqld] log-slow-queries=/path/log_slow