Full Garbage Collection every 62 seconds

, ,
1

We have Solaris 10 Sparc, Sun JVM 1.4.2_17 and Oracle 10g non-RAC (on Solaris).
webMethods Clustered(2 nodes) 65 SP3, wMPRT6-5-1_SP1 (base wM packages only)

MIN/MAX memory = 1024MB on both nodes

We see that the Full GC is getting created every 62 seconds or so…

Example:

103946.512: [Full GC 103946.513: [Tenured: 10274K->10332K(932096K), 1.2073948 secs] 10910K->10332K(1045184K), [Perm : 27106K->27106K(27136K)], 1.2075708 secs]

104007.858: [Full GC 104007.859: [Tenured: 10332K->10528K(932096K), 0.8247412 secs] 12745K->10528K(1045184K), [Perm : 27106K->27106K(27136K)], 0.8248932 secs]

104068.742: [Full GC 104068.742: [Tenured: 10528K->10259K(932096K), 0.5669642 secs] 11160K->10259K(1045184K), [Perm : 27106K->27106K(27136K)], 0.5671070 secs]

Any thoughts are welcome…(I am interested to see what Mark carlson and otehr gurus say…)

Thanks,
– Rocky

2

What are your JVM startup parms related to mem management?

3

That behavior may be perfectly normal depending on the workload. So long as the pauses during collections are manageable and memory is being freed correctly the JVM may be doing exactly what it needs to be doing based on how much memory you’ve given it to work with and the work you are asking IS to perform.

Yes, as Rob asked, what JVM GC parameters are being set in startup.sh? How much physical memory is available on the box?

Mark

4

Hi,

Do you mean that you have only Full GC(major collection) going on and their are no minor collection happening ?

If Yes , then if the Pauses caused by major collection is bearable then you shouldnt worry too much about it and should let JVM do its work. If you are getting very long pause and its affecting overall performance then I think before changes any defauts collectors/parameters you should closely monitor your system, verbose logs, different conditions in which you see this behavior.

Also check if you are not calling any System.GC() is your java code as this call would do a major collection and generally its not a good idea to call system.gc(correct me if I am wrong)

http://java.sun.com/docs/hotspot/gc5.0/gc_tuning_5.html explains the working of GC with different options.

Jiten

5

This TEST instance has bare webMethods packages (no custom packages). Also, I tried starting up using “safeboot” feature (just WmRoot). Same results - 62 seconds.

Here are the param details…

JAVA_MIN_MEM=1024M
JAVA_MAX_MEM=1024M
JAVA_MEMSET=“-ms${JAVA_MIN_MEM} -mx${JAVA_MAX_MEM}”
JAVA_ARG1=“-XdoCloseWithReadPending”
JAVA_OPTIONS=“${JAVA_OPTIONS} -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:logs/gc.log”

6

This is an interesting question – During initial server startup, the collections are both major and minor. After startup, its just Full GC every 62 seconds (like a trigger, very consistent).
NOTE: This clustered instance has only bare wM packages. So, the use of system.gc() or custom Java collection doesn’t apply here (I only wish if -LOL-)

As for pauses, let me get back to you on the specific number. I have to take a read on how to get it.

7

only WmRoot package active - regular server mode (not safeboot).

Here are the pauses numbers:

Acc pauses: 47.2 sec
Acc full GC: 47.08 sec (99.7%)
Acc GC: 0.12 sec (0.3%)
Min pause: 0.1187 sec
Max pause: 2.91438 sec

Are these numbers normal ?

8

Hi,

If you have only bare minimum webMethods packages and you are not executing anything, thn why are you so much worried about GC logs. Are you getting out of memory error or somthing.

Their no such things like normal and as mark pointed out “behavior may be perfectly normal depending on the workload”. Even if you not executing anything Integration server creates object for its own execution, pools, external connection etc and this objects are collected once they are not referenced.

Jiten

9

Rocky,

I’ve recently ran into the same issue. I got the following explanation from a fellow colleague:

Hope this helps,
Percio