不經意的兩行代碼把CPU使用率干到了90%+ 沒源碼怎么排查?
背景介紹
某同學反映某個應用ECS CPU使用率90%+,希望分析下原因。
該應用使用schedulerx來做定時任務執行,每隔一小時執行一次,每次執行5分鐘左右,執行任務期間CPU使用率90%+。
問題現象
圖1 ECS監控指標
ECS配置是4c8g,從上圖來看系統負載已經非常高了。
分析過程
尋找熱點代碼
arthas profiler比較適用CPU使用率持續較高的場景。通過對熱點火焰圖的分析,NoSuchMethodException異常相關代碼占用了很多CPU時間。
圖2 熱點火焰圖
上圖紅框中NoSuchMethodException展開后如下圖:
圖2 異常火焰圖
分析異常
ClassUtils
從上圖可以看出org.springframework.util.ClassUtils.getStaticMethod調用了Class.getMethod,Class.getMethod拋出了NoSuchMethodException,代碼如下。
圖3 ClassUtils.getStaticMethod
為了進一步定位問題,需要知道ClassUtils.getStaticMethod方法的入參:
圖4 arthas watch
?從上圖看出ClassUtils.getStaticMethod方法入參分別是:**clazz:java.util.Date;_methodName:_valueOf;args[0]:**java.sql.Timestamp。上面圖片只是截取了一部分,其中methodName還有of、from。
ObjectToObjectConverter
調用ClassUtils.getStaticMethod的地方是org.springframework.core.convert.support.ObjectToObjectConverter.determineFactoryMethod:?
圖5 ObjectToObjectConverter.determineFactoryMethod
調用ObjectToObjectConverter.determineFactoryMethod的地方是ObjectToObjectConverter.getValidateMember:
圖6 ObjectToObjectConverter.getValidateMember
雖然java.sql.Timestamp是java.util.Date的子類,但是從上面代碼可以看出進行了很多次無效的調用。
定位業務代碼
為了更準確的定位相關業務代碼,我們需要知道拋出NoSuchMethodException的線程棧,可以使用arthas stack,從線程棧我們可以知道在【哪個類哪個方法哪行】發出的調用。
stack org.springframework.util.ClassUtils getStaticMethod 'returnObj==null'
圖7 arthas stack
分析業務代碼
在我們沒有源代碼的情況,我們可以使用arthas jad反編譯定位到的類,進而分析業務代碼,到這里就可以具體定位到問題了。
圖8 業務代碼
gmt_created、gmt_modified在實體類中的定義:
圖9 業務實體類
異常場景回顧
查詢數據庫,數據庫返回ResultSet對象。
遍歷ResultSet,將ResultSet每一行映射到相應的業務實體類實例化業務實體類,根據ResultSet.getMetaData()獲取每一列的值并將該值set到實體類對應屬性上在將gmt_created、gmt_modified解析為java.sql.Timestamp類實例,接著使用ObjectToObjectConverter將java.sql.Timestamp轉換為java.util.Date的時候拋出了NoSuchMethodException。
異常場景復現示例代碼:
圖10 測試代碼
圖11 測試代碼
解決辦法
數據庫表中gmt_created、gmt_modified類型與實體類中對應字段類型的定義保持一致,可以解決異常。
延申閱讀
通過提高BeanPropertyRowMapper相關邏輯的緩存命中率可以進一步優化性能,如提前將轉換邏輯放到GenericConversionService類的converters中:
圖12 優化邏輯
另外可以通過自定義RowMapper來提高性能,因為BeanPropertyRowMapper并不是高性能的一種實現:
圖13 BeanPropertyRowMapper