5.CPU占用100%定位方法


0. 背景

经常做后端服务开发的同学,或多或少都遇到过 CPU 负载特别高的问题。尤其是在周末或大半夜,突然群里有人反馈线上机器负载特别高,不熟悉定位流程和思路的同学可能登上服务器一通手忙脚乱,定位过程百转千回。

对此,也有不少同学曾经整理过相关流程或方法论,类似把大象放进冰箱要几步,传统的方案一般是4步:

  1. top oder by with P:1040 // 首先按进程负载排序找到 maxLoad(pid)
  2. top -Hp 进程PID:1073 // 找到相关负载 线程PID
  3. printf “0x%x\n” 线程PID: 0x431 // 将线程PID转换为 16进制,为后面查找 jstack 日志做准备
  4. jstack 进程PID | vim +/十六进制线程PID - // 例如:jstack 1040|vim +/0x431 -

但是对于线上问题定位来说,分秒必争,上面的 4 步还是太繁琐耗时了,有没有可能封装成为一个工具,在有问题的时候一键定位,秒级找到有问题的代码行呢?

当然可以!工具链的成熟与否不仅体现了一个开发者的运维能力,也体现了开发者的效率意识。淘宝的oldratlee 同学就将上面的流程封装为了一个工具:show-busy-java-threads.sh(点击可直接下载,或参考文末链接下载),可以很方便的定位线上的这类问题,下面我会举两个例子来看实际的效果。

快速安装使用:

