一次線程OOM排查看線程使用注意事項

時間 2020-07-17

標籤一次線程 oom 排查使用注意事項简体版

原文原文鏈接

1、背景介紹

在開發項目中發生了一次OOM問題，經過crash 平臺查看上報信息，發如今不少的頁面都有報這個錯誤，可是相同的出錯都是如下的錯誤，看不到APP的堆棧只能看到是線程池建立有問題的堆棧信息，以下所示：java

java.lang.OutOfMemoryError: pthread_create (1040KB stack) failed: Try again
    at java.lang.Thread.nativeCreate(Native Method)
    at java.lang.Thread.start(Thread.java:883)
    at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:975)
    at java.util.concurrent.ThreadPoolExecutor.processWorkerExit(ThreadPoolExecutor.java:1043)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1185)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
    at java.lang.Thread.run(Thread.java:919)
複製代碼

從上報信息看到最後的線程數是 1456 個，這個數量是遠遠超出咱們正常使用量的，再經過這個堆棧信息咱們能夠知道就是APP中的線程建立數量太多而致使的OOM，排查方向的重點就是要關注APP 裏面線程池使用的地方；不一樣頁面都會報這個錯誤，那這個問題說明不是在特定頁面產生的，是通性問題，那麼就須要來檢測總體的線程狀態來看，看看是哪裏在一直的建立線程，有了思路就開始先來分析線程狀態吧。react

2、排查方法

2.1 Android CPU Profiler

因爲線程池致使的 OOM 問題，咱們須要查看當前的線程池的狀態，有Android CPU profiler這個工具可供使用，那麼咱們就能夠經過這個工具來作檢查了，啓動profiler能夠看到當前建立的全部線程基本信息，線程狀態等；能夠看到對應的線程數和線程名稱，以及線程的狀態，以此能夠進一步排查問題，如圖所示：android

可是這個工具備兩個問題：git

要AS鏈接當前的進程，鏈接成功以後APP的部分操做會比較卡頓，不如正常使用流暢
確實展現了全部線程的名稱以及狀態，可是不能分類統計；好比說我想知道OkHttp Dispatch這個爲前綴的線程名如今有多少個了，這個很難統計；

基於此咱們可使用adb shell中的ps命令來一樣觀測當前的線程狀態github

2.2 ps 命令

根據包名查看當前進程shell

adb shell ps | grep xxx
複製代碼

獲得當前進程pid或名字則查看當前全部的線程後端

adb shell ps -T | grep 6661
複製代碼

這樣就能夠看到當前的全部的線程了，可使用wc -l來統計線程數量。bash

2.3 開始排查

咱們並不清楚究竟是哪一個部分有問題致使的線程數的增加，因此咱們須要一個每1s能夠打印一下當前的線程數再經過頁面交互來肯定究竟是哪裏出現的問題，可使用watch命令來完成咱們的想法，以下所示：socket

watch -n 1 -d 'adb shell ps -T | grep u0_a589 | wc -l'
複製代碼

從上圖看到輸出的線程名字，這樣咱們在操做APP時能夠試試的看到線程數的大小，而且經過觀察看到那類的線程名字在增多ide

咱們在按照復現路徑長時間的使用APP後發現頻繁進行操做線程數居然能夠達到1232，這個數量值已經很大了，接近崩潰平臺全部暴露的問題了，仔細觀察了全部線程名的輸出發現以OkHttp Connect 和 pool-前綴的線程很是之多，咱們知道線程池裏默認建立的線程名稱就是以pool-來命名的，以下所示：

DefaultThreadFactory() {
    SecurityManager s = System.getSecurityManager();
    group = (s != null)? s.getThreadGroup() :
                         Thread.currentThread().getThreadGroup();
    namePrefix = "pool-" +
                  poolNumber.getAndIncrement() +
                 "-thread-";
}
複製代碼

那咱們就清楚了這個問題的所在，有一個地方在不斷地建立線程池而沒有複用這樣頻繁的建立必然致使最後線程數的增加最後致使OOM。

既然咱們知道了是線程池建立的時候產生的問題，那咱們的項目裏本身使用了線程池，還有許多的第三方SDK也是用了線程池，那怎麼去排查這個問題呢？

