編者按：在升級(jí) JDK8U 的小版本后（從 8u74 升級(jí)到 8u202），遇到性能劇烈下降的問(wèn)題（性能下降 13 倍）。該應(yīng)用是一個(gè)非常簡(jiǎn)單的 Web 應(yīng)用，且應(yīng)用在 JDK 升級(jí)前后并無(wú)任何發(fā)布修復(fù)。

通常來(lái)說(shuō) JDK 小版本升級(jí)都是問(wèn)題修改，不影響功能和性能使用，而應(yīng)用性能劇烈下降一定是 JDK 的內(nèi)部 bug。對(duì)于這樣明確由 JDK 引起的性能問(wèn)題，該如何解決？

最常見(jiàn)的方法是通過(guò)工具分析 JVM 執(zhí)行過(guò)程，檢查函數(shù)執(zhí)行的情況是否發(fā)生變化，如果找到變化，則可以深入分析哪些因素引起了變化，并進(jìn)一步得到根因。筆者使用 perf 工具分析 JVM 執(zhí)行時(shí)的熱點(diǎn)函數(shù)，并對(duì)出現(xiàn)問(wèn)題的函數(shù)進(jìn)行剖析，使用函數(shù)插樁來(lái)分析函數(shù)的執(zhí)行次數(shù)，發(fā)現(xiàn)不同版本行為差異的根源，并找到了引起問(wèn)題的根因。希望讀者遇到性能問(wèn)題時(shí)可以參照本文使用 perf 工具對(duì)問(wèn)題進(jìn)行定位。

工欲善其事，必先利其器。程序員在定位性能瓶頸的時(shí)候，要是有一個(gè)趁手的性能調(diào)優(yōu)工具，能一針見(jiàn)血地指出程序的性能問(wèn)題，可謂事半功倍。

Linux 中最常用的性能調(diào)優(yōu)工具 Perf（Linux 系統(tǒng)原生提供的性能分析工具），使用 perf 先對(duì)應(yīng)用（假設(shè)要采樣的應(yīng)用為 JavaApp）進(jìn)行采樣，使用 record 命令，如下：

perfrecordjavaJavaApp

另外 perf 能按出現(xiàn)的百分比降序打印 CPU 正在執(zhí)行的函數(shù)名以及調(diào)用棧，如命令：

perfreport-n

這種結(jié)果的輸出還是不直觀的，Linux 性能優(yōu)化大師 Brendan Gregg 發(fā)明了火焰圖（因整個(gè)圖形看起來(lái)像燃燒的火焰而得名），以全局的方式來(lái)看各個(gè)函數(shù)的調(diào)用時(shí)間分布，以圖形化的方式列出調(diào)用棧。

火焰圖是基于 perf 的結(jié)果生成的圖形，我們先了解一下怎么去看火焰圖。

X 軸表示被抽樣到的次數(shù)。理解 X 軸的含義，需先了解采樣數(shù)據(jù)的原理。Perf 是在指定時(shí)間段內(nèi)，每隔一段時(shí)間采集一次數(shù)據(jù)，被采集到的次數(shù)越多，說(shuō)明該函數(shù)的執(zhí)行總時(shí)間長(zhǎng)，可能的原因有：調(diào)用次數(shù)多，或者單次執(zhí)行時(shí)間長(zhǎng)。因此，X 軸的寬度不能簡(jiǎn)單的認(rèn)為是運(yùn)行時(shí)長(zhǎng)。Y 軸表示調(diào)用棧。

如何從火焰圖看出性能的瓶頸在哪里？最有理由懷疑的地方，頂層的“平頂”。關(guān)于 perf 和火焰圖使用方法可以參官網(wǎng)http://www.brendangregg.com/FlameGraphs/cpuflamegraphs.html。

下面是我們利用火焰圖來(lái)定位問(wèn)題的一次實(shí)戰(zhàn)。

火焰圖定位問(wèn)題的實(shí)戰(zhàn)

問(wèn)題場(chǎng)景

問(wèn)題發(fā)生的場(chǎng)景是客戶端向服務(wù)器發(fā)起 http 請(qǐng)求，服務(wù)器返回?cái)?shù)據(jù)給客戶端（這是一個(gè)非常簡(jiǎn)單的服務(wù)交互）。我們發(fā)現(xiàn)使用 JDK 8u74 的性能要遠(yuǎn)優(yōu)于 JDK 8u202 的性能，下表中統(tǒng)計(jì)了 20 次服務(wù)器的響應(yīng)時(shí)長(zhǎng)。

從響應(yīng)時(shí)間來(lái)看，8u202 相比 8u74 性能下降 13 倍之多，由于應(yīng)用本身并未做任何修改，所以考慮使用火焰圖來(lái)定位性能消耗的問(wèn)題點(diǎn)。在 8u74 和 8u202 分別運(yùn)行應(yīng)用，并用 perf 的 record 抓取數(shù)據(jù)并生成火焰圖。

火焰圖定位

對(duì)比兩張火焰圖，使用 8u74 時(shí) ClientHandshaker.processMessage 占比為 1.15%，而在 8u202 中這個(gè)函數(shù)占比為 23.98%，很明顯在 ClientHandshaker.processMessage 帶來(lái)了性能差異。

根因定位

兩者在這個(gè) ClientHandshaker.processMessage 上的 cpu 消耗差異很大，繼續(xù)分析這個(gè)函數(shù)找到根因。

