> On 30 Aug 2017, at 16:38, Suvendu Sekhar Mondal <suv3...@gmail.com> wrote: > > > In Hotspot VM, Full GC will collect "dead" objects/classes from all > the regions(Young, Old, Metaspace/PermGen). In the provided GC log, I > can see that you had triggered Full GCs but Metaspace did not shrunk > much. That clearly indicates you had good number of classes that were > "in use": > > 48318.001: [Full GC (Heap Dump Initiated GC) 5232M->1298M(20G), 4.9784080 > secs] > [Eden: 2800.0M(3136.0M)->0.0B(9616.0M) Survivors: 120.0M->0.0B > Heap: 5232.7M(20.0G)->1298.9M(20.0G)], [Metaspace: > 1419958K->1398648K(2621440K)] > [Times: user=9.55 sys=0.09, real=4.98 secs] > 48404.270: [Full GC (System.gc()) 2825M->1301M(20G), 4.3863751 secs] > [Eden: 1528.0M(9616.0M)->0.0B(9616.0M) Survivors: 0.0B->0.0B Heap: > 2825.2M(20.0G)->1301.6M(20.0G)], [Metaspace: > 1425628K->1425623K(2627584K)] > [Times: user=9.09 sys=0.15, real=4.38 secs] > > Sometimes Full GC were able to clean up some space from Metaspace but > only as part of a final last ditch collection effort: > > 43618.504: [Full GC (Last ditch collection) 1386M->250M(20G), 1.6455823 secs] > [Eden: 0.0B(6408.0M)->0.0B(6408.0M) Survivors: 0.0B->0.0B Heap: > 1386.7M(20.0G)->250.5M(20.0G)], [Metaspace: > 1646471K->163253K(1843200K)] > [Times: user=2.23 sys=0.10, real=1.65 secs] > 49034.392: [Full GC (Last ditch collection) 1491M->347M(20G), 1.9965534 secs] > [Eden: 0.0B(5600.0M)->0.0B(5600.0M) Survivors: 0.0B->0.0B Heap: > 1491.1M(20.0G)->347.9M(20.0G)], [Metaspace: > 1660804K->156199K(2031616K)] > [Times: user=2.78 sys=0.10, real=2.00 secs]
This is interesting because I see this pattern for metaspace gc… https://ibb.co/b2B9HQ there’s something that clears it but it seems it’s not the full gc. I don’t think there’s something that happens in the app that causes that much metaspace space to become instantly dead. So I think the full gc is not doing the metaspace cleaning the way it could do it. Maybe it’s a light clean… >>>> Tomcat is running with these VM options: >>>> >>>> -Xms20480m -Xmx20480m -Dsun.rmi.dgc.client.gcInterval=3600000 >>>> -Dsun.rmi.dgc.server.gcInterval=3600000 -Xloggc:/tmp/gc.txt >>>> -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=9012 >>>> -Dcom.sun.management.jmxremote.ssl=false >>>> -Dcom.sun.management.jmxremote.authenticate=false -XX:+PrintGCDetails >>>> -XX:+PrintGCTimeStamps -XX:+UseG1GC -XX:ReservedCodeCacheSize=1g >>>> -XX:InitialCodeCacheSize=256m -XX:+UseHugeTLBFS -XX:MetaspaceSize=1g >>>> -XX:MaxMetaspaceSize=2g >>>> >>>> Some of the options have been recently added (for example the increase in >>>> code cache size) but it seems they had no impact on the issue. >>>> >>> >>> Is there any specific reason to trigger Full GC every >>> 60min(-Dsun.rmi.dgc.client.gcInterval=3600000)? I think that's >>> overkill. >> >> That’s a value I saw “everywhere” as suggested value (the default is too >> short). Note that on the GC logs I don’t see full GCs every hour so maybe >> that option is not triggering full gc ? > > That's is the default value. Please see: > http://docs.oracle.com/javase/8/docs/technotes/guides/rmi/sunrmiproperties.html > > <http://docs.oracle.com/javase/8/docs/technotes/guides/rmi/sunrmiproperties.html> They must have changed it recently, it was 180k when I first checked that option. Do you think it’s worth to increase it ? I don’t see a full gc every hour… Thanks
