「DUBBO系列」线程池打满问题怎么查

欢迎你们关注公众号「JAVA前线」查看更多精彩分享文章,主要包括源码分析、实际应用、架构思惟、职场分享、产品思考等等,同时欢迎你们加我微信「java_front」一块儿交流学习java


1 文章概述

DUBBO线程池打尽是一个严重问题,本文经过一个实例分析如何排查。首先咱们用代码重现这个异常。linux

1.1 生产者配置

<beans>
  <dubbo:registry address="zookeeper://127.0.0.1:2181" />
  <dubbo:protocol name="dubbo" port="8888" />
  <dubbo:service interface="com.itxpz.dubbo.demo.provider.HelloService" ref="helloService" />
</beans>
复制代码

1.2 生产者业务

package com.itxpz.dubbo.demo.provider;
public interface HelloService {
    public String sayHello(String name) throws Exception;
}

public class HelloServiceImpl implements HelloService {
    public String sayHello(String name) throws Exception {
        String result = "hello[" + name + "]";
        Thread.sleep(10000L); // 模拟耗时操做
        System.out.println("生产者执行结果" + result);
        return result;
    }
}
复制代码

1.3 消费者配置

<beans>
    <dubbo:registry address="zookeeper://127.0.0.1:2181" />
    <dubbo:reference id="helloService" interface="com.itxpz.dubbo.demo.provider.HelloService" />
</beans>  
复制代码

1.4 消费者业务

public class Consumer {
    public static void main(String[] args) throws Exception {
        testThread();
        System.in.read();
    }

    public static void testThread() {
        ClassPathXmlApplicationContext context = new ClassPathXmlApplicationContext(new String[] { "classpath*:METAINF/spring/dubbo-consumer.xml" });
        context.start();
        // 模拟高并发场景
        for (int i = 0; i < 500; i++) {
            new Thread(new Runnable() {
                @Override
                public void run() {
                    HelloService helloService = (HelloService) context.getBean("helloService");
                    String result;
                    try {
                        result = helloService.sayHello("IT徐胖子");
                        System.out.println("客户端收到结果" + result);
                    } catch (Exception e) {
                        System.out.println(e.getMessage());
                    }
                }
            }).start();
        }
    }
}
复制代码

2 问题分析

运行程序发现生产者和消费者都抛出异常信息,下面咱们从三个维度分析这个问题。spring

2.1 生产者仍是消费者

分析异常发生在生产者仍是消费者很是重要,本文提供三个步骤apache

(1) 生产者和消费者异常日志内容不相同
(2) DubboServerHandler-x.x.x.x:port表示发生异常服务器地址和端口
(3) 根据服务器地址和端口分析是生产者仍是消费者
复制代码

分析生产者日志DubboServerHandler地址和端口能够得出这是生产者异常windows

[02/06/20 20:50:15:991 CST] NettyServerWorker-5-1 WARN support.AbortPolicyWithReport: [DUBBO] Thread pool is EXHAUSTED Thread Name: DubboServerHandler-1.1.1.1:8888 Pool Size: 200 (active: 200, core: 200, max: 200, largest: 200) Task: 201 (completed: 1)服务器

分析消费者日志DubboServerHandler地址和端口能够分析得出这是生产者异常,再结合Server side信息能够确认异常发生在生产者微信

Failed to invoke the method sayHello in the service com.itxpz.dubbo.demo.provider.HelloService Tried 3 times of the providers [1.1.1.1:8888] (1/1) from the registry 127.0.0.1:2181 Server side(1.1.1.1,8888) threadpool is exhausted ,detail msg:Thread pool is EXHAUSTED Thread Name: DubboServerHandler-1.1.1.1:8888, Pool Size: 200 (active: 200, core: 200, max: 200, largest: 200), Task: 201 (completed: 1)markdown


2.2 消费者分析

分析消费者日志咱们知道生产者线程池被打满,并且能够定位到哪个方法报错。消费者须要作好降级策略,例如使用mock机制或者熔断保护系统。咱们还能够查找生产者地址在控制台查询这台机器服务运行状况,若是不是本团队维护还要联系相关技术团队迅速处理。架构


2.3 生产者分析

分析生产者日志咱们知道生产者线程池被打满,可是不知道哪个方法报错,这就须要结合线程快照进行分析。线程池被打满时拒绝策略会被执行,拒绝策略会输出线程快照文件保护现场,咱们经过分析线程快照文件能够定位方法并发

public class AbortPolicyWithReport extends ThreadPoolExecutor.AbortPolicy {
    protected static final Logger logger = LoggerFactory.getLogger(AbortPolicyWithReport.class);
    private final String threadName;
    private final URL url;
    private static volatile long lastPrintTime = 0;
    private static Semaphore guard = new Semaphore(1);

    public AbortPolicyWithReport(String threadName, URL url) {
        this.threadName = threadName;
        this.url = url;
    }