咱們使用了epic這個庫來作hook，能夠監控到當前的線程建立，在裏面打印了堆棧信息便於咱們排查，以下所示：

private void hookThread() {
    DexposedBridge.hookAllConstructors(Thread.class, new XC_MethodHook() {
        @Override
        protected void afterHookedMethod(MethodHookParam param) throws Throwable {
            super.afterHookedMethod(param);
            Thread thread = (Thread) param.thisObject;
            Class<?> clazz = thread.getClass();
            if (clazz != Thread.class) {
                Log.d(ThreadMethodHook.TAG, "found class extend Thread:" + clazz);
                DexposedBridge.findAndHookMethod(clazz, "run", new ThreadMethodHook());
            }
            Log.d(ThreadMethodHook.TAG, "Thread: " + thread.getName() + " class:" + thread.getClass() +  " is created.");
            Log.d(ThreadMethodHook.TAG, "Thread:" + thread.getName() + "stack:" + Log.getStackTraceString(new Throwable()));
        }
    });
}
複製代碼

2.4 問題確認

這樣咱們結合上述的方法，再按照Crash信息裏面暴露的頁面路徑來複現，就能夠發現問題了，最終問題定位在有一個SDK的OkHttp建立有問題還有錯誤的使用了RxJava的newThread，咱們來看一下代碼

//只貼了部分相關代碼
private static OkHttpClient newClient(Context context){
    Dispatcher dispatcher = new Dispatcher(Executors.newSingleThreadScheduledExecutor());
    ...
    return new OkHttpClient.Builder()
            .dispatcher(dispatcher)
            ...
            .build();
}
複製代碼

這個OkHttpClient的方法會每次從新建立client對象

//只貼了部分代碼
Observable.create(new Observable.OnSubscribe<Throwable>() {
    @Override
    public void call(Subscriber<? super Throwable> subscriber) {
        subscriber.onNext(t);
    }
})
.subscribeOn(Schedulers.newThread())
.subscribe(new Subscriber<Throwable>() {
    @Override
    public void onCompleted() {
        ...
    }

    @Override
    public void onError(Throwable e) {
        ...
    }

    @Override
    public void onNext(Throwable o) {
        ...
    }
});
複製代碼

這個RxJava的使用咱們看到了是用了一個Schedulers.newThread()，操做符的意思就是每次會從新建立一個線程來執行任務。

最後再來總結一下問題的緣由吧，咱們的請求中有一個公共參數若是公共參數的值爲空，那麼就會調用SDK的方法來獲取值，因爲後端升級過接口返回，致使SDK的解析有問題，就會走到上面的Observable方法中進行日誌上報，這樣致使這個參數一直爲空，那麼在下一次的請求中就還會調用SDK的方法來請求，SDK中每次從新請求都會從新建立OkHttpClient，它裏面的調度器是使用的有一個核心線程的線程池，這樣若是大量的請求會致使重複建立線程池；而且Observable是用的Schedulers.newThread()會建立一個新的線程，這兩個方面致使了咱們的OOM產生。

2.5 意外發現

咱們項目中接入了RN，在使用epic來作hook的過程當中發現了一個RN會存在的隱患這裏說明一下：
在ReconnectingWebSocket這個類，主要是用戶本地調試RN時，會創建WebSocket來進行的通訊，若是鏈接失敗則會再次從新鏈接，先看一下日誌吧

at com.taobao.android.dexposed.DexposedBridge.handleHookedArtMethod(DexposedBridge.java:273)
        at me.weishu.epic.art.entry.Entry.onHookObject(Entry.java:69)
        at me.weishu.epic.art.entry.Entry.referenceBridge(Entry.java:186)
        at com.squareup.okhttp.internal.Util$1.newThread(Util.java:225)
        at java.util.concurrent.ThreadPoolExecutor$Worker.<init>(ThreadPoolExecutor.java:631)
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:945)
        at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1388)
        at com.squareup.okhttp.Dispatcher.enqueue(Dispatcher.java:110)
        at com.squareup.okhttp.Call.enqueue(Call.java:114)
        at com.squareup.okhttp.OkHttpClient$1.callEnqueue(OkHttpClient.java:98)
        at com.squareup.okhttp.ws.WebSocketCall.enqueue(WebSocketCall.java:109)
        at com.facebook.react.packagerconnection.ReconnectingWebSocket.connect(ReconnectingWebSocket.java:80)
        at com.facebook.react.packagerconnection.ReconnectingWebSocket.delayedReconnect(ReconnectingWebSocket.java:86)
        at com.facebook.react.packagerconnection.ReconnectingWebSocket.access$000(ReconnectingWebSocket.java:35)
        at com.facebook.react.packagerconnection.ReconnectingWebSocket$1.run(ReconnectingWebSocket.java:104)
