Dear Reader,
In a production environment Java Profiling is not an option, we have seen multiple times that
our CPU has reached almost 100% or even 300% sometime. That is really a panic scenario especially
when you are handling production environment or at client place to check what went wrong.
Fortunately, Java comes with some great debugging tools, co-operating those tools with Linux
built-in tools will help you to know what is happening.
I am going to explain below items here:
1) An introduction about Java threads and its relation to Linux LWP (Light Weight Process).
2) Step-by-step process to take thread dump and analyze CPU utilization.
3) “jmap” – Memory Map (dump), Command to get this.
4) “jmap” – Histo, Command to get this.
5) Command to see list of open files in Unix.
1) Introduction: Any java program starts when the JVM calls the main method, this creates a thread
called the main thread and any thread you create using java code will be derived from the main
thread. The same exact behavior occurs on the Linux level, the main thread for java means a Process
for the OS and every thread you create using java the OS will create a Light-weight-process
or LWP. In short: Java main thread = Linux process and Java supporting threads = Linux LWP.
The idea here:
Ask Linux which LWP is eating the CPU.
Ask Java for a Thread Dump.
Map this LWP to a Java thread.
Get the part of code causing the issue.
2) Step-by-step process:
Get the PID: the very first step is to know what is the Java process ID, we will use Linux commands
as below. Use either of the below commands (we use our grep “DAPPNAME”, you can use anything):
jps -v | cut -c -106 | grep DAPPNAME
jps -mvl | cut -c -106 | grep DAPPNAME
ps -eaf | cut -c -106 | grep DAPPNAME
ps -ef | cut -c -106 | grep DAPPNAME
ps -eaf | grep java
Below are the sample output when you execute the command:
dmodi@MyDirectory:~$ jps -mlv | cut -c -106 | grep DAPPNAME
8243 org.quickserver.net.server.QuickServer -load config/DmodiServer.xml -DAPPNAME=CLIENT
13712 org.quickserver.net.server.QuickServer -load ./conf/DmodiDNXServer.xml -DAPPNAME=SERVER
12229 org.quickserver.net.server.QuickServer -load ./config/DmodiPOSServer.xml -DAPPNAME=SERVER2
Explanation: “jps” – Java Virtual Machine Process Status Tool, a command in Unix. “106” shows 106
characters we want to display in console.
The next step is to get the CPU usage per each LWP related to the main process, we can use below commands:
ps -eLo pid,lwp,nlwp,ruser,pcpu,stime,etime,args | grep PROCESS_ID | cut -c -106 > threadsList.txt
The newly created file threadsList.txt will contain below things in similar way (The headers will not be
shown as below):
PID LWP NLWP RUSER %CPU STIME ELAPSED COMMAND
8243 8243 3 dmodi 0.0 May13 1-19:20:18 java -Dprogram.name=run.sh -Xms64m -Xmx100m -Dsun.rmi.dgc
8243 8244 3 dmodi 0.0 May13 1-19:20:18 java -Dprogram.name=run.sh -Xms64m -Xmx100m -Dsun.rmi.dgc
8243 8245 3 dmodi 99.9 May13 1-19:20:18 java -Dprogram.name=run.sh -Xms64m -Xmx100m -Dsun.rmi.dgc
To see headers too, just execute the below command:
ps -eLo pid,lwp,nlwp,ruser,pcpu,stime,etime,args > threadsList.txt
Explanation: PID is process Id.
LWP: is Light weight processes Lists for the above PID. These values are in Decimal.
NLWP: is number of LWP created for the above PID.
Rest other headers don’t require any explanation.
We can see LWP – 8245 is eating CPU. We need to convert this value into HEX value which will be “2035”.
Now take the thread dump and kill the process Id: 8243. Open the thread dump file and search value “2035”.
See below command:
//Taking thread dump
jstack -l 8243 > ThreadDump_15_May_2014_13_PM.txt
//Killing process
kill -9 8243
3) “jmap” – Memory Map (dump): Prints shared object memory maps or heap memory details of a given JVM process.
dmodiUnixUser@productName79:~$ jmap -dump:file=deepak.bin 8243
Dumping heap to /home/dmodiUnixUser/deepak.bin …
Heap dump file created
dmodiUnixUser@productName79:~$ ls
deepak.bin
This newly created file will be big in size (of 5-10 MB around). You can’t see this content using
“less” or “cat” command. You need tool to see this. We don’t use this generally, so not mentioning here.
4) “jmap” – Histo: See below command:
dmodiUnixUser@productName79:~$ jmap -histo:live 8243 > deepak.txt
Contents of this file “deepak.txt” will have similar like above:
num #instances #bytes class name
———————————————-
1: 14452 2229096
2: 14452 1740720
3: 1004 1406296
4: 1336 1270504 [B
5: 25057 1060840
6: 835 809368
7: 1004 787096
5) List of open files in Linux:
lsof – list open files
dmodiUnixUser@productName79:~$ lsof | grep home/dmodi/productName/dist/
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
java 16460 dmodiUnixUser mem REG 9,2 25680 8127062 home/dmodi/productName/dist/sample1.jar
java 16460 dmodiUnixUser mem REG 9,2 66770 8127061 home/dmodi/productName/dist/sample2.jar
dmodiUnixUser@productName79:~$ lsof | grep PROCESS_ID > help.txt
dmodiUnixUser@productName79:~$ less help.txt
———————————-END—————————————–
Recent Comments