您现在的位置：程式碼之家 >> 編程語言 > >> Java 程式設計 >> Java 相關知識

Java 應用頻繁拋出異常導致 CPU 異常飆升的排查實戰

編輯：Java 相關知識

某 Java 生產環境應用出現詭異 CPU 現象：QPS 基本穩定，但 CPU us 陷入「緩慢上升 → 急劇下降 → 再次上升」的週期性循環。初見此圖以為是 GC 曲線，深入排查後發現真兇竟是頻繁拋出的 NoSuchMethodException 觸發了 String.intern() 的效能崩塌。

現象與初步定位

使用 perf 追蹤發現 CPU 主要消耗在 StringTable::intern。淘寶 JVM 團隊曾遇過類似案例：應用大量拋異常導致 StringTable::intern 成為熱點。根據 JavaOne 2012《Advanced JVM Tuning》投影片，StringTable 預設大小僅 1009，超載後效能劇烈下降；《Look into the JVM Crystal Ball》也提及未來計劃改為動態擴容。

鎖定異常來源

使用淘寶自研 JDK 開關收集高頻異常與堆疊，鎖定為 NoSuchMethodException，堆疊指向：

java.lang.Class.getMethod(Class.java:1605)
org.apache.commons.beanutils.MethodUtils.getMatchingAccessibleMethod(MethodUtils.java:957)
org.apache.commons.beanutils.MappedPropertyDescriptor.getMethod(MappedPropertyDescriptor.java:409)

BTrace 精準定位缺失方法

編寫 BTrace 腳本攔截 NoSuchMethodException 建構子，打印呼叫堆疊：

@BTrace public class Trace {
    @OnMethod(clazz="java.lang.NoSuchMethodException", method="")
    public static void traceExecute(String s) {
        println("who call");
        println(s);
        jstack();
    }
}

快速捕獲到缺失的方法名，且異常拋出極其頻繁。初步懷疑類衝突，開啟 -XX:+TraceClassLoading 確認類載入來源，反編譯對應 JAR 確認方法確實不存在。業務邏輯在調用 BeanUtils 時觸發，推測前端提交了 POJO 中已刪除屬性對應的參數。

根因深挖：BeanUtils 「吞噬」異常

開發同學確認：頁面 Form 包含隱藏域，但 POJO 已無對應屬性。追蹤 BeanUtils 1.8.3 原始碼發現關鍵邏輯：

try {
    method = clazz.getMethod(methodName, parameterTypes);
    // ... 緩存與存取權限設定
    return method;
} catch (NoSuchMethodException e) { /* SWALLOW */ }

異常被直接吞噬，外部完全無感知。這解釋了為何日誌無異常卻 CPU 異常。

解決方案與效果驗證
採用預載入屬性白名單策略：啟動時將 POJO 所有屬性載入 Map，調用 BeanUtils 前先檢查屬性是否存在，不存在則跳過，徹底避免觸發 NoSuchMethodException。

上線後效果顯著：

CPU 曲線：從週期性飆升變為平穩低位運行（見對比圖）。
壓測數據：升級前 5 倍流量 CPU 80%、RT 接近 1s；升級後 10 倍流量 CPU 僅 13%、RT < 100ms。


深度復盤：真正的效能殺手
後續分析發現：頻繁拋異常本身非直接原因。真兇是 clazz.getMethod(methodName, parameterTypes) 內部呼叫 methodName.intern()。本案例中 methodName 隨請求動態變化，導致永久代 StringTable 不斷膨脹，超過 1009 桶限制引發嚴重哈希衝突，鏈表過長使每次 intern() 遍歷極其耗時。

核心教訓

