歡迎你們關注公衆號「JAVA前線」查看更多精彩分享文章,主要包括源碼分析、實際應用、架構思惟、職場分享、產品思考等等,同時歡迎你們加我微信「java_front」一塊兒交流學習java
DUBBO線程池打盡是一個嚴重問題,本文經過一個實例分析如何排查。首先咱們用代碼重現這個異常。linux
<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>
複製代碼
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;
}
}
複製代碼
<beans>
<dubbo:registry address="zookeeper://127.0.0.1:2181" />
<dubbo:reference id="helloService" interface="com.itxpz.dubbo.demo.provider.HelloService" />
</beans>
複製代碼
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();
}
}
}
複製代碼
運行程序發現生產者和消費者都拋出異常信息,下面咱們從三個維度分析這個問題。spring
分析異常發生在生產者仍是消費者很是重要,本文提供三個步驟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
分析消費者日誌咱們知道生產者線程池被打滿,並且能夠定位到哪個方法報錯。消費者須要作好降級策略,例如使用mock機制或者熔斷保護系統。咱們還能夠查找生產者地址在控制檯查詢這臺機器服務運行狀況,若是不是本團隊維護還要聯繫相關技術團隊迅速處理。架構
分析生產者日誌咱們知道生產者線程池被打滿,可是不知道哪個方法報錯,這就須要結合線程快照進行分析。線程池被打滿時拒絕策略會被執行,拒絕策略會輸出線程快照文件保護現場,咱們經過分析線程快照文件能夠定位方法併發
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)
複製代碼
本文分析了DUBBO線程池打滿問題排查思路,第一經過日誌分析是生產者仍是消費者發生問題,生產者和消費者異常日誌信息不一樣。第二經過線程快照信息定位具體慢服務信息。第三優化慢服務是解決問題核心。
歡迎你們關注公衆號「JAVA前線」查看更多精彩分享文章,主要包括源碼分析、實際應用、架構思惟、職場分享、產品思考等等,同時歡迎你們加我微信「java_front」一塊兒交流學習