You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Benjamin Adams <ba...@ambrosiasw.com> on 2006/08/01 23:28:13 UTC

cpu 100% java

I'm on OS X 10.4.7 running with weblog software (blojsom)
I have to do a kill -9 on java to stop it from using 100+ on cpu  
sometimes, to let users connect.
This comes up over and over in the log:
2006-08-01 17:22:08 StandardWrapperValve[blojsom]: Servlet.service()  
for servlet blojsom threw exception
javax.servlet.ServletException: Servlet execution threw an exception
         at  
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter 
(ApplicationFilterChain.java:269)
         at org.apache.catalina.core.ApplicationFilterChain.doFilter 
(ApplicationFilterChain.java:193)
         at org.blojsom.filter.CompressionFilter.doFilter 
(CompressionFilter.java:107)
         at  
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter 
(ApplicationFilterChain.java:213)
         at org.apache.catalina.core.ApplicationFilterChain.doFilter 
(ApplicationFilterChain.java:193)
         at org.blojsom.filter.PermalinkFilter.doFilter 
(PermalinkFilter.java:208)
         at  
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter 
(ApplicationFilterChain.java:213)
         at org.apache.catalina.core.ApplicationFilterChain.doFilter 
(ApplicationFilterChain.java:193)
         at org.apache.catalina.core.StandardWrapperValve.invoke 
(StandardWrapperValve.java:256)
         at org.apache.catalina.core.StandardPipeline 
$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
         at org.apache.catalina.core.StandardPipeline.invoke 
(StandardPipeline.java:480)
         at org.apache.catalina.core.ContainerBase.invoke 
(ContainerBase.java:995)
         at org.apache.catalina.core.StandardContextValve.invoke 
(StandardContextValve.java:191)
         at org.apache.catalina.core.StandardPipeline 
$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
         at org.apache.catalina.core.StandardPipeline.invoke 
(StandardPipeline.java:480)
         at org.apache.catalina.core.ContainerBase.invoke 
(ContainerBase.java:995)
         at org.apache.catalina.core.StandardContext.invoke 
(StandardContext.java:2417)
         at org.apache.catalina.core.StandardHostValve.invoke 
(StandardHostValve.java:180)
         at org.apache.catalina.core.StandardPipeline 
$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
         at org.apache.catalina.valves.ErrorDispatcherValve.invoke 
(ErrorDispatcherValve.java:171)
         at org.apache.catalina.core.StandardPipeline 
$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
         at org.apache.catalina.valves.ErrorReportValve.invoke 
(ErrorReportValve.java:172)
         at org.apache.catalina.core.StandardPipeline 
$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
         at org.apache.catalina.core.StandardPipeline.invoke 
(StandardPipeline.java:480)
         at org.apache.catalina.core.ContainerBase.invoke 
(ContainerBase.java:995)
         at org.apache.catalina.core.StandardEngineValve.invoke 
(StandardEngineValve.java:174)
         at org.apache.catalina.core.StandardPipeline 
$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
         at org.apache.catalina.core.StandardPipeline.invoke 
(StandardPipeline.java:480)
         at org.apache.catalina.core.ContainerBase.invoke 
(ContainerBase.java:995)
         at org.apache.coyote.tomcat4.CoyoteAdapter.service 
(CoyoteAdapter.java:193)
         at org.apache.jk.server.JkCoyoteHandler.invoke 
(JkCoyoteHandler.java:309)
         at org.apache.jk.common.HandlerRequest.invoke 
(HandlerRequest.java:387)
         at org.apache.jk.common.ChannelSocket.invoke 
(ChannelSocket.java:673)
         at org.apache.jk.common.ChannelSocket.processConnection 
(ChannelSocket.java:615)
         at org.apache.jk.common.SocketConnection.runIt 
(ChannelSocket.java:786)
         at org.apache.tomcat.util.threads.ThreadPool 
