jdk6和7服務器端(-server) 默認的新生代的垃圾回收器為:PS Scavenge,老年代默認的垃圾回收器為:PS MarkSweep
目前項目使用了jdk7,tomcat7,經常出現內存堆使用量200s持續超過堆總內存80%,觸發報警。
由於項目最近的更新為jdk和tomcat升級,從6升級到7,而之前使用tomcat6時並未報警,是因為tomcat的一個監聽器行為模式變更造成的
<Listener className="org.apache.catalina.core.JreMemoryLeakPreventionListener" />
在tomcat6中,它會每隔一個小時3600s(1小時)調用一次System.gc()方法,手動執行Full GC,使老年代中的無用對象每隔一小時清理一次;
在tomcat7中,事情發生了變化,它會每隔Long.Max_Value -1 毫秒秒執行一次System.gc()
/* * Several components end up calling * sun.misc.GC.requestLatency(long) which creates a daemon * thread without setting the TCCL. * * Those libraries / components known to trigger memory leaks * due to eventual calls to requestLatency(long) are: * - javax.management.remote.rmi.RMIConnectorServer.start() * * Note: Long.MAX_VALUE is a special case that causes the thread * to terminate * */ if (gcDaemonProtection) { try { Class<?> clazz = Class.forName("sun.misc.GC"); Method method = clazz.getDeclaredMethod( "requestLatency", new Class[] {long.class}); method.invoke(null, Long.valueOf(Long.MAX_VALUE - 1)); } catch (ClassNotFoundException e) { if (JreVendor.IS_ORACLE_JVM) { log.error(sm.getString( "jreLeakListener.gcDaemonFail"), e); } else { log.debug(sm.getString( "jreLeakListener.gcDaemonFail"), e); } } catch (SecurityException e) { log.error(sm.getString("jreLeakListener.gcDaemonFail"), e); } catch (...) { ... } }
調用GC類的方法,最終開啟一個優先級為2的Deamon線程,在一個無限循環中調用System.gc()
public void run() { while(true) { synchronized(GC.lock) { long var1 = GC.latencyTarget; if(var1 == 9223372036854775807L) { GC.daemon = null; return; } long var4 = GC.maxObjectInspectionAge(); if(var4 >= var1) { System.gc(); var4 = 0L; } try { GC.lock.wait(var1 - var4); } catch (InterruptedException var8) { ; } } } }
Long.Max_Value -1 毫秒換算成時間,是62億年,這個時間太長了,因此我們指望不了這個功能幫你什么忙,並且最好的方式應該是應用自己在適當的時候觸發Full GC
回到實際項目中,老年代持續增加,平均每天會觸發1~2次Full GC,這個次數倒是不多;由於老年代內存使用量長時間居高不下,而新生代的內存使用量隨着業務頻率的變化,有時候迅速撐滿,觸發Young GC;有時候又增長緩慢,如果(Young Memory + Turned Memory / Total Memeory) > 80%,就會報警。
總的來說,老年代內存占用量長期偏高,增長較快,是導致這個問題的主要原因。
先來了解垃圾回收算法的一些術語:
PS Scavenge:新生代垃圾回收器,使用復制算法(指針碰撞,內存分為Eden,S1,S2),並行(不能和App線程同時運行,GC會stw)的多線程收集器,它關注的系統的吞吐量,有效的利用cpu,盡快完成任務,不太關注線程停頓時間。它有一個自適應調整策略(可以通過-XX:-UseAdaptiveSizePolicy關閉,默認開啟
),導致虛擬機參數配置-XX:SurvivorRatio參數沒有實際意義(S1,S2的大小會不定的變化,實際觀察來看,S1和S2的大小是每次回收后剩余的對象所占用空間的大小),適用於高吞吐量的場景,而不適合時間敏感的場景
我們的系統是一個后端任務系統,單純從系統屬性來分析,他是很適合使用PS Scavenge、PS MarkSweep的,是什么導致它變得不適合呢?
分析原因:
1.系統大量引入了MQ、ServiceFramework,調用三方系統,使用的是nio封裝的長連接,在每次調用后,連接依然還在; 2.由於1產生了很多長連接,在某次minor GC回收后s1空間大小為n,下次minor GC回收時,剩余存活對象占用空間 > n,此時如果系統沒有重新設置S空間大小,對象更易進入老年代 3.在2的基礎上,一些長連接進入老年代后,由於網絡異常、連接斷開或其他因素,已不可用,伴生對象仍然在老年代中,但它需要等到下次full GC時才會回收
此時我們已經想到一個解決辦法,那就是如何讓O區在空間用完前就執行Full GC,並且對象不過快\過早進入O區,這個問題就可完美解決,而這是PS MarkSweep收集器不具備的功能。
下面來了解一下標記清理算法:
標記-清除MarkSweep:把內存分成很多塊,對象沒有引用了就標記出來,標記完后統一回收對象,清除后空間不再連續,分配大對象時可能無法找到足夠空間將觸發一次垃圾回收,如果在老年代,將觸發Full GC
(《深入理解Java虛擬機第二版》圖)
PS MarkSweep:老年代收集器,是一個可以並行標記和清理垃圾的回收器,無整理,使用的是空閑列表的方式,就像一個多線程版本的Serial Old收集器
能做到老年代提前GC的垃圾回收器有CMS收集器,但它的搭配伙伴是ParNew,由ParNew來執行新生代垃圾回收。
ParNew:多個線程並行(app線程需等待,stop the world)收集,新生代收集器,最大的優點是可以配合CMS回收器,默認gc線程數和cpu數量相同,當cpu太多,如32個時,可以使用-XX:ParallelGCThreads來限制gc線程個數
CMS:(-XX:+UseConcMarkSweepGC)分為初始標記(並行,app線程掛起 stop the world,僅標記GC Roots關聯的對象,速度很快)、並發標記(GC Roots對象向下追蹤)、重新標記(並行,app線程掛起 stop the world,矯正並發標記時的修改,時間稍長)、並發清除,垃圾收集過程中最耗時的並發標記、並發清除都可以和用戶線程一起工作,所以,整體來說,它的內存回收過程與app線程是一起並發執行的,stop the world的時間較短;
但並發執行也意味着此時會與app線程競爭cpu資源,app會變慢,系統吞吐量降低,gc線程數為(cpu+3)/4個;無法處理浮動垃圾:即stop the world后的並發階段,生成的對象。jdk1.6會在老年代占比92%時觸發full gc,以預留空間給浮動對象,參數為(-XX:CMSInitiatingOccupancyFraction=80 手動設定),設置太高時可能會出現Concurrent Mode Failure(老年代剩余空間大於 新生代 Eden + S1的和),不建議設置太高
CMSInitiatingOccupancyFraction = (100 - MinHeapFreeRatio) + (CMSTriggerRatio * MinHeapFreeRatio / 100)
MinHeapFreeRatio默認40、 指定 jvm heap 在使用率小於 n 的情況下 ,heap 進行收縮 ,Xmx==Xms 的情況下無效
CMSTriggerRatio默認80, 設置由-XX:MinHeapFreeRatio指定值的百分比的值。默認是80%
計算結果
CMSInitiatingOccupancyFraction=92
查看方式:jinfo -flag CMSInitiatingOccupancyFraction pid
CMS基於標記-清除算法,收集結束后會有大量碎片空間,不利於大對象(當前連續的碎片空間已不能滿足某個對象分配所需內存時,這里的大對象相對而言的)分配,大對象分配失敗時,會觸發一次FullGC,CMS為此提供了-XX:+UseCMSCompactAtFullCollection開關(默認開啟),在沒有足夠的連續空間時,啟動碎片整理合並,但此時stop the world時間相應增加。默認情況下,每次Full GC都會對老年代進行碎片整理
使用ParNew + CMS后
1.Eden、S1、S2空間大小固定,相對於PS Scavenge收集器,S1、S2空間更大,能容納更大的對象,這樣對象在S1、S2呆的時間更容易長久,在對象被回收前進入老年代的概率大大降低 2.老年代對象增加的速度明顯變慢,並且在jdk6、jdk7環境默認參數下,在 占用空間 / 總空間 > 92%時,及時回收掉無用對象,老年代內存使用量大幅降低 備注:須知老年代在執行Full GC后對象應該是大大降低的,如果GC后對象並未下降太多,可能有兩種情況:老年代內存分配較少\程序有內存泄露的風險
如果使用CMS后還會有堆內存長時間使用率 > 80%的異常情況,我們可根據New空間和Turned空間的空間總占用量極限值來推導參數CMSInitiatingOccupancyFraction的合適值
如新生代 1000M、老年代1000M -Xmx\-Xmn
則Eden(800m) S1(100M) S2(100M) Tenured(1000M)
Eden + S1 = 900M
Tenured* 92% = 920M
則最大推內存使用率為 900M + 920M = 1820M
最大堆內存使用率 1820 / 2000 = 91%
當然這是極端情況,如果你的內存占用率要求不能長時間高於80%,則可以通過配置新生代、老年代的比例,以及-XX:CMSInitiatingOccupancyFraction=n參數來保證
內存分配了,如果一直不使用也是一種浪費,我們的目標不是完全杜絕堆利用 > 80%,而是長時間大於80%
目前來看,默認的老年代92%時進行Full GC已經滿足了我們的需求
HotSpot為什么perm和heap要一起回收:因為兩塊區域可能有相互引用的關系,分開回收比較困難
由於新生代采用復制算法進行垃圾收集,所以可能會由於分配擔保導致一次full gc,空間分配擔保機制可使對象提前進入老年代
也就是Eden + S1 > Turned的剩余連續空間 或者 turned剩余連續空間 > 歷次晉升到老年代對象空間大小的平均值, 並且 -XX:HandlePromotionFailure(JDK6 Update 24之后這個參數就沒有意義了,也就是強制使用空間分配擔保策略了)為是否開啟擔保,如果擔保,就進行Minor GC,如果無擔保則會Full GC,也就是
JDK6 Update24之后的空間分配擔保:如果老年代剩余的連續空間大小大於新生代所有對象總和或大於歷次晉升到老年代的平均大小,執行Minor GC,否則Full GC
擔保失敗是指執行minor gc后,剩余的空間survior空間裝不下,不得不觸發一次Full GC,這個路徑相對於直接執行Full GC,中間多了一步Minor GC,而Full GC本身會回收新生代、老年代、方法區(Major GC僅回收老年代,我們不拘泥於MajorGC\FullGC這樣的區別,都當成一次比較深度的GC來理解)
大對象直接進入老年代,避免在Eden和Survivor之間進行大量內存復制
G1:充分利用多核環境縮短stop-the-world,通過並發執行減少app線程停頓時間;擁有分代收集,將整個堆划分為多個相等的獨立區域,這樣,老年代和新生代不再是物理隔離的了,它們有可能是挨着的,且不只是兩塊區域,但可以獨立管理整個堆,整體上是標記-整理算法;可預測的停頓時間,可以知道在長度多少毫秒時間片段內,垃圾收集時間不超過n毫秒
GC日志:
jvm參數:-XX:MaxPermSize=400M -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=80 -XX:+PrintGCDetails -Xloggc:D:\gc.log
3324K->152K(11904K)表示GC前堆已使用量 -> GC后堆已使用容量(堆總容量)
有書上(《深入理解java虛擬機》)說GC、FULL GC說明的是停頓類型,若是Full GC則在GC時產生了stop-the-world,也就是用它來區分是否發生了stop-the-world,而不是用來說明是對哪個代進行回收的(Young代還是turned代、Perm),這個說法應該是有誤的
根據GC算法原理,每個代的回收都會有GC Roots分析可達性,Young代也是如此,因此他們都會有stop-the-world(虛擬機的某些機制可加速,如在安全點的基礎上,OopMap快速找出棧上有普通對象引用的區域,避免挨個遍歷棧的內存區域)。
84.884: [GC 84.884: [ParNew: 18175K->1358K(19136K), 0.0099206 secs] 74132K->57459K(109692K), 0.0100078 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 85.104: [GC 85.184: [ParNew: 18382K->1160K(19136K), 0.0042949 secs] 74483K->58053K(109692K), 0.0043920 secs] [Times: user=0.00 sys=0.00, real=0.08 secs] 兩次普通GC 新生代回收空間 堆總的回收空間 (新生代回收-堆總空間回收) 第一條GC日志: 16817 16673 144 第二條GC日志: 17222 16430 792 可以看到每次MinorGC后,新生代回收的空間都是大於了堆總的回收空間,這說明有新生代的對象進入了老年代,而這兩個GC日志間並沒有老年代GC日志,ParNew是新生代回收器
Full GC會回收老年代內的對象,Hotspot中還會回收Perm空間,同時,觸發Full GC一般是因為需要往老年代放入對象,而這個操作一般都伴隨了先前一次的Young GC
-Xmx150M -Xms150M -XX:+PrintGCDetails 不斷插入1M的大對象,且不釋放引用時的GC日志
[GC [PSYoungGen: 43187K->5680K(44800K)] 103604K->101937K(147200K), 0.0601768 secs] [Times: user=0.03 sys=0.06, real=0.06 secs]
[Full GC [PSYoungGen: 5680K->0K(44800K)] [PSOldGen: 96257K->101848K(102400K)] 101937K->101848K(147200K) [PSPermGen: 3718K->3718K(21248K)], 0.1401878 secs] [Times: user=0.01 sys=0.00, real=0.14 secs]
可以看到這種極端情況下Full GC會同時觸發Minor GC、Turned GC、PermGen GC,同時Minor GC依然用的青年代的收集器,所以這次Full GC,其實是有多個階段的,因為他們不是同時進行的;
虛擬機性能監控指令:
jps
jps -m 顯示main函數的參數
jps -v 顯示虛擬機啟動參數
jstat -gcutil pid 查看垃圾回收各個代的內存情況,百分比,gc時間
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
8.90 0.00 40.80 60.12 - - 238 1.165 16 0.080 1.245
SO\S1\E\O分別是兩個Survior空間的使用率,Eden空間、老年代使用率,在java8中引入了MetaSpace
jinfo 查看虛擬機配置參數
jmap -dump 生成java堆轉儲快照到文件
jmap -heap 顯示堆詳細信息,如回收器、參數、分代情況
jmap -histo 堆中對象統計
jhat xxx.bin 解析jmap -dump出來的文件,會生成一個http server,展示頁面中包括了各種信息
jstack pid查看線程的堆棧信息
jstack -l pid額外查詢鎖的附加信息
G1:-XX:MetaspaceSize=128m -XX:MaxMetaspaceSize=256m -XX:+PrintTenuringDistribution -XX:+UseG1GC -XX:+DisableExplicitGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:ParallelGCThreads=4 -Xloggc:/export/Logs/gclogs
再談引用:強引用、軟引用、弱引用、虛引用
強引用:比如new,只要強引用還存在,垃圾收集永遠不會回收掉對象
軟引用:對於被軟引用關聯的對象,在系統發布內存溢出之前,會把這些對象列入可回收返回,進行二次垃圾回收
弱引用:只被弱引用關聯的對象,只能生存到下次垃圾回收
虛引用:一個對象是否有虛引用,對其生命周期毫不影響
CMS筆記
cms,擔保失敗,會使用Serial Old搜集器重新對老年代進行垃圾回收,這個和G1相同
cms垃圾回收器只回收老年代,可以通過啟動參數配置,在重新標記前執行一次young gc,降低remark的工作量,提高老年代的GC速度
有兩種情況會觸發fullgc:
1.擔保失敗, 指minor gc時,survivor空間放不下,對象只能放到老年代,而此時老年代也放不下
2.並發失敗comcurrent mode failure 指cms gc過程中,同時有對象放入老年代,而此時老年代空間不足
2018-08-06T20:39:36.689+0800: 3600.552: [Full GC (System) 3600.552: [CMS: 130965K->149171K(1835008K), 0.7744930 secs] 925033K->149171K(3063808K), [CMS Perm : 121859K->120837K(262144K)], 0.7748330 secs] [Times: user=0.77 sys=0.00, real=0.77 secs]
System.gc()不會直接回收新生代
CMS日志
4.595: [GC 4.595: [ParNew: 19136K->1808K(19136K), 0.0042364 secs] 31584K->15824K(49088K), 0.0043025 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
4.793: [GC 4.793: [ParNew: 18832K->1901K(19136K), 0.0021414 secs] 32848K->15917K(49088K), 0.0021969 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
4.902: [GC 4.902: [ParNew: 18925K->1748K(19136K), 0.0024316 secs] 32941K->16459K(49088K), 0.0026722 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
4.977: [GC 4.977: [ParNew: 18772K->1912K(19136K), 0.0016380 secs] 33483K->17185K(49088K), 0.0016828 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
老年代閾值導致的cms?,怎么這么低,根據preclean后的young gc,可能是由於擔保失敗造成的,young gc后,suviror裝不下,但上次yg后,應該不足以觸發擔保失敗
則極有可能是老年代的連續空間不足以分配某個對象,然后這看起來也不太可能,解釋權只能給JVM自動觸發動態策略了(這個動態策略極有可能是50%左右第一次觸發),如果使用了-XX:+UseCMSInitiatingOccupancyOnly,這個參數是會生效的
4.979: [GC [1 CMS-initial-mark: 15272K(29952K)] 17521K(49088K), 0.0008371 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
4.980: [CMS-concurrent-mark-start]
5.015: [CMS-concurrent-mark: 0.035/0.035 secs] [Times: user=0.06 sys=0.00, real=0.04 secs]
5.015: [CMS-concurrent-preclean-start]
5.016: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
5.016: [CMS-concurrent-abortable-preclean-start]
5.071: [GC 5.071: [ParNew: 18933K->1539K(19136K), 0.0018825 secs] 34205K->17552K(49088K), 0.0019298 secs] [Times: user=0.06 sys=0.00, real=0.00 secs]
5.157: [GC 5.157: [ParNew: 18563K->1886K(19136K), 0.0012275 secs] 34576K->17899K(49088K), 0.0012685 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
5.246: [GC 5.246: [ParNew: 18910K->1413K(19136K), 0.0029214 secs] 34923K->18444K(49088K), 0.0029696 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
5.350: [GC 5.350: [ParNew: 18437K->1859K(19136K), 0.0019435 secs] 35468K->19389K(49088K), 0.0020356 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
5.432: [GC 5.432: [ParNew: 18883K->2112K(19136K), 0.0021222 secs] 36413K->20335K(49088K), 0.0021679 secs] [Times: user=0.06 sys=0.00, real=0.00 secs]
5.507: [GC 5.507: [ParNew: 19136K->1689K(19136K), 0.0020429 secs] 37359K->21727K(49088K), 0.0020890 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
5.581: [GC 5.581: [ParNew: 18713K->1472K(19136K), 0.0011870 secs] 38751K->21511K(49088K), 0.0012326 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
5.681: [GC 5.681: [ParNew: 18496K->2112K(19136K), 0.0013845 secs] 38535K->22240K(49088K), 0.0014276 secs] [Times: user=0.06 sys=0.00, real=0.00 secs]
5.755: [GC 5.755: [ParNew: 19136K->2103K(19136K), 0.0022780 secs] 39264K->23213K(49088K), 0.0023245 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
5.850: [GC 5.850: [ParNew: 19127K->1370K(19136K), 0.0018551 secs] 40237K->23337K(49088K), 0.0018978 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
5.915: [GC 5.915: [ParNew: 18394K->1720K(19136K), 0.0015151 secs] 40361K->23688K(49088K), 0.0015586 secs] [Times: user=0.06 sys=0.00, real=0.00 secs]
5.985: [GC 5.985: [ParNew: 18744K->1816K(19136K), 0.0022302 secs] 40712K->24297K(49088K), 0.0022801 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
6.067: [GC 6.067: [ParNew: 18840K->2049K(19136K), 0.0024256 secs] 41321K->25281K(49088K), 0.0024695 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
6.149: [GC 6.149: [ParNew: 19073K->1358K(19136K), 0.0018667 secs] 42305K->25242K(49088K), 0.0019145 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
6.227: [GC 6.227: [ParNew: 18382K->2112K(19136K), 0.0015543 secs] 42266K->25996K(49088K), 0.0015970 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
6.299: [GC 6.299: [ParNew: 19136K->1845K(19136K), 0.0028023 secs] 43020K->26721K(49088K), 0.0028659 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
6.388: [GC 6.388: [ParNew: 18869K->2112K(19136K), 0.0020894 secs] 43745K->27566K(49088K), 0.0021431 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
6.472: [GC 6.472: [ParNew: 19136K->1358K(19136K), 0.0019375 secs] 44590K->27416K(49088K), 0.0019836 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
6.542: [GC 6.542: [ParNew: 18382K->1717K(19136K), 0.0012241 secs] 44440K->27776K(49088K), 0.0012702 secs] [Times: user=0.00 sys=0.02, real=0.00 secs]
6.606: [GC 6.606: [ParNew: 18741K->1533K(19136K), 0.0020919 secs] 44800K->28156K(49088K), 0.0021414 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
6.700: [GC 6.700: [ParNew: 18557K->1448K(19136K), 0.0018522 secs] 45180K->28531K(49088K), 0.0018970 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
6.771: [GC 6.771: [ParNew: 18472K->1901K(19136K), 0.0017114 secs] 45555K->29263K(49088K), 0.0017553 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
6.814: [GC 6.814: [ParNew: 18925K->2112K(19136K), 0.0020745 secs] 46287K->29806K(49088K), 0.0021210 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
6.871: [GC 6.871: [ParNew (promotion failed): 19136K->19136K(19136K), 0.0058138 secs]6.877: [CMS6.877: [CMS-concurrent-abortable-preclean: 0.232/1.862 secs] [Times: user=2.13 sys=0.23, real=1.86 secs]
(concurrent mode failure): 28066K->28158K(29952K), 0.0945723 secs] 46830K->28158K(49088K), [CMS Perm : 17828K->17805K(21248K)], 0.1005691 secs] [Times: user=0.09 sys=0.00, real=0.10 secs] 執行了serial old gc,用了0.1sec
7.584: [Full GC 7.584: [CMS: 29951K->29943K(29952K), 0.0865138 secs] 49086K->30785K(49088K), [CMS Perm : 17811K->17811K(29868K)], 0.0865800 secs] [Times: user=0.09 sys=0.00, real=0.09 secs]
FULL GC會回收老年代和永久代,普通的cms gc只會回收老年代
G1
-把一塊內存分成很多塊固定大小的內存:每個region可以為:EDEN\SURVIOR\H\OLD\UN USED
OLD GC:
初始標記:young gc時稍帶會執行初始標記,如gc log里面的GC pause (young)(inital-mark)