Photo by Pixabay from Pexels
前言
對Java虛擬機器進行效能調優是一個非常寬泛的話題,在實踐上也是非常棘手的過程。因為它需要一種系統的優化方法和清晰的優化期望。預設的JVM引數嘗試在大多數情況下提供可接受的效能;但是,根據應用程式的行為和它所處的工作負載,預設值可能不會產生理想的結果。如果Java虛擬機器沒有按照預期執行就可能需要對應用程式進行基準測試並進行調優,以找到一組合適的 JVM引數。
大多數情況下談論的“JVM調優”都是在說“Java GC調優”,Java官方手冊上關於HotSpot虛擬機器下的第一個主題就是HotSpot Virtual Machine Garbage Collection Tuning Guide。
本文記錄的是從真實業務開發GC調優中總結的一個“基本步驟和流程“,結合著一些參考資料給出一個案例,以及個人對這塊知識點的理解進行講解。
1. 開始優化前的準備
- 深入理解需要優化系統的業務邏輯
- 深入理解Java虛擬機器相關的概念(書籍、官方文件)
- 思考一下JVM調優的目的,真的需要調優嗎?90%以上的問題都是業務程式碼導致的,把調優的精力放到業務邏輯的優化上是不是可以達到更好的效果?
有一些因素會影響你得到的最終調優引數:
- JDK的版本
- 伺服器硬體
- 作業系統
- 系統的負載曲線
- 系統的業務型別,優化需要圍繞的業務型別進行
- 系統的資料集
以上所有內容構成了調優GC效能的環境。調優引數越具體,解決方案就越不通用,它適用的環境也就越少。這意味著,如果任何變數發生變化(例如,更多使用者被授予請求應用程式、應用程式升級、硬體升級的許可權),那麼所做的任何效能調優都可能需要重新評估。
另外必須理解通過顯式調優,實際上可能會降低效能。重要的是要持續監控應用程式,並檢查基於調優的假設是否仍然有效。如果經過仔細的除錯後仍達不到目標,或許應該考慮GC調優之外的更改,例如更換更適合的硬體、作業系統調優和應用程式調優。
Default Arrangement of Generations 。 圖不重要,看文字~
2.選擇優化目標
JVM優化首先需要選擇目標。在下一步為GC調優準備系統時圍繞著這些目標設定值。可參考的目標選擇方向:
- 延遲——JVM在執行垃圾收集時引起的Stop The World(STW)。有兩個主要的指標,平均GC延遲和最大GC延遲。這個目標的動機通常與客戶感知到的效能或響應能力有關。
- 吞吐量——JVM可用於執行應用程式的時間百分比。可用來執行應用程式的時間越多,可用來服務請求的處理時間就越多。需要注意的是,高吞吐量和低延遲並不一定相關——高吞吐量可能伴隨著較長但不頻繁的暫停時間。
- 記憶體成本——記憶體佔用是JVM為執行應用程式所消耗的記憶體量。如果應用程式環境記憶體有限,將此項設為目標也可以起到降低成本的作用。
以上內容可以在Java官方手冊的HotSpot調優部分找到,而一些經驗性的優化原則如下:
- 優先考慮MinorGC。在大多數應用程式中,大多數垃圾都是由最近短暫的物件分配建立的,所以優先考慮年輕代的GC。年輕代物件生命週期越短,不會因為動態年齡判斷和空間分配擔保等因素導致存活時間不長的物件被分配到老年代;同時老年代物件生命週期長,JVM的整體垃圾收集就越高效,這將導致更高的吞吐量。
- 設定合適的堆區大小。給JVM的記憶體越多,收集頻率就越低。此外,這還意味著可以適當地調整年輕代的大小,以更好地應對短期物件的建立速度,這就減少了向老年代分配的物件數量。
- 設定簡單的目標。為了使事情變得更容易,把JVM調優的目標設定的簡單一點,例如只選擇其中兩個效能目標進行調整,而犧牲另一個甚至只選擇一個。通常情況下,這些目標是相互競爭的,例如,為了提高吞吐量,你給堆的記憶體越多,平均暫停時間就可能越長;反之,如果你給堆的記憶體越少,從而減少了平均暫停時間,暫停頻率就可能增加,降低吞吐量。同樣,對於堆的大小,如果所有分代區域的大小合適則可以提供更好的延遲和吞吐量,這通常是以犧牲JVM的佔用率為代價的。
簡而言之,調整GC是一種平衡的行為。通常無法僅僅通過GC的調整來實現所有的目標。
Typical Distribution for Lifetimes of Objects 。 圖不重要,看文字~
3.業務邏輯分析
這裡並不會把真實的業務系統拿出來進行分析,而是模擬類似的場景,大致的業務資訊如下:
- 一個微服務系統(本例中是一個SpringBoot Demo,以下簡稱D服務)主要提供書籍實體資訊的快取和搜尋業務
- 底層資料庫為MySQL+Redis+Elasticsearch
- 業務場景為向其他微服務模組或者其他部分提供快取記憶體及書籍資訊檢索
- 實際實現需求時採用MySQL+Redis+應用記憶體式多級快取
從D服務的性質來說並不屬於使用者強互動型別的後端服務,主要面向的部門內的其他微服務和其他部門的後端服務,所以對於請求的響應速度(延遲)並不屬於第一目標,所以可以把主要的調優目標設定為增加吞吐量或者降低記憶體佔用。當然由於服務本身並不算臃腫,生產資源也不是很吃緊,所以也不考慮降低記憶體,則最後的目標為增加吞吐量。
從業務邏輯的角度分析主要是對書籍資訊的增刪改查,請求流量中90%以上是查,增刪改則大多是服務內部對於多方資料的維護。
查詢的型別分為多種,從物件的角度來說大多數是短期物件,例如:
- 通過AdvanceSearch(AS)模組生成的複雜ES查詢語句物件(資料量小,頻率中等,存活時間極短)
- 從多方資料來源整合業務邏輯的資料響應物件(資料量中,頻率極高,存活時間極短)
- 多級快取體系中在記憶體中暫存的資料物件(資料量小,頻率高,存活時間中等,因為是LRU快取)
- 定期維護任務處理分發的資料物件(資料量大、頻率低、存活時間極短)
可能會進入老年代的業務物件只有記憶體快取中的物件,這一塊結合業務量+過期時間常時保持在數百MB以內,這裡的大小是多次壓測中Dump堆記憶體+MAT分析得出的結果。
統合以上所有資訊可以看出這是一個大部分物件存活時間都不會太長的應用,所以初步的想法是增大年輕代的大小,讓大部分物件都在年輕代被回收,減少進入老年代的機率。
下面貼出Demo的程式碼,為了模擬一個類似的情況可能Demo中的程式碼採用了一些取巧或者極端的設定,或許這也不能很好的表達原本的邏輯,但一個40行不到就可以執行的Demo總比一個複雜的專案或者開源軟體容易理解
/**
* @author fengxiao
* @date 2021-11-09
*/
@RestController
@SpringBootApplication
public class Application {
private final Logger logger = LoggerFactory.getLogger(Application.class);
//1. 模擬記憶體快取, 短期物件
private Cache<Integer, Book> shortCache;
//2. 模擬業務流程裡 中等存活時長 物件,,從而使短期物件更有可能進入老年代
private Cache<Integer, Book> mediumCache;
public static void main(String[] args) {
SpringApplication.run(Application.class, args);
}
@PostConstruct
public void init() {
//3. 這裡本地快取的數值設定在實際業務中並不具有參考性,只是設法讓一部分物件在初始的設定下進入老年代
shortCache = Caffeine.newBuilder().maximumSize(800).initialCapacity(800)
.expireAfterWrite(3, TimeUnit.SECONDS)
.removalListener((k, v, c) -> logger.info("Cache Removed,K:{}, V:{}, Cause:{}", k, v, c))
.build();
mediumCache = Caffeine.newBuilder().maximumSize(1000).softValues()
.expireAfterWrite(30, TimeUnit.SECONDS)
.build();
}
@GetMapping("/book")
public Book book() {
//4. 模擬業務處理流程中其他模組短期物件生成的消耗,可以調整這個引數來對老年代無干擾的增加YoungGC的頻率
// byte[] bytes = new byte[16 * 1024];
return shortCache.get(new Random().nextInt(5000), (id) -> {
//5. 模擬正常的LRU快取場景消耗
Book book = new Book().setId(id).setArchives(new byte[256 * 1024]);
//6. 模擬業務系統中對老年代的正常消耗
mediumCache.put(id, new Book().setArchives(new byte[128 * 1024]));
return book;
}
);
}
}
4.準備調優環境
一旦確定了方向,就需要為GC調優準備環境。這一步的結果將是你所選擇目標的價值。總之,目標和價值將成為要調優的環境的系統需求。
4.1 容器映象選擇
其實就是選擇JDK的版本,不同版本的JDK可選擇的收集器組合不盡相同,而根據業務型別選擇收集器也是至關重要的。
因為在日常工作中使用的JDK版本還是1.8,結合上面談到的吞吐量目標自然就選擇了PS/PO(也是JDK1.8服務端預設收集器),關於收集器的特性和組合在這裡不做展開,有需要自行查閱書籍和文件。
4.2 啟動/預熱工作負載
在測量特定應用程式JVM的GC效能之前,需要能夠讓應用程式執行工作並達到穩定狀態。這是通過將load應用到應用程式來實現的。
建議將負載建模為希望調優GC的穩定狀態負載,即反映應用程式在生產環境中使用時的使用模式和使用量的負載。這裡可以拉上測試部門的同事一起完成,通過壓測、流量回放等手段讓目標程式接近於真實生產中的狀態,同時需要注意的是類似的硬體、作業系統版本、載入配置檔案等等。負載環境、配額可以通過容器化很方便的實現。
Demo這裡以JMeter來模擬壓力。簡單的一點也可以用指令碼或者直接錄製真實的流量進行回放。
4.3 開啟GC日誌/監控
這一點相信大部分生產上的系統都是預設開啟的,如果是JDK9以下則:
JAVA_OPT="${JAVA_OPT} -Xloggc:${BASE_DIR}/logs/server_gc.log -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M"
JDK9則整合在了xlog引數中:
-Xlog:gc*:file=${BASE_DIR}/logs/server_gc.log:time,tags:filecount=10,filesize=102400"
然後就需要理解GC日誌的各種欄位資訊含義了,這裡建議多觀察自己系統中的GC日誌,理解日誌含義。
至於監控的話可以接入類似Prometheus+Grafana這樣的監控系統,監控+報警,誰也不想天天盯著GC日誌看。所以此處為了方便展示結果臨時搭建了一個Prometheus+Grafana監控,Elasticsearch+Kibana用來分析GC日誌。用最小的配置啟動Grafana:
version: '3.1'
services:
prometheus:
image: prom/prometheus
volumes:
- ./prometheus/prometheus.yml:/etc/prometheus/prometheus.yml
ports:
- 9090:9090
container_name: prometheus
grafana:
image: grafana/grafana
depends_on:
- prometheus
ports:
- 3000:3000
container_name: grafana
對Prometheus和Grafana做一些基本的配置後隨意匯入一個JVM相關的監控皮膚即可:
4.4 確定記憶體足跡
記憶體足跡是指程式在執行時使用或引用的主記憶體的數量(Wiki傳送門:Memory footprint,以下以記憶體佔用這個通俗的理解作為簡稱)
為了優化JVM分代的大小,需要很好地瞭解穩定狀態活動資料集的大小,可以通過以下兩種方式獲得相關資訊:
- 從GC日誌觀察
- 從視覺化監控中觀察(直觀)
5. 確定系統需求
回到效能目標,我們討論了VM GC調優的三個效能目標。現在需要確定這些目標的值,它們表示你正在調優GC效能的環境的系統需求。需要確定的一些系統要求是:
- 可接受的平均Minor GC暫停時間
- 可接受的平均GC暫停時間
- 最大可容忍的Full GC暫停時間
- 可用時間百分比表示的可接受的最小吞吐量
通常,如果關注的是Latency(延遲)或Footprint(記憶體佔用)目標,那麼可能傾向於較小的堆記憶體值,並使用較小的吞吐量值設定暫停時間的最大容限;相反,如果您關注的是吞吐量,那麼您可能會希望在沒有最大容差的情況下使用更大的暫停時間值和更大的吞吐量值。
這部分最好結合自己當前負責業務系統的現狀進行評估和擬定,在一個基準值上進行調優。以D服務的原始吞吐量舉例(實際的業務系統中各種複雜的情況都要細緻考慮):
系統要求 | 值 |
---|---|
可接受的Minor GC暫停時間: | 0.2秒 |
可接受的Full GC暫停時間: | 2秒 |
可接受的最低吞吐量: | 95% |
這一步可以多理解Java官方文件中的 Behavior-Based Tuning ,以及一些現成的JVM調優案例,重要的是理解思想然後結合自己的業務來確定需求。
6. 設定樣本引數開始壓測
以下為本例中D服務的基準執行引數
java -Xms4g -Xmx4g
-XX:-OmitStackTraceInFastThrow
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=logs/java_heapdump.hprof
-Xloggc:logs/server_gc.log
-verbose:gc
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-XX:+PrintGCTimeStamps
-XX:+UseGCLogFileRotation
-XX:NumberOfGCLogFiles=10
-XX:GCLogFileSize=100M
-jar spring-lite-1.0.0.jar
此時使用jmap命令分析堆區情況如下,程式是跑在虛擬機器裡的,因為除錯引數的時候發現有些情況下會頻繁GC所以只分配了4個邏輯處理器:
Debugger attached successfully.
Server compiler detected.
JVM version is 25.40-b25
using thread-local object allocation.
Parallel GC with 4 thread(s)
Heap Configuration:
MinHeapFreeRatio = 0
MaxHeapFreeRatio = 100
MaxHeapSize = 4294967296 (4096.0MB)
NewSize = 1431306240 (1365.0MB)
MaxNewSize = 1431306240 (1365.0MB)
OldSize = 2863661056 (2731.0MB)
NewRatio = 2
SurvivorRatio = 8
MetaspaceSize = 21807104 (20.796875MB)
CompressedClassSpaceSize = 1073741824 (1024.0MB)
MaxMetaspaceSize = 17592186044415 MB
G1HeapRegionSize = 0 (0.0MB)
Heap Usage:
PS Young Generation
Eden Space:
capacity = 1073741824 (1024.0MB)
used = 257701336 (245.76314544677734MB)
free = 816040488 (778.2368545532227MB)
24.00030717253685% used
From Space:
capacity = 178782208 (170.5MB)
used = 0 (0.0MB)
free = 178782208 (170.5MB)
0.0% used
To Space:
capacity = 178782208 (170.5MB)
used = 0 (0.0MB)
free = 178782208 (170.5MB)
0.0% used
PS Old Generation
capacity = 2863661056 (2731.0MB)
used = 12164632 (11.601097106933594MB)
free = 2851496424 (2719.3989028930664MB)
0.42479301014037324% used
14856 interned Strings occupying 1288376 bytes.
Jmeter請求設定如下,因為Demo的流程裡沒有任何業務邏輯所以即使單執行緒都有較高的吞吐量,但要注意測試環境配置的區別,例如我在IDE中直接使用Jmeter單執行緒吞吐量就可以達到1800/s,而到了一個配置較低的虛擬機器中需要多個執行緒才能達到相似的吞吐量級,所以可以加幾個執行緒同時用吞吐量定時器控制請求速率:
每次調整引數反覆的進行請求,每次半個小時。這是對於Demo的,如果時真實的業務系統務必多花時間取樣
7.分析GC日誌
對於本例中的Demo取了四種引數下的GC日誌結果,Grafana概覽如下:
最終產生了四個GC日誌樣本,檔名裡的記憶體大小是指年輕代的大小,對於生產服務可以從多個角度採集更多引數樣本:
7.1 匯入Elasticsearch
接下來我們將GC日誌匯入到Elasticsearch中,並來到Kibana檢視(注意這裡的Elasticsearch和Kibana必需是7.14版本以上的,否則後續的操作會因為版本原因無法完成):
此時索引中的GC還是原始格式,就像是在Linux中直接開啟一樣,所以我們需要通過Grok Pattern將日誌拆分成各個關鍵欄位。實際開發場景可以用Logstash解析並傳輸,這裡只是做個演示,所以通過IngestPipeline + Reindex 快速處理索引資料。
成功後索引如下所示,我們擁有了可以製作視覺化皮膚的結構化GC資料(Grok Pattern這裡就不分享了,主要是我花了半個小時寫出來的表示式似乎還不能完美匹配一些特殊的GC日誌行= =。也是建議大家自己編寫匹配表示式,這樣可以細緻的消化GC日誌的結構)
7.2 製作視覺化皮膚
現在通過聚合找到每個日誌索引對應的開始時間以及結束時間
GET throughput-gc-log-converted*/_search
{
"size": 0,
"aggs": {
"index": {
"terms": { "field": "_index", "size": 10 },
"aggs": {
"start_time": {
"min": { "field": "timestamp" }
},
"stop_time": {
"max": { "field": "timestamp" }
}
}
}
}
}
// 響應如下:
"aggregations" : {
"index" : {
"doc_count_error_upper_bound" : 0,
"sum_other_doc_count" : 0,
"buckets" : [
{
"key" : "throughput-gc-log-converted-eden1.3g",
"doc_count" : 1165,
"start_time" : { "value" : 1.637476135722E12, "value_as_string" : "2021-11-21T06:28:55.722Z"
},
"stop_time" : { "value" : 1.637478206592E12, "value_as_string" : "2021-11-21T07:03:26.592Z" }
},
{
"key" : "throughput-gc-log-converted-eden1.6g",
"doc_count" : 898,
"start_time" : { "value" : 1.637480290228E12, "value_as_string" : "2021-11-21T07:38:10.228Z"
},
"stop_time" : { "value" : 1.637482100695E12, "value_as_string" : "2021-11-21T08:08:20.695Z" }
},
{
"key" : "throughput-gc-log-converted-eden2.0g",
"doc_count" : 669,
"start_time" : { "value" : 1.63747831467E12, "value_as_string" : "2021-11-21T07:05:14.670Z"
},
"stop_time" : { "value" : 1.637480148437E12, "value_as_string" : "2021-11-21T07:35:48.437Z" }
},
{
"key" : "throughput-gc-log-converted-eden2.5g",
"doc_count" : 505,
"start_time" : { "value" : 1.637482323999E12, "value_as_string" : "2021-11-21T08:12:03.999Z"
},
"stop_time" : { "value" : 1.637484145358E12, "value_as_string" : "2021-11-21T08:42:25.358Z" }
}
]
}
}
確定了時間範圍之後進入Dashboard頁面,建立視覺化皮膚如下。之所以需要精確的時間範圍,就是需要精確的偏移時間以對比不同情況下GC的表現,現在我們可以觀察不同設定下的GC次數和GC耗時,另外和同事分享或者向領導彙報調優結果時有現成的圖示總比一堆資料好用吧~
7.3 獲得效能指標
使用聚合語句來計算GC各項指標:
GET throughput-gc-log-converted*/_search
{
"size": 0,
"aggs": {
"index": {
"terms": {
"field": "_index",
"size": 10
},
"aggs": {
"gc_type_count": {
"terms": { "field": "gc_type.keyword" },
"aggs": {
"cost": {
"sum": { "field": "clock_time" }
}
}
},
"total_cost": {
"sum": { "field": "clock_time" }
},
"throughput_calc": {
"bucket_script": {
"buckets_path": { "total_cost": "total_cost" },
"script": "1 -(params.total_cost/1800)"
}
}
}
}
}
}
結果如圖所示:
8.確定結果引數
分析之後的結果其實並不重要,因為最終的決定要看調優者對業務系統以及垃圾收集的理解。在上一小節我們得到了在不同引數下D服務的吞吐量表現,最終是否要選那個看起來數值最好的引數還要結合其他情況。
本例中,最好的吞吐量結果 98.2%是在年輕代2.5G的設定下得到的,那為什麼不嘗試著再加大年輕代的大小呢?因為沒有意義,真實的業務系統不太可能出現年輕代和老年代比例超過3:1的。即使真的有,這樣的虛擬機器引數似乎也有點偏激了,業務需求永遠不會變動嗎?
最後如何改變引數還是得結合著一些成熟穩定的調優準則和經驗,例如你可以在各種GC優化的部落格裡看到諸如:
- 最大堆大小應該在老年代平均值的3 - 4倍之間。
- 觀察記憶體足跡,老年代不應少於老年代平均值的1.5倍。
- 年輕代應該大於整個堆的10%。
- 在調整JVM的大小時,不要超過可用的實體記憶體量。
- 。。。。。
話題回到本例中的Demo,如果看到一個生產服務這樣的綜合結果,我不會顯式的設定-Xmn到任何值,而是會設定例如-XX:NewRatio=1這樣的相對比值(本文參考最近一次真實的生產服務調優,真實的調優結果就是NewRatio和一些其他值)。
如果正在看文章的你仔細的觀察了Demo 的程式碼並分析其物件消耗就會發現,筆者花費不少時間調製了一些引數讓這個Demo在較低年輕代分配下會產生年輕代物件剛進入老年代就進入瀕死狀態了,從而導致高頻的GC;而當年輕代達到2.3G+的閾值時,快取物件和超時時間達到了一個微妙的平衡,快取物件根本不可能進入老年代,不會產生Full GC。如以下聚合結果所示(這個SpringBoot程式啟動基礎產生了2次Full GC):
{
"key": "throughput-gc-log-converted-eden1.3g",
"doc_count": 1165,
"total_cost": { "value": 75.87 },
"gc_type_count": {
"doc_count_error_upper_bound": 0,
"sum_other_doc_count": 0,
"buckets": [
{
"key": "GC",
"doc_count": 1113,
"cost": { "value": 69.86 }
},
{
"key": "Full GC",
"doc_count": 52,
"cost": { "value": 6.01 }
}
]
},
"throughput_calc": { "value": 0.95785 }
},
{
"key": "throughput-gc-log-converted-eden2.0g",
"doc_count": 669,
"total_cost": { "value": 45.75 },
"gc_type_count": {
"doc_count_error_upper_bound": 0,
"sum_other_doc_count": 0,
"buckets": [
{
"key": "GC",
"doc_count": 650,
"cost": { "value": 43.65 }
},
{
"key": "Full GC",
"doc_count": 19,
"cost": { "value": 2.1 }
}
]
},
"throughput_calc": { "value": 0.9745833333333334 }
},
{
"key": "throughput-gc-log-converted-eden2.5g",
"doc_count": 505,
"total_cost": { "value": 30.66 },
"gc_type_count": {
"doc_count_error_upper_bound": 0,
"sum_other_doc_count": 0,
"buckets": [
{
"key": "GC",
"doc_count": 503,
"cost": { "value": 30.57 }
},
{
"key": "Full GC",
"doc_count": 2,
"cost": { "value": 0.09 }
}
]
},
"throughput_calc": { "value": 0.9829666666666667 }
}
而在實際快速迭代的生產服務中很少出現這樣的巧合,即使真的出現了也不要自作聰明的取巧設定。因為在錯綜複雜的業務系統之上,任何一個簡單的業務需求改動都能輕鬆的破壞精心設定的引數。當然如果你開發的系統是定期釋出的中介軟體產品或類似的軟體那無所謂。
9. 測量引數變化後的狀況
這一步的耗時通常比調優的過程更長。在實際的確定了調優方向和引數後,制定結果預期、和測試部門的同事進行對接,各種方面的測試全部走起來,從系統頂層收集指標變化,順利的話花費數週的時間或許引數配置就可以被合併到配置倉庫主幹分支了。
如果結果沒有達到預期,那重新來~
10. 總結
最近雜項事情很多,匆匆忙忙整理的一篇隨筆,結構和措辭可能沒有經過細緻整理,還請諒解 =_=
本文整理的是關於GC調優方面理解的一個基本流程以及思路,個人水平有限如果有描述錯誤或者更好的思想還請不吝賜教 X_X。
附錄:參考資料
- https://docs.oracle.com/javase/8/docs/technotes/guides/vm/gctuning/
- https://docs.oracle.com/en/java/javase/11/gctuning/index.html
- https://docs.oracle.com/javase/8/docs/technotes/tools/unix/java.html#BABDJJFI
- Memory Management in the Java HotSpot Virtual Machine (oracle.com)
- https://docs.tigase.net/tigase-server/7.1.0/Administration_Guide/html_chunk/jvm_settings.html
- https://confluence.atlassian.com/enterprise/garbage-collection-gc-tuning-guide-461504616.html