$ControlRunnable.run(ThreadPool.java:666)
         at java.lang.Thread.run(Thread.java:613)
----- Root Cause -----
java.lang.OutOfMemoryError: Java heap space

Can some one point me in the right direction to fix?
Thanks
Ben

---------------------------------------------------------------------
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: cpu 100% java

Posted by Benjamin Adams <ba...@ambrosiasw.com>.
On Aug 2, 2006, at 4:18 PM, Christopher Schultz wrote:

> Ben,
>
>> How much ram do I set?
>>
>> Load Avg:  1.30, 1.28, 1.22     CPU usage:  51.3% user, 8.4% sys,  
>> 40.3%
>> idle
>> SharedLibs: num =  137, resident = 22.8M code, 3.20M data, 6.41M  
>> LinkEdit
>> MemRegions: num =  7345, resident =  142M + 8.15M private, 27.4M  
>> shared
>> PhysMem:  61.1M wired, 68.0M active,  173M inactive,  302M used,   
>> 209M free
>> VM: 3.44G + 89.5M   18117(0) pageins, 0(0) pageouts
>>
>>   PID COMMAND      %CPU   TIME   #TH #PRTS #MREGS RPRVT  RSHRD  RSIZE
>> VSIZE
>>   825 java       102.4%  2:43:34  61   >>>   371  98.0M   872K   
>> 85.1M-
>> 308M
>>
>> Should have 209MB Available.
>
> Aah... when Java starts up, it will cap its own memory at a certain
> size, even if the OS can give it more. You set the heap size using...
>
>> I added this to catalina.sh:
>> JAVA_OPTS="$CF_JVM_OPTIONS -Xms128m -Xmx256m"
>
> ...these parameters. That means that, no matter what, Java will not
> allocate more than 256MB of heap space. The JVM may take more memory
> than that ('cause the non-Java stuff such as the JIT, memory manager,
> etc.) all need some memory to work with, but your heap size will  
> not get
> any bigger than 256MB.

Think the Java that is hogging the cpu is something different.
I run /Library/Tomcat/bin/startup.sh (with ram settings)
  1792 java        27.9%  0:08.83  12   255   191  47.9M+ 13.1M  35.6M 
+  469M+ (using -Xms128m -Xmx256m)

but this one is still around
1775 java        98.8%  0:56.40  21   597   243  88.3M  9.94M   
77.8M   288M (one that hogs cpu, the problem process from the start)

I do  /Library/Tomcat/bin/shutdown.sh and I only have the pid 1775  
(hog one) other java is gone now.

Two Java programs:
Ran by Appserve "java -Djava.endorsed.dirs=/Library/Tomcat/common/ 
endorsed -classpath /Library/Java/Home/lib/tools.jar:/Library/Tomcat/ 
bin/bootstrap.jar -Dcatalina.base=/Library/Tomcat/blojsom_root - 
Dcatalina.home=/Library/Tomcat -Djava.io.tmpdir=/Library/Tomcat/ 
blojsom_root/temp org.apache.catalina.startup.Bootstrap start"
(weblogs use this one, seems to be the problem one, any idea where  
the config is for this one?)

Ran by Root "/System/Library/Frameworks/JavaVM.framework/Versions/1.4/ 
Home/bin/java -Xms128m -Xmx256m -Djava.endorsed.dirs=/Library/Tomcat/ 
common/endorsed ...." so this one is using the ram change -Xms128m - 
Xmx256m other is not.



>
> It's tough to tell what's going on with this:
>
>>   PID COMMAND      %CPU   TIME   #TH #PRTS #MREGS RPRVT  RSHRD  RSIZE
>> VSIZE
>>   825 java       102.4%  2:43:34  61   >>>   371  98.0M   872K   
>> 85.1M-
>> 308M
>
> RSIZE (resident size, IIRC) is 85.1M - 308M? WTF does that mean?
>
> If the 308M is spurious, then your Java process was using 85MB which
> suggests that your heap size was probably more like 64MB or  
> somewhere in
> there. Increasing it to 128/256 as you have above ought to give you  
> some
> more room to move around in.
>
> Does this help the problem?
>
> -chris
>
>

