[轉帖]使用perf解決JDK8U小版本升級後效能下降的問題

济南小老虎發表於2024-05-22
JDK
https://heapdump.cn/monographic/detail/27/4172432

編者按：在升級JDK8U的小版本後（從8u74升級到8u202），遇到效能劇烈下降的問題（效能下降13倍）。該應用是一個非常簡單的Web應用，且應用在JDK升級前後並無任何釋出修改。通常來說JDK小版本升級都是問題修復，不影響功能和效能使用，而應用效能劇烈下降一定是JDK的內部bug。對於這樣明確由JDK引起的效能問題，該如何解決？最常見的方法是透過工具分析JVM執行過程，檢查函式執行的情況是否發生變化，如果找到變化，則可以深入分析哪些因素引起了變化，並進一步得到根因。筆者使用perf工具分析JVM執行時的熱點函式，並對出現問題的函式進行剖析，使用函式插樁來分析函式的執行次數，發現不同版本行為差異的根源，並找到了引起問題的根因。希望讀者遇到效能問題時可以參照本文使用perf工具對問題進行定位。

工欲善其事，必先利其器。程式設計師在定位效能瓶頸的時候，要是有一個趁手的效能調優工具，能一針見血地指出程式的效能問題，可謂事半功倍。
Linux中最常用的效能調優工具Perf（Linux系統原生提供的效能分析工具），使用perf先對應用（假設要取樣的應用為JavaApp）進行取樣，使用record命令，如下：
perf record java JavaApp
另外perf能按出現的百分比降序列印CPU正在執行的函式名以及呼叫棧，如命令：
perf report -n
可列印出：
image.png
這種結果的輸出還是不直觀的，Linux效能最佳化大師Brendan Gregg發明了火焰圖（因整個圖形看起來像燃燒的火焰而得名），以全域性的方式來看各個函式的呼叫時間分佈，以圖形化的方式列出呼叫棧。
1初識火焰圖
火焰圖是基於perf的結果生成的圖形，我們先了解一下怎麼去看火焰圖。以下圖為例：
image.png
X軸表示被抽樣到的次數。理解X軸的含義，需先了解取樣資料的原理。Perf是在指定時間段內，每隔一段時間採集一次資料，被採集到的次數越多，說明該函式的執行總時間長，可能的原因有：呼叫次數多，或者單次執行時間長。因此，X軸的寬度不能簡單的認為是執行時長。
Y軸表示呼叫棧。
如何從火焰圖看出效能的瓶頸在哪裡？最有理由懷疑的地方，頂層的“平頂”。關於perf和火焰圖使用方法可以參官網http://www.brendangregg.com/FlameGraphs/cpuflamegraphs.html。下面是我們利用火焰圖來定位問題的一次實戰。
2火焰圖定位問題的實戰
2.1問題場景
問題發生的場景是客戶端向伺服器發起http請求，伺服器返回資料給客戶端（這是一個非常簡單的服務互動）。我們發現使用JDK 8u74的效能要遠優於JDK 8u202的效能，下表中統計了20次伺服器的響應時長。
image.png

從響應時間來看，8u202相比8u74效能下降13倍之多，由於應用本身並未做任何修改，所以考慮使用火焰圖來定位效能消耗的問題點。在8u74和8u202分別執行應用，並用perf的record抓取資料並生成火焰圖。
2.2火焰圖定位
對比兩張火焰圖，使用8u74時ClientHandshaker.processMessage佔比為1.15%，而在8u202中這個函式佔比為23.98%，很明顯在ClientHandshaker.processMessage帶來了效能差異。
image.png
image.png
2.3根因定位
兩者在這個ClientHandshaker.processMessage上的cpu消耗差異很大，繼續分析這個函式找到根因。

