1. 程式人生 > >一次JVM調優實戰

一次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? 效能調優的程式 效能調優的