JVM(十四)visualVM使用分析GC日志,OOM
1:关于visualVM的使用介绍
参见:https://www.cnblogs.com/krock/p/14419459.html
2:测试
环境:jdk1.8, window
1)Metaspace OOM
测试代码:
![](https://images.cnblogs.com/OutliningIndicators/ContractedBlock.gif)
public static void main(String[]args) { while (true) { try { Thread.sleep(10); } catch (InterruptedException e) { e.printStackTrace(); } Enhancer enhancer = new Enhancer(); enhancer.setSuperclass(MytestwebApplicationTests.class); enhancer.setUseCache(false); enhancer.setCallback(new MethodInterceptor() { public Object intercept(Object obj, Method method, Object[] args, MethodProxy proxy) throws Throwable { return proxy.invokeSuper(obj, args); } }); long initialHeapSize = Runtime.getRuntime().totalMemory(); long maxHeapSize = Runtime.getRuntime().maxMemory(); /*System.out.println("-Xms = " + initialHeapSize / 1024 + "kb or " + initialHeapSize / 1024 / 1024 + "mb"); System.out.println("-Xmx = " + maxHeapSize / 1024 + "kb or " + maxHeapSize / 1024 / 1024 + "mb"); */ System.out.println("running..."); enhancer.create(); } }
JVM参数:JVM基本参数介绍参见: https://www.cnblogs.com/krock/p/14417036.html
![](https://images.cnblogs.com/OutliningIndicators/ContractedBlock.gif)
-Xms256m -Xmx256m -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:MetaspaceSize=68m -XX:MaxMetaspaceSize=68m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\indigoProject\LinkScape\testFolder\guobao\sourceFile -Xloggc:D:\indigoProject\LinkScape\testFolder\guobao\sourceFile\gc.log
运行这个程序之后,在visualVM中会自动捕获到这个线程,打开之后由于堆设置的很小,已经开始频繁发生Minor GC(新生代GC)了,博客无法上传视频,我截图两个不同时刻的图片看下,如果自己测试的话就可以明显看到,Eden反复从满到空闲,S0和S1反复切换From,To角色,Metaspace里面装载的类逐渐增加。
时刻1:
时刻2:
最后程序停止之后的图形:
执行一段时间Metaspace就报了内存不足的错误:
2)分析GC日志
去把GC日志打开看:完整日志我贴出来了
![](https://images.cnblogs.com/OutliningIndicators/ContractedBlock.gif)
Java HotSpot(TM) 64-Bit Server VM (25.171-b11) for windows-amd64 JRE (1.8.0_171-b11), built on Mar 28 2018 16:06:12 by "java_re" with MS VC++ 10.0 (VS2010) Memory: 4k page, physical 16657512k(4880600k free), swap 49163368k(22854332k free) CommandLine flags: -XX:CompressedClassSpaceSize=62914560 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\indigoProject\LinkScape\testFolder\guobao\sourceFile -XX:InitialHeapSize=268435456 -XX:MaxHeapSize=268435456 -XX:MaxMetaspaceSize=71303168 -XX:MetaspaceSize=71303168 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 5.101: [GC (Allocation Failure) [PSYoungGen: 65536K->3405K(76288K)] 65536K->3413K(251392K), 0.0126293 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 6.415: [GC (Allocation Failure) [PSYoungGen: 68941K->3432K(76288K)] 68949K->3448K(251392K), 0.0056732 secs] [Times: user=0.05 sys=0.02, real=0.01 secs] 9.191: [GC (Allocation Failure) [PSYoungGen: 68968K->5096K(76288K)] 68984K->5120K(251392K), 0.0076425 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 10.421: [GC (Allocation Failure) [PSYoungGen: 70632K->5720K(76288K)] 70656K->5752K(251392K), 0.0086860 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 12.625: [GC (Allocation Failure) [PSYoungGen: 71256K->6680K(76288K)] 71288K->6720K(251392K), 0.0105985 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 13.728: [GC (Allocation Failure) [PSYoungGen: 72216K->7324K(77312K)] 72256K->7372K(252416K), 0.0091171 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 15.693: [GC (Allocation Failure) [PSYoungGen: 76956K->4928K(78336K)] 77004K->8296K(253440K), 0.0106936 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 16.981: [GC (Allocation Failure) [PSYoungGen: 74560K->3328K(78848K)] 77928K->9032K(253952K), 0.0085366 secs] [Times: user=0.03 sys=0.02, real=0.01 secs] 18.732: [GC (Allocation Failure) [PSYoungGen: 73984K->2496K(78848K)] 79688K->9858K(253952K), 0.0073972 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 20.078: [GC (Allocation Failure) [PSYoungGen: 73152K->1600K(77824K)] 80514K->10562K(252928K), 0.0046807 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 21.494: [GC (Allocation Failure) [PSYoungGen: 71232K->848K(78336K)] 80194K->11334K(253440K), 0.0034924 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 22.789: [GC (Allocation Failure) [PSYoungGen: 70480K->768K(78336K)] 80966K->11982K(253440K), 0.0020502 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 24.130: [GC (Allocation Failure) [PSYoungGen: 70400K->816K(78336K)] 81614K->12726K(253440K), 0.0024386 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 25.435: [GC (Allocation Failure) [PSYoungGen: 70448K->672K(78336K)] 82358K->13286K(253440K), 0.0019981 secs] [Times: user=0.05 sys=0.01, real=0.00 secs] 26.782: [GC (Allocation Failure) [PSYoungGen: 70304K->704K(78336K)] 82918K->13966K(253440K), 0.0017985 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 28.012: [GC (Allocation Failure) [PSYoungGen: 70336K->704K(78336K)] 83598K->14598K(253440K), 0.0020085 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 29.202: [GC (Allocation Failure) [PSYoungGen: 70336K->672K(78336K)] 84230K->15174K(253440K), 0.0026793 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 30.360: [GC (Allocation Failure) [PSYoungGen: 70304K->704K(78848K)] 84806K->15814K(253952K), 0.0020223 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 31.494: [GC (Allocation Failure) [PSYoungGen: 71360K->672K(78848K)] 86470K->16374K(253952K), 0.0019185 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 32.613: [GC (Allocation Failure) [PSYoungGen: 71328K->640K(79360K)] 87030K->16926K(254464K), 0.0027215 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 33.801: [GC (Allocation Failure) [PSYoungGen: 72320K->672K(79360K)] 88606K->17534K(254464K), 0.0020780 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 34.946: [GC (Allocation Failure) [PSYoungGen: 72352K->680K(80384K)] 89214K->18110K(255488K), 0.0023864 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 36.077: [GC (Allocation Failure) [PSYoungGen: 73896K->640K(79872K)] 91326K->18670K(254976K), 0.0023509 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 37.287: [GC (Allocation Failure) [PSYoungGen: 73856K->608K(80896K)] 91886K->19198K(256000K), 0.0027587 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 38.478: [GC (Allocation Failure) [PSYoungGen: 74848K->672K(80384K)] 93438K->19798K(255488K), 0.0021026 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 39.557: [GC (Allocation Failure) [PSYoungGen: 74912K->640K(81408K)] 94038K->20342K(256512K), 0.0018315 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 40.650: [GC (Allocation Failure) [PSYoungGen: 75904K->608K(80896K)] 95606K->20846K(256000K), 0.0018708 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 41.698: [GC (Allocation Failure) [PSYoungGen: 75872K->608K(81920K)] 96110K->21390K(257024K), 0.0019732 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 42.799: [GC (Allocation Failure) [PSYoungGen: 76896K->576K(81408K)] 97678K->21878K(256512K), 0.0031073 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 43.892: [GC (Allocation Failure) [PSYoungGen: 76864K->672K(82432K)] 98166K->22534K(257536K), 0.0034619 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 45.120: [GC (Allocation Failure) [PSYoungGen: 77984K->608K(81920K)] 99846K->23046K(257024K), 0.0028213 secs] [Times: user=0.05 sys=0.02, real=0.00 secs] 46.233: [GC (Allocation Failure) [PSYoungGen: 77920K->576K(82944K)] 100358K->23534K(258048K), 0.0024761 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 47.381: [GC (Allocation Failure) [PSYoungGen: 78912K->544K(82432K)] 101870K->24014K(257536K), 0.0028066 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 48.389: [GC (Allocation Failure) [PSYoungGen: 78880K->608K(83456K)] 102350K->24582K(258560K), 0.0024857 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 48.498: [GC (Metadata GC Threshold) [PSYoungGen: 24595K->224K(82944K)] 48569K->24694K(258048K), 0.0024885 secs] [Times: user=0.00 sys=0.02, real=0.00 secs] 48.500: [Full GC (Metadata GC Threshold) [PSYoungGen: 224K->0K(82944K)] [ParOldGen: 24470K->23707K(175104K)] 24694K->23707K(258048K), [Metaspace: 69014K->69014K(1114112K)], 0.3482776 secs] [Times: user=0.94 sys=0.02, real=0.35 secs] 48.848: [GC (Last ditch collection) [PSYoungGen: 0K->0K(83456K)] 23707K->23707K(258560K), 0.0010140 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 48.850: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(83456K)] [ParOldGen: 23707K->11368K(175104K)] 23707K->11368K(258560K), [Metaspace: 69014K->68867K(1114112K)], 0.0952605 secs] [Times: user=0.33 sys=0.00, real=0.10 secs] 49.052: [GC (Metadata GC Threshold) [PSYoungGen: 1590K->128K(83456K)] 12958K->11496K(258560K), 0.0017742 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.054: [Full GC (Metadata GC Threshold) [PSYoungGen: 128K->0K(83456K)] [ParOldGen: 11368K->11363K(175104K)] 11496K->11363K(258560K), [Metaspace: 68867K->68867K(1114112K)], 0.1009133 secs] [Times: user=0.31 sys=0.00, real=0.10 secs] 49.155: [GC (Last ditch collection) [PSYoungGen: 0K->0K(83968K)] 11363K->11363K(259072K), 0.0012378 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.157: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(83968K)] [ParOldGen: 11363K->11363K(175104K)] 11363K->11363K(259072K), [Metaspace: 68867K->68867K(1114112K)], 0.0368071 secs] [Times: user=0.13 sys=0.00, real=0.04 secs] 49.195: [GC (Metadata GC Threshold) [PSYoungGen: 1222K->64K(83456K)] 12586K->11427K(258560K), 0.0018324 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.197: [Full GC (Metadata GC Threshold) [PSYoungGen: 64K->0K(83456K)] [ParOldGen: 11363K->11359K(175104K)] 11427K->11359K(258560K), [Metaspace: 68867K->68867K(1114112K)], 0.0325830 secs] [Times: user=0.06 sys=0.00, real=0.03 secs] 49.229: [GC (Last ditch collection) [PSYoungGen: 0K->0K(83968K)] 11359K->11359K(259072K), 0.0009879 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.230: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(83968K)] [ParOldGen: 11359K->11359K(175104K)] 11359K->11359K(259072K), [Metaspace: 68867K->68867K(1114112K)], 0.0388890 secs] [Times: user=0.11 sys=0.00, real=0.04 secs] 49.270: [GC (Metadata GC Threshold) [PSYoungGen: 0K->0K(83968K)] 11359K->11359K(259072K), 0.0012192 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.271: [Full GC (Metadata GC Threshold) [PSYoungGen: 0K->0K(83968K)] [ParOldGen: 11359K->11358K(175104K)] 11359K->11358K(259072K), [Metaspace: 68867K->68867K(1114112K)], 0.1153955 secs] [Times: user=0.28 sys=0.00, real=0.12 secs] 49.387: [GC (Last ditch collection) [PSYoungGen: 0K->0K(84480K)] 11358K->11358K(259584K), 0.0009881 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.388: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(84480K)] [ParOldGen: 11358K->11358K(175104K)] 11358K->11358K(259584K), [Metaspace: 68867K->68867K(1114112K)], 0.0276961 secs] [Times: user=0.08 sys=0.00, real=0.03 secs] 49.416: [GC (Metadata GC Threshold) [PSYoungGen: 1244K->128K(83968K)] 12603K->11486K(259072K), 0.0011793 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.417: [Full GC (Metadata GC Threshold) [PSYoungGen: 128K->0K(83968K)] [ParOldGen: 11358K->11359K(175104K)] 11486K->11359K(259072K), [Metaspace: 68869K->68869K(1114112K)], 0.0972575 secs] [Times: user=0.36 sys=0.00, real=0.10 secs] 49.515: [GC (Last ditch collection) [PSYoungGen: 0K->0K(84480K)] 11359K->11359K(259584K), 0.0009651 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.516: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(84480K)] [ParOldGen: 11359K->11359K(175104K)] 11359K->11359K(259584K), [Metaspace: 68869K->68869K(1114112K)], 0.0283726 secs] [Times: user=0.06 sys=0.00, real=0.03 secs] 49.547: [GC (Metadata GC Threshold) [PSYoungGen: 1631K->64K(84480K)] 12990K->11423K(259584K), 0.0019427 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.549: [Full GC (Metadata GC Threshold) [PSYoungGen: 64K->0K(84480K)] [ParOldGen: 11359K->11373K(175104K)] 11423K->11373K(259584K), [Metaspace: 68871K->68871K(1114112K)], 0.1218152 secs] [Times: user=0.31 sys=0.00, real=0.12 secs] 49.671: [GC (Last ditch collection) [PSYoungGen: 0K->0K(84992K)] 11373K->11373K(260096K), 0.0011670 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.672: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(84992K)] [ParOldGen: 11373K->11367K(175104K)] 11373K->11367K(260096K), [Metaspace: 68871K->68871K(1114112K)], 0.0325638 secs] [Times: user=0.06 sys=0.00, real=0.03 secs] 49.705: [GC (Metadata GC Threshold) [PSYoungGen: 397K->128K(84992K)] 11764K->11495K(260096K), 0.0009596 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.706: [Full GC (Metadata GC Threshold) [PSYoungGen: 128K->0K(84992K)] [ParOldGen: 11367K->11364K(175104K)] 11495K->11364K(260096K), [Metaspace: 68871K->68871K(1114112K)], 0.0288354 secs] [Times: user=0.13 sys=0.00, real=0.03 secs] 49.735: [GC (Last ditch collection) [PSYoungGen: 0K->0K(84992K)] 11364K->11364K(260096K), 0.0009065 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.736: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(84992K)] [ParOldGen: 11364K->11364K(175104K)] 11364K->11364K(260096K), [Metaspace: 68871K->68871K(1114112K)], 0.0282498 secs] [Times: user=0.08 sys=0.00, real=0.03 secs] 49.765: [GC (Metadata GC Threshold) [PSYoungGen: 1267K->96K(84992K)] 12631K->11460K(260096K), 0.0010034 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.766: [Full GC (Metadata GC Threshold) [PSYoungGen: 96K->0K(84992K)] [ParOldGen: 11364K->11366K(175104K)] 11460K->11366K(260096K), [Metaspace: 68871K->68871K(1114112K)], 0.0274981 secs] [Times: user=0.02 sys=0.00, real=0.03 secs] 49.793: [GC (Last ditch collection) [PSYoungGen: 0K->0K(85504K)] 11366K->11366K(260608K), 0.0009064 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 49.794: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(85504K)] [ParOldGen: 11366K->11365K(175104K)] 11366K->11365K(260608K), [Metaspace: 68871K->68871K(1114112K)], 0.0406365 secs] [Times: user=0.08 sys=0.00, real=0.04 secs] 49.835: [GC (Metadata GC Threshold) [PSYoungGen: 1271K->32K(84992K)] 12637K->11397K(260096K), 0.0009762 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.836: [Full GC (Metadata GC Threshold) [PSYoungGen: 32K->0K(84992K)] [ParOldGen: 11365K->11366K(175104K)] 11397K->11366K(260096K), [Metaspace: 68871K->68871K(1114112K)], 0.0287186 secs] [Times: user=0.13 sys=0.00, real=0.03 secs] 49.865: [GC (Last ditch collection) [PSYoungGen: 0K->0K(85504K)] 11366K->11366K(260608K), 0.0009453 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.866: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(85504K)] [ParOldGen: 11366K->11366K(175104K)] 11366K->11366K(260608K), [Metaspace: 68871K->68871K(1114112K)], 0.0294249 secs] [Times: user=0.13 sys=0.00, real=0.03 secs] 49.897: [GC (Metadata GC Threshold) [PSYoungGen: 2566K->128K(85504K)] 13932K->11494K(260608K), 0.0010616 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 49.898: [Full GC (Metadata GC Threshold) [PSYoungGen: 128K->0K(85504K)] [ParOldGen: 11366K->11259K(175104K)] 11494K->11259K(260608K), [Metaspace: 68880K->68880K(1114112K)], 0.1465769 secs] [Times: user=0.49 sys=0.00, real=0.15 secs] 50.045: [GC (Last ditch collection) [PSYoungGen: 0K->0K(85504K)] 11259K->11259K(260608K), 0.0021317 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.047: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(85504K)] [ParOldGen: 11259K->11242K(175104K)] 11259K->11242K(260608K), [Metaspace: 68880K->68880K(1114112K)], 0.0318108 secs] [Times: user=0.05 sys=0.00, real=0.03 secs] 50.080: [GC (Metadata GC Threshold) [PSYoungGen: 396K->64K(85504K)] 11639K->11306K(260608K), 0.0024672 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.082: [Full GC (Metadata GC Threshold) [PSYoungGen: 64K->0K(85504K)] [ParOldGen: 11242K->11236K(175104K)] 11306K->11236K(260608K), [Metaspace: 68880K->68880K(1114112K)], 0.0353489 secs] [Times: user=0.08 sys=0.00, real=0.04 secs] 50.118: [GC (Last ditch collection) [PSYoungGen: 0K->0K(86016K)] 11236K->11236K(261120K), 0.0011646 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.119: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(86016K)] [ParOldGen: 11236K->11236K(175104K)] 11236K->11236K(261120K), [Metaspace: 68880K->68880K(1114112K)], 0.0299239 secs] [Times: user=0.06 sys=0.00, real=0.03 secs] 50.149: [GC (Metadata GC Threshold) [PSYoungGen: 849K->96K(85504K)] 12086K->11332K(260608K), 0.0012139 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.150: [Full GC (Metadata GC Threshold) [PSYoungGen: 96K->0K(85504K)] [ParOldGen: 11236K->11237K(175104K)] 11332K->11237K(260608K), [Metaspace: 68880K->68880K(1114112K)], 0.0338103 secs] [Times: user=0.08 sys=0.00, real=0.03 secs] 50.184: [GC (Last ditch collection) [PSYoungGen: 0K->0K(86016K)] 11237K->11237K(261120K), 0.0010343 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 50.185: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(86016K)] [ParOldGen: 11237K->11226K(175104K)] 11237K->11226K(261120K), [Metaspace: 68880K->68880K(1114112K)], 0.0325331 secs] [Times: user=0.08 sys=0.00, real=0.03 secs] 50.219: [GC (Metadata GC Threshold) [PSYoungGen: 850K->64K(86016K)] 12076K->11290K(261120K), 0.0010981 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.220: [Full GC (Metadata GC Threshold) [PSYoungGen: 64K->0K(86016K)] [ParOldGen: 11226K->11224K(175104K)] 11290K->11224K(261120K), [Metaspace: 68884K->68884K(1114112K)], 0.0332821 secs] [Times: user=0.03 sys=0.00, real=0.03 secs] 50.253: [GC (Last ditch collection) [PSYoungGen: 0K->0K(86016K)] 11224K->11224K(261120K), 0.0011355 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.254: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(86016K)] [ParOldGen: 11224K->11224K(175104K)] 11224K->11224K(261120K), [Metaspace: 68884K->68884K(1114112K)], 0.0332115 secs] [Times: user=0.03 sys=0.00, real=0.03 secs] 50.289: [GC (Metadata GC Threshold) [PSYoungGen: 421K->96K(86016K)] 11645K->11320K(261120K), 0.0010384 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.290: [Full GC (Metadata GC Threshold) [PSYoungGen: 96K->0K(86016K)] [ParOldGen: 11224K->11242K(175104K)] 11320K->11242K(261120K), [Metaspace: 68884K->68884K(1114112K)], 0.0317665 secs] [Times: user=0.06 sys=0.00, real=0.03 secs] 50.322: [GC (Last ditch collection) [PSYoungGen: 0K->0K(86016K)] 11242K->11242K(261120K), 0.0008965 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.323: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(86016K)] [ParOldGen: 11242K->11227K(175104K)] 11242K->11227K(261120K), [Metaspace: 68884K->68881K(1114112K)], 0.0409731 secs] [Times: user=0.14 sys=0.00, real=0.04 secs] 50.364: [GC (Metadata GC Threshold) [PSYoungGen: 404K->96K(86016K)] 11631K->11323K(261120K), 0.0011994 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.365: [Full GC (Metadata GC Threshold) [PSYoungGen: 96K->0K(86016K)] [ParOldGen: 11227K->11221K(175104K)] 11323K->11221K(261120K), [Metaspace: 68881K->68881K(1114112K)], 0.0298713 secs] [Times: user=0.06 sys=0.00, real=0.03 secs] 50.395: [GC (Last ditch collection) [PSYoungGen: 0K->0K(86016K)] 11221K->11221K(261120K), 0.0014522 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.397: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(86016K)] [ParOldGen: 11221K->11221K(175104K)] 11221K->11221K(261120K), [Metaspace: 68881K->68881K(1114112K)], 0.0427857 secs] [Times: user=0.16 sys=0.02, real=0.04 secs] 50.443: [GC (Metadata GC Threshold) [PSYoungGen: 869K->96K(86016K)] 12091K->11317K(261120K), 0.0010048 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.444: [Full GC (Metadata GC Threshold) [PSYoungGen: 96K->0K(86016K)] [ParOldGen: 11221K->11227K(175104K)] 11317K->11227K(261120K), [Metaspace: 68881K->68881K(1114112K)], 0.0513194 secs] [Times: user=0.14 sys=0.00, real=0.05 secs] 50.495: [GC (Last ditch collection) [PSYoungGen: 0K->0K(86528K)] 11227K->11227K(261632K), 0.0014694 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.497: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(86528K)] [ParOldGen: 11227K->11226K(175104K)] 11227K->11226K(261632K), [Metaspace: 68881K->68881K(1114112K)], 0.0285380 secs] [Times: user=0.08 sys=0.00, real=0.03 secs] 50.526: [GC (Metadata GC Threshold) [PSYoungGen: 7K->96K(86528K)] 11234K->11322K(261632K), 0.0009894 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.527: [Full GC (Metadata GC Threshold) [PSYoungGen: 96K->0K(86528K)] [ParOldGen: 11226K->11228K(175104K)] 11322K->11228K(261632K), [Metaspace: 68881K->68881K(1114112K)], 0.0290601 secs] [Times: user=0.08 sys=0.00, real=0.03 secs] 50.556: [GC (Last ditch collection) [PSYoungGen: 0K->0K(86528K)] 11228K->11228K(261632K), 0.0009976 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 50.557: [Full GC (Last ditch collection) [PSYoungGen: 0K->0K(86528K)] [ParOldGen: 11228K->11228K(175104K)] 11228K->11228K(261632K), [Metaspace: 68881K->68881K(1114112K)], 0.0512065 secs] [Times: user=0.11 sys=0.00, real=0.05 secs] Heap PSYoungGen total 86528K, used 410K [0x00000000fab00000, 0x0000000100000000, 0x0000000100000000) eden space 86016K, 0% used [0x00000000fab00000,0x00000000fab66a08,0x00000000fff00000) from space 512K, 0% used [0x00000000fff80000,0x00000000fff80000,0x0000000100000000) to space 512K, 0% used [0x00000000fff00000,0x00000000fff00000,0x00000000fff80000) ParOldGen total 175104K, used 11228K [0x00000000f0000000, 0x00000000fab00000, 0x00000000fab00000) object space 175104K, 6% used [0x00000000f0000000,0x00000000f0af7040,0x00000000fab00000) Metaspace used 68883K, capacity 69166K, committed 69632K, reserved 1114112K class space used 5574K, capacity 5670K, committed 5760K, reserved 1048576K
里面有两种GC日志格式:
第一种:
[GC (Allocation Failure) [PSYoungGen: 65536K->3405K(76288K)] 65536K->3413K(251392K), 0.0126293 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
[GC类型(GC原因)[新生代垃圾收集器:gc前新生代的内存使用情况(eden+from)->gc后新生代的内存使用情况(新生代总内存(eden+from))]gc前堆内存的使用情况->gc后堆内存的使用情况(堆总内存), gc耗时] [Times: gc阶段用户空间耗时 gc阶段内核空间耗时, gc阶段实际耗时]
第二种:
[Full GC (Metadata GC Threshold) [PSYoungGen: 96K->0K(86016K)] [ParOldGen: 11227K->11221K(175104K)] 11323K->11221K(261120K), [Metaspace: 68881K->68881K(1114112K)], 0.0298713 secs] [Times: user=0.06 sys=0.00, real=0.03 secs]
[GC类型 (GC原因) [新生代垃圾收集器: gc前新生代的内存使用情况->gc后新生代的内存使用情况(新生代总内存)] [老年代垃圾收集器: gc前老年代的内存使用情况->gc后老年代的内存使用情况(老年代总内存)] gc前堆内存的使用情况->gc后堆内存的使用情况(堆总内存), [Metaspace: gc前元空间的内存使用情况->gc后元空间的内存使用情况(元空间总内存)], gc耗时] [Times: gc阶段用户空间耗时 gc阶段内核空间耗时, gc阶段实际耗时]
最后在抛出OOM之后输出此时堆和元空间的内存大小:
Heap PSYoungGen total 86528K(enden+from), used 410K(和图形上的Eden Space一致) [0x00000000fab00000, 0x0000000100000000, 0x0000000100000000) eden space 86016K, 0% used [0x00000000fab00000,0x00000000fab66a08,0x00000000fff00000) from space 512K, 0% used [0x00000000fff80000,0x00000000fff80000,0x0000000100000000) to space 512K, 0% used [0x00000000fff00000,0x00000000fff00000,0x00000000fff80000) ParOldGen total 175104K, used 11228K [0x00000000f0000000, 0x00000000fab00000, 0x00000000fab00000) object space 175104K, 6% used [0x00000000f0000000,0x00000000f0af7040,0x00000000fab00000) Metaspace used 68883K, capacity 69166K, committed 69632K, reserved 1114112K class space used 5574K, capacity 5670K, committed 5760K, reserved 1048576K
主要调优的参数:
-XX:MetaspaceSize
-XX:MaxMetaspaceSize
调优原则
1、最大、最小设置成一样大防止内存动态扩展
2、程序运行起来后,通过visualVM、arthas查看占用了多少内存,向上调优,预留20%以上的空间
通过gc日志和visualVM可以看到Eden,s0,s1区的内存是动态变化的。这是因为新生代使用的垃圾收集器PSYoungGen代表ParallelGC垃圾收集器,它是一个追求系统吞吐量的垃圾收集器,它有一个参数:-XX:UseAdaptiveSizePolicy
默认是开启的,表示自适应GC模式,垃圾回收器将自动调整年轻代、老年代等参数,达到吞吐量、堆大小、停顿时间之间的平衡。一般用于,手动调整参数比较困难的场景,让收集器自动进行调整。
关于gc日志最后的一段内容: Metaspace used 68883K, capacity 69166K, committed 69632K, reserved 1114112K 。每个内容代表什么内容也是很重要的一部分知识,这里先展开讲述,后面单独讲这部分。
3)堆区OOM
测试代码:
![](https://images.cnblogs.com/OutliningIndicators/ContractedBlock.gif)
int[] intArr = new int[10]; List<MytestwebApplicationTests> objs = new ArrayList<>(); for (;;) { try { Thread.sleep(1); } catch (InterruptedException e) { e.printStackTrace(); } objs.add(new MytestwebApplicationTests()); }
gc日志:
![](https://images.cnblogs.com/OutliningIndicators/ContractedBlock.gif)
Java HotSpot(TM) 64-Bit Server VM (25.171-b11) for windows-amd64 JRE (1.8.0_171-b11), built on Mar 28 2018 16:06:12 by "java_re" with MS VC++ 10.0 (VS2010) Memory: 4k page, physical 16657512k(4457476k free), swap 49163368k(21068572k free) CommandLine flags: -XX:CompressedClassSpaceSize=62914560 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\indigoProject\LinkScape\testFolder\guobao\sourceFile -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxMetaspaceSize=71303168 -XX:MetaspaceSize=71303168 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 0.428: [GC (Allocation Failure) [PSYoungGen: 2048K->508K(2560K)] 2048K->984K(9728K), 0.0015592 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 5.954: [GC (Allocation Failure) [PSYoungGen: 2556K->488K(2560K)] 3032K->1321K(9728K), 0.0011141 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 6.045: [GC (Allocation Failure) [PSYoungGen: 2536K->508K(2560K)] 3369K->1672K(9728K), 0.0023201 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 6.588: [GC (Allocation Failure) [PSYoungGen: 2556K->492K(2560K)] 3720K->1960K(9728K), 0.0012657 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 6.665: [GC (Allocation Failure) [PSYoungGen: 2540K->492K(2560K)] 4008K->2340K(9728K), 0.0017305 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 7.239: [GC (Allocation Failure) [PSYoungGen: 2540K->492K(1536K)] 4388K->2761K(8704K), 0.0030774 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 9.266: [GC (Allocation Failure) [PSYoungGen: 1516K->432K(2048K)] 3785K->3017K(9216K), 0.0018632 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 15.268: [GC (Allocation Failure) [PSYoungGen: 1456K->420K(2048K)] 4041K->3101K(9216K), 0.0011105 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 22.268: [GC (Allocation Failure) [PSYoungGen: 1444K->374K(2048K)] 4125K->3192K(9216K), 0.0010120 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 29.386: [GC (Allocation Failure) [PSYoungGen: 1398K->306K(2048K)] 4216K->3331K(9216K), 0.0013355 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 38.277: [GC (Allocation Failure) [PSYoungGen: 1330K->128K(2048K)] 4355K->3395K(9216K), 0.0020058 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 44.284: [GC (Allocation Failure) [PSYoungGen: 1152K->283K(2048K)] 4419K->3655K(9216K), 0.0009829 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 52.288: [GC (Allocation Failure) [PSYoungGen: 1307K->128K(2048K)] 4679K->3711K(9216K), 0.0010639 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 59.287: [GC (Allocation Failure) [PSYoungGen: 1152K->313K(2048K)] 4735K->3984K(9216K), 0.0021038 secs] [Times: user=0.03 sys=0.02, real=0.00 secs] 67.291: [GC (Allocation Failure) [PSYoungGen: 1337K->160K(2048K)] 5008K->4104K(9216K), 0.0012702 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 75.296: [GC (Allocation Failure) [PSYoungGen: 1184K->128K(2048K)] 5128K->4160K(9216K), 0.0013662 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 83.307: [GC (Allocation Failure) [PSYoungGen: 1152K->160K(2048K)] 5184K->4288K(9216K), 0.0014977 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 89.299: [GC (Allocation Failure) [PSYoungGen: 1184K->437K(2048K)] 5312K->4662K(9216K), 0.0012284 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 97.314: [GC (Allocation Failure) [PSYoungGen: 1461K->128K(2048K)] 5686K->4710K(9216K), 0.0011155 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 106.307: [GC (Allocation Failure) [PSYoungGen: 1152K->192K(2048K)] 5734K->4862K(9216K), 0.0013460 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 114.310: [GC (Allocation Failure) [PSYoungGen: 1216K->160K(2048K)] 5886K->4934K(9216K), 0.0012923 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 122.316: [GC (Allocation Failure) [PSYoungGen: 1184K->192K(2048K)] 5958K->5046K(9216K), 0.0012928 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 127.317: [GC (Allocation Failure) [PSYoungGen: 1216K->544K(2048K)] 6070K->5487K(9216K), 0.0015028 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 135.334: [GC (Allocation Failure) [PSYoungGen: 1568K->128K(2048K)] 6511K->5551K(9216K), 0.0021384 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 144.324: [GC (Allocation Failure) [PSYoungGen: 1152K->192K(2048K)] 6575K->5695K(9216K), 0.0015513 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 152.339: [GC (Allocation Failure) [PSYoungGen: 1216K->128K(2048K)] 6719K->5727K(9216K), 0.0017518 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 161.330: [GC (Allocation Failure) [PSYoungGen: 1152K->192K(2048K)] 6751K->5887K(9216K), 0.0016048 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 169.346: [GC (Allocation Failure) [PSYoungGen: 1216K->160K(2048K)] 6911K->5951K(9216K), 0.0015451 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 178.336: [GC (Allocation Failure) [PSYoungGen: 1184K->160K(2048K)] 6975K->6039K(9216K), 0.0015526 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 186.357: [GC (Allocation Failure) [PSYoungGen: 1184K->128K(2048K)] 7063K->6103K(9216K), 0.0019706 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 189.417: [GC (Allocation Failure) [PSYoungGen: 1152K->753K(2048K)] 7127K->6816K(9216K), 0.0014603 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 198.349: [GC (Allocation Failure) [PSYoungGen: 1777K->128K(2048K)] 7840K->6872K(9216K), 0.0022700 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 198.352: [Full GC (Ergonomics) [PSYoungGen: 128K->0K(2048K)] [ParOldGen: 6744K->4596K(7168K)] 6872K->4596K(9216K), [Metaspace: 9423K->9357K(1058816K)], 0.0704926 secs] [Times: user=0.14 sys=0.00, real=0.07 secs] 206.352: [GC (Allocation Failure) [PSYoungGen: 1024K->128K(2048K)] 5620K->4732K(9216K), 0.0012006 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 214.355: [GC (Allocation Failure) [PSYoungGen: 1152K->224K(2048K)] 5756K->4828K(9216K), 0.0016980 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 222.367: [GC (Allocation Failure) [PSYoungGen: 1248K->288K(2048K)] 5852K->4892K(9216K), 0.0017520 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 231.359: [GC (Allocation Failure) [PSYoungGen: 1312K->384K(2048K)] 5916K->4988K(9216K), 0.0021191 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 239.363: [GC (Allocation Failure) [PSYoungGen: 1408K->448K(2048K)] 6012K->5052K(9216K), 0.0036738 secs] [Times: user=0.05 sys=0.00, real=0.00 secs] 247.366: [GC (Allocation Failure) [PSYoungGen: 1472K->544K(2048K)] 6076K->5156K(9216K), 0.0050299 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 255.370: [GC (Allocation Failure) [PSYoungGen: 1568K->544K(2048K)] 6180K->5260K(9216K), 0.0036398 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 263.390: [GC (Allocation Failure) [PSYoungGen: 1568K->512K(2048K)] 6284K->5324K(9216K), 0.0035550 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 271.667: [GC (Allocation Failure) [PSYoungGen: 1536K->416K(2048K)] 6348K->5404K(9216K), 0.0043608 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 280.380: [GC (Allocation Failure) [PSYoungGen: 1440K->352K(2048K)] 7366K->6422K(9216K), 0.0034423 secs] [Times: user=0.05 sys=0.02, real=0.00 secs] 288.400: [GC (Allocation Failure) [PSYoungGen: 1376K->320K(2048K)] 7446K->6542K(9216K), 0.0023892 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 297.388: [GC (Allocation Failure) [PSYoungGen: 1344K->320K(2048K)] 7566K->6638K(9216K), 0.0023476 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 305.408: [GC (Allocation Failure) [PSYoungGen: 1344K->288K(2048K)] 7662K->6694K(9216K), 0.0026645 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 312.410: [GC (Allocation Failure) [PSYoungGen: 1312K->352K(2048K)] 7718K->6846K(9216K), 0.0023412 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 321.395: [GC (Allocation Failure) [PSYoungGen: 1376K->320K(2048K)] 7870K->6902K(9216K), 0.0024090 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 329.402: [GC (Allocation Failure) [PSYoungGen: 1344K->416K(2048K)] 7926K->6998K(9216K), 0.0023041 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 337.410: [GC (Allocation Failure) [PSYoungGen: 1440K->480K(2048K)] 8022K->7062K(9216K), 0.0027981 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 345.432: [GC (Allocation Failure) [PSYoungGen: 1504K->544K(2048K)] 8086K->7126K(9216K), 0.0035824 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 354.416: [GC (Allocation Failure) [PSYoungGen: 1568K->544K(2048K)] 8150K->7214K(9216K), 0.0039511 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 362.423: [GC (Allocation Failure) [PSYoungGen: 1568K->512K(2048K)] 8238K->7278K(9216K), 0.0036294 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 370.427: [GC (Allocation Failure) [PSYoungGen: 1536K->512K(2048K)] 8302K->7366K(9216K), 0.0038899 secs] [Times: user=0.05 sys=0.00, real=0.00 secs] 370.431: [Full GC (Ergonomics) [PSYoungGen: 512K->0K(2048K)] [ParOldGen: 6854K->6347K(7168K)] 7366K->6347K(9216K), [Metaspace: 9426K->9334K(1058816K)], 0.1011058 secs] [Times: user=0.17 sys=0.00, real=0.10 secs] 374.427: [GC (Allocation Failure) [PSYoungGen: 1024K->288K(2048K)] 7371K->6643K(9216K), 0.0024651 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 382.434: [GC (Allocation Failure) [PSYoungGen: 1312K->224K(2048K)] 7667K->6587K(9216K), 0.0014437 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 390.437: [GC (Allocation Failure) [PSYoungGen: 1248K->352K(2048K)] 7611K->6723K(9216K), 0.0016985 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 398.440: [GC (Allocation Failure) [PSYoungGen: 1376K->416K(2048K)] 7747K->6787K(9216K), 0.0021561 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 406.455: [GC (Allocation Failure) [PSYoungGen: 1440K->448K(2048K)] 7811K->6827K(9216K), 0.0025337 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 415.149: [GC (Allocation Failure) [PSYoungGen: 1472K->544K(2048K)] 7851K->6931K(9216K), 0.0037714 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 416.106: [GC (Allocation Failure) [PSYoungGen: 682K->544K(2048K)] 7069K->6931K(9216K), 0.0035274 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 416.110: [GC (Allocation Failure) [PSYoungGen: 544K->544K(2048K)] 6931K->6931K(9216K), 0.0035866 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 416.114: [Full GC (Allocation Failure) [PSYoungGen: 544K->0K(2048K)] [ParOldGen: 6387K->6788K(7168K)] 6931K->6788K(9216K), [Metaspace: 9420K->9420K(1058816K)], 0.0928162 secs] [Times: user=0.24 sys=0.00, real=0.09 secs] 416.207: [GC (Allocation Failure) [PSYoungGen: 0K->0K(2048K)] 6788K->6788K(9216K), 0.0004495 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 416.207: [Full GC (Allocation Failure) [PSYoungGen: 0K->0K(2048K)] [ParOldGen: 6788K->6752K(7168K)] 6788K->6752K(9216K), [Metaspace: 9420K->9343K(1058816K)], 0.0539839 secs] [Times: user=0.20 sys=0.00, real=0.05 secs] Heap PSYoungGen total 2048K, used 26K [0x00000000ffd00000, 0x0000000100000000, 0x0000000100000000) eden space 1024K, 2% used [0x00000000ffd00000,0x00000000ffd06aa0,0x00000000ffe00000) from space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000) to space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000) ParOldGen total 7168K, used 6752K [0x00000000ff600000, 0x00000000ffd00000, 0x00000000ffd00000) object space 7168K, 94% used [0x00000000ff600000,0x00000000ffc980c8,0x00000000ffd00000) Metaspace used 9361K, capacity 9594K, committed 9984K, reserved 1058816K class space used 1067K, capacity 1152K, committed 1280K, reserved 1048576K
最后抛出的异常:
visualVM中最后的显示:
可以看到明显和Metaspace中OOM表现完全不同,old Gen发生4次,YGC发生62次,对象一直在向old区域移动,从Full GC日志可以看出:
[Full GC (Ergonomics) [PSYoungGen: 128K->0K(2048K)] [ParOldGen: 6744K->4596K(7168K)] 6872K->4596K(9216K), [Metaspace: 9423K->9357K(1058816K)], 0.0704926 secs] [Times: user=0.14 sys=0.00, real=0.07 secs]
Old GC也就是Full GC时Metaspace也会发生垃圾回收。
调优参数
-Xms10m -Xmx10m
调优原则
1、预留30%以上的空间
2、周期性看日志,重点关注full gc频率
4)虚拟机栈OOM
测试代码:
![](https://images.cnblogs.com/OutliningIndicators/ContractedBlock.gif)
private int val = 0; public void test() { val++; test(); } public static void main(String[] args) { StackOverFlowTest test = new StackOverFlowTest(); try { test.test(); } catch (Throwable t) { t.printStackTrace(); System.out.println(test.val); } }
JVM参数:-Xss 虚拟机栈大小,这个大小有最小的限制,和系统有关。
执行完程序会抛出栈溢出的异常:
这里输出了栈的深度:3099,而且设置的同一个栈大小多次执行抛错时得到栈深是不一样的。
这是因为有对象和轻量级锁会在栈上分配,导致栈深变小。而且我们还知道每次调用方法会创建一个栈帧放入栈内,我们可以大致推算栈帧的小 200 *1024/2709。
3:使用visualVM分析死锁
死锁代码:
![](https://images.cnblogs.com/OutliningIndicators/ContractedBlock.gif)
/** * 一个简单的死锁类 * 当DeadLock类的对象flag==1时(td1),先锁定o1,睡眠500毫秒 * 而td1在睡眠的时候另一个flag==0的对象(td2)线程启动,先锁定o2,睡眠500毫秒 * td1睡眠结束后需要锁定o2才能继续执行,而此时o2已被td2锁定; * td2睡眠结束后需要锁定o1才能继续执行,而此时o1已被td1锁定; * td1、td2相互等待,都需要得到对方锁定的资源才能继续执行,从而死锁。 */ public class DeadLock implements Runnable { public int flag = 1; //静态对象是类的所有对象共享的 private static Object o1 = new Object(), o2 = new Object(); @Override public void run() { System.out.println("flag=" + flag); if (flag == 1) { synchronized (o1) { try { Thread.sleep(500); } catch (Exception e) { e.printStackTrace(); } synchronized (o2) { System.out.println("1"); } } } if (flag == 0) { synchronized (o2) { try { Thread.sleep(500); } catch (Exception e) { e.printStackTrace(); } synchronized (o1) { System.out.println("0"); } } } } public static void main(String[] args) { DeadLock td1 = new DeadLock(); DeadLock td2 = new DeadLock(); td1.flag = 1; td2.flag = 0; //td1,td2都处于可执行状态,但JVM线程调度先执行哪个线程是不确定的。 //td2的run()可能在td1的run()之前运行 new Thread(td1).start(); new Thread(td2).start(); } }
代码运行起来在visualVM中的线程监控tab页可以看到已经有了提示:
点击线程Dump:
可以看到死锁的位置就给你定位到了。是不是很方便。
4:分析CPU占用过高问题
这个主要在服务器上进行监控的时候或打印出来线程堆栈分析。
1)根据top命令,发现PID为28555的Java进程占用CPU高达200%,出现故障。
通过ps aux | grep PID命令,可以进一步确定是tomcat进程出现了问题。但是,怎么定位到具体线程或者代码呢?
2)首先显示线程列表:
ps -mp pid -o THREAD,tid,time
找到了耗时最高的线程28802,占用CPU时间快两个小时了!
其次将需要的线程ID转换为16进制格式:
printf "%x\n" tid
3)最后打印线程的堆栈信息:
jstack pid |grep tid -A 30
定位到问题查看代码
分析CPU占用过高另外一种方式,其实思路都是一样的,只是方式不同而且:
把线程dump出来,然后分析
1:Threaddump的方法:使用命令把结果重定向到threaddump.log中
- kill -3 pid > threaddump.log
- jstack -l pid >threaddump.log
- jvisualvm中来thread dump
2:找到导致cpu高的线程
top -H -p pid
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
4691 root 19 0 448m 132m 13m S 0.0 7.5 0:00.01 java
4692 root 19 0 448m 132m 13m S 0.0 7.5 0:00.39 java
4698 root 15 0 448m 132m 13m S 0.0 7.5 0:14.14 java
4699 root 15 0 448m 132m 13m S 0.0 7.5 0:00.43 java
4700 root 15 0 448m 132m 13m S 0.0 7.5 0:00.63 java
4701 root 18 0 448m 132m 13m S 0.0 7.5 0:00.00 java
对应的线程id是十进制的,需要转换为十六进制的在threaddump文件中才可以看到
3:十进制转十六进制
-bash-3.2# python
>>> print hex(4739)
0×1283
4:找到对应的线程
vi threaddump.log
查找:/0×1283
找到对应的线程,把相关的方法找出来,可以精确到代码的行号,自己修改相关源码来fix bug。