生產問題記錄Cannot allocate memory分析
故障出現時間和描述
前段時間下午3點左右,專案組某個系統出現問題,具體為機器無法登陸,報錯catnot allocate memory
,如下圖所示:
先緊急啟動備機,然後重啟這臺故障的的機器(由於無法登陸重啟linux),重啟應用解決,中間止血速度,且由於是封板期間,未造成生產故障。後續經排查,由於下面程式碼問題,導致每次部署請求,都會建立固定執行緒池,請求完畢,但是由於執行緒池未手工shutdown,導致每次請求都會建立固定執行緒池,最終導致的該問題。
故障覆盤和分析
catnot allocate memory
問題,初看以為是記憶體不足導致,但是由於我們的應用啟動引數有 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/logs/ -XX:ErrorFile=/data/logs/hs_err_pid%p.log
,在oom情況下會生成oom檔案,但是實際未生成,且最小最大堆記憶體是8g,基本排除了oom的情況。通過網上查詢,catnot allocate memory
除了記憶體不足導致這個問題外,還有就是執行緒數太高,也會導致該問題。
通過排查專案程式碼,發現下面這裡,每次請求建立個固定執行緒池,這樣系統執行一個多月,最終出現了這個問題。
解決辦法:在請求結束對執行緒池進行shutdown操作,或者把執行緒池移儲存到該bean的屬性上。
最後通過檢視日誌,日誌裡面有大量的unable to create new native thread
錯誤,這說明建立執行緒已經達到上限。
故障復現:
step1:
建立個demo應用,進行模擬,程式碼如下所示,每次請求建立個固定執行緒池,每次請求執行緒+10,
step2:
使用controller接收請求,使用jmeter進行壓測
controller如下
jmeter配置如下:
直接在windows下啟動jmeter進行壓測即可,小測試不需要把jmeter放到linux了。
step3:
寫個shell allocate.sh不斷統計執行緒數,shell內容如下
#! /bin/bash
PID=`ps -fe | grep java | grep allocate-0.0.1-SNAPSHOT | grep -v grep | awk '{print $2}'`
log=~/allocate.`date +%Y%m%d'.'%H%M%S`.log
> $log
for i in {1..900000}
do
tasks=`ls /proc/$PID/task | wc -l`
echo "第$i次迴圈列印->`date +%Y-%m-%d'.'%H:%M:%S` --> $tasks" >> $log
sleep 3
done
備註:/proc/${PID}/task下面就是執行緒數
step4:
測試步驟:先啟動應用,然後啟動allocate.sh,最後使用jmeter進行壓測,最終發現執行緒數達到7250後不再增加,檢視demo應用,裡面報錯大量的java.lang.OutOfMemoryError: unable to create new native thread
,和生產應用錯誤相同。
實際中,使用執行緒都是使用的執行緒池,但是執行緒池建立不當,比如我們這個專案,就會導致這樣問題,這個問題不容易發現,且比較容易忽略。如果有監控,可以通過監控檢視應用一週內的執行緒數是否一直在增加,我們對這個應用沒有看監控習慣,這個習慣要改。如果沒有監控,可以通過上面的shell輸出執行緒數。
故障總結
1.出現故障,要有迅速止血的方案。通常是快速重啟
2.經常檢視監控,檢視記憶體、cpu、執行緒、jvm記憶體、gc指標。監控預設通常是查詢當天一段時間內的,要經常檢視一週內的指標監控趨勢,比如我們這個執行緒數一直增加問題,後面通過檢視一週的監控,很容易就看到一直在增長,就會去解決,而非等到出了故障才發現。
3.我們這個應用這麼久才發現這個問題的原因是由於快速迭代,半個月發版一次,執行緒數增長到上線3w多是很難的,這樣問題產生也是由於沒做壓測導致。對於新應用,要做壓測。
故障引發的思考,linux /proc學習
問題:生產上執行緒數達到了3w多是上線,但是測試環境應用啟動執行緒數是7250,應用建立的執行緒數和什麼有關係呢?
linux一切皆檔案,記憶體資訊也會對映到檔案內,具體目錄是/proc
使用者和應用程式可以通過 /proc 得到系統的資訊,並可以改變核心的某些引數。由於系統的資訊,如程序,是動態改變的,所以使用者或應用程式讀取 /proc 檔案時,/proc 檔案系統是動態從系統核心讀出所需資訊並提交的。
/proc 下還有三個很重要的目錄:net,scsi 和 sys。 sys 目錄是可寫的,可以通過它來訪問或修改核心的引數,而 net 和 scsi 則依賴於核心配置。例如,如果系統不支援 scsi,則 scsi 目錄不存在。
除了以上介紹的這些,還有的是一些以數字命名的目錄,它們是程序目錄。系統中當前執行的每一個程序都有對應的一個目錄在 proc 下,以程序的 PID 號為目錄名,它們是讀取程序資訊的介面。而 self 目錄則是讀取程序本身的資訊介面,是一個 link。
/proc/sys/kernel 核心
/proc/sys/kernel/pid_max 系統最大pid值,在大型系統裡可適當調大
/proc/sys/kernel/threads-max 系統允許的最大執行緒數
對應檔案/etc/sysctl.conf,修改該檔案永久生效。臨時生效通過echo "32768" > /proc/sys/kernel/pid_max
只改/proc/sys/kernel/xxx即可。
/proc/sys/net 網路
對於高併發的服務,經常會優化tcp引數,如果臨時生效,可以直接修改這裡
/proc/sys/net/ipv4/tcp_rmem 優化TCP接收
/proc/sys/net/ipv4/tcp_wmem 優化傳送緩衝區
優化TCP協議棧
開啟TCP SYN cookie選項,有助於保護伺服器免受SyncFlood攻擊。
net.ipv4.tcp_syncookies=1 對應/proc/sys/net/ipv4/tcp_syncookies
開啟TIME-WAIT套接字重用功能,對於存在大量連線的Web伺服器非常有效。
net.ipv4.tcp_tw_recyle=1 對應/proc/sys/net/ipv4/tcp_tw_recyle
net.ipv4.tcp_tw_reuse=1 對應/proc/sys/net/ipv4/tcp_tw_reuse
減少處於FIN-WAIT-2連線狀態的時間,使系統可以處理更多的連線。
net.ipv4.tcp_fin_timeout=30 對應/proc/sys/net/ipv4/tcp_fin_timeout
減少TCP KeepAlive連線偵測的時間,使系統可以處理更多的連線。
net.ipv4.tcp_keepalive_time=1800 對應/proc/sys/net/ipv4/tcp_keepalive_time
增加TCP SYN佇列長度,使系統可以處理更多的併發連線。
net.ipv4.tcp_max_syn_backlog=819200 對應/proc/sys/net/ipv4/tcp_max_syn_backlog
/proc/sys/scsi 磁碟
略,暫時不懂。
/proc/PID/ 程序狀態
列舉幾個常用的
cmdline 顯示應用的啟動命令,比如java -jar xxx.jar
,顯示的就是完整命令java -jar xxx.jar
comm 顯示啟動的命令,比如java -jar xxx.jar方法啟動,顯示的命令就是java
cwd 連結,包含了當前程序工作目錄的一個鏈,比如cwd -> /usr/local/devops/projects/allvms-restart-allocate/7c083dac,如下圖所示
exe啟動命令的連結,比如exe -> /usr/local/devops/tool/jdk/jdk1.8.0_73/bin/java
environ 包含了可用程序環境變數的列表
limits 檔案控制代碼限制,如圖所示,最大允許開啟7259個控制代碼數
task,是個目錄,下面是當前PID程序建立的執行緒,可以統計執行緒數。
fd 這個目錄包含了程序開啟的每一個檔案的連結。
mem 包含了程序在記憶體中的內容。
stat 包含了程序的狀態資訊。
statm 包含了程序的記憶體使用資訊。
應用可建立的執行緒數
由系統層面和使用者層面決定。
系統層面:
引數/proc/sys/kernel/threads-max,有直接關係,每個程序中做多建立的的執行緒數目。用於指示整個系統可生成的最大執行緒數 引數/proc/sys/kernel/pid_max,有直接關係,系統中最多分配的pid數量。用於指定系統能夠分配的PID的個數(即系統能夠建立的最大程序個數) 引數/proc/sys/vm/max_map_count,數量越大,能夠建立的執行緒數目越多,目前具體關係未明
通過echo臨時設定:
echo 204800 > /proc/sys/kernel/threads-max echo 204800 > /proc/sys/kernel/pid_max echo 204800 > /proc/sys/kernel/pid_max
永久修改
sysctl -w kernel.threads-max=2061206
修改最大執行緒數
sysctl -w kernel.pid_max=4194303
修改最大pid數
sysctl -w vm.max_map_count=4194303
使用者層面:
可以通過修改/etc/security/limits.d/20-nproc.conf檔案設定普通使用者的執行緒數限制。注:/etc/security/limits.conf只是設定root使用者
當前應用最大可開啟的執行緒數通過/proc/PID/limits檢視Max processes
jvm引數限制:
此外可以開啟的最大執行緒數除了以上,還受到jvm引數設定,這個具體計算暫時不清楚。通常只需要linux不限制即可。
linux /var/log/message說明
/var/log/messages 存放的是系統的日誌資訊,它記錄了各種事件,基本上什麼應用都能往裡寫日誌,在做故障診斷時可以首先檢視該檔案內容。在本次故障也參考了這個檔案,檔案格式說明如下
可以分為幾個欄位來描述這些事件資訊:
1. 事件的日期和時間
2. 事件的來源主機
3. 產生這個事件的程式[程序號]
4. 實際的日誌資訊
如:Nov 9 15:00:10 JD salt-minion[6728]: [ERROR ] fork #1 failed: 12 ([Errno 12] Cannot allocate memory)
1. 產生這個事件的時間是:Nov 9 15:00:10
2. 事件的來源主機為:JD
3. 產生這個事件的程式和程序號為:salt-minion[6728]
4. 這個事件實際的日誌資訊為:[ERROR ] fork #1 failed: 12 ([Errno 12] Cannot allocate memory)