On 15-Nov-16 11:45 PM, john.e.gr...@wellsfargo.com wrote:
-----Original Message-----
From: George I. Develekos [mailto:gdevele...@omilia.com]
Sent: Tuesday, November 15, 2016 3:00 PM
To: users@tomcat.apache.org
Subject: Re: Please help with Tomcat Garbage Collection
The system does very little swapping, both when it's GC'ing and when it's not.
Less than 100MB worth of swap is taken.
Giving Tomcat its own HW is not an option at this time, especially as there's no
guarantee it'll solve the problem. Besides it would be a VM anyway, not physical
dedicated HW. The current server is also a VM.
On 15-Nov-16 10:55 PM, Zdeněk Henek wrote:
I would start with moving this tomcat to its own hw.
Did you check swap? This long pauses could be because part of your
heap is swapped to hdd
Regards,
Zdenek Henek
On Tue, Nov 15, 2016, 21:37 George I. Develekos
<gdevele...@omilia.com>
wrote:
On 15-Nov-16 10:22 PM, Christopher Schultz wrote:
George,
On 11/15/16 10:46 AM, George I. Develekos wrote:
Hello guys,
We are having problems on a production system with very long "full
GC" times, as long as1200sec real time (!!!).
We are using Java 6 (stuck with CentOS 5.8 at this time) and Tomcat
7.0.64.
Xmx is 5G, Xms is 2G, and GC options are -XX:+UseConcMarkSweepGC
-XX:+CMSIncrementalMode
No other custom memory-related settings are in place.
Looking at the GC log, the last few Full-GC entries are:
1367.020: [Full GC 1367.020: [CMS: 1178831K->527456K(1926784K),
2.1117220 secs] 1250378K->527456K(2080128K), [CMS Perm :
169762K->56187K(169984K)] icms_dc=0 , 2.1118160 secs] [Times:
user=1.96 sys=0.13, real=2.11 secs]
2579.317: [Full GC 2579.317: [CMS2581.876: [CMS-concurrent-mark:
2.558/1212.733 secs] [*Times: user=113.05 sys=28.01,
real=**1212.49 **secs] ** * 3539.969: [Full GC 3539.969:
[CMS3540.056: [CMS-concurrent-sweep: 1.571/23.223 secs] [Times:
user=6.12 sys=1.36, real=*23.21 secs*]
4070.456: [Full GC 4070.457: [CMS: 1252569K->591200K(1926784K),
2.3447040 secs] 1270617K->591200K(2080128K), [CMS Perm :
169983K->56598K(169984K)] icms_dc=0 , 2.3448140 secs] [Times:
user=2.18 sys=0.14, real=2.34 secs]
What can we do?
1367.020 Full GC duration=2.11s
2579.317 Full GC duration=1212.49s
So your full GC immediately started another full GC that took 20
minutes ?
Are you only showing certain FULL GC activity from your log, or is
that everything?
CMS should have a mark and then a sweep each time, but your times
don't seem to add up.
also note that the whole point of CMS is that there isn't any
stop-the-world during the mark portion of the process.
Are you actually experiencing a problem, or are you just suffering
from instrumentor's remorse?
- -chris
Chris,
What I listed is the result of the command:
grep "Full GC" gc.log
So (obviously) I have skipped other GC activity, i.e. whatever GC
activity didn't include the "Full GC" string.
Yes we are having app trouble due to the GC delays so this is a real
problem. Our application has real-time constraints so the GC delays
cannot be tolerated. I selected those GC options _in order to avoid
_long GC times.
Additionally, these periods coincide with high CPU for that JVM
process. From 5-20% CPU where it is normally, it jumps to 60% ore more.
Once GC is done, our app rushes to catch up with tasks that had to
wait for GC to finish.
Answering another question from a member who has kindly responded,
yes the server is running other stuff. Basically it runs three
tomcats, the main one being this one. It also runs a DB2 database
that has close-to-zero activity.
George
It might be helpful if you could post a larger chunk of your GC log, at least
long enough to cover the start and end of the CMS phases and maybe even more.
Additionally, try using a tool like GCViewer to analyze the log.
How many CPUs do you have? 60% CPU usage isn't usually a big deal.
Like Chris already said, this is not a stop-the-world phase, so your
application should continue working in parallel with the garbage collector.
Looks like your young generation is only 150MB (2080128k - 1926784k.) That's
very small for a 2-5GB heap. Are you explicitly setting it somewhere or is the
JVM choosing that for you? It's so small that your old generation might be
filling up faster that it should, leading to more frequent full collections.
You could try setting the young generation to something like 25-50% of the
total heap. You'd get a lot of small pauses as the young gen is collected but
fewer long ones.
John
John,
I have a couple of cores. One would be enough for what the server does.
I'll post a larger log chunk tomorrow. I'll look into GCViewer, thanks.
I don't set the young gen, It's selected by the JVM. I don't even know
what that is, to be honest. I do too many things for my company to know
such esoteric things about each one of them. Server admin, network
admin, DB admin, all admin....
Nevertheless, if setting the Young gen makes GC less frequent it won't
really help, because still I'll have periods of "crisis", just not as
frequently. Ideally I want to keep Full-GC under 3sec, and from what
I've read it's a realistic goal.
Looking at application logs, it looks like app tasks DO stop running
during Full-GC.
---
This email has been checked for viruses by Avast antivirus software.
https://www.avast.com/antivirus
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
