一次线程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来让它结束，不然就会一直存在占据资源