How to collect threaddump using jcmd and analyse it ?

[#1]

[Related Article On Ambari Server Tuning : https://community.hortonworks.com/articles/131670/ambari-server-performance-tuning-troubleshooting-c... ]

-The jcmd utility comes with the JDK and is present inside the "$JAVA_HOME/bin". It is used to send diagnostic command requests to the JVM, where these requests are useful for controlling Java Flight Recordings, troubleshoot, and diagnose JVM and Java Applications.

Following are the conditions for using this utility.

- 1. It must be used on the same machine where the JVM is running

- 2. Only a user who own the JVM process can connect to is using this utility.

This utility can help us in getting many details about the JVM process. Some of the most useful information's are as following: Syntax:

jcmd  $PID   $ARGUMENT

Example1: Classes taking the most memory are listed at the top, and classes are listed in a descending order.

/usr/jdk64/jdk1.8.0_60/bin/jcmd  $PID  GC.class_histogram  > /tmp/22421_ClassHistogram.txt

Example2: Generate Heap Dump

/usr/jdk64/jdk1.8.0_60/bin/jcmd  $PID  GC.heap_dump  /tmp/test123.hprof

Example3: Explicitly request JVM to trigger a Garbage Collection Cycle.

/usr/jdk64/jdk1.8.0_60/bin/jcmd  $PID  GC.run

Example4: Generate Thread dump.

usr/jdk64/jdk1.8.0_60/bin/jcmd  $PID  Thread.print

Example5: List JVM properties.

/usr/jdk64/jdk1.8.0_60/bin/jcmd  $PID  VM.system_properties

Example6: The Command line options along with the CLASSPATH setting.

/usr/jdk64/jdk1.8.0_60/bin/jcmd  $ PID  VM.command_line

**NOTE:** To use few specific features offered by "jcmd" tool the "-XX:+UnlockDiagnosticVMOptions" JVM option need to be enabled.

.

When to Collect Thread Dumps?

---------------------------------------------------------

Here now we will see a very common scenario when we find that the JVM process is talking a lots of time in processing the request. Many times we see that the JVM process is stuck/slow or completely Hung. In such scenario in order to investigate the root cause of the slowness we need to collect the thread dumps of the JVM process which will tell us about the various activities those threads are actually performing. Sometimes some threads are involved in some very high CPU intensive operations which also might cause a slowness in getting the response. So We should collect the thread dump as well as the CPU data using "top" command. Few things to consider while collecting the thread dumps:

- 1. Collect the thread dump when we see the issue (slowness, stuck/ hung scenario ...etc). .

- 2. Mostly a single thread dump is not very useful. So whenever we collect the thread dump then we should collect at least 5-6 thread dumps. In some interval like collect 5-6 thread dumps in 10 seconds interval. Like that we will get around 5-6 thread dumps in 1 minute.

- 3. If we are also investigating that few threads might be consuming high CPU cycles then in order to find the APIs that are actually consuming the high CPU we must collect the Thread dump as well as the "top" command output data almost at the same time.

.

- In order to make this easy we can use a simple script "threaddump_cpu_with_cmd.sh" and use it for out troubleshooting & JVM data collection. The following script can be downloaded from:

https://github.com/jaysensharma/MiddlewareMagicDemos/tree/master/HDP_Ambari/JVM

#!/bin/sh
# Takes the JavaApp PID as an argument.
# Make sure you set JAVA_HOME
# Create thread dumps a specified number of times (i.e. LOOP) and INTERVAL.
# Thread dumps will be collected in the file "jcmd_threaddump.out", in the same directory from where this script is been executed.
#   Usage:
#          sudo  -  $user_Who_Owns_The_JavaProcess
#          ./threaddump_cpu_with_cmd.sh <JAVA_APP_PID>
#
#
#   Example:
#   NameNode PID is "5752" and it is started by user "hdfs" then run this utility as following:
#
#   su -l hdfs  -c "/tmp/threaddump_cpu_with_cmd.sh  5752"
################################################################################################


# Number of times to collect data. Means total number of thread dumps.
LOOP=10

# Interval in seconds between data points.
INTERVAL=10

# Where to generate the threddump & top output files.
WHERE_TO_GENERATE_OUTPUT_FILES="/tmp"

# Setting the Java Home, by giving the path where your JDK is kept
# USERS MUST SET THE JAVA_HOME before running this scripta s following:
JAVA_HOME=/usr/jdk64/jdk1.8.0_60

echo "Writing CPU data log files to Directory:  $WHERE_TO_GENERATE_OUTPUT_FILES"

for ((i=1; i <= $LOOP; i++))
  do
    #$JAVA_HOME/bin/jstack -l $1 >> jstack_threaddump.out
    $JAVA_HOME/bin/jcmd  $1  Thread.print >> $WHERE_TO_GENERATE_OUTPUT_FILES/jcmd_threaddump.out
    _now=$(date)
    echo "${_now}" >> $WHERE_TO_GENERATE_OUTPUT_FILES/top_highcpu.out
    top -b -n 1 -H -p $1 >> $WHERE_TO_GENERATE_OUTPUT_FILES/top_highcpu.out
    echo "Collected 'top' output and Thread Dump #" $i
    if [ $i -lt $LOOP ]; then
        echo "Sleeping for $INTERVAL seconds."
        sleep $INTERVAL
    fi
done

- Get the file "jcmd_threaddump.out" and "top_highcpu.out" for analysis.

.

How to analyze the Thread dump Data?

---------------------------------------------------------

You may have a look at one of my old blog article which explains

"High CPU Utilization Finding Cause?" http://middlewaremagic.com/weblogic/?p=4884

.

.

Common Errors with "jcmd" utility.

---------------------------------------------------------

While running the JCMD we might see the below mentioned error. Here the "5752" is the NameNode PID.

[root@c6401 keys]# /usr/jdk64/jdk1.8.0_60/bin/jcmd 5752 help
5752:
com.sun.tools.attach.AttachNotSupportedException: Unable to open socket file: target process not responding or HotSpot VM not loaded
    at sun.tools.attach.LinuxVirtualMachine.<init>(LinuxVirtualMachine.java:106)
    at sun.tools.attach.LinuxAttachProvider.attachVirtualMachine(LinuxAttachProvider.java:63)
    at com.sun.tools.attach.VirtualMachine.attach(VirtualMachine.java:208)
    at sun.tools.jcmd.JCmd.executeCommandForPid(JCmd.java:147)
    at sun.tools.jcmd.JCmd.main(JCmd.java:131)

This error occurred because, JCMD utility allows to connect only to the JVM process that we own the process. In this case we see that the "NameNode" process is being owned by the "hdfs" user where as in the above command we are trying to connect to the NameNode process Via "jcmd" utility as "root" user. The root user here does not own the process, Hence we see the error.

-

"hdfs" user owned process

# su -l hdfs -c "/usr/jdk64/jdk1.8.0_60/bin/jcmd -l"
5752 org.apache.hadoop.hdfs.server.namenode.NameNode
5546 org.apache.hadoop.hdfs.tools.DFSZKFailoverController
5340 org.apache.hadoop.hdfs.server.datanode.DataNode
4991 org.apache.hadoop.hdfs.qjournal.server.JournalNode

.

- "root" user owned process

[root@c6401 keys]# /usr/jdk64/jdk1.8.0_60/bin/jcmd -l
1893 com.hortonworks.support.tools.server.SupportToolServer
6470 com.hortonworks.smartsense.activity.ActivityAnalyzerFacade
16774 org.apache.ambari.server.controller.AmbariServer
29100 sun.tools.jcmd.JCmd -l
6687 org.apache.zeppelin.server.ZeppelinServer

More information about this utility can be found at: https://docs.oracle.com/javase/8/docs/technotes/guides/troubleshoot/tooldescr006.html

.

.