接口耗时2000多秒!我人麻了!
- 前几天早上,有个push服务不断报警,报了很多次,每次都得运维同学重启服务来维持,因为这个是我负责的,所以我顿时紧张了起来,匆忙来到公司,早饭也不吃了,赶紧排查!
1、 现象与排查步骤:
下面是下午时候几次告警的截图:
- 来看下图。。。。接口超时 2000多秒。。。。我的心碎了!!!人也麻了!!!脑瓜子嗡嗡的。。。
- 另外还总是报pod不健康、不可用 这些比较严重的警告!
我的第一反应是调用方有群发操作,然后看了下接口的qps 貌似也不高呀!也就 9req/s, 之后我去 grafana 监控平台 观察jvm信息发现,线程数量一直往上涨,而且线程状态是 WAITING
的也是一直涨。
如下是某一个pod的监控:
为了观察到底是哪个线程状态一直在涨,我们点进去看下详情:
上图可以看到 该pod的线程状态图 6种线程状态全列出来了, 分别用不同颜色的线代表。而最高那个同时也是14点以后不断递增那个是蓝线 代表的是 WAITING 状态下的线程数量。
通过上图现象,我大概知道了,肯定有线程是一直在wait
,无限wait下去
,后来我找运维同学 dump了线程文件,分析一波,来看看到底是哪个地方使线程进入了wait !!!
如下 是dump下来的线程文件,可以看到搜索出427个WAITING
, 这也基本和 grafana 监控中状态是WAITTING的线程数量一致
重点来了(这个 WAITING 状态的堆栈信息,还都是从 IOSPushStrategy#pushMsgWithIOS
这个方法的某个地方出来的(151行出来的)),于是我们找到代码来看看,是哪个小鬼在作怪?
而类 PushNotificationFuture 继承了 CompletableFuture,他自己又没有get方法,所以本质上 就是调用的 CompletableFuture的 get 方法。 ps:提一嘴,我们这里的场景是 等待ios push服务器的结果,不知道啥情况,今天(指发生故障的那天)ios push服务器(域名: api.push.apple.com )一直没返回,所以就导致
一直等待下去了
。。
看到这, 我 豁然开朗 && 真相大白 了,原来是在使用 CompletableFuture
的 get
时候,没设置超时时间,这样的话会导致一直在等结果。。。(但代码不是我写的,因为我知道 CompletableFuture 的get不设置参数会一直等下去 ,我只是维护,后期也没怎么修改这块的逻辑,哎 ,说多了都是泪呀!)
好一个 CompletableFuture#get();
(真是 死等啊。。。一点不含糊的等待下去,等的天荒地老海枯石烂也要等下去\~\~\~ )
到此,问题的原因找到了。
2、 修复问题
解决办法很简单,给CompletableFuture的get操作 加上超时时间即可,如下代码即可修复:
在修复后,截止到今天(6月8号)没有这种报警情况了,而且线程数和WAITING线程都比较稳定,都在正常范围内,如下截图(一共4个pod):
至此问题解决了\~\~\~ 终于可以睡个好觉啦!
3、 复盘总结
3.1、 代码浅析
既然此次的罪魁祸首是 CompletableFuture的get方法 那么我们就浅析一下 :
- 首先看下
get();
方法
上边可以看到 不带参数的get方法: if(deadLine==0) 成立
,也就是最终调用了LockSupport的park(this);方法,而这个方法最终调了unsafe的这个方法-> unsafe.park(false, 0L); 其中第二个参数就是等待多长时间后,unpark即唤醒被挂起的线程,而0 则代表无限期等待。
- 再来看下
get(long timeOut,TimeUnit unit);
方法 我们可以看到 带参数的get方法:if(deadLine==0) 不成立,走的else逻辑
也就是最终调用了LockSupport
的parkNanos(this,nanos);
方法,而这个方法最终调了unsafe
的这个方法->unsafe.park(false, nanos);
其中第二个参数就是你调用get时,传入的tiimeOut参数(只不过底层转成纳秒了) 我们跑了下程序,发现超过指定时间后,get(long timeOut,TimeUnit unit);
方法抛出 TimeoutException异常,而至于超时后我们开发者怎么处理,就在于具体情况了。java Exception in thread "main" java.util.concurrent.TimeoutException at java.base/java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1886) at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2021)
而在 我的另一篇文章 万字长文分析synchroized 这篇文章中,我们其实深入过openjdk
的源码,见识过park
和unpark
操作,我们截个图回忆一下:
3.2、最后总结:
1.在调用外部接口时。一定要注意设置超时时间,防止三方服务出问题后影响自身服务。
2. 以后无论看到什么类型的Future,都要谨慎,因为这玩意说的是异步,但是调用get方法时,他本质上是同步等待,所以必须给他设置个超时时间,否则他啥时候能返回结果,就得看天意了! 3. 凡是和第三方对接的东西,都要做最坏的打算,快速失败的方式很有必要。 4. 遇到天大的问题,都尽可能保持冷静,不要乱了阵脚!