Welcome to pay attention to the public account “JAVA Front” to view more wonderful sharing articles, mainly including source code analysis, practical application, architecture thinking, workplace sharing, product thinking and so on, at the same time, welcome to add my wechat “JAVA_front” to communicate and learn together


1. Article Overview

DUBBO thread pool full is a serious problem, this article through an example analysis how to troubleshoot. First we reproduce the exception in code.

1.1 Producer Configuration

<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>
Copy the code


1.2 Producer Services

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); // Simulate time-consuming operations
        System.out.println("Producer performance Results" + result);
        returnresult; }}Copy the code


1.3 Consumer Configuration

<beans>
    <dubbo:registry address=Zookeeper: / / "127.0.0.1:2181" />
    <dubbo:reference id="helloService" interface="com.itxpz.dubbo.demo.provider.HelloService" />
</beans>  
Copy the code


1.4 Consumer Business

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

    public static void testThread(a) {
        ClassPathXmlApplicationContext context = new ClassPathXmlApplicationContext(new String[] { "classpath*:METAINF/spring/dubbo-consumer.xml" });
        context.start();
        // Simulate high concurrency scenarios
        for (int i = 0; i < 500; i++) {
            new Thread(new Runnable() {
                @Override
                public void run(a) {
                    HelloService helloService = (HelloService) context.getBean("helloService");
                    String result;
                    try {
                        result = helloService.sayHello("IT xu Fatty.");
                        System.out.println("Client receives result" + result);
                    } catch(Exception e) { System.out.println(e.getMessage()); } } }).start(); }}}Copy the code


2 Problem Analysis

Running the program finds that both producers and consumers throw exception messages. Let’s analyze the problem from three dimensions.

2.1 Producer or consumer

It is important to analyze whether the exception occurred at the producer or consumer, and this article provides three steps

Dubboserverhandler-x.x.x. x:port indicates the IP address and port of the server where the exception occurs. (3) Determine whether the producer or consumer is a producer based on the server IP address and portCopy the code

Analysis of the producer log DubboServerHandler address and port indicates that this is a producer exception

[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)

By analyzing the address and port of the DubboServerHandler in the consumer log, it can be concluded that this is a producer exception. Combined with the Server side information, it can be confirmed that the exception occurred at the producer

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)


2.2 Consumer Analysis

By analyzing the consumer log, we know that the producer thread pool is full, and we can locate which method reported an error. Consumers need to implement de-escalation strategies, such as using mock mechanisms or circuit breakers. We can also search the producer address to check the service running status of this machine on the console. If it is not maintained by our team, we need to contact relevant technical team to deal with it quickly.


2.3 Producer Analysis

We know that the producer thread pool is full, but we do not know which method reported an error, so we need to analyze the thread snapshot. When the thread pool is full, the reject policy will be executed, and the reject policy will output thread snapshot file to protect the site. We can locate the method by analyzing thread snapshot file

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);
        // Prints a thread snapshot
        dumpJStack();
        throw new RejectedExecutionException(msg);
    }

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

        // Output thread snapshot every 10 minutes
        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 file location /home/xxx/dubbo_jstack.log.2020-06-09_20:50:15
            // Windows file location /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();
        });
        // The thread pool must be disabled otherwise OOM will be raisedpool.shutdown(); }}Copy the code

We focused on the status of BLOCKED and TIMED_WAITING threads. Analyzing the thread snapshot file, we found that a large number of threads were BLOCKED or waiting, so that we could locate the specific method. After locating the specific method, we could optimize it, which is the core of solving the problem of thread pool full.

"Dubboserverhandler-1.1.1.1:8888 -thread-200" Id=230 TIMED_WAITING at java.lang.thread. sleep(Native Method) at" 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)Copy the code


3 Article Summary

This paper analyzes the troubleshooting idea of DUBBO thread pool full. First, through log analysis, it is the producer or the consumer that causes the problem. The producer and consumer exception log information is different. Second, the thread snapshot information is used to locate slow service information. Third, slow service optimization is the core to solve the problem.

Welcome to pay attention to the public account “JAVA Front” to view more wonderful sharing articles, mainly including source code analysis, practical application, architecture thinking, workplace sharing, product thinking and so on, at the same time, welcome to add my wechat “JAVA_front” to communicate and learn together