一、背景

该次Full GC的产生,是在Jmeter并发调用的情况下产生,具体的参数如下图1。5分钟内循环调用本地接口,机器配置为4c 16g,Windows单机运行,JVM的配置如图2。

二、运行结果

本次压测的汇总图如下。

GC日志如下。

Java HotSpot(TM) 64-Bit Server VM (25.101-b13) for windows-amd64 JRE (1.8.0_101-b13), built on Jun 22 2016 01:21:29 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 16687556k(8513928k free), swap 18389444k(7267256k free)
CommandLine flags: -XX:-BytecodeVerificationLocal -XX:-BytecodeVerificationRemote -XX:InitialHeapSize=1368601392 -XX:+ManagementServer -XX:MaxHeapSize=4272014336 -XX:MaxNewSize=1363148800 -XX:MetaspaceSize=134217728 -XX:NewSize=1363148800 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:TieredStopAtLevel=1 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC
2021-04-23T16:44:18.678+0800: 5.132: [GC (Allocation Failure) [PSYoungGen: 998400K->63124K(1164800K)] 998400K->63164K(1170944K), 0.0408616 secs] [Times: user=0.05 sys=0.03, real=0.04 secs]
2021-04-23T16:45:36.435+0800: 82.889: [GC (Allocation Failure) [PSYoungGen: 1061524K->116513K(1164800K)] 1061564K->116577K(1170944K), 0.0748102 secs] [Times: user=0.25 sys=0.02, real=0.08 secs]
2021-04-23T16:45:37.896+0800: 84.351: [GC (Allocation Failure) [PSYoungGen: 1114913K->156057K(1164800K)] 1114977K->156209K(1170944K), 0.0671057 secs] [Times: user=0.23 sys=0.02, real=0.07 secs]
2021-04-23T16:45:40.565+0800: 87.019: [GC (Allocation Failure) [PSYoungGen: 1154457K->166368K(1164800K)] 1154609K->167075K(1170944K), 0.0705892 secs] [Times: user=0.23 sys=0.02, real=0.07 secs]
2021-04-23T16:45:42.956+0800: 89.410: [GC (Allocation Failure) [PSYoungGen: 1164768K->166294K(1164800K)] 1165475K->167009K(1170944K), 0.0641620 secs] [Times: user=0.20 sys=0.00, real=0.06 secs]
2021-04-23T16:45:45.406+0800: 91.860: [GC (Allocation Failure) [PSYoungGen: 1164694K->166263K(1047040K)] 1165409K->166986K(1053184K), 0.0731659 secs] [Times: user=0.23 sys=0.00, real=0.07 secs]
2021-04-23T16:45:47.739+0800: 94.193: [GC (Allocation Failure) [PSYoungGen: 1046903K->65453K(946176K)] 1047626K->167344K(1048576K), 0.0896584 secs] [Times: user=0.24 sys=0.08, real=0.09 secs]
2021-04-23T16:45:47.830+0800: 94.284: [Full GC (Ergonomics) [PSYoungGen: 65453K->60377K(946176K)] [ParOldGen: 101891K->102348K(161792K)] 167344K->162725K(1107968K), [Metaspace: 69759K->69584K(1114112K)], 0.8424038 secs] [Times: user=2.36 sys=0.00, real=0.84 secs]
2021-04-23T16:45:50.912+0800: 97.366: [GC (Allocation Failure) [PSYoungGen: 941017K->14224K(1080320K)] 1043365K->166411K(1242112K), 0.0340157 secs] [Times: user=0.08 sys=0.03, real=0.03 secs]
2021-04-23T16:45:50.946+0800: 97.400: [Full GC (Ergonomics) [PSYoungGen: 14224K->4398K(1080320K)] [ParOldGen: 152187K->161652K(238592K)] 166411K->166050K(1318912K), [Metaspace: 69584K->69584K(1114112K)], 0.2608357 secs] [Times: user=0.74 sys=0.02, real=0.26 secs]
2021-04-23T16:45:53.440+0800: 99.894: [GC (Allocation Failure) [PSYoungGen: 855342K->10720K(861696K)] 1016994K->172388K(1100288K), 0.0191096 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:45:55.667+0800: 102.121: [GC (Allocation Failure) [PSYoungGen: 861664K->11680K(1082880K)] 1023332K->173348K(1321472K), 0.0112519 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:45:57.893+0800: 104.347: [GC (Allocation Failure) [PSYoungGen: 849312K->8640K(1084416K)] 1010980K->170308K(1323008K), 0.0114434 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:46:00.130+0800: 106.584: [GC (Allocation Failure) [PSYoungGen: 846272K->14144K(1089024K)] 1007940K->175812K(1327616K), 0.0135143 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2021-04-23T16:46:02.553+0800: 109.007: [GC (Allocation Failure) [PSYoungGen: 856896K->10304K(1084928K)] 1018564K->171972K(1323520K), 0.0106947 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2021-04-23T16:46:04.785+0800: 111.239: [GC (Allocation Failure) [PSYoungGen: 853056K->10880K(1099776K)] 1014724K->172548K(1338368K), 0.0116308 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:46:07.127+0800: 113.581: [GC (Allocation Failure) [PSYoungGen: 873088K->11648K(1093632K)] 1034756K->173316K(1332224K), 0.0116023 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:46:09.428+0800: 115.882: [GC (Allocation Failure) [PSYoungGen: 873856K->29632K(1118208K)] 1035524K->191300K(1356800K), 0.0225421 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
2021-04-23T16:46:11.966+0800: 118.420: [GC (Allocation Failure) [PSYoungGen: 924096K->12160K(1107456K)] 1085764K->173828K(1346048K), 0.0122453 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:46:14.384+0800: 120.838: [GC (Allocation Failure) [PSYoungGen: 906624K->10880K(1134592K)] 1068292K->172548K(1373184K), 0.0118113 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
2021-04-23T16:46:16.874+0800: 123.328: [GC (Allocation Failure) [PSYoungGen: 940672K->11808K(1126400K)] 1102340K->173476K(1364992K), 0.0116605 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:46:19.340+0800: 125.794: [GC (Allocation Failure) [PSYoungGen: 941600K->12672K(1152000K)] 1103268K->174340K(1390592K), 0.0117730 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:46:21.906+0800: 128.360: [GC (Allocation Failure) [PSYoungGen: 976256K->12448K(1142784K)] 1137924K->174116K(1381376K), 0.0116093 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:46:24.472+0800: 130.926: [GC (Allocation Failure) [PSYoungGen: 976032K->10944K(1168896K)] 1137700K->172612K(1407488K), 0.0110888 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:46:27.108+0800: 133.562: [GC (Allocation Failure) [PSYoungGen: 1009344K->11488K(1160704K)] 1171012K->173284K(1399296K), 0.0119912 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:46:29.866+0800: 136.321: [GC (Allocation Failure) [PSYoungGen: 1009888K->12032K(1185792K)] 1171684K->174268K(1424384K), 0.0119740 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:46:32.676+0800: 139.130: [GC (Allocation Failure) [PSYoungGen: 1044224K->10464K(1177600K)] 1206460K->172740K(1416192K), 0.0112648 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:46:35.443+0800: 141.897: [GC (Allocation Failure) [PSYoungGen: 1042656K->12544K(1201664K)] 1204932K->174884K(1440256K), 0.0117231 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2021-04-23T16:46:38.398+0800: 144.852: [GC (Allocation Failure) [PSYoungGen: 1076480K->11104K(1193472K)] 1238820K->173956K(1432064K), 0.0114057 secs] [Times: user=0.03 sys=0.02, real=0.01 secs]
2021-04-23T16:46:41.267+0800: 147.722: [GC (Allocation Failure) [PSYoungGen: 1075040K->11552K(1216000K)] 1237892K->174420K(1454592K), 0.0122714 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:46:44.342+0800: 150.796: [GC (Allocation Failure) [PSYoungGen: 1105184K->12688K(1208832K)] 1268052K->175580K(1447424K), 0.0118236 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:46:47.219+0800: 153.673: [GC (Allocation Failure) [PSYoungGen: 1106320K->12336K(1229824K)] 1269212K->175260K(1468416K), 0.0120391 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:46:50.190+0800: 156.645: [GC (Allocation Failure) [PSYoungGen: 1134128K->13264K(1223168K)] 1297052K->176204K(1461760K), 0.0126300 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:46:53.319+0800: 159.773: [GC (Allocation Failure) [PSYoungGen: 1135056K->12720K(1242112K)] 1297996K->175684K(1480704K), 0.0150936 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
2021-04-23T16:46:57.261+0800: 163.716: [GC (Allocation Failure) [PSYoungGen: 1159600K->22976K(1235968K)] 1322564K->185956K(1474560K), 0.0197274 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:47:00.383+0800: 166.837: [GC (Allocation Failure) [PSYoungGen: 1169856K->18432K(1253888K)] 1332836K->181428K(1492480K), 0.0137343 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:47:03.546+0800: 170.000: [GC (Allocation Failure) [PSYoungGen: 1188864K->12336K(1247744K)] 1351860K->175356K(1486336K), 0.0152053 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
2021-04-23T16:47:06.721+0800: 173.175: [GC (Allocation Failure) [PSYoungGen: 1182768K->12320K(1262080K)] 1345788K->175348K(1500672K), 0.0117930 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:47:09.881+0800: 176.335: [GC (Allocation Failure) [PSYoungGen: 1201184K->26496K(1257984K)] 1364212K->189556K(1496576K), 0.0175689 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:47:13.094+0800: 179.548: [GC (Allocation Failure) [PSYoungGen: 1215360K->12944K(1267712K)] 1378420K->176012K(1506304K), 0.0125079 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:47:16.334+0800: 182.788: [GC (Allocation Failure) [PSYoungGen: 1213584K->18176K(1264128K)] 1376652K->181282K(1502720K), 0.0161077 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:47:20.151+0800: 186.605: [GC (Allocation Failure) [PSYoungGen: 1218816K->13232K(1275392K)] 1381922K->176393K(1513984K), 0.0154384 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
2021-04-23T16:47:23.508+0800: 189.962: [GC (Allocation Failure) [PSYoungGen: 1229744K->27568K(1272320K)] 1392905K->190761K(1510912K), 0.0185133 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:47:26.827+0800: 193.281: [GC (Allocation Failure) [PSYoungGen: 1244080K->11840K(1277952K)] 1407273K->175892K(1516544K), 0.0115197 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:47:30.109+0800: 196.563: [GC (Allocation Failure) [PSYoungGen: 1233984K->11680K(1275392K)] 1398036K->175764K(1513984K), 0.0120605 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
2021-04-23T16:47:33.371+0800: 199.825: [GC (Allocation Failure) [PSYoungGen: 1233824K->23488K(1281536K)] 1397908K->188328K(1520128K), 0.0189819 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:47:36.800+0800: 203.254: [GC (Allocation Failure) [PSYoungGen: 1253824K->11264K(1280000K)] 1418664K->176120K(1518592K), 0.0128422 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:47:40.222+0800: 206.676: [GC (Allocation Failure) [PSYoungGen: 1241600K->13120K(1285632K)] 1406456K->178000K(1524224K), 0.0124956 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:47:43.582+0800: 210.036: [GC (Allocation Failure) [PSYoungGen: 1250624K->13456K(1283072K)] 1415504K->178368K(1521664K), 0.0121517 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:47:46.897+0800: 213.351: [GC (Allocation Failure) [PSYoungGen: 1250960K->17840K(1289728K)] 1415872K->182952K(1528320K), 0.0156291 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:47:50.306+0800: 216.761: [GC (Allocation Failure) [PSYoungGen: 1264048K->20576K(1287680K)] 1429160K->185720K(1526272K), 0.0148787 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:47:53.719+0800: 220.174: [GC (Allocation Failure) [PSYoungGen: 1266784K->13936K(1292800K)] 1431928K->179112K(1531392K), 0.0150392 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
2021-04-23T16:47:57.161+0800: 223.615: [GC (Allocation Failure) [PSYoungGen: 1266288K->16432K(1290752K)] 1431464K->181640K(1529344K), 0.0151169 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:48:00.530+0800: 226.985: [GC (Allocation Failure) [PSYoungGen: 1268784K->20560K(1295360K)] 1433992K->185800K(1533952K), 0.0152100 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:48:03.994+0800: 230.448: [GC (Allocation Failure) [PSYoungGen: 1279568K->14496K(1294848K)] 1444808K->179776K(1533440K), 0.0177966 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
2021-04-23T16:48:07.392+0800: 233.846: [GC (Allocation Failure) [PSYoungGen: 1273504K->13200K(1297920K)] 1438784K->178512K(1536512K), 0.0118668 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2021-04-23T16:48:10.804+0800: 237.258: [GC (Allocation Failure) [PSYoungGen: 1276816K->12896K(1296896K)] 1442128K->178240K(1535488K), 0.0115612 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2021-04-23T16:48:14.184+0800: 240.639: [GC (Allocation Failure) [PSYoungGen: 1276512K->15008K(1299968K)] 1441856K->180384K(1538560K), 0.0124917 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:48:17.570+0800: 244.024: [GC (Allocation Failure) [PSYoungGen: 1282720K->14112K(1298944K)] 1448096K->179536K(1537536K), 0.0122087 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:48:20.954+0800: 247.408: [GC (Allocation Failure) [PSYoungGen: 1281824K->19840K(1300480K)] 1447248K->185288K(1539072K), 0.0155607 secs] [Times: user=0.01 sys=0.02, real=0.02 secs]
2021-04-23T16:48:24.388+0800: 250.842: [GC (Allocation Failure) [PSYoungGen: 1290624K->23568K(1294848K)] 1456072K->189056K(1533440K), 0.0160307 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:48:27.884+0800: 254.339: [GC (Allocation Failure) [PSYoungGen: 1294352K->13296K(1300480K)] 1459840K->178880K(1539072K), 0.0136047 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:48:31.620+0800: 258.074: [GC (Allocation Failure) [PSYoungGen: 1282544K->14816K(1299968K)] 1448128K->182266K(1538560K), 0.0159953 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:48:35.156+0800: 261.610: [GC (Allocation Failure) [PSYoungGen: 1284064K->15232K(1302528K)] 1451514K->182730K(1541120K), 0.0136714 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:48:38.756+0800: 265.210: [GC (Allocation Failure) [PSYoungGen: 1288064K->24320K(1297408K)] 1455562K->191842K(1536000K), 0.0166216 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:48:42.238+0800: 268.692: [GC (Allocation Failure) [PSYoungGen: 1297152K->17648K(1302016K)] 1464674K->185202K(1540608K), 0.0156265 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:48:45.624+0800: 272.078: [GC (Allocation Failure) [PSYoungGen: 1289456K->12464K(1300992K)] 1457010K->180154K(1539584K), 0.0118812 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:48:49.033+0800: 275.487: [GC (Allocation Failure) [PSYoungGen: 1284272K->20992K(1301504K)] 1451962K->188955K(1540096K), 0.0156894 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
2021-04-23T16:48:52.399+0800: 278.853: [GC (Allocation Failure) [PSYoungGen: 1293824K->19328K(1302016K)] 1461787K->187435K(1540608K), 0.0152671 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:48:55.926+0800: 282.381: [GC (Allocation Failure) [PSYoungGen: 1292160K->16208K(1303552K)] 1460267K->184347K(1542144K), 0.0192634 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
2021-04-23T16:48:59.485+0800: 285.939: [GC (Allocation Failure) [PSYoungGen: 1291088K->11616K(1302528K)] 1459227K->179787K(1541120K), 0.0117753 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:49:02.947+0800: 289.401: [GC (Allocation Failure) [PSYoungGen: 1286496K->13424K(1304064K)] 1454667K->181626K(1542656K), 0.0123255 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:49:06.369+0800: 292.824: [GC (Allocation Failure) [PSYoungGen: 1289840K->21040K(1297920K)] 1458042K->189275K(1536512K), 0.0178856 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
2021-04-23T16:49:11.575+0800: 298.029: [GC (Allocation Failure) [PSYoungGen: 1297456K->21008K(1303040K)] 1465691K->189275K(1541632K), 0.0151061 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
2021-04-23T16:49:14.980+0800: 301.435: [GC (Allocation Failure) [PSYoungGen: 1295888K->26352K(1301504K)] 1464155K->194651K(1540096K), 0.0178180 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:49:18.437+0800: 304.891: [GC (Allocation Failure) [PSYoungGen: 1301232K->29680K(1290240K)] 1469531K->202251K(1528832K), 0.0224459 secs] [Times: user=0.09 sys=0.02, real=0.02 secs]
2021-04-23T16:49:22.038+0800: 308.493: [GC (Allocation Failure) [PSYoungGen: 1290224K->11472K(1295872K)] 1462795K->184075K(1534464K), 0.0118862 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
2021-04-23T16:49:25.509+0800: 311.963: [GC (Allocation Failure) [PSYoungGen: 1272016K->11520K(1296384K)] 1444619K->184123K(1534976K), 0.0120496 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:49:28.897+0800: 315.351: [GC (Allocation Failure) [PSYoungGen: 1272576K->17168K(1295872K)] 1445179K->189827K(1534464K), 0.0148384 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:49:32.652+0800: 319.106: [GC (Allocation Failure) [PSYoungGen: 1278224K->12032K(1298432K)] 1450883K->185187K(1537024K), 0.0122488 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:49:36.128+0800: 322.582: [GC (Allocation Failure) [PSYoungGen: 1277184K->27040K(1292288K)] 1450339K->200386K(1530880K), 0.0184628 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:49:39.631+0800: 326.085: [GC (Allocation Failure) [PSYoungGen: 1292192K->11488K(1296896K)] 1465538K->184834K(1535488K), 0.0139051 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
2021-04-23T16:49:43.084+0800: 329.538: [GC (Allocation Failure) [PSYoungGen: 1273568K->11168K(1296384K)] 1446914K->184522K(1534976K), 0.0140695 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2021-04-23T16:49:46.448+0800: 332.902: [GC (Allocation Failure) [PSYoungGen: 1273248K->29888K(1291264K)] 1446602K->203258K(1529856K), 0.0205998 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:49:50.082+0800: 336.536: [GC (Allocation Failure) [PSYoungGen: 1287360K->18880K(1294336K)] 1460730K->192274K(1532928K), 0.0154204 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2021-04-23T16:49:53.939+0800: 340.393: [GC (Allocation Failure) [PSYoungGen: 1276352K->35301K(1282560K)] 1449746K->213632K(1521152K), 0.0356496 secs] [Times: user=0.11 sys=0.00, real=0.04 secs]
2021-04-23T16:49:57.937+0800: 344.390: [GC (Allocation Failure) [PSYoungGen: 1282502K->23461K(1289216K)] 1460832K->201824K(1527808K), 0.0148029 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 

笔者希望通过GC日志分析FULL GC的原因,而避免GC的耗时,优化程序的响应。从GC日志可以看出,在这么多次GC中发生了2次FULL GC,而且这2次FULL GC 的时间消耗快抵得上其他新生代的GC耗时,具体统计图如下。

本次测试使用的垃圾收集器是ParallelGC收集器(JDK8默认垃圾收集器,即Parallel Scavenge + Parallel Old),而Parallel Scavenge收集器会注重吞吐量,即吞吐量优先,而FULL GC(Ergonomics)是由Parallel Scavenge收集器自动平衡吞吐量和停顿时间时产生的,产生的判断条件,根据参考,如果晋升到老生代的平均大小大于老生代的剩余大小,则需要一次FULL GC。

三、比较

2021-04-23T16:45:47.739+0800: 94.193: [GC (Allocation Failure) [PSYoungGen: 1046903K->65453K(946176K)] 1047626K->167344K(1048576K), 0.0896584 secs] [Times: user=0.24 sys=0.08, real=0.09 secs]
2021-04-23T16:45:47.830+0800: 94.284: [Full GC (Ergonomics) [PSYoungGen: 65453K->60377K(946176K)] [ParOldGen: 101891K->102348K(161792K)] 167344K->162725K(1107968K), [Metaspace: 69759K->69584K(1114112K)], 0.8424038 secs] [Times: user=2.36 sys=0.00, real=0.84 secs]
2021-04-23T16:45:50.912+0800: 97.366: [GC (Allocation Failure) [PSYoungGen: 941017K->14224K(1080320K)] 1043365K->166411K(1242112K), 0.0340157 secs] [Times: user=0.08 sys=0.03, real=0.03 secs]
2021-04-23T16:45:50.946+0800: 97.400: [Full GC (Ergonomics) [PSYoungGen: 14224K->4398K(1080320K)] [ParOldGen: 152187K->161652K(238592K)] 166411K->166050K(1318912K), [Metaspace: 69584K->69584K(1114112K)], 0.2608357 secs] [Times: user=0.74 sys=0.02, real=0.26 secs]

既然该收集器是以吞吐量优先,那我换一个垃圾收集器试试吧。

1.改用CMS收集器,同条件下测试,GC结果。

2.改用CMS + parNew测试,参数调整如下,结果如下。

3.改用G1收集器,从结果可以看到,在连续一段时间内,会有多次Young GC,而导致STW,此时,响应时间骤增,最高达到了5.8s。

四、调优

1  由对比可以看出,CMS或G1垃圾收集器在响应时间和吞吐量方面都逊色于JDK8的默认垃圾收集器,据此可推断JDK8默认的垃圾收集器可能更适合我的程序,那么下一步的调优工作即可针对该收集器展开。

1.1  对AdaptiveSizePolicy参数进行配置:

  开启:-XX:+UseAdaptiveSizePolicy关闭:-XX:-UseAdaptiveSizePolicy

该收集器默认打开关闭参数,遂关闭该参数测试,测试结果差强人意,故舍弃该参数的配置。

1.2  从线程数方面考虑,通过程序日志观察,程序主要耗时是在数据校验与封装阶段,外部io所占的时间相对较少,故怀疑是Tomcat配置过多的线程,导致CPU对线程的调度耗时过长,将tomcat的线程数从原来的最大线程数300调降至50进行测试(最大连接数与可接受数由原来的的1000与300调至1000与50),测试2次结果如下,结果也是符合预期的,相对于未调整线程数时,确实在响应时间方面得到了优化。究其缘由,CMS是并行的垃圾收集器,也需要用到线程,如果工作程序的线程数预设过多,用于标记清除的线程会减少,这也会加大GC的时间。目前暂时先这样吧,项目对并发的要求其实并不高,这样的吞吐量也能够满足了,下一步可以对程序代码进行硬编码优化,进一步优化程序的响应时间。

2   在第一步的基础上再更换响应时间优先的垃圾收集器,比如CMS(老年代) +  ParaNew(新生代),再进行同样条件下的测试,发现效果也不错,吞吐量稍有提高,可是响应时间并没有实质的优化,测试结果如下。再观察压测时的GC,无FUll GC的产生。

至此,优化已经达到预期目标了,减少FULL GC,优化响应时间。相对于比较章节时的测试,这次对于JVM的调整如下,而之前的调整仅是使用了CMS + ParNew收集器,并未对堆内存等进行调整。

-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-XX:+PrintGCDateStamps
-Xloggc:D:\gc-cms-paran.log
-XX:MetaspaceSize=128m
-Xmx4096m
-Xms4096m
-Xmn2g
-Xss256k                       //设置每个线程的堆栈大小,可根据实际情况调整
-XX:+UseParNewGC
-XX:+UseConcMarkSweepGC

3  观察S0区和S1区的使用情况,发现此时的Max tenuring threshold 的配置为6,而每个年龄分代实际的使用内存占用比较小,完全不会超过S区内存的一半,并且各分代的平均大小在age2的时候发生骤减,猜测是这些对象已经被动态提升到老年区,于是,直接设置参数-XX:MaxTenuringThreshold=2,让这些在经历2轮Minor GC仍然存活的对象直接提升到老年代,避免这些对象在两个S区中来回复制而造成的服务器性能开销,添加参数后进行测试,发现在响应时间上没有明显的提升,可是吞吐量提高了近100个。

调整后:

4  配置元空间的初始大小,即上面的MetaspaceSize配置,该参数的默认配置为20m,当该空间快满的时候会触发扩容而进行一次FULL GC(Metadata GC Threshold),初始值可以根据实际情况调整,128m对于我的程序而言够用,在压测期间不会发生该类型的FULL GC,因而如此配置。

五、总结

对于JVM的调优原则,我觉得可以总结为以下几点:

后续优化思路:

  • 升级JDK9 ,使用其默认的G1垃圾收集器
  • 使用ZGC
  • 代码重构
  • ...

记一次Full GC(Ergonomics)引发的思考相关推荐

  1. 干货 | 记一次跨域配置引发的思考

    作者简介 Flora,携程高级研发经理,关注Node.js相关领域. 本文主要记录一次静态资源服务源站更新了跨域策略后,引发的客户端跨域请求失败的案例. 如果对跨域不太熟悉的同学,可以阅读一下MDN ...

  2. 由「Metaspace容量不足触发CMS GC」从而引发的思考

    转载自  由「Metaspace容量不足触发CMS GC」从而引发的思考 某天早上,毛老师在群里问「cat 上怎么看 gc」. 好好的一个群 看到有 GC 的问题,立马做出小鸡搓手状. 之后毛老师发来 ...

  3. mysql gtid 还是pxc_记一次 PXC 集群拆分引发的思考

    原标题:记一次 PXC 集群拆分引发的思考 作者简介 冷正磊 2018年2月加入去哪儿网 DBA 团队,主要负责机票业务的 MySQL 和 Redis 数据库的运维管理工作,以及数据库自动化运维平台部 ...

  4. Full GC (Ergonomics) 原因和实验

    本文参考的圣思园张龙讲的JVM虚拟机 背景 首先程序如下:创建4个2M的对象 并设置如下参数: -verbose:gc 会输出详细的垃圾回收信息 -Xms20M   初始值20m 堆空间 -Xmx20 ...

  5. 升级jenkins 导致jenkins启动失败_害你加班的Bug是我写的,记一次升级Jenkins插件引发的加班

    本文主要记录了下Jenkins升级插件过程中出现的场景,一次加班经历,事发时没有截图,有兴趣可以看看. 起因 需求 最近有个需求:在Jenkins流水线中完成下载Git上的文件简单修改并提交的功能 起 ...

  6. 害你加班的bug就是我写的,记一次升级Jenkins插件引发的加班

    主旨 本文主要记录了下Jenkins升级插件过程中出现的场景,一次加班经历,事发时没有截图,有兴趣可以看看. 起因 需求 最近有个需求:在Jenkins流水线中完成下载Git上的文件简单修改并提交的功 ...

  7. 一个小程序引发的思考

    既然是一个小程序引发的思考,那么我们就先看看这个小程序,看看他有何神奇之处: namespace ConsoleApplication1 {class Program{static void Main ...

  8. 【汇编语言与计算机系统结构笔记01】x86/MIPS/ARM指令集概述与特性,一篇HPCA引发的思考(商业生态的决定性作用)

    资源Bilibili AV46914471 + AV57921488 汇编语言与计算机系统结构 清华大学 张悠慧 本次笔记内容: 01.汇编语言与计算机系统结构 02.汇编基础知识--指令集综述 文章 ...

  9. 阿里面试题亿级表合并引发的思考之 SQL Bloom Filter(二)

    布隆过滤器在日常开发中常见,但在 SQL 使用中大家肯定会很陌生.详情见我上一篇文章: 阿里面试题亿级表合并引发的思考之 SQL Bloom Filter(一) 首先,我们直接上图,一目了然来看下 B ...

  10. JAVA-OPTS引发的思考

    JAVA-OPTS引发的思考 我们在性能测试过程中,经常要修改应用的JAVA-OPTS参数.修改这些参数,不单单是修改这些数字,本着知其所以然的态度,我们要知道这些参数背后的意义. 常见的JAVA-O ...

最新文章

  1. php 编译安装降解,对php编译安装的修正
  2. EditText 自动保留两位小数
  3. 最好js代码验证×××号码
  4. [科普]MinGW vs MinGW-W64及其它
  5. 使用XMANAGER 联接LINUX 后使用SQLPLUS 不能使用BACKSPACE 回格键.
  6. 服务端高并发分布式架构演进之路(转载,图画的好)
  7. 摩根大通:iPhone 13和新款iPhone SE将推动苹果业绩明年再破纪录
  8. python shell 运行时不打印日志_shell编程
  9. Twitter数据抓取的方法(三)
  10. Java实现拖拉/滑动图片验证码
  11. Rect类基本函数使用
  12. 省选+NOI 第九部分 博弈论
  13. java 排班日历,排班日历
  14. linux7.1装宝塔,CentOS 7.6 宝塔 + SSRPanel 安装
  15. 【力扣3题】快乐数有效的字母异位词字符串中的单词数
  16. try{}里面有一个return语句,那么紧跟在这个try后的finally{}里的code会不会被执行,什么时候被执行,在return前还是后?
  17. 用python制作田字格_2分钟学会在Word中制作田字格 米字格 书法练字再也不用买本子了...
  18. 博南石上海公司的那个hr,貌似叫什么harvey hou,太恶心了。。。
  19. 应该担心什么不应该关心什么(做正确的事,把事情做对)
  20. Dynamic Bone(Unity拖尾插件)使用说明

热门文章

  1. cocos creator编写简易游戏摇杆以及通过摇杆控制精灵移动
  2. [源码和报告分享]基于C++实现的运动会统分系统
  3. Windows实例通过IIS如何搭建多个FTP站点
  4. win10桌面计算机打不开,win10开机后桌面无响应,win10开机后啥都打不开
  5. linux qemu的使用教程,详解QEMU网络配置的方法
  6. Priceline拥有五个子品牌分别是:Booking.com、Priceline.com、Agoda、Kayak 以及Rentalcars
  7. Hyperledger Fabric(1) - 整体架构和源码结构
  8. git-commit-amend踩坑
  9. AndroidImageSlider三分钟快速集成酷炫自动轮播广告
  10. oj刷题 Problem J: 软件工程