由多執行緒記憶體溢位產生的實戰分析

一日凌晨，手機瘋狂報警，簡訊以摧枯拉朽之勢瞬間以百條的速度到達，我在睡夢中被驚醒，看到簡訊的部分內容如下：

Caused by: java.lang.OutOfMemoryError: unable to create new native thread
    at java.lang.Thread.start0(Native Method)
    at java.lang.Thread.start(Thread.java:597)
    at java.util.Timer.<init>(Timer.java:154)

看到這個錯誤，我的第一感覺是建立了大量的執行緒，並且資源沒有被回收，但是報錯的卻是其中一臺應用伺服器，表象看不太像是程式的問題，而此時在凌晨併發量也不應該會有這麼大啊？同時我們不能因為報錯暫停服務使用，而影響商戶，所以決定要先解決問題，於是採用必殺技重啟這臺伺服器，觀察一小時記憶體溢位消失，問題暫時解決。

第二天白天這個問題並沒有復現，我認為這是偶發事件，就沒有過於在意，於是當晚再次出現記憶體溢位，並且還是隨機某一臺伺服器爆出，我緊急找到監控部和系統部要求拿到棧資訊內容和dump檔案，然而並沒有。。。。我們緊急開會做程式碼走查，發現這個應用其實是一個非常簡單的應用，裡面沒有使用執行緒，也沒有很複雜的邏輯，只是簡單的增刪改操作，那會是什麼原因呢？

接下來我們的分析之路開始了。。。。。

一、現狀情況

1. 無法找到OOM時的javacore和heapdump檔案。
2. 無法還原問題發生時候系統記憶體被各個程式使用的佔比，CPU的佔比。
3. 日誌沒有異常堆疊資訊。

二、解決思路

1、要能夠驗證Tomcat配置記憶體溢位時列印堆疊並驗證可行性，並保證在上線和重啟不被擦除。
現狀：當前只配置-XX:+HeapDumpOnOutOfMemoryError”，沒有配置路徑，不知道是被重啟刪除還是沒有產生。

2、實現指令碼，在出現OOM的時候，重啟前，列印jstack棧資訊和dump檔案。
現狀：目前是人工使用jmap和jstack列印CPU和記憶體資訊給應急人員看。

3、實現JVM記憶體監控，在JVM記憶體緊張的時候提前報警，人工干預。
現狀：無

4.、監控或者實現指令碼收集java程式OOM的時候，各個程式對記憶體的佔比等，以及監控cache, buffer等。
現狀：根據凌晨OOM的情況，錯誤堆疊表明，start0是JVM申請系統記憶體時記憶體不夠，並非jvm堆記憶體不夠而導致，需要上面資訊檢視詳細的系統。

5、研究底層，尋找java.lang.OutOfMemoryError: unable to create new native thread錯誤的引發原因有哪些。

6、針對專案進行壓測發現問題點。

三、深層次測試研究

測試環境
作業系統：centos 7 64bit
Linux核心：Linux centos 3.10.0-327.10.1.el7.x86_64
配置：1G記憶體
虛擬機器工具：virtual box 64bit
JDK：
openjdk version “1.8.0_71”
OpenJDK Runtime Environment (build 1.8.0_71-b15)
OpenJDK 64-Bit Server VM (build 25.71-b15, mixed mode)

程式碼如下：

/**
 * PROJECT_NAME: test
 * CREATE BY:    chao.cheng
 **/
public class OOMTest {
    public static void main(String[] args) throws IOException {
        if (args.length < 1) {
            System.out.println("please input thread numbers!");
            return;
        }

        int threadNumber = Integer.parseInt(args[0]);

        try {
            for (int i = 0; i < threadNumber; i++) {
                new Thread() {
                    public void run() {
                        while (true) {
                            try {
                                Thread.sleep(1000);
                            } catch (InterruptedException e) {
                                e.printStackTrace();
                            }
                        }
                    }

                }.start();
                System.out.println("Thread " + i);
            }
        } catch (Throwable e) {
            e.printStackTrace();
        }
    }
}

1、第一次測試過程：
輸入命令如下：

   ulimit -u
   顯示：3584

注： ulimit -u是顯示使用者最多可開啟的程式數目。

程式JVM引數設定如下：

java OOMTest 4000 -Xmx500m -Xss2m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp

執行結果如下：

檢視系統記憶體如下：

結論分析：
a、在tmp目錄下沒有生成dump檔案。
我們需要注意，使用-XX:+HeapDumpOnOutOfMemoryError引數的時候，並不一定在任何溢位場景下都會產生dump檔案。

b、系統記憶體還有很多，卻無法建立執行緒了。感覺是系統中存在的程式/執行緒已經達到系統配置的極限。

2、第二次測試過程：

使用ulimit -u 65535命令或者直接修改limits.conf檔案，將max user process引數修改為65535。

jvm引數配置如下：

java OOMTest 4000 -Xmx500m -Xss2m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp

程式執行結果如下：
並沒有報任何錯誤

修改jvm引數為：

java OOMTest 40000 -Xmx500m -Xss2m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp

配置只是修改了建立執行緒數為40000，比上一次4000多了10倍。

程式執行結果如下：

檢視記憶體如下：

結論分析：
此時已經把系統的記憶體全部耗盡，無法使用free、top命令，此時已經無法執行任何命令

3、綜合分析
a、當max user processers 設定的較小的時候，影響系統執行緒數目的是max user processers的設定
b、當max user processers設定為65535的時候，影響系統執行緒數目的是系統的記憶體。
c、對外的異常資訊均為：OOM:unable to create native thread。

四、多執行緒記憶體溢位的理論支撐

