1. 程式人生 > 實用技巧 >生產問題記錄Cannot allocate memory分析

生產問題記錄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)