记录一次loadavg报警及其排查

问题描述:

上线项目之后一直会有loadavg报警

• 服务器上线一段时间后运行没问题,在某一个时间段(通常是上线2小时以后),loadreport会突然顶到很高(100以上)然后逐渐降低.
• 多出了2000多个Timer线程(这个看服务具体情况,多出的线程不一定多少)

如图:

 

 

排查过程:

经过最后逐一排查(查了足足十天),发现是在一个jar包里修改了一个关于数据库的连接池的配置导致的这个问题.

1. 使用ps查到java进程id;__具体命令:ps -ef | grep java
2. 之后使用ps查看占用cpu较高的线程;__具体命令:ps p $TARGET_PID -L -o pcpu,pid,tid,time,tname,stat,psr | sort -n -k1 -r 
3. 然后使用jstack PID去抓进程中的线程情况;__具体命令:jstack PID
4. 之后根据@2步出来的cpu占用情况查到线程id为:751511
5. 之后进行进制转换,把751511转换为16进制:b7797
6. 在相对应的jstack输出结果中查找b7797,查找到对应进程的调用栈.

找到调用栈之后就比较好具体定位是什么原因了:

可以发现

是dbcp连接池的问题,启动了一个timer一直在执行什么任务.队列过长而导致的loadavg过高

最终定位到代码:

由于修改了dbcp的配置属性

在82行配置了最少空闲为5

所以会有一个timer来一直扫描所有的连接,检查其是否空闲.

由于是一个db使用非常重的工程,可能同时存在连接上百个库的情况.所以会有大量连接排队等待扫描回收.

这样造成了loadavg过高.

 

总结:

以后可以快速使用ps和jstack工具来定位到具体的线程和调用栈.来方便查找问题.