首页手记一次排查Java线程数异常--线程池使用不当造成线程数升高

一次排查Java线程数异常--线程池使用不当造成线程数升高

标签：

Java

Java对多线程有良好的支持，并且提供了方便使用的线程池框架（Executor）。但如果使用不当，可能会带来一些不安全的隐患。本文将分享一次由于随意创建线程池造成线程数持续增加的问题。

一、背景

首先看一个图，下图是线上服务器Java线程数的监控图。

图中每个下降的点都是在该时间点有上线操作，Tomcat重启的原因。其他时间，线程数呈线性增长趋势，最高点已经快到3千了。非常恐怖！如果不是因为有频繁的上线操作，线上服务很快就会出问题。

二、问题调查分析

将监控图时间点往回拉，定位到线程数异常开始的时间点。查看当天提交记录，发现一处与线程有关的修改。代码如下：

 1    /** 2      * 异步执行操作 3      */ 4     private void asyncDoSomething() { 5         ExecutorService executorService = Executors.newSingleThreadExecutor(); 6         ExecutorService executorService = new ThreadPoolExecutor(1, 1, 0L, TimeUnit.MILLISECONDS, new LinkedBlockingQueue<Runnable>(1)); 7         executorService.submit(new Runnable() { 8             @Override 9             public void run() {10                 // 此处仅使用示例代码11                 System.out.println("do something async...");12             }13         });14     }

我们先不讨论此处线程池使用是否正确，仅就此处修改而言，将原有 Executors.newSingleThreadExecutor() 替换为 new ThreadPoolExecutor(1, 1, 0L, TimeUnit.MILLISECONDS, new LinkedBlockingQueue<Runnable>(1)) ，似乎并无不妥（这么修改，是为了遵循阿里规约）。实现的功能都是创建一个单线程池。

1.dump线程栈分析

既然代码上未发现明显问题，那就转而直接查看线上问题。执行 $jps -v 查找到Java程序对应的进程号，然后执行 $jstack ${pid_num} > thread_dump.log ，将对应Java程序的线程栈信息转储到thread_dump.log文件中。（注意，如果当前操作用户不是启动Java程序的用户，需要执行 $sudo -u user_name jstack ${pid_num} > thread_dump.log ）。

截取部分线程栈信息如下：

"pool-165671-thread-1" #188938 prio=5 os_prio=0 tid=0x00007f1a38040000 nid=0x7f19 waiting on condition [0x00007f19065b9000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)        - parking to wait for  <0x00000000dbb0a178> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:        - None"pool-164990-thread-1" #188175 prio=5 os_prio=0 tid=0x00007f1a5402c800 nid=0x7a61 waiting on condition [0x00007f18d0d5e000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)        - parking to wait for  <0x00000000d8c1ef78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:        - None

线程栈信息即是在java程序中，所有线程的调用栈信息。其中包含了线程名、线程当前状态等内容。

经统计发现，当前Java程序一共有845个线程，其中803个线程处于线程阻塞等待状态：WAITING (parking)。而所有该状态的线程名字均为 pool-xxxxx-thread-1 ，即该线程属于某单线程池。

进一步分析 ThreadPoolExecutor 源码后发现，ThreadPoolExecutor 默认使用 DefaultThreadFactory 构造的线程池前缀即为pool-xxxxx-thread-1 ，如所示：

1         DefaultThreadFactory() {2             SecurityManager s = System.getSecurityManager();3             group = (s != null) ? s.getThreadGroup() :4                                   Thread.currentThread().getThreadGroup();5             namePrefix = "pool-" +6                           poolNumber.getAndIncrement() +7                          "-thread-";8         }

目前基本确定问题该问题是此处使用 ThreadPoolExecutor引起的。其实原因不复杂：程序每次调用asyncDoSomething方法时，均会创建一个新的线程池来执行任务。但在执行任务后并未关闭该线程池，造成线程无法被回收，线程一直处于等待状态。因而线程数会随时间线性上升。

2.分析Executors创建线程池方式

为什么原来使用 Executors.newSingleThreadExecutor() 时未出现这个问题呢？仍然是查看源码：

1 public static ExecutorService newSingleThreadExecutor() {2         return new FinalizableDelegatedExecutorService3             (new ThreadPoolExecutor(1, 1,4                                     0L, TimeUnit.MILLISECONDS,5                                     new LinkedBlockingQueue<Runnable>()));6}

原来该方法并不是直接new一个ThreadPoolExecutor对象返回，而是使用了一个代理类进行代理。进一步查看 FinalizableDelegatedExecutorService 源码：

1     static class FinalizableDelegatedExecutorService2         extends DelegatedExecutorService {3         FinalizableDelegatedExecutorService(ExecutorService executor) {4             super(executor);5         }6         protected void finalize() {7             super.shutdown();8         }9     }

在这个代理类中，实现了finalize方法，并在finalize方法中关闭线程池。根据finalize的特性，在GC时会调用finalize方法。因此 Executors.newSingleThreadExecutor()在每次垃圾回收时触发未被使用的线程池关闭，所以没有出现线程数持续上升的问题。

三、总结

这个问题是由于线程池使用不当造成的。使用线程池是为了避免重复、频繁地创建、销毁线程，进而对多个线程进行复用。以上线程池的使用明显未达到该目的，并因为线程池未关闭而造成线程无法被回收，线程数持续增加。

对以上代码进行修改后如下：

1     /** 固定大小线程池：核心线程数10，最大线程数10，空闲线程存活时长120秒，等待队列无界 */2     private static final ExecutorService EXECUTOR_SERVICE = new ThreadPoolExecutor(10,3             10,4             120L,5             TimeUnit.MILLISECONDS,6             new LinkedBlockingQueue<Runnable>(),7             new ThreadFactoryBuilder().setNameFormat("do-something-thread-pool-%d").build(),8             new ThreadPoolExecutor.AbortPolicy());

 1 /** 2      * 异步执行操作 3      */ 4     private void asyncDoSomething() { 5         EXECUTOR_SERVICE.submit(new Runnable() { 6             @Override 7             public void run() { 8                     // 此处仅使用示例代码 9                     System.out.println("do something async...");10                 }11         });12     }

定义一个统一的线程池，在每次调用asyncDoSomething方法时，都向该线程池提交一个任务。

修改后，线程数维持在一个比较稳定的量。