通過 Java 線程堆棧進行性能瓶頸分析

改善性能意味着用更少的資源做更多的事情。為了利用並發來提高系統性能，我們需要更有效的利用現有的處理器資源，這意味着我們期望使 CPU 盡可能出於忙碌狀態（當然，並不是讓 CPU 周期出於應付無用計算，而是讓 CPU 做有用的事情而忙）。如果程序受限於當前的 CPU 計算能力，那么我們通過增加更多的處理器或者通過集群就能提高總的性能。總的來說，性能提高，需要且僅需要解決當前的受限資源，當前受限資源可能是：

• CPU： 如果當前 CPU 已經能夠接近 100% 的利用率，並且代碼業務邏輯無法再簡化，那么說明該系統的性能以及達到上線，只有通過增加處理器來提高性能
• 其他資源：比如連接數等。可以修改代碼，盡量利用 CPU，可以獲得極大的性能提升

如果你的系統有如下的特點，說明系統存在性能瓶頸：

• 隨着系統逐步增加壓力，CPU 使用率無法趨近 100%（如下圖）

  

• 持續運行緩慢。時常發現應用程序運行緩慢。通過改變環境因子（負載，連接數等）也無法有效提升整體響應時間

• 系統性能隨時間的增加逐漸下降。在負載穩定的情況下，系統運行時間越長速度越慢。可能是由於超出某個閾值范圍，系統運行頻繁出錯從而導致系統死鎖或崩潰
• 系統性能隨負載的增加而逐漸下降。

一個好的程序，應該是能夠充分利用 CPU 的。如果一個程序在單 CPU 的機器上無論多大壓力都不能使 CPU 使用率接近 100%，說明這個程序設計有問題。一個系統的性能瓶頸分析過程大致如下：

1. 先進性單流程的性能瓶頸分析，受限讓單流程的性能達到最優。
2. 進行整體性能瓶頸分析。因為單流程性能最優，不一定整個系統性能最優。在多線程場合下，鎖爭用㩐給也會導致性能下降。

高性能在不同的應用場合下，有不同的含義：

1. 有的場合高性能意味着用戶速度的體驗，如界面操作等
2. 有的場合，高吞吐量意味着高性能，如短信或者彩信，系統更看重吞吐量，而對每一個消息的處理時間不敏感
3. 有的場合，是二者的結合

性能調優的終極目標是：系統的 CPU 利用率接近 100%，如果 CPU 沒有被充分利用，那么有如下幾個可能：

1. 施加的壓力不足
2. 系統存在瓶頸

1 常見的性能瓶頸

1.1 由於不恰當的同步導致的資源爭用

1.1.1 不相關的兩個函數，公用了一個鎖，或者不同的共享變量共用了同一個鎖，無謂地制造出了資源爭用

下面是一種常見的錯誤

兩個不相干的方法（沒有使用同一個共享變量），共用了 this 鎖，導致人為的資源競爭上面的代碼將 synchronized 加在類的每一個方法上面，違背了保護什么鎖什么的原則。對於無共享資源的方法，使用了同一個鎖，人為造成了不必要的等待。Java 缺省提供了 this 鎖，這樣很多人喜歡直接在方法上使用 synchronized 加鎖，很多情況下這樣做是不恰當的，如果不考慮清楚就這樣做，很容易造成鎖粒度過大：

• 即使一個方法中的代碼也不是處處需要鎖保護的。如果整個方法使用了 synchronized，那么很可能就把 synchronized 的作用域給人為擴大了。在方法級別上加鎖，是一種粗獷的鎖使用習慣。

上面的代碼應該變成下面

這樣會導致當前線程占用鎖的時間過長，其他需要鎖的線程只能等待，最終導致性能受到極大影響1.1.2 鎖的粒度過大，對共享資源訪問完成后，沒有將后續的代碼放在synchronized 同步代碼塊之外

單 CPU 場合 將耗時操作拿到同步塊之外，有的情況下可以提升性能，有的場合則不能：上面的代碼，會導致一個線程長時間占有鎖，而在這么長的時間里其他線程只能等待，這種寫法在不同的場合下有不同的提升余地：

• • 同步塊的耗時代碼是 CPU 密集型代碼（純 CPU 運算等），不存在磁盤 IO/網絡 IO 等低 CPU 消耗的代碼，這種情況下，由於 CPU 執行這段代碼是 100% 的使用率，因此縮小同步塊也不會帶來任何性能上的提升。但是，同時縮小同步塊也不會帶來性能上的下降
  • 同步塊中的耗時代碼屬於磁盤/網絡 IO等低 CPU 消耗的代碼，當當前線程正在執行不消耗 CPU 的代碼時，這時候 CPU 是空閑的，如果此時讓 CPU 忙起來，可以帶來整體性能上的提升，所以在這種場景下，將耗時操作的代碼放在同步之外，肯定是可以提高整個性能的（？）