Ben


---------------------------------------------------------------------
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: cpu 100% java

Posted by Christopher Schultz <ch...@christopherschultz.net>.
Ben,

> How much ram do I set?
>
> Load Avg:  1.30, 1.28, 1.22     CPU usage:  51.3% user, 8.4% sys, 40.3%
> idle
> SharedLibs: num =  137, resident = 22.8M code, 3.20M data, 6.41M LinkEdit
> MemRegions: num =  7345, resident =  142M + 8.15M private, 27.4M shared
> PhysMem:  61.1M wired, 68.0M active,  173M inactive,  302M used,  209M free
> VM: 3.44G + 89.5M   18117(0) pageins, 0(0) pageouts
> 
>   PID COMMAND      %CPU   TIME   #TH #PRTS #MREGS RPRVT  RSHRD  RSIZE 
> VSIZE
>   825 java       102.4%  2:43:34  61   >>>   371  98.0M   872K  85.1M- 
> 308M
> 
> Should have 209MB Available.

Aah... when Java starts up, it will cap its own memory at a certain
size, even if the OS can give it more. You set the heap size using...

> I added this to catalina.sh:
> JAVA_OPTS="$CF_JVM_OPTIONS -Xms128m -Xmx256m"

...these parameters. That means that, no matter what, Java will not
allocate more than 256MB of heap space. The JVM may take more memory
than that ('cause the non-Java stuff such as the JIT, memory manager,
etc.) all need some memory to work with, but your heap size will not get
any bigger than 256MB.

It's tough to tell what's going on with this:

>   PID COMMAND      %CPU   TIME   #TH #PRTS #MREGS RPRVT  RSHRD  RSIZE 
> VSIZE
>   825 java       102.4%  2:43:34  61   >>>   371  98.0M   872K  85.1M- 
> 308M

RSIZE (resident size, IIRC) is 85.1M - 308M? WTF does that mean?

If the 308M is spurious, then your Java process was using 85MB which
suggests that your heap size was probably more like 64MB or somewhere in
there. Increasing it to 128/256 as you have above ought to give you some
more room to move around in.

Does this help the problem?

-chris



Re: cpu 100% java

Posted by Benjamin Adams <ba...@ambrosiasw.com>.
On Aug 1, 2006, at 5:55 PM, Christopher Schultz wrote:

> Ben,
>
>> I'm on OS X 10.4.7 running with weblog software (blojsom)
>> I have to do a kill -9 on java to stop it from using 100+ on cpu
>> sometimes, to let users connect.
>
> I assume that you also have to restart Tomcat at this point, yes?
I just kill Java, Tomcat auto restarts it.

