我去dubbo线程池又被打爆（打满）了java.util.concurrent.RejectedExecutionException: Thread pool is EXHAUSTED

最近线上系统经常告警dubbo线程池打满报错如下：

172.28.152.53/Caused by: java.util.concurrent.RejectedExecutionException: Thread pool is EXHAUSTED! Thread Name: DubboServerHandler-172.28.149.131:20880, Pool Size: 500 (active: 500, core: 500, max: 500, largest: 500), Task: 71795841 (completed: 71795342), Executor status:(isShutdown:false, isTerminated:false, isTerminating:false), in dubbo://172.28.149.131:20880!

对这个告警做了协查，记录一下，给大家一个参考。

dubbo线程池打满后，会立即生成一个线程dump文件，这里先去服用器上拿文件，立即生成一个线程dump文件需要配置一下启动参数

-Ddubbo.application.dump.directory=/data/dataLogs/jetty/dump

以后发生 dubbo线程池打满就到以到/data/dataLogs/jetty/dump下找文件,另外大家也可以通过jstack jmap等命令分析，我们因为投产使用不了，这里大家自行学习。

拿到dump文件后，打开看看 

 足足有2W多行，这么一行行看也没问题，这里推荐个分析工具：Smart Java thread dump analyzer - thread dump analysis in seconds

 上传文件后，生产一个分析结果页面，很好用，如下图。

上图BLOCKED 的线程有2个，点进去看一下明细

 

 综合业务和线程栈分析： 我们做了一个日志打印的aop,在方法入口切入，添加一个uuid生成的TraceID,通过MDC将日志串起来，我们使用java的UUID对象的randomUUID()生成id,randomUUID底层使用SecureRandom,像注释里讲了，多线程并发时，会BLOCK，所以性能不是很高。

 解决办法：

我自己写一个方法：

package com.test.java8;

import java.util.UUID;
import java.util.concurrent.atomic.AtomicLong;

public class MyUUID {

//    static final AtomicLong counter = new AtomicLong(System.nanoTime());
    static final AtomicLong counter = new AtomicLong(System.currentTimeMillis());

    public static String getUUID() {
        return String.valueOf(counter.getAndIncrement());
    }


    public static String getUuid() {
        return UUID.randomUUID().toString().replace("-", "");
    }


    public static void main(String[] args) {
        int rCount = 100000000;
        System.out.println("开始随机数生成测试！");
        Long begin = System.currentTimeMillis();
        for (int i = 0; i < rCount; i++) {
            MyUUID.getUUID();
//            System.out.println(MyUUID.getUUID());
        }
        System.out.printf("完成随机数生成，用时" + (System.currentTimeMillis() - begin) + "ms");

        System.out.println("-----------------------------------------------------------------");

//        Long begin2 = System.currentTimeMillis();
//        for (int i = 0; i < rCount; i++) {
//            MyUUID.getUuid();
//        }
//        System.out.printf("完成随机数生成，用时" + (System.currentTimeMillis() - begin2) + "ms");
//        System.out.println(MyUUID.getUUID());
//        System.out.println(MyUUID.getUuid());
    }
}

注意！：不保证集群唯一的，这里因为主要是Trace 所以问题不大。如果有集群唯一的需求不要用我这个方法，可以参考SnowFlake等算法。

至此这个dump就分析完了。

那边在这次协查中，还有一个dump锁在了另外一个地方，贴一下图：

 

 通过分析：

项目中使用的是logback的实现，项目配置的是AsyncAppender异步打印，异步打印日志会被存放在一个SynchronousQueue,然后再由消费线程来消费打印，以提升系统性能（建议大家生产一定要用异步），SynchronousQueue是阻塞队列，由于请求量大，打印的日志又多，最终导致消费速度跟不上，后面的添加队列都阻塞了，业务线程都夯在这里。

解决方案：

1.删除一些多余，无用日志（打印日志确实也很耗性能），打印尽量精简（我们通过此方法解决）。

2.升级日志框架（考虑中），目前log4j2看起来是不错的选择，官方也给了一些性能比较数据Log4j – Performance，log4j2的异步消息存储不是阻塞队列，是通过Disruptor高性能队列实现性能更强劲。更有美团在2016年将使用log4j2作为内部规范（高性能队列——Disruptor - 美团技术团队）,哈哈，看来我们的步子还是有点慢了！

 也做了一个集成log4j2的demo,仅供参考：GitHub - kevinmails/h2-test

牺牲了午休时间，用心总结，觉得有用的话，收藏转发，哈哈！