Java 线程池 ThreadPoolExecutor 引发的线程及内存泄露

旺财gg
1,693 阅读5分钟

1.问题及分析

1.1 问题

最近遇到一个问题。这个问题的业务场景是这样的：用户可以通过微信扫码关注医生。扫码后，系统会通过微信公众号推送小程序卡片给用户。承载这个场景的服务运行十多天后，服务开始出现异常。异常的表现是：一次推送多个卡片给用户。

1.2 分析

分析日志得出结论：微信扫码回调的处理逻辑超时，微信重试导致了重复处理扫码关注回调事件。从而导致了多次推送小程序卡片给用户。

微信回调处理逻辑比较复杂。日志记录的不详细，提供的信息比较有限。 Skywalking 的调用链追踪日志提供了更多信息。整个回调处理的耗时分布特征并不固定，有时候是这个远程调用耗时长，有时候是另外一个远程调用，有时候是服务本身访问数据库耗时长。下图是该服务通过 feign 远程调用其他服务的一个调用链。从图中我们可以这次远程调用的总体耗时是标记为“1.耗时”的时间条。而远程服务的实际耗时是标记为“2.远程服务耗时”的时间条。可以看到远程实际耗时很小，只有 90 毫秒。远程调用早早地返回了，但是调用线程似乎是卡住了，没有被正常调度运行，结束远程调用。 微信图片_20220717111724.png

1.3 推测

基于以上信息，推测可能的情况是服务内部比较忙，从而导致上图中的远程调用的线程等待了很久才得到运行。不过从日志上看不出来服务在忙什么，对比了重启后不久，服务行为正常时候的日志，并没有发现特别不一样的地方。那么导致这种现象的可能的原因是服务器本身 CPU 很忙，另外一种情况服务器并不忙，只是出现问题的服务本身忙。服务器的监控显示当时 CPU 比较空闲，如图：

image.png

所以只有一个可能，出现问题的服务本身忙。我们采用 k8s 对服务进行编排，服务器是 4 核的 CPU, 设置了 CPU 最大为 1000m，也就是最大占用 1 核。服务器 CPU 性能监控图可以看出 CPU 使用率是 32% 多点。服务重启后，下降 CPU 使用率下降到 5% 左右。也就是说重启之前该服务基本上是把分配的 CPU 配额全用上了。

下图是基于 Grafana 的服务实例的 CPU 使用率监控。从图中可以看到服务的 CPU 使用率持续上升，直到达到分配的最高配额 1 个核。这就印证了我们的推测，服务很忙，导致微信回调处理过程获得的 CPU 分片不足，从而导致回调超时。 1658053757682.png

1.4 定位

从日志和 skywalking 大致统计同时段的请求数并没有出现较明显的增长。再对照Grafana 的服务实例的 CPU 使用率监控图，可以得出系统存在 CPU 资源泄露的情况。CPU 资源泄露一定是和线程相关的。在服务的工程代码中用 “thread” 关键字搜索。发现了一个可疑的地方。在 xxljob 中，创建 ThreadPoolExecutor 线程池。

BlockingDeque<Runnable> blockingDeque = new LinkedBlockingDeque<>(10);
ThreadPoolExecutor exs = new ThreadPoolExecutor(
        10, 20, 60, TimeUnit.SECONDS, blockingDeque);
CompletableFuture[] completableFutures = datas.stream().map(t -> {
            ...
            return CompletableFuture.supplyAsync(() -> doSomeThing(), exs)
                    .whenComplete((v, e) -> {
                        ...
                    });
        }
).toArray(CompletableFuture[]::new);
CompletableFuture.allOf(completableFutures).join();

这段代码的主要逻辑是创建一个核心线程数为 10 的线程池，作为 CompletableFuture 异步任务的执行线程池。最后等待所有异步任务完成。 我们知道创建线程池是耗时操作，正确的用法是创建线程池长期使用，而不是在定时任务中临时创建线程池。这里一定是存在问题的。那么撇开用法是否合理，这里的用法会导致本文描述的问题吗？

2.线程池对象超出变量有效范围后能正常释放吗？

线程池需要手动关闭吗，可以通过简单的测试验证下下到底线程池用完要不要关闭。代码如下：

public static void main(String[] args) throws Exception { 
    //用于获取到本java进程，进而获取总线程数 
    RuntimeMXBean runtimeBean = ManagementFactory.getRuntimeMXBean(); 
    String jvmName = runtimeBean.getName(); 
    System.out.println("JVM Name = " + jvmName); 
    ThreadMXBean bean = ManagementFactory.getThreadMXBean(); 
    int n = 30000; 
    for (int i = 0; i < n; i++) { 
        ThreadPoolExecutor executor = new ThreadPoolExecutor(10,20,1000,TimeUnit.SECONDS,new LinkedBlockingDeque<>()); 
        for(int j=0;j<10;j++){ 
            executor.execute(()->{ 
                System.out.println("total thread count: "+bean.getThreadCount()); 
            }); 
        } 
    } 
    Thread.sleep(10000); 
    System.out.println("exit, total thread count: " + bean.getThreadCount()); 
}
--------------------
运行打印输出：
total thread count: 2790
thread: pool-465-thread-1
task complted, thread: pool-465-thread-1
Exception in thread "main" java.lang.OutOfMemoryError: unable to create new native thread
	at java.lang.Thread.start0(Native Method)
	at java.lang.Thread.start(Thread.java:714)

运行结果给我们的答案是：如果没有手动关闭线程池，那么线程池的线程并不会自动释放，会越积越多，直到进程内存耗尽。

image.png

我们再来看看官方文档怎么说，下面节选一段相关的描述：

  • Finalization
    A pool that is no longer referenced in a program AND has no remaining threads will be shutdown automatically. If you would like to ensure that unreferenced pools are reclaimed even if users forget to call shutdown(), then you must arrange that unused threads eventually die, by setting appropriate keep-alive times, using a lower bound of zero core threads and/or setting allowCoreThreadTimeOut(boolean).

这段话说的是：一个没有被引用的线程池，并且没有存活线程的话，将会被自动 shutdown。那也就是说，如果线程池有存活线程的话，即使线程池对象以及被引用，也不会自动释放线程。线程将会一直存在。

3.结论

Java 线程与系统线程相对应，系统线程是系统的关键资源。如果无节制的创建线程，将很快消耗完系统资源。线程池的正确使用模式是长期存在，用于为某种特定任务场景提供多线程执行支持。比如 web 容器处理请求的线程池。不应该为了临时创建用来执行一次性的短期任务。即使是特殊场景，需要临时创建线程池，那么也应该在任务完成后显式的调用 shutdown() 关闭线程池。

avatar
文章
阅读
粉丝