>
>> This comes up over and over in the log:
>> 2006-08-01 17:22:08 StandardWrapperValve[blojsom]: Servlet.service 
>> () for
>> servlet blojsom threw exception
>> javax.servlet.ServletException: Servlet execution threw an exception
>
> [snip]
>
>> ----- Root Cause -----
>> java.lang.OutOfMemoryError: Java heap space
>
> You done run outta memory. Since this question ("why did I run out of
> memory") comes up a lot, I'll save you some time going through the
> gauntlet of one-off responses you are likely to get:
>
> 3. There might be a memory leak. Since you are getting 100% CPU use,
>    you might have found a problem with the software getting it into
>    a tight and infinite loop (or, at least sufficiently many  
> iterations
>    that it may as well be infinite) that generates loads of objects:
>    hence, your memory exhaustion. Make sure you have the latest  
> patches
>    from the vendor.
>
>
How much ram do I set?
Load Avg:  1.30, 1.28, 1.22     CPU usage:  51.3% user, 8.4% sys,  
40.3% idle
SharedLibs: num =  137, resident = 22.8M code, 3.20M data, 6.41M  
LinkEdit
MemRegions: num =  7345, resident =  142M + 8.15M private, 27.4M shared
PhysMem:  61.1M wired, 68.0M active,  173M inactive,  302M used,   
209M free
VM: 3.44G + 89.5M   18117(0) pageins, 0(0) pageouts

   PID COMMAND      %CPU   TIME   #TH #PRTS #MREGS RPRVT  RSHRD   
RSIZE  VSIZE
   825 java       102.4%  2:43:34  61   >>>   371  98.0M   872K   
85.1M-  308M

Should have 209MB Available.

>
> After that, it's just a matter of changing your memory settings.  
> How you
> do that depends on your deployment, but generally you set the
> environment variable JAVA_OPTS and use the "-X" parameters to set the
> Java heap size.

I added this to catalina.sh:
JAVA_OPTS="$CF_JVM_OPTIONS -Xms128m -Xmx256m"

>
> Often, it helps to set the initial and maximum heap sizes to the same
> thing, so that the memory manager never has to grow the heap during  
> the
> life of the process -- that can save time and avoid OOMs if Java  
> demands
> too much memory too fast (I really hope this is fixed in recent  
> versions
> of the JVM... this used to happen and it really should not).
>
> Hope that helps,
>
> -chris
>
>
Thanks
--Ben


---------------------------------------------------------------------
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: cpu 100% java

Posted by Christopher Schultz <ch...@christopherschultz.net>.
Ben,

> I'm on OS X 10.4.7 running with weblog software (blojsom)
> I have to do a kill -9 on java to stop it from using 100+ on cpu
> sometimes, to let users connect.

I assume that you also have to restart Tomcat at this point, yes?

> This comes up over and over in the log:
> 2006-08-01 17:22:08 StandardWrapperValve[blojsom]: Servlet.service() for
> servlet blojsom threw exception
> javax.servlet.ServletException: Servlet execution threw an exception

[snip]

> ----- Root Cause -----
> java.lang.OutOfMemoryError: Java heap space

You done run outta memory. Since this question ("why did I run out of
memory") comes up a lot, I'll save you some time going through the
gauntlet of one-off responses you are likely to get:

1. Contact the vendor or read their documentation to find out how
   much memory they recommend for the application (taking into account
   the number of users, etc.) and check to see that you have your JVM
   configured have that much memory. If they recommend 128MB and you
   have 16MB configured, then you might just be running out of memory.

2. If you are meeting the vendor's suggestions for memory usage, but
   you think that you have an unusual load (number of users, frequency
   or requests, whatever), then consider increasing your memory
   /somewhat/ to cover that load. Generally, you don't need to go
   allocating 4GB of heap space right away... if you do that, you're
   more likely to put the problem off than anything else.

3. There might be a memory leak. Since you are getting 100% CPU use,
   you might have found a problem with the software getting it into
   a tight and infinite loop (or, at least sufficiently many iterations
   that it may as well be infinite) that generates loads of objects:
   hence, your memory exhaustion. Make sure you have the latest patches
   from the vendor.

4. If you added any of your own code, check that out.
   If you are using a weird JDBC driver, check to see that you have
   the latest compatible version. In fact, check all your libraries.

After that, it's just a matter of changing your memory settings. How you
do that depends on your deployment, but generally you set the
environment variable JAVA_OPTS and use the "-X" parameters to set the
Java heap size.

Often, it helps to set the initial and maximum heap sizes to the same
thing, so that the memory manager never has to grow the heap during the
life of the process -- that can save time and avoid OOMs if Java demands
too much memory too fast (I really hope this is fixed in recent versions
of the JVM... this used to happen and it really should not).

Hope that helps,

-chris



Re: cpu 100% java

Posted by Justin Spies <ju...@thespies.org>.
Damn copy and paste..... I've re-edited for the missing details below,  
my apologies.


Quoting Justin Spies <ju...@thespies.org>:
...
>
> The VSIZE question--when the JVM starts, it places a hold on the
> memory it thinks is needed.  So if you allocate a maximum heap of
> 256MB + the permanent size of 128MB (which I realize you haven't set
> and I don't recall the default) + extra overhead memory =3D3D 469MB of
> VSIZE.  Note that the JVM needs memory, as Chris mentioned, of HEAP +
> PERMSIZE + (THREADMEMORY * NUM THREADS).
>
> To check memory usage, you'll want to add the following to your
> startup parameters (plus any others you want):
>
> -verbose:gc -Xloggc:/tmp/garbage.log -XX:+PrintGCTimeStamps -XX:PrintGCDetai=
> =3D
> ls

The above should read
-verbose:gc -Xloggc:/tmp/garbage.log -XX:+PrintGCTimeStamps -XX:PrintGCDetails

...

>
> Also note that the above instance is using much more REAL memory
> (88MB) than the first instance, but has much less total allocated
> memory (288MB).  It's highly likely that the application is defaulting
> to a heap size of something like or 9MB.

The above should read
... to a heap size of something like 64MB or 96MB...

Justin

----------------------------------------------------------------
This message was sent using IMP, the Internet Messaging Program.


---------------------------------------------------------------------
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: cpu 100% java

Posted by Justin Spies <ju...@thespies.org>.
Ben,
For various reasons, I've had to send this response using your  
original message.  I've included below some of the feedback provided  
by Chris since I'm pretty sure I'v read the entire thread so far...

I've run into this type of issue many times as well, memory management
definitely is not automatic in Java, at least not for admins.


[Hide Quoted Text]
>
> Think the Java that is hogging the cpu is something different.
> I run /Library/Tomcat/bin/startup.sh (with ram settings)
> PID COMMAND      %CPU   TIME   #TH #PRTS #MREGS RPRVT  RSHRD  RSIZE
> VSIZE
>  1792 java        27.9%  0:08.83  12   255   191  47.9M+ 13.1M  35.6M+
> 469M+ (using -Xms128m -Xmx256m)
>

This application looks to not be using much of the heap.  What you see
is that the system is using only about 50MB of memory.  According to
http://www.mozilla.org/projects/footprint/OSX_opt_mem_usage.txt
however, the numbers add up the opposite (the document says that
47+13=3D3D35, but it looks more like 13+35=3D3D48)

The VSIZE question--when the JVM starts, it places a hold on the
memory it thinks is needed.  So if you allocate a maximum heap of
256MB + the permanent size of 128MB (which I realize you haven't set
and I don't recall the default) + extra overhead memory =3D3D 469MB of
VSIZE.  Note that the JVM needs memory, as Chris mentioned, of HEAP +
PERMSIZE + (THREADMEMORY * NUM THREADS).

To check memory usage, you'll want to add the following to your
startup parameters (plus any others you want):

-verbose:gc -Xloggc:/tmp/garbage.log -XX:+PrintGCTimeStamps -XX:PrintGCDetai=
=3D
ls

The above will tell you how much memory is being allocated and how
often the system is doing garbage collection.

Details for reading and understanding the log files can be found at
http://java.sun.com/docs/hotspot/gc5.0/gc_tuning_5.html  (jvm 1.5)
http://java.sun.com/docs/hotspot/gc1.4.2/ (jvm 1.4.2)

I've seen weird issues with the different garbage collectors as well,
for example we have an application in BEA WebLogic on a Sun server
where using the ConcMarkSweep collector caused a core dump.  I've also
seen JVM's on Linux hard lock in the middle of a GC and the CPU spike
to 100% utilization.  Only a kill -9 would kill the process.

[Hide Quoted Text]
> but this one is still around
> PID COMMAND      %CPU   TIME   #TH #PRTS #MREGS RPRVT  RSHRD  RSIZE
> VSIZE
> 1775 java        98.8%  0:56.40  21   597   243  88.3M  9.94M  77.8M
> 288M (one that hogs cpu, the problem process from the start)
>
> I do  /Library/Tomcat/bin/shutdown.sh and I only have the pid 1775 (hog
> one) other java is gone now.
>

I haven't used a Mac in about 8 mo, so I don't recall the details of
the startup / shutdown for Tomcat, however this could be due to the
high load & the shutdown command cannot communicate with the Tomcat
instance.

Also note that the above instance is using much more REAL memory
(88MB) than the first instance, but has much less total allocated
memory (288MB).  It's highly likely that the application is defaulting
to a heap size of something like or 9MB.

Since this is the instance causing problems, you'll probably want to
use the above JVM arguments for this instance.  Note that you probably
cannot put the -Xloggc:/tmp/garbage.log into a shared startup script.
Any instance started with that script would write to the same file,
destroying / contaminating your data.


[Hide Quoted Text]
> Two Java programs:
> Ran by Appserve "java
> -Djava.endorsed.dirs=3D3D/Library/Tomcat/common/endorsed -classpath
> /Library/Java/Home/lib/tools.jar:/Library/Tomcat/bin/bootstrap.jar
> -Dcatalina.base=3D3D/Library/Tomcat/blojsom_root
> -Dcatalina.home=3D3D/Library/Tomcat
> -Djava.io.tmpdir=3D3D/Library/Tomcat/blojsom_root/temp
> org.apache.catalina.startup.Bootstrap start"
> (weblogs use this one, seems to be the problem one, any idea where the
> config is for this one?)
>
> Ran by Root
> "/System/Library/Frameworks/JavaVM.framework/Versions/1.4/Home/bin/java
> -Xms128m -Xmx256m -Djava.endorsed.dirs=3D3D/Library/Tomcat/common/endorsed
> ...." so this one is using the ram change -Xms128m -Xmx256m other is
> not.
>
>
>
>>
>> It's tough to tell what's going on with this:
>>
>>>  PID COMMAND      %CPU   TIME   #TH #PRTS #MREGS RPRVT  RSHRD  RSIZE
>>> VSIZE
>>>  825 java       102.4%  2:43:34  61   >>>   371  98.0M   872K  85.1M-
>>> 308M
>>
>> RSIZE (resident size, IIRC) is 85.1M - 308M? WTF does that mean?
>>
>> If the 308M is spurious, then your Java process was using 85MB which
>> suggests that your heap size was probably more like 64MB or somewhere in
>> there. Increasing it to 128/256 as you have above ought to give you some
>> more room to move around in.
>>
>> Does this help the problem?
>>
>> -chris
>>
>>
>
> Ben

----------------------------------------------------------------
This message was sent using IMP, the Internet Messaging Program.


---------------------------------------------------------------------
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: cpu 100% java

Posted by Mike Davis <md...@lookhere.co.za>.
On Tue, 1 Aug 2006 17:28:13 -0400
Benjamin Adams <ba...@ambrosiasw.com> wrote:

> I'm on OS X 10.4.7 running with weblog software (blojsom)
> I have to do a kill -9 on java to stop it from using 100+ on cpu  
> sometimes, to let users connect.
>

I find that a very similar problem occurs quite consisitently if I use
the manager to restart an app and a user tries to access that app
during the second or two it takes to restart.

The -Xmx/ms fix reduces the time app takes to restart and also
reduces the number of times the error occurs, but doesn't make the
problem go away.

Is it possible that the OutOfMemory error is just a red herring and
there is actually some other common problem?

It's a Tapestry app, using Tomcat 5.5.17 (also happens on 5.5.15), 
JVM: '1.5.0_05-b05, Sun Microsystems Inc.',
OS: Gentoo 'Linux 2.6.16-suspend2-r8' (also happens on Debian, stock
2.6.16)

HTH

Mike Davis

---------------------------------------------------------------------
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