Java 应用程序运行中,有时会遇到 Java 应用( JVM )进程 CPU 使用率高的情况。在这种情况下,Java 应用的性能通常会下降,我们可以借助一些工具或命令进行分析诊断,找到并优化造成 Java 应用( JVM )进程 CPU 使用率高的原因。

1. 使用 edas-agent 自带的命令诊断

EDAS 为导入 ECS 集群中的 ECS 提供了一个可以直接显示出应用进程中使用 CPU 的线程及其 StackTrace,可以帮助用户快速找到造成应用进程 CPU 使用率高的问题原因。

使用 root 账号通过 SSH 登录到 CPU 高的应用进程所在的 ECS,然后切换到 admin 账号,执行 edas busy-threads 即可查看到应用进程中消耗 CPU 高的线程(默认前 5 个):

[root@iZbp19o2g75lcdht92iaaeZ ~]# su - admin
[admin@iZbp19o2g75lcdht92iaaeZ ~]$ edas busy-threads
09/28/19 22:57:07 [INFO]  EXECUTING: busy-threads
[1] Busy(4.6%) thread(3222/0xc96) stack of java process(3221) under user(admin):
"main" #1 prio=5 os_prio=0 tid=0x00002ab68004e800 nid=0xc96 runnable [0x00002ab67c1df000]
   java.lang.Thread.State: RUNNABLE
    at java.net.PlainSocketImpl.socketAccept(Native Method)
    at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
    at java.net.ServerSocket.implAccept(ServerSocket.java:545)
    at java.net.ServerSocket.accept(ServerSocket.java:513)
    at org.apache.catalina.core.StandardServer.await(StandardServer.java:490)
    at org.apache.catalina.startup.Catalina.await(Catalina.java:819)
    at org.apache.catalina.startup.Catalina.start(Catalina.java:765)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:309)
    at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:443)

[2] Busy(0.9%) thread(2725/0xaa5) stack of java process(2721) under user(admin):
"DestroyJavaVM" #13 prio=5 os_prio=0 tid=0x00002ba81004c000 nid=0xaa5 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

[3] Busy(0.0%) thread(3221/0xc95) stack of java process(3221) under user(admin):
[4] Busy(0.0%) thread(2721/0xaa1) stack of java process(2721) under user(admin):       

该脚本的使用帮助如下:

[admin@iZbp19o2g75lcdht92iaaeZ component]$ edas busy-threads -h
Usage: busy-threads.sh [OPTION]... [delay [count]]
Find out the highest cpu consumed threads of java, and print the stack of these threads.

Example:
  busy-threads.sh       # show busy java threads info
  busy-threads.sh 1     # update every 1 seconds, (stop by eg: CTRL+C)
  busy-threads.sh 3 10  # update every 3 seconds, update 10 times

Options:
  -p, --pid <java pid>      find out the highest cpu consumed threads from the specifed java process,
                            default from all java process.
  -c, --count <num>         set the thread count to show, default is 5
  -a, --append-file <file>  specify the file to append output as log
  -s, --jstack-path <path>  specify the path of jstack command
  -F, --force               set jstack to force a thread dump
                            use when jstack <pid> does not respond (process is hung)
  -m, --mix-native-frames   set jstack to print both java and native frames (mixed mode)
  -l, --lock-info           set jstack with long listing. Prints additional information about locks
  --cpu_period              period of time for collecting cpu stats, in secs, default 2 (this option is valid only when --current option is set)
  --current                 use current cpu stats rather than that since start
  -h, --help                display this help and exit

常用的几个参数及选项(注意使用的是 admin 账号执行):

#每隔 2 秒执行一次,共执行 5 次(每次默认显示应用进程中前 5 个使用 CPU 高的线程)
edas busy-threads 2 5 

#显示指定 Java 进程的前 5 个使用 CPU 高的线程:
edas busy-threads -p <jvm_pid>

#显示 Java 进程中前 10 个使用 CPU 高的线程:
edas busy-threads -c 10 

#计算最近的 2 秒种内 CPU 使用较高的线程:
edas busy-threads --current        

2. 使用开源工具诊断

在非 ECS 集群的环境,可以直接使用下面这个开源的脚本来找到占用指定进程中排名前几位 CPU 高的线程:

admin$ wget --no-check-certificate https://raw.github.com/oldratlee/useful-scripts/release/show-busy-java-threads
admin$ chmod +x show-busy-java-threads
admin$ ./show-busy-java-threads            

具体使用方法,请参见 show-busy-java-threads

除了这个脚本以外,还可以使用阿里巴巴的 Java 问题综合诊断工具 Arthas。该工具也可以用来显示指定 JVM 进程中使用 CPU 的排名前几位的线程。

#显示当前连接的 JVM 进程中 CPU 占用排名前 3 名的线程及 StraceTrace 信息:
admin$ thread -n 3
"as-command-execute-daemon" Id=29 cpuUsage=75% RUNNABLE
    at sun.management.ThreadImpl.dumpThreads0(Native Method)
    at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:440)
    at com.taobao.arthas.core.command.monitor200.ThreadCommand$1.action(ThreadCommand.java:58)
    at com.taobao.arthas.core.command.handler.AbstractCommandHandler.execute(AbstractCommandHandler.java:238)
    at com.taobao.arthas.core.command.handler.DefaultCommandHandler.handleCommand(DefaultCommandHandler.java:67)
    at com.taobao.arthas.core.server.ArthasServer$4.run(ArthasServer.java:276)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

    Number of locked synchronizers = 1
    - java.util.concurrent.ThreadPoolExecutor$Worker@6cd0b6f8

"as-session-expire-daemon" Id=25 cpuUsage=24% TIMED_WAITING
    at java.lang.Thread.sleep(Native Method)
    at com.taobao.arthas.core.server.DefaultSessionManager$2.run(DefaultSessionManager.java:85)

"Reference Handler" Id=2 cpuUsage=0% WAITING on java.lang.ref.Reference$Lock@69ba0f27
    at java.lang.Object.wait(Native Method)
    -  waiting on java.lang.ref.Reference$Lock@69ba0f27
    at java.lang.Object.wait(Object.java:503)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)          

更多参数及解释,详见 thread 命令。

3. 使用传统方式诊断

在没有互联网连接的主机还可以使用下面原始的方式来获取 CPU 占用较高的线程:

#在执行 JVM 进程 CPU 高时,每隔 3-5 秒执行一次,执行 3-5 次。
admin$ top -Hbp <jvm_pid> -d 1 -n 1 >> top.<jvm_pid>.txt && jstack <jvm_pid> >> jstack.*jvm_pid*.txt           

例如:

admin$ top -Hbp 22801 -d 1 -n 1 >> top.22801.txt && jstack 22801 >> jstack.22801.txt            
  1. 从收集到的 top.xxxxx.txt 中找到 CPU 占用率最高的线程 ID(注意跟 jstack.xxxxx.txt 文件中的线程堆栈信息一一对应)。
  2. 将这些线程 ID (十进制的数字)转换成十六进制(可以用 printf %x 1234)。
  3. 用这些转换后的十六进制的线程 ID 去 jstack.xxxxx.txt 文件中搜索,即可找到对应线程的信息(这方面资料较多,这里不再赘述)。