We have observed that full garbage collections (GCs) are often performed on an hourly basis.
Checked the time intreval of JreMemoryLeakPreventionListener. it is set to Long.MAX_VALUE. though gc is running every hour.
Also observed that GC called hourly basis is an explicit GC
GC logs:
2016-10-15T23:23:09.341-0400: 165558.099: [GC (System.gc()) [PSYoungGen: 264601K->5865K(1357312K)] 389672K->130937K(4153856K), 0.0075210 secs] [Times: user=0.07 sys=0.00, real=0.00 secs]
2016-10-15T23:23:09.349-0400: 165558.107: [Full GC (System.gc()) [PSYoungGen: 5865K->0K(1357312K)] [ParOldGen: 125071K->125178K(2796544K)] 130937K->125178K(4153856K) [PSPermGen: 72263K->72263K(131072K)], 0.3417940 secs] [Times: user=5.16 sys=0.04, real=0.35 secs]
2016-10-16T00:23:09.692-0400: 169158.450: [GC (System.gc()) [PSYoungGen: 198858K->2600K(1354752K)] 324037K->127779K(4151296K), 0.0077680 secs] [Times: user=0.08 sys=0.01, real=0.01 secs]
2016-10-16T00:23:09.700-0400: 169158.458: [Full GC (System.gc()) [PSYoungGen: 2600K->0K(1354752K)] [ParOldGen: 125178K->124436K(2796544K)] 127779K->124436K(4151296K) [PSPermGen: 72282K->72282K(131072K)], 0.3481690 secs] [Times: user=5.13 sys=0.03, real=0.35 secs]
2016-10-16T01:23:10.050-0400: 172758.808: [GC (System.gc()) [PSYoungGen: 279139K->7990K(1361408K)] 403576K->132426K(4157952K), 0.0075860 secs] [Times: user=0.07 sys=0.00, real=0.01 secs]
2016-10-16T01:23:10.058-0400: 172758.815: [Full GC (System.gc()) [PSYoungGen: 7990K->0K(1361408K)] [ParOldGen: 124436K->124383K(2796544K)] 132426K->124383K(4157952K) [PSPermGen: 72284K->72284K(131072K)], 0.3713300 secs] [Times: user=5.73 sys=0.04, real=0.37 secs]
2016-10-16T02:23:10.430-0400: 176359.188: [GC (System.gc()) [PSYoungGen: 112842K->544K(1358848K)] 237225K->124927K(4155392K), 0.0167260 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
2016-10-16T02:23:10.447-0400: 176359.205: [Full GC (System.gc()) [PSYoungGen: 544K->0K(1358848K)] [ParOldGen: 124383K->124265K(2796544K)] 124927K->124265K(4155392K) [PSPermGen: 72292K->72292K(131072K)], 0.2931430 secs] [Times: user=3.21 sys=0.03, real=0.29 secs]
2016-10-16T03:23:10.742-0400: 179959.500: [GC (System.gc()) [PSYoungGen: 117926K->768K(1363968K)] 242192K->125033K(4160512K), 0.0070720 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2016-10-16T03:23:10.749-0400: 179959.507: [Full GC (System.gc()) [PSYoungGen: 768K->0K(1363968K)] [ParOldGen: 124265K->124263K(2796544K)] 125033K->124263K(4160512K) [PSPermGen: 72306K->72306K(131072K)], 0.2602180 secs] [Times: user=3.33 sys=0.02, real=0.26 secs]
2016-10-16T04:23:11.011-0400: 183559.768: [GC (System.gc()) [PSYoungGen: 198248K->2356K(1362432K)] 322511K->126619K(4158976K), 0.0076610 secs] [Times: user=0.07 sys=0.00, real=0.01 secs]
2016-10-16T04:23:11.018-0400: 183559.776: [Full GC (System.gc()) [PSYoungGen: 2356K->0K(1362432K)] [ParOldGen: 124263K->124978K(2796544K)] 126619K->124978K(4158976K) [PSPermGen: 72308K->72308K(131072K)], 0.3353340 secs] [Times: user=5.78 sys=0.04, real=0.33 secs]
2016-10-16T05:23:11.355-0400: 187160.113: [GC (System.gc()) [PSYoungGen: 228778K->10333K(1367040K)] 353757K->135311K(4163584K), 0.0069470 secs] [Times: user=0.08 sys=0.00, real=0.00 secs]
2016-10-16T05:23:11.362-0400: 187160.120: [Full GC (System.gc()) [PSYoungGen: 10333K->0K(1367040K)] [ParOldGen: 124978K->130352K(2796544K)] 135311K->130352K(4163584K) [PSPermGen: 72308K->72308K(131072K)], 0.2240270 secs] [Times: user=2.96 sys=0.02, real=0.23 secs]
Tomcat Version : Apache Tomcat/8.0.24
# /opt/tomcat/bin/version.sh
Using CATALINA_BASE: /opt/tomcat
Using CATALINA_HOME: /opt/tomcat
Using CATALINA_TMPDIR: /opt/tomcat/temp
Using JRE_HOME: /usr
Using CLASSPATH: /opt/hbase/conf:/opt/tomcat/bin/bootstrap.jar:/opt/tomcat/bin/tomcat-juli.jar
Server version: Apache Tomcat/8.0.24
Server built: Jul 1 2015 20:19:55 UTC
Server number: 8.0.24.0
OS Name: Linux
OS Version: 2.6.32-573.3.1.el6.x86_64
Architecture: amd64
JVM Version: 1.7.0_79-b15
JVM Vendor: Oracle Corporation
Why GC is running on hourly basis even though the heap is not full?
I suspect this is a duplicate but can't find it.
The default period for the DGC (Distributed GC) is 1 hour. This runs regularly to clean up distributed RMI resources such as JMX.
You can lengthen the cycle to a week.
https://docs.oracle.com/javase/8/docs/technotes/guides/rmi/sunrmiproperties.html
see
sun.rmi.dgc.server.gcInterval
When it is necessary to ensure that unreachable remote objects are unexported and garbage collected in a timely fashion, the value of this property represents the maximum interval (in milliseconds) that the Java RMI runtime will allow between garbage collections of the local heap. The default value is 3600000 milliseconds (one hour).
and
sun.rmi.dgc.client.gcInterval
When it is necessary to ensure that DGC clean calls for unreachable remote references are delivered in a timely fashion, the value of this property represents the maximum interval (in milliseconds) that the Java RMI runtime will allow between garbage collections of the local heap. The default value is 3600000 milliseconds (one hour).
Both of these have to be set to a high number (I set it to a week)
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With