複製代碼

從日誌能夠看出來每2s會建立一個線程，查看具體代碼：

@Override
public synchronized void onFailure(IOException t, Response response) {
    if (mWebSocket != null) {
      abort("Websocket exception", t);
    }
    if (!mClosed) {
      if (mConnectionCallback != null) {
        mConnectionCallback.onDisconnected();
      }
      //1.重連
      reconnect();
    }
}
複製代碼

private void reconnect() {
    ...
    mHandler.postDelayed(
        new Runnable() {
            @Override
            public void run() {
                //2.延遲鏈接
                delayedReconnect();
            }
        },
    RECONNECT_DELAY_MS);
}
複製代碼

private synchronized void delayedReconnect() {
    // check that we haven't been closed in the meantime if (!mClosed) { // 3.鏈接 connect(); } } 複製代碼

public void connect() {
    if (mClosed) {
      throw new IllegalStateException("Can't connect closed client");
    }
    //4.建立OkHttpClient
    OkHttpClient httpClient = new OkHttpClient();
    httpClient.setConnectTimeout(10, TimeUnit.SECONDS);
    httpClient.setWriteTimeout(10, TimeUnit.SECONDS);
    httpClient.setReadTimeout(0, TimeUnit.MINUTES); // Disable timeouts for read

    Request request = new Request.Builder().url(mUrl).build();
    WebSocketCall call = WebSocketCall.create(httpClient, request);
    call.enqueue(this);
}
複製代碼

咱們經過以上關鍵部分代碼發現，這個connect方法會被重複調用的，在這個裏面它的實現是每次都從新建立一個OkHttpClient的，它延遲2s後再重連，一個線程池裏非核心線程是60s後會被銷燬，那麼若是一直重連失敗的話就會致使一直建立OkHttpClient和線程池，這樣會重複的申請資源致使浪費，咱們來看一下這個ReconnectingWebSocket建立的線程數量，以下所示：

這些線程都是此ReconnectingWebSocket來建立的，並無實現複用。

3、解決方案

問題咱們都排查清楚了，咱們逐個解決就能夠了；

針對於Schedulers.newThread()的使用去掉了，由於目的是爲了日誌上報，不須要新開線程來作
針對於SDK OkHttpClient和線程池濫用的方式，通知了SDK方進行了修改，在代碼裏針對於通用參數爲空就請求的策略添加了新的限制，以請求次數和時間間隔兩個維度來請求，不要頻繁進行請求；

問題解決完畢，咱們在用ps命令按照以前的復現步驟操做一次看看效果吧，以下所示：

能夠看到線程的數量保持穩定了，沒有一直上漲了。

4、總結

以上就是排查OOM的流程和解決方案了，在線程的排查過程當中有一些注意事項須要注意一下：

項目中若是使用了RxJava的話可使用自帶的hook方法，registerSchedulersHook來自定義CPU密集型和IO密集型的線程建立方式，便於以後排查和統計
項目裏面使用的線程池應該作統一的配置收斂，不要處處都建立線程池致使浪費和排查困難
OkHttpClient的請求應該複用client不要每次都從新建立，致使資源浪費
SDK裏使用線程池或使用OkHttpClient時，都最好能夠暴露出來可讓業務方自行建立和管理，相似於RxJava的方式
線程池建立中核心線程的負載不高，可使用allowCoreThreadTimeOut來讓它結束，不然就會一直存在佔據資源

相關標籤/搜索

每日一句

每一个你不满意的现在，都有一个你没有努力的曾经。