    @Override
    public void rejectedExecution(Runnable r, ThreadPoolExecutor e) {
        String msg = String.format("Thread pool is EXHAUSTED!" +
                                   " Thread Name: %s, Pool Size: %d (active: %d, core: %d, max: %d, largest: %d), Task: %d (completed: %d)," +
                                   " Executor status:(isShutdown:%s, isTerminated:%s, isTerminating:%s), in %s://%s:%d!",
                                   threadName, e.getPoolSize(), e.getActiveCount(), e.getCorePoolSize(), e.getMaximumPoolSize(), e.getLargestPoolSize(),
                                   e.getTaskCount(), e.getCompletedTaskCount(), e.isShutdown(), e.isTerminated(), e.isTerminating(),
                                   url.getProtocol(), url.getIp(), url.getPort());
        logger.warn(msg);
        // 打印线程快照
        dumpJStack();
        throw new RejectedExecutionException(msg);
    }

    private void dumpJStack() {
        long now = System.currentTimeMillis();

        // 每10分钟输出线程快照
        if (now - lastPrintTime < 10 * 60 * 1000) {
            return;
        }
        if (!guard.tryAcquire()) {
            return;
        }

        ExecutorService pool = Executors.newSingleThreadExecutor();
        pool.execute(() -> {
            String dumpPath = url.getParameter(Constants.DUMP_DIRECTORY, System.getProperty("user.home"));
            System.out.println("AbortPolicyWithReport dumpJStack directory=" + dumpPath);
            SimpleDateFormat sdf;
            String os = System.getProperty("os.name").toLowerCase();

            // linux文件位置/home/xxx/Dubbo_JStack.log.2020-06-09_20:50:15
            // windows文件位置/user/xxx/Dubbo_JStack.log.2020-06-09_20-50-15
            if (os.contains("win")) {
                sdf = new SimpleDateFormat("yyyy-MM-dd_HH-mm-ss");
            } else {
                sdf = new SimpleDateFormat("yyyy-MM-dd_HH:mm:ss");
            }
            String dateStr = sdf.format(new Date());

            // try-with-resources
            try (FileOutputStream jStackStream = new FileOutputStream(new File(dumpPath, "Dubbo_JStack.log" + "." + dateStr))) {
                JVMUtil.jstack(jStackStream);
            } catch (Throwable t) {
                logger.error("dump jStack error", t);
            } finally {
                guard.release();
            }
            lastPrintTime = System.currentTimeMillis();
        });
        // 必须关闭线程池不然会引起OOM
        pool.shutdown();
    }
}
复制代码

BLOCKED和TIMED_WAITING线程状态咱们重点关注,分析线程快照文件发现大量线程阻塞或者等待从而能够定位到具体方法,定位具体方法后进行优化这是解决线程池打满问题核心。

"DubboServerHandler-1.1.1.1:8888-thread-200" Id=230 TIMED_WAITING
	at java.lang.Thread.sleep(Native Method)
	at com.itxpz.dubbo.demo.provider.HelloServiceImpl.sayHello(HelloServiceImpl.java:13)
	at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.dubbo.rpc.proxy.jdk.JdkProxyFactory$1.doInvoke(JdkProxyFactory.java:47)
	at org.apache.dubbo.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:88)
	at org.apache.dubbo.config.invoker.DelegateProviderMetaDataInvoker.invoke(DelegateProviderMetaDataInvoker.java:56)
	at org.apache.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:56)
	at org.apache.dubbo.rpc.filter.ExceptionFilter.invoke(ExceptionFilter.java:63)
	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:80)
	at org.apache.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:88)
	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:80)
	at org.apache.dubbo.rpc.filter.TimeoutFilter.invoke(TimeoutFilter.java:42)
	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:80)
	at org.apache.dubbo.rpc.protocol.dubbo.filter.TraceFilter.invoke(TraceFilter.java:80)
	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:80)
	at org.apache.dubbo.rpc.filter.ContextFilter.invoke(ContextFilter.java:78)
	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:80)
	at org.apache.dubbo.rpc.filter.GenericFilter.invoke(GenericFilter.java:143)
	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:80)
	at org.apache.dubbo.rpc.filter.ClassLoaderFilter.invoke(ClassLoaderFilter.java:38)
	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:80)
	at org.apache.dubbo.rpc.filter.EchoFilter.invoke(EchoFilter.java:39)
	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:80)
	at org.apache.dubbo.rpc.protocol.dubbo.DubboProtocol$1.reply(DubboProtocol.java:115)
	at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:104)
	at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:208)
	at org.apache.dubbo.remoting.transport.DecodeHandler.received(DecodeHandler.java:51)
	at org.apache.dubbo.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:57)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
复制代码

3 文章总结

本文分析了DUBBO线程池打满问题排查思路,第一经过日志分析是生产者仍是消费者发生问题,生产者和消费者异常日志信息不一样。第二经过线程快照信息定位具体慢服务信息。第三优化慢服务是解决问题核心。

欢迎你们关注公众号「JAVA前线」查看更多精彩分享文章,主要包括源码分析、实际应用、架构思惟、职场分享、产品思考等等,同时欢迎你们加我微信「java_front」一块儿交流学习