- 摘要:背景在开发中,我们经常要使用Executors类创建线程池来执行大量的任务,使用线程池的并发特性提高系统的吞吐量。但是,线程池使用不当也会使服务器资源枯竭,导致异常情况的发生,比如固定线程池的阻塞队列任务数量过多、缓存线程池创建的线程过多导致内存溢出、系统假死等问题。因此,我们需要一种简单的监控方案来监控线程池的使用情况,比如完成任务数量、未完成任务数量、线程大小等信息。ExecutorsUtil工具类以下是我们开发的一个线程池工具类,该工具类扩展ThreadPoolExec
- 背景
在开发中,我们经常要使用Executors类创建线程池来执行大量的任务,使用线程池的并发特性提高系统的吞吐量。但是,线程池使用不当也会使服务器资源枯竭,导致异常情况的发生,比如固定线程池的阻塞队列任务数量过多、缓存线程池创建的线程过多导致内存溢出、系统假死等问题。因此,我们需要一种简单的监控方案来监控线程池的使用情况,比如完成任务数量、未完成任务数量、线程大小等信息。
ExecutorsUtil工具类以下是我们开发的一个线程池工具类,该工具类扩展ThreadPoolExecutor实现了线程池监控功能,能实时将线程池使用信息打印到日志中,方便我们进行问题排查、系统调优。具体代码如下:
package com.concurrent.monitor; import java.util.Date; import java.util.List; import java.util.concurrent.BlockingQueue; import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ExecutorService; import java.util.concurrent.LinkedBlockingQueue; import java.util.concurrent.SynchronousQueue; import java.util.concurrent.ThreadFactory; import java.util.concurrent.ThreadPoolExecutor; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicInteger; import org.slf4j.Logger; import org.slf4j.LoggerFactory; /** * 该类继承ThreadPoolExecutor类,覆盖了shutdown(), shutdownNow(), beforeExecute() 和 afterExecute() * 方法来统计线程池的执行情况 * */ public class ExecutorsUtil extends ThreadPoolExecutor { private static final Logger LOGGER = LoggerFactory.getLogger(ExecutorsUtil.class); // 保存任务开始执行的时间,当任务结束时,用任务结束时间减去开始时间计算任务执行时间 private ConcurrentHashMap startTimes; // 线程池名称,一般以业务名称命名,方便区分 private String poolName; /** * 调用父类的构造方法,并初始化HashMap和线程池名称 * * @param corePoolSize * 线程池核心线程数 * @param maximumPoolSize * 线程池最大线程数 * @param keepAliveTime * 线程的最大空闲时间 * @param unit * 空闲时间的单位 * @param workQueue * 保存被提交任务的队列 * @param poolName * 线程池名称 */ public ExecutorsUtil(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue workQueue, String poolName) { super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, new EventThreadFactory(poolName)); this.startTimes = new ConcurrentHashMap<>(); this.poolName = poolName; } /** * 线程池延迟关闭时(等待线程池里的任务都执行完毕),统计线程池情况 */ @Override public void shutdown() { // 统计已执行任务、正在执行任务、未执行任务数量 LOGGER.info(String.format(this.poolName + " Going to shutdown. Executed tasks: %d, Running tasks: %d, Pending tasks: %d", this.getCompletedTaskCount(), this.getActiveCount(), this.getQueue().size())); super.shutdown(); } /** * 线程池立即关闭时,统计线程池情况 */ @Override public List shutdownNow() { // 统计已执行任务、正在执行任务、未执行任务数量 LOGGER.info( String.format(this.poolName + " Going to immediately shutdown. Executed tasks: %d, Running tasks: %d, Pending tasks: %d", this.getCompletedTaskCount(), this.getActiveCount(), this.getQueue().size())); return super.shutdownNow(); } /** * 任务执行之前,记录任务开始时间 */ @Override protected void beforeExecute(Thread t, Runnable r) { startTimes.put(String.valueOf(r.hashCode()), new Date()); } /** * 任务执行之后,计算任务结束时间 */ @Override protected void afterExecute(Runnable r, Throwable t) { Date startDate = startTimes.remove(String.valueOf(r.hashCode())); Date finishDate = new Date(); long diff = finishDate.getTime() - startDate.getTime(); // 统计任务耗时、初始线程数、核心线程数、正在执行的任务数量、已完成任务数量、任务总数、队列里缓存的任务数量、池中存在的最大线程数、最大允许的线程数、线程空闲时间、线程池是否关闭、线程池是否终止 LOGGER.info(String.format(this.poolName + "-pool-monitor: Duration: %d ms, PoolSize: %d, CorePoolSize: %d, Active: %d, Completed: %d, Task: %d, Queue: %d, LargestPoolSize: %d, MaximumPoolSize: %d,KeepAliveTime: %d, isShutdown: %s, isTerminated: %s", diff, this.getPoolSize(), this.getCorePoolSize(), this.getActiveCount(), this.getCompletedTaskCount(), this.getTaskCount(), this.getQueue().size(), this.getLargestPoolSize(), this.getMaximumPoolSize(), this.getKeepAliveTime(TimeUnit.MILLISECONDS), this.isShutdown(), this.isTerminated())); } /** * 创建固定线程池,代码源于Executors.newFixedThreadPool方法,这里增加了poolName * * @param nThreads * 线程数量 * @param poolName * 线程池名称 * @return ExecutorService对象 */ public static ExecutorService newFixedThreadPool(int nThreads, String poolName) { return new ExecutorsUtil(nThreads, nThreads, 0L, TimeUnit.MILLISECONDS, new LinkedBlockingQueue (), poolName); } /** * 创建缓存型线程池,代码源于Executors.newCachedThreadPool方法,这里增加了poolName * * @param poolName * 线程池名称 * @return ExecutorService对象 */ public static ExecutorService newCachedThreadPool(String poolName) { return new ExecutorsUtil(0, Integer.MAX_VALUE, 60L, TimeUnit.SECONDS, new SynchronousQueue (), poolName); } /** * 生成线程池所用的线程,只是改写了线程池默认的线程工厂,传入线程池名称,便于问题追踪 */ static class EventThreadFactory implements ThreadFactory { private static final AtomicInteger poolNumber = new AtomicInteger(1); private final ThreadGroup group; private final AtomicInteger threadNumber = new AtomicInteger(1); private final String namePrefix; /** * 初始化线程工厂 * * @param poolName * 线程池名称 */ EventThreadFactory(String poolName) { SecurityManager s = System.getSecurityManager(); group = (s != null) ? s.getThreadGroup() : Thread.currentThread().getThreadGroup(); namePrefix = poolName + "-pool-" + poolNumber.getAndIncrement() + "-thread-"; } @Override public Thread newThread(Runnable r) { Thread t = new Thread(group, r, namePrefix + threadNumber.getAndIncrement(), 0); if (t.isDaemon()) t.setDaemon(false); if (t.getPriority() != Thread.NORM_PRIORITY) t.setPriority(Thread.NORM_PRIORITY); return t; } } }
以上的ExecutorsUtil类继承了ThreadPoolExecutor类,重写了shutdown()、shutdownNow()、beforeExecute() 和 afterExecute() 方法来统计线程池的执行情况,这四个方法是ThreadPoolExecutor类预留给开发者进行扩展的方法,具体如下:
shutdown():线程池延迟关闭时(等待线程池里的任务都执行完毕),统计已执行任务、正在执行任务、未执行任务数量
shutdownNow():线程池立即关闭时,统计已执行任务、正在执行任务、未执行任务数量
beforeExecute(Thread t, Runnable r):任务执行之前,记录任务开始时间,startTimes这个HashMap以任务的hashCode为key,开始时间为值
afterExecute(Runnable r, Throwable t):任务执行之后,计算任务结束时间。统计任务耗时、初始线程数、核心线程数、正在执行的任务数量、已完成任务数量、任务总数、队列里缓存的任务数量、池中存在的最大线程数、最大允许的线程数、线程空闲时间、线程池是否关闭、线程池是否终止信息监控到的记录如下:
momentspush-pool-2-thread-90 ExecutorsUtil.java:91 momentspush_monitor: Duration: 599 ms, PoolSize: 200, CorePoolSize: 200, Active: 200, Completed: 334924, Task: 417702, Queue: 82578, LargestPoolSize: 200, MaximumPoolSize: 200,KeepAliveTime: 0, isShutdown: false, isTerminated: false一般我们会依赖beforeExecute和afterExecute这两个方法统计的信息,具体原因请参考需要注意部分的最后一项。有了这些信息之后,我们可以根据业务情况和统计的线程池信息合理调整线程池大小,根据任务耗时长短对自身服务和依赖的其他服务进行调优,提高服务的可用性。
需要注意的
在afterExecute方法中需要注意,需要调用ConcurrentHashMap的remove方法移除并返回任务的开始时间信息,而不是调用get方法,因为在高并发情况下,线程池里要执行的任务很多,如果只获取值不移除的话,会使ConcurrentHashMap越来越大,引发内存泄漏或溢出问题。该行代码如下:
Date startDate = startTimes.remove(String.valueOf(r.hashCode()));有了ExecutorsUtil类之后,我们可以通过newFixedThreadPool(int nThreads, String poolName)和newCachedThreadPool(String poolName)方法创建两个日常我们使用最多的线程池,跟默认的Executors里的方法不同的是,这里需要传入poolName参数,该参数主要是用来给线程池定义一个与业务相关并有具体意义的线程池名字,方便我们排查线上问题。具体可参考《Java线程池扩展之关联线程池与业务》一文
在生产环境中,谨慎调用shutdown()和shutdownNow()方法,因为调用这两个方法之后,线程池会被关闭,不再接收新的任务,如果有新任务提交到一个被关闭的线程池,会抛出java.util.concurrent.RejectedExecutionException异常,具体可参考《一步一步分析RejectedExecutionException异常》一文。其实在使用Spring等框架来管理类的生命周期的条件下,也没有必要调用这两个方法来关闭线程池,线程池的生命周期完全由该线程池所属的Spring管理的类决定
-
转者实践代码:
import java.util.Date;
import java.util.List;
import java.util.concurrent.*;
import java.util.concurrent.atomic.AtomicInteger;
import org.slf4.LoggerFactory;
import org.slf4j.Logger;
/**
* 参考 https://www.aliyun.com/jiaocheng/778174.html
* 该类继承ThreadPoolExecutor类,覆盖了shutdown(), shutdownNow(), beforeExecute() 和 afterExecute()
* 方法来统计线程池的执行情况
*/
public class ThreadPoolExecutorWrapper extends ThreadPoolExecutor {
private static final Logger THREAD_POOL_MONITOR_LOGGER = LoggerFactory.getLogger("THREAD_POOL_MONITOR_LOGGER");
// 保存任务开始执行的时间,当任务结束时,用任务结束时间减去开始时间计算任务执行时间
private ConcurrentHashMap<String,Date> startTimes;
// 线程池名称,一般以业务名称命名,方便区分
private String poolName;
/**
* 调用父类的构造方法,并初始化HashMap和线程池名称
*
* @param corePoolSize 线程池核心线程数
* @param maximumPoolSize 线程池最大线程数
* @param keepAliveTime 线程的最大空闲时间
* @param unit 空闲时间的单位
* @param queueCapacity 保存被提交任务的队列
* @param poolName 线程池名称
*/
public ThreadPoolExecutorWrapper(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, int queueCapacity,
String poolName, RejectedExecutionHandler rejectedExecutionHandler) {
super(corePoolSize, maximumPoolSize, keepAliveTime, unit, new LinkedBlockingQueue<Runnable>(queueCapacity), new EventThreadFactory(poolName),rejectedExecutionHandler);
this.startTimes = new ConcurrentHashMap<>();
this.poolName = poolName;
}
/**
* 线程池延迟关闭时(等待线程池里的任务都执行完毕),统计线程池情况
*/
@Override
public void shutdown() {
// 统计已执行任务、正在执行任务、未执行任务数量
THREAD_POOL_MONITOR_LOGGER.info(String.format(this.poolName + " Going to shutdown. Executed tasks: %d, Running tasks: %d, Pending tasks: %d",
this.getCompletedTaskCount(), this.getActiveCount(), this.getQueue().size()));
super.shutdown();
}
/**
* 线程池立即关闭时,统计线程池情况
*/
@Override
public List shutdownNow() {
// 统计已执行任务、正在执行任务、未执行任务数量
THREAD_POOL_MONITOR_LOGGER.info(
String.format(this.poolName + " Going to immediately shutdown. Executed tasks: %d, Running tasks: %d, Pending tasks: %d",
this.getCompletedTaskCount(), this.getActiveCount(), this.getQueue().size()));
return super.shutdownNow();
}
/**
* 任务执行之前,记录任务开始时间
*/
@Override
protected void beforeExecute(Thread t, Runnable r) {
startTimes.put(String.valueOf(r.hashCode()), new Date());
}
/**
* 任务执行之后,计算任务结束时间
*/
@Override
protected void afterExecute(Runnable r, Throwable t) {
Date startDate = startTimes.remove(String.valueOf(r.hashCode()));
if(startDate == null){
startDate = new Date(0L);
}
Date finishDate = new Date();
long diff = finishDate.getTime() - startDate.getTime();
// 统计任务耗时、初始线程数、核心线程数、正在执行的任务数量、已完成任务数量、任务总数、队列里缓存的任务数量、池中存在的最大线程数、最大允许的线程数、线程空闲时间、线程池是否关闭、线程池是否终止
THREAD_POOL_MONITOR_LOGGER.info(String.format(this.poolName
+ "-pool-monitor: Duration: %d ms, PoolSize: %d, CorePoolSize: %d, Active: %d, Completed: %d, Task: %d, Queue: %d, LargestPoolSize: %d, MaximumPoolSize: %d,KeepAliveTime: %d, isShutdown: %s, isTerminated: %s",
diff, this.getPoolSize(), this.getCorePoolSize(), this.getActiveCount(), this.getCompletedTaskCount(), this.getTaskCount(),
this.getQueue().size(), this.getLargestPoolSize(), this.getMaximumPoolSize(), this.getKeepAliveTime(TimeUnit.MILLISECONDS),
this.isShutdown(), this.isTerminated()));
}
/**
* 生成线程池所用的线程,只是改写了线程池默认的线程工厂,传入线程池名称,便于问题追踪
*/
static class EventThreadFactory implements ThreadFactory {
private static final AtomicInteger poolNumber = new AtomicInteger(1);
private final ThreadGroup group;
private final AtomicInteger threadNumber = new AtomicInteger(1);
private final String namePrefix;
/**
* 初始化线程工厂
*
* @param poolName 线程池名称
*/
EventThreadFactory(String poolName) {
SecurityManager s = System.getSecurityManager();
group = (s != null) ? s.getThreadGroup() : Thread.currentThread().getThreadGroup();
namePrefix = poolName + "-pool-" + poolNumber.getAndIncrement() + "-thread-";
}
@Override
public Thread newThread(Runnable r) {
Thread t = new Thread(group, r, namePrefix + threadNumber.getAndIncrement(), 0);
if (t.isDaemon())
t.setDaemon(false);
if (t.getPriority() != Thread.NORM_PRIORITY)
t.setPriority(Thread.NORM_PRIORITY);
return t;
}
}
}
spring配置一个线程池实例
<!-- test -->
<bean id="myTaskExecutor" class="*.util.ThreadPoolExecutorWrapper">
<constructor-arg type="int" value="8"/><!-- corePoolSize 线程池维护线程的最少数量 -->
<constructor-arg type="int" value="20"/><!-- maximumPoolSize-->
<constructor-arg type="long" value="60"/><!--keep alive time-->
<constructor-arg type="java.util.concurrent.TimeUnit" value="SECONDS"/>
<constructor-arg type="int" value="5000" /><!--work queue capacity-->
<constructor-arg type="java.lang.String" value="myTask" />
<constructor-arg type="java.util.concurrent.RejectedExecutionHandler" ref="abortPolicy"/>
</bean>
<bean id ="abortPolicy" class="java.util.concurrent.ThreadPoolExecutor$AbortPolicy" />
logger4j配置
<logger name="THREAD_POOL_MONITOR_LOGGER" additivity="false">
<level value="INFO"/>
<appender-ref ref="THREAD_POOL_MONITOR_APPENDER"/>
</logger>
<appender name="THREAD_POOL_MONITOR_APPENDER" class="org.apache.log4j.DailyRollingFileAppender">
<param name="File" value="/app/logs/test/monitor/threadpool.log"/>
<param name="Append" value="true"/>
<param name="DatePattern" value="'.'yyyy-MM-dd"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss} %m%n"/>
</layout>
</appender>
日志
2018-10-16 20:51:02 my_task_pool-pool-monitor: Duration: 12 ms, PoolSize: 8, CorePoolSize: 8, Active: 2, Completed: 2998, Task: 3000, Queue: 0, LargestPoolSize: 8, MaximumPoolSize: 20,KeepAliveTime: 60000, isShutdown: false, isTerminated: false
2018-10-16 20:51:02 my_task_pool-pool-monitor: Duration: 12 ms, PoolSize: 8, CorePoolSize: 8, Active: 2, Completed: 2998, Task: 3000, Queue: 0, LargestPoolSize: 8, MaximumPoolSize: 20,KeepAliveTime: 60000, isShutdown: false, isTerminated: false