troubleshoot之:使用JFR分析性能問題

簡介

java程序的性能問題分析是一個很困難的問題。尤爲是對於一個很是複雜的程序來講，分析起來更是頭疼。

還好JVM引入了JFR，能夠經過JFR來監控和分析JVM的各類事件。經過這些事件的分析，咱們能夠找出潛在的問題。

今天咱們就來介紹一下對java性能分析比較重要的一些JFR事件。

GC性能事件

通常來講，GC會對java程序的性能操做產生比較重要的影響。咱們可使用jfr監控jdk.GCPhasePause事件。

下面是一個jdk.GCPhasePause的例子：

jfr print --events jdk.GCPhasePause flight_recording_1401comflydeanTestMemoryLeak89268.jfr

輸出結果：

jdk.GCPhasePause {
  startTime = 19:51:49.798
  duration = 41.1 ms
  gcId = 2
  name = "GC Pause"
}

經過GCPhasePause事件，咱們能夠統計總的GC pause時間和平均每一次GC pause的時間。

通常來講GC是在後臺執行的，因此GC自己的執行時間咱們並不須要關注，由於這並不會影響到程序的性能。咱們須要關注的是應用程序由於GC暫停的時間。

考慮下面兩種狀況，第一種單獨的GC致使GC pause時間過長。第二種是總的GC pause時間過長。

若是是第一種狀況，那麼可能須要考慮換一個GC類型，由於不一樣的GC類型在pause時間和吞吐量的平衡直接會有不一樣的處理。同時咱們須要減小finalizers的使用。

若是是第二種狀況，咱們能夠從下面幾個方面來解決。

• 增長heap空間大小。heap空間越大，GC的間隔時間就越長。總的GC pause時間就會越短。
• 儘可能減小tmp對象的分配。咱們知道爲了提高多線程的性能，JVM會使用TLAB技術。通常來講小對象會分配在TLAB中，但若是是大對象，則會直接分配在heap空間中。可是大部分對象都是在TLAB中分配的。因此咱們能夠同時關注TLAB和TLAB以外的兩個事件：jdk.ObjectAllocationInNewTLAB和dk.ObjectAllocationOutsideTLAB。
• 減小分配頻率。咱們能夠經過jdk.ThreadAllocationStatistics來分析。

同步性能

在多線程環境中，由於多線程會競爭共享資源，因此對資源的同步，或者鎖的使用都會影響程序的性能。

咱們能夠監控jdk.JavaMonitorWait事件。

jfr print --events jdk.JavaMonitorWait flight_recording_1401comflydeanTestMemoryLeak89268.jfr

咱們看一個結果：

jdk.JavaMonitorWait {
  startTime = 19:51:25.395
  duration = 2 m 0 s
  monitorClass = java.util.TaskQueue (classLoader = bootstrap)
  notifier = N/A
  timeout = 2 m 0 s
  timedOut = true
  address = 0x7FFBB7007F08
  eventThread = "JFR Recording Scheduler" (javaThreadId = 17)
  stackTrace = [
    java.lang.Object.wait(long)
    java.util.TimerThread.mainLoop() line: 553
    java.util.TimerThread.run() line: 506
  ]
}

經過分析JavaMonitorWait事件，咱們能夠找到競爭最激烈的鎖，從而進行更深層次的分析。

IO性能

若是應用程序有不少IO操做，那麼IO操做也是會影響性能的關鍵一環。

咱們能夠監控兩種IO類型：socket IO和File IO。

相對應的事件有：dk.SocketWrite，jdk.SocketRead，jdk.FileWrite，jdk.FileRead。

代碼執行的性能

代碼是經過CPU來運行的，若是CPU使用太高，也可能會影響到程序的性能。

咱們能夠經過監聽jdk.CPULoad事件來對CPULoad進行分析。

jfr print --events jdk.CPULoad flight_recording_1401comflydeanTestMemoryLeak89268.jfr

看下運行結果：

jdk.CPULoad {
  startTime = 19:53:25.519
  jvmUser = 0.63%
  jvmSystem = 0.37%
  machineTotal = 20.54%
}

若是jvm使用的cpu比較少，可是整個machine的CPU使用率比較高，這說明了有其餘的程序在佔用CPU。

若是JVM本身的CPU使用就很高的話，那麼就須要找到這個佔用CPU的線程進行進一步分析。

其餘有用的event

除了上面提到的event以外，還有一些其餘有用的咱們能夠關注的event。

好比線程相關的：jdk.ThreadStart，jdk.ThreadEnd，jdk.ThreadSleep，jdk.ThreadPark。

若是你使用JMC，那麼能夠很直觀的查看JFR的各類事件。

因此推薦你們使用JMC。

本文做者：flydean程序那些事

本文連接：http://www.flydean.com/jvm-diagnostic-perform-issue/

本文來源：flydean的博客

歡迎關注個人公衆號:程序那些事，更多精彩等着您！