一个load飙高的过程分析,非常有价值。

转自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。

已标记关键词 清除标记
相关推荐
©️2020 CSDN 皮肤主题: 大白 设计师:CSDN官方博客 返回首页