You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Jesse Klaasse <je...@indicia.nl> on 2010/02/01 11:22:29 UTC
Re: Tomcat 100% CPU usage after moving from Java 5 to 6
In the meantime, the environment has been much more stable than it was before
the move to Java 6 and the new JVM options. However, a few minutes ago,
Tomcat became completely unresponsive, while the CPU usage was very low
(~3%). This was on our external server, with these options:
-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory
-Dcom.sun.management.jmxremote -XX:MaxPermSize=512m
-Xloggc:D:\logs\gc\tomcat-gc.log -XX:+PrintGCDetails -XX:+UseConcMarkSweepGC
-XX:+CMSClassUnloadingEnabled -XX:+DisableExplicitGC -XX:NewSize=3072m
-XX:+UseCompressedOops -Xms7168m -Xmx7168m
The gc log is showing a lot of activity during the unresponsiveness (the gc
log is attached to this message). Do you guys see any clues? Thanks in
advance!
The Tomcat GC log:
http://old.nabble.com/file/p27402032/tomcat-gc.log tomcat-gc.log
--
View this message in context: http://old.nabble.com/Tomcat-100--CPU-usage-after-moving-from-Java-5-to-6-tp27305110p27402032.html
Sent from the Tomcat - User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Tomcat 100% CPU usage after moving from Java 5 to 6
Posted by Dan Armbrust <da...@gmail.com>.
>
> Well, as I said, Tomcat is working much more stable now than it did before.
> However, once in a few days it still becomes unresponsive, while CPU usage
> stays incredibly low.
Unresponsive, meaning what, exactly? If the CPU is idle, but your
webapp isn't returning a response... it seems to indicate that your
webapp is waiting on something else... DB query, file read, whatever.
It seems unlikely that it would be blocked, consistently by a garbage
collection - especially with the heap sizes you are running with.
VisualJVM can give you a clue as to what threads are running, and
which ones are waiting when the system is unresponsive.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: Tomcat 100% CPU usage after moving from Java 5 to 6
Posted by "Caldarale, Charles R" <Ch...@unisys.com>.
> From: Christopher Schultz [mailto:chris@christopherschultz.net]
> Subject: Re: Tomcat 100% CPU usage after moving from Java 5 to 6
>
> It's interesting that there's no timing data for that last statement.
> It /is/ possible this is where the JVM went down. (Did it go down?)
That's very suspicious. I'm wondering if the OS killed the process just because it asked for timing information in a bad way? (E.g., have some counters overflowed?)
> Both of these GC runs seem to be collecting a /lot/ of garbage:
> 3272635K->747297K
Completely understandable given the large heap size. Note that the term "garbage collection" is somewhat of a misnomer these days; it's the live objects that are collected and moved - the dead ones are simply ignored.
> I don't believe the GC will do "serial" collections unless explicitly
> told to do that. The days of "stop the world" garbage collection are
> long gone.
Not true; "stop the world" is still the default, but the pause time is a lot shorter than it used to be. (I'd avoid the use of the word "serial" here, since the GC default is parallel, but not concurrent.) Regardless, I would try removing the concurrent GC settings and see if the problem disappears.
> > And also the +DisableExplicitGC?
>
> That only causes the JVM to ignore calls to System.gc(), which aren't
> guaranteed to do anything, anyway. Unless you are deploying unknown
> webapps, this probably isn't doing anything at all.
There is some Sun-provided RMI code that still insists on calling System.gc() for no particular reason, so disabling the explicit calls is a good idea.
> If the GC were running like crazy, I suspect you'd see more
> CPU usage.
Definitely. This does not have the feel of a GC problem, but rather something broken in JVM native calls to the OS causing abrupt process termination. Since your CPU utilization doesn't seem to be a problem, is there any detailed OS logging you can enable to trace the calls to the kernel?
- 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.
Re: Tomcat 100% CPU usage after moving from Java 5 to 6
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Jesse,
On 2/2/2010 3:23 AM, Jesse Klaasse wrote:
> Christopher Schultz-2 wrote:
>>
>> Can you give us a timestamp for when the trouble started? Reading GC
>> output is pretty tedious.
>>
>
> I believe the trouble started around 15 - 20 minutes before the end of the
> gc log, so that would be from ~61h36m.
That's 221760 minutes, and you only have two GC log lines near or after
that time:
222745.754: [GC 222745.754: [ParNew: 2566632K->34378K(2831168K),
0.1180327 secs] 3272635K->747297K(7025472K), 0.1187242 secs] [Times:
user=0.44 sys=0.02, real=0.13 secs]
223001.755: [GC 223001.756: [ParNew: 2550986K->55967K(2831168K),
0.1662147 secs] 3263905K->775682K(7025472K), 0.1667915 secs]
It's interesting that there's no timing data for that last statement. It
/is/ possible this is where the JVM went down. (Did it go down?)
Both of these GC runs seem to be collecting a /lot/ of garbage:
3272635K->747297K
That's a reduction of roughly 75%... though I guess in .13 seconds, it's
not taking so long, so it should be fine. I guess your webapp generates
a lot of temporary data, fast. At least it gets cleaned-up quickly.
>> Also, what happens if you remove all your *GC* options (other than
>> logging) from your JAVA_OPTS?
>
> I am quite hesitant to try this. This is a production environment, and all
> in all Tomcat is performing pretty good now, in comparison to what the
> situation was before.
Do you have a place where you can really play around with this?
> By "all" GC options, do you also mean the UseConcMarkSweepGC? Wouldn't the
> GC become serial then (with pauses which stop the whole webapp for a while)?
I don't believe the GC will do "serial" collections unless explicitly
told to do that. The days of "stop the world" garbage collection are
long gone.
> And also the +DisableExplicitGC?
That only causes the JVM to ignore calls to System.gc(), which aren't
guaranteed to do anything, anyway. Unless you are deploying unknown
webapps, this probably isn't doing anything at all.
>> Is this reproducible?
>
> Well, as I said, Tomcat is working much more stable now than it did before.
> However, once in a few days it still becomes unresponsive, while CPU usage
> stays incredibly low. I have tried load tests using jMeter on our
> development environment, but it's working fine then. Must have something to
> do with the "real" (more diverse, less predictable/repetitive) traffic on
> the production environment, I guess..
I'd be interested in what a thread dump shows you during one of these
pauses. I agree with Dan: this sounds much more like your webapp is
waiting around for something like a db connection than doing anything
active. If the GC were running like crazy, I suspect you'd see more CPU
usage.
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEUEARECAAYFAktojf4ACgkQ9CaO5/Lv0PAcAwCWJdL0fddltpbT4xliEY3Cgiqc
3QCfYE4EvIedEbFtQnGWVbij29Oz234=
=rVYe
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Tomcat 100% CPU usage after moving from Java 5 to 6
Posted by Jesse Klaasse <je...@indicia.nl>.
Christopher Schultz-2 wrote:
>
> Can you give us a timestamp for when the trouble started? Reading GC
> output is pretty tedious.
>
I believe the trouble started around 15 - 20 minutes before the end of the
gc log, so that would be from ~61h36m.
Christopher Schultz-2 wrote:
>
> Also, what happens if you remove all your *GC* options (other than
> logging) from your JAVA_OPTS?
>
I am quite hesitant to try this. This is a production environment, and all
in all Tomcat is performing pretty good now, in comparison to what the
situation was before.
By "all" GC options, do you also mean the UseConcMarkSweepGC? Wouldn't the
GC become serial then (with pauses which stop the whole webapp for a while)?
And also the +DisableExplicitGC?
Christopher Schultz-2 wrote:
>
> Is this reproducible?
>
Well, as I said, Tomcat is working much more stable now than it did before.
However, once in a few days it still becomes unresponsive, while CPU usage
stays incredibly low. I have tried load tests using jMeter on our
development environment, but it's working fine then. Must have something to
do with the "real" (more diverse, less predictable/repetitive) traffic on
the production environment, I guess..
--
View this message in context: http://old.nabble.com/Tomcat-100--CPU-usage-after-moving-from-Java-5-to-6-tp27305110p27416818.html
Sent from the Tomcat - User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Tomcat 100% CPU usage after moving from Java 5 to 6
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Jesse,
On 2/1/2010 5:22 AM, Jesse Klaasse wrote:
>
> In the meantime, the environment has been much more stable than it was before
> the move to Java 6 and the new JVM options. However, a few minutes ago,
> Tomcat became completely unresponsive, while the CPU usage was very low
> (~3%). This was on our external server, with these options:
>
> -Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory
> -Dcom.sun.management.jmxremote -XX:MaxPermSize=512m
> -Xloggc:D:\logs\gc\tomcat-gc.log -XX:+PrintGCDetails -XX:+UseConcMarkSweepGC
> -XX:+CMSClassUnloadingEnabled -XX:+DisableExplicitGC -XX:NewSize=3072m
> -XX:+UseCompressedOops -Xms7168m -Xmx7168m
>
> The gc log is showing a lot of activity during the unresponsiveness (the gc
> log is attached to this message). Do you guys see any clues? Thanks in
> advance!
Can you give us a timestamp for when the trouble started? Reading GC
output is pretty tedious.
Also, what happens if you remove all your *GC* options (other than
logging) from your JAVA_OPTS?
Is this reproducible?
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAktnFpsACgkQ9CaO5/Lv0PCLVgCdHzgBFn2cWkBhYpRgIbHHX1jV
GqsAnjYuakiGzdELRgMEmzNGxKu8fIR+
=sPnf
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org