【51CTO.com 專家特稿】那天因參加MS的新品發(fā)布大會(huì)，中午就離開(kāi)辦公室，當(dāng)我正在出租車上前往會(huì)場(chǎng)的途中，同事打電話來(lái)說(shuō)主數(shù)據(jù)庫(kù)出現(xiàn)寫(xiě)保護(hù)錯(cuò)誤。這可不得了，所有的應(yīng)用都靠這個(gè)數(shù)據(jù)庫(kù)呀，我心里默念：千萬(wàn)不要出漏子，否則就不能參會(huì)了！于是我在電話里交代同事重啟mysql數(shù)據(jù)庫(kù)試試，還好，重啟后問(wèn)題解決。

一散會(huì)，就趕緊上去找故障原因。這里先描述一下平臺(tái)環(huán)境，把邏輯關(guān)系弄清楚。在這個(gè)應(yīng)用中，由一個(gè)web前段服務(wù)器，一個(gè)tomcat應(yīng)用服務(wù)器及一個(gè)mysql服務(wù)器構(gòu)成，所有的系統(tǒng)都是linux。用戶的請(qǐng)求先到前端的apache服務(wù)器，如果請(qǐng)求頁(yè)面是.jsp，apache就把請(qǐng)求轉(zhuǎn)交給tomcat服務(wù)器，tomcat再?gòu)臄?shù)據(jù)庫(kù)獲取數(shù)據(jù)或向數(shù)據(jù)庫(kù)插入記錄。這是典型的3層應(yīng)用邏輯。

登錄到數(shù)據(jù)庫(kù)mysql服務(wù)器，用mysql客戶端連接mysql數(shù)據(jù)庫(kù)，執(zhí)行命令 mysql > show processlist; 沒(méi)發(fā)現(xiàn)什么異常，負(fù)載也很低?？磥?lái)從這里看不出什么名堂。接下來(lái)當(dāng)然該看mysql錯(cuò)誤日志，發(fā)現(xiàn)如下異常：

080313 11:25:35 InnoDB: Error: cannot allocate 1064960 bytes of

InnoDB: memory with malloc! Total allocated memory

InnoDB: by InnoDB 1233305429 bytes. Operating system errno: 12

InnoDB: Check if you should increase the swap file or

InnoDB: ulimits of your operating system.

InnoDB: On FreeBSD check you have compiled the OS with

InnoDB: a big enough maximum process size.

InnoDB: Note that in most 32-bit computers the process

InnoDB: memory space is limited to 2 GB or 4 GB.

InnoDB: We keep retrying the allocation for 60 seconds...

080313 11:26:08 [ERROR] /usr/local/mysql/bin/mysqld: Sort aborted

080313 11:26:19 InnoDB: Error: cannot allocate 1064960 bytes of

InnoDB: memory with malloc! Total allocated memory

這個(gè)報(bào)錯(cuò)的大意是：內(nèi)存基本耗盡，沒(méi)有再可以分配的空間。由此判斷是什么東西產(chǎn)生巨大的負(fù)荷導(dǎo)致系統(tǒng)內(nèi)存被榨干了。不過(guò)現(xiàn)在數(shù)據(jù)庫(kù)服務(wù)器已經(jīng)趨于平穩(wěn)，暫時(shí)查不到什么原因引起這個(gè)故障。

基本情況掌握了，停下來(lái)休息片刻，于是順手收一下郵件，乖乖，來(lái)了一封報(bào)警郵件，趕緊打開(kāi)，其內(nèi)容如下：

***** Nagios 2.9 *****

Notification Type: PROBLEM

Service: check_load

Host: tomcat nch100

Address: 61.154.105.100

State: WARNING

Date/Time: Thu Mar 13 10:59:53 CST 2008

Additional Info:

WARNING - load average: 3.94, 8.56, 9.17

報(bào)警消息表明主機(jī)61.154.105.100在10:59的這個(gè)時(shí)間負(fù)載過(guò)大。而這個(gè)主機(jī)正好是tomcat服務(wù)器,看來(lái)問(wèn)題就在這個(gè)上面.為了近一步確認(rèn)自己的想法,我來(lái)查看一下網(wǎng)絡(luò)流量:

從流量圖可以看出,產(chǎn)生異常流量的時(shí)間正好與報(bào)警信息的時(shí)間一致,再給同事打電話,問(wèn)：“你們都在61.154.105.100 這個(gè)機(jī)器上干了啥?”，答：“執(zhí)行了一條不正確的sql語(yǔ)句，發(fā)現(xiàn)問(wèn)題后取消這個(gè)sql語(yǔ)句”。至此，原因查明！

更多信息請(qǐng)查看IT技術(shù)專欄