转自http://blog.csdn.net/axman/article/details/7104819
ae的多语言应用中不断出现load飙高的情况 ,即使重启过10几个小时以后,cpu慢慢从1核到4核到被吃光。
而且集群中8台机器都是如此,所以应用方自己开始开分析原因。
前两天跟踪没结果,后来有一位同学根据tb达人的分析中得到启发:
关于us高和ys高的问题分析:
当us值过高时,表示运行的应用消耗大量的CPU。java应用造成us高的原因主要是线程一直处于可运行(Runnable)状态,通常这些线程在执行无阻塞、循环、正则或纯粹的计算等任务造成的;另外一个可能也会造成us高的原因是频繁GC。
当sy值高时,表示linux花费了更多的时间在进行java线程切换。java应用造成这种现象的主要原因是启动的线程比较多,且这些线程多数处于不断的阻塞(例如锁等待,IO等待状态)和执行状态的变化过程中,这就导致了操作系统要不断地切换执行的线程,产生大量的线程上下文切换。
以下代码用于验证上面的经验:
public static void main(String[] args) {
for (int i = 0; i < 500; i++) {
new Thread().start();
}
}
static class ComsumeCPURunnable implements Runnable {
public void run() {
long start = System.currentTimeMillis();
long end = start;
while (end - start < 10000) {
end = System.currentTimeMillis();
}
}
}
运行结果为:
模拟sy占用很高的代码:
public static void main(String[] args) {
for (int i = 0; i < 500; i++) {
Object lock = new Object();
new Thread(new RunnableA(lock)).start();
new Thread(new RunnableB(lock)).start();
}
}
static class RunnableA implements Runnable {
private Object lock = null;
public RunnableA(Object lock){
this.lock = lock;
}
public void run() {
while (true) {
try {
synchronized (lock) {
lock.wait(50);
}
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
}
static class RunnableB implements Runnable {
private Object lock = null;
public RunnableB(Object lock){
this.lock = lock;
}
public void run() {
while (true) {
synchronized (lock) {
lock.notify();
}
try {
Thread.sleep(20);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
}
运行结果:
线上实际的情况是us很高;那原因就不在于线程等待或者阻塞导致的.
通过ps Lf [pid]命令可以看到所有java线程情况,cpu占用率、线程时间。可以看到占用cpu比较高的就几个线程:
UID PID PPID LWP C NLWP STIME TTY STAT TIME
admin 10702 10692 11817 26 415 19:03 ? Rl 65:19
admin 10702 10692 11807 16 415 19:03 ? Rl 39:56
admin 10702 10692 11805 26 415 19:03 ? Rl 65:32
admin 10702 10692 11801 26 415 19:03 ? Rl 66:09
LWP(java线程id),NLWP(java线程总数)
再通过jstack –l [pid]命令 dump java线程栈的情况,将以上线程id转换成16进制,后在dump出来的jstack文件中搜索,发现所有线程都属于xss过滤线程:
"TP-Processor59" daemon prio=10 tid=0x00002aab4b11b800 nid=0x450 runnable [0x0000000049fa7000]
java.lang.Thread.State: RUNNABLE
at xxxxxxxxxxxxxxxx....................最后的问题定位于at xxxxxxxxxxxxxxxxx这里的二方库调用,问题被提交到我们这里时,我知道之前这个二方库存在一个死循环的bug并已经在新版本中解决,
直接通知应用方升级新版本的二方库测试一切正常,问题解决。(为了优化把把读字符的返回值优化为为为char,但循环时用了-1,char不可能为-1)
解决这样的问题,要求我们对 jps, jstack, jstat, top -p, jinfo, jmap等Java自身携带的工具,以及系统命(ps,pstree,pstack等),Jvisualvm及所有的插件非常熟悉,
这些工具基本98%的以上问题能分析出来。
对于jstack做的ThreadDump的栈,可以反映如下信息。
如果某个相同的call stack经常出现, 我们有80%的以上的理由确定这个代码存在性能问题(读网络的部分除外);
如果相同的call stack出现在同一个线程上(tid)上, 我们很很大理由相信, 这段代码可能存在较多的循环或者死循环;
如果某call stack经常出现, 并且里面带有lock,请检查一下这个lock的产生的原因, 可能是全局lock造成了性能问题;
在一个不大压力的群集里(w<2), 我们是很少拿到带有业务代码的stack的, 并且一般在一个完整stack中, 最多只有1-2业务代码的stack,
如果经常出现, 一定要检查代码, 是否出现性能问题。
如果你怀疑有dead lock问题, 那么请把所有的lock id找出来,看看是不是出现重复的lock id。