Re: Java/Tomcat 5 CPU utilization very high under low load
Leon Rosenberg wrote: How best can I find the troubled thread on a running production system? kill -QUIT id_of_the_tomcat_process the thread dump will be printed into the catalina.out Best to take several (eg 30 thread dumps ~10 seconds apart. Mark Its best to restart the server after the thread dump, but since it's handing anyway... also include the heap info: jmap -heap pid regards Leon - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Java/Tomcat 5 CPU utilization very high under low load
We are running Tomcat 5.5.27 on Linux 2.6.18-53.1.4.el5xen (Red Hat 4.1.2-14) with Java 1.6.0_05 (32 bit) in a Xen virtualization environment (not my server, so unsure what version that is). It has 3 webapps running, two of ours and Tomcat's manager. Normally, when we run 'top', Java and it's related PG 8.3.3 database that drives the Tomcat webapps show very low CPU utilization (0-1%) and even leave the 'top' listing. When there is higher user activity, we see Java increase to 4-20% utilization, but these are spikes that also tend to return to the low utilization shortly after the burst. We run Java with options: -server -Xms2200m -Xmx2200m -XX:MaxPermSize=128m. But every so often, Java goes crazy and reaches 95-99% CPU utilization, and it sticks there, even though there is little Tomcat activity. What is unusual to me is that during this initial phase of high CPU utilization, the webapps themselves appear to run smoothly (don't really notice a slowdown like you'd expect from such high utilization), logging in, using the web interface, doing queries, updates, etc. Also, the tomcat access log show little actual user activity while it's running so busy. Unfortunately, after some time, it seems that Tomcat eventually locks up and we have to restart the system, where the process repeats itself: initially normal low utilization, followed by 99% utilization with the system still working okay, followed by a lock-up and restart. So it seems like there's a Java thread that is running amok, yet not a critical thread (at least not initially) since the apps appear to be working fine. How best can I find the troubled thread on a running production system? Thanks, David P.S. Note that our webapps run on lots of servers in a similar configuration (albeit without Xen) and we've never seen this before after years of running production systems -- it's just this one system. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Java/Tomcat 5 CPU utilization very high under low load
How best can I find the troubled thread on a running production system? kill -QUIT id_of_the_tomcat_process the thread dump will be printed into the catalina.out Its best to restart the server after the thread dump, but since it's handing anyway... also include the heap info: jmap -heap pid regards Leon - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Java/Tomcat 5 CPU utilization very high under low load
David Wall wrote: We are running Tomcat 5.5.27 on Linux 2.6.18-53.1.4.el5xen (Red Hat 4.1.2-14) with Java 1.6.0_05 (32 bit) in a Xen virtualization environment (not my server, so unsure what version that is). It has 3 webapps running, two of ours and Tomcat's manager. Normally, when we run 'top', Java and it's related PG 8.3.3 database that drives the Tomcat webapps show very low CPU utilization (0-1%) and even leave the 'top' listing. When there is higher user activity, we see Java increase to 4-20% utilization, but these are spikes that also tend to return to the low utilization shortly after the burst. We run Java with options: -server -Xms2200m -Xmx2200m -XX:MaxPermSize=128m. But every so often, Java goes crazy and reaches 95-99% CPU utilization, and it sticks there, even though there is little Tomcat activity. To me this sounds like the garbage collection kicking in (and not finding much to throw out). You should be able to see thread-level elapsed CPU time with ps -fLp tomcat_process_id. By running this command a few consecutive times and comparing the results, you should be able to see if there's a certain single thread that is taking up all or most of the CPU. Then it'd be a task to match these thread ids to information from the thread dump. F.ex. from my toy machine; $ ps -fLp 7044 UIDPID PPID LWP C NLWP STIME TTY TIME CMD tomcat7044 1 7044 0 40 2008 ?00:00:12 /usr/lib/jvm/java/bin tomcat7044 1 7118 0 40 2008 ?00:02:58 /usr/lib/jvm/java/bin tomcat7044 1 7119 0 40 2008 ?00:00:00 /usr/lib/jvm/java/bin ... tomcat7044 1 7892 0 40 2008 ?00:36:26 /usr/lib/jvm/java/bin ... (there are a number of other threads) Then, at least on my JVM, the thread ids are shown in hexadecimal, so it's best to convert the interesting thread ids to hex; from the above, 7044=0x1b84 7118=0x1bce 7119=0x1bcf 7892=0x1ed4 ... and the thread info from the dump matchind to the above: main prio=1 tid=0x0805cfb8 nid=0x1b84 runnable [0xbfffc000..0xbfffd708] VM Thread prio=1 tid=0x08099f38 nid=0x1bce runnable Reference Handler daemon prio=1 tid=0x0809cae0 nid=0x1bcf in Object.wait() [0xb2519000..0xb2519f20] ContainerBackgroundProcessor[StandardEngine[Catalina]] daemon prio=1 tid=0x083444e0 nid=0x1ed4 waiting on condition [0xb135c000..0xb135cfa0] In the dump there is also the call stack for each of the threads, so if it's an application thread that's using CPU, you'll get at least some glimpse where in the code the time is spent. The call stack may also contain information about threads being deadlocked with each other (but this wouldn't lead to high CPU usage -- instead this would lead to a standstill without any CPU being used). I hope these were of any help, -- ..Juha - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Java/Tomcat 5 CPU utilization very high under low load
F.ex. from my toy machine; $ ps -fLp 7044 UIDPID PPID LWP C NLWP STIME TTY TIME CMD tomcat7044 1 7044 0 40 2008 ?00:00:12 /usr/lib/jvm/java/bin tomcat7044 1 7118 0 40 2008 ?00:02:58 /usr/lib/jvm/java/bin tomcat7044 1 7119 0 40 2008 ?00:00:00 /usr/lib/jvm/java/bin ... tomcat7044 1 7892 0 40 2008 ?00:36:26 /usr/lib/jvm/java/bin ... (there are a number of other threads) Then, at least on my JVM, the thread ids are shown in hexadecimal, so it's best to convert the interesting thread ids to hex; from the above, 7044=0x1b84 7118=0x1bce 7119=0x1bcf 7892=0x1ed4 ... and the thread info from the dump matchind to the above: main prio=1 tid=0x0805cfb8 nid=0x1b84 runnable [0xbfffc000..0xbfffd708] VM Thread prio=1 tid=0x08099f38 nid=0x1bce runnable Reference Handler daemon prio=1 tid=0x0809cae0 nid=0x1bcf in Object.wait() [0xb2519000..0xb2519f20] ContainerBackgroundProcessor[StandardEngine[Catalina]] daemon prio=1 tid=0x083444e0 nid=0x1ed4 waiting on condition [0xb135c000..0xb135cfa0] In the dump there is also the call stack for each of the threads, so if it's an application thread that's using CPU, you'll get at least some glimpse where in the code the time is spent. Thanks for the detailed explanation, Juha. When I get some info, I'll post back what I find. I've added your 'ps' commands to our checking, along with the jmap and thread dumps suggested as well. Hopefully we'll be able to find it. I was interested to see that it could also be SOAP threads that get in trouble, since another aspect of this particular deployment is that it uses the Salesforce SOAP APIs to update data back in Salesforce, so perhaps it will be something there. David - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
