tag:blogger.com,1999:blog-7735872642513631302.post6168969665138785414..comments2023-07-15T17:54:51.492+01:00Comments on Alexey Ragozin: Understanding GC pauses in JVM, HotSpot's CMS collector.Alexey Ragozinhttp://www.blogger.com/profile/13720493857045012756noreply@blogger.comBlogger9125tag:blogger.com,1999:blog-7735872642513631302.post-52046803219578292902017-05-18T15:15:31.279+01:002017-05-18T15:15:31.279+01:00Fragmentation would cause a Full GC, but in your l...Fragmentation would cause a Full GC, but in your logs it looks like concurrent GC. If you are using JMX it is using RMI under hood.Alexey Ragozinhttps://www.blogger.com/profile/13720493857045012756noreply@blogger.comtag:blogger.com,1999:blog-7735872642513631302.post-85360910400322109442017-05-18T08:31:19.080+01:002017-05-18T08:31:19.080+01:00No, I don't set the -Dsun.rmi.dgc.server.gcIn...No, I don't set the -Dsun.rmi.dgc.server.gcInterval option。Full gc happened once a day and we don't use RMI function。 I suspect The Fullgc was caused by old space fragmentation. Application was allocate a big array (about 1G bytes) when the fullgc happened.<br />Anonymoushttps://www.blogger.com/profile/03608740144688296827noreply@blogger.comtag:blogger.com,1999:blog-7735872642513631302.post-66911755922720998822017-05-17T19:10:37.427+01:002017-05-17T19:10:37.427+01:00You have -XX:+ExplicitGCInvokesConcurrent option e...You have -XX:+ExplicitGCInvokesConcurrent option enabled. This GC may have been triggered by System.gc(). RMI is common culprit here, do you have -Dsun.rmi.dgc.server.gcInterval option?Alexey Ragozinhttps://www.blogger.com/profile/13720493857045012756noreply@blogger.comtag:blogger.com,1999:blog-7735872642513631302.post-67045711312868563122017-05-17T09:41:32.632+01:002017-05-17T09:41:32.632+01:00this is my gc log :
"2017-05-13T10:51:22.981+...this is my gc log :<br />"2017-05-13T10:51:22.981+0800: 161814.005: [GC2017-05-13T10:51:22.981+0800: 161814.005: [Class Histogram (before full gc):<br />2017-05-13T10:51:25.395+0800: 161816.419: [CMS[YG occupancy: 2702192 K (3584000 K)]2017-05-13T10:51:28.026+0800: 161819.051: [weak refs processing2017-05-13T10:51:28.026+0800: 161819.051: [SoftReference, 21 refs, 0.0008800 secs]2017-05-13T10:51:28.027+0800: 161819.052: [WeakReference, 961 refs, 0.0005750 secs]2017-05-13T10:51:28.028+0800: 161819.052: [FinalReference, 241 refs, 0.0006460 secs]2017-05-13T10:51:28.028+0800: 161819.053: [PhantomReference, 0 refs, 3 refs, 0.0010360 secs]2017-05-13T10:51:28.030+0800: 161819.054: [JNI Weak Reference, 0.0003030 secs], 0.0035570 secs]2017-05-13T10:51:28.030+0800: 161819.054: [class unloading, 0.0266950 secs]2017-05-13T10:51:28.057+0800: 161819.081: [scrub symbol table, 0.0060380 secs]2017-05-13T10:51:28.063+0800: 161819.087: [scrub string table, 0.0009950 secs]: 4142448K->4135557K(8192000K), 3.1914830 secs]2017-05-13T10:51:28.586+0800: 161819.611: [Class Histogram (after full gc):<br />Heap after GC invocations=5935 (full 10):<br />par new generation total 3584000K, used 2702192K [0x000000050a000000, 0x0000000604000000, 0x0000000604000000)<br /> eden space 3072000K, 87% used [0x000000050a000000, 0x00000005ae7ad0e8, 0x00000005c5800000)<br /> from space 512000K, 1% used [0x00000005c5800000, 0x00000005c5f2ef48, 0x00000005e4c00000)<br /> to space 512000K, 0% used [0x00000005e4c00000, 0x00000005e4c00000, 0x0000000604000000)<br />concurrent mark-sweep generation total 8192000K, used 4135557K [0x0000000604000000, 0x00000007f8000000, 0x00000007f8000000)<br />concurrent-mark-sweep perm gen total 131072K, used 68094K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)<br />}<br />{Heap before GC invocations=5935 (full 10):<br />par new generation total 3584000K, used 2702192K [0x000000050a000000, 0x0000000604000000, 0x0000000604000000)<br /> eden space 3072000K, 87% used [0x000000050a000000, 0x00000005ae7ad0e8, 0x00000005c5800000)<br /> from space 512000K, 1% used [0x00000005c5800000, 0x00000005c5f2ef48, 0x00000005e4c00000)<br /> to space 512000K, 0% used [0x00000005e4c00000, 0x00000005e4c00000, 0x0000000604000000)<br />concurrent mark-sweep generation total 8192000K, used 4135557K [0x0000000604000000, 0x00000007f8000000, 0x00000007f8000000)<br />concurrent-mark-sweep perm gen total 131072K, used 68094K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)<br />2017-05-13T10:51:30.778+0800: 161821.803: [Full GC2017-05-13T10:51:30.778+0800: 161821.803: [Class Histogram (before full gc):<br />2017-05-13T10:51:33.004+0800: 161824.028: [CMS2017-05-13T10:51:33.822+0800: 161824.846: [SoftReference, 1437 refs, 0.0002190 secs]2017-05-13T10:51:33.822+0800: 161824.847: [WeakReference, 4480 refs, 0.0002930 secs]2017-05-13T10:51:33.822+0800: 161824.847: [FinalReference, 32 refs, 0.0000160 secs]2017-05-13T10:51:33.822+0800: 161824.847: [PhantomReference, 0 refs, 24 refs, 0.0000120 secs]2017-05-13T10:51:33.822+0800: 161824.847: [JNI Weak Reference, 0.0003360 secs]: 4135557K->4137966K(8192000K), 3.8480810 secs]2017-05-13T10:51:36.852+0800: 161827.877: [Class Histogram (after full gc):<br />6837749K->4137966K(11776000K), [CMS Perm : 68094K->68052K(131072K)], 6.6932460 secs] [Times: user=6.49 sys=0.00, real=6.70 secs<br />"<br />CMS threshold is 65%.In my opinion, CMS will be triggered Only if old space occupation is greater than 8192000K* 65%= 5324800K .From the gc log ,when CMS gc was triggered ,old space occupation is 4135557K . What's the reason ? Thank you very much ! Anonymoushttps://www.blogger.com/profile/03608740144688296827noreply@blogger.comtag:blogger.com,1999:blog-7735872642513631302.post-7785292459244291992017-05-17T09:41:05.731+01:002017-05-17T09:41:05.731+01:00hi, Alexey, thank you for your help . Could you he...hi, Alexey, thank you for your help . Could you help me to analyze the reason of CMS gc,which is triggered by minor gc ? <br />This is my jvm command : <br /> "CommandLine flags: -XX:CICompilerCount=4 -XX:+CMSClassUnloadingEnabled -XX:CMSFullGCsBeforeCompaction=2 -XX:CMSInitiatingOccupancyFraction=65 -XX:+CMSParallelRemarkEnabled -XX:+CMSScavengeBeforeRemark -XX:CMSWaitDuration=60000 -XX:ErrorFile=/opt/logs/mobile/adsms/adsms.vmerr.log -XX:+ExplicitGCInvokesConcurrent -XX:HeapDumpPath=/opt/logs/mobile/adsms/adsms.heaperr.log -XX:InitialHeapSize=12582912000 -XX:MaxHeapSize=12582912000 -XX:MaxTenuringThreshold=15 -XX:NewRatio=2 -XX:OldPLABSize=16 -XX:+ParallelRefProcEnabled -XX:PermSize=134217728 -XX:PretenureSizeThreshold=309857600 -XX:+PrintClassHistogramAfterFullGC -XX:+PrintClassHistogramBeforeFullGC -XX:+PrintFlagsFinal -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+PrintJNIGCStalls -XX:+PrintReferenceGC -XX:+PrintTenuringDistribution -XX:StringTableSize=30011 -XX:SurvivorRatio=6 -XX:+TieredCompilation -XX:-UseBiasedLocking -XX:+UseCMSCompactAtFullCollection -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC"<br /><br />to be continued<br />Anonymoushttps://www.blogger.com/profile/03608740144688296827noreply@blogger.comtag:blogger.com,1999:blog-7735872642513631302.post-84989989349977640332017-05-16T18:42:18.910+01:002017-05-16T18:42:18.910+01:00Direct allocation in old space would increase old ...Direct allocation in old space would increase old space occupation and may exceed threshold. In Java 7 and below, concurrent cycle could be also triggered by allocation in Perm gen, which also has occupancy threshold.Alexey Ragozinhttps://www.blogger.com/profile/13720493857045012756noreply@blogger.comtag:blogger.com,1999:blog-7735872642513631302.post-91455163731002362642017-05-16T11:20:13.693+01:002017-05-16T11:20:13.693+01:00hi, Alexey
"But in certain cases object may ...hi, Alexey <br />"But in certain cases object may be allocated directly in old space and CMS cycle could start while Eden has lots of objects. " Does it mean that CMS gc will trigger even olds space occupation is less than 70% <br /> ? ‑XX:+UseCMSInitiatingOccupancyOnly ‑XX:CMSInitiatingOccupancyFraction=70Anonymoushttps://www.blogger.com/profile/03608740144688296827noreply@blogger.comtag:blogger.com,1999:blog-7735872642513631302.post-44878996050610375382011-12-30T09:31:19.718+00:002011-12-30T09:31:19.718+00:00Hi,
Which JVM version are you talking about?
-XX...Hi,<br /><br />Which JVM version are you talking about?<br /><br />-XX:ParallelCMSThreads -XX:ParallelMarkingThread<br />are not recognized by JVM 1.7 and 1.6 (at least since u24)<br /><br />-AlexeyAlexey Ragozinhttps://www.blogger.com/profile/13720493857045012756noreply@blogger.comtag:blogger.com,1999:blog-7735872642513631302.post-52045900655518156672011-12-22T16:30:16.880+00:002011-12-22T16:30:16.880+00:00Hi Alexey,
‑XX:ConcGCThreads= is not supported by...Hi Alexey,<br /><br />‑XX:ConcGCThreads= is not supported by using -XX: command option, instead, it's set programmatically by using -XX:ParallelCMSThreads or -XX:ParallelMarkingThread=<br /><br />-Baihao YuanAnonymousnoreply@blogger.com