一、背景和現象 初創公司,架構lanmp,web前端和後端分開伺服器,業務驅動主要是nginx和apache,nginx主要是處理靜態文件和反向代理,前後端、搜索引擎、緩存、隊列等附加的服務都是用docker容器部署。因為比較初級,上傳文件和採集文件都是直接寫在硬碟上,涉及到的目錄共用,就在其中一臺 ...
一、背景和現象 初創公司,架構lanmp,web前端和後端分開伺服器,業務驅動主要是nginx和apache,nginx主要是處理靜態文件和反向代理,前後端、搜索引擎、緩存、隊列等附加的服務都是用docker容器部署。因為比較初級,上傳文件和採集文件都是直接寫在硬碟上,涉及到的目錄共用,就在其中一臺伺服器存儲並且nfs共用。我們暫且分為ECS1(apache1)、ECS2(apache2)、ECS3(nginx)。某天網站業務中斷,但是沒有報錯。一直在等待響應,預設響應超時是一分鐘,所以很基礎高可用沒有起到作用。中斷10分鐘左右,重啟服務,提示“open too many files”,但是lsof統計沒幾個。因為初級處理不了,所以直接重啟伺服器,一段時間後一切恢復正常,可是第二天又來一次這種情況。 二、第一次出現後的排查思路 本來第一次發現這種問題的時候就要追查原因了,看了一下zabbix監控圖像其中斷了十分鐘,包括網路、記憶體、CPU、硬碟、IO等監控數據。首先想到的是網路問題,結論是zabbix-servert獲取不到了zabbix-agent採集的數據,估計就是網路不通了。 但是,這個結論站不住腳,因為我本身通過ssh登錄伺服器,並且命令輸入無卡頓,不至於頭文件都傳不過來。後來一看阿裡雲的雲監控,上面有數據,似乎也可以佐證網路這個說法,因為雲監控是阿裡雲內部的監控,可以內網獲取到監控數據。直到看CPU的使用率這項,發現有一段時間的CPU使用率100%。並且我重啟的時候CPU恢復正常,不能說網路一定沒問題,但系統肯定有問題。也可以解釋因為CPU使用已經是100%,zabbix-agent和根本不能正常運行,所以沒有監控數據。因為這個公司全部都是雲伺服器,沒有使用IDC所以我們也沒有安裝smokeping來監控,接著我們就不把重心在網路上了。 目前掌握的信息就是:在毫無徵兆的情況下,CPU暴漲到100%,重啟之前一直保留,重啟之後恢複原樣。匆忙之中又看了一下系統各日誌,因為太匆忙,沒有總結,沒有找到什麼有價值的東西。現在有下麵幾種猜想:第一,程式的bug或者部署不當,觸發之後耗盡資源。第二、docker容器的bug。第三、網路攻擊。第四、病毒入侵。第五、阿裡雲方系統不穩定。 小總結了一下,現在問題還沒有找出來。下次還有這個問題的可能,所以先儘量防範,但是又不能重啟一刀切。所以在zabbix上面設置了自動化,當檢測到ECS1獲取不到數據的時候馬上操作ECS3標記後端為ECS1的apache為down。保留異常現場。(請求停止的時候,CPU100%還在) 三、現場排查 1、相應的排查計劃(想到這些信息需要獲取的,實際上沒有嚴格按照這樣的步驟) 1)用htop和top命令監控CPU、記憶體使用大的進程。先看看哪個進程消耗資源較多,用戶態、內核態、記憶體、IO……同時sar -b查io的歷史定時抽樣。 2)統計tcp連接數,看看有沒有DDOS攻擊。netstat -anp |grep tcp |wc -l 。用iftop-i eth1看看通訊。同時用tail -n 1200 /var/log/messages查看內核日誌。 3)用pstree查看打開進程,ps aux|wc-l看看有沒有特別多的進程。雖然zabbix監控上說沒有,但是我們要檢查一下看看有沒有異常的進程名字。 4)查看全部容器的資源使用docker stats $(docker ps -a -q),看看能不能從容器上排查。 5)有了“too many open files”的啟發,計算打開文件數目lsof|wc -l,根據進程看看ll /proc/PID/fd文件描述符有沒有可疑的打開文件、文件描述符。 6)關於用lsof打開文件數找到的線索,排序打開文件找出進程號 lsof -n|awk '{print $2}'|sort|uniq -c|sort -nr|more 7)關於用lsof打開文件數找到的線索,用lsof -p PID查看進程打開的句柄。直接查看打開的文件。 8)啟動容器的時候又總是“open too many files"。那就是打開文件數的問題,因為CPU的使用率是CPU的使用時間和空閑時間比,有可能因為打開文件數阻塞而導致CPU都在等待。針對連接數的問題,大不了最後一步試試echo 6553500 > /proc/sys/fs/file-max 測試打開文件對CPU的影響。 9)玩意測出來了消耗CPU的進程,可以使用strace最終程式。用戶態的函數調用跟蹤用「ltrace」,所以這裡我們應該用「strace」-p PID 10)從程式裡面看到調用系統底層的函數可以跟蹤。跟蹤操作 strace -T -e * -p PID,主要看看代碼調用的函數有沒有問題。 2、現場排查 第二天同樣時間,ECS果然暴漲了CPU。這是時候zabbix的工作如希望進行保留了一臺故障的ECS1給我。 1)用htop看到資源使用最大是,搜索引擎下我寫的一個判斷腳本xunsearch.sh。腳本裡面很簡單,判斷索引和搜索服務缺一個就全部重啟。就當是我的容器有問題我直接關掉搜索引擎容器。httpd頂上,我又關掉apache容器。rabbitmq相關進程又頂上。這時候我沒心情周旋了,肯定不也是這個原因。sar -b查看的歷史io也沒有異常。 2)統計tcp連接,幾百。先不用著重考慮攻擊了。用tail -n 1200 /var/log/messages查看內核日誌,是TCP TIME WAIT的錯誤。可以理解為CPU使用100%,程式無響應外面的tcp請求超時。這是結果,還是沒有找到根本原因。 接著往下看系統內核日誌,發現了和“open too many files”呼應的錯誤,“file-max limit 65535 reached”意思是,已到達了文件限制瓶頸。這裡保持懷疑,繼續收集其他信息。 3)查看進程數量,數量幾百。列出來也看到都是熟悉的進程,可以先排除異常進程。 4)監控容器的資源使用,裡面很不穩定,首先是xunsearch容器使用80%的CPU,關掉xunsearch,又變成了其他容器使用CPU最高。很大程度上可以排查容器的問題和執行程式的問題。 5)查看了最大連接數cat /proc/sys/fs/file-max是65535但是用lsof查到的連接數是10000多,完全沒有達到連接數。 6)各項參數都正常,現在聚焦在打開的文件數這個問題上面。也可以用另外同一種方式查看一下內核統計文件 /proc/sys/fs/file-nr,比較一下差異,看看能不能找出問題。cat了一下,打開文件數是66080,果然超了!內核日誌就以這個為標準。 但是看lsof怎麼統計不出來,ll /proc/PID/fd也沒幾個。這個問題放在後面,先按照步驟echo 6553500 > /proc/sys/fs/file-max給連接數提高到100倍,CPU果然降了下來。原因確認了,但是必須找到根源,為什麼忽然有這麼大的打開文件數。關掉全部docker容器和docker引擎,打開文件數是少了一點,但是仍然在65535差不多。我就先排除一下業務的影響,把ECS3的nginx直接指向視頻ECS2的apache,就等同於在ECS2上實現了ECS1的場景。查看一下ECS2的句柄數,才4000多,排除了業務相關應用對伺服器的影響。那就能下個小結論,ECS1被神秘程式打開了6萬多句柄數,打開業務就多了2000多的句柄數,然後就崩潰了。不過這個現象有點奇怪,ECS2和ECS1在一樣的機房一樣的配置一樣的網路環境,一樣的操作系統,一樣的服務,一樣的容器,為什麼一個有問題,一個沒問題呢?不同的只是有一臺是共用nfs。難道是靜態文件共用了,其他人讀了,也算是本伺服器打開的? 7)現在程式找不到,沒法繼續lsof -p了。排查之前的猜想。帶著排查得到對的結論往下想。 程式的bug和部署不當,那是不可能的,因為主要問題來自於打開句柄數,當部署到ECS2那裡,一切正常。docker容器的bug,那也不可能的,每個都是我親自寫腳本,親自編譯,親自構建的,關鍵是我關掉了docker容器和引擎都沒有很大改善。網路攻擊也排除,因為網路連接數沒幾個,流量也不變。那就只剩下病毒入侵也不是,沒有異常進程。考慮到ECS的穩定性問題了。這方面就協助阿裡雲工程師去排查。 8)阿裡雲工程師用的排查手段和我差不多,最終也是沒能看到什麼。也只是給了我一些治標不治本的建議。後來上升到專家排查,專家直接在阿裡雲後端抓取了coredump文件分析打開的文件是圖片,程式是nfsd。 好像印證了我剛纔後面的猜想,應該就是ECS1使用了nfs共用其他伺服器打開瞭然後算在ECS1頭上。那問題又來了,我們的業務已經到達了可以影響伺服器的程度嗎? 9)既然問題解決到這一步,先不管程式有沒有關閉打開的文件和nfs的配置。我們架構上面的圖片應該是歸nginx讀取,難道是linux的記憶體機制讓它緩存了。帶著緩存的問題,首先去ECS3上釋放記憶體echo 3 > /proc/sys/vm/drop_caches,釋放之後,發現沒什麼改善,有點失落。總是覺得還有一臺後端是PHP主導,但是邏輯上是寫入,沒有打開文件之說。後來從程式員中瞭解到,PHP也有打開圖片。我猛然去ECS2釋放一下記憶體,果然,句柄數降下來。(這裡大家一定有個疑問,為什麼我直接想到記憶體緩存而不是目前打開的文件呢。其一,這是生產環境,web前端只有一個,不能亂來停服務。其二,第一次遇到問題的時候,重啟之後沒有問題,過了一天之後積累到一定的程度才爆發,這裡已經引導了我的思路是積累的問題,那就是緩存不斷積累了) 10)因為ECS2的調用ECS1的nfs共用文件,所以lsof也有讀不到那麼多句柄數的理由。如果說是nfs的服務本身就有緩存,導致問題的話,我查看了配置文件,還是預設值允許緩存,30S過期,根本不會因為nfs的緩存造成打開文件過多。如果我們的後端程式打開之後沒好好處理的話,那倒有可能。然後嘗試排除:我改了ECS3的配置,使程式只讀ECS1後端,從ECS1上面卻看不到有什麼異常表現,說明PHP程式已經好好處理了打開的文件。也不是docker掛載了nfs的共用的問題,因為nginx也有掛載。排查到這裡也很大程度上解決問題,而且緩存了nfs的全部共用文件,句柄並沒有增加,也算合理,所以就增加了打開文件數的限制。 11)現在排查的結果是跟後端和nfs共用有關。就是說,後端掛載了nfs的網路共用,被程式讀取。而程式釋放之後,在正常背景的硬碟文件是沒有緩存的。但是在nfs掛載的環境下,緩存並沒有得到釋放。 12)總結:很多問題的排查和我們的猜想結果一樣,但是有些例外的情況。比如這次我想到的原因都一一排除,但是問題也是在一步步排查中,逐步被髮現的。