void processMessage(byte handshakeType, int length) throws IOException {
    if(this.state >= handshakeType && handshakeType != 0) {
        //... 異常
    } else {
        label105:
        switch(handshakeType) {
        case 0://hello_request
            this.serverHelloRequest(new HelloRequest(this.input));
            break;
        //...
        case 2://sever_hello 
            this.serverHello(new ServerHello(this.input, length));
            break;
        case 11:///certificate 
            this.serverCertificate(new CertificateMsg(this.input));
            this.serverKey = this.session.getPeerCertificates()[0].getPublicKey();
            break;
        case 12://server_key_exchange 該訊息並不是必須的，取決於協商出的key交換演算法
            //...
        case 13: //certificate_request 客戶端雙向驗證時需要
            //...
        case 14://server_hello_done
            this.serverHelloDone(new ServerHelloDone(this.input));
            break;
        case 20://finished
            this.serverFinished(new Finished(this.protocolVersion, this.input, this.cipherSuite));
        }
        if(this.state < handshakeType) {//握手狀態
            this.state = handshakeType;
        }
    }
}

processMessage()主要是透過不同的資訊型別進行不同的握手訊息的處理。而在火焰圖中可以看到，JDK8u74圖中，主要消耗在函式serverFinished()和serverHello()上，而JDK8u202主要消耗在函式serverHelloDone()和serverKeyExchange()。
在介紹火焰圖的時候，我們有提到，X軸的長度是對映了被取樣到的次數。因此需要進一步確定消耗：函式單次執行耗時過長而成為熱點，還是因為頻繁呼叫函式導致函式耗時過長而成為熱點。可透過位元組碼插樁（透過Instrument技術實現對函式的計數，然後編譯成agent，執行應用時載入agent，具體使用Instrument的方法可以參考官方文件）檢視函式serverHelloDone()的呼叫次數及執行時間。
JDK8u202 資料

Execute count : 253
Execute count : 258
Execute count : 649
Execute count : 661
serverHelloDone execute time [1881195 ns]
Execute count : 1223
Execute count : 1234
Execute count : 1843
Execute count : 1852
serverHelloDone execute time [1665012 ns]
Execute count : 2446
Execute count : 2456
serverHelloDone execute time [1686206 ns]

JDK8u74 資料

Execute count : 56
Execute count : 56
Execute count : 56
Execute count : 56
Execute count : 56
Execute count : 56

Execute time是取了每1000次呼叫的平均值，Execute count每5000ms輸出一次總執行次數。很明顯使用JDK8u202時在不斷呼叫serverHelloDone,而74在呼叫56次後沒有再呼叫過這個函式。
初始化握手時，serverHelloDone方法中，客戶端會根據服務端返回加密套件決定加密方式，構造不同的Client Key Exchange訊息；伺服器如果允許重用該會話，則透過在Server Hello訊息中設定相同的會話ID來應答。這樣，客戶端和伺服器就可以利用原有會話的金鑰和加密套件，不必重新協商，也就不再走serverHelloDone方法。
從現象來看， JDK8u202沒有複用會話，而是建立的新的會話。
2.4水落石出
檢視JDK8u 161的release notes，新增了TLS會話雜湊和擴充套件主金鑰擴充套件支援，找到引入的一個還未修復的issue，對於帶有身份驗證的TLS的客戶端，支援UseExtendedMasterSecret會破壞TLS-Session的恢復，導致不使用現有的TLS-Session，而執行新的Handshake。
JDK8u161之後的版本(含JDK8u161)，若複用會話時不能成功恢復Session，而是建立新的會話，會造成較大效能消耗，且積壓的大量的不可複用的session造成GC壓力變大；如果業務場景存在不變更證書金鑰，需要複用會話，且對效能有要求，可透過新增引數-Djdk.tls.useExtendedMasterSecret=false來解決這個問題。
3後記
如果遇到相關技術問題（包括不限於畢昇JDK），可以透過畢昇JDK社群求助。畢昇JDK社群每雙週週二舉行技術例會，同時有一個技術交流群討論GCC、LLVM、JDK和V8等相關編譯技術，感興趣的同學可以新增如下微信小助手入群：amy347888，回覆Compiler入群（僅限技術交流，不允許其他目的）

相關文章