• 多 CPU 場合 將耗時的操作拿到同步塊之外，總是可以提升性能
  • 同步塊的耗時代碼是 CPU 密集型代碼（純 CPU 運算等），不存在磁盤 IO/網絡 IO 等低 CPU 消耗的代碼，這種情況下，由於是多 CPU，其他 CPU也許是空閑的，因此縮小同步塊可以讓其他線程馬上得到執行這段代碼，可以帶來性能的提升
  • 同步塊中的耗時代碼屬於磁盤/網絡 IO等低 CPU 消耗的代碼，當當前線程正在執行不消耗 CPU 的代碼時，這時候總有 CPU 是空閑的，如果此時讓 CPU 忙起來，可以帶來整體性能上的提升，所以在這種場景下，將耗時操作的代碼放在同步塊之外，肯定是可以提高整個性能的

不管如何，縮小同步范圍，對系統沒有任何不好的影響，大多數情況下，會帶來性能的提升，所以一定要縮小同步范圍，因此上面的代碼應該改為

Sleep 的濫用，尤其是輪詢中使用 sleep，會讓用戶明顯感覺到延遲，可以修改為 notify 和 wait1.1.3 其他問題

• String + 的濫用，每次 + 都會產生一個臨時對象，並有數據的拷貝
• 不恰當的線程模型
• 效率地下的 SQL 語句或者不恰當的數據庫設計
• 不恰當的 GC 參數設置導致的性能低下
• 線程數量不足
• 內存泄漏導致的頻繁 GC

2.2 性能瓶頸分析的手段和工具

上面提到的這些原因形成的性能瓶頸，都可以通過線程堆棧分析，找到根本原因。

2.2.1 如何去模擬，發現性能瓶頸

性能瓶頸的幾個特征：

• 當前的性能瓶頸只有一處，只有當解決了這一處，才知道下一處。沒有解決當前性能瓶頸，下一處性能瓶頸是不會出現的。如下圖所示，第二段是瓶頸，解決第二段的瓶頸后，第一段就變成了瓶頸，如此反復找到所有的性能瓶頸

• 性能瓶頸是動態的，低負載下不是瓶頸的地方，高負載下可能成為瓶頸。由於 JProfile 等性能剖析工具依附在 JVM 上帶來的開銷，使系統根本就無法達到該瓶頸出現時需要的性能，因此在這種場景下線程堆棧分析才是一個真正有效的方法

鑒於性能瓶頸的以上特點，進行性能模擬的時候，一定要使用比系統當前稍高的壓力下進行模擬，否則性能瓶頸不會出現。具體步驟如下：

2.2.2 如何通過線程堆棧識別性能瓶頸

通過線程堆棧，可以很容易的識別多線程場合下高負載的時候才會出現的性能瓶頸。一旦一個系統出現性能瓶頸，最重要的就是識別性能瓶頸，然后根據識別的性能瓶頸進行修改。一般多線程系統，先按照線程的功能進行歸類（組），把執行相同功能代碼的線程作為一組進行分析。當使用堆棧進行分析的時候，以這一組線程進行統計學分析。如果一個線程池為不同的功能代碼服務，那么將整個線程池的線程作為一組進行分析即可。

一般一個系統一旦出現性能瓶頸，從堆棧上分析，有如下三種最為典型的堆棧特征：

1. 絕大多數線程的堆棧都表現為在同一個調用上下文，且只剩下非常少的空閑線程。可能的原因如下：
   • 線程的數量過少
   • 鎖的粒度過大導致的鎖競爭
   • 資源競爭
   • 鎖范圍中有大量耗時操作
   • 遠程通信的對方處理緩慢
2. 絕大多數線程出於等待狀態，只有幾個工作的線程，總體性能上不去。可能的原因是，系統存在關鍵路徑，關鍵路徑已經達到瓶頸
3. 線程總的數量很少（有些線程池的實現是按需創建線程，可能程序中創建線程

一個例子

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83