voidprocessMessage(bytehandshakeType,intlength)throwsIOException{ if(this.state>=handshakeType&&handshakeType!=0){ //...異常 }else{ label105: switch(handshakeType){ case0://hello_request this.serverHelloRequest(newHelloRequest(this.input)); break; //... case2://sever_hello this.serverHello(newServerHello(this.input,length)); break; case11:///certificate this.serverCertificate(newCertificateMsg(this.input)); this.serverKey=this.session.getPeerCertificates()[0].getPublicKey(); break; case12://server_key_exchange該消息并不是必須的，取決于協(xié)商出的key交換算法 //... case13://certificate_request客戶端雙向驗(yàn)證時(shí)需要 //... case14://server_hello_done this.serverHelloDone(newServerHelloDone(this.input)); break; case20://finished this.serverFinished(newFinished(this.protocolVersion,this.input,this.cipherSuite)); } if(this.state

processMessage()主要是通過(guò)不同的信息類(lèi)型進(jìn)行不同的握手消息的處理。而在火焰圖中可以看到，JDK8u74 圖中，主要消耗在函數(shù) serverFinished()和 serverHello()上，而 JDK8u202 主要消耗在函數(shù) serverHelloDone()和 serverKeyExchange()。

在介紹火焰圖的時(shí)候，我們有提到，X 軸的長(zhǎng)度是映射了被采樣到的次數(shù)。因此需要進(jìn)一步確定消耗：函數(shù)單次執(zhí)行耗時(shí)過(guò)長(zhǎng)而成為熱點(diǎn)，還是因?yàn)轭l繁調(diào)用函數(shù)導(dǎo)致函數(shù)耗時(shí)過(guò)長(zhǎng)而成為熱點(diǎn)。

可通過(guò)字節(jié)碼插樁（通過(guò) Instrument 技術(shù)實(shí)現(xiàn)對(duì)函數(shù)的計(jì)數(shù)，然后編譯成 agent，執(zhí)行應(yīng)用時(shí)加載 agent，具體使用 Instrument 的方法可以參考官方文檔）查看函數(shù) serverHelloDone()的調(diào)用次數(shù)及執(zhí)行時(shí)間。

JDK8u202數(shù)據(jù) Executecount:253 Executecount:258 Executecount:649 Executecount:661 serverHelloDoneexecutetime[1881195ns] Executecount:1223 Executecount:1234 Executecount:1843 Executecount:1852 serverHelloDoneexecutetime[1665012ns] Executecount:2446 Executecount:2456 serverHelloDoneexecutetime[1686206ns] JDK8u74數(shù)據(jù) Executecount:56 Executecount:56 Executecount:56 Executecount:56 Executecount:56 Executecount:56

Execute time 是取了每 1000 次調(diào)用的平均值，Execute count 每 5000ms 輸出一次總執(zhí)行次數(shù)。很明顯使用 JDK8u202 時(shí)在不斷調(diào)用 serverHelloDone,而 74 在調(diào)用 56 次后沒(méi)有再調(diào)用過(guò)這個(gè)函數(shù)。

初始化握手時(shí)，serverHelloDone 方法中，客戶端會(huì)根據(jù)服務(wù)端返回加密套件決定加密方式，構(gòu)造不同的 Client Key Exchange 消息；服務(wù)器如果允許重用該會(huì)話，則通過(guò)在 Server Hello 消息中設(shè)置相同的會(huì)話 ID 來(lái)應(yīng)答。

這樣，客戶端和服務(wù)器就可以利用原有會(huì)話的密鑰和加密套件，不必重新協(xié)商，也就不再走 serverHelloDone 方法。從現(xiàn)象來(lái)看， JDK8u202 沒(méi)有復(fù)用會(huì)話，而是建立的新的會(huì)話。

水落石出

查看 JDK8u 161 的 release notes，添加了 TLS 會(huì)話散列和擴(kuò)展主密鑰擴(kuò)展支持，找到引入的一個(gè)還未修復(fù)的 issue，對(duì)于帶有身份驗(yàn)證的 TLS 的客戶端，支持 UseExtendedMasterSecret 會(huì)破壞 TLS-Session 的恢復(fù)，導(dǎo)致不使用現(xiàn)有的 TLS-Session，而執(zhí)行新的 Handshake。

JDK8u161 之后的版本(含 JDK8u161)，若復(fù)用會(huì)話時(shí)不能成功恢復(fù) Session，而是創(chuàng)建新的會(huì)話，會(huì)造成較大性能消耗，且積壓的大量的不可復(fù)用的 session 造成 GC 壓力變大；如果業(yè)務(wù)場(chǎng)景存在不變更證書(shū)密鑰，需要復(fù)用會(huì)話，且對(duì)性能有要求，可通過(guò)添加參數(shù)-Djdk.tls.useExtendedMasterSecret=false 來(lái)解決這個(gè)問(wèn)題。

后記

如果遇到相關(guān)技術(shù)問(wèn)題（包括不限于畢昇 JDK），可以通過(guò)畢昇 JDK 社區(qū)求助。畢昇 JDK 社區(qū)每雙周周二舉行技術(shù)例會(huì)，同時(shí)有一個(gè)技術(shù)交流群討論 GCC、LLVM 和 JDK 等相關(guān)編譯技術(shù)，感興趣的同學(xué)可以添加如下微信小助手入群（請(qǐng)備注：Complier）。

編輯：jq