During the running of a Java application, sometimes the CPU utilization of the Java virtual machine (JVM) process running the Java application is high. If this occurs, the performance of the Java application usually deteriorates. You can use some tools or commands to perform analysis and diagnosis to find the causes for the high CPU utilization of the JVM process and rectify the problem.

1. Use the built-in commands of EDAS Agent for diagnosis

Enterprise Distributed Application Service (EDAS) displays threads that consume CPU resources in JVM processes and their stack trace information for Elastic Compute Service (ECS) instances in an imported ECS cluster. This allows users to quickly discover the causes for the high CPU utilization of JVM processes.

To view the threads (top 5 threads by default) with high CPU utilization in a JVM process, use the root account to log on to the ECS instance where the JVM process with high CPU utilization is located through SSH. Then, switch to the admin account and run the edas busy-threads command. The script is as follows:

[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):       

The following describes the usage of the script:

[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.

  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

  -p, --pid <java pid>      find out the highest cpu consumed threads from the specified 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

The following shows common parameters and options. Note that the admin account must be used to run the following commands.

# Run the command once every two seconds for five times. By default, the top 5 threads with the highest CPU utilization in the application process are displayed each time.
edas busy-threads 2 5 

# Display the top 5 threads with the highest CPU utilization in the specified Java process.
edas busy-threads -p <jvm_pid>

# Display the top 10 threads with the highest CPU utilization in a Java process.
edas busy-threads -c 10 

# Calculate the threads with high CPU utilization within the most recent two seconds.
edas busy-threads --current        

2. Use open-source tools for diagnosis

In a non-ECS cluster, you can use the following open-source script to discover the threads with the highest CPU utilization in a specified process.

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            

For the specific usage of the script, see show-busy-java-threads.

In addition to the preceding script, you can use the integrated Java problem diagnosis tool Arthas provided by Alibaba. This tool can also display the threads with the highest CPU utilization in a specified JVM process.

# Display the top 3 threads with the highest CPU utilization and their stack trace information in the currently connected JVM process.
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)          

For more parameters and their descriptions, see the thread command.

3. Use the conventional diagnosis method

If your host is not connected to the Internet, you can use the following conventional method to obtain the information about the threads with high CPU utilization:

# When the CPU utilization of a JVM process is high, run the following command once every three to five seconds, three to five times.
admin$ top -Hbp <jvm_pid> -d 1 -n 1 >> top.<jvm_pid>.txt && jstack <jvm_pid> >> jstack.*jvm_pid*.txt           

For example, the specific command is as follows:

admin$ top -Hbp 22801 -d 1 -n 1 >> top.22801.txt && jstack 22801 >> jstack.22801.txt            
  1. In the collected top.xxxxx.txt, find the IDs of threads with the highest CPU utilization. Ensure that the thread IDs correspond to the thread stack information in the jstack.xxxxx.txt file.
  2. Convert these thread IDs from decimal to hexadecimal. For example, you can convert an ID to printf %x 1234.
  3. Search jstack.xxxxx.txt for the corresponding thread information by using the hexadecimal thread IDs. Details are not described here.