JVM

GC log

这是真实的例子：

Java HotSpot(TM) 64-Bit Server VM (25.92-b14) for windows-amd64 JRE (1.8.0_92-b14), built on Mar 31 2016 21:03:04 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 33553976k(28013868k free), swap 41942584k(35723144k free)
CommandLine flags: -XX:+CMSClassUnloadingEnabled -XX:InitialHeapSize=536870912 -XX:+ManagementServer -XX:MaxHeapSize=1887436800 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:ThreadStackSize=1024 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
4.016: [GC (Allocation Failure) [PSYoungGen: 131584K->9051K(153088K)] 131584K->9075K(502784K), 0.0190427 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 
5.228: [GC (Allocation Failure) [PSYoungGen: 140635K->10670K(153088K)] 140659K->10702K(502784K), 0.0277551 secs] [Times: user=0.05 sys=0.00, real=0.03 secs] 
5.481: [GC (Metadata GC Threshold) [PSYoungGen: 39862K->10775K(153088K)] 39894K->10879K(502784K), 0.0105720 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
5.492: [Full GC (Metadata GC Threshold) [PSYoungGen: 10775K->0K(153088K)] [ParOldGen: 104K->10602K(349696K)] 10879K->10602K(502784K), [Metaspace: 21011K->21011K(1069056K)], 0.0640503 secs] [Times: user=0.17 sys=0.00, real=0.06 secs] 
6.384: [GC (Allocation Failure) [PSYoungGen: 131584K->18910K(267264K)] 142186K->29513K(616960K), 0.3559559 secs] [Times: user=1.00 sys=0.00, real=0.36 secs] 
7.545: [GC (Metadata GC Threshold) [PSYoungGen: 86040K->21479K(282112K)] 96643K->35404K(631808K), 0.0353545 secs] [Times: user=0.05 sys=0.03, real=0.03 secs] 
7.581: [Full GC (Metadata GC Threshold) [PSYoungGen: 21479K->0K(282112K)] [ParOldGen: 13924K->33848K(349696K)] 35404K->33848K(631808K), [Metaspace: 34684K->34684K(1079296K)], 0.1439593 secs] [Times: user=0.36 sys=0.02, real=0.14 secs] 
9.282: [GC (Allocation Failure) [PSYoungGen: 260608K->18236K(439296K)] 294456K->52093K(788992K), 0.0368250 secs] [Times: user=0.09 sys=0.00, real=0.04 secs] 
11.404: [GC (Allocation Failure) [PSYoungGen: 439100K->25320K(482304K)] 472957K->59184K(832000K), 0.0435979 secs] [Times: user=0.03 sys=0.03, real=0.04 secs] 
21.138: [GC (Allocation Failure) [PSYoungGen: 481512K->29689K(535552K)] 515376K->110703K(885248K), 0.1258300 secs] [Times: user=0.30 sys=0.03, real=0.13 secs] 
22.563: [GC (Allocation Failure) [PSYoungGen: 535545K->10799K(560128K)] 616559K->106165K(909824K), 0.0304536 secs] [Times: user=0.09 sys=0.00, real=0.03 secs] 
23.583: [GC (Allocation Failure) [PSYoungGen: 516655K->37057K(556032K)] 612021K->134335K(905728K), 0.0484882 secs] [Times: user=0.09 sys=0.00, real=0.05 secs] 
24.594: [GC (GCLocker Initiated GC) [PSYoungGen: 539841K->44417K(547328K)] 637120K->146911K(897024K), 0.0434443 secs] [Times: user=0.09 sys=0.00, real=0.04 secs] 
25.366: [GC (Allocation Failure) [PSYoungGen: 547201K->49443K(543232K)] 649697K->152795K(892928K), 0.0290345 secs] [Times: user=0.05 sys=0.03, real=0.03 secs] 
26.185: [GC (Allocation Failure) [PSYoungGen: 532771K->51538K(535040K)] 636123K->163353K(884736K), 0.0413371 secs] [Times: user=0.06 sys=0.00, real=0.04 secs] 
28.422: [GC (Metadata GC Threshold) [PSYoungGen: 169670K->24121K(546816K)] 281485K->145018K(896512K), 0.0264674 secs] [Times: user=0.05 sys=0.02, real=0.03 secs] 
28.449: [Full GC (Metadata GC Threshold) [PSYoungGen: 24121K->0K(546816K)] [ParOldGen: 120897K->90191K(414720K)] 145018K->90191K(961536K), [Metaspace: 58202K->58202K(1099776K)], 0.2879307 secs] [Times: user=0.95 sys=0.00, real=0.29 secs] 
41.510: [GC (Allocation Failure) [PSYoungGen: 476672K->31190K(507904K)] 566863K->121390K(922624K), 0.0384179 secs] [Times: user=0.09 sys=0.00, real=0.04 secs] 
204.104: [GC (Allocation Failure) [PSYoungGen: 504692K->56246K(534016K)] 594892K->146454K(948736K), 0.0358823 secs] [Times: user=0.13 sys=0.00, real=0.04 secs] 
213.685: [GC (Allocation Failure) [PSYoungGen: 526262K->56221K(526336K)] 616470K->146437K(941056K), 0.0398694 secs] [Times: user=0.09 sys=0.00, real=0.04 secs] 
232.814: [GC (Allocation Failure) [PSYoungGen: 525503K->55682K(531968K)] 615719K->145906K(946688K), 0.0511670 secs] [Times: user=0.13 sys=0.00, real=0.05 secs] 
242.768: [GC (Allocation Failure) [PSYoungGen: 512386K->60218K(517120K)] 602610K->150450K(931840K), 0.0434427 secs] [Times: user=0.11 sys=0.00, real=0.04 secs] 
251.466: [GC (Metadata GC Threshold) [PSYoungGen: 192256K->62502K(522752K)] 282488K->152742K(937472K), 0.0342334 secs] [Times: user=0.08 sys=0.00, real=0.03 secs] 
251.501: [Full GC (Metadata GC Threshold) [PSYoungGen: 62502K->0K(522752K)] [ParOldGen: 90239K->149115K(603136K)] 152742K->149115K(1125888K), [Metaspace: 96937K->96937K(1134592K)], 0.3098292 secs] [Times: user=0.92 sys=0.00, real=0.31 secs] 
258.311: [GC (Allocation Failure) [PSYoungGen: 439296K->37657K(526848K)] 588411K->186780K(1129984K), 0.0592208 secs] [Times: user=0.14 sys=0.00, real=0.06 secs] 
268.202: [GC (Allocation Failure) [PSYoungGen: 476953K->39709K(519680K)] 626076K->188840K(1122816K), 0.0332047 secs] [Times: user=0.06 sys=0.00, real=0.03 secs] 
309.379: [GC (Allocation Failure) [PSYoungGen: 483101K->75250K(523264K)] 632232K->224389K(1126400K), 0.0385272 secs] [Times: user=0.14 sys=0.00, real=0.04 secs] 
335.565: [GC (Allocation Failure) [PSYoungGen: 518642K->88558K(489984K)] 667781K->254121K(1093120K), 0.0738648 secs] [Times: user=0.25 sys=0.02, real=0.07 secs] 
336.685: [GC (Allocation Failure) [PSYoungGen: 489966K->98840K(500736K)] 655529K->264411K(1103872K), 0.0610549 secs] [Times: user=0.16 sys=0.00, real=0.06 secs] 
337.906: [GC (Allocation Failure) [PSYoungGen: 500248K->113634K(459776K)] 665819K->280053K(1062912K), 0.0617283 secs] [Times: user=0.20 sys=0.00, real=0.06 secs] 
339.127: [GC (Allocation Failure) [PSYoungGen: 459746K->106398K(452608K)] 626165K->272825K(1055744K), 0.0570718 secs] [Times: user=0.19 sys=0.00, real=0.06 secs] 
340.196: [GC (Allocation Failure) [PSYoungGen: 452510K->106430K(456192K)] 618937K->272857K(1059328K), 0.0509874 secs] [Times: user=0.20 sys=0.00, real=0.05 secs] 
341.165: [GC (Allocation Failure) [PSYoungGen: 418750K->106462K(418816K)] 585177K->272889K(1021952K), 0.0623639 secs] [Times: user=0.19 sys=0.00, real=0.06 secs] 
342.209: [GC (Allocation Failure) [PSYoungGen: 418782K->83581K(462336K)] 585209K->279711K(1065472K), 0.0801249 secs] [Times: user=0.20 sys=0.03, real=0.08 secs] 
343.180: [GC (Allocation Failure) [PSYoungGen: 389757K->41469K(347648K)] 585887K->285514K(950784K), 0.0792789 secs] [Times: user=0.23 sys=0.02, real=0.08 secs] 
344.153: [GC (Allocation Failure) [PSYoungGen: 347645K->11243K(454144K)] 591690K->288322K(1057280K), 0.0467670 secs] [Times: user=0.11 sys=0.02, real=0.05 secs] 
345.086: [GC (Allocation Failure) [PSYoungGen: 315371K->160K(456192K)] 592450K->288371K(1059328K), 0.0198098 secs] [Times: user=0.06 sys=0.00, real=0.02 secs] 
345.991: [GC (Allocation Failure) [PSYoungGen: 304288K->192K(458752K)] 592499K->288411K(1061888K), 0.0044848 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
346.882: [GC (Allocation Failure) [PSYoungGen: 304320K->128K(304640K)] 592539K->288371K(907776K), 0.0045859 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 
347.777: [GC (Allocation Failure) [PSYoungGen: 304256K->160K(460800K)] 592499K->288411K(1063936K), 0.0068435 secs] [Times: user=0.00 sys=0.01, real=0.01 secs] 
348.675: [GC (Allocation Failure) [PSYoungGen: 307360K->160K(307712K)] 595611K->288435K(910848K), 0.0050312 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
349.575: [GC (Allocation Failu11306.668: [GC (Allocation Failure) [PSYoungGen: 265322K->12474K(381952K)] 560704K->334984K(947200K), 0.0496945 secs] [Times: user=0.17 sys=0.02, real=0.05 secs] 
12579.928: [GC (Allocation Failure) [PSYoungGen: 232122K->11610K(227840K)] 554632K->334976K(793088K), 0.0183653 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 
13068.103: [GC (Allocation Failure) [PSYoungGen: 227674K->11052K(382464K)] 551040K->335583K(947712K), 0.0245607 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 
13359.772: [GC (Allocation Failure) [PSYoungGen: 223532K->9936K(219136K)] 548063K->335092K(784384K), 0.0202452 secs] [Times: user=0.03 sys=0.00, real=0.02 secs] 
13996.517: [GC (Allocation Failure) [PSYoungGen: 218832K->10712K(369664K)] 543988K->336168K(934912K), 0.0135019 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 
14499.412: [GC (Allocation Failure) [PSYoungGen: 216024K->10304K(212992K)] 541480K->336424K(778240K), 0.0162407 secs] [Times: user=0.00 sys=0.02, real=0.02 secs] 
14859.516: [GC (Allocation Failure) [PSYoungGen: 212544K->8352K(354816K)] 538664K->335584K(920064K), 0.0218380 secs] [Times: user=0.03 sys=0.00, real=0.02 secs] 
64K->160K(475136K)] 653939K->288435K(1078272K), 0.0046356 secs] [Times: user=0.03 sys=0.00, real=0.00 secs] 
357.543: [GC (Allocation Failure) [PSYoungGen: 365728K->160K(475136K)] 654003K->288435K(1078272K), 0.0080850 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
358.668: [GC (Allocation Failure) [PSYoungGen: 383136K->224K(480768K)] 671411K->288499K(1083904K), 0.0044304 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
359.787: [GC (Allocation Failure) [PSYoungGen: 383200K->160K(478720K)] 671475K->288435K(1081856K), 0.0056352 secs] [Times: user=0.00 sys=0.02, real=0.01 secs] 
360.953: [GC (Allocation Failure) [PSYoungGen: 399008K->192K(485376K)] 687283K->288467K(1088512K), 0.0137202 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 
362.131: [GC (Allocation Failure) [PSYoungGen: 399040K->160K(484864K)] 687315K->288435K(1088000K), 0.0051994 secs] [Times: user=0.00 sys=0.02, real=0.01 secs]
.............
.............

　　

详细解释

https://blog.csdn.net/topdeveloperr/article/details/88874957

概述博主在最近使用spring batch的过程当中遇到了内存容量耗尽程序崩溃的问题，于是决定将此次的内存问题分析通过本篇博客记录下来。
在分析gc日实例志之前，我们先通过一条《深入理解java虚拟机》一书中的一个例子gc日志来回顾一下gc日志的基本知识，下面是一条gc日志：
33.125：[GC[DefNew: 3324k->152k(3712k), 0.0025925 secs] 3324k>152k(11904k),0.0031680 secs]从左至右，各个信息的意思为：
33.125： 自虚拟机启动以来经过的秒数，单位为秒；GC： 垃圾收集的停顿类型为不需要STW（Stop The World ）。如果是Full GC说明发生了STW。如果是Full GC (System)说明是调用System.gc()方法所触发的收集。DefNew：表示GC发生的区域在新生代。这个名称和所使用的收集器密切相关。可以有Tenured、Perm、ParNew、PSYoungGen等等。其中hotspot虚拟机使用的是PSYoungGen代表新生代3324k->152k(3712k)：GC前该区域（DefNew）已使用容量->GC后该区域已使用容量（该内存区域总容量）0.0025925 secs：该内存区域（DefNew）GC所占用的时间。3324k->152k(11904k)：GC前Java堆已使用容量->GC后Java堆已使用容量（Java堆总容量）本次博主遇到的内存问题是在使用spring batch做数据迁移时遇到的，在使用springbatch迁移数据时，发现了虚拟机内存用量不断增大的现象，于是将gc日志存了下来，并且通过jconsole截取了内存变化的情况。使用的vm运行参数为：
-XX:InitialHeapSize=266386688 -XX:MaxHeapSize=4262187008 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC JConsole通过JConsole监测到的memory使用情况如下.
堆内存的整体情况如下图所示：


老年代的整体情况如下图所示


年轻代eden space如下


VisualVmJconsole当中的信息比较粗略，作为JConsole的升级版，VisualVm提供了更多的信息。
堆内存信息:


上图中可以清楚的看出元空间metaspace占的大小是固定的，而老年代则占据了相当大的内存空间。年轻代则是相对不停在动态变化的区域。因此，老年代的内存是我们要重点分析的。


这是整个内存区域的折线图展示。
我们可以使用Java VisualVM浏览堆heap dump文件的内容，并查看堆中已分配的对象。 对我们需要进行heap dump分析的java程序点右键就能找到heap dump选项。一次heap dump是特定时间点Java虚拟机（JVM）堆中所有对象的一个快照。 JVM为所有类实例和数组对象在堆中分配内存。 当不再需要对象且没有对象的引用时，垃圾收集器将回收堆内存。 通过检查堆，可以找到创建对象的位置，并查找对这些对象的引用。 如果JVM无法从堆中删除不需要的对象，Java VisualVM可以帮助我们找到对象的最近的GC Root。博主dump出来的结果如下:
Summary.
java VisualVm默认会展示Summary界面的信息，主要显示执行heap dump时的运行环境以及其他系统属性。GC Roots这一垃圾回收的概念也被展示在这里。


class
Class视图显示了类的列表以及该类引用的实例的数量和百分比。 通过右键单击名称并选择查看nstances，可以查看特定类的实例列表。


可以发现占据最大堆内存的是一个byte类型的数组。另外有句题外话，在上图中我们发现String和char[]这两个类的数量几乎是相当的，这从侧面印证了String内部是由Char数组实现的。
它对应的实例对象instance信息如下：


注意,这里有一个非常重要的问题需要弄清楚。在上面的截图当中，虽然占内存最多的是Byte类型的对象，但是这绝不意味着所有的byte对象都是由同一个模块或类所持有的。例如，上面截图当中的instance类型是HRequestPacket,这是jdbc写数据时用到的一个类。但是不能就此判断就是该类导致了这个问题。因为除了这个类，还有很多其他的类里面有byte类型的数据引用。
理解了这一点对于分析这个问题至关重要，因此，如果我们能分析出是哪个类的对象占据了绝大多数的byte类型引用，则我们就找到了问题的关键。
GC日志gc日志如下：
Java HotSpot(TM) 64-Bit Server VM (25.151-b12) for windows-amd64 JRE (1.8.0_151-b12), built on Sep  5 2017 19:33:46 by "java_re" with MS VC++ 10.0 (VS2010)Memory: 4k page, physical 16649168k(5641848k free), swap 41814992k(16763352k free)CommandLine flags: -XX:InitialHeapSize=266386688 -XX:MaxHeapSize=4262187008 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 2019-03-28T18:02:49.809+0800: 3.175: [GC (Allocation Failure) [PSYoungGen: 65536K->7435K(76288K)] 65536K->7451K(251392K), 0.0132004 secs] [Times: user=0.00 sys=0.02, real=0.01 secs] 2019-03-28T18:02:52.006+0800: 5.371: [GC (Allocation Failure) [PSYoungGen: 72971K->10722K(76288K)] 72987K->12689K(251392K), 0.0207831 secs] [Times: user=0.06 sys=0.00, real=0.02 secs] 2019-03-28T18:02:52.097+0800: 5.463: [GC (Metadata GC Threshold) [PSYoungGen: 13589K->8536K(76288K)] 15555K->10511K(251392K), 0.0159315 secs] [Times: user=0.03 sys=0.00, real=0.02 secs] 2019-03-28T18:02:52.114+0800: 5.479: [Full GC (Metadata GC Threshold) [PSYoungGen: 8536K->0K(76288K)] [ParOldGen: 1974K->8439K(88064K)] 10511K->8439K(164352K), [Metaspace: 20723K->20723K(1067008K)], 0.0733626 secs] [Times: user=0.09 sys=0.03, real=0.07 secs] 2019-03-28T18:02:54.666+0800: 8.031: [GC (Allocation Failure) [PSYoungGen: 65536K->5668K(123904K)] 73975K->14116K(211968K), 0.0442485 secs] [Times: user=0.13 sys=0.00, real=0.05 secs] 2019-03-28T18:03:01.638+0800: 15.004: [GC (Allocation Failure) [PSYoungGen: 123428K->10746K(137216K)] 131876K->20995K(225280K), 0.0197362 secs] [Times: user=0.00 sys=0.02, real=0.02 secs] 2019-03-28T18:03:02.068+0800: 15.433: [GC (Metadata GC Threshold) [PSYoungGen: 40440K->9781K(222208K)] 50689K->20038K(310272K), 0.0189468 secs] [Times: user=0.06 sys=0.00, real=0.02 secs] 2019-03-28T18:03:02.087+0800: 15.452: [Full GC (Metadata GC Threshold) [PSYoungGen: 9781K->0K(222208K)] [ParOldGen: 10256K->17742K(114688K)] 20038K->17742K(336896K), [Metaspace: 34221K->34221K(1079296K)], 0.0911808 secs] [Times: user=0.31 sys=0.00, real=0.09 secs] 2019-03-28T18:03:06.921+0800: 20.287: [GC (Allocation Failure) [PSYoungGen: 206848K->13185K(221696K)] 224590K->30928K(336384K), 0.0362549 secs] [Times: user=0.11 sys=0.00, real=0.04 secs] 2019-03-28T18:03:11.063+0800: 24.429: [GC (Allocation Failure) [PSYoungGen: 220033K->15854K(367104K)] 237776K->38236K(481792K), 0.0308660 secs] [Times: user=0.06 sys=0.02, real=0.03 secs] 2019-03-28T18:03:35.129+0800: 48.495: [GC (Allocation Failure) [PSYoungGen: 367086K->19965K(372224K)] 389468K->53072K(486912K), 0.0610547 secs] [Times: user=0.11 sys=0.02, real=0.06 secs] 2019-03-28T18:03:49.929+0800: 63.294: [GC (Allocation Failure) [PSYoungGen: 372221K->26619K(495616K)] 405328K->98061K(610304K), 0.0611854 secs] [Times: user=0.11 sys=0.06, real=0.06 secs] 2019-03-28T18:04:50.342+0800: 123.709: [GC (Metadata GC Threshold) [PSYoungGen: 312233K->32080K(513536K)] 383676K->129526K(628224K), 0.0438135 secs] [Times: user=0.06 sys=0.03, real=0.04 secs] 2019-03-28T18:04:50.386+0800: 123.753: [Full GC (Metadata GC Threshold) [PSYoungGen: 32080K->0K(513536K)] [ParOldGen: 97445K->114064K(259072K)] 129526K->114064K(772608K), [Metaspace: 57009K->57009K(1101824K)], 0.4012776 secs] [Times: user=0.70 sys=0.00, real=0.40 secs] 2019-03-28T18:07:00.393+0800: 253.760: [GC (Allocation Failure) [PSYoungGen: 468992K->5210K(656896K)] 583056K->119283K(915968K), 0.0112825 secs] [Times: user=0.00 sys=0.02, real=0.01 secs] 2019-03-28T18:07:07.441+0800: 260.808: [GC (Allocation Failure) [PSYoungGen: 618586K->43428K(659968K)] 732659K->159101K(919040K), 0.0781209 secs] [Times: user=0.17 sys=0.05, real=0.08 secs] 2019-03-28T18:07:21.225+0800: 274.592: [GC (Allocation Failure) [PSYoungGen: 656804K->45214K(854016K)] 772477K->195296K(1113088K), 0.1500614 secs] [Times: user=0.39 sys=0.09, real=0.15 secs] 2019-03-28T18:07:35.972+0800: 289.340: [GC (Allocation Failure) [PSYoungGen: 845982K->58860K(859648K)] 996064K->816543K(1617408K), 0.9032023 secs] [Times: user=2.23 sys=0.80, real=0.90 secs] 2019-03-28T18:07:36.876+0800: 290.243: [Full GC (Ergonomics) [PSYoungGen: 58860K->52656K(859648K)] [ParOldGen: 757683K->757303K(1154560K)] 816543K->809960K(2014208K), [Metaspace: 62060K->62053K(1105920K)], 4.0586369 secs] [Times: user=11.55 sys=0.16, real=4.06 secs] 2019-03-28T18:08:08.469+0800: 321.836: [GC (Allocation Failure) [PSYoungGen: 853424K->293373K(794112K)] 1610728K->1305776K(1948672K), 0.8246918 secs] [Times: user=2.02 sys=0.70, real=0.82 secs] 2019-03-28T18:08:09.294+0800: 322.661: [Full GC (Ergonomics) [PSYoungGen: 293373K->126822K(794112K)] [ParOldGen: 1012403K->1154394K(1639424K)] 1305776K->1281217K(2433536K), [Metaspace: 62153K->62153K(1105920K)], 3.9747741 secs] [Times: user=11.53 sys=0.23, real=3.97 secs] 2019-03-28T18:08:21.298+0800: 334.666: [GC (Allocation Failure) [PSYoungGen: 627558K->438638K(939520K)] 1781953K->1720672K(2578944K), 0.7545171 secs] [Times: user=2.23 sys=0.16, real=0.75 secs] 2019-03-28T18:08:30.753+0800: 344.120: [GC (Allocation Failure) [PSYoungGen: 937287K->419692K(910848K)] 2219321K->2134423K(2626048K), 1.1363656 secs] [Times: user=2.72 sys=0.92, real=1.14 secs] 2019-03-28T18:08:31.890+0800: 345.257: [Full GC (Ergonomics) [PSYoungGen: 419692K->381752K(910848K)] [ParOldGen: 1714731K->1714877K(2346496K)] 2134423K->2096629K(3257344K), [Metaspace: 62177K->62177K(1105920K)], 6.8793414 secs] [Times: user=21.08 sys=0.33, real=6.88 secs] 2019-03-28T18:09:14.832+0800: 388.199: [GC (Allocation Failure) [PSYoungGen: 844600K->17010K(925184K)] 2559477K->2115103K(3271680K), 0.9426621 secs] [Times: user=2.38 sys=0.47, real=0.94 secs] 2019-03-28T18:09:15.774+0800: 389.142: [Full GC (Ergonomics) [PSYoungGen: 17010K->0K(925184K)] [ParOldGen: 2098093K->2103707K(2776064K)] 2115103K->2103707K(3701248K), [Metaspace: 62299K->62299K(1105920K)], 5.5291426 secs] [Times: user=14.83 sys=0.09, real=5.53 secs] 2019-03-28T18:09:58.493+0800: 431.862: [GC (Allocation Failure) [PSYoungGen: 462848K->8896K(925184K)] 2566555K->2112611K(3701248K), 0.0247480 secs] [Times: user=0.13 sys=0.00, real=0.02 secs] 2019-03-28T18:10:34.529+0800: 467.898: [GC (Allocation Failure) [PSYoungGen: 471744K->7264K(925184K)] 2575459K->2111091K(3701248K), 0.0401908 secs] [Times: user=0.13 sys=0.00, real=0.04 secs] 2019-03-28T18:11:12.197+0800: 505.566: [GC (Allocation Failure) [PSYoungGen: 470112K->8256K(925184K)] 2573939K->2112171K(3701248K), 0.0219496 secs] [Times: user=0.06 sys=0.00, real=0.02 secs] 2019-03-28T18:11:54.626+0800: 547.995: [GC (Allocation Failure) [PSYoungGen: 471104K->7072K(925184K)] 2575019K->2111107K(3701248K), 0.0252580 secs] [Times: user=0.03 sys=0.00, real=0.03 secs] 2019-03-28T18:12:35.224+0800: 588.593: [GC (Allocation Failure) [PSYoungGen: 469920K->6848K(925184K)] 2573955K->2111010K(3701248K), 0.0348010 secs] [Times: user=0.13 sys=0.00, real=0.03 secs] 2019-03-28T18:13:19.063+0800: 632.432: [GC (Allocation Failure) [PSYoungGen: 469696K->5664K(925184K)] 2573858K->2109898K(3701248K), 0.0440174 secs] [Times: user=0.09 sys=0.00, real=0.04 secs] 2019-03-28T18:14:14.429+0800: 687.798: [GC (Allocation Failure) [PSYoungGen: 468512K->6240K(890368K)] 2572746K->2110626K(3666432K), 0.0410298 secs] [Times: user=0.14 sys=0.00, real=0.04 secs] 2019-03-28T18:15:19.975+0800: 753.345: [GC (Allocation Failure) [PSYoungGen: 469088K->6528K(469504K)] 2573474K->2110914K(3245568K), 0.0545711 secs] [Times: user=0.02 sys=0.02, real=0.05 secs] 2019-03-28T18:16:23.762+0800: 817.133: [GC (Allocation Failure) [PSYoungGen: 469376K->6720K(845824K)] 2573762K->2111106K(3621888K), 0.0540892 secs] [Times: user=0.09 sys=0.02, real=0.05 secs] GC日志分析前两行打出的是虚拟机的基本信息和使用的vm参数。其中InitialHeapSize=266386688，即我们设定虚拟机的堆初始化大小为2.5G左右。MaxHeapSize=4262187008，即最大的堆大小为4G。
下面我们来挑几条gc日志进行分析，第一条：
2019-03-28T18:02:49.809+0800: 3.175: [GC (Allocation Failure) [PSYoungGen: 65536K->7435K(76288K)] 65536K->7451K(251392K), 0.0132004 secs] [Times: user=0.00 sys=0.02, real=0.01 secs] 2019-03-28T18:02:49.809+0800  : gc日志记录时间3.175 ：gc发生时，虚拟机运行了多少秒GC (Allocation Failure) ： 发生了一次垃圾回收，若前面有Full则表明是Full GC，没有Full的修饰表明这是一次Minor GC 。注意它不表示只GC新生代，括号里的内容是gc发生的原因，这里的Allocation Failure的原因是年轻代中没有足够区域能够存放需要分配的数据而失败，。PSYoungGen： 使用的垃圾收集器的名字。65536K->7435K(76288K) ：垃圾收集前后的年轻代内存使用情况，其中前面的65536kb为gc之前的使用量，7435kb为gc之后的内存使用量。括号里的76288k为该内存区域的总量。  65536K->7451K(251392K) ： 垃圾收集前后整个堆内存的使用情况，括号里的为整个可以的堆内存的容量。0.0132004 secs ：整个GC过程持续时间[Times: user=0.00 sys=0.02, real=0.01 secs] ：分别表示用户态耗时，内核态耗时和总耗时。也是对gc耗时的一个记录。第二条：
019-03-28T18:02:52.097+0800: 5.463: [GC (Metadata GC Threshold) [PSYoungGen: 13589K->8536K(76288K)] 15555K->10511K(251392K), 0.0159315 secs] [Times: user=0.03 sys=0.00, real=0.02 secs] 也是一次minor gc，但是与前两次的gc原因不一样，这次的gc原因是：Metadata GC Threshold。Metadata即元数据的意思。我们可以看出这是与虚拟机的元数据区有关系的一次gc。元数据区，在jdk1.8以前又叫永久代，从JDK8开始，永久代(PermGen)的概念被废弃掉了，取而代之的就是这里的称为Metaspace的存储空间。元空间和永久代是虚拟机对方法区这个概念的一个具体实现。对于元空间而言，这一块空间是存在本地内存当中的。因此，默认情况下，元空间的大小仅受本地内存限制，但我们可以通过参数来指定元空间的大小。
这里元空间发生gc，说明元空间的内存不够了，到达了阀值。对元空间进行了一次垃圾回收，回收之前是13489k，回收之后是8536k。
第三条：
2019-03-28T18:02:52.114+0800: 5.479: [Full GC (Metadata GC Threshold) [PSYoungGen: 8536K->0K(76288K)] [ParOldGen: 1974K->8439K(88064K)] 10511K->8439K(164352K), [Metaspace: 20723K->20723K(1067008K)], 0.0733626 secs] [Times: user=0.09 sys=0.03, real=0.07 secs] 在元空间gc之后，紧接着发生了一次Full GC，且触发原因也是元空间不足。
[PSYoungGen: 8536K->0K(76288K)] ：年轻代进行了一次gc[ParOldGen: 1974K->8439K(88064K)] ：老年代进行了一次gc[Metaspace: 20723K->20723K(1067008K)] ： 元空间（方法区）发生了一次gc，但是值得注意的是，gc前后内存使用情况并没有发生任何改变。同时，元空间总的可使用的内存为：1gb。后面又发生了两次full gc，且与这次full gc基本是一致的，但是不同的是元空间使用量在不停变大。
第二次full gc的日志为：
2019-03-28T18:03:02.087+0800: 15.452: [Full GC (Metadata GC Threshold) [PSYoungGen: 9781K->0K(222208K)] [ParOldGen: 10256K->17742K(114688K)] 20038K->17742K(336896K), [Metaspace: 34221K->34221K(1079296K)], 0.0911808 secs] [Times: user=0.31 sys=0.00, real=0.09 secs] 其中空间信息为：[Metaspace: 34221K->34221K(1079296K)]
第三次full gc时的日志为：
2019-03-28T18:04:50.386+0800: 123.753: [Full GC (Metadata GC Threshold) [PSYoungGen: 32080K->0K(513536K)] [ParOldGen: 97445K->114064K(259072K)] 129526K->114064K(772608K), [Metaspace: 57009K->57009K(1101824K)], 0.4012776 secs] [Times: user=0.70 sys=0.00, real=0.40 secs] 其中元空间信息为：[Metaspace: 57009K->57009K(1101824K)]
可以看到元空间的使用量一直在增大，且没有被回收。同时，老年代的使用内存在一直变大，gc的同时，老年代又不断有新的对象进入。对老年代的gc并没有降低老年代的内存使用量，这与通过jconsle看到的信息也是一致的。
在这三次full gc之后的第四次full gc日志如下：
2019-03-28T18:07:36.876+0800: 290.243: [Full GC (Ergonomics) [PSYoungGen: 58860K->52656K(859648K)] [ParOldGen: 757683K->757303K(1154560K)] 816543K->809960K(2014208K), [Metaspace: 62060K->62053K(1105920K)], 4.0586369 secs] [Times: user=11.55 sys=0.16, real=4.06 secs] 注意，这次full gc的原因发生了变化，为Full GC (Ergonomics），它的意思是执行了一次全局gc。
且从执行效果[ParOldGen: 757683K->757303K(1154560K)]来看，本次full gc从内存使用情况来看几乎没有起到作用。这有两个可能的原因：
gc本身没有回收多少对象gc回收了很多对象，但同时又有更多的对象进入老年代同时，元数据区使用量继续变大。
从第四次full gc开始，之后的full gc全部变成了全局Ergonomics gc。
第五次：[ParOldGen: 1012403K->1154394K(1639424K)]，从这次开始老年代超过了初始容量，开始变大
第六次：[ParOldGen: 1714731K->1714877K(2346496K)] ，老年代容量继续变大,元空间几乎不变。
第七次：[ParOldGen: 2098093K->2103707K(2776064K)]， 老年代容量继续变大，元空间几乎不变
这之后随着程序继续运行，但是full gc不再出现，只出现minor gc, 但我们观察到，可用容量已达到4g，几乎达到了总容量,且老年代的内存使用量不再发生变化，这说明也许这时候老年代已经无法再进行gc。
以上就是对此次gc日志的分析。至于每次gc的根本原因，则需要结合自己的代码进行分析，博主这次的原因在于在读数据时一次将所有数据读入了内存当中,详细的分析可以参考这篇博客：spring batch数据迁移时reader读数据的内存容量问题。这里不再展开。————————————————版权声明：本文为CSDN博主「topEngineerray」的原创文章，遵循CC 4.0 BY-SA版权协议，转载请附上原文出处链接及本声明。原文链接：https://blog.csdn.net/topdeveloperr/article/details/88874957