美文网首页
一次tomcat启动特别慢的排查

一次tomcat启动特别慢的排查

作者: 站在海边看远方 | 来源:发表于2020-09-10 18:39 被阅读0次

    事件的起因是有一次tomcat启动,花了32分钟才启动好,非常的诡异。
    tomcat启动会打印一个日志:catalina.yyyy-MM-dd.log,即会生成一个带日期的日志文件,然后查看启动耗时,花了1790967ms,折合分钟是29.84945min。

    image.png

    这个时间肯定是不正常的,我本地调试环境一般启动耗时是1分钟左右,虽然部署到Linux上一个tomcat启动了多个应用,不过也不应该这么慢。

    后来我把linux上的tomcat下载到本地,除了硬件不一样,其他都一样,然后启动耗时7分钟。

    这么看,问题是出在了linux服务器上,其他的组件都是一样的,排除其他组件的问题。

    然后重启linux上的进程,在本地使用jmx连接,查看启动耗时,如下图


    image.png

    看右上角的CPU总时间,localhost-startStop-1花了16min,点开线程看,耗时如下:


    image.png

    基本上是Spring Bean的加载耗时,这个也看不出啥,不过排查启动问题的时候可以查看jmx看一下。

    然后回到服务器本身,使用top命令查看cpu负载:


    这台机器是16核的,可是查看load average,基本上稳定在40,平均每核2.5左右,根据经验,平均每核的负载最好不要超过1,现在负载已经很高了。

    然后用户占用CPU,基本稳定在96%,再看下面CPU利用率,即%CPU这一栏,并不高,所以现在问题就有点诡异。

    这台机器是一个docker容器,容器数据不对,可能是宿主机出问题了,查看宿主机的CPU负载,使用top命令查看:


    image.png

    可以看到宿主机的负载也是40,下面有1个进程CPU占用1100%,基本占了11个核,问题就出在这里了。
    容器是用的宿主机的硬件资源,所以查到的信息和宿主机的保持一致。

    问题到这里也就清楚了,是宿主机CPU被占满,导致tomcat启动的时候分配不到CPU,启动能耗时半小时。

    再来回顾一下排查过程,首先是tomcat启动耗时30分钟这个现象。

    先是使用jmx观察tomcat启动耗时,只看出来时间花在哪了,但是并没有看出问题在哪。

    排查启动线程耗时无果,于是在本地模拟和linux上一样的环境,观察启动耗时,在本地环境启动只花了7分钟。问题可以确认出在服务器上。

    随后使用top命令观察CPU,一开始对top命令不熟悉,所以走了好多弯路,top的各项指标还是值得好好学习一下。

    首先是load average,这3个值分别表示1分钟、5分钟、15分钟内系统的平均负荷,这个值单核最好不要超过1,超过1算负载很高了,需要进行排查。

    然后是us,us是用户进程执行时间百分比,这个值如果长期超过50%,需要对程序进行优化。

    sy是内核系统进程执行时间百分比,这个值也不宜过高。

    %CPU是当前程序执行占用CPU。

    其实如果对top命令的参数熟悉的话,可以很快的看出来CPU的负载长期处于飙高的状态,不仅load average高,us也高,然后就可以快速定位到问题了。

    另外涉及到docker的话,如果出现负载高,但是%CPU列值不高的情况,可以去查看一下宿主机的状态。本次就是宿主机有1个进程把CPU资源占的差不多了。

    相关文章

      网友评论

          本文标题:一次tomcat启动特别慢的排查

          本文链接:https://www.haomeiwen.com/subject/wsvpektx.html