Mailing-List: contact users-help@tomcat.apache.org; run by ezmlm
Precedence: bulk
Reply-To: "Tomcat Users List" <users@tomcat.apache.org>
Received-SPF: neutral (nike.apache.org: local policy)
Message-ID: <4B688DFE.6090608@christopherschultz.net>
Date: Tue, 02 Feb 2010 15:41:34 -0500
From: Christopher Schultz <chris@christopherschultz.net>
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US;
 rv:1.9.1.7) Gecko/20100111 Thunderbird/3.0.1
MIME-Version: 1.0
To: Tomcat Users List <users@tomcat.apache.org>
Subject: Re: Tomcat 100% CPU usage after moving from Java 5 to 6
References: <2A999A47A42ED94185DCE3BE09C3938E05CBE121@AURORA.nl.indicia.org>
 <4B5D7CF9.4070908@pidster.com>
 <327858f41001250331h1eb19359h3afee56d8a25e5c0@mail.gmail.com>
 <27305988.post@talk.nabble.com> <27306041.post@talk.nabble.com>
 <327858f41001250501y660b837dr6a387a918d11fa1c@mail.gmail.com>
 <27306543.post@talk.nabble.com> <27319482.post@talk.nabble.com>
 <99C8B2929B39C24493377AC7A121E21F96841B3D26@USEA-EXCH8.na.uis.unisys.com>
 <27324793.post@talk.nabble.com>
 <327858f41001260944g720a8b4bvfa1186daa07ad3cb@mail.gmail.com>
 <e0c148a1001260951s345fa11eg51caf611f058f0ed@mail.gmail.com>
 <27402032.post@talk.nabble.com> <4B67169B.90608@christopherschultz.net>
 <27416818.post@talk.nabble.com>
In-Reply-To: <27416818.post@talk.nabble.com>
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

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