2012-07-17 33 views
2

我收到了一份报告,表明我的服务有时不响应。密集的GC活动会关闭服务临时服务

我发现一个Java进程完全占据(其中4只有一个核心)一个核心,

所以我通过网络搜索,发现这样的:Hung JVM consuming 100% CPU

我开始记录每GC活动,并发现奇怪的日志。

26149.891: [GC [PSYoungGen: 138048K->37757K(184512K)] 360110K->295763K(1495232K), 0.0749820 secs] [Times: user=0.53 sys=0.02, real=0.07 secs] 
26150.173: [GC [PSYoungGen: 143741K->37312K(183616K)] 401747K->333115K(1494336K), 0.0706090 secs] [Times: user=0.50 sys=0.02, real=0.07 secs] 
26150.450: [GC [PSYoungGen: 143296K->37280K(187328K)] 439099K->370363K(1498048K), 0.1557100 secs] [Times: user=1.07 sys=0.02, real=0.15 secs] 
26150.818: [GC [PSYoungGen: 148320K->42028K(185856K)] 481403K->412407K(1496576K), 0.0835340 secs] [Times: user=0.60 sys=0.03, real=0.08 secs] 
26151.121: [GC [PSYoungGen: 153068K->39040K(188416K)] 523447K->451423K(1499136K), 0.0831170 secs] [Times: user=0.58 sys=0.02, real=0.08 secs] 
26151.436: [GC [PSYoungGen: 152448K->39872K(187136K)] 564831K->491311K(1497856K), 0.1627710 secs] [Times: user=1.22 sys=0.03, real=0.17 secs] 
26151.832: [GC [PSYoungGen: 153280K->39744K(190720K)] 604719K->531063K(1501440K), 0.1741030 secs] [Times: user=1.30 sys=0.03, real=0.17 secs] 
26152.230: [GC [PSYoungGen: 157760K->46130K(189440K)] 649079K->577265K(1500160K), 0.0940570 secs] [Times: user=0.66 sys=0.03, real=0.09 secs] 
26152.554: [GC [PSYoungGen: 164146K->41504K(190784K)] 695281K->618785K(1501504K), 0.0948330 secs] [Times: user=0.68 sys=0.02, real=0.10 secs] 
26152.879: [GC [PSYoungGen: 159840K->41440K(189696K)] 737121K->660233K(1500416K), 0.1807870 secs] [Times: user=1.37 sys=0.02, real=0.18 secs] 
26153.296: [GC [PSYoungGen: 159776K->41568K(193280K)] 778569K->701849K(1504000K), 0.1802040 secs] [Times: user=1.22 sys=0.03, real=0.18 secs] 
26153.721: [GC [PSYoungGen: 164768K->43168K(192064K)] 825049K->745065K(1502784K), 0.1874250 secs] [Times: user=1.42 sys=0.02, real=0.19 secs] 
26154.134: [GC [PSYoungGen: 159404K->40352K(195840K)] 861301K->785481K(1506560K), 0.1758760 secs] [Times: user=1.30 sys=0.02, real=0.18 secs] 
26154.546: [GC [PSYoungGen: 168032K->51803K(179520K)] 913161K->837348K(1490240K), 0.1128670 secs] [Times: user=0.76 sys=0.02, real=0.12 secs] 
26154.910: [GC [PSYoungGen: 179483K->44768K(194112K)] 965028K->882164K(1504832K), 0.1198690 secs] [Times: user=0.88 sys=0.03, real=0.12 secs] 
26155.275: [GC [PSYoungGen: 170080K->44064K(193344K)] 1007476K->926252K(1504064K), 0.2003860 secs] [Times: user=1.51 sys=0.02, real=0.20 secs] 
26155.722: [GC [PSYoungGen: 169376K->43968K(196352K)] 1051564K->970212K(1507072K), 0.2186830 secs] [Times: user=1.67 sys=0.03, real=0.22 secs] 
26156.194: [GC [PSYoungGen: 173376K->45472K(195200K)] 1099620K->1015700K(1505920K), 0.1993740 secs] [Times: user=1.40 sys=0.04, real=0.20 secs] 
26156.647: [GC [PSYoungGen: 174880K->45440K(197696K)] 1145108K->1061172K(1508416K), 0.2208800 secs] [Times: user=1.64 sys=0.03, real=0.23 secs] 
26157.125: [GC [PSYoungGen: 177984K->45984K(196992K)] 1193716K->1107220K(1507712K), 0.2207530 secs] [Times: user=1.62 sys=0.02, real=0.22 secs] 
26157.580: [GC [PSYoungGen: 178528K->56664K(191680K)] 1239764K->1163988K(1502400K), 0.1383820 secs] [Times: user=0.98 sys=0.04, real=0.14 secs] 
26157.966: [GC [PSYoungGen: 184408K->44768K(194944K)] 1291732K->1208844K(1505664K), 0.1331440 secs] [Times: user=0.94 sys=0.03, real=0.14 secs] 
26158.457: [GC [PSYoungGen: 172512K->44928K(198336K)] 1336588K->1253828K(1509056K), 0.2231800 secs] [Times: user=1.68 sys=0.03, real=0.23 secs] 
26158.963: [GC [PSYoungGen: 177856K->46624K(196736K)] 1386756K->1300436K(1507456K), 0.2182210 secs] [Times: user=1.65 sys=0.03, real=0.22 secs] 
26159.181: [Full GC [PSYoungGen: 46624K->0K(196736K)] [PSOldGen: 1253812K->1300242K(1310720K)] 1300436K->1300242K(1507456K) [PSPermGen: 55231K->55231K(262144K)], 3.4748620 secs] [Times: user=3.43 sys=0.03, real=3.47 secs] 
26163.002: [Full GC [PSYoungGen: 132928K->35639K(196736K)] [PSOldGen: 1300242K->1310720K(1310720K)] 1433170K->1346359K(1507456K) [PSPermGen: 55231K->55231K(262144K)], 3.5303910 secs] [Times: user=3.51 sys=0.02, real=3.53 secs] 
26166.802: [Full GC [PSYoungGen: 132928K->76010K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1386730K(1507456K) [PSPermGen: 55231K->55231K(262144K)], 3.4764380 secs] [Times: user=3.48 sys=0.00, real=3.47 secs] 
26170.464: [Full GC [PSYoungGen: 132928K->41991K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1352711K(1507456K) [PSPermGen: 55231K->55211K(262144K)], 4.6156250 secs] [Times: user=4.57 sys=0.04, real=4.61 secs] 
26175.372: [Full GC [PSYoungGen: 132928K->80309K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1391029K(1507456K) [PSPermGen: 55211K->55211K(262144K)], 3.5159220 secs] [Times: user=3.51 sys=0.00, real=3.51 secs] 
26179.074: [Full GC [PSYoungGen: 132928K->98592K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1409312K(1507456K) [PSPermGen: 55211K->55211K(262144K)], 3.5558960 secs] [Times: user=3.55 sys=0.00, real=3.55 secs] 
26182.700: [Full GC [PSYoungGen: 132928K->110146K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1420866K(1507456K) [PSPermGen: 55211K->55211K(262144K)], 3.8777130 secs] [Times: user=3.87 sys=0.00, real=3.88 secs] 
26186.663: [Full GC [PSYoungGen: 132928K->111368K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1422088K(1507456K) [PSPermGen: 55211K->55211K(262144K)], 4.5746670 secs] [Times: user=4.57 sys=0.00, real=4.57 secs] 
26191.321: [Full GC [PSYoungGen: 132928K->125449K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1436169K(1507456K) [PSPermGen: 55211K->55211K(262144K)], 3.6080590 secs] [Times: user=3.56 sys=0.04, real=3.61 secs] 
26194.954: [Full GC [PSYoungGen: 132928K->127668K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1438388K(1507456K) [PSPermGen: 55211K->55211K(262144K)], 3.5435640 secs] [Times: user=3.54 sys=0.00, real=3.54 secs] 
26198.517: [Full GC [PSYoungGen: 132928K->129407K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1440127K(1507456K) [PSPermGen: 55211K->55211K(262144K)], 3.5862840 secs] [Times: user=3.57 sys=0.02, real=3.58 secs] 
26202.117: [Full GC [PSYoungGen: 132928K->123893K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1434613K(1507456K) [PSPermGen: 55211K->55211K(262144K)], 4.7643840 secs] [Times: user=4.73 sys=0.03, real=4.76 secs] 
26206.912: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55214K->55214K(262144K)], 3.6269220 secs] [Times: user=3.62 sys=0.00, real=3.63 secs] 
26210.539: [Full GC [PSYoungGen: 132928K->126271K(196736K)] [PSOldGen: 1310720K->1310719K(1310720K)] 1443648K->1436991K(1507456K) [PSPermGen: 55214K->55151K(262144K)], 4.6103030 secs] [Times: user=4.61 sys=0.00, real=4.61 secs] 
26215.191: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55202K->55202K(262144K)], 3.5856180 secs] [Times: user=3.59 sys=0.00, real=3.59 secs] 
26218.777: [Full GC [PSYoungGen: 132928K->128287K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1439007K(1507456K) [PSPermGen: 55202K->55151K(262144K)], 4.6097420 secs] [Times: user=4.60 sys=0.00, real=4.60 secs] 
26223.406: [Full GC [PSYoungGen: 132926K->132926K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443646K->1443646K(1507456K) [PSPermGen: 55202K->55202K(262144K)], 3.6066240 secs] [Times: user=3.60 sys=0.00, real=3.61 secs] 
26227.012: [Full GC [PSYoungGen: 132926K->129377K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443646K->1440097K(1507456K) [PSPermGen: 55202K->55184K(262144K)], 4.6120400 secs] [Times: user=4.61 sys=0.00, real=4.61 secs] 
26231.653: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55199K->55199K(262144K)], 3.5711710 secs] [Times: user=3.59 sys=0.00, real=3.57 secs] 
26235.225: [Full GC [PSYoungGen: 132928K->130479K(196736K)] [PSOldGen: 1310719K->1310720K(1310720K)] 1443647K->1441199K(1507456K) [PSPermGen: 55199K->55199K(262144K)], 4.4967450 secs] [Times: user=4.49 sys=0.00, real=4.50 secs] 
26239.732: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55202K->55202K(262144K)], 3.5474400 secs] [Times: user=3.54 sys=0.00, real=3.54 secs] 
26243.279: [Full GC [PSYoungGen: 132928K->131113K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1441833K(1507456K) [PSPermGen: 55202K->55184K(262144K)], 3.5526010 secs] [Times: user=3.55 sys=0.00, real=3.56 secs] 
26246.838: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55202K->55202K(262144K)], 3.5478440 secs] [Times: user=3.54 sys=0.01, real=3.55 secs] 
26250.386: [Full GC [PSYoungGen: 132928K->131392K(196736K)] [PSOldGen: 1310720K->1310719K(1310720K)] 1443648K->1442112K(1507456K) [PSPermGen: 55202K->55157K(262144K)], 3.6749040 secs] [Times: user=3.67 sys=0.00, real=3.67 secs] 
26254.067: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.secs] [Times: user=3.59 sys=0.00, real=3.58 secs] 
26257.650: [Full GC [PSYoungGen: 132928K->131782K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1442502K(1507456K) [PSPermGen: 55178K->55166K(262144K)], 3.5557440 secs] [Times: user=3.55 sys=0.00, real=3.56 secs] 
26261.211: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55175K->55175K(262144K)], 3.5458550 secs] [Times: user=3.55 sys=0.00, real=3.55 secs] 
26264.757: [Full GC [PSYoungGen: 132928K->132082K(196736K)] [PSOldGen: 1310719K->1310720K(1310720K)] 1443647K->1442802K(1507456K) [PSPermGen: 55175K->55154K(262144K)], 4.5970920 secs] [Times: user=4.60 sys=0.00, real=4.59 secs] 
26269.357: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55157K->55157K(262144K)], 3.5443640 secs] [Times: user=3.55 sys=0.00, real=3.54 secs] 
26272.901: [Full GC [PSYoungGen: 132928K->132206K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1442926K(1507456K) [PSPermGen: 55157K->55157K(262144K)], 4.6007130 secs] [Times: user=4.60 sys=0.00, real=4.60 secs] 
26277.504: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55169K->55169K(262144K)], 3.5481120 secs] [Times: user=3.55 sys=0.00, real=3.55 secs] 
26281.052: [Full GC [PSYoungGen: 132928K->132330K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443050K(1507456K) [PSPermGen: 55169K->55160K(262144K)], 3.5732500 secs] [Times: user=3.57 sys=0.00, real=3.57 secs] 
26284.628: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55163K->55163K(262144K)], 3.5440330 secs] [Times: user=3.55 sys=0.00, real=3.54 secs] 
26288.173: [Full GC [PSYoungGen: 132928K->132396K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443116K(1507456K) [PSPermGen: 55163K->55154K(262144K)], 3.5533020 secs] [Times: user=3.55 sys=0.00, real=3.55 secs] 
26291.728: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55156K->55156K(262144K)], 3.5478580 secs] [Times: user=3.55 sys=0.00, real=3.55 secs] 
26295.276: [Full GC [PSYoungGen: 132928K->132554K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443274K(1507456K) [PSPermGen: 55156K->55153K(262144K)], 3.5612690 secs] [Times: user=3.56 sys=0.00, real=3.56 secs] 
26298.840: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55163K->55163K(262144K)], 3.5476290 secs] [Times: user=3.54 sys=0.00, real=3.54 secs] 
26302.387: [Full GC [PSYoungGen: 132928K->132630K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443350K(1507456K) [PSPermGen: 55163K->55163K(262144K)], 3.5523880 secs] [Times: user=3.56 sys=0.00, real=3.55 secs] 
26305.941: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55166K->55166K(262144K)], 3.5477250 secs] [Times: user=3.55 sys=0.00, real=3.54 secs] 
26309.489: [Full GC [PSYoungGen: 132928K->132694K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443414K(1507456K) [PSPermGen: 55166K->55160K(262144K)], 3.5517750 secs] [Times: user=3.55 sys=0.00, real=3.55 secs] 
26313.042: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55164K->55164K(262144K)], 3.6786080 secs] [Times: user=3.66 sys=0.01, real=3.67 secs] 
26316.721: [Full GC [PSYoungGen: 132928K->132761K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443481K(1507456K) [PSPermGen: 55164K->55164K(262144K)], 3.5701210 secs] [Times: user=3.57 sys=0.00, real=3.57 secs] 
26320.293: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55169K->55169K(262144K)], 3.5485590 secs] [Times: user=3.55 sys=0.00, real=3.54 secs] 
26323.842: [Full GC [PSYoungGen: 132928K->132815K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443535K(1507456K) [PSPermGen: 55169K->55169K(262144K)], 3.5526530 secs] [Times: user=3.55 sys=0.00, real=3.56 secs] 
26327.396: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55169K->55169K(262144K)], 3.5483590 secs] [Times: user=3.55 sys=0.00, real=3.54 secs] 
26330.944: [Full GC [PSYoungGen: 132928K->132833K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443553K(1507456K) [PSPermGen: 55169K->55166K(262144K)], 3.5551080 secs] [Times: user=3.55 sys=0.00, real=3.56 secs] 
26334.501: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310720K->1310720K(1310720K)] 1443648K->1443648K(1507456K) [PSPermGen: 55172K->55172K(262144K)], 3.6050900 secs] [Times: user=3.59 sys=0.01, real=3.61 secs] 
26338.106: [Full GC [PSYoungGen: 132928K->132833K(196736K)] [PSOldGen: 1310720K->1310719K(1310720K)] 1443648K->1443553K(1507456K) [PSPermGen: 55172K->55172K(262144K)], 4.6456700 secs] [Times: user=4.63 sys=0.01, real=4.64 secs] 
26342.754: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.6874260 secs] [Times: user=3.69 sys=0.00, real=3.69 secs] 
26346.442: [Full GC [PSYoungGen: 132928K->132859K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443579K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 4.6572880 secs] [Times: user=4.65 sys=0.00, real=4.66 secs] 
26351.100: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5457670 secs] [Times: user=3.54 sys=0.00, real=3.54 secs] 
26354.646: [Full GC [PSYoungGen: 132928K->132854K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443574K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.8780600 secs] [Times: user=3.88 sys=0.00, real=3.88 secs] 
26358.525: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.6869670 secs] [Times: user=3.68 sys=0.00, real=3.69 secs] 
26362.212: [Full GC [PSYoungGen: 132928K->132870K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443590K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.6601190 secs] [Times: user=3.65 sys=0.00, real=3.66 secs] 
26365.874: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5784780 secs] [Times: user=3.57 sys=0.01, real=3.58 secs] 
26369.452: [Full GC [PSYoungGen: 132928K->132893K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443613K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5865440 secs] [Times: user=3.56 sys=0.02, real=3.58 secs] 
26373.040: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5989820 secs] [Times: user=3.57 sys=0.03, real=3.60 secs] 
26376.639: [Full GC [PSYoungGen: 132928K->132897K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443617K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5529890 secs] [Times: user=3.55 sys=0.00, real=3.56 secs] 
26380.193: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5474210 secs] [Times: user=3.55 sys=0.00, real=3.54 secs] 
26383.740: [Full GC [PSYoungGen: 132928K->132915K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443635K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5972640 secs] [Times: user=3.58 sys=0.01, real=3.60 secs] 
26387.339: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.6116590 secs] [Times: user=3.59 sys=0.02, real=3.61 secs] 
26390.950: [Full GC [PSYoungGen: 132928K->132912K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443632K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.6188690 secs] [Times: user=3.58 sys=0.04, real=3.62 secs] 
26394.570: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.6132870 secs] [Times: user=3.59 sys=0.01, real=3.61 secs] 
26398.184: [Full GC [PSYoungGen: 132928K->132916K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443636K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5736670 secs] [Times: user=3.57 sys=0.01, real=3.58 secs] 
26401.759: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5491540 secs] [Times: user=3.54 sys=0.00, real=3.55 secs] 
26405.308: [Full GC [PSYoungGen: 132928K->132919K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443639K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5484790 secs] [Times: user=3.55 sys=0.00, real=3.55 secs] 
26408.857: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5489760 secs] [Times: user=3.55 sys=0.00, real=3.54 secs] 
26412.406: [Full GC [PSYoungGen: 132928K->132922K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443642K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5474050 secs] [Times: user=3.55 sys=0.00, real=3.55 secs] 
26415.955: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5476430 secs] [Times: user=3.54 sys=0.00, real=3.55 secs] 
26419.502: [Full GC [PSYoungGen: 132928K->132922K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443642K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5518040 secs] [Times: user=3.56 sys=0.00, real=3.55 secs] 
26423.055: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5467870 secs] [Times: user=3.54 sys=0.00, real=3.55 secs] 
26426.602: [Full GC [PSYoungGen: 132928K->132924K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443644K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.5525280 secs] [Times: user=3.55 sys=0.00, real=3.55 secs] 
26430.156: [Full GC [PSYoungGen: 132928K->132928K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443647K(1507456K) [PSPermGen: 55178K->55178K(262144K)], 3.6035060 secs] [Times: user=3.60 sys=0.00, real=3.61 secs] 
26433.760: [Full GC [PSYoungGen: 132928K->132920K(196736K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1443647K->1443640K(1507456K) [PSPermGen: 55178K->55172K(262144K)], 3.5433380 secs] [Times: user=3.54 sys=0.00, real=3.54 secs] 
26437.304: [Full GC [PSYoungGen: 132928K->0K(196736K)] [PSOldGen: 1310719K->53875K(1310720K)] 1443647K->53875K(1507456K) [PSPermGen: 55172K->55172K(262144K)], 0.6250820 secs] [Times: user=0.63 sys=0.00, real=0.62 secs] 
26723.816: [GC [PSYoungGen: 132928K->4016K(189504K)] 186803K->57891K(1500224K), 0.secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
27069.299: [GC [PSYoungGen: 130608K->8368K(134976K)] 184483K->62243K(1445696K), 0.0219260 secs] [Times: user=0.14 sys=0.00, real=0.02 secs] 
myScheduler-2> [2012-07-17 17:35:00] [AlarmService] [110] [INFO] issue alarm mail sent, contract_id = 10, tweet_id = 225111165720735745 
27436.179: [GC [PSYoungGen: 134960K->12816K(190400K)] 188835K->66692K(1501120K), 0.0323320 secs] [Times: user=0.23 sys=0.00, real=0.03 secs] 
27782.840: [GC [PSYoungGen: 132880K->16976K(191104K)] 186756K->70852K(1501824K), 0.0416410 secs] [Times: user=0.31 sys=0.00, real=0.04 secs] 

正如你所看到的,在一段时间内,完整的GC活动被执行并且tomcat挂起。

它最终恢复,但它同时瘫痪我的服务。

有人知道我的机器正在发生什么吗?

+0

GC日志的墙壁对我至关重要。 :o – 2012-07-17 08:58:57

+0

@Thomas对不起,我修改了它:$ – 2012-07-17 08:59:48

回答

5

大约5分钟,除了运行主要的GC之外,您的应用程序几乎不做任何事情。每个GC需要3-4秒(此时JVM没有响应),紧接着是另一个GC。 (?一个核心),同时GC消耗了100%的CPU

需要注意的是每个主要GC是不是真的收集任何垃圾,无论是在年轻:

PSYoungGen: 132928K->132922K(196736K) 

,并在老一代:

PSOldGen: 1310719K->1310719K(1310720K) 

而且由于JVM无法找到任何空闲的内存,它再次运行GC,又一次,...

但是您的应用程序不只是崩溃。相反,它突然这几分钟(分割线的清晰度)后不知何故恢复:

26437.304: [Full GC 
    [PSYoungGen: 132928K->0K(196736K)] 
    [PSOldGen: 1310719K->53875K(1310720K)] 1443647K->53875K(1507456K) 
    [PSPermGen: 55172K->55172K(262144K)], 0.6250820 secs] 
    [Times: user=0.63 sys=0.00, real=0.62 secs] 

不仅整个年轻一代被释放,而且老一代的数量从1280 MB降至52 MB。请仔细观察这张图表(zoom)。蓝线显示你的堆使用情况,几分钟后,突然间天空火箭弹落下。此外绿线显示平均GC时间 - 从可忍受的毫秒到灾难性的秒数。最后黑色竖条表示主要的GC。他们不应该每隔一分钟(小时?)出现更多,而不是每隔一秒钟。

GCViewer

这告诉我,为这短短的时间段你保持数据在内存中很多。可能是一些巨大的对象集合。不知怎的,JVM没有崩溃,但设法继续处理。当你的工作完成后,整个收集只是简单的了。

很难说没有看到代码(我看到AlarmService悬挂在日志中......),但在使用内存转储和性能分析之类的大炮之前,请检查您的代码,特别是从数据库加载的无限集合或从外面(我看到Twitter吗?)

+0

创建堆转储并使用jvisualvm查看类汇总通常会提供有关在代码中查找的快速提示。我不是在谈论大量的堆分析,只是快速一瞥,不应超过五分钟。 – biziclop 2012-07-17 09:21:14

+0

很好的回答,+1 – Tomer 2012-07-17 09:27:23

+0

真棒。谢谢! – 2012-07-18 00:12:05

2

存储器中的对象大致分为两堆(从GC的角度来看):年轻一代和老一代。

大多数情况下,GC会在Young gen对象上运行短迭代,并且这些迭代通常与应用程序流并行运行(应用程序不会停止)。

每隔一段时间,年轻一代堆满了,GC执行称为“停止世界”的干净任务,意味着应用程序停止完成,GC将清理堆中的所有不必要的对象。显然,这个迭代需要比通常的短迭代多一点的时间。

您需要检查几件事情:

  1. 尝试剖析应用程序,并确保你没有引起你的堆增长迅速,从而执行一个完整的GC经常一个memmory泄漏。
  2. GC有几种算法会导致其行为不同(并行运行,运行序列等),您可能需要调查它并查看哪一个更适合您的需求。

你可以看看here作为一个指针,也可以使用谷歌。