接口耗时2000多秒!我人麻了!

  • 前几天早上,有个push服务不断报警,报了很多次,每次都得运维同学重启服务来维持,由于这个是我担任的,所以我顿时紧张了起来,匆忙来到公司,早饭也不吃了,赶忙排查!

1、 现象与排查过程:

下面是下午时分几次告警的截图:

  • 来看下图。。。。接口超时 2000多秒。。。。我的心碎了!!!人也麻了!!!脑瓜子嗡嗡的。。。
  • 接口耗时2000多秒!我人麻了!
  • 另外还总是报pod不健康、不可用 这些比较严重的正告!
  • 接口耗时2000多秒!我人麻了!

我的榜首反应是调用方有群发操作,然后看了下接口的qps 貌似也不高呀!也就 9req/s, 之后我去 grafana 监控平台 调查jvm信息发现,线程数量一向往上涨,并且线程状况是 WAITING 的也是一向涨。

如下是某一个pod的监控:

接口耗时2000多秒!我人麻了!
接口耗时2000多秒!我人麻了!

为了调查到底是哪个线程状况一向在涨,咱们点进去看下详情:

接口耗时2000多秒!我人麻了!

上图能够看到 该pod的线程状况图 6种线程状况全列出来了, 别离用不同颜色的线代表。而最高那个同时也是14点以后不断递增那个是蓝线 代表的是 WAITING 状况下的线程数量。

通过上图现象,我大概知道了,肯定有线程是一向在wait无限wait下去,后来我找运维同学 dump了线程文件,剖析一波,来看看到底是哪个地方使线程进入了wait !!!

如下 是dump下来的线程文件,能够看到查找出427个WAITING这也基本和 grafana 监控中状况是WAITTING的线程数量共同

接口耗时2000多秒!我人麻了!

重点来了(这个 WAITING 状况的仓库信息,还都是从 IOSPushStrategy#pushMsgWithIOS 这个办法的某个地方出来的(151行出来的)),所以咱们找到代码来看看,是哪个小鬼在作怪?

接口耗时2000多秒!我人麻了!
而类 PushNotificationFuture 继承了 CompletableFuture,他自己又没有get办法,所以本质上 便是调用的 CompletableFuture的 get 办法。
接口耗时2000多秒!我人麻了!
ps:提一嘴,咱们这里的场景是 等候ios push服务器的成果,不知道啥情况,今天(指产生毛病的那天)ios push服务器(域名: api.push.apple.com )一向没回来,所以就导致一向等候下去了。。

看到这, 我 豁然开朗 && 真相大白 了,原来是在使用 CompletableFutureget时分,没设置超时时刻,这样的话会导致一向在等成果。。。(但代码不是我写的,由于我知道 CompletableFuture 的get不设置参数会一向等下去 ,我仅仅保护,后期也没怎么修正这块的逻辑,哎 ,说多了都是泪呀!)

好一个 CompletableFuture#get();

(真是 死等啊。。。一点不含糊的等候下去,等的天荒地老海枯石烂也要等下去~~~ )

到此,问题的原因找到了。

2、 修正问题

解决办法很简单,给CompletableFuture的get操作 加上超时时刻即可,如下代码即可修正:

接口耗时2000多秒!我人麻了!

在修正后,截止到今天(6月8号)没有这种报警情况了,并且线程数和WAITING线程都比较稳定,都在正常范围内,如下截图(一共4个pod):

接口耗时2000多秒!我人麻了!

至此问题解决了~~~ 总算能够睡个好觉啦!

3、 复盘总结

3.1、 代码浅析

已然此次的元凶巨恶是 CompletableFuture的get办法 那么咱们就浅析一下 :

  1. 首先看下 get(); 办法
    接口耗时2000多秒!我人麻了!
    接口耗时2000多秒!我人麻了!

上边能够看到 不带参数的get办法: if(deadLine==0) 成立 ,也便是终究调用了LockSupport的park(this);办法,而这个办法终究调了unsafe的这个办法-> unsafe.park(false, 0L); 其间第二个参数便是等候多长时刻后,unpark即唤醒被挂起的线程,而0 则代表无限期等候。

  1. 再来看下 get(long timeOut,TimeUnit unit);办法
    接口耗时2000多秒!我人麻了!
    咱们能够看到 带参数的get办法: if(deadLine==0) 不成立,走的else逻辑 也便是终究调用了LockSupportparkNanos(this,nanos);办法,而这个办法终究调了unsafe的这个办法-> unsafe.park(false, nanos); 其间第二个参数便是你调用get时,传入的tiimeOut参数(只不过底层转成纳秒了) 咱们跑了下程序,发现超越指定时刻后,get(long timeOut,TimeUnit unit); 办法抛出 TimeoutException反常,而至于超时后咱们开发者怎么处理,就在于具体情况了。
    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源码,见识过parkunpark操作,咱们截个图回忆一下:

接口耗时2000多秒!我人麻了!

3.2、最后总结:

1.在调用外部接口时。一定要注意设置超时时刻,防止三方服务出问题后影响本身服务。

2.以后不管看到什么类型的Future,都要慎重,由于这玩意说的是异步,但是调用get办法时,他本质上是同步等候,所以必须给他设置个超时时刻,不然他啥时分能回来成果,就得看天意了! 3.但凡和第三方对接的东西,都要做最坏的打算,快速失败的方式很有必要。 4.遇到天大的问题,都尽可能坚持冷静,不要乱了阵脚!