You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Lindsay Patten <BL...@netscape.net> on 2007/09/21 19:11:36 UTC
100% cpu usage by "VM Thread" in tomcat
I am looking for information on how to debug a problem. Any pointers to
documentation, suggestions of approaches etc. would be much appreciated.
I am having a problem with my tomcat server periodically going into a
state where it is using up all the available cpu and providing very slow
response. None of the jsp or servlets on the site should take up a lot
of cpu, they all just do relatively simple database queries and produce
simple html pages from the results. During the times when the cpu is
busy the database will generally not be under any significant load.
Top shows process 324 (0x144) as the busy process, and ps shows it
having consumed a lot of cpu:
PID TTY STAT TIME COMMAND
324 ? S 837:41 /usr/java/jdk1.5.0_10/bin/java -Djava...
Expecting to find that I had some error in my webapp I did a few thread
dumps, but assuming that nid in the thread dump corresponds to pid from
ps I found that the process that was spinning was "VM Thread":
"VM Thread" prio=1 tid=0x08098a48 nid=0x144 runnable
The thread dump does not give any additional information about this
thread. I presume it is the Virtual Machine itself.
If I look at the system status using the Tomcat manager webapp there are
often requests listed with ridiculously large values in the Time column,
several hundred seconds for jsp pages that only take a fraction of a
second to generate, and I can cut an paste the request into my browser
and the request will finish in a fraction of a second.
Sometimes it seems that reloading some of the webapps can "fix" the
problem, at least for a while - I don't know for sure, it could be
coincidence, but if I don't do anything the problem can persist for long
periods of time and then go away after a few webapp reloads. I have
tried to detect a pattern about which app reload solves the problem but
it seems to be different different times. vmstat doesn't show the
machine as thrashing or using much IO (everything basically fits into
physical memory). The only thing I can think of is that the VM is going
into a marathon garbage collection phase, but I don't know how to test
that hypothesis, and it seems odd that even that could go on for lengthy
periods of time.
Help?!?
JVM: jdk1.5.0_10
Tomcat: apache-tomcat-6.0.13
uname -a: Linux [hostname here] 2.4.34-grsec #27 SMP Mon Jan 22 21:19:29
CST 2007 i686 unknown
The system is a two cpu system with 4GB RAM, and when not in this
spinning state it handles its load with 10-15% cpu load.
---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: 100% cpu usage by "VM Thread" in tomcat
Posted by Jim Cox <sh...@gmail.com>.
On 9/21/07, Lindsay Patten <BL...@netscape.net> wrote:
[ ...stuff elided...]
>
> If I look at the system status using the Tomcat manager webapp there are
> often requests listed with ridiculously large values in the Time column,
> several hundred seconds for jsp pages that only take a fraction of a
> second to generate, and I can cut an paste the request into my browser
> and the request will finish in a fraction of a second.
>
[ ...stuff elided...]
As far as that goes, I've seen such threads on a Solaris box running
Tomcat 5.0.19. I can recreate them at will by requesting a JSP page in
a browser (Firefox, in this case) and making a request for another
page before I've received the response from the first request. In that
case the http80-Processor thread appears to time out after 8 minutes
of inactivity. I suppose if that happened a lot (e.g. if a network
burp caused a bunch of those) you might max out your "http processor"
threads, but that situation would be easy to spot in the thread dump.
FWIW, the "kill -QUIT <pid>" thread dump in these cases is along the lines of:
"http80-Processor22" daemon prio=5 tid=0x00430600 nid=0x227 runnable
[0xae17f000..0xae1819c8]
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at org.apache.coyote.http11.InternalOutputBuffer.realWriteBytes(InternalOutputBuffer.java:757)
at org.apache.tomcat.util.buf.ByteChunk.flushBuffer(ByteChunk.java:436)
---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: 100% cpu usage by "VM Thread" in tomcat
Posted by "Caldarale, Charles R" <Ch...@unisys.com>.
> From: Lindsay Patten [mailto:BLindsayPatten@netscape.net]
> Subject: Re: 100% cpu usage by "VM Thread" in tomcat
>
> I need to figure out how to reproduce the situation out of
> the production server to see how I can use it...
For an initial check, set -Dcom.sun.management.jmxremote for the Tomcat
startup, and run JConsole when you see the problem. (You could probably
run this all the time; it won't consume much in the way of CPU
resources.) This will at least let you see if the heap is full and if
any long-running GCs occur.
- Chuck
THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY
MATERIAL and is thus for use only by the intended recipient. If you
received this in error, please contact the sender and delete the e-mail
and its attachments from all computers.
---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: 100% cpu usage by "VM Thread" in tomcat
Posted by Lindsay Patten <BL...@netscape.net>.
Looking at the cpu times, top says that pid 324 has used over 900
minutes of cpu time, none of the other tomcat threads have used more
than 9 minutes. When the system is grinding it is pid 324 that is
listed as 97% of cpu with no other java threads on screen. The problem
may be caused by something in my code but the cpu activity appears to be
taking place in that system thread. Garbage collection seems to be the
most obvious candidate. I'm not sure where to go with that conclusion, I
received a reference to GCViewer, but I need to figure out how to
reproduce the situation out of the production server to see how I can
use it...
Further suggestions very welcome!
Thanks,
Lindsay
Caldarale, Charles R wrote:
>> From: Lindsay Patten [mailto:BLindsayPatten@netscape.net]
>> Subject: 100% cpu usage by "VM Thread" in tomcat
>>
>> Expecting to find that I had some error in my webapp I did a
>> few thread dumps, but assuming that nid in the thread dump
>> corresponds to pid from ps I found that the process that was
>> spinning was "VM Thread":
>>
>> "VM Thread" prio=1 tid=0x08098a48 nid=0x144 runnable
>>
>
> That's not likely to be the one actually spinning, unless your JVM is
> very broken. The VM thread will always show as runnable, since it's the
> one displaying the thread dump. You probably need to look a bit more
> closely at the other threads.
>
RE: 100% cpu usage by "VM Thread" in tomcat
Posted by "Caldarale, Charles R" <Ch...@unisys.com>.
> From: Lindsay Patten [mailto:BLindsayPatten@netscape.net]
> Subject: 100% cpu usage by "VM Thread" in tomcat
>
> Expecting to find that I had some error in my webapp I did a
> few thread dumps, but assuming that nid in the thread dump
> corresponds to pid from ps I found that the process that was
> spinning was "VM Thread":
>
> "VM Thread" prio=1 tid=0x08098a48 nid=0x144 runnable
That's not likely to be the one actually spinning, unless your JVM is
very broken. The VM thread will always show as runnable, since it's the
one displaying the thread dump. You probably need to look a bit more
closely at the other threads.
> The thread dump does not give any additional information about this
> thread. I presume it is the Virtual Machine itself.
It's the JVM's non-dedicated background thread; it does get involved in
garbage collection, but may or may not do the bulk of the work,
depending on the GC mechanism selected.
> If I look at the system status using the Tomcat manager
> webapp there are often requests listed with ridiculously
> large values in the Time column, several hundred seconds
> for jsp pages that only take a fraction of a second to
> generate
That sounds like your webapp logic may be spinning somewhere after it
has sent the response.
> Sometimes it seems that reloading some of the webapps can "fix" the
> problem, at least for a while
Another bit of evidence pointing to a problem in the webapp, not Tomcat
or the JVM.
- Chuck
THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY
MATERIAL and is thus for use only by the intended recipient. If you
received this in error, please contact the sender and delete the e-mail
and its attachments from all computers.
---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: 100% cpu usage by "VM Thread" in tomcat
Posted by Lindsay Patten <BL...@netscape.net>.
Thank you to the several people who made suggestions, either on the list
or by direct email!
I think I have solved the problem by simply using the -server option to
java when starting tomcat. By default tomcat uses the default VM, which
for Sun JDK1.5 is the client VM. By default the client VM sets a heap
size limit of 64MB. It seems that as I have added jsp pages and webapps
the total memory footprint of the webapps on my server had crept up over
time to more than 64MB so the virtual machine was "thrashing" in garbage
collection. I have plenty of memory so the higher limit makes complete
sense for me. The tool that led me to this conclusion was JConsole,
which I was unfamiliar with when I first posted. JConsole comes with the
jdk and allows you to connect to the VM and monitor things like memory
usage and limits and garbage collection:
http://java.sun.com/j2se/1.5.0/docs/guide/management/agent.html
It was due to JConsole that I realized I was using the client VM and
that memory was limited to 64MB. When I switched to the server VM the
memory limit was set to a much higher default, and after watching usage
for a while I realized that the "steady state" memory usage was over
64MB. JConsole seems to be a very useful tool, and perhaps a mention
could be added to the tomcat documentation someplace under
administration. Thank you to Chuck for suggesting using JConsole.
This page gives really simple instructions on how to set up JConsole
with password protected access:
http://www.opennms.org/index.php/Tomcat_5.5_JMX_How-To
I was a little surprised to see that one could access tomcat passwords
(like the password for manager access) using JConsole, so think twice
before setting it up without authentication!
Thanks again to everyone who helped me out on this!
Lindsay
Lindsay Patten wrote:
> I am looking for information on how to debug a problem. Any pointers
> to documentation, suggestions of approaches etc. would be much
> appreciated.
>
> I am having a problem with my tomcat server periodically going into a
> state where it is using up all the available cpu and providing very
> slow response. None of the jsp or servlets on the site should take up
> a lot of cpu, they all just do relatively simple database queries and
> produce simple html pages from the results. During the times when the
> cpu is busy the database will generally not be under any significant
> load.
>
> Top shows process 324 (0x144) as the busy process, and ps shows it
> having consumed a lot of cpu:
> PID TTY STAT TIME COMMAND
> 324 ? S 837:41 /usr/java/jdk1.5.0_10/bin/java -Djava...
>
> Expecting to find that I had some error in my webapp I did a few
> thread dumps, but assuming that nid in the thread dump corresponds to
> pid from ps I found that the process that was spinning was "VM Thread":
>
> "VM Thread" prio=1 tid=0x08098a48 nid=0x144 runnable
>
> The thread dump does not give any additional information about this
> thread. I presume it is the Virtual Machine itself.
>
> If I look at the system status using the Tomcat manager webapp there
> are often requests listed with ridiculously large values in the Time
> column, several hundred seconds for jsp pages that only take a
> fraction of a second to generate, and I can cut an paste the request
> into my browser and the request will finish in a fraction of a second.
>
> Sometimes it seems that reloading some of the webapps can "fix" the
> problem, at least for a while - I don't know for sure, it could be
> coincidence, but if I don't do anything the problem can persist for
> long periods of time and then go away after a few webapp reloads. I
> have tried to detect a pattern about which app reload solves the
> problem but it seems to be different different times. vmstat doesn't
> show the machine as thrashing or using much IO (everything basically
> fits into physical memory). The only thing I can think of is that the
> VM is going into a marathon garbage collection phase, but I don't know
> how to test that hypothesis, and it seems odd that even that could go
> on for lengthy periods of time.
>
> Help?!?
>
> JVM: jdk1.5.0_10
> Tomcat: apache-tomcat-6.0.13
> uname -a: Linux [hostname here] 2.4.34-grsec #27 SMP Mon Jan 22
> 21:19:29 CST 2007 i686 unknown
>
> The system is a two cpu system with 4GB RAM, and when not in this
> spinning state it handles its load with 10-15% cpu load.
---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: 100% cpu usage by "VM Thread" in tomcat
Posted by Jerome Jar <iu...@gmail.com>.
Hi, Lindsay,
Sorry for my ignorance, but seeing that you were trying to locate the
thread using "PID", I think perhaps it's wrong. I have the same
experience identifying such a CPU utilization issue on a Debian box
using a 2.6.x version kernel. I cannot recall whether on a 2.4.x
kernal linux box you can use ps to see "TID", the native thread id.
Well, maybe you can refer to
http://iusr.spaces.live.com/blog/cns!69F4725ED815E770!408.entry , this
is a summary after I resolving the same problem. Hope it can help.
On 9/22/07, Lindsay Patten <BL...@netscape.net> wrote:
> I am looking for information on how to debug a problem. Any pointers to
> documentation, suggestions of approaches etc. would be much appreciated.
>
> I am having a problem with my tomcat server periodically going into a
> state where it is using up all the available cpu and providing very slow
> response. None of the jsp or servlets on the site should take up a lot
> of cpu, they all just do relatively simple database queries and produce
> simple html pages from the results. During the times when the cpu is
> busy the database will generally not be under any significant load.
>
> Top shows process 324 (0x144) as the busy process, and ps shows it
> having consumed a lot of cpu:
> PID TTY STAT TIME COMMAND
> 324 ? S 837:41 /usr/java/jdk1.5.0_10/bin/java -Djava...
>
> Expecting to find that I had some error in my webapp I did a few thread
> dumps, but assuming that nid in the thread dump corresponds to pid from
> ps I found that the process that was spinning was "VM Thread":
>
> "VM Thread" prio=1 tid=0x08098a48 nid=0x144 runnable
>
> The thread dump does not give any additional information about this
> thread. I presume it is the Virtual Machine itself.
>
> If I look at the system status using the Tomcat manager webapp there are
> often requests listed with ridiculously large values in the Time column,
> several hundred seconds for jsp pages that only take a fraction of a
> second to generate, and I can cut an paste the request into my browser
> and the request will finish in a fraction of a second.
>
> Sometimes it seems that reloading some of the webapps can "fix" the
> problem, at least for a while - I don't know for sure, it could be
> coincidence, but if I don't do anything the problem can persist for long
> periods of time and then go away after a few webapp reloads. I have
> tried to detect a pattern about which app reload solves the problem but
> it seems to be different different times. vmstat doesn't show the
> machine as thrashing or using much IO (everything basically fits into
> physical memory). The only thing I can think of is that the VM is going
> into a marathon garbage collection phase, but I don't know how to test
> that hypothesis, and it seems odd that even that could go on for lengthy
> periods of time.
>
> Help?!?
>
> JVM: jdk1.5.0_10
> Tomcat: apache-tomcat-6.0.13
> uname -a: Linux [hostname here] 2.4.34-grsec #27 SMP Mon Jan 22 21:19:29
> CST 2007 i686 unknown
>
> The system is a two cpu system with 4GB RAM, and when not in this
> spinning state it handles its load with 10-15% cpu load.
>
>
> ---------------------------------------------------------------------
> To start a new topic, e-mail: users@tomcat.apache.org
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>
--
"Houston, we have a problem."
---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org