一次JVM調優實戰
早上檢視低峰期gc情況,發現昨晚上fgc有274次,感覺有些不正常,開始查詢原因
[[email protected]order-binlog-data002 spring-boot]$ sudo jstat -gc 20028 4000 10
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
283328.0 283328.0 1036.4 0.0 2266752.0 589773.4 1700864.0 52111.5 41476.0 40494.4 4672.0 4507.7 5998 157.033 274 37.794 194.827
283328.0 283328.0 1036.4 0.0 2266752.0 1902667.1 1700864.0 52111.5 41476.0 40494.4 4672.0 4507.7 5998 157.033 274 37.794 194.827
283328.0 283328.0 0.0 906.8 2266752.0 1165571.6 1700864.0 52125.8 41476.0 40494.4 4672.0 4507.7 5999 157.037 274 37.794 194.831
283328.0 283328.0 588.3 0.0 2266752.0 419124.4 1700864.0 52222.6 41476.0 40494.4 4672.0 4507.7 6000 157.041 274 37.794 194.834
283328.0 283328.0 588.3 0.0 2266752.0 1858587.9 1700864.0 52222.6 41476.0 40494.4 4672.0 4507.7 6000 157.041 274 37.794 194.834
283328.0 283328.0 0.0 980.7 2266752.0 1015355.0 1700864.0 52311.3 41476.0 40494.4 4672.0 4507.7 6001 157.046 274 37.794 194.839
283328.0 283328.0 1075.6 0.0 2266752.0 376459.3 1700864.0 52369.0 41476.0 40494.4 4672.0 4507.7 6002 157.050 274 37.794 194.843
283328.0 283328.0 1075.6 0.0 2266752.0 1725419.9 1700864.0 52369.0 41476.0 40494.4 4672.0 4507.7 6002 157.050 274 37.794 194.843
283328.0 283328.0 0.0 650.2 2266752.0 993727.1 1700864.0 52471.9 41476.0 40494.4 4672.0 4507.7 6003 157.053 274 37.794 194.847
283328.0 283328.0 1402.2 0.0 2266752.0 203814.7 1700864.0 52553.9 41476.0 40494.4 4672.0 4507.7 6004 157.058 274 37.794 194.851
中午高峰期檢視,老年代一直在增長,每4秒增長大概1M
[[email protected]order-binlog-data002 spring-boot]$ sudo jstat -gc 20028 4000 10
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
283328.0 283328.0 3849.7 0.0 2266752.0 510658.3 1700864.0 80623.6 41476.0 40494.4 4672.0 4507.7 6396 158.987 274 37.794 196.780
283328.0 283328.0 0.0 2788.4 2266752.0 477917.0 1700864.0 80689.9 41476.0 40494.4 4672.0 4507.7 6397 158.991 274 37.794 196.784
283328.0 283328.0 1931.9 0.0 2266752.0 474958.2 1700864.0 80791.0 41476.0 40494.4 4672.0 4507.7 6398 158.995 274 37.794 196.788
283328.0 283328.0 0.0 2145.2 2266752.0 483570.1 1700864.0 80877.9 41476.0 40494.4 4672.0 4507.7 6399 158.999 274 37.794 196.793
283328.0 283328.0 2864.5 0.0 2266752.0 638776.6 1700864.0 80953.9 41476.0 40494.4 4672.0 4507.7 6400 159.004 274 37.794 196.797
283328.0 283328.0 0.0 1856.1 2266752.0 880657.2 1700864.0 81013.6 41476.0 40494.4 4672.0 4507.7 6401 159.009 274 37.794 196.802
283328.0 283328.0 4210.8 0.0 2266752.0 894710.5 1700864.0 81099.8 41476.0 40494.4 4672.0 4507.7 6402 159.014 274 37.794 196.808
283328.0 283328.0 0.0 2900.8 2266752.0 960077.2 1700864.0 81210.0 41476.0 40494.4 4672.0 4507.7 6403 159.018 274 37.794 196.812
283328.0 283328.0 1813.5 0.0 2266752.0 1064101.3 1700864.0 81266.9 41476.0 40494.4 4672.0 4507.7 6404 159.023 274 37.794 196.817
283328.0 283328.0 0.0 1498.7 2266752.0 1126030.4 1700864.0 81323.5 41476.0 40494.4 4672.0 4507.7 6405 159.028 274 37.794 196.822
檢視昨晚gc日誌發現,age1和age2表示新生代年齡為1和2, 但是有個地方只有age1沒有age2,緊接著就開始CMS收集,感覺有些線索。首先簡單介紹一些該應用,大多數是物件都是朝生夕死的物件,不太可能進入老年代。開始懷疑是年齡晉升閾值太小,只配置了2。本該在新生代回收的物件,由於沒有及時回收,從age1直接到了老年代。
2017-07-12T20:54:06.586+0800: 80.309: [GC (Allocation Failure) 2017-07-12T20:54:06.586+0800: 80.309: [ParNew
Desired survivor size 145063936 bytes, new threshold 2 (max 2)
- age 1: 33586544 bytes, 33586544 total
- age 2: 35816528 bytes, 69403072 total
: 2355435K->78957K(2550080K), 0.0317835 secs] 3532169K->1284299K(4250944K), 0.0319476 secs] [Times: user=0.12 sys=0.00, real=0.03 secs]
2017-07-12T20:54:06.618+0800: 80.341: Total time for which application threads were stopped: 0.0325909 seconds, Stopping threads took: 0.0001534 seconds
2017-07-12T20:54:07.620+0800: 81.342: Total time for which application threads were stopped: 0.0006056 seconds, Stopping threads took: 0.0001820 seconds
2017-07-12T20:54:08.384+0800: 82.107: [GC (Allocation Failure) 2017-07-12T20:54:08.384+0800: 82.107: [ParNew
Desired survivor size 145063936 bytes, new threshold 2 (max 2)
- age 1: 56321632 bytes, 56321632 total
- age 2: 31853384 bytes, 88175016 total
: 2345709K->116591K(2550080K), 0.0398190 secs] 3551051K->1356910K(4250944K), 0.0399864 secs] [Times: user=0.14 sys=0.00, real=0.04 secs]
2017-07-12T20:54:08.424+0800: 82.147: Total time for which application threads were stopped: 0.0406831 seconds, Stopping threads took: 0.0001112 seconds
2017-07-12T20:54:10.085+0800: 83.808: [GC (Allocation Failure) 2017-07-12T20:54:10.085+0800: 83.808: [ParNew
Desired survivor size 145063936 bytes, new threshold 1 (max 2)
- age 1: 190948400 bytes, 190948400 total
- age 2: 54471392 bytes, 245419792 total
: 2383343K->264021K(2550080K), 0.0715712 secs] 3623662K->1535443K(4250944K), 0.0717427 secs] [Times: user=0.27 sys=0.00, real=0.07 secs]
2017-07-12T20:54:10.157+0800: 83.880: Total time for which application threads were stopped: 0.0724583 seconds, Stopping threads took: 0.0001708 seconds
2017-07-12T20:54:11.595+0800: 85.318: [GC (Allocation Failure) 2017-07-12T20:54:11.595+0800: 85.318: [ParNew
Desired survivor size 145063936 bytes, new threshold 1 (max 2)
- age 1: 188703680 bytes, 188703680 total
: 2530773K->250075K(2550080K), 0.1668482 secs] 3802195K->1753036K(4250944K), 0.1670176 secs] [Times: user=0.52 sys=0.04, real=0.17 secs]
2017-07-12T20:54:11.762+0800: 85.485: Total time for which application threads were stopped: 0.1676754 seconds, Stopping threads took: 0.0000755 seconds
2017-07-12T20:54:11.765+0800: 85.488: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1502960K(1700864K)] 1771515K(4250944K), 0.0158729 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2017-07-12T20:54:11.781+0800: 85.504: Total time for which application threads were stopped: 0.0167987 seconds, Stopping threads took: 0.0002961 seconds
2017-07-12T20:54:11.781+0800: 85.504: [CMS-concurrent-mark-start]
2017-07-12T20:54:12.050+0800: 85.773: [CMS-concurrent-mark: 0.269/0.269 secs] [Times: user=0.70 sys=0.11, real=0.26 secs]
2017-07-12T20:54:12.050+0800: 85.773: [CMS-concurrent-preclean-start]
2017-07-12T20:54:12.055+0800: 85.778: [CMS-concurrent-preclean: 0.005/0.005 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2017-07-12T20:54:12.055+0800: 85.778: [CMS-concurrent-abortable-preclean-start]
2017-07-12T20:54:12.055+0800: 85.778: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2017-07-12T20:54:12.056+0800: 85.778: [GC (CMS Final Remark) [YG occupancy: 631012 K (2550080 K)]2017-07-12T20:54:12.056+0800: 85.778: [Rescan (parallel) , 0.0752694 secs]2017-07-12T20:54:12.131+0800: 85.854: [weak refs processing, 0.0000552 secs]2017-07-12T20:54:12.131+0800: 85.854: [class unloading, 0.0092330 secs]2017-07-12T20:54:12.140+0800: 85.863: [scrub symbol table, 0.0050382 secs]2017-07-12T20:54:12.145+0800: 85.868: [scrub string table, 0.0010191 secs][1 CMS-remark: 1502960K(1700864K)] 2133973K(4250944K), 0.0924674 secs] [Times: user=0.31 sys=0.00, real=0.09 secs]
2017-07-12T20:54:12.148+0800: 85.871: Total time for which application threads were stopped: 0.0930845 seconds, Stopping threads took: 0.0001297 seconds
2017-07-12T20:54:12.148+0800: 85.871: [CMS-concurrent-sweep-start]
2017-07-12T20:54:12.612+0800: 86.335: [CMS-concurrent-sweep: 0.464/0.464 secs] [Times: user=1.21 sys=0.26, real=0.47 secs]
2017-07-12T20:54:12.612+0800: 86.335: [CMS-concurrent-reset-start]
2017-07-12T20:54:12.617+0800: 86.339: [CMS-concurrent-reset: 0.005/0.005 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
2017-07-12T20:54:13.595+0800: 87.318: [GC (Allocation Failure) 2017-07-12T20:54:13.595+0800: 87.318: [ParNew
Desired survivor size 145063936 bytes, new threshold 1 (max 2)
- age 1: 158235824 bytes, 158235824 total
: 2516827K->235282K(2550080K), 0.1279312 secs] 3152007K->1049527K(4250944K), 0.1281230 secs] [Times: user=0.43 sys=0.03, real=0.13 secs]
2017-07-12T20:54:13.723+0800: 87.446: Total time for which application threads were stopped: 0.1288954 seconds, Stopping threads took: 0.0001631 seconds
2017-07-12T20:54:15.493+0800: 89.216: [GC (Allocation Failure) 2017-07-12T20:54:15.493+0800: 89.216: [ParNew
Desired survivor size 145063936 bytes, new threshold 2 (max 2)
- age 1: 82668368 bytes, 82668368 total
: 2502034K->203689K(2550080K), 0.1076523 secs] 3316279K->1170879K(4250944K), 0.1078419 secs] [Times: user=0.35 sys=0.02, real=0.10 secs]
2017-07-12T20:54:15.601+0800: 89.324: Total time for which application threads were stopped: 0.1085887 seconds, Stopping threads took: 0.0001270 seconds
2017-07-12T20:54:17.307+0800: 91.029: [GC (Allocation Failure) 2017-07-12T20:54:17.307+0800: 91.029: [ParNew
Desired survivor size 145063936 bytes, new threshold 2 (max 2)
- age 1: 77960664 bytes, 77960664 total
- age 2: 65094536 bytes, 143055200 total
: 2470441K->182761K(2550080K), 0.0338754 secs] 3437631K->1149951K(4250944K), 0.0340508 secs] [Times: user=0.13 sys=0.00, real=0.03 secs]
2017-07-12T20:54:17.341+0800: 91.064: Total time for which application threads were stopped: 0.0348178 seconds, Stopping threads took: 0.0001475 seconds
找到原因後,就開始做調整。首先為了儘可能把物件留到新生代回收,需要提高Survivor的利用率。有個TargetSurvivorRatio引數,預設是50,表示利用率超過50%就將物件送入老年代。還有物件晉升閾值MaxTenuringThreshold,調整為最大。考慮到機器記憶體為8G,而運維預設設定最大堆為4.4G,還有可利用空間,即將最大堆調整為6G。
-Xmx6000m
-Xms6000m
-Xmn4000m
-XX:TargetSurvivorRatio=90
-XX:MaxTenuringThreshold=15
調整後gc後,第二天早上檢視gc情況,發現昨晚上沒有一次fgc,而且老年代增長非常緩慢,雖然不能完全避免fgc,但是已經將fgc減少,並且延後。
sudo jstat -gc 31703 5000 10
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
350976.0 350976.0 0.0 1974.1 2808320.0 686899.3 2048000.0 85810.0 41856.0 41050.9 4736.0 4544.5 4017 40.907 0 0.000 40.907
350976.0 350976.0 1834.3 0.0 2808320.0 623932.5 2048000.0 85816.7 41856.0 41050.9 4736.0 4544.5 4018 40.916 0 0.000 40.916
350976.0 350976.0 0.0 2378.6 2808320.0 426285.4 2048000.0 85832.0 41856.0 41050.9 4736.0 4544.5 4019 40.926 0 0.000 40.926
350976.0 350976.0 2783.9 0.0 2808320.0 556281.0 2048000.0 85858.5 41856.0 41050.9 4736.0 4544.5 4020 40.935 0 0.000 40.935
350976.0 350976.0 0.0 2848.8 2808320.0 609204.5 2048000.0 85893.7 41856.0 41050.9 4736.0 4544.5 4021 40.944 0 0.000 40.944
350976.0 350976.0 2076.1 0.0 2808320.0 735427.5 2048000.0 85989.6 41856.0 41050.9 4736.0 4544.5 4022 40.953 0 0.000 40.953
350976.0 350976.0 0.0 2687.3 2808320.0 685107.7 2048000.0 86028.1 41856.0 41050.9 4736.0 4544.5 4023 40.963 0 0.000 40.963
350976.0 350976.0 3439.6 0.0 2808320.0 507868.2 2048000.0 86074.3 41856.0 41050.9 4736.0 4544.5 4024 40.972 0 0.000 40.972
350976.0 350976.0 0.0 2130.9 2808320.0 950108.9 2048000.0 86145.5 41856.0 41050.9 4736.0 4544.5 4025 40.982 0 0.000 40.982
350976.0 350976.0 3430.0 0.0 2808320.0 917396.6 2048000.0 86145.5 41856.0 41050.9 4736.0 4544.5 4026 40.992 0 0.000 40.992
相關推薦
一次JVM調優實戰
早上檢視低峰期gc情況,發現昨晚上fgc有274次,感覺有些不正常,開始查詢原因 [[email protected]order-binlog-data002 spring-boot]$ sudo jstat -gc 20028 4000 10
記一次JVM調優(Permanent Generation)
最近在一次搭建公司系統執行環境的時候tomcat總是報出 java.lang.OutOfMemoryError PermGen space 的問題,即記憶體溢位 在解決這個問題的時候 一.問題解決 此處用到一個命令:jmap 顯示java堆中的詳
一次jvm調優過程
jvm調優實戰 前端時間把公司的一個分散式定時排程的系統弄上了容器雲,部署在kubernetes,在容器執行的動不動就出現問題,特別容易jvm溢位,導致程式不可用,終端無法進入,日誌一直在刷錯誤,kubernetes也沒有將該容器自動重啟。業務方基本每天都在反饋task不穩定,後續就協助接手看了下,先主要講下
《JVM調優實戰-理論篇》
logic nor 器) 官方 虛擬內存 1.3 三個月 最優化 all 1 理論篇1.1 多功能養魚塘-JVM內存大魚塘O(可分配內存): JVM可以調度使用的總的內存數,這個數量受操作系統進程尋址範圍、系統虛擬內存總數、系統物理內存總數、其他系統運行所占用的內存資源
一次weblogic調優的經過(StuckThreadMaxTime) of "600" seconds) .
一次weblogic調優的經過 專案組反應資料庫有問題, 檢查發現sga還用的預設引數,緩衝區命中率很低。根據系統記憶體調整後,好像系統正常了。資料庫調整就算是結束了 一天後,我再登這個資料庫的時候,發現一個提示說執行緒已經超過限制,不允許再登入。然後我去修改了proces
jvm調優實戰,定位效能瓶頸
玩過效能優化的朋友都清楚,效能優化的關鍵並不在於怎麼進行優化,而在於怎麼找到當前系統的效能瓶頸。效能優化分為好幾個層次,比如系統層次、演算法層次、程式碼層次…JVM 的效能優化被認為是底層優化,門檻較高,精通這種技能的人比較少。筆者呆過幾家技術力量不算弱的公司,每個公司內部真
spark2.x-jvm調優實戰(以tomcat訪問日誌分析為例)
背景 如果在持久化RDD的時候,持久化了大量的資料,那麼Java虛擬機器的垃圾回收就可能成為一個性能瓶頸。因為Java虛擬機器會定期進行垃圾回收,此時就會追蹤所有的java物件,並且在垃圾回收時,找到那些已經不在使用的物件,然後清理舊的物件,來給新的物件騰出記
記一次SQL調優
insert優化 如果你在某一時刻有大量的insert操作,一條一條插入是非常耗時的。insert語句本身支援一次插入很多條記錄,插入記錄數上限受sql語句長度限制,一般一次插個幾千條是沒問題的。在我的 《如何手動實現Try Insert和Insert Or Update》 一文中對於各種情況都有具體的例子,
JVM 性能調優實戰之:一次系統性能瓶頸的尋找過程
大量 調用棧 怎麽 鎖定 穩定 verbose 註意 代碼層次 一行 前言: 玩過性能優化的朋友都清楚,性能優化的關鍵並不在於怎麽進行優化,而在於怎麽找到當前系統的性能瓶頸。性能優化分為好幾個層次,比如系統層次、算法層次、代碼層次…JVM 的性能優化被認為是底層優化,門檻較
JVM 效能調優實戰之:一次系統性能瓶頸的尋找過程
玩過效能優化的朋友都清楚,效能優化的關鍵並不在於怎麼進行優化,而在於怎麼找到當前系統的效能瓶頸。效能優化分為好幾個層次,比如系統層次、演算法層次、程式碼層次...JVM 的效能優化被認為是底層優化,門檻較高,精通這種技能的人比較少。筆者呆過幾家技術力量不算弱的公司,每個公司內
JVM GC一次調優實戰
CMS的Full GC採用壓縮式垃圾收集,在堆比較大的時候,如果full gc頻繁,會導致停頓,並且呼叫方阻塞、超時、甚至雪崩的情況出現,所以降低full gc的發生頻率和需要時間,非常有必要。 目標 減少full gc頻率減少ygc和full gc時間 優化 配置變化 優化前 <jvm-ar
一次線上JVM調優實踐,FullGC40次/天到10天一次的優化過程
通過這一個多月的努力,將FullGC從40次/天優化到近10天才觸發一次,而且YoungGC的時間也減少了一半以上,這麼大的優化,有必要記錄一下中間的調優過程。 對於JVM垃圾回收,之前一直都是處於理論階段,就知道新生代,老年代的晉升關係,這些知識僅夠應付面試
一次jVM效能調優記錄
前言 填別人留下來的坑其實挺無奈的,會被搞的特別煩,特別是我這種要填三四個人留下來的坑的時候,滿滿的都是無奈。 幸好的是填坑也可以選擇一種更能提升自己的方式來填。 這次遇到的一個程式,是一個從kafka消費並且插入mysql的程式,該程式歷經三人之手,頻頻
JVM調優總結(十一)-反思
垃圾回收的悖論 所謂“成也蕭何敗蕭何”。Java的垃圾回收確實帶來了很多好處,為開發帶來了便利。但是在一些高效能、高併發的情況下,垃圾回收確成為了制約Java應用的瓶頸。目前JDK的垃圾回收演算法,始終無法解決垃圾回收時的暫停問題,因為這個暫停嚴重影響了程式
ifeve.com 南方《JVM 性能調優實戰之:使用阿裏開源工具 TProfiler 在海量業務代碼中精確定位性能代碼》
oca ive java tla inline .net lin 原因 調優 https://blog.csdn.net/defonds/article/details/52598018 多次拉取 JStack,發現很多線程處於這個狀態: at jrockit/vm/
ifeve.com 南方《JVM 效能調優實戰之:使用阿里開源工具 TProfiler 在海量業務程式碼中精確定位效能程式碼》
https://blog.csdn.net/defonds/article/details/52598018 多次拉取 JStack,發現很多執行緒處於這個狀態: at jrockit/vm/Allocator.getNewTla(JJ)V(Native Method)
JVM調優(一)虛擬機器的記憶體模型
前言 Java虛擬機器記憶體模型是Java程式執行的基礎,JVM虛擬機器的記憶體模型如下圖: 程式計數器 程式計數器(Program Counter Register)是一塊很小的記憶體空間。由於java是支援多執行緒的語言,當執行緒數超過cpu的數量時,執行緒之間根據時間片輪詢搶
JVM 效能調優實戰之 使用阿里開源工具 TProfiler 在海量業務程式碼中精確定位效能程式碼
本文是《JVM 效能調優實戰之:一次系統性能瓶頸的尋找過程》 的後續篇,該篇介紹瞭如何使用 JDK 自身提供的工具進行 JVM 調優將 TPS 由 2.5 提升到 20 (提升了 7 倍),並準確定位系統瓶頸:我們應用裡靜態物件不是太多、有大量的業務執行緒在頻繁建立一些生命週期
JVM調優總結(一):基本概念
一、資料型別 Java虛擬機器中,資料型別可以分為兩類:基本型別和引用型別。 基本型別的變數儲存原始值,即:他代表的值就是數值本身; 而引用型別的變數儲存引用值。“引用值”代表了某個物件的引用,而不是物件本身,物件本身存放在這個引用值所表示的地址的位置。
JVM調優大全及實戰總結
文章目錄 JVM 型別 JVM 記憶體中的概念及分割槽 在JDK6及之前的版本 JDK7及之後的版本 為什麼叫Hot Spot? 效能調優的程式 效能調優的