作者：sunshujie1990
www.jianshu.com/p/d85cd6d60a6e
前情提要
最近读了一篇关于线程池故障排查的文章，收货颇丰。文章地址如下：
这里简要回顾一下,感兴趣的同学可以仔细读一下这篇文章。
1、故障场景：dubbo线程池打满，服务处于夯死状态。但是5分钟之后却自动恢复了。
2、排查过程：略
3、故障原因：
项目使用RestTemplate访问某个外部接口。
RestTemplate使用的是HttpClient的实现，HttpClient实现了连接池,但是默认的最大连接数只有5。
基于以上两点，一旦该外部接口超时很有可能在HttpClient获取连接的时候阻塞当前线程,最终造成dubbo线程池全部打满。
排查过程优化
问题是找到了，但是原文排查过程颇为艰辛。那么有没有更为有效的方法来快速定位线程池打满的问题呢?
可以通过jstack dump线程,然后对线程进行分析,从而快速定位问题!
场景构建
这里构建一个简单的环境复现上述场景：
1、构建一个spring boot项目，简单起见使用Tmocat线程池代替案例中的dubbo线程池.项目引入了httpclient，spring boot会自动将RestTemplate配置为httpclient的实现。
<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
<groupId>org.apache.httpcomponents</groupId>
<artifactId>httpclient</artifactId>
<version>4.5.4</version>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-test</artifactId>
<scope>test</scope>
</dependency>
</dependencies>
设置Tomcat工作线程池，最小10个线程,最大20个线程。这里只是为了模拟场景，所以最大线程池设置的比较小。
server.tomcat.min-spare-threads=10
server.tomcat.max-threads=20
2、编写一个http接口模拟案例中的外部接口，这里睡眠3秒模拟接口超时
@GetMapping("/slowApi")
public String slowApi() throws InterruptedException {
TimeUnit.SECONDS.sleep(3);
return "ok!";
}
3、构建一个RestTemplate，连接超时，读取超时设置为2秒
@Bean
public RestTemplate restTemplate(RestTemplateBuilder builder) {
return builder.setConnectTimeout(Duration.ofSeconds(2))
.setReadTimeout(Duration.ofSeconds(2)).build();
}
4、提供一个接口，使用RestTemplate访问外部接口
@GetMapping("/getMsg")
public String getMsg() {
try {
String demo = restTemplate.getForObject("http://localhost:8080/slowApi", String.class);
return ">>>" + demo;
} catch (Exception e) {
return "failed!";
}
}
5、编写一个简单的测试模拟并发访问
System.setProperty("http.maxConnections", String.valueOf(THREAD_POOL_SIZE));这里是设置HttpClient最大连接数，否则将达不到我们所期望的并发量。
public class ConcurrenceTest {
private static final int TOTAL_REQUEST = 100000;
private static final int THREAD_POOL_SIZE = 50;
@Test
public void test() throws InterruptedException {
System.setProperty("http.maxConnections", String.valueOf(THREAD_POOL_SIZE));
RestTemplateBuilder builder = new RestTemplateBuilder();
RestTemplate restTemplate = builder.build();
ExecutorService executorService = Executors.newFixedThreadPool(THREAD_POOL_SIZE);
CountDownLatch countDownLatch = new CountDownLatch(TOTAL_REQUEST);
for (int i = 0; i < TOTAL_REQUEST; i++) {
executorService.execute(()->{
restTemplate.getForObject("http://localhost:8080/getMsg", String.class);
countDownLatch.countDown();
});
}
countDownLatch.await();
executorService.shutdown();
}
}
以上代码已经上传至:
https://github.com/sunshujie1990/thread-troubleshooting
故障定位
1.启动项目
2.通过jps -l找到项目的进程号,，如下是16555
ssj@ssj-PC$: jps -l
16555 com.shujie.threadtroubleshooting.ThreadTroubleshootingApplication
3.通过jstack dump线程信息，如下会将线程信息dump到一个名为thread.txt的文件中
jstack 16555 > thread.txt
4.启动并发测试，通过浏览器访问http://localhost:8080/getMsg一直等待，说明Tomcat线程池已经被打满了，无法对外提供访问.
5.再次dump线程信息到另外一个文件
jstack 16555 > thread2.txt
6.分析dump线程信息
首先打开thread.txt，看下健康的Tomcat线程池是什么样子的：
"http-nio-8080-exec-10" #34 daemon prio=5 os_prio=0 tid=0x00007fa500bf9000 nid=0x40ea waiting on condition [0x00007fa4e02dc000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000007844d1038> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:107)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:33)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
http-nio-8080-exec-10表示当前是第10个线程，因为我们设置了Tomcat初始化10个线程。
waiting on condition说明线程在等待某个条件。
线程栈从上往下看,排除JDK的方法，第一个是
org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:107)从方法名称可以看出，这里线程处于Tomcat的任务队列中,等待的条件就是一个新的请求的到来。
然后打开thread2.txt，再来看一下线程池被打满之后的线程信息
"http-nio-8080-exec-20" #54 daemon prio=5 os_prio=0 tid=0x00007fa468011800 nid=0x421c waiting on condition [0x00007fa4cd6ff000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000007067027e8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:379)
at org.apache.http.pool.AbstractConnPool.access$200(AbstractConnPool.java:69)
at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:245)
- locked <0x00000007824713a0> (a org.apache.http.pool.AbstractConnPool$2)
at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:193)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:303)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:279)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:191)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at org.springframework.http.client.HttpComponentsClientHttpRequest.executeInternal(HttpComponentsClientHttpRequest.java:87)
at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48)
at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53)
at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:735)
at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:670)
at org.springframework.web.client.RestTemplate.getForObject(RestTemplate.java:311)
at com.shujie.threadtroubleshooting.ThreadTroubleshootingApplication.getMsg(ThreadTroubleshootingApplication.java:35)
http-nio-8080-exec-20 说明当前是第20个线程，线程池确实被打满了，因为我们设置的最大线程数就是20个。
waiting on condition同上，线程处于等待状态，等待某个状态。
同样线程栈从上往下看,排除JDK的方法,第一个是
org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:379)从方法名可以看出是获取池化的资源阻塞。再往下看
PoolingHttpClientConnectionManager.leaseConnection可以看到HttpClient使用了连接池，每次从连接池租借一个连接执行任务，如果获取不到链接会使用J.U.C中的AQS阻塞当前线程。当前线程所等待的条件就是其他线程释放连接。
至此排查过程结束。
总结
线程池被打满，无法对外提供服务是非常严重的故障。产生的原因也是多种多样，不仅仅限于本文提到的这个场景。
本文希望能够通过这个简单的例子帮助大家在遇到类似的问题时快速定位BUG，而不至于一脸懵逼.
END
Java面试题专栏
【61期】MySQL行锁和表锁的含义及区别（MySQL面试第四弹）
【62期】解释一下MySQL中内连接，外连接等的区别（MySQL面试第五弹）
【63期】谈谈MySQL 索引，B+树原理，以及建索引的几大原则（MySQL面试第六弹）
【64期】MySQL 服务占用cpu 100%，如何排查问题? （MySQL面试第七弹）
【66期】Java容器面试题：谈谈你对 HashMap 的理解
【67期】谈谈ConcurrentHashMap是如何保证线程安全的？
【68期】面试官：对并发熟悉吗？说说Synchronized及实现原理
【69期】面试官：对并发熟悉吗？谈谈线程间的协作(wait/notify/sleep/yield/join)
【70期】面试官：对并发熟悉吗？谈谈对volatile的使用及其原理
我知道你 “在看”
扫一扫
4071
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