"Thread-243" prio=1 tid=0xa58f2048 nid=0x7ac2 runnable [0xaeedb000..0xaeedc480] at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at oracle.net.ns.Packet.receive(Unknown Source) ... ... at oracle.jdbc.driver.LongRawAccessor.getBytes() at oracle.jdbc.driver.OracleResultSetImpl.getBytes() - locked <0x9350b0d8> (a oracle.jdbc.driver.OracleResultSetImpl) at oracle.jdbc.driver.OracleResultSet.getBytes(O) ... ... at org.hibernate.loader.hql.QueryLoader.list() at org.hibernate.hql.ast.QueryTranslatorImpl.list() ... ... at com.wes.NodeTimerOut.execute(NodeTimerOut.java:175) at com.wes.timer.TimerTaskImpl.executeAll(TimerTaskImpl.java:707) at com.wes.timer.TimerTaskImpl.execute(TimerTaskImpl.java:627) - locked <0x80df8ce8> (a com.wes.timer.TimerTaskImpl) at com.wes.threadpool.RunnableWrapper.run(RunnableWrapper.java:209) at com.wes.threadpool.PooledExecutorEx$Worker.run() at java.lang.Thread.run(Thread.java:595) "Thread-248" prio=1 tid=0xa58f2048 nid=0x7ac2 runnable [0xaeedb000..0xaeedc480] at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at oracle.net.ns.Packet.receive(Unknown Source) ... ... at oracle.jdbc.driver.LongRawAccessor.getBytes() at oracle.jdbc.driver.OracleResultSetImpl.getBytes() - locked <0x9350b0d8> (a oracle.jdbc.driver.OracleResultSetImpl) at oracle.jdbc.driver.OracleResultSet.getBytes(O) ... ... at org.hibernate.loader.hql.QueryLoader.list() at org.hibernate.hql.ast.QueryTranslatorImpl.list() ... ... at com.wes.NodeTimerOut.execute(NodeTimerOut.java:175) at com.wes.timer.TimerTaskImpl.executeAll(TimerTaskImpl.java:707) at com.wes.timer.TimerTaskImpl.execute(TimerTaskImpl.java:627) - locked <0x80df8ce8> (a com.wes.timer.TimerTaskImpl) at com.wes.threadpool.RunnableWrapper.run(RunnableWrapper.java:209) at com.wes.threadpool.PooledExecutorEx$Worker.run() at java.lang.Thread.run(Thread.java:595) ... ... "Thread-238" prio=1 tid=0xa4a84a58 nid=0x7abd in Object.wait() [0xaec56000..0xaec57700] at java.lang.Object.wait(Native Method) at com.wes.collection.SimpleLinkedList.poll(SimpleLinkedList.java:104) - locked <0x6ae67be0> (a com.wes.collection.SimpleLinkedList) at com.wes.XADataSourceImpl.getConnection_internal(XADataSourceImpl.java:1642) ... ... at org.hibernate.impl.SessionImpl.list() at org.hibernate.impl.SessionImpl.find() at com.wes.DBSessionMediatorImpl.find() at com.wes.ResourceDBInteractorImpl.getCallBackObj() at com.wes.NodeTimerOut.execute(NodeTimerOut.java:152) at com.wes.timer.TimerTaskImpl.executeAll() at com.wes.timer.TimerTaskImpl.execute(TimerTaskImpl.java:627) - locked <0x80e08c00> (a com.facilities.timer.TimerTaskImpl) at com.wes.threadpool.RunnableWrapper.run(RunnableWrapper.java:209) at com.wes.threadpool.PooledExecutorEx$Worker.run() at java.lang.Thread.run(Thread.java:595)     "Thread-233" prio=1 tid=0xa4a84a58 nid=0x7abd in Object.wait() [0xaec56000..0xaec57700]   at java.lang.Object.wait(Native Method) at com.wes.collection.SimpleLinkedList.poll(SimpleLinkedList.java:104) - locked <0x6ae67be0> (a com.wes.collection.SimpleLinkedList) at com.wes.XADataSourceImpl.getConnection_internal(XADataSourceImpl.java:1642) ... ... at org.hibernate.impl.SessionImpl.list() at org.hibernate.impl.SessionImpl.find() at com.wes.DBSessionMediatorImpl.find() at com.wes.ResourceDBInteractorImpl.getCallBackObj() at com.wes.NodeTimerOut.execute(NodeTimerOut.java:152) at com.wes.timer.TimerTaskImpl.executeAll() at com.wes.timer.TimerTaskImpl.execute(TimerTaskImpl.java:627) - locked <0x80e08c00> (a com.facilities.timer.TimerTaskImpl) at com.wes.threadpool.RunnableWrapper.run(RunnableWrapper.java:209) at com.wes.threadpool.PooledExecutorEx$Worker.run() at java.lang.Thread.run(Thread.java:595) ... ...

從堆棧看，有 51 個（socket）訪問，其中有 50 個是 JDBC 數據庫訪問。其他方法被阻塞在 java.lang.Object.wait() 方法上。

2.2.3 其他提高性能的方法

減少鎖的粒度，比如 ConcurrentHashMap 的實現默認使用 16 個鎖的 Array（有一個副作用：鎖整個容器會很費力，可以添加一個全局鎖）

2.2.4 性能調優的終結條件

性能調優總有一個終止條件，如果系統滿足如下兩個條件，即可終止：

1. 算法足夠優化
2. 沒有線程/資源的使用不當而導致的 CPU 利用不足