一次线程OOM排查看线程使用注意事项

一、背景介绍

在开发项目中发生了一次OOM问题，通过crash 平台查看上报信息，发现在很多的页面都有报这个错误，但是相同的出错都是以下的错误，看不到APP的堆栈只能看到是线程池创建有问题的堆栈信息，如下所示：

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 里面线程池使用的地方；不同页面都会报这个错误，那这个问题说明不是在特定页面产生的，是通性问题，那么就需要来检测整体的线程状态来看，看看是哪里在一直的创建线程，有了思路就开始先来分析线程状态吧。

二、排查方法

2.1 Android CPU Profiler

由于线程池导致的 OOM 问题，我们需要查看当前的线程池的状态，有Android CPU profiler这个工具可供使用，那么我们就可以通过这个工具来做检查了，启动profiler可以看到当前创建的所有线程基本信息，线程状态等；可以看到对应的线程数和线程名称，以及线程的状态，以此可以进一步排查问题，如图所示：

但是这个工具有两个问题：

• 要AS连接当前的进程，连接成功之后APP的部分操作会比较卡顿，不如正常使用流畅
• 确实展示了所有线程的名称以及状态，但是不能分类统计；比如说我想知道OkHttp Dispatch这个为前缀的线程名现在有多少个了，这个很难统计；

基于此我们可以使用adb shell中的ps命令来同样观测当前的线程状态

2.2 ps 命令

根据包名查看当前进程

adb shell ps | grep xxx

得到当前进程pid或名字则查看当前所有的线程

adb shell ps -T | grep 6661

这样就可以看到当前的所有的线程了，可以使用wc -l来统计线程数量。

2.3 开始排查

我们并不清楚到底是哪个部分有问题导致的线程数的增长，所以我们需要一个每1s可以打印一下当前的线程数再通过页面交互来确定到底是哪里出现的问题，可以使用watch命令来完成我们的想法，如下所示：

watch -n 1 -d 'adb shell ps -T | grep u0_a589 | wc -l'

从上图看到输出的线程名字，这样我们在操作APP时可以试试的看到线程数的大小，并且通过观察看到那类的线程名字在增多

我们在按照复现路径长时间的使用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来创建的，并没有实现复用。

三、解决方案

问题我们都排查清楚了，我们逐个解决就可以了；

• 针对于Schedulers.newThread()的使用去掉了，因为目的是为了日志上报，不需要新开线程来做
• 针对于SDK OkHttpClient和线程池滥用的方式，通知了SDK方进行了修改，在代码里针对于通用参数为空就请求的策略添加了新的限制，以请求次数和时间间隔两个维度来请求，不要频繁进行请求；

问题解决完毕，我们在用ps命令按照之前的复现步骤操作一次看看效果吧，如下所示：

可以看到线程的数量保持稳定了，没有一直上涨了。

四、总结

以上就是排查OOM的流程和解决方案了，在线程的排查过程中有一些注意事项需要注意一下：

• 项目中如果使用了RxJava的话可以使用自带的hook方法，registerSchedulersHook来自定义CPU密集型和IO密集型的线程创建方式，便于之后排查和统计
• 项目里面使用的线程池应该做统一的配置收敛，不要到处都创建线程池导致浪费和排查困难
• OkHttpClient的请求应该复用client不要每次都重新创建，导致资源浪费
• SDK里使用线程池或使用OkHttpClient时，都最好可以暴露出来可以让业务方自行创建和管理，类似于RxJava的方式
• 线程池创建中核心线程的负载不高，可以使用allowCoreThreadTimeOut来让它结束，否则就会一直存在占据资源