通過上面的分析，我們看到其實多執行緒記憶體溢位有很大原因是因為系統設定和記憶體大小造成的，那麼我們如何來分析當前系統配置能夠支援多少執行緒呢？

對於java中的執行緒，我之前的理解一直是在java中new新執行緒的時候是直接使用jvm的記憶體，可實際情況卻不是這樣的。在java中每個執行緒需要分配執行緒記憶體，用來儲存自身的執行緒變數，在jdk1.4中每個執行緒是256K的記憶體，在jdk1.5中每個執行緒是1M的記憶體，jdk1.6以上版本不太清楚。在java中每new一個執行緒，jvm都是向作業系統請求new一個本地執行緒，此時作業系統會使用剩餘的記憶體空間來為執行緒分配記憶體，而不是使用jvm的記憶體。這樣，當作業系統的可用記憶體越少，則jvm可用建立的新執行緒也就越少，我們舉一個例子如下：

| 總記憶體 | -Xmx | -Xms |-Xss|剩餘記憶體|執行緒數|
| ————- |:————-:| —–:|
| 1024M| 256M| 256M | 1M | 768M | 768 |

根據上面的知識，於是衍生出了下面這樣的通用公式：
(MaxProcessMemory – JVMMemory – ReservedOsMemory) / (ThreadStackSize) = Number of threads
注：
MaxProcessMemory：程式最大定址空間。
JVMMMEMORY：jvm的記憶體空間（堆+永久區）-Xmx大小 (應該是實際分配大小)
ReservedOsMemory：作業系統預留記憶體
ThreadStackSize：-Xss大小

五、資訊檔案的匯出

文章開始的時候說過，在記憶體溢位的時候，因為伺服器重啟導致jstack內容消失了，雖然配置了jvm引數HeapDumpOnOutOfMemoryError，但並沒有產生相應的dump檔案，於是我們採用指令碼匯出的方式，內容如下：

#!/bin/bash
ps -Leo pid,lwp,user,pcpu,pmem,cmd > /tmp/ps.log
echo 1
pid=`ps aux|grep tomcat|grep xxx|awk -F ` ` `{print $2}``
echo 2
pstack $pid >/tmp/pstack.log
echo 3
lsof > /tmp/sys-o-files.log
echo 4
lsof -p $pid > /tmp/service-o-files.log
echo 5
jstack -l $pid  > /tmp/js.log
echo 6 
free -m >/tmp/free.log
echo end

vmstat 2 1

在系統異常的時候，監控系統能夠自動呼叫指令碼產生資訊檔案，有了這些檔案分析問題才能夠得心應手，不然出了問題根本無從查起，只能是沒頭蒼蠅亂撞。

六、壓測分析

在壓測環境中配置與生產環境一樣的硬體環境和配置環境進行壓測，可以看到如下的測試圖：

通過壓測分析，在程式併發執行緒達到1010個的時候，就報出unable to create new native thread異常，檢視上面這張圖其實不難看出，應用程式中並沒有使用執行緒，但是在Log4j中卻大量的使用了synchronized這個關鍵字，在併發非常高的時候會產生非常多的阻塞，最終記憶體資源耗盡報出記憶體溢位錯誤。

七、問題解決方案

問題解決方案

1、優化程式，減少沒用的log4j日誌輸出，將log4j日誌改為非同步+buffer的模式。
2、單臺伺服器本身效能有限，通過增加伺服器的方式提高擴充套件性。
3、將系統的一些限制屬性增大，如：ulimit -a。

通用解決方案

上面的四點是針對我們的解決方案，但通過以上的這些分析，我們不難發現所有的unable to create new native thread的錯誤異常都有其共性的地方，那接下來我再總結一些相對通用一點的方法幫助大家在以後遇到類似的問題的時候，能夠有據可查知道如何進行逐步的排查。

1、當發現這個錯誤的時候，第一時間要排查程式是否有bug，是否大量的建立了執行緒，或者沒有正確使用執行緒池，比如：是否使用了Executors.newCachedThreadPool()方法，該方法能建立Integer最大值個執行緒，建立到一定程度的時候系統資源耗盡就會報錯。

2、如果發現程式中並沒有使用執行緒卻依然報這個錯，那麼觀察一下這個時刻的併發情況如何，要是溢位的這一時刻比其他時候併發量都要大，這時先檢視一下系統資源的情況，使用ulimit –a檢視max user processes和open files這二個屬性的值越大，能建立的執行緒數也就越大。
3、如果以上二個屬性調大依然報錯的話，說明此時受限於系統記憶體資源了，要是伺服器本身記憶體就比較小的話，建議增加記憶體。要是伺服器記憶體比較大，就需要通過調整jvm引數來增加執行緒使用的記憶體，比如減小-Xss值，這個值越小能建立的執行緒數也就越多，也可以適當減少-Xmx和-Xms的值，增加堆外記憶體的容量。

八、回顧總結

在我們排查整個記憶體溢位問題的過程中，其實耗費了挺長時間，而且報錯的時間基本都是在晚上，分析交易量看到這個時間段的併發量確實比白天要高，給我們最大的啟示是發生問題的時候，不能很快的定位問題原因，沒有最重要的報錯日誌可供分析。基於此我們開發了JAVA探針功能，可以實時採集當前伺服器的記憶體使用情況、JVM堆使用情況，棧使用情況等等，並且能夠提前預警，介面類似下面這樣：

注：第一張圖顯示的記憶體使用的百分比，第二張圖可以檢視一段時間jvm記憶體使用情況，當高峰期來臨時可以提前預警。

最後感謝在這次排查問題的過程中給與支援的曉輝同學。