source <(curl -fsSL https://raw.githubusercontent.com/oldratlee/useful-scripts/master/test-cases/self-installer.sh)

1. 正则表达式导致的100%

  1. java 正则表达式回溯造成 CPU 100%
import java.util.ArrayList;
import java.util.List;
import java.util.regex.Matcher;
import java.util.regex.Pattern;


public class RegexLoad {
    public static void main(String[] args) {
        String[] patternMatch = {"([\\w\\s]+)+([+\\-/*])+([\\w\\s]+)",
                "([\\w\\s]+)+([+\\-/*])+([\\w\\s]+)+([+\\-/*])+([\\w\\s]+)"};
        List<String> patternList = new ArrayList<String>();

        patternList.add("Avg Volume Units product A + Volume Units product A");
        patternList.add("Avg Volume Units /  Volume Units product A");
        patternList.add("Avg retailer On Hand / Volume Units Plan / Store Count");
        patternList.add("Avg Hand Volume Units Plan Store Count");
        patternList.add("1 - Avg merchant Volume Units");
        patternList.add("Total retailer shipment Count");

        for (String s :patternList ){

            for(int i=0;i<patternMatch.length;i++){
                Pattern pattern = Pattern.compile(patternMatch[i]);

                Matcher matcher = pattern.matcher(s);
                System.out.println(s);
                if (matcher.matches()) {

                    System.out.println("Passed");
                }else
                    System.out.println("Failed;");
            }

        }
    }
}

编译、运行上述代码之后,咱们就能观察到服务器多了一个 100% CPU 的 java 进程:

怎么使用呢?

show-busy-java-threads.sh
# 从 所有的 Java进程中找出最消耗CPU的线程(缺省5个),打印出其线程栈。

show-busy-java-threads.sh -c <要显示的线程栈数>

show-busy-java-threads.sh -c <要显示的线程栈数> -p <指定的Java Process>
# -F选项:执行jstack命令时加上-F选项(强制jstack),一般情况不需要使用
show-busy-java-threads.sh -p <指定的Java Process> -F

show-busy-java-threads.sh -s <指定jstack命令的全路径>
# 对于sudo方式的运行,JAVA_HOME环境变量不能传递给root,
# 而root用户往往没有配置JAVA_HOME且不方便配置,
# 显式指定jstack命令的路径就反而显得更方便了

show-busy-java-threads.sh -a <输出记录到的文件>

show-busy-java-threads.sh -t <重复执行的次数> -i <重复执行的间隔秒数>
# 缺省执行一次;执行间隔缺省是3秒

##############################
# 注意:
##############################
# 如果Java进程的用户 与 执行脚本的当前用户 不同,则jstack不了这个Java进程。
# 为了能切换到Java进程的用户,需要加sudo来执行,即可以解决:
sudo show-busy-java-threads.sh

示例:

work@dev_zz_Master 10.48.186.32 23:45:50 ~/demo >
bash show-busy-java-threads.sh
[1] Busy(96.2%) thread(8577/0x2181) stack of java process(8576) under user(work):
"main" prio=10 tid=0x00007f0c64006800 nid=0x2181 runnable [0x00007f0c6a64a000]
   java.lang.Thread.State: RUNNABLE
        at java.util.regex.Pattern$GroupHead.match(Pattern.java:4168)
        at java.util.regex.Pattern$Loop.match(Pattern.java:4295)
        ...
        at java.util.regex.Matcher.match(Matcher.java:1127)
        at java.util.regex.Matcher.matches(Matcher.java:502)
        at RegexLoad.main(RegexLoad.java:27)

[2] Busy(1.5%) thread(8591/0x218f) stack of java process(8576) under user(work):
"C2 CompilerThread1" daemon prio=10 tid=0x00007f0c64095800 nid=0x218f waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

[3] Busy(0.8%) thread(8590/0x218e) stack of java process(8576) under user(work):
"C2 CompilerThread0" daemon prio=10 tid=0x00007f0c64093000 nid=0x218e waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

[4] Busy(0.2%) thread(8593/0x2191) stack of java process(8576) under user(work):
"VM Periodic Task Thread" prio=10 tid=0x00007f0c640a2800 nid=0x2191 waiting on condition 

[5] Busy(0.1%) thread(25159/0x6247) stack of java process(25137) under user(work):
"VM Periodic Task Thread" prio=10 tid=0x00007f13340b4000 nid=0x6247 waiting on condition 
work@dev_zz_Master 10.48.186.32 23:46:04 ~/demo >

可以看到,一键直接定位异常代码行,是不是很方便?

2. 线程死锁,程序 hang 住

import java.util.*;
public class SimpleDeadLock extends Thread {
    public static Object l1 = new Object();
    public static Object l2 = new Object();
    private int index;
    public static void main(String[] a) {
        Thread t1 = new Thread1();
        Thread t2 = new Thread2();
        t1.start();
        t2.start();
    }
    private static class Thread1 extends Thread {
        public void run() {
            synchronized (l1) {
                System.out.println("Thread 1: Holding lock 1...");
                try { Thread.sleep(10); }
                catch (InterruptedException e) {}
                System.out.println("Thread 1: Waiting for lock 2...");
                synchronized (l2) {
                    System.out.println("Thread 2: Holding lock 1 & 2...");
                }
            }
        }
    }
    private static class Thread2 extends Thread {
        public void run() {
            synchronized (l2) {
                System.out.println("Thread 2: Holding lock 2...");
                try { Thread.sleep(10); }
                catch (InterruptedException e) {}
                System.out.println("Thread 2: Waiting for lock 1...");
                synchronized (l1) {
                    System.out.println("Thread 2: Holding lock 2 & 1...");
                }
            }
        }
    }
}

执行之后的效果:

如何用工具定位:

一键定位:可以清晰的看到线程互相锁住了对方等待的资源,导致死锁,直接定位到代码行和具体原因。

通过上面两个例子,我想各位同学应该对这个工具和工具能解决什么问题有了比较深刻的了解了,遇到 CPU 100% 问题可以从此不再慌乱。但是更多的还是依赖大家自己去实践,毕竟实践出真知嘛~

3. 免费实用的脚本工具大礼包

除了正文提到的 show-busy-java-threads.sh,oldratlee 同学还整合和不少常见的开发、运维过程中涉及到的脚本工具,觉得特别有用的我简单列下:

3.1 show-duplicate-java-classes

偶尔会遇到本地开发、测试都正常,上线后却莫名其妙的 class 异常,历经千辛万苦找到的原因竟然是 Jar冲突!这个工具就可以找出Java Lib(Java库,即Jar文件)或Class目录(类目录)中的重复类。

Java开发的一个麻烦的问题是Jar冲突(即多个版本的Jar),或者说重复类。会出NoSuchMethod等的问题,还不见得当时出问题。找出有重复类的Jar,可以防患未然。

# 查找当前目录下所有Jar中的重复类
show-duplicate-java-classes

# 查找多个指定目录下所有Jar中的重复类
show-duplicate-java-classes path/to/lib_dir1 /path/to/lib_dir2

# 查找多个指定Class目录下的重复类。 Class目录 通过 -c 选项指定
show-duplicate-java-classes -c path/to/class_dir1 -c /path/to/class_dir2

# 查找指定Class目录和指定目录下所有Jar中的重复类的Jar
show-duplicate-java-classes path/to/lib_dir1 /path/to/lib_dir2 -c path/to/class_dir1 -c path/to/class_dir2

例如:

# 在war模块目录下执行,生成war文件
$ mvn install
...
# 解压war文件,war文件中包含了应用的依赖的Jar文件
$ unzip target/*.war -d target/war
...
# 检查重复类
$ show-duplicate-java-classes -c target/war/WEB-INF/classes target/war/WEB-INF/lib
...

3.2 find-in-jars

在当前目录下所有jar文件里,查找类或资源文件。

用法:注意,后面Pattern是grep的 扩展正则表达式。

find-in-jars 'log4j\.properties'
find-in-jars 'log4j\.xml$' -d /path/to/find/directory
find-in-jars log4j\\.xml
find-in-jars 'log4j\.properties|log4j\.xml'

示例:

$ ./find-in-jars 'Service.class$'
./WEB-INF/libs/spring-2.5.6.SEC03.jar!org/springframework/stereotype/Service.class
./rpc-benchmark-0.0.1-SNAPSHOT.jar!com/taobao/rpc/benchmark/service/HelloService.class

3.3 housemd pid [java_home]

很早的时候,我们使用BTrace排查问题,在感叹BTrace的强大之余,也曾好几次将线上系统折腾挂掉。2012年淘宝的聚石写了HouseMD,将常用的几个Btrace脚本整合在一起形成一个独立风格的应用,其核心代码用的是Scala,HouseMD是基于字节码技术的诊断工具, 因此除了Java以外, 任何最终以字节码形式运行于JVM之上的语言, HouseMD都支持对它们进行诊断,如Clojure(感谢@Killme2008提供了它的使用入门), scala, Groovy, JRuby, Jython, kotlin等.

使用housemd对java程序进行运行时跟踪,支持的操作有:

3.4 jvm pid

执行jvm debug工具,包含对java栈、堆、线程、gc等状态的查看,支持的功能有:

========线程相关=======
1 : 查看占用cpu最高的线程情况
2 : 打印所有线程
3 : 打印线程数
4 : 按线程状态统计线程数
========GC相关=======
5 : 垃圾收集统计(包含原因)可以指定间隔时间及执行次数,默认1秒, 10次
6 : 显示堆中各代的空间可以指定间隔时间及执行次数,默认1秒,5次
7 : 垃圾收集统计。可以指定间隔时间及执行次数,默认1秒, 10次
8 : 打印perm区内存情况*会使程序暂停响应*
9 : 查看directbuffer情况
========堆对象相关=======
10 : dump heap到文件*会使程序暂停响应*默认保存到`pwd`/dump.bin,可指定其它路径
11 : 触发full gc。*会使程序暂停响应*
12 : 打印jvm heap统计*会使程序暂停响应*
13 : 打印jvm heap中top20的对象。*会使程序暂停响应*参数:1:按实例数量排序,2:按内存占用排序,默认为1
14 : 触发full gc后打印jvm heap中top20的对象。*会使程序暂停响应*参数:1:按实例数量排序,2:按内存占用排序,默认为1
15 : 输出所有类装载器在perm里产生的对象。可以指定间隔时间及执行次数
========其它=======
16 : 打印finalzer队列情况
17 : 显示classloader统计
18 : 显示jit编译统计
19 : 死锁检测
20 : 等待X秒,默认为1
q : exit

进入jvm工具后可以输入序号执行对应命令
可以一次执行多个命令,用分号”;”分隔,如:1;3;4;5;6
每个命令可以带参数,用冒号”:”分隔,同一命令的参数之间用逗号分隔,如:
Enter command queue:1;5:1000,100;10:/data1/output.bin

3.5 greys pid [IP:PORT]

PS:目前Greys仅支持Linux/Unix/Mac上的Java6+,Windows暂时无法支持

Greys是一个JVM进程执行过程中的异常诊断工具,可以在不中断程序执行的情况下轻松完成问题排查工作。和HouseMD一样,Greys-Anatomy取名同名美剧“实习医生格蕾”,目的是向前辈致敬。代码编写的时候参考了BTrace和HouseMD两个前辈的思路。

使用greys对java程序进行运行时跟踪(不传参数,需要先greys -C pid,再greys)。支持的操作有:

  • 查看加载类,方法信息
  • 查看JVM当前基础信息
  • 方法执行监控(调用量,失败率,响应时间等)
  • 方法执行数据观测、记录与回放(参数,返回结果,异常信息等)
  • 方法调用追踪渲染
  • 详细信息请参考: https://github.com/oldmanpushcart/greys-anatomy/wiki

3.6 sjk sjk –commands sjk –help

使用sjk对Java诊断、性能排查、优化工具

  • ttop:监控指定jvm进程的各个线程的cpu使用情况
  • jps: 强化版
  • hh: jmap -histo强化版
  • gc: 实时报告垃圾回收信息
  • 更多信息请参考: https://github.com/aragozin/jvm-tools

Refer:

[1] oldratlee/useful-scripts

https://github.com/oldratlee/useful-scripts

[2] awesome-scripts

https://github.com/superhj1987/awesome-scripts

[3] JDK自带工具之问题排查场景示例

http://bit.ly/2xtukcb

[4] Java调优经验谈

http://bit.ly/2xCIj2L

[5] jvm排查工具箱jvm-tools

https://segmentfault.com/a/1190000012658814

[6] alibaba/arthas

https://github.com/alibaba/arthas/blob/7f236219ddbd040764dd821cbcbd44899dd57c90/README.md

原文链接: https://my.oschina.net/leejun2005/blog/1524687


文章作者: Soulballad
版权声明: 本博客所有文章除特別声明外,均采用 CC BY 4.0 许可协议。转载请注明来源 Soulballad !
评论
 上一篇
6.阿里员工排查Java问题常用工具 6.阿里员工排查Java问题常用工具
我的问题排查工具箱前言平时的工作中经常碰到很多疑难问题的处理,在解决问题的同时,有一些工具起到了相当大的作用,在此书写下来,一是作为笔记,可以让自己后续忘记了可快速翻阅,二是分享,希望看到此文的同学们可以拿出自己日常觉得帮助很大的工具,大家
下一篇 
4.磁盘IO高分析方法 4.磁盘IO高分析方法
磁盘IO高分析方法工具准备:iotop: http://guichaz.free.fr/iotop/pt-ioprofile:http://www.percona.com/downloads/percona-toolkit/2.2.1/ i
  目录