高併發下頻繁拋異常代價極大，尤其是被吞噬的異常，更難發現。
String.intern() 在固定大小 StringTable 下極易成為瓶頸，動態產生大量字串時需謹慎使用。
排查 CPU 異常時，perf + BTrace + JDK 診斷開關的組合拳極其有效。
第三方庫（如 BeanUtils）的預設行為可能隱藏風險，生產環境必須審視源碼關鍵路徑。

   某Java應用在生產環境運行時cpu us呈現了非常詭異的現象，在qps（每秒請求數）基本穩定的情況下，cpu us會進入一個上漲–迅速下降然後又上漲的循環中，我第一眼看到這cpu us的圖的時候都以為是java gc的圖，於是著手排查是什麼原因造成的。
 1、用perf看看是什麼地方在耗cpu，跟蹤了一段時間後，看到主要是StringTable::intern在消耗cpu，幸運的是淘寶JVM團隊之前在做一個應用的優化的時候，也碰到了StringTable::intern是cpu us消耗的主要因素的現象，當時排查的原因是應用裡拋異常比較多造成的，於是同樣按照這個思路繼續；
 至於為什麼StringTable::intern會變得耗cpu，這個原因不太清楚，在JavaOne2012的《Advanced JVM Tuning》 slide裡有講到StringTable默認的大小是1009，超過了這個大小後性能會大幅度下降，在《Look into the JVM Crystal Ball》裡面的footprint的提升部分，也講到了希望將來改造為Dynamic resize StringTable。
 2、Taobao自己的JDK支持輸出某段時間內拋出的最多次數的異常，以及拋出異常的堆棧，於是在應用上打開了這個開關進行收集，看到應用會頻繁拋出NoSuchMethodException，堆棧信息如下：
 java.lang.Throwable.fillInStackTrace(Native Method)
 java.lang.Throwable.(Throwable.java:196)
 java.lang.Exception.(Exception.java:41)
 java.lang.NoSuchMethodException.(NoSuchMethodException.java:32)
 java.lang.Class.getMethod(Class.java:1605)
 org.apache.commons.beanutils.MethodUtils.getMatchingAccessibleMethod(MethodUtils.java:957)
 org.apache.commons.beanutils.MappedPropertyDescriptor.getMethod(MappedPropertyDescriptor.java:409)
 3、用Btrace跟蹤更為詳細的堆棧信息，以及到底是什麼方法找不到，BTrace腳本如下：
 import static com.sun.btrace.BTraceUtils.*;
 import com.sun.btrace.annotations.*;
 @BTrace public class Trace{
 @OnMethod(
 clazz=”java.lang.NoSuchMethodException”,
 method=””
 )
 public static void traceExecute(String s){
 println(“who call”);
 println(s);
 jstack();
 }
 }
 掛上Btrace後很快跟蹤到了找不到的方法（而且確實也能看到，NoSuchMethodException拋的是比較的頻繁），最初我懷疑是應用裡面有多個沖突的版本的類，導致method找不到，於是打開-XX:+TraceClassLoading，確認需要找的那個類是從哪加載的，然後反編譯對應的jar包，發現確實是沒有相應的方法，因為是業務代碼中調BeanUtils時出現的現象，我的猜測是頁面請求中提交了這樣的參數，但在POJO類中相應的屬性已經被刪除了，於是把這個猜測提交給了應用開發的同學。
 4、應用的開發同學確認是由於頁面上form裡會有一些隱藏域，而這些隱藏域在這個POJO類是沒有對應的屬性的，但有點奇怪的是，為什麼外部捕捉不到這個異常，跟蹤BeanUtils（1.8.3）的代碼，才發現BeanUtils在出現NoSuchMethodException的時候，會直接吃掉異常：
 950 try {
 951 // Check the cache first
 952 Method method = getCachedMethod(md);
 953 if (method != null) {
 954 return method;
 955 }
 956
 957 method = clazz.getMethod(methodName, parameterTypes);
 958 if (log.isTraceEnabled()) {
 959 log.trace(“Found straight match: ” + method);
 960 log.trace(“isPublic:” + Modifier.isPublic(method.getModifiers()));
 961 }
 962
 963 setMethodAccessible(method); // Default access superclass workaround
 964
 965 cacheMethod(md, method);
 966 return method;
 967
 968 } catch (NoSuchMethodException e) { /* SWALLOW */ }
 到這就徹底能解釋通了，於是著手做解決方案，在這裡采用的解決方法是：寫了一個static類，在啟動時即把需要用到的相應的POJO類有的屬性裝載到一個map裡，然後在每次調用BeanUtils之前，先判斷下屬性是否存在，不存在則跳過，這樣就不會觸發NoSuchMethodException了。
 5、改造完成上線後，效果非常理想，cpu us在升級前和升級後的對比狀況圖示如下：
 
 另外一個數據是壓測數據，在升級前當引5倍流量進行壓測時，cpu us就會到80%左右，rt接近1s，升級後引10倍流量壓測，cpu us也才13%左右，rt在100ms以下，可見效果非常明顯。
 總結：從這個案例可以看到，Java應用裡頻繁拋異常對於高並發而言影響還是非常的大，因此在編寫Java應用時，還是要盡可能減少拋異常，尤其是吃異常這種事情，要少做。
 總結：在查看String.intern的一些變化時，突然想到了這個case，發現在這個case的根本原因上，判斷錯誤了，頻繁拋NoSuchMethodException並不是造成cpu us變化的原因，而是因為method = clazz.getMethod(methodName, parameterTypes);這行代碼，對應的Class.getMethod中會執行methodName.intern()，而這個case中，methodName會跟著請求而動態的變化，所以導致位於perm gen的StringTable中的String不斷的增加，而StringTable的size默認為1009，String太多的話會導致hash沖突嚴重，鏈表長度過長，導致了每次String.intern時去鏈表裡遍歷很耗cpu。