又两个case(偶尔超时、恶性循环)

Case I
有个应用出现集群里有部分服务器访问DB超时比其他机器多很多的现象,而且诡异的是时间基本都是200ms多一点点。

排查时首先想到的是确认下是不是这些机器在处理网卡中断的时候不够给力造成的,但看到的现象是这些服务器的cpu消耗都非常的低,另外也确认了网卡是支持多队列的并且已开启了的。

接着排查是不是网络上的问题,对比了正常的机器和这些超时多的机器在网络上的表现状况,发现超时多的这些机器在tcp重传上会稍高一些,大概在0.2左右,而正常的机器则基本都在0,于是猜想是网络上出问题了。

于是将现象交给网络同事进行排查,在折腾了几次后确认是其中的一个交换机在处理某些包的时候会出现这样的现象,更换交换机后一切回归正常。

这个case值得说说的一点是为什么看到超时的时候访问时间都是200ms多一点点,tcp在重传时会采用避让策略,就是每次重传重试的时间会逐步拉长,重传的具体时间间隔取决于RTO,但因为是内网环境,所以RTO都会很低,在linux上,有一个最小的重传间隔时间,这个时间刚好是200ms,so…具体大家可以参阅此文(有可能要备梯子)。

Case II
有个应用出现了重启后load一直高的现象,页面上访问返回502或504。

排查的时候首先看到的现象是cpu消耗非常严重,按照一贯的惯例,先扫一眼gc log,就看到cms gc非常频繁,大概1分钟1次,young gc大概2秒1次,每次大概需要消耗掉90ms+,按照这种现象,基本上cpu就一直耗在gc上了,因此应用的响应时间非常糟糕。

从观察到的现象来看,是内存占用很严重,于是dump内存,在等待分析的过程中,决定先增大了一点heap size,但仍然无法解决,因为内存消耗的实在是太快了。

dump内存分析的结果是一切正常,这就有点悲催了..

临时扩容了几台机器,然后就突然恢复了…

继续排查,由于内存dump分析的结果一切正常,猜想这些内存的消耗完全就是正常的请求处理的消耗,而仅仅是因为响应时间慢,导致了内存中存活的对象比较多,从而导致gc频繁,于是模拟做了一次压测,但按照差不多的qps去压,发现一切正常。

回想出问题的时候刚好是发布重启,因此猜测可能是刚启动的时间性能不佳,而qps又不低造成的,于是按照这个思路在压测过程中做了一次重启,果然重现了之前的现象…

这是个极度悲催的恶性循环的问题,刚启动的时候Java性能比较糟糕,请求处理慢,内存中存活对象比较多,而这个时候如果请求较多的话,直接就会导致gc频繁,gc频繁后又会导致搞不好大部分时候在做GC,于是响应时间更加糟糕,存活的对象更多,就进入了一个恶性循环,因此还是要控制刚启动的时候进来的请求不要太多(这就意味着对发布有要求了)。

=============================
欢迎关注微信公众号:hellojavacases

关于此微信号:
分享Java问题排查的Case、Java业界的动态和新技术、Java的一些小知识点Test,以及和大家一起讨论一些Java问题或场景,这里只有Java细节的分享,没有大道理、大架构和大框架。

公众号上发布的消息都存放在http://hellojava.info上。

《又两个case(偶尔超时、恶性循环)》有2个想法

  1. 您好:

    最近,我们的一个tomcat下的应用,访问一段时间后,tomcat无法响应页面的请求,但是tomcat是在运行状态的,请问,我该如何排查、定位该问题的原因,tomcat的jvm参数配置如下:

    JAVA_OPTS=”$JAVA_OPTS -server -Xms512M -Xmx512M -verbose:gc -Djava.awt.headless=true -XX:PermSize=256M -XX:MaxPermSize=256M -Xloggc:gc.log -XX:-UseGCOverheadLimit -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+HeapDumpOnOutOfMemoryError”

    当时用jmap看了下tomcat的内存情况,截图如下:

    谢谢。期望得到您的指点。

    另外,当时的gc.log没有留意。

发表评论

电子邮件地址不会被公开。 必填项已用*标注


*