Posted by cxcgoard
on April 6, 2010 at 3:12 PM PDT
Hello. We are having a problem with minor GC pauses, and we are hoping somebody might be able to provide some insight.
Occasionally, we have a minor GC which itself only takes a couple of milliseconds, but which can stop all application threads for orders of magnitude longer, as reported by PrintGCApplicationStoppedTime, and as observed externally. These events are isolated, the preceding and succeeding minor collections not having this delay.
Below is a log snippet illustrating the problem.
485314.676: [GC 485314.676: [ParNew: 105774K->885K(118016K), 0.0025400 secs] 136315K->31532K(1035520K), 0.0025990 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
Total time for which application threads were stopped: 0.0030830 seconds
485377.257: [GC 485378.857: [ParNew: 105845K->621K(118016K), 0.0028070 secs] 136492K->31374K(1035520K), 0.0028720 secs] [Times: user=0.01 sys=0.00, real=1.61 secs]
Total time for which application threads were stopped: 1.6032830 seconds
485448.282: [GC 485448.282: [ParNew: 105581K->701K(118016K), 0.0033700 secs] 136334K->31565K(1035520K), 0.0034310 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
Total time for which application threads were stopped: 0.0039300 seconds
GenCollectForAllocation [ 78 0 0] [ 0 0 0] [ 2 43996] 0
GenCollectForAllocation [ 78 0 0] [ 0 0 0] [ 1603 16565] 0
GenCollectForAllocation [ 78 0 1] [ 0 0 0] [ 3 27583] 0
The machines on which we are observing this behaviour are dedicated to the JVM, each has 8 CPU cores, plenty of unused RAM, and is running Red Hat Enterprise Linux ES Release 4 Update 8 with kernel 2.6.9-89.0.1EL-smp. We have observed this with JVM versions 1.6.0_13 and 1.6.0_18.
What are some possible explanations for this behaviour?