记一次tomcat进程cpu占用过高的问题排查记录

来自:网络
时间:2020-11-05
阅读:

本文主要记录一次tomcat进程,因TCP连接过多导致CPU占用过高的问题排查记录。

问题描述

linux系统下,一个tomcat web服务的cpu占用率非常高,top显示结果超过200%。请求无法响应。反复重启依然同一个现象。

问题排查

1、获取进程信息

通过jdk提供的jps命令可以快速查出jvm进程,

jps pid

2、查看jstack信息

jstack pid

发现存在大量log4j线程block,处于waiting lock状态

org.apache.log4j.Category.callAppenders(org.apache.log4j.spi.LoggingEvent) @bci=12, line=201 (Compiled frame)

搜索相关信息,发现log4j 1.x版本存在死锁问题。

发现问题,于是调整log4j配置,仅打开error级别日志,重启tomcat。此时stack中block线程消失,但进程cpu占用率依然高涨。

3、进一步排查

分析每个线程的cpu占用量,此处需要引入一个大神贡献的脚本,计算java进程中,每个线程的cpu使用量。

#!/bin/bash

typeset top=${1:-10}
typeset pid=${2:-$(pgrep -u $USER java)}
typeset tmp_file=/tmp/java_${pid}_$$.trace

$JAVA_HOME/bin/jstack $pid > $tmp_file
ps H -eo user,pid,ppid,tid,time,%cpu --sort=%cpu --no-headers\

    | tail -$top\

    | awk -v "pid=$pid" '$2==pid{print $4"\t"$6}'\

    | while read line;
do
    typeset nid=$(echo "$line"|awk '{printf("0x%x",$1)}')
    typeset cpu=$(echo "$line"|awk '{print $2}')
    awk -v "cpu=$cpu" '/nid='"$nid"'/,/^$/{print $0"\t"(isF++?"":"cpu="cpu"%");}' $tmp_file
done

rm -f $tmp_file

脚本适用范围

因为ps中的%CPU数据统计来自于/proc/stat,这个份数据并非实时的,而是取决于OS对其更新的频率,一般为1S。所以你看到的数据统计会和jstack出来的信息不一致也就是这个原因~但这份信息对持续LOAD由少数几个线程导致的问题排查还是非常给力的,因为这些固定少数几个线程会持续消耗CPU的资源,即使存在时间差,反正也都是这几个线程所导致。

除了这个脚本,简单点儿的方法则是,查出进程id后,通过如下命令查看该进程中每个线程的资源使用情况

top -H -p pid

从这里获取pid(线程id),转换为16进制,然后去stack信息中查找对象的线程信息。

通过上述方法,查出tomcat进程对应的线程cpu占用率累积之和约80%,远小于top给出的200%+

说明并不存在长期占用cpu的线程,应该是属于有许多短暂性的cpu密集计算。进而怀疑是不是jvm内存不足,频繁gc导致。

jstat -gc pid

发现jvm内存使用并未出现异常,gc次数明显暴涨

查完内存,由于本身是一个网络程序,进一步排查网络连接。

4、问题定位

查询tomcat对应端口的tcp链接,发现存在大量EASTABLISH的链接,还有部分其它状态的连接,总计400+。

netstat -anp | grep port

进一步查看这些连接的来源,发现是该tomcat服务的应用端,存在大量后台线程,在频繁轮询该服务,导致该服务tomcat 连接数被打满,无法继续接收请求。

netstat状态说明:

LISTEN:侦听来自远方的TCP端口的连接请求 SYN-SENT:再发送连接请求后等待匹配的连接请求(如果有大量这样的状态包,检查是否中招了) SYN-RECEIVED:再收到和发送一个连接请求后等待对方对连接请求的确认(如有大量此状态,估计被flood***了) ESTABLISHED:代表一个打开的连接 FIN-WAIT-1:等待远程TCP连接中断请求,或先前的连接中断请求的确认 FIN-WAIT-2:从远程TCP等待连接中断请求 CLOSE-WAIT:等待从本地用户发来的连接中断请求 CLOSING:等待远程TCP对连接中断的确认 LAST-ACK:等待原来的发向远程TCP的连接中断请求的确认(不是什么好东西,此项出现,检查是否被***) TIME-WAIT:等待足够的时间以确保远程TCP接收到连接中断请求的确认 CLOSED:没有任何连接状态

5、根源分析

直接触发原因是客户端轮询,请求异常,继续轮序;客户端不断有新的后台线程加入轮询队伍,最终导致服务端tomcat连接被打满。

返回顶部
顶部