線上排查:記憶體異常使用導致full gc頻繁

IntoTw發表於2023-02-07

線上排查:記憶體異常使用導致full gc頻繁

問題系統

日常巡檢發現,應用線上出現頻繁full gc

現象

應用線上出現頻繁full gc

排查過程

分析dump

拉dump檔案:小插曲:dump時如果指定:live,則在dump前jvm會先進行一次full gc,並且gc log裡會列印dump full gc,這種對非記憶體洩漏導致的線上異常記憶體情況排查反而會帶來不便,導致我們多dump了好幾次。
分析dump檔案
a. 發現大量long[]陣列佔用最大空間,有異常情況

b. 檢視gc根節點,發現這些long[]資料大部分是被org.HdrHistogram.Histogram持有,每個Histogram物件會持有一個2048size的long[]
c. 檢視Histogram例項的數量,竟然有5w個,對比下正常專案的堆疊,大約是100倍

d. 這裡又有一個插曲,一開始習慣用mat分析,但是mat生成的報告對分析洩露比較有用,對於分析異常的記憶體沒有jvisualvm.exe和idea的profiler好用

排查原因

本地啟動,可以復現這個類的記憶體使用情況,於是本地起一個其他記憶體正常的服務與有問題的應用,分析記憶體對比

這裡用的是idea的profiler,很方便

發現差異:
對比正常的應用,發現異常應用的引用存在異常的來自

● rx.internal.operators.OnSubscribeReduceSeed$ReduceSeedSubscriber的引用,懷疑就是這個異常引用就是導致這些例項無法在新生代回收而是堆積到了老年代觸發full gc的原因

排查差異
簡單看了下相關程式碼,看不出個所以然,直接debug對比
系統確實走進了相關的程式碼,增加了對Histogram的引用,而正常應用沒有

但是光這樣也看不出來為什麼,此時關注到了左下角的執行緒池,這個執行緒池比較奇怪,是Metric的執行緒池
Metric是Hystrix用來統計相關指標,來供自己的dashboard或者使用者來獲取,以此來了解系統熔斷相關引數和指標的功能
再看堆疊,走到這裡的邏輯是

這個流用來統計單位時間內的系統指標,導致Hystrix使用Histogram的long陣列實現類似滑動視窗的效果統計單位時間內的指標
Histogram本身是Hystrix用來實現類似桶+滑動視窗的功能,來統計單位時間內的流量,但是因為開啟了指標引數,導致hystrix為了統計更長時間範圍內的指標,新增了物件持有更多(單位時間內)的Histogram引用來聚合,這部分引用因為是統計更長時間範圍週期的,就會因為引用持有時間長而到老年代,但是本質並不是記憶體洩漏,所以每次full gc後又可以得到回收

解決問題

看到上面的差異和怪異的執行緒池,第一反應就是關閉metric使應用不走到這段邏輯中增加引用,看官方文件,該配置預設是開啟的,並且確認該功能隻影響指標統計不影響斷路器本身功能,使用配置hystrix.metrics.enabled=false配置來關閉
新增配置後,驗證並檢視堆疊,引用恢復正常,並且系統在一段時間後並沒有新增更多的Histogram例項,釋出線上後觀察一段時間,full gc問題確實得到解決

根本原因

在當時發現解決的辦法並驗證後,並沒有時間去研究hystrix.metrics.enabled預設配置就是true但是其他應用沒有出現這個full gc問題的原因, 先解決了之後後續再繼續跟進排查根本原因防止其他專案也出現相同問題
之前發現可疑的執行緒池是HystrixMetricsPoller ,經過檢視,該執行緒池由HystrixMetricsPollerConfiguration

類開啟,主要依靠hystrix.metrics.enabled開啟,但是預設是true,為什麼其他專案沒有開啟呢?
搜了下原始碼,這個類的開啟還和一個註解有關

對比了一下程式碼,果然只有異常的應用使用了這個註解,這個註解的目的是開啟斷路器
但是研究之後發現,不使用這個註解,熔斷等功能依舊可用,原因是在spring-cloud高版本之後,spring透過使用hystrix封裝openfeign的方法來使用熔斷,而不是整合整個hystrix體系,可能spring-cloud也發現了hystrix記憶體使用上的問題
所以在較高版本(起碼我們的版本),feign是透過feign.hystrix.enabled來開關斷路器的(這個開關是關閉的話,單純加@EnableCircuitBreaker註解斷路器是不會生效的)
其實在更高點版本的spring-cloud中,@EnableCircuitBreaker這個註解已經被標註為廢棄了,但是可能因為我們是中間版本,所以存在既沒有標註廢棄其實又沒有什麼用的情況
總而言之,feign的斷路功能只透過feign.hystrix.enabled來控制,增加@EnableCircuitBreaker註解之後僅僅只是會開啟Hystrix其他所有的指標等功能

問題總結

問題根本原因

本次問題產生的根本原因是因為開啟了@EnableCircuitBreaker註解,開啟了Hystrix指標功能,導致Histogram例項大量進入老年代,只有full gc才可以回收
Histogram本身是Hystrix用來實現類似桶+滑動視窗的功能,來統計單位時間內的流量,但是因為開啟了指標引數,導致hystrix為了統計更長時間範圍內的指標,新增了物件持有更多(單位時間內)的Histogram引用來聚合,這部分引用因為是統計更長時間範圍週期的,在訪問量上升新生代複製速度變快時,就會因為引用持有時間長而到老年代,但是本質並不是記憶體洩漏,所以每次full gc後又可以得到回收

後續關注點

  1. Spring-Cloud本身體系比較複雜,因為和Netfilx套件糾纏不清加上很多歷史原因,能用明白某一個版本的就很不錯了
  2. 開發本身並不瞭解這個版本斷路器到底怎麼開啟,沒有仔細看過對應版本的官方文件就去使用註解,在老版本,斷路器確實是透過這個註解才能啟用的

解決方式

關閉metric功能或者去掉@EnableCircuitBreaker註解均可解決
百度spring-cloud教程和文件時,一定一定一定要看對應版本的,否則可能加一堆配置解決某個問題,結果開啟一大堆亂七八糟的功能

相關文章