{"id":3059,"date":"2014-05-19T00:34:20","date_gmt":"2014-05-18T16:34:20","guid":{"rendered":"http:\/\/rmohan.com\/?p=3059"},"modified":"2014-05-19T00:34:33","modified_gmt":"2014-05-18T16:34:33","slug":"java-using-more-cpu","status":"publish","type":"post","link":"https:\/\/mohan.sg\/?p=3059","title":{"rendered":"JAVA using More CPU"},"content":{"rendered":"<p><span style=\"font-size: large;\">I<\/span>n a production environment profiling is not an option, we have seen several times that our CPU has reached almost 100%, we are running tomcat on Linux, so what is happening?<\/p>\n<p>Fortunately, java comes with some great debugging tools,\u00a0cooperating those tools with Linux built-in tools will let you know what is\u00a0happening.<\/p>\n<p>Here is what i am going to explain:<\/p>\n<ul style=\"text-align: left;\">\n<li>An introduction about java threads and its relation to what-so-called Linux LWP<\/li>\n<li>A step-by-step<\/li>\n<\/ul>\n<div>1- An introduction<\/div>\n<div><\/div>\n<div>as you may know, 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\u00a0derived from the main thread (<span style=\"color: #38761d;\">out-of-focus: it is always a good\u00a0practice to give your threads a name, it is very\u00a0useful in debugging, however, it is not\u00a0required here<\/span>) the same exact\u00a0behavior\u00a0occurs 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 <b><a href=\"http:\/\/en.wikipedia.org\/wiki\/Light-weight_process\" target=\"_blank\">LWP<\/a><\/b>.<\/div>\n<div>to cut it short, Java main thread = Linux process and Java thread\u00a0= Linux LWP.<\/div>\n<div><\/div>\n<div>the idea here:<\/div>\n<div>\n<ul style=\"text-align: left;\">\n<li>Ask Linux which LWP is eating the CPU.<\/li>\n<li>Ask Java for a Thread Dump.<\/li>\n<li>Map this LWP to a Java thread.<\/li>\n<li>Get the part of code causing the issue.<\/li>\n<\/ul>\n<\/div>\n<div><\/div>\n<div>2- A Step-By-Step:<\/div>\n<div>\n<ul style=\"text-align: left;\">\n<li>Get the PID: the very first step is to know what is the Java process ID, we will use Linux tools\u00a0<span style=\"color: #38761d;\"><a href=\"http:\/\/linux.about.com\/od\/commands\/l\/blcmdl1_ps.htm\" target=\"_blank\">ps<\/a> and <a href=\"http:\/\/linux.about.com\/od\/commands\/l\/blcmdl1_grep.htm\" target=\"_blank\">grep<\/a><\/span><br \/>\n<code style=\"border: 1px solid #c4c4c4;\"> ps -A|grep java<\/code><br \/>\nif you are running\u00a0multiple java processes we can execute<br \/>\n<code style=\"border: 1px solid #c4c4c4;\"> ps -ef|grep java<\/code><\/li>\n<li>the next step is to get CPU usage per each LWP related to the main process, again we will use\u00a0<span style=\"color: #38761d;\"> <a href=\"http:\/\/linux.about.com\/od\/commands\/l\/blcmdl1_ps.htm\" target=\"_blank\">ps<\/a>\u00a0\u00a0and\u00a0<\/span> <a href=\"http:\/\/linux.about.com\/od\/commands\/l\/blcmdl1_grep.htm\" target=\"_blank\">grep<\/a><br \/>\n<code style=\"border: 1px solid #c4c4c4;\">ps -eLo pid,lwp,nlwp,ruser,pcpu,stime,etime,args|grep {pid} &gt; lwpthread.txt<\/code><br \/>\nthe file <b>lwpthread.txt<\/b> will contain some thing similar:<\/p>\n<table style=\"border: 1px solid #c4c4c4;\">\n<tbody>\n<tr>\n<th style=\"border: 1px solid #c4c4c4;\">PID<\/th>\n<th style=\"border: 1px solid #c4c4c4;\">NLWP<\/th>\n<th style=\"border: 1px solid #c4c4c4;\">SZ<\/th>\n<th style=\"border: 1px solid #c4c4c4;\">RUSER<\/th>\n<th style=\"border: 1px solid #c4c4c4;\">%CPU<\/th>\n<th style=\"border: 1px solid #c4c4c4;\">STIME<\/th>\n<th style=\"border: 1px solid #c4c4c4;\">ELAPSED<\/th>\n<th style=\"border: 1px solid #c4c4c4;\">COMMAND<\/th>\n<\/tr>\n<tr>\n<td style=\"border: 1px solid #c4c4c4;\">8234<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">8234<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">1110<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">admin<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">0.3<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">08:11<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">30:15<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">\/usr\/java\/jdk1.6.0_24\/bin\/java<\/td>\n<\/tr>\n<tr>\n<td style=\"border: 1px solid #c4c4c4;\">8234<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">8245<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">1110<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">admin<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">99.0<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">08:45<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">10:15<\/td>\n<td style=\"border: 1px solid #c4c4c4;\">\/usr\/java\/jdk1.6.0_24\/bin\/java<\/td>\n<\/tr>\n<\/tbody>\n<\/table>\n<p>as you can see, we have an LWP(mapped to a java thread) eating the CPU, get the NLWP, that will be our lead in the next step.<\/li>\n<li>the next step is to generate a java thread dump, there are two main ways to create a thread dump, the first one is to use the JDK tool <a href=\"http:\/\/docs.oracle.com\/javase\/1.5.0\/docs\/tooldocs\/share\/jstack.html\" target=\"_blank\">jstack<\/a> and pass the PID to it, the second way is to send a <b>kill <\/b>signal to the JVM, however in the first way you will have control over where you want to save the thread dump, while on the second way you will have the thread dump written on the java process standard output stream.<br \/>\nas said, we are using tomcat, so the thread dump will be in <b>catalina.out<\/b><br \/>\n<code style=\"border: 1px solid #c4c4c4;\"> kill -3 {pid}<\/code><br \/>\nthe thread dump will be printed to the file with full stack trace. the file will contain the thread you are after, but first convert your <b>LWP <\/b>id from <b>DEC <\/b>to <b>HEX <\/b>so <b>8245\u00a0<\/b>would be\u00a0<b>2035<\/b>, now open the thread dump with text editor and search for\u00a0<b>2035<\/b>, you will find something similar:<br \/>\n<code>\"TP-Processor234786\" daemon prio=10 tid=0x00002aaad8024800 <span style=\"background-color: yellow;\">nid=0x2035<\/span> runnable [0x00002aaadef29000]<br \/>\njava.lang.Thread.State: RUNNABLE<br \/>\nat <span style=\"background-color: yellow;\">java.util.HashMap.get(HashMap.java:303)<\/span><br \/>\nat ...... <\/code><\/li>\n<\/ul>\n<p>and you are done!<\/p>\n<\/div>\n","protected":false},"excerpt":{"rendered":"<p>In a production environment profiling is not an option, we have seen several times that our CPU has reached almost 100%, we are running tomcat on Linux, so what is happening?<\/p>\n<p>Fortunately, java comes with some great debugging tools, cooperating those tools with Linux built-in tools will let you know what is happening.<\/p>\n<p>Here is [&#8230;]<\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[46,4],"tags":[],"_links":{"self":[{"href":"https:\/\/mohan.sg\/index.php?rest_route=\/wp\/v2\/posts\/3059"}],"collection":[{"href":"https:\/\/mohan.sg\/index.php?rest_route=\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/mohan.sg\/index.php?rest_route=\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/mohan.sg\/index.php?rest_route=\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/mohan.sg\/index.php?rest_route=%2Fwp%2Fv2%2Fcomments&post=3059"}],"version-history":[{"count":2,"href":"https:\/\/mohan.sg\/index.php?rest_route=\/wp\/v2\/posts\/3059\/revisions"}],"predecessor-version":[{"id":3061,"href":"https:\/\/mohan.sg\/index.php?rest_route=\/wp\/v2\/posts\/3059\/revisions\/3061"}],"wp:attachment":[{"href":"https:\/\/mohan.sg\/index.php?rest_route=%2Fwp%2Fv2%2Fmedia&parent=3059"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/mohan.sg\/index.php?rest_route=%2Fwp%2Fv2%2Fcategories&post=3059"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/mohan.sg\/index.php?rest_route=%2Fwp%2Fv2%2Ftags&post=3059"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}